Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

USB subsystem will stop working. Pi 4 #3680

Open
JacoFourie opened this issue Jun 18, 2020 · 27 comments
Open

USB subsystem will stop working. Pi 4 #3680

JacoFourie opened this issue Jun 18, 2020 · 27 comments

Comments

@JacoFourie
Copy link

Describe the bug
The USB subsystem will stop working at random after hours or days. You can no longer see any connected devices.

Is there a way to get the USB back without having to reboot. Some command I can run to reset all USB.

Only a reboot will fix the issue. Here you can see an lsusb shows no devices and a hub-ctrl says there are no hubs found.

image

To reproduce
Run my libusb program with a python program that communicates with a RS485 modbus

Expected behaviour
The programs should keep on working.

Actual behaviour
I will start the programs and they may run for days but at some point the USB subsystem will vanish

System
System Information

Raspberry Pi 4 Model B Rev 1.1
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"

Raspberry Pi reference 2019-07-10
Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, 175dfb027ffabd4b8d5080097af0e51ed9a4a56c, stage5

Linux PI4 4.19.118-v7l+ raspberrypi/firmware#1311 SMP Mon Apr 27 14:26:42 BST 2020 armv7l GNU/Linux
Revision : c03111
Serial : 1xxxxc
Model : Raspberry Pi 4 Model B Rev 1.1
Throttled flag : throttled=0x0
Camera : supported=0 detected=0

Videocore information

May 11 2020 18:59:41
Copyright (c) 2012 Broadcom
version 21bfdeee3a6ea823e2113b983390acd1eec8edfb (clean) (release) (start)

alloc failures: 0
compactions: 0
legacy block fails: 0

Filesystem information

Filesystem 1K-blocks Used Available Use% Mounted on
/dev/root 30438344 18726248 10396652 65% /
devtmpfs 1966332 0 1966332 0% /dev
tmpfs 2000124 8 2000116 1% /dev/shm
tmpfs 2000124 18344 1981780 1% /run
tmpfs 5120 4 5116 1% /run/lock
tmpfs 2000124 0 2000124 0% /sys/fs/cgroup
/dev/mmcblk0p1 258096 52147 205949 21% /boot
tmpfs 400024 0 400024 0% /run/user/1000

Filename Type Size Used Priority
/var/swap file 1048572 0 -2

Package version information

raspberrypi-ui-mods:
Installed: 1.20200514
raspberrypi-sys-mods:
Installed: 20200514
openbox:
Installed: 3.6.1-8+rpt4
lxpanel:
Installed: 0.10.0-2+rpt9
pcmanfm:
Installed: 1.3.1-1+rpt21
rpd-plym-splash:
Installed: 0.23

Networking Information

eth0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST> mtu 1500
inet x.x.x.x netmask x.x.x.x broadcast x.x.x.x
inet6 y::y.y.y.y prefixlen 64 scopeid 0x20
ether m.m.m.m txqueuelen 1000 (Ethernet)
RX packets 7970703 bytes 746785062 (712.1 MiB)
RX errors 0 dropped 0 overruns 0 frame 0
TX packets 12254606 bytes 926117289 (883.2 MiB)
TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0

lo: flags=73<UP,LOOPBACK,RUNNING> mtu 65536
inet x.x.x.x netmask x.x.x.x
inet6 ::1 prefixlen 128 scopeid 0x10
loop txqueuelen 1000 (Local Loopback)
RX packets 206186 bytes 32671765 (31.1 MiB)
RX errors 0 dropped 0 overruns 0 frame 0
TX packets 206186 bytes 32671765 (31.1 MiB)
TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0

wlan0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST> mtu 1500
inet x.x.x.x netmask x.x.x.x broadcast x.x.x.x
inet6 y::y.y.y.y prefixlen 64 scopeid 0x20
ether m.m.m.m txqueuelen 1000 (Ethernet)
RX packets 768715 bytes 80631414 (76.8 MiB)
RX errors 0 dropped 0 overruns 0 frame 0
TX packets 243632 bytes 133322310 (127.1 MiB)
TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0

USB Information

/: Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/4p, 5000M
/: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/1p, 480M
|__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 480M
|__ Port 1: Dev 3, If 0, Class=Vendor Specific Class, Driver=pl2303, 12M
|__ Port 2: Dev 4, If 0, Class=Communications, Driver=cdc_acm, 12M
|__ Port 2: Dev 4, If 1, Class=CDC Data, Driver=cdc_acm, 12M
|__ Port 3: Dev 5, If 0, Class=Vendor Specific Class, Driver=ch341, 12M
|__ Port 4: Dev 6, If 0, Class=Human Interface Device, Driver=usbfs, 1.5M

config.txt

arm_freq=1500
audio_pwm_mode=514
config_hdmi_boost=5
core_freq=500
core_freq_min=200
disable_commandline_tags=2
disable_l2cache=1
display_default_lcd=1
display_hdmi_rotate=-1
display_lcd_rotate=-1
enable_gic=1
force_eeprom_read=1
force_pwm_open=1
framebuffer_ignore_alpha=1
framebuffer_swap=1
gpu_freq=500
gpu_freq_min=250
init_uart_clock=0x2dc6c00
lcd_framerate=60
lcd_rotate=2
max_framebuffers=2
over_voltage_avs=7500
pause_burst_frames=1
program_serial_random=1
total_mem=4096
hdmi_force_cec_address:0=65535
hdmi_force_cec_address:1=65535
hdmi_pixel_freq_limit:0=0x11e1a300
hdmi_pixel_freq_limit:1=0x11e1a300
device_tree=-
overlay_prefix=overlays/
hdmi_cvt:0=
hdmi_cvt:1=
hdmi_edid_filename:0=
hdmi_edid_filename:1=
hdmi_timings:0=
hdmi_timings:1=

cmdline.txt

coherent_pool=1M 8250.nr_uarts=0 cma=64M snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 bcm2708_fb.fbwidth=800 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 smsc95xx.macaddr=DC:A6:32:0F:1C:08 vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 dwc_otg.lpm_enable=0 console=ttyS0,115200 console=tty1 root=PARTUUID=5bc516df-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait

raspi-gpio settings

BANK0 (GPIO 0 to 27):
GPIO 0: level=1 fsel=0 func=INPUT pull=UP
GPIO 1: level=1 fsel=0 func=INPUT pull=UP
GPIO 2: level=1 fsel=4 alt=0 func=SDA1 pull=UP
GPIO 3: level=1 fsel=4 alt=0 func=SCL1 pull=UP
GPIO 4: level=1 fsel=0 func=INPUT pull=UP
GPIO 5: level=1 fsel=0 func=INPUT pull=UP
GPIO 6: level=1 fsel=0 func=INPUT pull=UP
GPIO 7: level=1 fsel=0 func=INPUT pull=UP
GPIO 8: level=1 fsel=0 func=INPUT pull=UP
GPIO 9: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 10: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 11: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 12: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 13: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 14: level=1 fsel=0 func=INPUT pull=NONE
GPIO 15: level=1 fsel=0 func=INPUT pull=UP
GPIO 16: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 17: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 18: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 19: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 20: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 21: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 22: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 23: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 24: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 25: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 26: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 27: level=0 fsel=0 func=INPUT pull=DOWN
BANK1 (GPIO 28 to 45):
GPIO 28: level=1 fsel=2 alt=5 func=RGMII_MDIO pull=UP
GPIO 29: level=0 fsel=2 alt=5 func=RGMII_MDC pull=DOWN
GPIO 30: level=0 fsel=7 alt=3 func=CTS0 pull=UP
GPIO 31: level=0 fsel=7 alt=3 func=RTS0 pull=NONE
GPIO 32: level=1 fsel=7 alt=3 func=TXD0 pull=NONE
GPIO 33: level=1 fsel=7 alt=3 func=RXD0 pull=UP
GPIO 34: level=0 fsel=7 alt=3 func=SD1_CLK pull=NONE
GPIO 35: level=1 fsel=7 alt=3 func=SD1_CMD pull=UP
GPIO 36: level=1 fsel=7 alt=3 func=SD1_DAT0 pull=UP
GPIO 37: level=1 fsel=7 alt=3 func=SD1_DAT1 pull=UP
GPIO 38: level=1 fsel=7 alt=3 func=SD1_DAT2 pull=UP
GPIO 39: level=1 fsel=7 alt=3 func=SD1_DAT3 pull=UP
GPIO 40: level=0 fsel=4 alt=0 func=PWM1_0 pull=NONE
GPIO 41: level=0 fsel=4 alt=0 func=PWM1_1 pull=NONE
GPIO 42: level=0 fsel=1 func=OUTPUT pull=UP
GPIO 43: level=1 fsel=0 func=INPUT pull=UP
GPIO 44: level=1 fsel=5 alt=1 func=SDA0 pull=UP
GPIO 45: level=1 fsel=5 alt=1 func=SCL0 pull=UP
BANK2 (GPIO 46 to 53):
GPIO 46: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 47: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 48: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 49: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 50: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 51: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 52: level=0 fsel=0 func=INPUT pull=DOWN
GPIO 53: level=0 fsel=0 func=INPUT pull=DOWN

vcdbg log messages

003267.054: arasan: arasan_emmc_open
003267.233: arasan: arasan_emmc_set_clock C0: 0x00000000 C1: 0x000e7187 emmc: 250000000 actual: 200000 div: 0x00000271 target: 200000 min: 100000 max: 400000 delay: 10
003372.001: arasan: arasan_emmc_set_clock C0: 0x00000000 C1: 0x000e7187 emmc: 250000000 actual: 200000 div: 0x00000271 target: 200000 min: 100000 max: 400000 delay: 10
003372.162: arasan: arasan_emmc_set_clock C0: 0x00000f00 C1: 0x000ec2c7 emmc: 250000000 actual: 129937 div: 0x000003c2 target: 130000 min: 100000 max: 400000 delay: 15
003412.637: arasan: arasan_emmc_set_clock C0: 0x00000f06 C1: 0x000e0307 emmc: 250000000 actual: 41666666 div: 0x00000003 target: 40000000 min: 0 max: 40000000 delay: 1
003419.694: brfs: File read: /mfs/sd/config.txt
003817.426: brfs: File read: 1776 bytes
003841.620: brfs: File read: /mfs/sd/config.txt
003848.185: brfs: File read: 1776 bytes
004327.420: gpioman: gpioman_get_pin_num: pin DISPLAY_DSI_PORT not defined
004630.692: *** Restart logging
004634.892: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
004638.294: hdmi: HDMI:hdmi_get_state is deprecated, use hdmi_get_display_state instead
004638.329: HDMI0: hdmi_pixel_encoding: 300000000

004638.343: HDMI1: hdmi_pixel_encoding: 300000000

004649.992: brfs: File read: /mfs/sd/bcm2711-rpi-4-b.dtb
004650.035: Loading 'bcm2711-rpi-4-b.dtb' to 0x100 size 0xa139
004711.886: brfs: File read: 41273 bytes
005021.568: brfs: File read: /mfs/sd/overlays/rpi-ft5406.dtbo
005052.200: Loaded overlay 'rpi-ft5406'
005148.745: brfs: File read: 1018 bytes
005157.821: brfs: File read: /mfs/sd/overlays/rpi-backlight.dtbo
005188.111: Loaded overlay 'rpi-backlight'
005263.333: brfs: File read: 489 bytes
005265.631: brfs: File read: /mfs/sd/config.txt
005266.048: dtparam: i2c_arm=on
005306.638: dtparam: audio=on
005353.822: brfs: File read: 1776 bytes
005360.033: brfs: File read: /mfs/sd/overlays/i2c-rtc.dtbo
005391.414: Loaded overlay 'i2c-rtc'
005391.443: dtparam: ds3231=true
005477.732: brfs: File read: 4761 bytes
005479.336: brfs: File read: /mfs/sd/cmdline.txt
005479.402: Read command line from file 'cmdline.txt':
005479.441: 'dwc_otg.lpm_enable=0 console=serial0,115200 console=tty1 root=PARTUUID=5bc516df-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait'
006925.791: brfs: File read: 142 bytes
007415.457: brfs: File read: /mfs/sd/kernel7l.img
007415.493: Loading 'kernel7l.img' to 0x8000 size 0x588460
007415.540: Device tree loaded to 0x2eff5800 (size 0xa748)
007416.275: gpioman: gpioman_get_pin_num: pin SDCARD_CONTROL_POWER not defined
009635.148: vchiq_core: vchiq_init_state: slot_zero = 0xf7580000, is_master = 1

dmesg log

[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Linux version 4.19.118-v7l+ (dom@buildbot) (gcc version 4.9.3 (crosstool-NG crosstool-ng-1.22.0-88-g8460611)) raspberrypi/firmware#1311 SMP Mon Apr 27 14:26:42 BST 2020
[ 0.000000] CPU: ARMv7 Processor [410fd083] revision 3 (ARMv7), cr=30c5383d
[ 0.000000] CPU: div instructions available: patching division code
[ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, PIPT instruction cache
[ 0.000000] OF: fdt: Machine model: Raspberry Pi 4 Model B Rev 1.1
[ 0.000000] Memory policy: Data cache writealloc
[ 0.000000] cma: Reserved 64 MiB at 0x0000000037400000
[ 0.000000] On node 0 totalpages: 1012736
[ 0.000000] DMA zone: 1728 pages used for memmap
[ 0.000000] DMA zone: 0 pages reserved
[ 0.000000] DMA zone: 196608 pages, LIFO batch:63
[ 0.000000] HighMem zone: 816128 pages, LIFO batch:63
[ 0.000000] random: get_random_bytes called from start_kernel+0xc0/0x4e8 with crng_init=0
[ 0.000000] percpu: Embedded 17 pages/cpu s36928 r8192 d24512 u69632
[ 0.000000] pcpu-alloc: s36928 r8192 d24512 u69632 alloc=17*4096
[ 0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 1011008
[ 0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 cma=64M snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 snd_bcm2835.enable_headphones=1 bcm2708_fb.fbwidth=800 bcm2708_fb.fbheight=480 bcm2708_fb.fbswap=1 smsc95xx.macaddr=m.m.m.m vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000 dwc_otg.lpm_enable=0 console=ttyS0,115200 console=tty1 root=PARTUUID=5bc516df-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait
[ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes)
[ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes)
[ 0.000000] Memory: 3932668K/4050944K available (8192K kernel code, 690K rwdata, 2420K rodata, 2048K init, 860K bss, 52740K reserved, 65536K cma-reserved, 3198976K highmem)
[ 0.000000] Virtual kernel memory layout:
vector : 0xffff0000 - 0xffff1000 ( 4 kB)
fixmap : 0xffc00000 - 0xfff00000 (3072 kB)
vmalloc : 0xf0800000 - 0xff800000 ( 240 MB)
lowmem : 0xc0000000 - 0xf0000000 ( 768 MB)
pkmap : 0xbfe00000 - 0xc0000000 ( 2 MB)
modules : 0xbf000000 - 0xbfe00000 ( 14 MB)
.text : 0x(ptrval) - 0x(ptrval) (10208 kB)
.init : 0x(ptrval) - 0x(ptrval) (2048 kB)
.data : 0x(ptrval) - 0x(ptrval) ( 691 kB)
.bss : 0x(ptrval) - 0x(ptrval) ( 861 kB)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[ 0.000000] ftrace: allocating 28928 entries in 85 pages
[ 0.000000] rcu: Hierarchical RCU implementation.
[ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[ 0.000000] GIC: Using split EOI/Deactivate mode
[ 0.000000] arch_timer: cp15 timer(s) running at 54.00MHz (phys).
[ 0.000000] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns
[ 0.000005] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns
[ 0.000021] Switching to timer-based delay loop, resolution 18ns
[ 0.000255] Console: colour dummy device 80x30
[ 0.000730] console [tty1] enabled
[ 0.000786] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000)
[ 0.000823] pid_max: default: 32768 minimum: 301
[ 0.001105] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.001138] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes)
[ 0.001913] CPU: Testing write buffer coherency: ok
[ 0.002335] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[ 0.002986] Setting up static identity map for 0x200000 - 0x20003c
[ 0.003160] rcu: Hierarchical SRCU implementation.
[ 0.004031] smp: Bringing up secondary CPUs ...
[ 0.004852] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[ 0.005778] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[ 0.006652] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[ 0.006771] smp: Brought up 1 node, 4 CPUs
[ 0.006837] SMP: Total of 4 processors activated (432.00 BogoMIPS).
[ 0.006860] CPU: All CPU(s) started in HYP mode.
[ 0.006881] CPU: Virtualization extensions available.
[ 0.007675] devtmpfs: initialized
[ 0.018319] VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0
[ 0.018553] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 0.018595] futex hash table entries: 1024 (order: 4, 65536 bytes)
[ 0.020759] pinctrl core: initialized pinctrl subsystem
[ 0.021580] NET: Registered protocol family 16
[ 0.024716] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[ 0.026251] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[ 0.026283] hw-breakpoint: maximum watchpoint size is 8 bytes.
[ 0.026489] Serial: AMBA PL011 UART driver
[ 0.029740] bcm2835-mbox fe00b880.mailbox: mailbox enabled
[ 0.050026] raspberrypi-firmware soc:firmware: Attached to firmware from 2020-05-11 18:59, variant start
[ 0.060058] raspberrypi-firmware soc:firmware: Firmware hash is 21bfdeee3a6ea823e2113b983390acd1eec8edfb
[ 0.102597] bcm2835-dma fe007000.dma: DMA legacy API manager at (ptrval), dmachans=0x1
[ 0.105606] vgaarb: loaded
[ 0.105978] SCSI subsystem initialized
[ 0.106185] usbcore: registered new interface driver usbfs
[ 0.106258] usbcore: registered new interface driver hub
[ 0.106370] usbcore: registered new device driver usb
[ 0.107730] clocksource: Switched to clocksource arch_sys_counter
[ 0.185802] VFS: Disk quotas dquot_6.6.0
[ 0.185903] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[ 0.186061] FS-Cache: Loaded
[ 0.186259] CacheFiles: Loaded
[ 0.195592] NET: Registered protocol family 2
[ 0.196252] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes)
[ 0.196298] TCP established hash table entries: 8192 (order: 3, 32768 bytes)
[ 0.196379] TCP bind hash table entries: 8192 (order: 4, 65536 bytes)
[ 0.196464] TCP: Hash tables configured (established 8192 bind 8192)
[ 0.196598] UDP hash table entries: 512 (order: 2, 16384 bytes)
[ 0.196643] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes)
[ 0.196868] NET: Registered protocol family 1
[ 0.197422] RPC: Registered named UNIX socket transport module.
[ 0.197449] RPC: Registered udp transport module.
[ 0.197470] RPC: Registered tcp transport module.
[ 0.197491] RPC: Registered tcp NFSv4.1 backchannel transport module.
[ 0.197519] PCI: CLS 0 bytes, default 64
[ 0.199439] hw perfevents: enabled with armv7_cortex_a15 PMU driver, 7 counters available
[ 0.201541] Initialise system trusted keyrings
[ 0.201726] workingset: timestamp_bits=14 max_order=20 bucket_order=6
[ 0.210742] FS-Cache: Netfs 'nfs' registered for caching
[ 0.211259] NFS: Registering the id_resolver key type
[ 0.211303] Key type id_resolver registered
[ 0.211325] Key type id_legacy registered
[ 0.211356] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[ 0.215895] Key type asymmetric registered
[ 0.215921] Asymmetric key parser 'x509' registered
[ 0.216044] bounce: pool size: 64 pages
[ 0.216098] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)
[ 0.216286] io scheduler noop registered
[ 0.216311] io scheduler deadline registered (default)
[ 0.216480] io scheduler cfq registered
[ 0.216504] io scheduler mq-deadline registered (default)
[ 0.216527] io scheduler kyber registered
[ 0.266832] brcm-pcie fd500000.pcie: dmabounce: initialised - 32768 kB, threshold 0x00000000c0000000
[ 0.266878] brcm-pcie fd500000.pcie: could not get clock
[ 0.266953] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:
[ 0.267005] brcm-pcie fd500000.pcie: MEM 0x600000000..0x603ffffff -> 0xf8000000
[ 0.317760] brcm-pcie fd500000.pcie: link up, 5.0 Gbps x1 (!SSC)
[ 0.318047] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00
[ 0.318078] pci_bus 0000:00: root bus resource [bus 00-01]
[ 0.318108] pci_bus 0000:00: root bus resource [mem 0x600000000-0x603ffffff] (bus address [0xf8000000-0xfbffffff])
[ 0.318171] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400
[ 0.318307] pci 0000:00:00.0: PME# supported from D0 D3hot
[ 0.321080] PCI: bus0: Fast back to back transfers disabled
[ 0.321114] pci 0000:00:00.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[ 0.321343] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330
[ 0.321468] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]
[ 0.321785] pci 0000:01:00.0: PME# supported from D0 D3cold
[ 0.324514] PCI: bus1: Fast back to back transfers disabled
[ 0.324544] pci_bus 0000:01: busn_res: [bus 01] end is updated to 01
[ 0.324590] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]
[ 0.324626] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]
[ 0.324714] pci 0000:00:00.0: PCI bridge to [bus 01]
[ 0.324744] pci 0000:00:00.0: bridge window [mem 0x600000000-0x6000fffff]
[ 0.324973] pcieport 0000:00:00.0: enabling device (0140 -> 0142)
[ 0.325164] pcieport 0000:00:00.0: Signaling PME with IRQ 51
[ 0.325335] pcieport 0000:00:00.0: AER enabled with IRQ 51
[ 0.325516] pci 0000:01:00.0: enabling device (0140 -> 0142)
[ 0.326039] bcm2708_fb soc:fb: FB found 1 display(s)
[ 0.337664] Console: switching to colour frame buffer device 100x30
[ 0.340971] bcm2708_fb soc:fb: Registered framebuffer for display 0, size 800x480
[ 0.345555] iproc-rng200 fe104000.rng: hwrng registered
[ 0.346790] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB)
[ 0.348404] vc-sm: Videocore shared memory driver
[ 0.349825] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000
[ 0.361049] brd: module loaded
[ 0.371788] loop: module loaded
[ 0.373589] Loading iSCSI transport class v2.0-870.
[ 0.376332] libphy: Fixed MDIO Bus: probed
[ 0.377824] bcmgenet fd580000.genet: failed to get enet clock
[ 0.378875] bcmgenet fd580000.genet: GENET 5.0 EPHY: 0x0000
[ 0.379897] bcmgenet fd580000.genet: failed to get enet-wol clock
[ 0.380889] bcmgenet fd580000.genet: failed to get enet-eee clock
[ 0.381858] bcmgenet: Skipping UMAC reset
[ 0.383020] unimac-mdio unimac-mdio.-19: DMA mask not set
[ 0.397758] libphy: bcmgenet MII bus: probed
[ 0.438264] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus at 0x(ptrval)
[ 0.440116] usbcore: registered new interface driver r8152
[ 0.441154] usbcore: registered new interface driver lan78xx
[ 0.442144] usbcore: registered new interface driver smsc95xx
[ 0.443372] xhci_hcd 0000:01:00.0: xHCI Host Controller
[ 0.444337] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1
[ 0.447804] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000001000000890
[ 0.450003] genirq: irq_chip Brcm_MSI did not update eff. affinity mask of irq 52
[ 0.451816] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19
[ 0.452839] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 0.453834] usb usb1: Product: xHCI Host Controller
[ 0.454793] usb usb1: Manufacturer: Linux 4.19.118-v7l+ xhci-hcd
[ 0.455743] usb usb1: SerialNumber: 0000:01:00.0
[ 0.457177] hub 1-0:1.0: USB hub found
[ 0.458236] hub 1-0:1.0: 1 port detected
[ 0.459611] xhci_hcd 0000:01:00.0: xHCI Host Controller
[ 0.460544] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2
[ 0.461493] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed
[ 0.462831] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 4.19
[ 0.463821] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 0.464824] usb usb2: Product: xHCI Host Controller
[ 0.465818] usb usb2: Manufacturer: Linux 4.19.118-v7l+ xhci-hcd
[ 0.466814] usb usb2: SerialNumber: 0000:01:00.0
[ 0.468305] hub 2-0:1.0: USB hub found
[ 0.469315] hub 2-0:1.0: 4 ports detected
[ 0.471425] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[ 0.472569] dwc_otg: FIQ enabled
[ 0.472578] dwc_otg: NAK holdoff enabled
[ 0.472586] dwc_otg: FIQ split-transaction FSM enabled
[ 0.472599] Module dwc_common_port init
[ 0.472809] usbcore: registered new interface driver uas
[ 0.473885] usbcore: registered new interface driver usb-storage
[ 0.475038] mousedev: PS/2 mouse device common for all mice
[ 0.477126] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[ 0.479727] sdhci: Secure Digital Host Controller Interface driver
[ 0.480680] sdhci: Copyright(c) Pierre Ossman
[ 0.481983] mmc-bcm2835 fe300000.mmcnr: could not get clk, deferring probe
[ 0.483310] sdhci-pltfm: SDHCI platform and OF driver helper
[ 0.487237] ledtrig-cpu: registered to indicate activity on CPUs
[ 0.488341] hidraw: raw HID events driver (C) Jiri Kosina
[ 0.489416] usbcore: registered new interface driver usbhid
[ 0.490344] usbhid: USB HID core driver
[ 0.492146] vchiq: vchiq_init_state: slot_zero = (ptrval), is_master = 0
[ 0.494895] [vc_sm_connected_init]: start
[ 0.504010] [vc_sm_connected_init]: end - returning 0
[ 0.506070] Initializing XFRM netlink socket
[ 0.507038] NET: Registered protocol family 17
[ 0.508080] Key type dns_resolver registered
[ 0.509391] Registering SWP/SWPB emulation handler
[ 0.510870] registered taskstats version 1
[ 0.511774] Loading compiled-in X.509 certificates
[ 0.519597] uart-pl011 fe201000.serial: cts_event_workaround enabled
[ 0.520600] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 34, base_baud = 0) is a PL011 rev2
[ 0.526658] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
[ 0.528210] brcmstb_thermal fd5d2200.thermal: registered AVS TMON of-sensor driver
[ 0.529871] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0
[ 0.530911] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated
[ 0.558048] sdhci-iproc fe340000.emmc2: Linked as a consumer to regulator.3
[ 0.559150] sdhci-iproc fe340000.emmc2: Linked as a consumer to regulator.4
[ 0.576399] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[ 0.579031] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[ 0.581736] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[ 0.585527] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[ 0.588014] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[ 0.592997] mmc0: SDHCI controller on fe340000.emmc2 [fe340000.emmc2] using ADMA
[ 0.596367] of_cfs_init
[ 0.597298] of_cfs_init: OK
[ 0.598718] Waiting for root device PARTUUID=5bc516df-02...
[ 0.644907] random: fast init done
[ 0.668191] mmc1: new high speed SDIO card at address 0001
[ 0.703627] mmc0: new ultra high speed DDR50 SDHC card at address 0001
[ 0.705667] mmcblk0: mmc0:0001 EB1QT 29.8 GiB
[ 0.707669] mmcblk0: p1 p2
[ 0.726310] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[ 0.727284] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[ 0.729067] devtmpfs: mounted
[ 0.737163] Freeing unused kernel memory: 2048K
[ 0.777984] Run /sbin/init as init process
[ 0.827772] usb 1-1: new high-speed USB device number 2 using xhci_hcd
[ 1.010529] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21
[ 1.011457] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[ 1.012357] usb 1-1: Product: USB2.0 Hub
[ 1.015429] hub 1-1:1.0: USB hub found
[ 1.016555] hub 1-1:1.0: 4 ports detected
[ 1.199773] systemd[1]: System time before build time, advancing clock.
[ 1.294768] NET: Registered protocol family 10
[ 1.296958] Segment Routing with IPv6
[ 1.335126] systemd[1]: systemd 241 running in system mode. (+PAM +AUDIT +SELINUX +IMA +APPARMOR +SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 +IDN -PCRE2 default-hierarchy=hybrid)
[ 1.339343] systemd[1]: Detected architecture arm.
[ 1.347785] usb 1-1.1: new full-speed USB device number 3 using xhci_hcd
[ 1.354179] systemd[1]: Set hostname to .
[ 1.482272] usb 1-1.1: New USB device found, idVendor=067b, idProduct=2303, bcdDevice= 4.00
[ 1.483516] usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[ 1.484651] usb 1-1.1: Product: USB-Serial Controller
[ 1.485931] usb 1-1.1: Manufacturer: Prolific Technology Inc.
[ 1.597792] usb 1-1.2: new full-speed USB device number 4 using xhci_hcd
[ 1.745019] usb 1-1.2: New USB device found, idVendor=2341, idProduct=0042, bcdDevice= 0.01
[ 1.746195] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=220
[ 1.747303] usb 1-1.2: Manufacturer: Arduino (www.arduino.cc)
[ 1.748434] usb 1-1.2: SerialNumber: 95530343534351A00241
[ 1.847774] usb 1-1.3: new full-speed USB device number 5 using xhci_hcd
[ 1.913356] systemd[1]: /lib/systemd/system/xrdp.service:8: PIDFile= references path below legacy directory /var/run/, updating /var/run/xrdp/xrdp.pid → /run/xrdp/xrdp.pid; please update the unit file accordingly.
[ 1.918715] systemd[1]: /lib/systemd/system/xrdp-sesman.service:9: PIDFile= references path below legacy directory /var/run/, updating /var/run/xrdp/xrdp-sesman.pid → /run/xrdp/xrdp-sesman.pid; please update the unit file accordingly.
[ 1.984185] usb 1-1.3: New USB device found, idVendor=1a86, idProduct=7523, bcdDevice= 2.54
[ 1.985499] usb 1-1.3: New USB device strings: Mfr=0, Product=2, SerialNumber=0
[ 1.986718] usb 1-1.3: Product: USB2.0-Serial
[ 2.010997] systemd[1]: /lib/systemd/system/smbd.service:9: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/smbd.pid → /run/samba/smbd.pid; please update the unit file accordingly.
[ 2.053781] systemd[1]: /lib/systemd/system/nmbd.service:9: PIDFile= references path below legacy directory /var/run/, updating /var/run/samba/nmbd.pid → /run/samba/nmbd.pid; please update the unit file accordingly.
[ 2.087781] usb 1-1.4: new low-speed USB device number 6 using xhci_hcd
[ 2.171815] random: systemd: uninitialized urandom read (16 bytes read)
[ 2.182876] random: systemd: uninitialized urandom read (16 bytes read)
[ 2.184585] systemd[1]: Listening on initctl Compatibility Named Pipe.
[ 2.208247] systemd[1]: Condition check resulted in Journal Audit Socket being skipped.
[ 2.209750] random: systemd: uninitialized urandom read (16 bytes read)
[ 2.211198] systemd[1]: Reached target Swap.
[ 2.237775] usb 1-1.4: New USB device found, idVendor=0665, idProduct=5161, bcdDevice= 0.02
[ 2.239314] usb 1-1.4: New USB device strings: Mfr=3, Product=1, SerialNumber=0
[ 2.283150] hid-generic 0003:0665:5161.0001: hiddev96,hidraw0: USB HID v1.11 Device [HID 0665:5161] on usb-0000:01:00.0-1.4/input0
[ 2.322886] i2c /dev entries driver
[ 2.787749] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[ 2.879530] systemd-journald[133]: Received request to flush runtime journal from PID 1
[ 3.493366] rpi-ft5406 rpi_ft5406: Probing device
[ 3.505520] input: FT5406 memory based driver as /devices/virtual/input/input0
[ 3.618360] rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x0000ffff
[ 3.618974] rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00000fff
[ 3.619511] rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x0000ffff
[ 3.620009] rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x0000ffff
[ 3.664672] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[ 3.666698] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
[ 3.666713] [vc_sm_connected_init]: start
[ 3.670003] [vc_sm_connected_init]: installed successfully
[ 3.670519] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
[ 3.689804] media: Linux media interface: v0.10
[ 3.716968] videodev: Linux video capture interface: v2.00
[ 3.724924] bcm2835_audio soc:audio: card created with 8 channels
[ 3.764869] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[ 3.803414] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
[ 3.803865] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
[ 3.876450] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[ 3.915835] bcm2835-codec bcm2835-codec: Device registered as /dev/video10
[ 3.915874] bcm2835-codec bcm2835-codec: Loaded V4L2 decode
[ 3.920671] bcm2835-codec bcm2835-codec: Device registered as /dev/video11
[ 3.920703] bcm2835-codec bcm2835-codec: Loaded V4L2 encode
[ 3.930962] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[ 3.933750] bcm2835-codec bcm2835-codec: Device registered as /dev/video12
[ 3.933783] bcm2835-codec bcm2835-codec: Loaded V4L2 isp
[ 4.020807] brcmfmac: F1 signature read @0x18000000=0x15264345
[ 4.033103] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[ 4.033825] usbcore: registered new interface driver brcmfmac
[ 4.166533] cdc_acm 1-1.2:1.0: ttyACM0: USB ACM device
[ 4.171315] usbcore: registered new interface driver cdc_acm
[ 4.171327] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
[ 4.280495] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[ 4.293371] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Mar 2 2020 23:30:41 version 7.45.202 (r724630 CY) FWID 01-72f6ece2
[ 4.350799] usbcore: registered new interface driver usbserial_generic
[ 4.350858] usbserial: USB Serial support registered for generic
[ 4.353478] usbcore: registered new interface driver ch341
[ 4.353554] usbserial: USB Serial support registered for ch341-uart
[ 4.353647] ch341 1-1.3:1.0: ch341-uart converter detected
[ 4.365512] usb 1-1.3: ch341-uart converter now attached to ttyUSB0
[ 4.391597] usbcore: registered new interface driver pl2303
[ 4.391666] usbserial: USB Serial support registered for pl2303
[ 4.391759] pl2303 1-1.1:1.0: pl2303 converter detected
[ 4.419229] usb 1-1.1: pl2303 converter now attached to ttyUSB1
[ 4.660970] rtc-ds1307 1-0068: registered as rtc0
[ 6.465454] random: crng init done
[ 6.465468] random: 7 urandom warning(s) missed due to ratelimiting
[ 6.489318] uart-pl011 fe201000.serial: no DMA platform data
[ 6.727025] 8021q: 802.1Q VLAN Support v1.8
[ 7.137016] Adding 1048572k swap on /var/swap. Priority:-2 extents:15 across:8134652k SSFS
[ 7.558750] IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
[ 7.558807] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
[ 7.968062] bcmgenet: Skipping UMAC reset
[ 8.068068] bcmgenet fd580000.genet: configuring instance for external RGMII (no delay)
[ 8.068214] IPv6: ADDRCONF(NETDEV_UP): eth0: link is not ready
[ 9.127835] bcmgenet fd580000.genet eth0: Link is Down
[ 13.063949] fuse init (API version 7.27)
[ 13.158722] Bluetooth: Core ver 2.22
[ 13.158776] NET: Registered protocol family 31
[ 13.158780] Bluetooth: HCI device and connection manager initialized
[ 13.158792] Bluetooth: HCI socket layer initialized
[ 13.158799] Bluetooth: L2CAP socket layer initialized
[ 13.158840] Bluetooth: SCO socket layer initialized
[ 13.179487] Bluetooth: HCI UART driver ver 2.3
[ 13.179497] Bluetooth: HCI UART protocol H4 registered
[ 13.179547] Bluetooth: HCI UART protocol Three-wire (H5) registered
[ 13.179671] Bluetooth: HCI UART protocol Broadcom registered
[ 13.287891] bcmgenet fd580000.genet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
[ 13.287915] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[ 13.654361] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[ 13.654368] Bluetooth: BNEP filters: protocol multicast
[ 13.654378] Bluetooth: BNEP socket layer initialized
[ 13.737787] Bluetooth: RFCOMM TTY layer initialized
[ 13.737804] Bluetooth: RFCOMM socket layer initialized
[ 13.737823] Bluetooth: RFCOMM ver 1.11
[ 13.891767] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[ 14.655719] ICMPv6: process `dhcpcd' is using deprecated sysctl (syscall) net.ipv6.neigh.eth0.retrans_time - use net.ipv6.neigh.eth0.retrans_time_ms instead
[ 148.441796] pl2303 ttyUSB1: pl2303_get_line_request - failed: -32
[ 148.445151] pl2303 ttyUSB1: pl2303_get_line_request - failed: -32
[ 149.447209] pl2303 ttyUSB1: pl2303_get_line_request - failed: -32
[ 402.607277] pl2303 ttyUSB1: pl2303_get_line_request - failed: -32
[ 402.610145] pl2303 ttyUSB1: pl2303_get_line_request - failed: -32
[ 427.990225] pl2303 ttyUSB1: error sending break = -32
[ 431.025770] pl2303 ttyUSB1: pl2303_get_line_request - failed: -32
[ 431.029024] pl2303 ttyUSB1: pl2303_get_line_request - failed: -32
[ 432.031091] pl2303 ttyUSB1: pl2303_get_line_request - failed: -32
[ 432.634893] usb 1-1.4: reset low-speed USB device number 6 using xhci_hcd
[ 9921.582270] bcmgenet fd580000.genet eth0: Link is Down
[ 9928.866421] bcmgenet fd580000.genet eth0: Link is Up - 1Gbps/Full - flow control rx/tx

Logs
[ 0.067819] usbcore: registered new interface driver usbfs
[ 0.067885] usbcore: registered new interface driver hub
[ 0.067995] usbcore: registered new device driver usb
[ 0.434065] usbcore: registered new interface driver r8152
[ 0.435101] usbcore: registered new interface driver lan78xx
[ 0.436092] usbcore: registered new interface driver smsc95xx
[ 0.438285] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1
[ 0.445794] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19
[ 0.446822] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 0.447816] usb usb1: Product: xHCI Host Controller
[ 0.448779] usb usb1: Manufacturer: Linux 4.19.75-v7l+ xhci-hcd
[ 0.449731] usb usb1: SerialNumber: 0000:01:00.0
[ 0.451174] hub 1-0:1.0: USB hub found
[ 0.454544] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2
[ 0.455491] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed
[ 0.456830] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 4.19
[ 0.457821] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 0.458832] usb usb2: Product: xHCI Host Controller
[ 0.459829] usb usb2: Manufacturer: Linux 4.19.75-v7l+ xhci-hcd
[ 0.460831] usb usb2: SerialNumber: 0000:01:00.0
[ 0.462336] hub 2-0:1.0: USB hub found
[ 0.492042] dwc_otg fe980000.usb: base=(ptrval)
[ 0.910719] dwc_otg fe980000.usb: DWC OTG Controller
[ 0.911642] dwc_otg fe980000.usb: new USB bus registered, assigned bus number 3
[ 0.912609] dwc_otg fe980000.usb: irq 38, io mem 0x00000000
[ 0.915622] usb usb3: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 4.19
[ 0.916587] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 0.917545] usb usb3: Product: DWC OTG Controller
[ 0.918494] usb usb3: Manufacturer: Linux 4.19.75-v7l+ dwc_otg_hcd
[ 0.919451] usb usb3: SerialNumber: fe980000.usb
[ 0.920899] hub 3-0:1.0: USB hub found
[ 0.923680] usbcore: registered new interface driver uas
[ 0.924708] usbcore: registered new interface driver usb-storage
[ 0.939923] usbcore: registered new interface driver usbhid
[ 0.940870] usbhid: USB HID core driver
[ 0.951704] usb 1-1: new high-speed USB device number 2 using xhci_hcd
[ 1.134392] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.20
[ 1.135327] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[ 1.136271] usb 1-1: Product: USB2.0 Hub
[ 1.138919] hub 1-1:1.0: USB hub found
[ 1.461715] usb 1-1.1: new full-speed USB device number 3 using xhci_hcd
[ 1.596198] usb 1-1.1: New USB device found, idVendor=067b, idProduct=2303, bcdDevice= 4.00
[ 1.597170] usb 1-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[ 1.598166] usb 1-1.1: Product: USB-Serial Controller
[ 1.599155] usb 1-1.1: Manufacturer: Prolific Technology Inc.
[ 1.701727] usb 1-1.2: new full-speed USB device number 4 using xhci_hcd
[ 1.847010] usb 1-1.2: New USB device found, idVendor=2341, idProduct=0042, bcdDevice= 0.01
[ 1.848317] usb 1-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=220
[ 1.849622] usb 1-1.2: Manufacturer: Arduino (www.arduino.cc)
[ 1.850827] usb 1-1.2: SerialNumber: 95530343534351A00241
[ 1.961770] usb 1-1.3: new full-speed USB device number 5 using xhci_hcd
[ 2.108146] usb 1-1.3: New USB device found, idVendor=1a86, idProduct=7523, bcdDevice= 2.54
[ 2.109327] usb 1-1.3: New USB device strings: Mfr=0, Product=2, SerialNumber=0
[ 2.110451] usb 1-1.3: Product: USB2.0-Serial
[ 2.221713] usb 1-1.4: new low-speed USB device number 6 using xhci_hcd
[ 2.381563] usb 1-1.4: New USB device found, idVendor=0665, idProduct=5161, bcdDevice= 0.02
[ 2.382964] usb 1-1.4: New USB device strings: Mfr=3, Product=1, SerialNumber=0
[ 2.395352] hid-generic 0003:0665:5161.0001: hiddev96,hidraw0: USB HID v1.11 Device [HID 0665:5161] on usb-0000:01:00.0-1.4/input0
[ 4.442491] usbcore: registered new interface driver brcmfmac
[ 4.550778] cdc_acm 1-1.2:1.0: ttyACM0: USB ACM device
[ 4.553317] usbcore: registered new interface driver cdc_acm
[ 4.553331] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters
[ 4.909233] usbcore: registered new interface driver usbserial_generic
[ 4.909303] usbserial: USB Serial support registered for generic
[ 4.915765] usbcore: registered new interface driver pl2303
[ 4.915845] usbserial: USB Serial support registered for pl2303
[ 4.927667] usb 1-1.1: pl2303 converter now attached to ttyUSB0
[ 4.952291] usbcore: registered new interface driver ch341
[ 4.952374] usbserial: USB Serial support registered for ch341-uart
[ 4.959604] usb 1-1.3: ch341-uart converter now attached to ttyUSB1
[ 45.850548] pl2303 ttyUSB0: pl2303_get_line_request - failed: -32
[ 45.856932] pl2303 ttyUSB0: pl2303_get_line_request - failed: -32
[ 46.862027] pl2303 ttyUSB0: pl2303_get_line_request - failed: -32
[ 74.406543] pl2303 ttyUSB0: pl2303_get_line_request - failed: -32
[ 75.413615] pl2303 ttyUSB0: pl2303_get_line_request - failed: -32
[ 119.356545] pl2303 ttyUSB0: pl2303_get_line_request - failed: -32
[ 120.361640] pl2303 ttyUSB0: pl2303_get_line_request - failed: -32
[ 180.603126] pl2303 ttyUSB0: pl2303_get_line_request - failed: -32
[ 181.608191] pl2303 ttyUSB0: pl2303_get_line_request - failed: -32

[177154.390351] pl2303 ttyUSB0: pl2303_set_control_lines - failed: -110
[177154.500387] pl2303 ttyUSB0: error sending break = -110
[177155.320685] usb 1-1.3: failed to send control message: -110
[177163.910789] pl2303 1-1.1:1.0: pl2303_vendor_write - failed to write [0008]: -110
[177164.020540] pl2303 1-1.1:1.0: pl2303_vendor_write - failed to write [0009]: -110
[177164.140505] pl2303 ttyUSB0: pl2303_get_line_request - failed: -110
[177164.250805] pl2303 ttyUSB0: pl2303_set_line_request - failed: -110
[177164.360541] pl2303 1-1.1:1.0: pl2303_vendor_write - failed to write [0000]: -110
[177164.470668] pl2303 ttyUSB0: pl2303_set_control_lines - failed: -110
[177164.580884] pl2303 ttyUSB0: pl2303_get_line_request - failed: -110
[177164.690604] pl2303 ttyUSB0: pl2303_set_line_request - failed: -110
[177164.810600] pl2303 1-1.1:1.0: pl2303_vendor_write - failed to write [0000]: -110
[177164.920912] usb 1-1.3: failed to send control message: -110
[177164.922074] pl2303 ttyUSB0: pl2303_set_control_lines - failed: -110
[177165.960854] usb 1-1.3: failed to send control message: -110
[177167.000846] usb 1-1.3: failed to receive control message: -110
[177167.000854] ch341-uart ttyUSB1: failed to read modem status: -110
[177167.130832] pl2303 ttyUSB0: pl2303_set_control_lines - failed: -110
[177167.240834] pl2303 ttyUSB0: error sending break = -110
[179126.115965] pl2303 1-1.1:1.0: pl2303_vendor_write - failed to write [0008]: -110
[179126.225713] pl2303 1-1.1:1.0: pl2303_vendor_write - failed to write [0009]: -110
[179126.335696] pl2303 ttyUSB0: pl2303_get_line_request - failed: -110
[179126.445674] pl2303 ttyUSB0: pl2303_set_line_request - failed: -110
[179126.555698] pl2303 1-1.1:1.0: pl2303_vendor_write - failed to write [0000]: -110
[179126.665679] pl2303 ttyUSB0: pl2303_set_control_lines - failed: -110
[179126.776066] pl2303 ttyUSB0: pl2303_set_control_lines - failed: -110
[179127.116082] usb 1-1.3: failed to send control message: -110
[179128.166013] usb 1-1.3: failed to send control message: -110
[179128.905745] pl2303 ttyUSB0: pl2303_set_control_lines - failed: -110
[179129.015744] pl2303 ttyUSB0: error sending break = -110
[179129.196028] usb 1-1.3: failed to receive control message: -110
[179129.196036] ch341-uart ttyUSB1: failed to read modem status: -110
[179161.676700] cdc_acm 1-1.2:1.0: failed to set dtr/rts
[179169.676559] cdc_acm 1-1.2:1.0: failed to set dtr/rts

Additional context
I did ask on the forum.
https://www.raspberrypi.org/forums/viewtopic.php?f=28&t=262007&p=1597041#p1597041
@popcornmix popcornmix transferred this issue from raspberrypi/firmware Jun 19, 2020
@P33M
Copy link
Contributor

P33M commented Jun 19, 2020

Please capture an xhci trace up until the first error message appears in the kernel log.

https://www.raspberrypi.org/forums/viewtopic.php?t=250990&start=75#p1560630

@JacoFourie
Copy link
Author

JacoFourie commented Jun 19, 2020 •
edited

OK I am now running the trace but as I said it can be hours or days before it will crash. We run this software on many pis and see the same issue so it is not just the one I am developing on. If there is a way to restart the USB hub via a command that would be great. Then I can issue that if I detect that I can no loger connect to the USB devices.

@JacoFourie
Copy link
Author

I will stop / start the Trace every now and then until it fails so the trace file is not that big

@P33M
Copy link
Contributor

P33M commented Jun 19, 2020

The trace is recorded to a ring buffer - oldest entries are evicted, so if you are able to intervene soon after an anomaly occurs, there is a good chance that it will span what happened either side of the event.

@JacoFourie
Copy link
Author

JacoFourie commented Jun 21, 2020 •
edited

OK so I managed to get the crash again.

If I look in the trace file all is normal showing this.

image

Then after the crash I see this.

image

After a lsusb this is what I see

image

Here is a link to the trace file.

http://jdphotography.co.za/files/pi/error_trace.txt

@timg236
Copy link
Contributor

timg236 commented Jun 22, 2020

This should fully reset the XHCI controller but if the attached devices are in a bad state it won't
necessarily resolve the issue i.e. it might be better to reboot on failure

echo 1 >/sys/bus/pci/devices/0000:00:00.0/remove
sleep 2
echo 1 >/sys/bus/pci/rescan

@P33M
Copy link
Contributor

P33M commented Jun 22, 2020

It would be useful to see what state the PCIe link is in when Linux decides that the xhci controller is dead. In the dead state, does sudo lspci -vvv return output for the VLI controller?

@JacoFourie
Copy link
Author

Hi. I have no idea. What commands should I type when it is dead, 'sudo lspci -vvv' ? Then I will share the output. I will have to wait for it to crash again as I rebooted the PI.

@JacoFourie
Copy link
Author

JacoFourie commented Jun 22, 2020 •
edited

This is the output now while all is well.

pi@PI4:~ $ sudo lspci -vvv
00:00.0 PCI bridge: Broadcom Limited Device 2711 (rev 10) (prog-if 00 [Normal decode])
Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr+ Stepping- SERR+ FastB2B- DisINTx-
Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- SERR- <PERR- INTx-
Latency: 0, Cache Line Size: 64 bytes
Interrupt: pin A routed to IRQ 51
Bus: primary=00, secondary=01, subordinate=01, sec-latency=0
I/O behind bridge: 00000000-00000fff
Memory behind bridge: f8000000-f80fffff
Prefetchable memory behind bridge: 00000000fff00000-00000000000fffff
Secondary status: 66MHz- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- <SERR- <PERR-
BridgeCtl: Parity+ SERR- NoISA- VGA- MAbort- >Reset- FastB2B-
PriDiscTmr- SecDiscTmr- DiscTmrStat- DiscTmrSERREn-
Capabilities: [48] Power Management version 3
Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0+,D1-,D2-,D3hot+,D3cold-)
Status: D0 NoSoftRst+ PME-Enable- DSel=0 DScale=1 PME-
Capabilities: [ac] Express (v2) Root Port (Slot-), MSI 00
DevCap: MaxPayload 512 bytes, PhantFunc 0
ExtTag- RBE+
DevCtl: Report errors: Correctable+ Non-Fatal+ Fatal+ Unsupported+
RlxdOrd+ ExtTag- PhantFunc- AuxPwr+ NoSnoop+
MaxPayload 128 bytes, MaxReadReq 512 bytes
DevSta: CorrErr- UncorrErr- FatalErr- UnsuppReq- AuxPwr- TransPend-
LnkCap: Port #0, Speed 5GT/s, Width x1, ASPM L0s L1, Exit Latency L0s <2us, L1 <4us
ClockPM+ Surprise- LLActRep- BwNot+ ASPMOptComp+
LnkCtl: ASPM Disabled; RCB 64 bytes Disabled- CommClk-
ExtSynch- ClockPM- AutWidDis- BWInt- AutBWInt-
LnkSta: Speed 5GT/s, Width x1, TrErr- Train- SlotClk+ DLActive- BWMgmt- ABWMgmt+
RootCtl: ErrCorrectable- ErrNon-Fatal- ErrFatal- PMEIntEna+ CRSVisible+
RootCap: CRSVisible+
RootSta: PME ReqID 0000, PMEStatus- PMEPending-
DevCap2: Completion Timeout: Range ABCD, TimeoutDis+, LTR+, OBFF Via WAKE# ARIFwd-
DevCtl2: Completion Timeout: 50us to 50ms, TimeoutDis-, LTR-, OBFF Disabled ARIFwd-
LnkCtl2: Target Link Speed: 5GT/s, EnterCompliance- SpeedDis-
Transmit Margin: Normal Operating Range, EnterModifiedCompliance- ComplianceSOS-
Compliance De-emphasis: -6dB
LnkSta2: Current De-emphasis Level: -6dB, EqualizationComplete-, EqualizationPhase1-
EqualizationPhase2-, EqualizationPhase3-, LinkEqualizationRequest-
Capabilities: [100 v1] Advanced Error Reporting
UESta: DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
UEMsk: DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
UESvrt: DLP+ SDES+ TLP- FCP+ CmpltTO- CmpltAbrt- UnxCmplt- RxOF+ MalfTLP+ ECRC- UnsupReq- ACSViol-
CESta: RxErr- BadTLP- BadDLLP- Rollover- Timeout- NonFatalErr-
CEMsk: RxErr- BadTLP- BadDLLP- Rollover- Timeout- NonFatalErr+
AERCap: First Error Pointer: 00, GenCap- CGenEn- ChkCap- ChkEn-
Capabilities: [180 v1] Vendor Specific Information: ID=0000 Rev=0 Len=028 <?>
Capabilities: [240 v1] L1 PM Substates
L1SubCap: PCI-PM_L1.2+ PCI-PM_L1.1+ ASPM_L1.2+ ASPM_L1.1+ L1_PM_Substates+
PortCommonModeRestoreTime=8us PortTPowerOnTime=10us
L1SubCtl1: PCI-PM_L1.2- PCI-PM_L1.1- ASPM_L1.2- ASPM_L1.1-
T_CommonMode=1us LTR1.2_Threshold=0ns
L1SubCtl2: T_PwrOn=10us
Kernel driver in use: pcieport

01:00.0 USB controller: VIA Technologies, Inc. VL805 USB 3.0 Host Controller (rev 01) (prog-if 30 [XHCI])
Subsystem: VIA Technologies, Inc. VL805 USB 3.0 Host Controller
Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr+ Stepping- SERR+ FastB2B- DisINTx+
Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- SERR- <PERR- INTx-
Latency: 0, Cache Line Size: 64 bytes
Interrupt: pin A routed to IRQ 52
Region 0: Memory at 600000000 (64-bit, non-prefetchable) [size=4K]
Capabilities: [80] Power Management version 3
Flags: PMEClk- DSI- D1- D2- AuxCurrent=375mA PME(D0+,D1-,D2-,D3hot-,D3cold+)
Status: D0 NoSoftRst- PME-Enable- DSel=0 DScale=0 PME-
Capabilities: [90] MSI: Enable+ Count=1/4 Maskable- 64bit+
Address: 00000000fffffffc Data: 6540
Capabilities: [c4] Express (v2) Endpoint, MSI 00
DevCap: MaxPayload 256 bytes, PhantFunc 0, Latency L0s <64ns, L1 <1us
ExtTag- AttnBtn- AttnInd- PwrInd- RBE+ FLReset- SlotPowerLimit 0.000W
DevCtl: Report errors: Correctable- Non-Fatal- Fatal- Unsupported-
RlxdOrd+ ExtTag- PhantFunc- AuxPwr- NoSnoop+
MaxPayload 128 bytes, MaxReadReq 512 bytes
DevSta: CorrErr- UncorrErr- FatalErr- UnsuppReq- AuxPwr+ TransPend-
LnkCap: Port #0, Speed 5GT/s, Width x1, ASPM L0s L1, Exit Latency L0s <2us, L1 <16us
ClockPM+ Surprise- LLActRep- BwNot- ASPMOptComp-
LnkCtl: ASPM Disabled; RCB 64 bytes Disabled- CommClk+
ExtSynch- ClockPM- AutWidDis- BWInt- AutBWInt-
LnkSta: Speed 5GT/s, Width x1, TrErr- Train- SlotClk+ DLActive- BWMgmt- ABWMgmt-
DevCap2: Completion Timeout: Range B, TimeoutDis+, LTR-, OBFF Not Supported
DevCtl2: Completion Timeout: 50us to 50ms, TimeoutDis-, LTR-, OBFF Disabled
LnkCtl2: Target Link Speed: 5GT/s, EnterCompliance- SpeedDis+
Transmit Margin: Normal Operating Range, EnterModifiedCompliance- ComplianceSOS-
Compliance De-emphasis: -6dB
LnkSta2: Current De-emphasis Level: -3.5dB, EqualizationComplete-, EqualizationPhase1-
EqualizationPhase2-, EqualizationPhase3-, LinkEqualizationRequest-
Capabilities: [100 v1] Advanced Error Reporting
UESta: DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
UEMsk: DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
UESvrt: DLP+ SDES+ TLP- FCP+ CmpltTO- CmpltAbrt- UnxCmplt- RxOF+ MalfTLP+ ECRC- UnsupReq- ACSViol-
CESta: RxErr- BadTLP- BadDLLP- Rollover- Timeout- NonFatalErr-
CEMsk: RxErr- BadTLP- BadDLLP- Rollover- Timeout- NonFatalErr+
AERCap: First Error Pointer: 00, GenCap- CGenEn- ChkCap- ChkEn-
Kernel driver in use: xhci_hcd

@P33M
Copy link
Contributor

P33M commented Jun 22, 2020

When the controller is in the dead state, capture the output of lspci first, before trying to do the rescan sequence.

@JacoFourie
Copy link
Author

OK another crash. This is the output of the command after the crash.

pi@PI4:~/Monitor $ sudo lspci -vvv
00:00.0 PCI bridge: Broadcom Limited Device 2711 (rev 10) (prog-if 00 [Normal decode])
Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr+ Stepping- SERR+ FastB2B- DisINTx-
Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- SERR- <PERR- INTx-
Latency: 0, Cache Line Size: 64 bytes
Interrupt: pin A routed to IRQ 51
Bus: primary=00, secondary=01, subordinate=01, sec-latency=0
I/O behind bridge: 00000000-00000fff
Memory behind bridge: f8000000-f80fffff
Prefetchable memory behind bridge: 00000000fff00000-00000000000fffff
Secondary status: 66MHz- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- <MAbort- <SERR- <PERR-
BridgeCtl: Parity+ SERR- NoISA- VGA- MAbort- >Reset- FastB2B-
PriDiscTmr- SecDiscTmr- DiscTmrStat- DiscTmrSERREn-
Capabilities: [48] Power Management version 3
Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA PME(D0+,D1-,D2-,D3hot+,D3cold-)
Status: D0 NoSoftRst+ PME-Enable- DSel=0 DScale=1 PME-
Capabilities: [ac] Express (v2) Root Port (Slot-), MSI 00
DevCap: MaxPayload 512 bytes, PhantFunc 0
ExtTag- RBE+
DevCtl: Report errors: Correctable+ Non-Fatal+ Fatal+ Unsupported+
RlxdOrd+ ExtTag- PhantFunc- AuxPwr+ NoSnoop+
MaxPayload 128 bytes, MaxReadReq 512 bytes
DevSta: CorrErr- UncorrErr- FatalErr- UnsuppReq- AuxPwr- TransPend-
LnkCap: Port #0, Speed 5GT/s, Width x1, ASPM L0s L1, Exit Latency L0s <2us, L1 <4us
ClockPM+ Surprise- LLActRep- BwNot+ ASPMOptComp+
LnkCtl: ASPM Disabled; RCB 64 bytes Disabled- CommClk-
ExtSynch- ClockPM- AutWidDis- BWInt- AutBWInt-
LnkSta: Speed 5GT/s, Width x1, TrErr- Train- SlotClk+ DLActive- BWMgmt- ABWMgmt+
RootCtl: ErrCorrectable- ErrNon-Fatal- ErrFatal- PMEIntEna+ CRSVisible+
RootCap: CRSVisible+
RootSta: PME ReqID 0000, PMEStatus- PMEPending-
DevCap2: Completion Timeout: Range ABCD, TimeoutDis+, LTR+, OBFF Via WAKE# ARIFwd-
DevCtl2: Completion Timeout: 50us to 50ms, TimeoutDis-, LTR-, OBFF Disabled ARIFwd-
LnkCtl2: Target Link Speed: 5GT/s, EnterCompliance- SpeedDis-
Transmit Margin: Normal Operating Range, EnterModifiedCompliance- ComplianceSOS-
Compliance De-emphasis: -6dB
LnkSta2: Current De-emphasis Level: -6dB, EqualizationComplete-, EqualizationPhase1-
EqualizationPhase2-, EqualizationPhase3-, LinkEqualizationRequest-
Capabilities: [100 v1] Advanced Error Reporting
UESta: DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
UEMsk: DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
UESvrt: DLP+ SDES+ TLP- FCP+ CmpltTO- CmpltAbrt- UnxCmplt- RxOF+ MalfTLP+ ECRC- UnsupReq- ACSViol-
CESta: RxErr- BadTLP- BadDLLP- Rollover- Timeout- NonFatalErr-
CEMsk: RxErr- BadTLP- BadDLLP- Rollover- Timeout- NonFatalErr+
AERCap: First Error Pointer: 00, GenCap- CGenEn- ChkCap- ChkEn-
Capabilities: [180 v1] Vendor Specific Information: ID=0000 Rev=0 Len=028 <?>
Capabilities: [240 v1] L1 PM Substates
L1SubCap: PCI-PM_L1.2+ PCI-PM_L1.1+ ASPM_L1.2+ ASPM_L1.1+ L1_PM_Substates+
PortCommonModeRestoreTime=8us PortTPowerOnTime=10us
L1SubCtl1: PCI-PM_L1.2- PCI-PM_L1.1- ASPM_L1.2- ASPM_L1.1-
T_CommonMode=1us LTR1.2_Threshold=0ns
L1SubCtl2: T_PwrOn=10us
Kernel driver in use: pcieport

01:00.0 USB controller: VIA Technologies, Inc. VL805 USB 3.0 Host Controller (rev 01) (prog-if 30 [XHCI])
Subsystem: VIA Technologies, Inc. VL805 USB 3.0 Host Controller
Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr+ Stepping- SERR+ FastB2B- DisINTx+
Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort- <TAbort- SERR- <PERR- INTx-
Latency: 0, Cache Line Size: 64 bytes
Interrupt: pin A routed to IRQ 52
Region 0: Memory at 600000000 (64-bit, non-prefetchable) [size=4K]
Capabilities: [80] Power Management version 3
Flags: PMEClk- DSI- D1- D2- AuxCurrent=375mA PME(D0+,D1-,D2-,D3hot-,D3cold+)
Status: D0 NoSoftRst- PME-Enable- DSel=0 DScale=0 PME-
Capabilities: [90] MSI: Enable+ Count=1/4 Maskable- 64bit+
Address: 00000000fffffffc Data: 6540
Capabilities: [c4] Express (v2) Endpoint, MSI 00
DevCap: MaxPayload 256 bytes, PhantFunc 0, Latency L0s <64ns, L1 <1us
ExtTag- AttnBtn- AttnInd- PwrInd- RBE+ FLReset- SlotPowerLimit 0.000W
DevCtl: Report errors: Correctable- Non-Fatal- Fatal- Unsupported-
RlxdOrd+ ExtTag- PhantFunc- AuxPwr- NoSnoop+
MaxPayload 128 bytes, MaxReadReq 512 bytes
DevSta: CorrErr+ UncorrErr- FatalErr- UnsuppReq- AuxPwr+ TransPend-
LnkCap: Port #0, Speed 5GT/s, Width x1, ASPM L0s L1, Exit Latency L0s <2us, L1 <16us
ClockPM+ Surprise- LLActRep- BwNot- ASPMOptComp-
LnkCtl: ASPM Disabled; RCB 64 bytes Disabled- CommClk+
ExtSynch- ClockPM- AutWidDis- BWInt- AutBWInt-
LnkSta: Speed 5GT/s, Width x1, TrErr- Train- SlotClk+ DLActive- BWMgmt- ABWMgmt-
DevCap2: Completion Timeout: Range B, TimeoutDis+, LTR-, OBFF Not Supported
DevCtl2: Completion Timeout: 50us to 50ms, TimeoutDis-, LTR-, OBFF Disabled
LnkCtl2: Target Link Speed: 5GT/s, EnterCompliance- SpeedDis+
Transmit Margin: Normal Operating Range, EnterModifiedCompliance- ComplianceSOS-
Compliance De-emphasis: -6dB
LnkSta2: Current De-emphasis Level: -3.5dB, EqualizationComplete-, EqualizationPhase1-
EqualizationPhase2-, EqualizationPhase3-, LinkEqualizationRequest-
Capabilities: [100 v1] Advanced Error Reporting
UESta: DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
UEMsk: DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt- UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
UESvrt: DLP+ SDES+ TLP- FCP+ CmpltTO- CmpltAbrt- UnxCmplt- RxOF+ MalfTLP+ ECRC- UnsupReq- ACSViol-
CESta: RxErr- BadTLP- BadDLLP+ Rollover- Timeout- NonFatalErr-
CEMsk: RxErr- BadTLP- BadDLLP- Rollover- Timeout- NonFatalErr+
AERCap: First Error Pointer: 00, GenCap- CGenEn- ChkCap- ChkEn-
Kernel driver in use: xhci_hcd

I also tried to rus those commands with and without sudo and I get Permission denied.

pi@PI4:/Monitor $ echo 1 >/sys/bus/pci/devices/0000:00:00.0/remove
-bash: /sys/bus/pci/devices/0000:00:00.0/remove: Permission denied
pi@PI4:/Monitor $ sleep 2
pi@PI4:/Monitor $ echo 1 >/sys/bus/pci/rescan
-bash: /sys/bus/pci/rescan: Permission denied
pi@PI4:/Monitor $ sudo echo 1 >/sys/bus/pci/devices/0000:00:00.0/remove
-bash: /sys/bus/pci/devices/0000:00:00.0/remove: Permission denied
pi@PI4:/Monitor $ sleep 2
pi@PI4:/Monitor $ sudo echo 1 >/sys/bus/pci/rescan
-bash: /sys/bus/pci/rescan: Permission denied
pi@PI4:~/Monitor $

@timg236
Copy link
Contributor

timg236 commented Jun 22, 2020

I think you need to do 'sudo su' and run the reset parameters from a root shell

@pelwell
Copy link
Contributor

pelwell commented Jun 22, 2020

Try either:

$ sudo sh -c "echo 1 > /sys/bus/pci/devices/0000:00:00.0/remove"
$ sudo sh -c "echo 1 > /sys/bus/pci/rescan"

or

$ echo 1 | sudo tee /sys/bus/pci/devices/0000:00:00.0/remove
$ echo 1 | sudo tee /sys/bus/pci/rescan

@pelwell
Copy link
Contributor

pelwell commented Jun 22, 2020

Unless you take one of the three approaches above, the echo command runs as root but the output of the command is still written to the /sys pseudo-files by the current shell, which is probably running as pi.

@JacoFourie
Copy link
Author

JacoFourie commented Jun 22, 2020 •
edited

$ sudo sh -c "echo 1 > /sys/bus/pci/devices/0000:00:00.0/remove"
$ sudo sh -c "echo 1 > /sys/bus/pci/rescan"

OK great. That works and I am able to get the USB back and all works again without a reboot. WOW OK that is great, thanks so much. Why does the USB stop working ??

@JacoFourie
Copy link
Author

This time it took 2 days before it crashed. The commands got it back again. Why would id do this? Is it hardware power or software?
Will these commands work on every PI 4,3 and zero? Is it always the same command (can I hardcode it) or do I need to find what to remove first?

@JacoFourie
Copy link
Author

JacoFourie commented Sep 23, 2020 •
edited

Hi. I have the same issue on the Pi 3. What are the same commands to remove and rescan the bus like on the 4 as these commands don't seem to work on the 3? Also, I Will need for the 2 and Zero just in case.

@JacoFourie
Copy link
Author

I see there are /sys/bus/devices folders.

So I tried my luck with. But it does not work.

sudo sh -c "echo 1 > /sys/bus/usb/devices/remove"
sudo sh -c "echo 1 > /sys/bus/usb/rescan"

@JacoFourie
Copy link
Author

I found this script but it wont work as lsusb brings back nothing. I need to reset the full system not just one device and then rescan for new devices.

#!/bin/bash
#type lsusb to find "vendor" and "product" ID in terminal
set -euo pipefail
IFS=$'\n\t'

    #edit the below tow lines of vendor and product values using lsusb result
    dev=$(lsusb -t | grep usbdevicename | grep 'If 1' | cut -d' ' -f13|cut -d"," -f1)
    #VENDOR=05a3
    #PRODUCT=9230
    VENDOR=$(lsusb -s $dev | cut -d' ' -f6 | cut -d: -f1)
    PRODUCT=$(lsusb -s $dev | cut -d' ' -f6 | cut -d: -f2)

    for DIR in $(find /sys/bus/usb/devices/ -maxdepth 1 -type l); do
      if [[ -f $DIR/idVendor && -f $DIR/idProduct &&
            $(cat $DIR/idVendor) == $VENDOR && $(cat $DIR/idProduct) == $PRODUCT ]]; then
        echo 0 > $DIR/authorized
        sleep 0.5
        echo 1 > $DIR/authorized
      fi
    done

@P33M
Copy link
Contributor

P33M commented Sep 23, 2020

Pi 1-3 use a completely different controller architecture. You can "rescan" the USB bus on a Pi 3 by forcing a disconnect/reconnect via

# echo 0 > /sys/devices/platform/soc/3f980000.usb/buspower
# echo 1 > /sys/devices/platform/soc/3f980000.usb/buspower

Note that the node address changes between BCM2835 and BCM2836/7.

@JacoFourie
Copy link
Author

@P33M thank you. What do you mean by "Note that the node address changes between BCM2835 and BCM2836/7."

@JacoFourie
Copy link
Author

Also if I use this command I lose network connection.

@P33M
Copy link
Contributor

P33M commented Sep 28, 2020

The 3f980000.usb directory turns into 20980000.usb on Pi 0/1.
You will temporarily lose the ethernet adapter on Pi 1-3 as it's connected via USB, but wireless and Pi 4 ethernet will be unaffected.

In practice, network protocols that don't send data during the bus reset typically survive - ssh sessions usually remain open.

@amundgr
Copy link

amundgr commented Apr 13, 2021

I am using a RPB4 to boot loop test a USB-unit and has encountered the exact same problem. After about 1 day lsusb yields the following:

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

The two commands seems to fix it for me to:

$ sudo sh -c "echo 1 > /sys/bus/pci/devices/0000:00:00.0/remove"
$ sudo sh -c "echo 1 > /sys/bus/pci/rescan"

Are there any plans to fix this? I am not too familiar with how such things get processed, but it looks like a problem worth fixing?

As mentioned, I am not too experienced with RBP or Linux, but if I can provide any logs or similar to help with the debugging I will happily do so.

@JacoFourie
Copy link
Author

I found that it was bad hardware that made the USB sub system fail. After replacing the hardware (copy of the prolific chip) I have not seen this again.

@maratbn
Copy link

maratbn commented Dec 5, 2021

@JacoFourie

I found that it was bad hardware that made the USB sub system fail. After replacing the hardware (copy of the prolific chip) I have not seen this again.

By replacing the hardware, do you mean you replaced your whole RP4 with another, or did you replace (un-soldered & re-soldered) one of the chips on the motherboard, and if so was that chip the VLI VL805-Q6 USB controller? Or do you mean you stopped using one of the USB peripherals you were using, replacing it with another, and after that the problem stopped?

@JacoFourie
Copy link
Author

@maratbn

Replaced the hardware that connects to the Pi.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
6 participants
@maratbn @timg236 @P33M @pelwell @JacoFourie @amundgr