USB webcam device disconnects don't trigger the associated kernel disconnect processing

[P33M]

Seen on latest 4.19 and rpi-update 5.4 on a Pi 4B.

Steps to reproduce: Configure a Pi Zero as a USB gadget webcam (legacy g_webcam was used). Plug the device in to any hub port while running the uvc-video script.

• Device attaches
• Is probed
• USB activity goes quiescent
  Disconnect the Pi Zero
• No disconnect message appears in the message log, and ffmpeg can still attempt to access the device (but it obviously fails).
• Plugging in a different device into the dead port does not generate a connect event message.

Swap g_webcam for g_ether -> disconnect is registered correctly.
Swap g_webcam for g_cdc -> disconnect is registered correctly.

I can provoke a disconnect when using g_webcam if it is unplugged before this uvcvideo trace message appears about suspending the interface:

[  168.090046] usb 1-1.4.3: new high-speed USB device number 5 using xhci_hcd
[  168.221025] usb 1-1.4.3: New USB device found, idVendor=1337, idProduct=0001, bcdDevice= 0.01
[  168.221041] usb 1-1.4.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[  168.221053] usb 1-1.4.3: Product: webbycam
[  168.221066] usb 1-1.4.3: Manufacturer: Dave
[  168.221079] usb 1-1.4.3: SerialNumber: 12345
[  168.223401] uvcvideo: Probing generic UVC device 1.4.3
[  168.223588] uvcvideo: Found format YUV 4:2:2 (YUYV).
[  168.223600] uvcvideo: - 640x360 (15.0 fps)
[  168.223610] uvcvideo: - 1280x720 (2.0 fps)
[  168.223621] uvcvideo: Found format MJPEG.
[  168.223631] uvcvideo: - 640x360 (15.0 fps)
[  168.223641] uvcvideo: - 1280x720 (2.0 fps)
[  168.223658] uvcvideo: Found a Status endpoint (addr 81).
[  168.223669] uvcvideo: Found UVC 1.00 device webbycam (1337:0001)
[  168.224001] uvcvideo: Added control 00000000-0000-0000-0000-000000000001/2 to device 1.4.3 entity 1
[  168.224018] uvcvideo: Adding mapping 'Exposure, Auto' to control 00000000-0000-0000-0000-000000000001/2.
[  168.224276] uvcvideo: Added control 00000000-0000-0000-0000-000000000101/2 to device 1.4.3 entity 2
[  168.224289] uvcvideo: Adding mapping 'Brightness' to control 00000000-0000-0000-0000-000000000101/2.
[  168.224305] uvcvideo: Scanning UVC chain: OT 3 <- PU 2 <- IT 1
[  168.224329] uvcvideo: Found a valid video chain (1 -> 3).
[  168.225764] uvcvideo 1-1.4.3:1.0: Entity type for entity Processing 2 was not initialized!
[  168.225780] uvcvideo 1-1.4.3:1.0: Entity type for entity Camera 1 was not initialized!
[  168.226137] input: webbycam: UVC Camera as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4/1-1.4.3/1-1.4.3:1.0/input/input0
[  168.226162] uvcvideo: UVC device initialized.
[  168.305309] uvcvideo: uvc_v4l2_open
[  168.305774] uvcvideo: uvc_v4l2_release
[  168.363400] uvcvideo: uvc_v4l2_open
[  168.363409] uvcvideo: uvc_v4l2_open
[  168.363453] uvcvideo: uvc_v4l2_release
[  168.363455] uvcvideo: uvc_v4l2_release
[  168.363809] uvcvideo: uvc_v4l2_open
[  168.364121] uvcvideo: uvc_v4l2_open
[  168.365354] uvcvideo: uvc_v4l2_release
[  168.365371] uvcvideo: uvc_v4l2_release
[  171.129630] uvcvideo: Suspending interface 1
[  171.129643] uvcvideo: Suspending interface 0


vs.

[  666.314342] usb 1-1.4.4: new high-speed USB device number 9 using xhci_hcd
[  666.445340] usb 1-1.4.4: New USB device found, idVendor=1d6b, idProduct=0102, bcdDevice= 4.19
[  666.445356] usb 1-1.4.4: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[  666.445369] usb 1-1.4.4: Product: Webcam gadget
[  666.445381] usb 1-1.4.4: Manufacturer: Linux Foundation
[  666.447533] uvcvideo: Probing generic UVC device 1.4.4
[  666.447705] uvcvideo: Found format YUV 4:2:2 (YUYV).
[  666.447718] uvcvideo: - 640x360 (15.0 fps)
[  666.447728] uvcvideo: - 1280x720 (2.0 fps)
[  666.447738] uvcvideo: Found format MJPEG.
[  666.447748] uvcvideo: - 640x360 (15.0 fps)
[  666.447758] uvcvideo: - 1280x720 (2.0 fps)
[  666.447775] uvcvideo: Found a Status endpoint (addr 81).
[  666.447786] uvcvideo: Found UVC 1.00 device Webcam gadget (1d6b:0102)
[  666.448117] uvcvideo: Added control 00000000-0000-0000-0000-000000000001/2 to device 1.4.4 entity 1
[  666.448135] uvcvideo: Adding mapping 'Exposure, Auto' to control 00000000-0000-0000-0000-000000000001/2.
[  666.448368] uvcvideo: Added control 00000000-0000-0000-0000-000000000101/2 to device 1.4.4 entity 2
[  666.448382] uvcvideo: Adding mapping 'Brightness' to control 00000000-0000-0000-0000-000000000101/2.
[  666.448397] uvcvideo: Scanning UVC chain: OT 3 <- PU 2 <- IT 1
[  666.448421] uvcvideo: Found a valid video chain (1 -> 3).
[  666.449692] uvcvideo 1-1.4.4:1.0: Entity type for entity Processing 2 was not initialized!
[  666.449708] uvcvideo 1-1.4.4:1.0: Entity type for entity Camera 1 was not initialized!
[  666.450048] input: Webcam gadget: UVC Camera as /devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb1/1-1/1-1.4/1-1.4.4/1-1.4.4:1.0/input/input2
[  666.450221] uvcvideo: UVC device initialized.
[  666.506873] uvcvideo: uvc_v4l2_open
[  666.507363] uvcvideo: uvc_v4l2_release
[  666.543203] uvcvideo: uvc_v4l2_open
[  666.543248] uvcvideo: uvc_v4l2_release
[  666.543892] uvcvideo: uvc_v4l2_open
[  666.545569] uvcvideo: uvc_v4l2_open
[  666.545594] uvcvideo: uvc_v4l2_release
[  666.545763] uvcvideo: uvc_v4l2_release
[  666.545852] uvcvideo: uvc_v4l2_open
[  666.546076] uvcvideo: uvc_v4l2_release
[  667.496107] usb 1-1.4.4: USB disconnect, device number 9

So there is a critical window in which the device behaves normally.

If I have a port in the "dead" state, i.e. one which previously had a g_webcam Pi Zero attached, and was unplugged outside of the critical window, then unplugging a Pi Zero webcam from a different port results in two disconnect messages - one for the dead port and one for the webcam.

[P33M]

It's related to suspend processing. If I disable global autosuspend, the webcam gadget is correctly detected as disconnected when unplugged.

Downstream USB2.0 hubs can also trigger this issue, as they are automatically put in suspend by Linux if there are no attached devices.

Unable to replicate the same behaviour on a Pi 2. I am also unable to replicate this issue if I force a device (e.g. a mouse) to be suspended by unbinding the driver and changing the associated bus power control to "auto" - verified that the device was in suspend, then unplugged it - disconnect was detected.

[P33M]

Git bisect on firmware and this is the first bad commit:

9dbd67c91d371171c9d8a624e90dba1190645a2a is the first bad commit
commit 9dbd67c91d371171c9d8a624e90dba1190645a2a
Author: popcornmix <popcornmix@gmail.com>
Date:   Fri Mar 6 19:16:43 2020 +0000

    kernel: Bump to 4.19.108

    kernel: Add support for merus-amp soundcard and ma120x0p codec
    See: https://github.com/raspberrypi/linux/pull/3483

    kernel: gpio-ir-overlay: add parameter to configure signal polarity
    See: https://github.com/raspberrypi/linux/pull/3490

    kernel: overlays: sc16ic750-i2c: Fix xtal parameter
    See: https://github.com/raspberrypi/linux/issues/3156

    kernel: configs: Add KVM support to arm64 bcm2711_defconfig
    See: https://github.com/raspberrypi/linux/issues/3035

    firmware: Support Isp stats and params

    firmware: arm_loader: Make EMMC2 dma-ranges patch more tolerant

    firmware: bootromfs: Delete unwanted assert

    firmware: usb_eth: Increase timeouts for TFTP requests and retransmit ACK

Last good commit;

commit e5d33208b78224bfe2d1fb5cbfdcf23c8fe83e88
Author: popcornmix <popcornmix@gmail.com>
Date:   Fri Feb 28 19:04:54 2020 +0000

    kernel: Bump to 4.19.106

    kernel: configs: Add CONFIG_EXT4_ENCRYPTION=y
    See: https://github.com/raspberrypi/linux/issues/2486

    kernel: ARM: dts: Remove virtgpio from bcm2711-rpi-4-b.dts

    kernel: configs: Add CONFIG_HID_STEAM=m
    See: https://github.com/raspberrypi/linux/issues/3344

    firmware: Allow use of 24 bit framebuffers
    See: https://github.com/raspberrypi/firmware/issues/1338

    firmware: arm_loader: Add non-os_prefix cmdline.txt fallback

    firmware: board_info: Set board-info memory size according to SDRAM mode registers

    firmware: arm_loader: Treat min frequencies as optional
    See: https://www.raspberrypi.org/forums/viewtopic.php?f=63&t=264786

    firmware: arm_loader: Add overvoltage_delta for manufacture tests

[pelwell]

The downstream patches look harmless.

[P33M]

This upstream commit doesn't:

commit 37d2eb43b64c3c24c6815860f9fcf4f7307df95b
Author: Alan Stern <stern@rowland.harvard.edu>
Date:   Fri Jan 31 10:39:26 2020 -0500

    USB: hub: Don't record a connect-change event during reset-resume

    commit 8099f58f1ecddf4f374f4828a3dff8397c7cbd74 upstream.

    Paul Zimmerman reports that his USB Bluetooth adapter sometimes
    crashes following system resume, when it receives a
    Get-Device-Descriptor request while it is busy doing something else.

    Such a request was added by commit a4f55d8b8c14 ("usb: hub: Check
    device descriptor before resusciation").  It gets sent when the hub
    driver's work thread checks whether a connect-change event on an
    enabled port really indicates a new device has been connected, as
    opposed to an old device momentarily disconnecting and then
    reconnecting (which can happen with xHCI host controllers, since they
    automatically enable connected ports).

    The same kind of thing occurs when a port's power session is lost
    during system suspend.  When the system wakes up it sees a
    connect-change event on the port, and if the child device's
    persist_enabled flag was set then hub_activate() sets the device's
    reset_resume flag as well as the port's bit in hub->change_bits.  The
    reset-resume code then takes responsibility for checking that the same
    device is still attached to the port, and it does this as part of the
    device's resume pathway.  By the time the hub driver's work thread
    starts up again, the device has already been fully reinitialized and
    is busy doing its own thing.  There's no need for the work thread to
    do the same check a second time, and in fact this unnecessary check is
    what caused the problem that Paul observed.

    Note that performing the unnecessary check is not actually a bug.
    Devices are supposed to be able to send descriptors back to the host
    even when they are busy doing something else.  The underlying cause of
    Paul's problem lies in his Bluetooth adapter.  Nevertheless, we
    shouldn't perform the same check twice in a row -- and as a nice side
    benefit, removing the extra check allows the Bluetooth adapter to work
    more reliably.

    The work thread performs its check when it sees that the port's bit is
    set in hub->change_bits.  In this situation that bit is interpreted as
    though a connect-change event had occurred on the port _after_ the
    reset-resume, which is not what actually happened.

    One possible fix would be to make the reset-resume code clear the
    port's bit in hub->change_bits.  But it seems simpler to just avoid
    setting the bit during hub_activate() in the first place.  That's what
    this patch does.

    (Proving that the patch is correct when CONFIG_PM is disabled requires
    a little thought.  In that setting hub_activate() will be called only
    for initialization and resets, since there won't be any resumes or
    reset-resumes.  During initialization and hub resets the hub doesn't
    have any child devices, and so this code path never gets executed.)

    Reported-and-tested-by: Paul Zimmerman <pauldzim@gmail.com>
    Signed-off-by: Alan Stern <stern@rowland.harvard.edu>
    Link: https://marc.info/?t=157949360700001&r=1&w=2
    CC: David Heinzelmann <heinzelmann.david@gmail.com>
    CC: <stable@vger.kernel.org>
    Link: https://lore.kernel.org/r/Pine.LNX.4.44L0.2001311037460.1577-100000@iolanthe.rowland.org
    Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>

And lo, reverting it results in a suspended hub being properly detected as disconnected when unplugged.

[P33M]

Given that this is code common to all USB2 hubs, and we've not had much downstream fiddling done to this part of the Linux stack, I wonder if this is an issue on x86 as well.