Re: Regression: onboard-usb-hub breaks USB on RPi 3

[Stefan Wahren <stefan.wahren@i2se.com>]

Hi Matthias,

Am 21.12.22 um 17:50 schrieb Matthias Kaehlcke:
> On Wed, Dec 21, 2022 at 01:29:25PM +0100, Stefan Wahren wrote:
>> Hi Matthias,
>>
>> Am 20.12.22 um 23:50 schrieb Matthias Kaehlcke:
>>> Today I learned that regulator_get() doesn't return an error when the regulator
>>> isn't specified, but the 'dummy regulator'. With that the platform driver is
>>> instantiated, which is not intended. The proper fix is probably to skip the
>>> creation of the 'raw' platform device in onboard_hub_create_pdevs() when the
>>> 'vdd-supply' does not exist.
>> Yes, i can confirm this by debugfs:
>>
>>   regulator                      use open bypass  opmode voltage current
>> min     max
>> ---------------------------------------------------------------------------------------
>>   regulator-dummy                  8    7      0 unknown 0mV     0mA
>> 0mV     0mV
>>      serial0-0-vddio 1                                 0mA     0mV     0mV
>>      serial0-0-vbat 1                                 0mA     0mV     0mV
>>      3f980000.usb:usb-port@1:usb-port@1-vdd 1
>> 0mA     0mV     0mV
>>      3f980000.usb:usb-port@1-vdd 1                                 0mA
>> 0mV     0mV
>>      3f980000.usb-vusb_a 1                                 0mA     0mV
>> 0mV
>>      3f980000.usb-vusb_d 1                                 0mA     0mV
>> 0mV
>>      phy-vcc 1                                 0mA     0mV     0mV
>>
>>> I tried to repro the Rpi 3 case by adjusting sc7280-herobrine.dtsi to look
>>> somewhat similar to the Rpi 3 hub config, but so far I wasn't 'successful'
>>> with breaking USB by deleting 'vdd-supply' (and 'peer-hub'). So I don't fully
>>> understand your scenario, but I'm relatively confident that not creating the
>>> platform devices should fix it.
>> I just played a little bit with arch/arm/boot/dts/bcm283x-rpi-lan7515.dtsi
>> and removed only the second hub node (including ethernet chip). After this
>> the issue also doesn't occur without any modification to onboard-usb-hub. So
>> it seems to me that the real issue is caused by the cascade of 2x Microchip
>> USB2514B USB 2.0 hubs.
> Thanks for your debugging efforts.
>
> I did some limited testing with nested hubs during development of the
> driver, using an external hub as alleged 2nd level onboard hub. I went
> back to such a configuration, unfortunately I still can't repro what
> you are seeing :(
>
>> Here are the relevant kernel log entries:
>>
>> [    4.025150] dwc2 3f980000.usb: supply vusb_d not found, using dummy
>> regulator
>> [    4.038776] dwc2 3f980000.usb: supply vusb_a not found, using dummy
>> regulator
>> [    4.104207] dwc2 3f980000.usb: DWC OTG Controller
>> [    4.115852] dwc2 3f980000.usb: new USB bus registered, assigned bus
>> number 1
>> [    4.129921] dwc2 3f980000.usb: irq 66, io mem 0x3f980000
>> [    4.513217] usb 1-1: new high-speed USB device number 2 using dwc2
>> [    5.123296] usb 1-1.1: new high-speed USB device number 3 using dwc2
>> [    5.623217] usb 1-1.3: new low-speed USB device number 4 using dwc2
>> [    5.785049] input: HID 046a:0011 as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3:1.0/0003:046A:0011.0001/input/input0
>> [    5.863240] usb 1-1.1.2: new low-speed USB device number 5 using dwc2
>> [    5.868998] hid-generic 0003:046A:0011.0001: input: USB HID v1.11
>> Keyboard [HID 046a:0011] on usb-3f980000.usb-1.3/input0
>> [    6.031327] input: PixArt Microsoft USB Optical Mouse as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1/1-1.1.2/1-1.1.2:1.0/0003:045E:00CB.0002/input/input1
>> [    6.031490] hid-generic 0003:045E:00CB.0002: input: USB HID v1.11 Mouse
>> [PixArt Microsoft USB Optical Mouse] on usb-3f980000.usb-1.1.2/input0
>> [    6.333278] usb 1-1.1.1: new high-speed USB device number 6 using dwc2
>> [   24.165633] usbcore: registered new interface driver lan78xx
>> [   24.423801] onboard-usb-hub 3f980000.usb:usb-port@1: supply vdd not
>> found, using dummy regulator
>> [   24.424202] usbcore: registered new device driver onboard-usb-hub
>> [   24.424376] usb 1-1.1: USB disconnect, device number 3
>> [   24.424385] usb 1-1.1.1: USB disconnect, device number 6
>> [   24.564921] usb 1-1.1.2: USB disconnect, device number 5
>> [   24.624696] usb 1-1.3: USB disconnect, device number 4
>> [   25.523236] usb 1-1.1: new high-speed USB device number 7 using dwc2
>> [   26.143248] usb 1-1.3: new low-speed USB device number 8 using dwc2
>> [   26.305673] input: HID 046a:0011 as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3:1.0/0003:046A:0011.0003/input/input2
>> [   26.374840] hid-generic 0003:046A:0011.0003: input: USB HID v1.11
>> Keyboard [HID 046a:0011] on usb-3f980000.usb-1.3/input0
>> [   26.383241] usb 1-1.1.2: new low-speed USB device number 9 using dwc2
>> [   26.521526] input: PixArt Microsoft USB Optical Mouse as /devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1/1-1.1.2/1-1.1.2:1.0/0003:045E:00CB.0004/input/input3
>> [   26.522241] hid-generic 0003:045E:00CB.0004: input: USB HID v1.11 Mouse
>> [PixArt Microsoft USB Optical Mouse] on usb-3f980000.usb-1.1.2/input0
>> [   26.833251] usb 1-1.1.1: new high-speed USB device number 10 using dwc2
>>
>> As you can see the input devices are deregistered after probing of
>> onboard-usb-hub and then registered again.
> It looks like the onboard_usb_hub driver is built as a module, which
> is the cause of the de- and re-registration. On a system that actually
> intends to use the onboard_hub driver I would recommand to make it a
> builtin driver to avoid this, but a module driver should still work.
Yes, most of the USB stuff is builtin, but onboard-usb-hub is build as 
module.
> I changed my kernel config to use a onboard_hub module, but that didn't
> help either with reproducing the issue.
>
> Which kernel version are you running on the Rpi 3?

I started with v6.1, then went to v6.0 and then

43993626de00 ("usb: misc: onboard-hub: add support for Microchip 
USB2514B USB 2.0 hub"). All of them showed the issue. The configuration 
based on arm/multi_v7_defconfig. In the last case i need to enable 
ONBOARD_USB_HUB in the configuration.

Based on my observations in v6.1 it wasn't always reproducible (50/50 
chance).

Btw the initial subject wasn't precise only Rpi 3 B Plus is affected.

>
>> The re-registering doesn't happen in the error case (as in my first email).
> Could you add logs to onboard_hub_usbdev_probe() to see whether it is called
> at all and how far it gets? Confirming whether onboard_hub_probe() completes
> successfully might also help.

Sure:

[    7.963910] usbcore: registered new interface driver lan78xx
[    8.231548] onboard-usb-hub 3f980000.usb:usb-port@1: 
onboard_hub_probe called
[    8.231590] onboard-usb-hub 3f980000.usb:usb-port@1: supply vdd not 
found, using dummy regulator
[    8.231763] onboard-usb-hub 3f980000.usb:usb-port@1: 
onboard_hub_probe success
[    8.231867] onboard-usb-hub 3f980000.usb:usb-port@1:usb-port@1: 
onboard_hub_probe called
[    8.231880] onboard-usb-hub 3f980000.usb:usb-port@1:usb-port@1: 
supply vdd not found, using dummy regulator
[    8.231971] onboard-usb-hub 3f980000.usb:usb-port@1:usb-port@1: 
onboard_hub_probe success
[    8.232090] usbcore: registered new device driver onboard-usb-hub
[    8.232256] usb 1-1.1: USB disconnect, device number 3
[    8.232264] usb 1-1.1.1: USB disconnect, device number 6
[    8.380602] usb 1-1.1.2: USB disconnect, device number 5
[    8.447421] usb 1-1.3: USB disconnect, device number 4

So onboard_hub_probe() is called successfully, but 
onboard_hub_usbdev_probe() doesn't seems to be.

>
>> Also in error case i noticed an unusual high load on the Rpi board, which
>> doesn't occur in good case. Is it possible that both onboard-usb-hub
>> instances are in some kind of deadlock?
> Possibly. The driver itself uses a mutex for locking, which shouldn't result
> in a high load in case of a deadlock, in any case the high load you are
> observing seems to be related with the issue if it is only seen in the error
> case.
I will try to play with lock debugging.
>
> Do things work properly when of_is_onboard_usb_hub() returns always false?
> That would be similar to the fix I have in mind for configs that shouldn't
> use the onboard_hub driver.
[   24.781914] usbcore: registered new device driver onboard-usb-hub
[   24.782097] usb 1-1.1: USB disconnect, device number 3
[   24.782110] usb 1-1.1.1: USB disconnect, device number 6
[   24.916725] usb 1-1.1.2: USB disconnect, device number 5
[   25.011118] usb 1-1.3: USB disconnect, device number 4
[   25.648211] onboard-usb-hub 1-1: onboard_hub_usbdev_probe called
[   25.648259] onboard-usb-hub 1-1: failed to find device node for peer hub
[   25.648264] onboard-usb-hub: probe of 1-1 failed with error -22
[   25.965643] usb 1-1.1: new high-speed USB device number 7 using dwc2
[   26.107578] onboard-usb-hub 1-1.1: onboard_hub_usbdev_probe called
[   26.107636] onboard-usb-hub 1-1.1: failed to find device node for 
peer hub
[   26.107642] onboard-usb-hub: probe of 1-1.1 failed with error -22
[   26.415691] usb 1-1.3: new low-speed USB device number 8 using dwc2
[   26.567393] input: HID 046a:0011 as 
/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.3/1-1.3:1.0/0003:046A:0011.0003/input/input2
[   26.637183] hid-generic 0003:046A:0011.0003: input: USB HID v1.11 
Keyboard [HID 046a:0011] on usb-3f980000.usb-1.3/input0
[   26.645694] usb 1-1.1.2: new low-speed USB device number 9 using dwc2
[   26.793634] input: PixArt Microsoft USB Optical Mouse as 
/devices/platform/soc/3f980000.usb/usb1/1-1/1-1.1/1-1.1.2/1-1.1.2:1.0/0003:045E:00CB.0004/input/input3
[   26.793859] hid-generic 0003:045E:00CB.0004: input: USB HID v1.11 
Mouse [PixArt Microsoft USB Optical Mouse] on usb-3f980000.usb-1.1.2/input0
[   27.135695] usb 1-1.1.1: new high-speed USB device number 10 using dwc2