[RPi4 4GB] xHCI host controller not responding, assume dead

[JANogueira]

Describe the bug
After boot-up, an when activating a service that uses USB interface (Network UPS tools, as an example) xHCI interface crashs and the USB devices get disconnected. Recovery only possible after system reboot.

List of USB devices when the system boots up:

Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 003: ID 0463:ffff MGE UPS Systems UPS
Bus 001 Device 002: ID 2109:3431 VIA Labs, Inc. Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

After enabling a:

Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

To reproduce
After system boot, start Network UPS tools (UPS connected through USB, having a poll frequency of 30 seconds), and the xHCI interface will crash shortly after, leading to all USB devices being disconnected.

System

Details:
Raspberry Pi 4 Model B Rev 1.1

# cat /etc/os-release | head -4
NAME=HassOS
VERSION="3.8 (RaspberryPi 4 64bit)"
ID=hassos
VERSION_ID=3.8

# uname -a
Linux hassio 4.19.93-v8 #1 SMP PREEMPT Sun Jan 12 18:33:10 UTC 2020 aarch64 Hassio/OS

# cat /proc/cpuinfo | tail -3
Revision        : c03111
Serial          : 1000000013df512e
Model           : Raspberry Pi 4 Model B Rev 1.1
#

# df                                                                                                                                                                                                                                     
Filesystem           1K-blocks      Used Available Use% Mounted on                                                                                                                                                                       
/dev/root                92032     92032         0 100% /                                                                                                                                                                                
devtmpfs               1915496         0   1915496   0% /dev                                                                                                                                                                             
tmpfs                  1948808         0   1948808   0% /dev/shm                                                                                                                                                                         
tmpfs                  1948808       708   1948100   0% /run                                                                                                                                                                             
tmpfs                  1948808         0   1948808   0% /sys/fs/cgroup                                                                                                                                                                   
tmpfs                  1948808       708   1948100   0% /etc/machine-id                                                                                                                                                                  
/dev/mmcblk0p7           91099     18656     65562  22% /mnt/overlay                                                                                                                                                                     
/dev/mmcblk0p7           91099     18656     65562  22% /root/.docker                                                                                                                                                                    
/dev/mmcblk0p7           91099     18656     65562  22% /etc/modprobe.d                                                                                                                                                                  
/dev/mmcblk0p7           91099     18656     65562  22% /etc/modules-load.d                                                                                                                                                              
/dev/mmcblk0p7           91099     18656     65562  22% /etc/docker                                                                                                                                                                      
/dev/mmcblk0p7           91099     18656     65562  22% /etc/dropbear                                                                                                                                                                    
/dev/mmcblk0p7           91099     18656     65562  22% /etc/udev/rules.d
/dev/mmcblk0p7           91099     18656     65562  22% /root/.ssh
/dev/mmcblk0p1           32686      3650     29036  11% /mnt/boot
/dev/mmcblk0p7           91099     18656     65562  22% /etc/hostname
/dev/mmcblk0p7           91099     18656     65562  22% /etc/systemd/timesyncd.conf
/dev/mmcblk0p7           91099     18656     65562  22% /etc/NetworkManager/system-connections
/dev/mmcblk0p7           91099     18656     65562  22% /etc/hosts
/dev/mmcblk0p8       122172044   6834280 109113732   6% /mnt/data
/dev/zram2               15856        40     14676   0% /tmp
/dev/zram1               31728       128     29312   0% /var
/dev/mmcblk0p7           91099     18656     65562  22% /var/lib/bluetooth
/dev/mmcblk0p8       122172044   6834280 109113732   6% /var/lib/docker
/dev/mmcblk0p7           91099     18656     65562  22% /var/log/journal
/dev/mmcblk0p7           91099     18656     65562  22% /var/lib/systemd
/dev/mmcblk0p7           91099     18656     65562  22% /var/lib/NetworkManager
overlay              122172044   6834280 109113732   6% /mnt/data/docker/overlay2/c79789ef74f2520ce9bf8308f4f0a0a0c2e2d1453a2836027ab47f3c629d6263/merged
overlay              122172044   6834280 109113732   6% /var/lib/docker/overlay2/c79789ef74f2520ce9bf8308f4f0a0a0c2e2d1453a2836027ab47f3c629d6263/merged
shm                      65536         0     65536   0% /mnt/data/docker/containers/4383e4a9b4bfd33f30377b389a5dd8e96f92522bfb5f5e75b5268393aca9af5f/mounts/shm
shm                      65536         0     65536   0% /var/lib/docker/containers/4383e4a9b4bfd33f30377b389a5dd8e96f92522bfb5f5e75b5268393aca9af5f/mounts/shm
overlay              122172044   6834280 109113732   6% /mnt/data/docker/overlay2/22cdad6842ade8567501c09ce194d03f072af3910c18cb54da5175d19b0e3aa6/merged
overlay              122172044   6834280 109113732   6% /var/lib/docker/overlay2/22cdad6842ade8567501c09ce194d03f072af3910c18cb54da5175d19b0e3aa6/merged
shm                      65536         0     65536   0% /mnt/data/docker/containers/d383f5286c098e038869aa411fbc087895e9852c34db2276b293d5493076e82f/mounts/shm
shm                      65536         0     65536   0% /var/lib/docker/containers/d383f5286c098e038869aa411fbc087895e9852c34db2276b293d5493076e82f/mounts/shm
overlay              122172044   6834280 109113732   6% /mnt/data/docker/overlay2/8a1741030a19b420c34768b69144ab241b11b00ec67083b86228cee3844dd40a/merged
overlay              122172044   6834280 109113732   6% /var/lib/docker/overlay2/8a1741030a19b420c34768b69144ab241b11b00ec67083b86228cee3844dd40a/merged
overlay              122172044   6834280 109113732   6% /mnt/data/docker/overlay2/69458a8f8866e9605cd4a15109eb3d1b2a81e7b2b76c81b8f7a1d1f3f7241ec1/merged
overlay              122172044   6834280 109113732   6% /var/lib/docker/overlay2/69458a8f8866e9605cd4a15109eb3d1b2a81e7b2b76c81b8f7a1d1f3f7241ec1/merged
shm                      65536        64     65472   0% /mnt/data/docker/containers/b9ddddacc42db28bed967a218c67d490d3b89e3bf3ac4bf980d0f027af739f41/mounts/shm
shm                      65536        64     65472   0% /var/lib/docker/containers/b9ddddacc42db28bed967a218c67d490d3b89e3bf3ac4bf980d0f027af739f41/mounts/shm
overlay              122172044   6834280 109113732   6% /mnt/data/docker/overlay2/563028cbdc5e65467e4299d65e42050ca216a6252d1e144e8491723a1434ad1e/merged
overlay              122172044   6834280 109113732   6% /var/lib/docker/overlay2/563028cbdc5e65467e4299d65e42050ca216a6252d1e144e8491723a1434ad1e/merged
overlay              122172044   6834280 109113732   6% /mnt/data/docker/overlay2/a00df7501c5d7ef5be8316129829c2b57b7fef415914170006b3172bb43ebaaa/merged
overlay              122172044   6834280 109113732   6% /var/lib/docker/overlay2/a00df7501c5d7ef5be8316129829c2b57b7fef415914170006b3172bb43ebaaa/merged
overlay              122172044   6834280 109113732   6% /mnt/data/docker/overlay2/a72a5bc9321264232980140c9bc6686e89db9c4a83a1da17c8755811f160de6a/merged
overlay              122172044   6834280 109113732   6% /var/lib/docker/overlay2/a72a5bc9321264232980140c9bc6686e89db9c4a83a1da17c8755811f160de6a/merged
overlay              122172044   6834280 109113732   6% /mnt/data/docker/overlay2/7624b7f0f58cc8d32d9d8702d26ae71c27fcd0026f27a6623b15c0ec13fd499a/merged
overlay              122172044   6834280 109113732   6% /var/lib/docker/overlay2/7624b7f0f58cc8d32d9d8702d26ae71c27fcd0026f27a6623b15c0ec13fd499a/merged
shm                      65536        48     65488   0% /mnt/data/docker/containers/376a3e6a98ad20b772ae7f38b2051750d0d38d2f876be82d1cc17a81ae801a05/mounts/shm
shm                      65536        48     65488   0% /var/lib/docker/containers/376a3e6a98ad20b772ae7f38b2051750d0d38d2f876be82d1cc17a81ae801a05/mounts/shm
shm                      65536        60     65476   0% /mnt/data/docker/containers/8043d49fda6b8c96b4cfd0fd77a8499b6f70e5a4ad7a66fc37eb417c1ac6a936/mounts/shm
shm                      65536        60     65476   0% /var/lib/docker/containers/8043d49fda6b8c96b4cfd0fd77a8499b6f70e5a4ad7a66fc37eb417c1ac6a936/mounts/shm
shm                      65536        68     65468   0% /mnt/data/docker/containers/ef4df3ae0e79c33285baec87cd55c0b9d28d150ffda2a19e799979073cd1297a/mounts/shm
shm                      65536        68     65468   0% /var/lib/docker/containers/ef4df3ae0e79c33285baec87cd55c0b9d28d150ffda2a19e799979073cd1297a/mounts/shm
shm                      65536        68     65468   0% /mnt/data/docker/containers/f73b6c980b13d97d27fb314c6224f8ed0ef66be8e8039b69436273dc328925f5/mounts/shm
shm                      65536        68     65468   0% /var/lib/docker/containers/f73b6c980b13d97d27fb314c6224f8ed0ef66be8e8039b69436273dc328925f5/mounts/shm
shm                      65536        56     65480   0% /mnt/data/docker/containers/6cbb56501e93036eebc86c0c4bfc38a133d2a62ab458290f5005c592a572e7e3/mounts/shm
shm                      65536        56     65480   0% /var/lib/docker/containers/6cbb56501e93036eebc86c0c4bfc38a133d2a62ab458290f5005c592a572e7e3/mounts/shm
overlay              122172044   6834280 109113732   6% /mnt/data/docker/overlay2/9737f2fb6b35435b15a046da2583412dd66e3559ab0fde67c9fd7c2e67336aa4/merged
overlay              122172044   6834280 109113732   6% /var/lib/docker/overlay2/9737f2fb6b35435b15a046da2583412dd66e3559ab0fde67c9fd7c2e67336aa4/merged
shm                      65536         0     65536   0% /mnt/data/docker/containers/05216e59fa3a97c660472ae072c417cab1743086a3bb61f40ff167f2caaa03ba/mounts/shm
shm                      65536         0     65536   0% /var/lib/docker/containers/05216e59fa3a97c660472ae072c417cab1743086a3bb61f40ff167f2caaa03ba/mounts/shm
overlay              122172044   6834280 109113732   6% /mnt/data/docker/overlay2/ce9f300e071672f49be4e085525ee1e19e381ff4e6bb869e12f5cad245018136/merged
overlay              122172044   6834280 109113732   6% /var/lib/docker/overlay2/ce9f300e071672f49be4e085525ee1e19e381ff4e6bb869e12f5cad245018136/merged
shm                      65536        68     65468   0% /mnt/data/docker/containers/f3c374354b066023eef0662df5fee6b5112d69eba4e2c18daff4223e387d00fa/mounts/shm
shm                      65536        68     65468   0% /var/lib/docker/containers/f3c374354b066023eef0662df5fee6b5112d69eba4e2c18daff4223e387d00fa/mounts/shm
# cat /proc/swaps
Filename                                Type            Size    Used    Priority
/dev/zram0                              partition       974400  0       -2
# 

• Which model of Raspberry Pi? Raspberry Pi 4B 4GB
• Which OS and version (cat /etc/rpi-issue)? HassOS 3.8
• Which firmware version (vcgencmd version)?
• Which kernel version (uname -a)? Linux hassio 4.19.93-v8 var->green.length may be left uninitialized #1 SMP PREEMPT Sun Jan 12 18:33:10 UTC 2020 aarch64 Hassio/OS

Logs
dmesg output:

[    0.197545] usbcore: registered new interface driver usbfs
[    0.197606] usbcore: registered new interface driver hub
[    0.197718] usbcore: registered new device driver usb
[    0.487955] usbcore: registered new interface driver r8152
[    0.488025] usbcore: registered new interface driver lan78xx
[    0.488474] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1
[    0.495448] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19
[    0.495481] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    0.495507] usb usb1: Product: xHCI Host Controller
[    0.495528] usb usb1: Manufacturer: Linux 4.19.88-v8 xhci-hcd
[    0.495549] usb usb1: SerialNumber: 0000:01:00.0
[    0.496073] hub 1-0:1.0: USB hub found
[    0.496671] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2
[    0.496706] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed
[    0.497145] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 4.19
[    0.497175] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    0.497200] usb usb2: Product: xHCI Host Controller
[    0.497220] usb usb2: Manufacturer: Linux 4.19.88-v8 xhci-hcd
[    0.497242] usb usb2: SerialNumber: 0000:01:00.0
[    0.497711] hub 2-0:1.0: USB hub found
[    0.499380] usbcore: registered new interface driver uas
[    0.499478] usbcore: registered new interface driver usb-storage
[    0.499601] usbcore: registered new interface driver usbserial_generic
[    0.499647] usbserial: USB Serial support registered for generic
[    0.507353] usbcore: registered new interface driver usbhid
[    0.507361] usbhid: USB HID core driver
[    0.830300] usb 1-1: new high-speed USB device number 2 using xhci_hcd
[    0.980982] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.20
[    0.981020] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[    0.981041] usb 1-1: Product: USB2.0 Hub
[    0.982796] hub 1-1:1.0: USB hub found
[    1.278306] usb 1-1.3: new full-speed USB device number 3 using xhci_hcd
[    1.615672] usbcore: registered new interface driver brcmfmac
[    1.999992] usb 1-1.3: New USB device found, idVendor=0463, idProduct=ffff, bcdDevice= 0.01
[    2.000016] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[    2.000027] usb 1-1.3: Product: 5E
[    2.000036] usb 1-1.3: Manufacturer: EATON
[    3.967565] hid-generic 0003:0463:FFFF.0001: hiddev96,hidraw0: USB HID v1.10 Device [EATON 5E] on usb-0000:01:00.0-1.3/input0
[  172.256228] xhci_hcd 0000:01:00.0: xHCI host not responding to stop endpoint command.
[  172.272306] xhci_hcd 0000:01:00.0: Host halt failed, -110
[  172.272321] xhci_hcd 0000:01:00.0: xHCI host controller not responding, assume dead
[  172.272369] xhci_hcd 0000:01:00.0: HC died; cleaning up [  172.272442] usb 1-1: USB disconnect, device number 2
[  172.272467] usb 1-1.3: USB disconnect, device number 3

Additional context
This bug report was opened here because HassOS3.8 rus default raspbian Kernel.
This issue was initially reported here:
home-assistant/operating-system#526

USB cable was replaced to ensure that it was not faulty.

If more logs are needed, please let me know

[timg236]

It might be worth trying different versions of the VL805 firmware. There’s a thread about it here
https://www.raspberrypi.org/forums/viewtopic.php?t=260879

[JANogueira]

Thank you. I will give it a try and share the outcome.

[JANogueira]

Well, on raspbian all went well, but not in hassio.
USB crash is still happening in hassio.

Before shutting down Raspbian I have ensured that the latest vl805 firmware was properly installed (using ´sudo vl805´ and have shown 0137ad).

Do you know if the EEPROM bin file deppends on any other optimization on the linux kernel side? or it should fix the USB behaviour by itself?

Thanks in advance.

[JANogueira]

Please, disregard my last post.
I was doing it wrong while trying to flash the EEPROM.

Took additional actions and all good apparently. 3 hours have passed and all is stable.
I will observe this for a couple of days more just to be sure, and share the outcome.

Many thanks once again!

[JANogueira]

Just to confirm that everything is still working perfectly.
0137ad solved the issue. USB devices are all stable and I had a small increase on the sdcard I/O.

[hardwareadictos]

Hey!! Having exactly the same issue on VL805 FW version: 000137ad

Are you still having issues? Can you provide more info about what you did to solve it?

[hardwareadictos]

Here some logs:

log_xhci_rpi4.txt

[JANogueira]

Hi @hardwareadictos,

It worked for about 1 week with VL805 FW 0137ad and then I am facing the same issue again.
Not fully solved unfortunately...

[hardwareadictos]

I opened an issue for that because I don't know if we have the same issue (I suspect we do):

#3438

Don't doubt on participating. Thanks for answering 😊

[hardwareadictos]

This could explain some things: c74b1b5

Dont know if that change is already implemented on last kernel...

[pelwell]

That patch allows for the possibility of loading VL805 firmware from system RAM rather than EEPROM, which has to be re-enabled after a PCI reset. The VPU firmware is not making use of that facility, so when it comes to your problem that commit is a red herring.

[hardwareadictos]

That patch allows for the possibility of loading VL805 firmware from system RAM rather than EEPROM, which has to be re-enabled after a PCI reset. The VPU firmware is not making use of that facility, so when it comes to your problem that commit is a red herring.

Im not an expert, that's why i said "could" and not "actually". Was also the only recent commit referencing to xHCI.

That issue isnt happening on previous releases.

What's you opinion on that?

Thanks in advance :)

[pelwell]

Perhaps the on-board voltage is a marginal - try adding over_voltage=1 to config.txt and rebooting.