Re: DWC2 gadget: unexpected device reenumeration on Rockchip RK3308

[Alan Stern]

On Mon, Apr 14, 2025 at 06:54:58PM +0200, Luca Ceresoli wrote:
> Hello Minas, Kever, linux-usb, recent dwc2 driver contributors,
> 
> I am facing an unexpected behavior (apparently a bug) with a dwc2
> controller in gadget mode, using a mainline kernel: the gadget device is
> enumerated normally but then disappears and gets re-enumerated about 6
> seconds after the initial enumeration, for no apparent reason. Here are
> the details.
> 
> Testing setup:
> 
> SoC:             Rockchip RK3308
> Board:           Rock Pi S [1]
> USB controller:  rockchip,rk3308-usb, snps,dwc2 [2]
> Controller mode: device only (dr_mode = "peripheral") [3]
> Tested kernels:
>  - v6.15-rc2
>  - v6.14.1
>  - v6.12.20
>  - v6.6.87
>  - v6.1.134
>  - v5.15.180
> Device tree:     upstream Rock Pi S dts [4]
> Kernel config:   ARM64 defconfig
> 
> Hardware setup: USB A-C cable connected from PC A port to the C
> connector on the Rock Pi S board. This cable provides board power as
> well as the connection between the host and the gadget.
> 
> Behavior:
>  1. boot board normally
>  2. optionally wait some time
>  3. run script to start a CDC serial gadget [5]
>  4. after about 0.6 seconds the ttyGS0 serial device is present and
>     working, and so is ttyACM0 on the host: so far all good
>  5. after about 6 seconds the dwc2 controller receives some
>     interrupts and starts a new enumeration sequence
> 
> This is what the kernel logs:
> 
> [   20.105688] dwc2 ff400000.usb: bound driver configfs-gadget.g1
> [   20.285431] dwc2 ff400000.usb: new device is high-speed
> [   20.373455] dwc2 ff400000.usb: new device is high-speed
> [   20.426496] dwc2 ff400000.usb: new address 28
> [   26.688388] dwc2 ff400000.usb: new device is high-speed
> [   26.775363] dwc2 ff400000.usb: new device is high-speed
> [   26.836880] dwc2 ff400000.usb: new address 29
> 
> Here is a side-by-side log of host and device, synced manually using
> a video capture (sorry about the long lines, can't do without):
> 
>     *** HOST ***                                                                                      *** DEVICE ***
>                                                                                                  <<< Last line of the script: 'echo ff400000.usb > UDC' >>>
>                                                                                                  [   14.281350] dwc2 ff400000.usb: bound driver configfs-gadget.g1
>                                                                                                  [   14.482332] dwc2 ff400000.usb: new device is high-speed
> [108204.084049] usb 3-2: new high-speed USB device number 39 using xhci_hcd
>                                                                                                  [   14.675692] dwc2 ff400000.usb: new device is high-speed
> [108204.274639] usb 3-2: New USB device found, idVendor=1209, idProduct=0001, bcdDevice= 1.00    [   14.737395] dwc2 ff400000.usb: new address 44
> [108204.274652] usb 3-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
> [108204.274656] usb 3-2: Product: ...
> [108204.274659] usb 3-2: Manufacturer: ...
> [108204.274662] usb 3-2: SerialNumber: 12345678
> [108204.282555] cdc_acm 3-2:1.0: ttyACM0: USB ACM device
>                                                             (...nothing happens for about 6 seconds...)
> [108209.972180] usb 3-2: USB disconnect, device number 39
>                                                                                                  [   20.766950] dwc2 ff400000.usb: new device is high-speed
> [108210.339297] usb 3-2: new high-speed USB device number 40 using xhci_hcd
>                                                                                                  [   20.960375] dwc2 ff400000.usb: new device is high-speed
> [108210.739738] usb 3-2: New USB device found, idVendor=1209, idProduct=0001, bcdDevice= 1.00    [   21.200670] dwc2 ff400000.usb: new address 45
> [108210.739750] usb 3-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
> [108210.739753] usb 3-2: Product: ...
> [108210.739756] usb 3-2: Manufacturer: ...
> [108210.739758] usb 3-2: SerialNumber: 12345678
> [108210.747084] cdc_acm 3-2:1.0: ttyACM0: USB ACM device
> 
> Note: the device address is different on the host and the target. Is
> this expected?

The value on the host side is a device number, not a device address.  
Device numbers are assigned sequentially by the kernel, whereas 
addresses are assigned automatically by the xHCI hardware without 
software intervention.

For non-xHCI controllers the two are the same, but not with xHCI.

> In the driver there are 2 interrupt handlers involved:
>  - dwc2_handle_common_intr in core_intr.c for the common events
>  - dwc2_hsotg_irq in gadget.c for gadget events
> 
> They share the same interrupt number, which AFAICU is because they
> actually read different bits from the same GINTSTS register.
> 
> I enabled DEBUG in the dwc2 driver and captured the initial events
> logged after the ~6 seconds pause, i.e. where the 2nd enumeration
> starts. Here they are with some annotations:
> 
>  1. first interrupt after the ~6 s break:
>     - dwc2_handle_common_intr finds no bits high
>     - dwc2_hsotg_irq finds one (early suspend bit):
>        [   46.203094] dwc2 ff400000.usb: dwc2_hsotg_irq: 04008428 00000400 (d88c3cc4) retry 8
>        [   46.204060] dwc2 ff400000.usb: GINTSTS_ErlySusp
> 
>  2. second interrupt
>     - dwc2_handle_common_intr finds one bits high (suspend):
>        [   46.206807] dwc2 ff400000.usb: USB SUSPEND
>        [   46.206824] dwc2 ff400000.usb: dwc2_handle_usb_suspend_intr: DSTS=0x502a01
>        [   46.206842] dwc2 ff400000.usb: DSTS.Suspend Status=1 HWCFG4.Power Optimize=1 HWCFG4.Hibernation=0
>        [   46.206872] dwc2 ff400000.usb: dwc2_hsotg_irq: 04008028 00000000 (d88c3cc4) retry 8      
>     - dwc2_hsotg_irq finds no bits high
> 
>  3. third interrupt
>     - dwc2_handle_common_intr finds no bits high
>     - dwc2_hsotg_irq finds two (reset detected + USB reset):
>        [   46.437109] dwc2 ff400000.usb: dwc2_hsotg_irq: 04809028 00801000 (d88c3cc4) retry 8
>        [   46.437607] dwc2 ff400000.usb: dwc2_hsotg_irq: USBRstDet
>        [   46.437630] dwc2 ff400000.usb: dwc2_hsotg_irq: USBRst
>        [   46.437649] dwc2 ff400000.usb: GNPTXSTS=00080010
>        [   46.437673] dwc2 ff400000.usb: complete: ep 00000000dab859c8 ep0, req 000000009cb97255, -108 => 00000000acdb2ee9
>        [   46.437719] dwc2 ff400000.usb: dwc2_hsotg_complete_setup: failed -108
>        [   46.437765] dwc2 ff400000.usb: dwc2_hsotg_ep_disable(ep 00000000cf8cf06f)
>        [   46.437790] dwc2 ff400000.usb: dwc2_hsotg_ep_disable: DxEPCTL=0x08080200
>        ...
> 
> From now on the log appears as a normal enumeration process.
> 
> I'm stuck at a dead end, trying to understand what may be triggering the
> second enumeration.

You should enable host-side debugging before connecting the cable:

	echo 'module usbcore =p' >/sys/kernel/debug/dynamic_debug/control

It's quite possible that you're getting messed up by link power 
management (LPM).  But that's just a guess.

Alan Stern