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.

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

RPi 4B, USB attached HDD fails with the message "xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr" in dmesg #3981

Closed
githubharald opened this issue Dec 2, 2020 · 324 comments

Comments

@githubharald
Copy link

Describe the bug

  1. Problem description:
    I'm having random problems with my external harddisk (HDD) connected to my Raspberry Pi 4B. When accessing the HDD with samba, or by doing a git push, the operation sometimes freezes on my computer or smartphone or smart-tv. When I then have a look at the HDD, I can see the white status LED blinking without stopping. I can ssh the RPi, but when I want to access the HDD (e.g. cd or ls on it), the ssh session also freezes. I also can not reboot using the reboot command. But as soon as I unplug the HDD, everything works fine again. After rebooting things usually work fine for quite some time again. Also keeping the HDD active (writing a file each minute) does not help, but it seems like the problem is not power-supply-related, because there are not more spin-ups needed because the HDD is never in standby mode.

  2. What I tried so far:
    At the beginning I directly attached the HDD to the USB3 port. It worked, but sometimes it made “click” noises, which might be caused by too little power. So I connected it to the USB2 port. Worked fine until after 1 month I got the issues described above, that samba was hanging. This happened multiple times, from different client devices. I then plugged a powered USB2 hub in between, and the problems disappeared for 2 month. I though it was solved, but this week I had the issue 2 times, first time when doing a git push, second time when I wanted to backup files from my computer to the samba share. I also added a cron job that writes a timestamp-file each minute to avoid the HDD to go to standby mode. But also with this it happened again after 5-6 days.

  3. Hardware:

    Hard disk connected to powered USB 2.0 Hub, Hub connected to RPi USB2 port (now switched to USB3 port)
    External hard drive: TOSHIBA MQ01UBD100, 1TB, 3 partitions, all formatted as ext4
    Powered USB 2.0 Hub: Belkin 7 port hub (lsusb shows 3 hubs, nut sure which one it is)
    The part of the lsusb output showing something hub related:
    Bus 001 Device 004: ID 05e3:0608 Genesys Logic, Inc. Hub
    Bus 001 Device 003: ID 05e3:0608 Genesys Logic, Inc. Hub
    Bus 001 Device 002: ID 2109:3431 VIA Labs, Inc. Hub
    RPi: model 4B, 4GB RAM, Linux raspberrypi 5.4.72-v7l+, apt-get update and upgrade done just a few days ago
    Power supply: the “official” one
    Connected to network via LAN port

To reproduce
Details about my setup see above. Basically, it seems to be somehow random, so there is no "do action X to cause issue Y".

Expected behaviour
Run 24/7 without at some point having processes hang which access the HDD.

Actual behaviour
Again, see above. Processes (like samba, git, or just some Python script writing to the HDD) accessing HDD hang.

System

Output of raspinfo: raspinfo.txt

  • Which model of Raspberry Pi? Raspberry Pi 4 Model B Rev 1.2
  • Which OS and version: Raspberry Pi reference 2020-08-20
  • Which firmware version: Oct 22 2020 13:59:27 version 74e754ff8947c58d2773253f77f6f68a303188f8 (clean) (release) (start)
  • Which kernel version: Linux raspberrypi 5.4.72-v7l+ Rpi 4.5.y #1356 SMP Thu Oct 22 13:57:51 BST 2020 armv7l GNU/Linux

Logs
dmesg only showing the OOM errors due to the hanging scripts which should keep the HDD active. Therefore the interesting information in the log seems to be already gone.

Here are some parts of /var/log/messages which might have something to do with the problem:

Nov 30 21:11:57 raspberrypi kernel: [433824.234047] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
Nov 30 21:11:57 raspberrypi kernel: [433824.234060] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
Nov 30 21:11:57 raspberrypi kernel: [433824.334485] usb 1-1.1.4.3: reset high-speed USB device number 5 using xhci_hcd
Nov 30 21:12:04 raspberrypi kernel: [433831.514247] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
Nov 30 21:12:04 raspberrypi kernel: [433831.514261] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
Nov 30 21:12:04 raspberrypi kernel: [433831.614585] usb 1-1.1.4.3: reset high-speed USB device number 5 using xhci_hcd
Nov 30 21:12:04 raspberrypi udisksd[393]: Error performing housekeeping for drive /org/freedesktop/UDisks2/drives/TOSHIBA_MQ01UBD100_1736TJIQT: Error updating SMART data: sk_disk_smart_read_data: Input/output error (udisks-error-quark, 0)
Nov 30 21:12:35 raspberrypi kernel: [433862.154573] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
Nov 30 21:12:35 raspberrypi kernel: [433862.154586] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
Nov 30 21:12:35 raspberrypi kernel: [433862.254858] usb 1-1.1.4.3: reset high-speed USB device number 5 using xhci_hcd
Nov 30 21:15:08 raspberrypi kernel: [434015.096131] python3 D 0 29096 29095 0x00000000
Nov 30 21:15:08 raspberrypi kernel: [434015.096151] Backtrace:
Nov 30 21:15:08 raspberrypi kernel: [434015.096184] [<c0a9ddb8>] (__schedule) from [<c0a9e634>] (schedule+0x5c/0xd0)
Nov 30 21:15:08 raspberrypi kernel: [434015.096205] r10:c1204ff0 r9:00000000 r8:00000002 r7:c0a9f07c r6:cc059ba0 r5:cc058000
Nov 30 21:15:08 raspberrypi kernel: [434015.096218] r4:d63a6ac0 

And some time later, we get OOM errors because of all the processes that should write to the file on the disk but hang:

     Dec 1 18:46:36 raspberrypi kernel: [511504.291042] systemd-journal invoked oom-killer: gfp_mask=0x400dc2(GFP_KERNEL_ACCOUNT|__GFP_HIGHMEM|__GFP_ZERO), order=0, oom_score_adj=0
    Dec 1 18:46:36 raspberrypi kernel: [511504.291052] CPU: 2 PID: 1821 Comm: systemd-journal Tainted: G C 5.4.72-v7l+ #1356
    Dec 1 18:46:36 raspberrypi kernel: [511504.291055] Hardware name: BCM2711
    Dec 1 18:46:36 raspberrypi kernel: [511504.291059] Backtrace:
    Dec 1 18:46:36 raspberrypi kernel: [511504.291072] [<c020e1c8>] (dump_backtrace) from [<c020e544>] (show_stack+0x20/0x24)
    Dec 1 18:46:36 raspberrypi kernel: [511504.291078] r7:ffffffff r6:00000000 r5:60000113 r4:c12a1130
    Dec 1 18:46:36 raspberrypi kernel: [511504.291086] [<c020e524>] (show_stack) from [<c0a84cb0>] (dump_stack+0xd4/0x118)
    Dec 1 18:46:36 raspberrypi kernel: [511504.291094] [<c0a84bdc>] (dump_stack) from [<c039250c>] (dump_header+0x64/0x1f8)
    Dec 1 18:46:36 raspberrypi kernel: [511504.291099] r10:00400dc2 r9:ca54a000 r8:00000000 r7:00000558 r6:c0ddc7ac r5:d2aabd00
    Dec 1 18:46:36 raspberrypi kernel: [511504.291103] r4:ca54bdd8 r3:00000000
    Dec 1 18:46:36 raspberrypi kernel: [511504.291109] [<c03924a8>] (dump_header) from [<c03918a4>] (oom_kill_process+0x17c/0x188)
    Dec 1 18:46:36 raspberrypi kernel: [511504.291113] r7:00000558 r6:c0ddc7ac r5:ca54bdd8 r4:d2aabd00
    Dec 1 18:46:36 raspberrypi kernel: [511504.291119] [<c0391728>] (oom_kill_process) from [<c039230c>] (out_of_memory+0x244/0x344)
    Dec 1 18:46:36 raspberrypi kernel: [511504.291123] r7:c1204ff0 r6:c12083c0 r5:ca54bdd8 r4:d2aabd00
    Dec 1 18:46:36 raspberrypi kernel: [511504.291131] [<c03920c8>] (out_of_memory) from [<c03e1154>] (__alloc_pages_nodemask+0xbfc/0x1230)
    Dec 1 18:46:36 raspberrypi kernel: [511504.291135] r6:c12a3550 r5:00001ca9 r4:00000000
    Dec 1 18:46:36 raspberrypi kernel: [511504.291142] [<c03e0558>] (__alloc_pages_nodemask) from [<c03c4260>] (__do_fault+0xb0/0x170)
    Dec 1 18:46:36 raspberrypi kernel: [511504.291147] r10:00000055 r9:ca54be80 r8:00000000 r7:00000055 r6:00000000 r5:d5a303a8
    Dec 1 18:46:36 raspberrypi kernel: [511504.291150] r4:ca54be80
    Dec 1 18:46:36 raspberrypi kernel: [511504.291156] [<c03c41b0>] (__do_fault) from [<c03c816c>] (handle_mm_fault+0x98c/0xde4)
    Dec 1 18:46:36 raspberrypi kernel: [511504.291161] r7:00000055 r6:d5a303a8 r5:00000040 r4:00000001
    Dec 1 18:46:36 raspberrypi kernel: [511504.291167] [<c03c77e0>] (handle_mm_fault) from [<c0aa46c0>] (do_page_fault+0x148/0x38c) 

blkid still shows all three partitions.

umount /dev/sda1: target is busy (also when using -l), or the command hangs (had both situations).

Is there anything else I can check?

Additional context
Also discussed in RPi Forum.

@BigMuscle85
Copy link

I don't know if it is the same problem but we have old Raspberry Pi 2 that streams from IP camera and stores video to mounted SMB storage. With kernel 4.19, everything runs for weeks without any problem. After update to kernel 5.4, it runs for a while but after several hours the access to the remote storage (even simple "ls /mnt") freezes the Raspberry. Similar backtrace appears in kernel log. I don't have the exact backtrace now, because we downgraded back to kernel 4.19 and everything runs without problem again.

@githubharald
Copy link
Author

githubharald commented Dec 2, 2020

Thanks for the information. I just downgraded to 4.19.118, let's see if this changes something. It might take days until the issue occurs, but I'll keep you updated.

@popcornmix
Copy link
Collaborator

Possibly a duplicate of #3210
does arm_64bit=1 in config.txt make a difference?

@githubharald
Copy link
Author

Possibly a duplicate of #3210
does arm_64bit=1 in config.txt make a difference?

I still have the test running with the downgraded kernel version. If the issue occurs again I will try arm_64bit=1.

@yoyojacky
Copy link

Could it be caused by the automatic hibernation of the hard disk, and the hard disk may enter a low power consumption mode without data collection for a long time? Similar to hard disk hibernation?

@yoyojacky
Copy link

I am running Raspbian OS version 2020-08-19 and kernel version as following :

pi@raspberrypi:~ $ uname -a
Linux raspberrypi 5.4.79-v7l+ #1373 SMP Mon Nov 23 13:27:40 GMT 2020 armv7l GNU/Linux
pi@raspberrypi:~ $ lsb_release -a
No LSB modules are available.
Distributor ID: Raspbian
Description:    Raspbian GNU/Linux 10 (buster)
Release:        10
Codename:       buster

and dmesg info:


pi@raspberrypi:~ $ dmesg
[    0.000000] Booting Linux on physical CPU 0x0
[    0.000000] Linux version 5.4.79-v7l+ (dom@buildbot) (gcc version 8.4.0 (Ubuntu/Linaro 8.4.0-3ubuntu1)) #1373 SMP Mon Nov 23 13:27:40 GMT 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.4
[    0.000000] Memory policy: Data cache writealloc
[    0.000000] Reserved memory: created CMA memory pool at 0x000000001ec00000, size 256 MiB
[    0.000000] OF: reserved mem: initialized node linux,cma, compatible id shared-dma-pool
[    0.000000] On node 0 totalpages: 2061312
[    0.000000]   DMA zone: 2304 pages used for memmap
[    0.000000]   DMA zone: 0 pages reserved
[    0.000000]   DMA zone: 196608 pages, LIFO batch:63
[    0.000000]   HighMem zone: 1864704 pages, LIFO batch:63
[    0.000000] percpu: Embedded 20 pages/cpu s49804 r8192 d23924 u81920
[    0.000000] pcpu-alloc: s49804 r8192 d23924 u81920 alloc=20*4096
[    0.000000] pcpu-alloc: [0] 0 [0] 1 [0] 2 [0] 3
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 2059008
[    0.000000] Kernel command line: coherent_pool=1M 8250.nr_uarts=0 snd_bcm2835.enable_compat_alsa=0 snd_bcm2835.enable_hdmi=1 video=HDMI-A-1:1360x768M@60 video=HDMI-A-2:640x480M@60 smsc95xx.macaddr=DC:A6:32:B0:81:7D vc_mem.mem_base=0x3ec00000 vc_mem.mem_size=0x40000000  console=ttyS0,115200 console=tty1 root=PARTUUID=69850c05-02 rootfstype=ext4 elevator=deadline fsck.repair=yes rootwait quiet splash plymouth.ignore-serial-consoles
[    0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear)
[    0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] software IO TLB: mapped [mem 0x14c00000-0x18c00000] (64MB)
[    0.000000] Memory: 7800748K/8245248K available (10240K kernel code, 739K rwdata, 2816K rodata, 2048K init, 854K bss, 182356K reserved, 262144K cma-reserved, 7458816K highmem)
[    0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] ftrace: allocating 31111 entries in 61 pages
[    0.000000] rcu: Hierarchical RCU implementation.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[    0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[    0.000000] GIC: Using split EOI/Deactivate mode
[    0.000000] random: get_random_bytes called from start_kernel+0x344/0x518 with crng_init=0
[    0.000007] sched_clock: 32 bits at 1000kHz, resolution 1000ns, wraps every 2147483647500ns
[    0.000023] clocksource: timer: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 1911260446275 ns
[    0.000100] bcm2835: system timer (irq = 17)
[    0.000752] arch_timer: cp15 timer(s) running at 54.00MHz (phys).
[    0.000767] clocksource: arch_sys_counter: mask: 0xffffffffffffff max_cycles: 0xc743ce346, max_idle_ns: 440795203123 ns
[    0.000782] sched_clock: 56 bits at 54MHz, resolution 18ns, wraps every 4398046511102ns
[    0.000794] Switching to timer-based delay loop, resolution 18ns
[    0.001037] Console: colour dummy device 80x30
[    0.001071] printk: console [tty1] enabled
[    0.001122] Calibrating delay loop (skipped), value calculated using timer frequency.. 108.00 BogoMIPS (lpj=540000)
[    0.001144] pid_max: default: 32768 minimum: 301
[    0.001292] LSM: Security Framework initializing
[    0.001484] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.001508] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.002876] Disabling memory control group subsystem
[    0.002998] CPU: Testing write buffer coherency: ok
[    0.003516] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[    0.004437] Setting up static identity map for 0x200000 - 0x20003c
[    0.004644] rcu: Hierarchical SRCU implementation.
[    0.005334] smp: Bringing up secondary CPUs ...
[    0.006556] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[    0.007908] CPU2: thread -1, cpu 2, socket 0, mpidr 80000002
[    0.009187] CPU3: thread -1, cpu 3, socket 0, mpidr 80000003
[    0.009344] smp: Brought up 1 node, 4 CPUs
[    0.009361] SMP: Total of 4 processors activated (432.00 BogoMIPS).
[    0.009374] CPU: All CPU(s) started in HYP mode.
[    0.009387] CPU: Virtualization extensions available.
[    0.010213] devtmpfs: initialized
[    0.024399] VFP support v0.3: implementor 41 architecture 3 part 40 variant 8 rev 0
[    0.024652] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[    0.024681] futex hash table entries: 1024 (order: 4, 65536 bytes, linear)
[    0.031589] pinctrl core: initialized pinctrl subsystem
[    0.032594] NET: Registered protocol family 16
[    0.036595] DMA: preallocated 1024 KiB pool for atomic coherent allocations
[    0.037172] audit: initializing netlink subsys (disabled)
[    0.037426] audit: type=2000 audit(0.030:1): state=initialized audit_enabled=0 res=1
[    0.038620] hw-breakpoint: found 5 (+1 reserved) breakpoint and 4 watchpoint registers.
[    0.038634] hw-breakpoint: maximum watchpoint size is 8 bytes.
[    0.038975] Serial: AMBA PL011 UART driver
[    0.042869] bcm2835-mbox fe00b880.mailbox: mailbox enabled
[    0.060826] raspberrypi-firmware soc:firmware: Attached to firmware from 2020-11-30 22:12, variant start
[    0.070840] raspberrypi-firmware soc:firmware: Firmware hash is ab1181cc0cb6df52bfae3b1d3fef0ce7c325166c
[    0.126347] bcm2835-dma fe007000.dma: DMA legacy API manager, dmachans=0x1
[    0.131449] vgaarb: loaded
[    0.131934] SCSI subsystem initialized
[    0.132173] usbcore: registered new interface driver usbfs
[    0.132230] usbcore: registered new interface driver hub
[    0.132355] usbcore: registered new device driver usb
[    0.132689] usb_phy_generic phy: phy supply vcc not found, using dummy regulator
[    0.134606] clocksource: Switched to clocksource arch_sys_counter
[    0.895676] VFS: Disk quotas dquot_6.6.0
[    0.895777] VFS: Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    0.895942] FS-Cache: Loaded
[    0.896157] CacheFiles: Loaded
[    0.897093] simple-framebuffer 3e7fc000.framebuffer: framebuffer at 0x3e7fc000, 0x3fc000 bytes, mapped to 0x(ptrval)
[    0.897112] simple-framebuffer 3e7fc000.framebuffer: format=a8r8g8b8, mode=1360x768x32, linelength=5440
[    0.897562] Console: switching to colour frame buffer device 170x48
[    0.902718] simple-framebuffer 3e7fc000.framebuffer: fb0: simplefb registered!
[    0.912815] thermal_sys: Registered thermal governor 'step_wise'
[    0.913271] NET: Registered protocol family 2
[    0.914029] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
[    0.914061] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear)
[    0.914119] TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear)
[    0.914187] TCP: Hash tables configured (established 8192 bind 8192)
[    0.914337] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
[    0.914370] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
[    0.914825] NET: Registered protocol family 1
[    0.915566] RPC: Registered named UNIX socket transport module.
[    0.915580] RPC: Registered udp transport module.
[    0.915592] RPC: Registered tcp transport module.
[    0.915605] RPC: Registered tcp NFSv4.1 backchannel transport module.
[    0.915626] PCI: CLS 0 bytes, default 64
[    0.917617] hw perfevents: enabled with armv7_cortex_a15 PMU driver, 7 counters available
[    0.919882] Initialise system trusted keyrings
[    0.920161] workingset: timestamp_bits=14 max_order=21 bucket_order=7
[    0.931104] FS-Cache: Netfs 'nfs' registered for caching
[    0.931872] NFS: Registering the id_resolver key type
[    0.931908] Key type id_resolver registered
[    0.931921] Key type id_legacy registered
[    0.931945] nfs4filelayout_init: NFSv4 File Layout Driver Registering...
[    0.933098] Key type asymmetric registered
[    0.933112] Asymmetric key parser 'x509' registered
[    0.933300] bounce: pool size: 64 pages
[    0.933344] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 249)
[    0.933582] io scheduler mq-deadline registered
[    0.933596] io scheduler kyber registered
[    0.937788] brcm-pcie fd500000.pcie: host bridge /scb/pcie@7d500000 ranges:
[    0.937812] brcm-pcie fd500000.pcie:   No bus range found for /scb/pcie@7d500000, using [bus 00-ff]
[    0.937886] brcm-pcie fd500000.pcie:      MEM 0x0600000000..0x0603ffffff -> 0x00f8000000
[    0.937956] brcm-pcie fd500000.pcie:   IB MEM 0x0000000000..0x00bfffffff -> 0x0000000000
[    0.996753] brcm-pcie fd500000.pcie: link up, 5 GT/s x1 (SSC)
[    0.997065] brcm-pcie fd500000.pcie: PCI host bridge to bus 0000:00
[    0.997084] pci_bus 0000:00: root bus resource [bus 00-ff]
[    0.997104] pci_bus 0000:00: root bus resource [mem 0x600000000-0x603ffffff] (bus address [0xf8000000-0xfbffffff])
[    0.997164] pci 0000:00:00.0: [14e4:2711] type 01 class 0x060400
[    0.997439] pci 0000:00:00.0: PME# supported from D0 D3hot
[    1.000809] PCI: bus0: Fast back to back transfers disabled
[    1.001051] pci 0000:01:00.0: [1106:3483] type 00 class 0x0c0330
[    1.001198] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x00000fff 64bit]
[    1.001631] pci 0000:01:00.0: PME# supported from D0 D3hot
[    1.005020] PCI: bus1: Fast back to back transfers disabled
[    1.005082] pci 0000:00:00.0: BAR 8: assigned [mem 0x600000000-0x6000fffff]
[    1.005105] pci 0000:01:00.0: BAR 0: assigned [mem 0x600000000-0x600000fff 64bit]
[    1.005188] pci 0000:00:00.0: PCI bridge to [bus 01]
[    1.005213] pci 0000:00:00.0:   bridge window [mem 0x600000000-0x6000fffff]
[    1.005532] pcieport 0000:00:00.0: enabling device (0140 -> 0142)
[    1.005792] pcieport 0000:00:00.0: PME: Signaling with IRQ 55
[    1.006191] pcieport 0000:00:00.0: AER: enabled with IRQ 55
[    1.006553] pci 0000:01:00.0: enabling device (0140 -> 0142)
[    1.055362] pci 0000:01:00.0: quirk_usb_early_handoff+0x0/0x800 took 47683 usecs
[    1.062459] iproc-rng200 fe104000.rng: hwrng registered
[    1.062801] vc-mem: phys_addr:0x00000000 mem_base=0x3ec00000 mem_size:0x40000000(1024 MiB)
[    1.063496] vc-sm: Videocore shared memory driver
[    1.064080] gpiomem-bcm2835 fe200000.gpiomem: Initialised: Registers at 0xfe200000
[    1.076521] brd: module loaded
[    1.089180] loop: module loaded
[    1.090620] Loading iSCSI transport class v2.0-870.
[    1.092701] libphy: Fixed MDIO Bus: probed
[    1.093330] bcmgenet fd580000.ethernet: failed to get enet clock
[    1.093349] bcmgenet fd580000.ethernet: GENET 5.0 EPHY: 0x0000
[    1.093373] bcmgenet fd580000.ethernet: failed to get enet-wol clock
[    1.093395] bcmgenet fd580000.ethernet: failed to get enet-eee clock
[    1.093423] bcmgenet: Skipping UMAC reset
[    1.104692] libphy: bcmgenet MII bus: probed
[    1.184716] unimac-mdio unimac-mdio.-19: Broadcom UniMAC MDIO bus
[    1.185817] usbcore: registered new interface driver r8152
[    1.185882] usbcore: registered new interface driver lan78xx
[    1.185953] usbcore: registered new interface driver smsc95xx
[    1.186449] xhci_hcd 0000:01:00.0: xHCI Host Controller
[    1.186484] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1
[    1.188714] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000003000000890
[    1.190025] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.04
[    1.190043] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.190059] usb usb1: Product: xHCI Host Controller
[    1.190074] usb usb1: Manufacturer: Linux 5.4.79-v7l+ xhci-hcd
[    1.190089] usb usb1: SerialNumber: 0000:01:00.0
[    1.190725] hub 1-0:1.0: USB hub found
[    1.190823] hub 1-0:1.0: 1 port detected
[    1.191386] xhci_hcd 0000:01:00.0: xHCI Host Controller
[    1.191423] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2
[    1.191448] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed
[    1.191906] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.04
[    1.191923] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    1.191938] usb usb2: Product: xHCI Host Controller
[    1.191953] usb usb2: Manufacturer: Linux 5.4.79-v7l+ xhci-hcd
[    1.191968] usb usb2: SerialNumber: 0000:01:00.0
[    1.192562] hub 2-0:1.0: USB hub found
[    1.192632] hub 2-0:1.0: 4 ports detected
[    1.194124] dwc_otg: version 3.00a 10-AUG-2012 (platform bus)
[    1.194434] dwc_otg: FIQ enabled
[    1.194447] dwc_otg: NAK holdoff enabled
[    1.194459] dwc_otg: FIQ split-transaction FSM enabled
[    1.194475] Module dwc_common_port init
[    1.194981] usbcore: registered new interface driver uas
[    1.195085] usbcore: registered new interface driver usb-storage
[    1.195305] mousedev: PS/2 mouse device common for all mice
[    1.197248] bcm2835-wdt bcm2835-wdt: Broadcom BCM2835 watchdog timer
[    1.200757] sdhci: Secure Digital Host Controller Interface driver
[    1.200770] sdhci: Copyright(c) Pierre Ossman
[    1.201428] mmc-bcm2835 fe300000.mmcnr: could not get clk, deferring probe
[    1.202035] sdhci-pltfm: SDHCI platform and OF driver helper
[    1.205978] ledtrig-cpu: registered to indicate activity on CPUs
[    1.206293] hidraw: raw HID events driver (C) Jiri Kosina
[    1.206477] usbcore: registered new interface driver usbhid
[    1.206489] usbhid: USB HID core driver
[    1.207559] vchiq: vchiq_init_state: slot_zero = (ptrval)
[    1.209559] [vc_sm_connected_init]: start
[    1.219183] [vc_sm_connected_init]: end - returning 0
[    1.221457] Initializing XFRM netlink socket
[    1.221495] NET: Registered protocol family 17
[    1.221647] Key type dns_resolver registered
[    1.222106] Registering SWP/SWPB emulation handler
[    1.222437] registered taskstats version 1
[    1.222457] Loading compiled-in X.509 certificates
[    1.223007] Key type ._fscrypt registered
[    1.223020] Key type .fscrypt registered
[    1.233918] uart-pl011 fe201000.serial: cts_event_workaround enabled
[    1.233994] fe201000.serial: ttyAMA0 at MMIO 0xfe201000 (irq = 29, base_baud = 0) is a PL011 rev2
[    1.240309] bcm2835-power bcm2835-power: Broadcom BCM2835 power domains driver
[    1.241290] mmc-bcm2835 fe300000.mmcnr: mmc_debug:0 mmc_debug2:0
[    1.241306] mmc-bcm2835 fe300000.mmcnr: DMA channel allocated
[    1.288161] mmc1: queuing unknown CIS tuple 0x80 (2 bytes)
[    1.289835] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    1.291500] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    1.294491] mmc1: queuing unknown CIS tuple 0x80 (7 bytes)
[    1.296175] mmc1: queuing unknown CIS tuple 0x80 (3 bytes)
[    1.304222] mmc0: SDHCI controller on fe340000.emmc2 [fe340000.emmc2] using ADMA
[    1.307202] of_cfs_init
[    1.307320] of_cfs_init: OK
[    1.308380] Waiting for root device PARTUUID=69850c05-02...
[    1.346273] random: fast init done
[    1.371059] mmc1: new high speed SDIO card at address 0001
[    1.424792] mmc0: new ultra high speed DDR50 SDHC card at address 0001
[    1.425729] mmcblk0: mmc0:0001 SD32G 29.2 GiB
[    1.428386]  mmcblk0: p1 p2
[    1.464905] EXT4-fs (mmcblk0p2): mounted filesystem with ordered data mode. Opts: (null)
[    1.464968] VFS: Mounted root (ext4 filesystem) readonly on device 179:2.
[    1.470623] devtmpfs: mounted
[    1.479406] Freeing unused kernel memory: 2048K
[    1.485484] Run /sbin/init as init process
[    1.565021] usb 2-1: new SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[    1.596408] usb 2-1: New USB device found, idVendor=152d, idProduct=0562, bcdDevice= 1.09
[    1.596427] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[    1.596444] usb 2-1: Product: RPi_SSD
[    1.596460] usb 2-1: Manufacturer: 52Pi
[    1.596475] usb 2-1: SerialNumber: DD5641988389F
[    1.620366] scsi host0: uas
[    1.621864] scsi 0:0:0:0: Direct-Access     52Pi     Tech             0109 PQ: 0 ANSI: 6
[    1.744671] usb 1-1: new high-speed USB device number 2 using xhci_hcd
[    1.926470] usb 1-1: New USB device found, idVendor=2109, idProduct=3431, bcdDevice= 4.21
[    1.926488] usb 1-1: New USB device strings: Mfr=0, Product=1, SerialNumber=0
[    1.926504] usb 1-1: Product: USB2.0 Hub
[    1.928250] hub 1-1:1.0: USB hub found
[    1.928487] hub 1-1:1.0: 4 ports detected
[    1.947225] systemd[1]: System time before build time, advancing clock.
[    2.050683] NET: Registered protocol family 10
[    2.052024] Segment Routing with IPv6
[    2.091957] 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)
[    2.092962] systemd[1]: Detected architecture arm.
[    2.160607] systemd[1]: Set hostname to <raspberrypi>.
[    2.331212] sd 0:0:0:0: [sda] 234441648 512-byte logical blocks: (120 GB/112 GiB)
[    2.331231] sd 0:0:0:0: [sda] 4096-byte physical blocks
[    2.331465] sd 0:0:0:0: [sda] Write Protect is off
[    2.331488] sd 0:0:0:0: [sda] Mode Sense: 53 00 00 08
[    2.331905] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[    2.332693] sd 0:0:0:0: [sda] Optimal transfer size 33553920 bytes not a multiple of physical block size (4096 bytes)
[    2.397863]  sda: sda1
[    2.401418] sd 0:0:0:0: [sda] Attached SCSI disk
[    2.922995] random: systemd: uninitialized urandom read (16 bytes read)
[    2.934393] random: systemd: uninitialized urandom read (16 bytes read)
[    2.935301] systemd[1]: Listening on fsck to fsckd communication Socket.
[    2.935752] random: systemd: uninitialized urandom read (16 bytes read)
[    2.936099] systemd[1]: Started Forward Password Requests to Wall Directory Watch.
[    2.939304] systemd[1]: Created slice system-systemd\x2dfsck.slice.
[    2.940054] systemd[1]: Listening on Syslog Socket.
[    2.941294] systemd[1]: Created slice system-getty.slice.
[    2.942432] systemd[1]: Created slice User and Session Slice.
[    2.943266] systemd[1]: Listening on Journal Socket.
[    3.058462] i2c /dev entries driver
[    3.608107] EXT4-fs (mmcblk0p2): re-mounted. Opts: (null)
[    3.728455] systemd-journald[128]: Received request to flush runtime journal from PID 1
[    4.269125] gpio-fan gpio-fan@0: GPIO fan initialized
[    4.314502] rpivid-mem feb00000.hevc-decoder: rpivid-hevcmem initialised: Registers at 0xfeb00000 length 0x00010000
[    4.317185] rpivid-mem feb10000.rpivid-local-intc: rpivid-intcmem initialised: Registers at 0xfeb10000 length 0x00001000
[    4.317717] rpivid-mem feb20000.h264-decoder: rpivid-h264mem initialised: Registers at 0xfeb20000 length 0x00010000
[    4.318184] rpivid-mem feb30000.vp9-decoder: rpivid-vp9mem initialised: Registers at 0xfeb30000 length 0x00010000
[    4.393027] vc_sm_cma: module is from the staging directory, the quality is unknown, you have been warned.
[    4.396014] bcm2835_vc_sm_cma_probe: Videocore shared memory driver
[    4.396041] [vc_sm_connected_init]: start
[    4.400777] [vc_sm_connected_init]: installed successfully
[    4.427014] mc: Linux media interface: v0.10
[    4.448185] snd_bcm2835: module is from the staging directory, the quality is unknown, you have been warned.
[    4.453670] videodev: Linux video capture interface: v2.00
[    4.518970] bcm2835_audio bcm2835_audio: card created with 4 channels
[    4.525649] bcm2835_audio bcm2835_audio: card created with 2 channels
[    4.534492] bcm2835_audio bcm2835_audio: card created with 2 channels
[    4.536414] bcm2835_mmal_vchiq: module is from the staging directory, the quality is unknown, you have been warned.
[    4.552049] bcm2835_isp: module is from the staging directory, the quality is unknown, you have been warned.
[    4.555458] bcm2835_v4l2: module is from the staging directory, the quality is unknown, you have been warned.
[    4.576458] bcm2835-isp bcm2835-isp: Device node output[0] registered as /dev/video13
[    4.577038] bcm2835-isp bcm2835-isp: Device node capture[0] registered as /dev/video14
[    4.577481] bcm2835-isp bcm2835-isp: Device node capture[1] registered as /dev/video15
[    4.577845] bcm2835-isp bcm2835-isp: Device node stats[2] registered as /dev/video16
[    4.577880] bcm2835-isp bcm2835-isp: Register output node 0 with media controller
[    4.577902] bcm2835-isp bcm2835-isp: Register capture node 1 with media controller
[    4.577923] bcm2835-isp bcm2835-isp: Register capture node 2 with media controller
[    4.577943] bcm2835-isp bcm2835-isp: Register capture node 3 with media controller
[    4.578662] bcm2835-isp bcm2835-isp: Loaded V4L2 bcm2835-isp
[    4.732717] bcm2835_codec: module is from the staging directory, the quality is unknown, you have been warned.
[    4.766543] bcm2835-codec bcm2835-codec: Device registered as /dev/video10
[    4.766588] bcm2835-codec bcm2835-codec: Loaded V4L2 decode
[    4.884884] bcm2835-codec bcm2835-codec: Device registered as /dev/video11
[    4.884995] bcm2835-codec bcm2835-codec: Loaded V4L2 encode
[    4.929069] bcm2835-codec bcm2835-codec: Device registered as /dev/video12
[    4.929114] bcm2835-codec bcm2835-codec: Loaded V4L2 isp
[    5.078674] cfg80211: Loading compiled-in X.509 certificates for regulatory database
[    5.084304] [drm] Initialized v3d 1.0.0 20180419 for fec00000.v3d on minor 0
[    5.097330] vc4-drm gpu: bound fe600000.firmwarekms (ops vc4_fkms_ops [vc4])
[    5.097352] checking generic (3e7fc000 3fc000) vs hw (0 ffffffffffffffff)
[    5.097367] fb0: switching to vc4drmfb from simple
[    5.098056] Console: switching to colour dummy device 80x30
[    5.098304] [drm] Supports vblank timestamp caching Rev 2 (21.10.2013).
[    5.098318] [drm] No driver support for vblank timestamp query.
[    5.098331] [drm] Setting vblank_disable_immediate to false because get_vblank_timestamp == NULL
[    5.099649] [drm] Initialized vc4 0.0.0 20140616 for gpu on minor 1
[    5.209016] cfg80211: Loaded X.509 cert 'sforshee: 00b28ddf47aef9cea7'
[    5.264736] sd 0:0:0:0: Attached scsi generic sg0 type 0
[    5.283677] brcmfmac: F1 signature read @0x18000000=0x15264345
[    5.295768] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[    5.296609] usbcore: registered new interface driver brcmfmac
[    5.300496] vc4-drm gpu: HDMI-A-2: EDID is invalid:
[    5.300517]  [00] BAD  ff 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f
[    5.300531]  [00] BAD  7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f
[    5.300544]  [00] BAD  ff 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f
[    5.300557]  [00] BAD  7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f
[    5.300570]  [00] BAD  ff 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f
[    5.300583]  [00] BAD  7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f
[    5.300596]  [00] BAD  ff 7f 7f 7f 7f 7f 7f 7f 3f 7f 7f 7f 7f 7f 7f 7f
[    5.300609]  [00] BAD  7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f 7f
[    5.308934] Console: switching to colour frame buffer device 80x30
[    5.308980] vc4-drm gpu: fb0: vc4drmfb frame buffer device
[    5.318360] brcmfmac mmc1:0001:1: Direct firmware load for brcm/brcmfmac43455-sdio.raspberrypi,4-model-b.txt failed with error -2
[    5.553988] brcmfmac: brcmf_fw_alloc_request: using brcm/brcmfmac43455-sdio for chip BCM4345/6
[    5.567139] brcmfmac: brcmf_c_preinit_dcmds: Firmware: BCM4345/6 wl0: Mar 23 2020 02:19:54 version 7.45.206 (r725000 CY) FWID 01-88ee44ea
[    7.726237] uart-pl011 fe201000.serial: no DMA platform data
[    7.875555] random: crng init done
[    7.875573] random: 7 urandom warning(s) missed due to ratelimiting
[    8.104662] 8021q: 802.1Q VLAN Support v1.8
[    8.375278] Adding 102396k swap on /var/swap.  Priority:-2 extents:1 across:102396k SSFS
[    8.589297] brcmfmac: brcmf_cfg80211_set_power_mgmt: power save enabled
[    8.902218] bcmgenet: Skipping UMAC reset
[    8.905224] bcmgenet fd580000.ethernet: configuring instance for external RGMII
[    8.905462] bcmgenet fd580000.ethernet eth0: Link is Down
[   10.581538] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[   11.522660] broken atomic modeset userspace detected, disabling atomic
[   14.626320] Bluetooth: Core ver 2.22
[   14.626362] NET: Registered protocol family 31
[   14.626367] Bluetooth: HCI device and connection manager initialized
[   14.626381] Bluetooth: HCI socket layer initialized
[   14.626390] Bluetooth: L2CAP socket layer initialized
[   14.626407] Bluetooth: SCO socket layer initialized
[   14.638171] Bluetooth: HCI UART driver ver 2.3
[   14.638181] Bluetooth: HCI UART protocol H4 registered
[   14.638218] Bluetooth: HCI UART protocol Three-wire (H5) registered
[   14.638369] Bluetooth: HCI UART protocol Broadcom registered
[   14.867059] Bluetooth: BNEP (Ethernet Emulation) ver 1.3
[   14.867067] Bluetooth: BNEP filters: protocol multicast
[   14.867082] Bluetooth: BNEP socket layer initialized
[   14.918668] Bluetooth: RFCOMM TTY layer initialized
[   14.918684] Bluetooth: RFCOMM socket layer initialized
[   14.918702] Bluetooth: RFCOMM ver 1.11
[   14.964359] fuse: init (API version 7.31)
[   17.987277] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
[   21.993401] warning: process `colord-sane' used the deprecated sysctl system call with 8.1.2.
[  100.171548] v3d fec00000.v3d: MMU error from client L2T (0) at 0x57a1000, pte invalid
[ 9459.303619] usb 1-1.3: new high-speed USB device number 3 using xhci_hcd
[ 9459.437310] usb 1-1.3: New USB device found, idVendor=05e3, idProduct=0751, bcdDevice=14.04
[ 9459.437321] usb 1-1.3: New USB device strings: Mfr=3, Product=4, SerialNumber=0
[ 9459.437328] usb 1-1.3: Product: USB Storage
[ 9459.437335] usb 1-1.3: Manufacturer: USB Storage
[ 9459.447327] usb-storage 1-1.3:1.0: USB Mass Storage device detected
[ 9459.472092] scsi host1: usb-storage 1-1.3:1.0
[ 9460.524860] scsi 1:0:0:0: Direct-Access     Generic  STORAGE DEVICE   1404 PQ: 0 ANSI: 6
[ 9460.529300] sd 1:0:0:0: Attached scsi generic sg1 type 0
[ 9460.631778] sd 1:0:0:0: [sdb] 61157376 512-byte logical blocks: (31.3 GB/29.2 GiB)
[ 9460.632901] sd 1:0:0:0: [sdb] Write Protect is off
[ 9460.632909] sd 1:0:0:0: [sdb] Mode Sense: 21 00 00 00
[ 9460.634032] sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[ 9460.699636]  sdb: sdb1 sdb2
[ 9460.706365] sd 1:0:0:0: [sdb] Attached SCSI removable disk
[ 9461.326447] EXT4-fs (sdb2): mounted filesystem with ordered data mode. Opts: (null)
[ 9542.929537] usb 1-1.3: USB disconnect, device number 3
[ 9554.752675] usb 1-1.3: new high-speed USB device number 4 using xhci_hcd
[ 9554.886278] usb 1-1.3: New USB device found, idVendor=05e3, idProduct=0751, bcdDevice=14.04
[ 9554.886298] usb 1-1.3: New USB device strings: Mfr=3, Product=4, SerialNumber=0
[ 9554.886315] usb 1-1.3: Product: USB Storage
[ 9554.886332] usb 1-1.3: Manufacturer: USB Storage
[ 9554.891686] usb-storage 1-1.3:1.0: USB Mass Storage device detected
[ 9554.898625] scsi host1: usb-storage 1-1.3:1.0
[ 9555.964243] scsi 1:0:0:0: Direct-Access     Generic  STORAGE DEVICE   1404 PQ: 0 ANSI: 6
[ 9555.966331] sd 1:0:0:0: Attached scsi generic sg1 type 0
[ 9556.088061] sd 1:0:0:0: [sdb] 61194240 512-byte logical blocks: (31.3 GB/29.2 GiB)
[ 9556.089413] sd 1:0:0:0: [sdb] Write Protect is off
[ 9556.089426] sd 1:0:0:0: [sdb] Mode Sense: 21 00 00 00
[ 9556.090703] sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[ 9556.139338]  sdb: sdb1 sdb2
[ 9556.144312] sd 1:0:0:0: [sdb] Attached SCSI removable disk
[ 9556.664072] EXT4-fs (sdb2): mounted filesystem with ordered data mode. Opts: (null)
[ 9607.397583] usb 1-1.3: USB disconnect, device number 4

seems it is work property for me, my Raspberry Pi 4B 8GB works fine.
and my M.2 SATA SSD information is:

pi@raspberrypi:~ $ lsusb -vvv

Bus 002 Device 002: ID 152d:0562 JMicron Technology Corp. / JMicron USA Technology Corp.
Couldn't open device, some information will be missing
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               3.00
  bDeviceClass            0
  bDeviceSubClass         0
  bDeviceProtocol         0
  bMaxPacketSize0         9
  idVendor           0x152d JMicron Technology Corp. / JMicron USA Technology Corp.
  idProduct          0x0562
  bcdDevice            1.09
  iManufacturer           1
  iProduct                2
  iSerial                 3
  bNumConfigurations      1
  Configuration Descriptor:
    bLength                 9
    bDescriptorType         2
    wTotalLength       0x0079
    bNumInterfaces          1
    bConfigurationValue     1
    iConfiguration          0
    bmAttributes         0xc0
      Self Powered
    MaxPower                8mA
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        0
      bAlternateSetting       0
      bNumEndpoints           2
      bInterfaceClass         8 Mass Storage
      bInterfaceSubClass      6 SCSI
      bInterfaceProtocol     80 Bulk-Only
      iInterface              0
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x81  EP 1 IN
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0400  1x 1024 bytes
        bInterval               0
        bMaxBurst              15
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x02  EP 2 OUT
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0400  1x 1024 bytes
        bInterval               0
        bMaxBurst              15
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        0
      bAlternateSetting       1
      bNumEndpoints           4
      bInterfaceClass         8 Mass Storage
      bInterfaceSubClass      6 SCSI
      bInterfaceProtocol     98
      iInterface              0
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x01  EP 1 OUT
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0400  1x 1024 bytes
        bInterval               0
        bMaxBurst               0
        Command pipe (0x01)
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x82  EP 2 IN
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0400  1x 1024 bytes
        bInterval               0
        bMaxBurst               0
        MaxStreams             32
        Status pipe (0x02)
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x83  EP 3 IN
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0400  1x 1024 bytes
        bInterval               0
        bMaxBurst              14
        MaxStreams             32
        Data-in pipe (0x03)
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x04  EP 4 OUT
        bmAttributes            2
          Transfer Type            Bulk
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0400  1x 1024 bytes
        bInterval               0
        bMaxBurst               7
        MaxStreams             32
        Data-out pipe (0x04)

Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Couldn't open device, some information will be missing
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               3.00
  bDeviceClass            9 Hub
  bDeviceSubClass         0
  bDeviceProtocol         3
  bMaxPacketSize0         9
  idVendor           0x1d6b Linux Foundation
  idProduct          0x0003 3.0 root hub
  bcdDevice            5.04
  iManufacturer           3
  iProduct                2
  iSerial                 1
  bNumConfigurations      1
  Configuration Descriptor:
    bLength                 9
    bDescriptorType         2
    wTotalLength       0x001f
    bNumInterfaces          1
    bConfigurationValue     1
    iConfiguration          0
    bmAttributes         0xe0
      Self Powered
      Remote Wakeup
    MaxPower                0mA
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        0
      bAlternateSetting       0
      bNumEndpoints           1
      bInterfaceClass         9 Hub
      bInterfaceSubClass      0
      bInterfaceProtocol      0 Full speed (or root) hub
      iInterface              0
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x81  EP 1 IN
        bmAttributes            3
          Transfer Type            Interrupt
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0004  1x 4 bytes
        bInterval              12
        bMaxBurst               0

Bus 001 Device 002: ID 2109:3431 VIA Labs, Inc. Hub
Couldn't open device, some information will be missing
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               2.10
  bDeviceClass            9 Hub
  bDeviceSubClass         0
  bDeviceProtocol         1 Single TT
  bMaxPacketSize0        64
  idVendor           0x2109 VIA Labs, Inc.
  idProduct          0x3431 Hub
  bcdDevice            4.21
  iManufacturer           0
  iProduct                1
  iSerial                 0
  bNumConfigurations      1
  Configuration Descriptor:
    bLength                 9
    bDescriptorType         2
    wTotalLength       0x0019
    bNumInterfaces          1
    bConfigurationValue     1
    iConfiguration          0
    bmAttributes         0xe0
      Self Powered
      Remote Wakeup
    MaxPower              100mA
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        0
      bAlternateSetting       0
      bNumEndpoints           1
      bInterfaceClass         9 Hub
      bInterfaceSubClass      0
      bInterfaceProtocol      0 Full speed (or root) hub
      iInterface              0
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x81  EP 1 IN
        bmAttributes            3
          Transfer Type            Interrupt
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0001  1x 1 bytes
        bInterval              12

Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Couldn't open device, some information will be missing
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               2.00
  bDeviceClass            9 Hub
  bDeviceSubClass         0
  bDeviceProtocol         1 Single TT
  bMaxPacketSize0        64
  idVendor           0x1d6b Linux Foundation
  idProduct          0x0002 2.0 root hub
  bcdDevice            5.04
  iManufacturer           3
  iProduct                2
  iSerial                 1
  bNumConfigurations      1
  Configuration Descriptor:
    bLength                 9
    bDescriptorType         2
    wTotalLength       0x0019
    bNumInterfaces          1
    bConfigurationValue     1
    iConfiguration          0
    bmAttributes         0xe0
      Self Powered
      Remote Wakeup
    MaxPower                0mA
    Interface Descriptor:
      bLength                 9
      bDescriptorType         4
      bInterfaceNumber        0
      bAlternateSetting       0
      bNumEndpoints           1
      bInterfaceClass         9 Hub
      bInterfaceSubClass      0
      bInterfaceProtocol      0 Full speed (or root) hub
      iInterface              0
      Endpoint Descriptor:
        bLength                 7
        bDescriptorType         5
        bEndpointAddress     0x81  EP 1 IN
        bmAttributes            3
          Transfer Type            Interrupt
          Synch Type               None
          Usage Type               Data
        wMaxPacketSize     0x0004  1x 4 bytes
        bInterval              12

lsblk infor:

 lsblk -t
NAME     ALIGNMENT MIN-IO OPT-IO PHY-SEC LOG-SEC ROTA SCHED    RQ-SIZE  RA WSAME
sda              0   4096      0    4096     512    1 mq-deadline
│                                                                   58 128   32M
└─sda1           0   4096      0    4096     512    1 mq-deadline
                                                                    58 128   32M
mmcblk0          0    512      0     512     512    0 mq-deadline
│                                                                  128 128    0B
├─mmcblk0p1
│                0    512      0     512     512    0 mq-deadline
│                                                                  128 128    0B
└─mmcblk0p2
                 0    512      0     512     512    0 mq-deadline
                                                                   128 128    0B

@githubharald
Copy link
Author

githubharald commented Dec 10, 2020

Could it be caused by the automatic hibernation of the hard disk, and the hard disk may enter a low power consumption mode without data collection for a long time? Similar to hard disk hibernation?

As I wrote, I have a script which writes a file each minute, so that the disk does no go to sleep. But still the problem occurred.
Could you please move the dmesg output to a text file? This would keep this thread more readable.

seems it is work property for me, my Raspberry Pi 4B 8GB works fine.

What is the uptime of your RPi? Days, weeks, or even months?

P.S.: With the downgraded kernel, the problem did no occur until now.

@BigMuscle85
Copy link

In our case, HDD does not hibernate either. Data is being written to it permanently. It is remote network HDD connected via SMB.
I tried to put the kernel 5.4 back. After several hours it got stuck. This is dmesg:

[   21.182264] FS-Cache: Netfs 'cifs' registered for caching
[   21.214956] Key type cifs.spnego registered
[   21.215212] Key type cifs.idmap registered
[   21.217919] CIFS: Attempting to mount //IP/Kamery
[   21.479274] CIFS VFS: Autodisabling the use of server inode numbers on new server.
[   21.479294] CIFS VFS: The server doesn't seem to support them properly or the files might be on different servers (DFS).
[   21.479304] CIFS VFS: Hardlinks will not be recognized on this mount. Consider mounting with the "noserverino" option to silence this message.
[36693.762505] CIFS VFS: \\IP sends on sock 0bcf5229 stuck for 15 seconds
[36693.762560] CIFS VFS: \\IP Error -11 sending data on socket to server
[36862.083309] INFO: task cifsd:509 blocked for more than 122 seconds.
[36862.083333]       Tainted: G         C        5.4.72-v7+ #1356
[36862.083343] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[36862.083354] cifsd           D    0   509      2 0x00000000
[36862.083372] Backtrace:
[36862.083407] [<809277c0>] (__schedule) from [<8092803c>] (schedule+0x5c/0xd0)
[36862.083426]  r10:7f3e8330 r9:00000000 r8:acedbd54 r7:00000002 r6:aceda000 r5:aceda000
[36862.083435]  r4:acef9e80
[36862.083453] [<80927fe0>] (schedule) from [<809284a8>] (schedule_preempt_disabled+0x18/0x1c)
[36862.083463]  r5:aceda000 r4:7f3e832c
[36862.083483] [<80928490>] (schedule_preempt_disabled) from [<8092a7fc>] (__mutex_lock.constprop.0+0x2c4/0x55c)
[36862.083500] [<8092a538>] (__mutex_lock.constprop.0) from [<8092abb0>] (__mutex_lock_slowpath+0x1c/0x20)
[36862.083515]  r10:00000012 r9:7f3c67ec r8:aeb1fe00 r7:a9d93800 r6:aeb1e100 r5:7f3e82a8
[36862.083524]  r4:7f3e832c
[36862.083539] [<8092ab94>] (__mutex_lock_slowpath) from [<8092ac10>] (mutex_lock+0x5c/0x60)
[36862.084010] [<8092abb4>] (mutex_lock) from [<7f3b77c8>] (dfs_cache_update_vol+0x38/0xb0 [cifs])
[36862.084025]  r5:7f3e82a8 r4:a9d93800
[36862.084436] [<7f3b7790>] (dfs_cache_update_vol [cifs]) from [<7f36e11c>] (cifs_reconnect+0x5cc/0x950 [cifs])
[36862.084456]  r9:7f3c67ec r8:aeb1fe00 r7:a9d93974 r6:00000000 r5:00000000 r4:a9d93800
[36862.084835] [<7f36db50>] (cifs_reconnect [cifs]) from [<7f36e69c>] (cifs_readv_from_socket+0x1fc/0x244 [cifs])
[36862.084853]  r10:aceda000 r9:80e03d00 r8:80ed7a4c r7:ffffff99 r6:acedbe9c r5:a9d93970
[36862.084861]  r4:a9d93800
[36862.085239] [<7f36e4a0>] (cifs_readv_from_socket [cifs]) from [<7f36e748>] (cifs_read_from_socket+0x64/0x8c [cifs])
[36862.085255]  r10:80ed7a4c r9:a9d9393c r8:aceda000 r7:a9d93800 r6:00000023 r5:a9d67c00
[36862.085264]  r4:a9d93800 r3:00000000
[36862.085641] [<7f36e6e4>] (cifs_read_from_socket [cifs]) from [<7f36eb68>] (cifs_demultiplex_thread+0x124/0xa48 [cifs])
[36862.085650]  r4:00000000
[36862.085851] [<7f36ea44>] (cifs_demultiplex_thread [cifs]) from [<801449cc>] (kthread+0x144/0x170)
[36862.085867]  r10:acd2fd1c r9:aeb1e19c r8:a9d93800 r7:aceda000 r6:00000000 r5:aeb1e0c0
[36862.085875]  r4:aeb1e180
[36862.085891] [<80144888>] (kthread) from [<801010ac>] (ret_from_fork+0x14/0x28)
[36862.085901] Exception stack(0xacedbfb0 to 0xacedbff8)
[36862.085913] bfa0:                                     00000000 00000000 00000000 00000000
[36862.085927] bfc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[36862.085940] bfe0: 00000000 00000000 00000000 00000000 00000013 00000000
[36862.085954]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:80144888
[36862.085962]  r4:aeb1e0c0
[36862.085982] INFO: task kworker/1:0:14486 blocked for more than 122 seconds.
[36862.085992]       Tainted: G         C        5.4.72-v7+ #1356
[36862.085999] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[36862.086008] kworker/1:0     D    0 14486      2 0x00000000
[36862.086217] Workqueue: cifsiod cifs_uncached_writev_complete [cifs]
[36862.086229] Backtrace:
[36862.086250] [<809277c0>] (__schedule) from [<8092803c>] (schedule+0x5c/0xd0)
[36862.086265]  r10:b0ec8018 r9:00000000 r8:a9f79c5c r7:00000002 r6:a9f78000 r5:a9f78000
[36862.086274]  r4:9946bd00
[36862.086290] [<80927fe0>] (schedule) from [<809284a8>] (schedule_preempt_disabled+0x18/0x1c)
[36862.086301]  r5:a9f78000 r4:b0ec8014
[36862.086317] [<80928490>] (schedule_preempt_disabled) from [<8092a7fc>] (__mutex_lock.constprop.0+0x2c4/0x55c)
[36862.086335] [<8092a538>] (__mutex_lock.constprop.0) from [<8092abb0>] (__mutex_lock_slowpath+0x1c/0x20)
[36862.086350]  r10:b0ec8014 r9:7f181000 r8:00000001 r7:b0ec8000 r6:b2b86000 r5:0000002f
[36862.086359]  r4:b0ec8014
[36862.086374] [<8092ab94>] (__mutex_lock_slowpath) from [<8092ac10>] (mutex_lock+0x5c/0x60)
[36862.086574] [<8092abb4>] (mutex_lock) from [<7f3618c8>] (cifs_reconnect_tcon+0x9c/0x5a0 [cifs])
[36862.086585]  r5:0000002f r4:a9d93800
[36862.086961] [<7f36182c>] (cifs_reconnect_tcon [cifs]) from [<7f361dfc>] (small_smb_init+0x30/0x84 [cifs])
[36862.086977]  r10:00000010 r9:a9d93800 r8:0000000e r7:a9f79d7c r6:0000002f r5:b2b86000
[36862.086986]  r4:aeb1ff00
[36862.087362] [<7f361dcc>] (small_smb_init [cifs]) from [<7f364d10>] (cifs_async_writev+0x9c/0x2bc [cifs])
[36862.088151]  r9:a9d93800 r8:0000000e r7:7f377d8c r6:00010000 r5:b2b86000 r4:aeb1ff00
[36862.088713] [<7f364c74>] (cifs_async_writev [cifs]) from [<7f37af94>] (cifs_write_from_iter+0x25c/0x8d8 [cifs])
[36862.089336]  r8:a9f79ebc r7:aeb1ff58 r6:00010000 r5:00000010 r4:aeb1ff00
[36862.089960] [<7f37ad38>] (cifs_write_from_iter [cifs]) from [<7f37ba64>] (cifs_uncached_writev_complete+0x454/0x560 [cifs])
[36862.090162]  r10:a6840380 r9:a68408a0 r8:a684038c r7:ff7c6e00 r6:a6840a80 r5:a6840884
[36862.090172]  r4:a6840880
[36862.090491] [<7f37b610>] (cifs_uncached_writev_complete [cifs]) from [<8013d1ac>] (process_one_work+0x214/0x538)
[36862.090517]  r10:00000000 r9:00000040 r8:00000000 r7:ff7c6e00 r6:b37b62c0 r5:a9c32b80
[36862.090526]  r4:a68408a0
[36862.090546] [<8013cf98>] (process_one_work) from [<8013d51c>] (worker_thread+0x4c/0x580)
[36862.090565]  r10:b37b62c0 r9:80e03d00 r8:b37b62d8 r7:00000008 r6:b37b62c0 r5:a9c32b94
[36862.090573]  r4:a9c32b80
[36862.090592] [<8013d4d0>] (worker_thread) from [<801449cc>] (kthread+0x144/0x170)
[36862.090607]  r10:a9ef1e7c r9:a6bee29c r8:a9c32b80 r7:a9f78000 r6:00000000 r5:a6bee740
[36862.090617]  r4:a6bee280
[36862.090635] [<80144888>] (kthread) from [<801010ac>] (ret_from_fork+0x14/0x28)
[36862.090676] Exception stack(0xa9f79fb0 to 0xa9f79ff8)
[36862.090691] 9fa0:                                     00000000 00000000 00000000 00000000
[36862.090705] 9fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[36862.090718] 9fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[36862.090734]  r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:80144888
[36862.090742]  r4:a6bee740
[36862.090763] INFO: task kworker/1:1:14597 blocked for more than 122 seconds.
[36862.090775]       Tainted: G         C        5.4.72-v7+ #1356
[36862.090783] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[36862.090791] kworker/1:1     D    0 14597      2 0x00000000
[36862.091092] Workqueue: cifsiod cifs_uncached_writev_complete [cifs]
[36862.091108] Backtrace:
[36862.091137] [<809277c0>] (__schedule) from [<8092803c>] (schedule+0x5c/0xd0)
...

@githubharald
Copy link
Author

FYI: after downgrading the kernel to 4.19 there were no more problems with the HDD so far.
Any comments from the RPi kernel team on this?

@debuti
Copy link

debuti commented Mar 19, 2021

Same issue here.

$ dmesg | grep -i xhci
[    1.484040] xhci_hcd 0000:01:00.0: xHCI Host Controller
[    1.484077] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 1
[    1.487297] xhci_hcd 0000:01:00.0: hcc params 0x002841eb hci version 0x100 quirks 0x0000030000000890
[    1.488633] usb usb1: Product: xHCI Host Controller
[    1.488650] usb usb1: Manufacturer: Linux 5.10.17-v7l+ xhci-hcd
[    1.490203] xhci_hcd 0000:01:00.0: xHCI Host Controller
[    1.490243] xhci_hcd 0000:01:00.0: new USB bus registered, assigned bus number 2
[    1.490269] xhci_hcd 0000:01:00.0: Host supports USB 3.0 SuperSpeed
[    1.490806] usb usb2: Product: xHCI Host Controller
[    1.490823] usb usb2: Manufacturer: Linux 5.10.17-v7l+ xhci-hcd
[    1.853064] usb 1-1: new high-speed USB device number 2 using xhci_hcd
[    2.373077] usb 1-1.2: new full-speed USB device number 3 using xhci_hcd
[    2.773152] usb 1-1.4: new high-speed USB device number 4 using xhci_hcd
[    7.143092] usb 1-1.4.1: new high-speed USB device number 5 using xhci_hcd
[    7.513159] usb 1-1.4.2: new high-speed USB device number 6 using xhci_hcd
[    7.813079] usb 1-1.4.3: new high-speed USB device number 7 using xhci_hcd
[    8.093820] usb 1-1.4.4: new high-speed USB device number 8 using xhci_hcd
[38771.059433] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
[38771.059449] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
[38771.169873] usb 1-1.4.1: reset high-speed USB device number 5 using xhci_hcd
[38801.779938] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
[38801.779954] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
[38801.890222] usb 1-1.4.1: reset high-speed USB device number 5 using xhci_hcd
[38832.500293] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
[38832.500309] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
[38832.620588] usb 1-1.4.1: reset high-speed USB device number 5 using xhci_hcd

@githubharald how did you downgraded your pi to 4.x kernel?

Thanks

@githubharald
Copy link
Author

sudo rpi-update e1050e94821a70b2e4c72b318d6c6c968552e9a2

@AaronFaltesek
Copy link

AaronFaltesek commented Mar 20, 2021

I believe I'm having this same issue. I'll try downgrading as well. It typically loses access to external HDD after 1-3 days of uptime. I'm writing data to it ~every 10 minutes.

    Mar 20 00:50:46 raspberrypi kernel: [63618.625874] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.  
Mar 20 00:50:46 raspberrypi kernel: [63618.726207] usb 1-1.4: reset high-speed USB device number 3 using xhci_hcd  
Mar 20 00:51:17 raspberrypi kernel: [63649.025975] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr  
Mar 20 00:51:17 raspberrypi kernel: [63649.025988] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.  
Mar 20 00:51:17 raspberrypi kernel: [63649.126248] usb 1-1.4: reset high-speed USB device number 3 using xhci_hcd  
Mar 20 00:51:17 raspberrypi kernel: [63649.257638] sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x03driverbyte=0x00  
Mar 20 00:51:17 raspberrypi kernel: [63649.257661] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 2e 0f be 38 00 00 10 00  
Mar 20 00:51:24 raspberrypi kernel: [63656.305916] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr  
Mar 20 00:51:24 raspberrypi kernel: [63656.305930] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.  
Mar 20 00:51:24 raspberrypi kernel: [63656.406243] usb 1-1.4: reset high-speed USB device number 3 using xhci_hcd  
Mar 20 00:51:24 raspberrypi udisksd[364]: Error performing housekeeping for drive /org/freedesktop/UDisks2/drives/TOSHIBA_MQ04UBD200_Y04FT0PYT: Error updating SMART data: sk_disk_smart_read_data: Operation not supported (udisks-error-quark, 0)

I will try the downgrading from 5.4.79 to 4.19 using your command.

Current Version

@raspberrypi:~ $ uname -a
Linux raspberrypi 5.4.79-v7l+ #1373 SMP Mon Nov 23 13:27:40 GMT 2020 armv7l GNU/Linux

Version after running sudo rpi-update e1050e94821a70b2e4c72b318d6c6c968552e9a2

Linux raspberrypi 4.19.118-v7l+ #1311 SMP Mon Apr 27 14:26:42 BST 2020 armv7l GNU/Linux

@githubharald
Copy link
Author

@debuti
@AaronFaltesek
Would be interesting to hear from you if downgrading also solved the problem.

@debuti
Copy link

debuti commented Mar 24, 2021

So far the downgrading solves the problem yes, its been 3 days without issues (while usually in 1-2 days it was failing)

@AaronFaltesek
Copy link

After 5 days without issue it's safe to say this has solved my issue.

@githubharald
Copy link
Author

would be cool if someone from the RPi team could comment on this. It seems that some bug was introduced in the new kernel.
I guess more people will be confronted with this issue as soon as they upgrade. Many people use the RPi as NAS, so even if it takes 2 or 3 days until the HDD hangs, one will notice it at some point.

Are all of you with the problem also using a Toshiba ext HDD (at least from the logs AaronFaltesek seems to also have one).

@bretonium
Copy link

No, i have WD or Seagate (not sure which one fails)

@t-paul
Copy link

t-paul commented Mar 25, 2021

Same issue with 2 WD disks running as raid on the USB3 connectors:

Bus 002 Device 003: ID 1058:25a3 Western Digital Technologies, Inc. Elements Desktop (WDBWLG)
Bus 002 Device 002: ID 1058:25a3 Western Digital Technologies, Inc. Elements Desktop (WDBWLG)
# cat /proc/mdstat 
Personalities : [raid1] 
md127 : active raid1 sdb[0] sda[1]
      3906853888 blocks super 1.2 [2/2] [UU]
      bitmap: 0/30 pages [0KB], 65536KB chunk

This does not seem related to #3210 as mentioned above, I'm running on a 4MB PI headless and there's no OOM in the logs.

@bassistguy
Copy link

I just wanted to reply and state that downgrading to 4.19.118-v7l+ fixed my issue. I was having this same issue for MONTHS where the connection to my external (powered) USB hard drive would just randomly freeze (within a day or 2 of rebooting my Pi). It would still show as mounted, but I couldn't' access it and the drive light would constantly blink. I would have to reboot my Pi 4 B in order for the drive to be accessible again for a day or so. I downgraded to 4.19.118-v7l+ via the command githubharald posted. That was 4 days ago and the drive is still connected.Thank you everyone for this post!! It was driving me nuts.

Has anyone tried to contact the Raspberry Pi folks to let them know? I'm assuming they have to know about this, as it's been going on for a number of months now.

sudo rpi-update e1050e94821a70b2e4c72b318d6c6c968552e9a2

@a123xxsp
Copy link

I am having the same issues (external USB HDD stop responding randomly, usually after a day uptime) :
uname -a
Linux raspberrypi 5.10.17-v7l+ #1403 SMP Mon Feb 22 11:33:35 GMT 2021 armv7l GNU/Linux

I will try to downgrade to 4.19 and let you know , I am just curious why I am on version 5.1 and everyone else is on 5.4 (I don't get 5.4 via apt upgrade)

@jimbasilio
Copy link

This isn't just raspberrypi, I have this issue on my mythbuntu installation with an external drive. Kernel is 5.4.

Trying to figure out how to downgrade to 4.19. I was going to upgrade to 5.10 but it seems that has an issue too.

Frustrating!

@a123xxsp
Copy link

This isn't just raspberrypi, I have this issue on my mythbuntu installation with an external drive. Kernel is 5.4.
Trying to figure out how to downgrade to 4.19. I was going to upgrade to 5.10 but it seems that has an issue too.
Frustrating!
Thanks for the notice, for now, I bypassed the problem by rebooting myPi every day with a CRON job, but I am also testing 4.19 with another microSD and let you know.

@PetrozPL
Copy link

PetrozPL commented Mar 31, 2021

the same issue on my RPI4

Linux rpi4tvhead 5.10.17-v7l+ #1403 SMP Mon Feb 22 11:33:35 GMT 2021 armv7l GNU/Linux

The USB 3.0 drive is :

Bus 002 Device 002: ID 1058:1230 Western Digital Technologies, Inc. My Book (WDBFJK)

The same problem was on other HDD i've previously tested. The kernel log as below:

[819629.648204] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
[819629.648220] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
[819629.799065] usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[819636.858297] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
[819636.858313] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
[819637.009119] usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[820229.583028] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
[820229.583045] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
[820229.733735] usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[820829.657287] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
[820829.657303] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
[820829.808092] usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[821429.661124] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
[821429.661140] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
[821429.811913] usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[822029.664256] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
[822029.664272] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
[822029.814936] usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[822629.667958] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
[822629.667974] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
[822629.818665] usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[823229.631802] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
[823229.631818] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
[823229.782543] usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[823829.606896] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
[823829.606911] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
[823829.757699] usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[824429.681450] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
[824429.681466] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
[824429.832298] usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[825029.685789] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
[825029.685805] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
[825029.836537] usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[825629.679042] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
[825629.679057] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
[825629.829764] usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[826229.621928] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
[826229.621944] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
[826229.772715] usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[826829.625498] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
[826829.625513] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
[826829.776227] usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[827429.699264] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
[827429.699280] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
[827429.849932] usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[827495.104002] cxd2880: cxd2880_set_frontend: sys:3 freq:586000000 bw:8
[827496.136567] cxd2880: cxd2880_set_frontend: tune result 0
[827555.499900] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
[827555.499916] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
[827555.650710] usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[827555.682449] sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x03 driverbyte=0x00 cmd_age=30s
[827555.682476] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 03 1c 43 93 00 00 02 00
[827555.682502] blk_update_request: I/O error, dev sda, sector 417471640 op 0x0:(READ) flags 0x80700 phys_seg 2 prio class 0
[827586.220071] xhci_hcd 0000:01:00.0: WARN Cannot submit Set TR Deq Ptr
[827586.220087] xhci_hcd 0000:01:00.0: A Set TR Deq Ptr command is pending.
[827586.370843] usb 2-2: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[827723.160680] INFO: task usb-storage:93 blocked for more than 122 seconds.
[827723.160702] Tainted: G C 5.10.17-v7l+ #1403
[827723.160717] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[827723.160734] task:usb-storage state:D stack: 0 pid: 93 ppid: 2 flags:0x00000000
[827723.160768] Backtrace:
[827723.160819] [] (__schedule) from [] (schedule+0x68/0xe4)
[827723.160843] r10:0000001f r9:00000002 r8:7fffffff r7:c1205048 r6:c269adf0 r5:c28abe00
[827723.160859] r4:ffffe000
[827723.160886] [] (schedule) from [] (schedule_timeout+0x2e8/0x384)
[827723.160904] r5:c1205048 r4:c269adec
[827723.160930] [] (schedule_timeout) from [] (wait_for_completion+0xb8/0x138)
[827723.160950] r9:00000002 r8:7fffffff r7:ffffe000 r6:c269adf0 r5:c1205048 r4:c269adec
[827723.160976] [] (wait_for_completion) from [] (usb_sg_wait+0x168/0x190)
[827723.160996] r9:00001000 r8:00000000 r7:00000000 r6:c269adec r5:00000001 r4:c269adcc
[827723.161020] [] (usb_sg_wait) from [] (usb_stor_bulk_transfer_sglist.part.2+0x80/0xdc)
[827723.161041] r9:00001000 r8:c269ad64 r7:00001000 r6:c0008280 r5:c269adcc r4:c269ad40
[827723.161064] [] (usb_stor_bulk_transfer_sglist.part.2) from [] (usb_stor_bulk_srb+0x58/0x84)
[827723.161083] r8:c1205048 r7:00000000 r6:c28e82a8 r5:c28e82a8 r4:c1205048
[827723.161106] [] (usb_stor_bulk_srb) from [] (usb_stor_Bulk_transport+0x128/0x384)
[827723.161123] r5:ded3b000 r4:c269ad40
[827723.161145] [] (usb_stor_Bulk_transport) from [] (usb_stor_invoke_transport+0x40/0x4c4)
[827723.161165] r10:c1b1197c r9:c269ad40 r8:00000000 r7:c1205048 r6:c1205048 r5:c28e82a8
[827723.161181] r4:c269ad40
[827723.161204] [] (usb_stor_invoke_transport) from [] (usb_stor_transparent_scsi_command+0x18/0x1c)
[827723.161224] r10:c1b1197c r9:c269ad40 r8:00000000 r7:c28e82a8 r6:c1205048 r5:c269ae0c
[827723.161240] r4:c269ad40
[827723.161262] [] (usb_stor_transparent_scsi_command) from [] (usb_stor_control_thread+0x19c/0x2a8)
[827723.161287] [] (usb_stor_control_thread) from [] (kthread+0x170/0x174)
[827723.161306] r8:c093b69c r7:c28a6000 r6:00000000 r5:c2793880 r4:c26fc680
[827723.161328] [] (kthread) from [] (ret_from_fork+0x14/0x28)
[827723.161346] Exception stack(0xc28a7fb0 to 0xc28a7ff8)
[827723.161365] 7fa0: 00000000 00000000 00000000 00000000
[827723.161384] 7fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[827723.161402] 7fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[827723.161423] r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02458e0
[827723.161438] r4:c2793880
[827846.041377] INFO: task scsi_eh_0:91 blocked for more than 122 seconds.
[827846.041399] Tainted: G C 5.10.17-v7l+ #1403
[827846.041415] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[827846.041432] task:scsi_eh_0 state:D stack: 0 pid: 91 ppid: 2 flags:0x00000000
[827846.041466] Backtrace:
[827846.041517] [] (__schedule) from [] (schedule+0x68/0xe4)
[827846.041541] r10:00000000 r9:00000002 r8:c1205048 r7:c2784000 r6:c2785e44 r5:c28a9f00
[827846.041557] r4:ffffe000
[827846.041583] [] (schedule) from [] (schedule_preempt_disabled+0x18/0x1c)
[827846.041601] r5:ffffe000 r4:c269ad40
[827846.041627] [] (schedule_preempt_disabled) from [] (__mutex_lock.constprop.9+0x344/0x58c)
[827846.041654] [] (__mutex_lock.constprop.9) from [] (__mutex_lock_slowpath+0x1c/0x20)
[827846.041674] r10:c1203d00 r9:c269a800 r8:c1203d00 r7:c1203d00 r6:c269b000 r5:c269a800
[827846.041690] r4:c269ad40
[827846.041715] [] (__mutex_lock_slowpath) from [] (mutex_lock+0x5c/0x60)
[827846.041740] [] (mutex_lock) from [] (device_reset+0x28/0x54)
[827846.041757] r5:c269a800 r4:c269ad40
[827846.041783] [] (device_reset) from [] (scsi_eh_ready_devs+0x4ec/0x8fc)
[827846.041800] r5:c28e82a8 r4:c2785f34
[827846.041825] [] (scsi_eh_ready_devs) from [] (scsi_error_handler+0x3d8/0x3e0)
[827846.041845] r10:c087c2f4 r9:c269a974 r8:c1205048 r7:c2785f34 r6:ffffe000 r5:c2785f3c
[827846.041861] r4:c269a800
[827846.041887] [] (scsi_error_handler) from [] (kthread+0x170/0x174)
[827846.041907] r10:c1b11944 r9:c269a800 r8:c087e5a0 r7:c2784000 r6:00000000 r5:c27936c0
[827846.041922] r4:c26fc600
[827846.041944] [] (kthread) from [] (ret_from_fork+0x14/0x28)
[827846.041961] Exception stack(0xc2785fb0 to 0xc2785ff8)
[827846.041979] 5fa0: 00000000 00000000 00000000 00000000
[827846.041999] 5fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[827846.042017] 5fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[827846.042037] r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02458e0
[827846.042053] r4:c27936c0
[827846.042071] INFO: task usb-storage:93 blocked for more than 245 seconds.
[827846.042088] Tainted: G C 5.10.17-v7l+ #1403
[827846.042103] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[827846.042119] task:usb-storage state:D stack: 0 pid: 93 ppid: 2 flags:0x00000000
[827846.042150] Backtrace:
[827846.042187] [] (__schedule) from [] (schedule+0x68/0xe4)
[827846.042208] r10:0000001f r9:00000002 r8:7fffffff r7:c1205048 r6:c269adf0 r5:c28abe00
[827846.042224] r4:ffffe000
[827846.042247] [] (schedule) from [] (schedule_timeout+0x2e8/0x384)
[827846.042264] r5:c1205048 r4:c269adec
[827846.042289] [] (schedule_timeout) from [] (wait_for_completion+0xb8/0x138)
[827846.042308] r9:00000002 r8:7fffffff r7:ffffe000 r6:c269adf0 r5:c1205048 r4:c269adec
[827846.042333] [] (wait_for_completion) from [] (usb_sg_wait+0x168/0x190)
[827846.042353] r9:00001000 r8:00000000 r7:00000000 r6:c269adec r5:00000001 r4:c269adcc
[827846.042375] [] (usb_sg_wait) from [] (usb_stor_bulk_transfer_sglist.part.2+0x80/0xdc)
[827846.042395] r9:00001000 r8:c269ad64 r7:00001000 r6:c0008280 r5:c269adcc r4:c269ad40
[827846.042417] [] (usb_stor_bulk_transfer_sglist.part.2) from [] (usb_stor_bulk_srb+0x58/0x84)
[827846.042437] r8:c1205048 r7:00000000 r6:c28e82a8 r5:c28e82a8 r4:c1205048
[827846.042458] [] (usb_stor_bulk_srb) from [] (usb_stor_Bulk_transport+0x128/0x384)
[827846.042475] r5:ded3b000 r4:c269ad40
[827846.042497] [] (usb_stor_Bulk_transport) from [] (usb_stor_invoke_transport+0x40/0x4c4)
[827846.042517] r10:c1b1197c r9:c269ad40 r8:00000000 r7:c1205048 r6:c1205048 r5:c28e82a8
[827846.042533] r4:c269ad40
[827846.042555] [] (usb_stor_invoke_transport) from [] (usb_stor_transparent_scsi_command+0x18/0x1c)
[827846.042575] r10:c1b1197c r9:c269ad40 r8:00000000 r7:c28e82a8 r6:c1205048 r5:c269ae0c
[827846.042590] r4:c269ad40
[827846.042613] [] (usb_stor_transparent_scsi_command) from [] (usb_stor_control_thread+0x19c/0x2a8)
[827846.042635] [] (usb_stor_control_thread) from [] (kthread+0x170/0x174)
[827846.042655] r8:c093b69c r7:c28a6000 r6:00000000 r5:c2793880 r4:c26fc680
[827846.042675] [] (kthread) from [] (ret_from_fork+0x14/0x28)
[827846.042692] Exception stack(0xc28a7fb0 to 0xc28a7ff8)
[827846.042710] 7fa0: 00000000 00000000 00000000 00000000
[827846.042729] 7fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[827846.042747] 7fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[827846.042767] r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02458e0
[827846.042782] r4:c2793880
[827968.922082] INFO: task scsi_eh_0:91 blocked for more than 245 seconds.
[827968.922103] Tainted: G C 5.10.17-v7l+ #1403
[827968.922119] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[827968.922136] task:scsi_eh_0 state:D stack: 0 pid: 91 ppid: 2 flags:0x00000000
[827968.922170] Backtrace:
[827968.922221] [] (__schedule) from [] (schedule+0x68/0xe4)
[827968.922245] r10:00000000 r9:00000002 r8:c1205048 r7:c2784000 r6:c2785e44 r5:c28a9f00
[827968.922261] r4:ffffe000
[827968.922287] [] (schedule) from [] (schedule_preempt_disabled+0x18/0x1c)
[827968.922304] r5:ffffe000 r4:c269ad40
[827968.922331] [] (schedule_preempt_disabled) from [] (__mutex_lock.constprop.9+0x344/0x58c)
[827968.922357] [] (__mutex_lock.constprop.9) from [] (__mutex_lock_slowpath+0x1c/0x20)
[827968.922378] r10:c1203d00 r9:c269a800 r8:c1203d00 r7:c1203d00 r6:c269b000 r5:c269a800
[827968.922394] r4:c269ad40
[827968.922418] [] (__mutex_lock_slowpath) from [] (mutex_lock+0x5c/0x60)
[827968.922443] [] (mutex_lock) from [] (device_reset+0x28/0x54)
[827968.922460] r5:c269a800 r4:c269ad40
[827968.922486] [] (device_reset) from [] (scsi_eh_ready_devs+0x4ec/0x8fc)
[827968.922503] r5:c28e82a8 r4:c2785f34
[827968.922528] [] (scsi_eh_ready_devs) from [] (scsi_error_handler+0x3d8/0x3e0)
[827968.922549] r10:c087c2f4 r9:c269a974 r8:c1205048 r7:c2785f34 r6:ffffe000 r5:c2785f3c
[827968.922565] r4:c269a800
[827968.922590] [] (scsi_error_handler) from [] (kthread+0x170/0x174)
[827968.922610] r10:c1b11944 r9:c269a800 r8:c087e5a0 r7:c2784000 r6:00000000 r5:c27936c0
[827968.922626] r4:c26fc600
[827968.922648] [] (kthread) from [] (ret_from_fork+0x14/0x28)
[827968.922665] Exception stack(0xc2785fb0 to 0xc2785ff8)
[827968.922683] 5fa0: 00000000 00000000 00000000 00000000
[827968.922704] 5fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[827968.922722] 5fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[827968.922741] r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02458e0
[827968.922757] r4:c27936c0
[827968.922775] INFO: task usb-storage:93 blocked for more than 368 seconds.
[827968.922792] Tainted: G C 5.10.17-v7l+ #1403
[827968.922806] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[827968.922822] task:usb-storage state:D stack: 0 pid: 93 ppid: 2 flags:0x00000000
[827968.922853] Backtrace:
[827968.922890] [] (__schedule) from [] (schedule+0x68/0xe4)
[827968.922910] r10:0000001f r9:00000002 r8:7fffffff r7:c1205048 r6:c269adf0 r5:c28abe00
[827968.922926] r4:ffffe000
[827968.922950] [] (schedule) from [] (schedule_timeout+0x2e8/0x384)
[827968.922967] r5:c1205048 r4:c269adec
[827968.922991] [] (schedule_timeout) from [] (wait_for_completion+0xb8/0x138)
[827968.923011] r9:00000002 r8:7fffffff r7:ffffe000 r6:c269adf0 r5:c1205048 r4:c269adec
[827968.923035] [] (wait_for_completion) from [] (usb_sg_wait+0x168/0x190)
[827968.923055] r9:00001000 r8:00000000 r7:00000000 r6:c269adec r5:00000001 r4:c269adcc
[827968.923077] [] (usb_sg_wait) from [] (usb_stor_bulk_transfer_sglist.part.2+0x80/0xdc)
[827968.923097] r9:00001000 r8:c269ad64 r7:00001000 r6:c0008280 r5:c269adcc r4:c269ad40
[827968.923119] [] (usb_stor_bulk_transfer_sglist.part.2) from [] (usb_stor_bulk_srb+0x58/0x84)
[827968.923139] r8:c1205048 r7:00000000 r6:c28e82a8 r5:c28e82a8 r4:c1205048
[827968.923161] [] (usb_stor_bulk_srb) from [] (usb_stor_Bulk_transport+0x128/0x384)
[827968.923177] r5:ded3b000 r4:c269ad40
[827968.923200] [] (usb_stor_Bulk_transport) from [] (usb_stor_invoke_transport+0x40/0x4c4)
[827968.923219] r10:c1b1197c r9:c269ad40 r8:00000000 r7:c1205048 r6:c1205048 r5:c28e82a8
[827968.923235] r4:c269ad40
[827968.923257] [] (usb_stor_invoke_transport) from [] (usb_stor_transparent_scsi_command+0x18/0x1c)
[827968.923277] r10:c1b1197c r9:c269ad40 r8:00000000 r7:c28e82a8 r6:c1205048 r5:c269ae0c
[827968.923293] r4:c269ad40
[827968.923315] [] (usb_stor_transparent_scsi_command) from [] (usb_stor_control_thread+0x19c/0x2a8)
[827968.923337] [] (usb_stor_control_thread) from [] (kthread+0x170/0x174)
[827968.923357] r8:c093b69c r7:c28a6000 r6:00000000 r5:c2793880 r4:c26fc680
[827968.923376] [] (kthread) from [] (ret_from_fork+0x14/0x28)
[827968.923393] Exception stack(0xc28a7fb0 to 0xc28a7ff8)
[827968.923411] 7fa0: 00000000 00000000 00000000 00000000
[827968.923430] 7fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[827968.923448] 7fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[827968.923467] r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02458e0
[827968.923483] r4:c2793880
[828091.802805] INFO: task scsi_eh_0:91 blocked for more than 368 seconds.
[828091.802827] Tainted: G C 5.10.17-v7l+ #1403
[828091.802843] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[828091.802860] task:scsi_eh_0 state:D stack: 0 pid: 91 ppid: 2 flags:0x00000000
[828091.802895] Backtrace:
[828091.802946] [] (__schedule) from [] (schedule+0x68/0xe4)
[828091.802971] r10:00000000 r9:00000002 r8:c1205048 r7:c2784000 r6:c2785e44 r5:c28a9f00
[828091.802987] r4:ffffe000
[828091.803012] [] (schedule) from [] (schedule_preempt_disabled+0x18/0x1c)
[828091.803030] r5:ffffe000 r4:c269ad40
[828091.803057] [] (schedule_preempt_disabled) from [] (__mutex_lock.constprop.9+0x344/0x58c)
[828091.803083] [] (__mutex_lock.constprop.9) from [] (__mutex_lock_slowpath+0x1c/0x20)
[828091.803104] r10:c1203d00 r9:c269a800 r8:c1203d00 r7:c1203d00 r6:c269b000 r5:c269a800
[828091.803120] r4:c269ad40
[828091.803145] [] (__mutex_lock_slowpath) from [] (mutex_lock+0x5c/0x60)
[828091.803170] [] (mutex_lock) from [] (device_reset+0x28/0x54)
[828091.803187] r5:c269a800 r4:c269ad40
[828091.803213] [] (device_reset) from [] (scsi_eh_ready_devs+0x4ec/0x8fc)
[828091.803229] r5:c28e82a8 r4:c2785f34
[828091.803255] [] (scsi_eh_ready_devs) from [] (scsi_error_handler+0x3d8/0x3e0)
[828091.803276] r10:c087c2f4 r9:c269a974 r8:c1205048 r7:c2785f34 r6:ffffe000 r5:c2785f3c
[828091.803291] r4:c269a800
[828091.803317] [] (scsi_error_handler) from [] (kthread+0x170/0x174)
[828091.803337] r10:c1b11944 r9:c269a800 r8:c087e5a0 r7:c2784000 r6:00000000 r5:c27936c0
[828091.803353] r4:c26fc600
[828091.803375] [] (kthread) from [] (ret_from_fork+0x14/0x28)
[828091.803392] Exception stack(0xc2785fb0 to 0xc2785ff8)
[828091.803410] 5fa0: 00000000 00000000 00000000 00000000
[828091.803430] 5fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[828091.803448] 5fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[828091.803468] r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02458e0
[828091.803484] r4:c27936c0
[828091.803502] INFO: task usb-storage:93 blocked for more than 491 seconds.
[828091.803519] Tainted: G C 5.10.17-v7l+ #1403
[828091.803534] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[828091.803551] task:usb-storage state:D stack: 0 pid: 93 ppid: 2 flags:0x00000000
[828091.803583] Backtrace:
[828091.803620] [] (__schedule) from [] (schedule+0x68/0xe4)
[828091.803641] r10:0000001f r9:00000002 r8:7fffffff r7:c1205048 r6:c269adf0 r5:c28abe00
[828091.803656] r4:ffffe000
[828091.803681] [] (schedule) from [] (schedule_timeout+0x2e8/0x384)
[828091.803698] r5:c1205048 r4:c269adec
[828091.803722] [] (schedule_timeout) from [] (wait_for_completion+0xb8/0x138)
[828091.803743] r9:00000002 r8:7fffffff r7:ffffe000 r6:c269adf0 r5:c1205048 r4:c269adec
[828091.803767] [] (wait_for_completion) from [] (usb_sg_wait+0x168/0x190)
[828091.803787] r9:00001000 r8:00000000 r7:00000000 r6:c269adec r5:00000001 r4:c269adcc
[828091.803808] [] (usb_sg_wait) from [] (usb_stor_bulk_transfer_sglist.part.2+0x80/0xdc)
[828091.803828] r9:00001000 r8:c269ad64 r7:00001000 r6:c0008280 r5:c269adcc r4:c269ad40
[828091.803851] [] (usb_stor_bulk_transfer_sglist.part.2) from [] (usb_stor_bulk_srb+0x58/0x84)
[828091.803870] r8:c1205048 r7:00000000 r6:c28e82a8 r5:c28e82a8 r4:c1205048
[828091.803892] [] (usb_stor_bulk_srb) from [] (usb_stor_Bulk_transport+0x128/0x384)
[828091.803909] r5:ded3b000 r4:c269ad40
[828091.803931] [] (usb_stor_Bulk_transport) from [] (usb_stor_invoke_transport+0x40/0x4c4)
[828091.803951] r10:c1b1197c r9:c269ad40 r8:00000000 r7:c1205048 r6:c1205048 r5:c28e82a8
[828091.803966] r4:c269ad40
[828091.803989] [] (usb_stor_invoke_transport) from [] (usb_stor_transparent_scsi_command+0x18/0x1c)
[828091.804009] r10:c1b1197c r9:c269ad40 r8:00000000 r7:c28e82a8 r6:c1205048 r5:c269ae0c
[828091.804025] r4:c269ad40
[828091.804047] [] (usb_stor_transparent_scsi_command) from [] (usb_stor_control_thread+0x19c/0x2a8)
[828091.804069] [] (usb_stor_control_thread) from [] (kthread+0x170/0x174)
[828091.804088] r8:c093b69c r7:c28a6000 r6:00000000 r5:c2793880 r4:c26fc680
[828091.804109] [] (kthread) from [] (ret_from_fork+0x14/0x28)
[828091.804125] Exception stack(0xc28a7fb0 to 0xc28a7ff8)
[828091.804143] 7fa0: 00000000 00000000 00000000 00000000
[828091.804162] 7fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[828091.804181] 7fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[828091.804200] r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02458e0
[828091.804216] r4:c2793880
[828214.683533] INFO: task scsi_eh_0:91 blocked for more than 491 seconds.
[828214.683556] Tainted: G C 5.10.17-v7l+ #1403
[828214.683571] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[828214.683589] task:scsi_eh_0 state:D stack: 0 pid: 91 ppid: 2 flags:0x00000000
[828214.683623] Backtrace:
[828214.683674] [] (__schedule) from [] (schedule+0x68/0xe4)
[828214.683698] r10:00000000 r9:00000002 r8:c1205048 r7:c2784000 r6:c2785e44 r5:c28a9f00
[828214.683714] r4:ffffe000
[828214.683741] [] (schedule) from [] (schedule_preempt_disabled+0x18/0x1c)
[828214.683758] r5:ffffe000 r4:c269ad40
[828214.683785] [] (schedule_preempt_disabled) from [] (__mutex_lock.constprop.9+0x344/0x58c)
[828214.683811] [] (__mutex_lock.constprop.9) from [] (__mutex_lock_slowpath+0x1c/0x20)
[828214.683831] r10:c1203d00 r9:c269a800 r8:c1203d00 r7:c1203d00 r6:c269b000 r5:c269a800
[828214.683847] r4:c269ad40
[828214.683872] [] (__mutex_lock_slowpath) from [] (mutex_lock+0x5c/0x60)
[828214.683897] [] (mutex_lock) from [] (device_reset+0x28/0x54)
[828214.683915] r5:c269a800 r4:c269ad40
[828214.683941] [] (device_reset) from [] (scsi_eh_ready_devs+0x4ec/0x8fc)
[828214.683958] r5:c28e82a8 r4:c2785f34
[828214.683983] [] (scsi_eh_ready_devs) from [] (scsi_error_handler+0x3d8/0x3e0)
[828214.684003] r10:c087c2f4 r9:c269a974 r8:c1205048 r7:c2785f34 r6:ffffe000 r5:c2785f3c
[828214.684019] r4:c269a800
[828214.684044] [] (scsi_error_handler) from [] (kthread+0x170/0x174)
[828214.684065] r10:c1b11944 r9:c269a800 r8:c087e5a0 r7:c2784000 r6:00000000 r5:c27936c0
[828214.684080] r4:c26fc600
[828214.684102] [] (kthread) from [] (ret_from_fork+0x14/0x28)
[828214.684119] Exception stack(0xc2785fb0 to 0xc2785ff8)
[828214.684138] 5fa0: 00000000 00000000 00000000 00000000
[828214.684157] 5fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[828214.684175] 5fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[828214.684195] r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02458e0
[828214.684211] r4:c27936c0
[828214.684230] INFO: task usb-storage:93 blocked for more than 614 seconds.
[828214.684246] Tainted: G C 5.10.17-v7l+ #1403
[828214.684261] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[828214.684276] task:usb-storage state:D stack: 0 pid: 93 ppid: 2 flags:0x00000000
[828214.684307] Backtrace:
[828214.684344] [] (__schedule) from [] (schedule+0x68/0xe4)
[828214.684365] r10:0000001f r9:00000002 r8:7fffffff r7:c1205048 r6:c269adf0 r5:c28abe00
[828214.684381] r4:ffffe000
[828214.684404] [] (schedule) from [] (schedule_timeout+0x2e8/0x384)
[828214.684421] r5:c1205048 r4:c269adec
[828214.684446] [] (schedule_timeout) from [] (wait_for_completion+0xb8/0x138)
[828214.684466] r9:00000002 r8:7fffffff r7:ffffe000 r6:c269adf0 r5:c1205048 r4:c269adec
[828214.684490] [] (wait_for_completion) from [] (usb_sg_wait+0x168/0x190)
[828214.684510] r9:00001000 r8:00000000 r7:00000000 r6:c269adec r5:00000001 r4:c269adcc
[828214.684532] [] (usb_sg_wait) from [] (usb_stor_bulk_transfer_sglist.part.2+0x80/0xdc)
[828214.684553] r9:00001000 r8:c269ad64 r7:00001000 r6:c0008280 r5:c269adcc r4:c269ad40
[828214.684575] [] (usb_stor_bulk_transfer_sglist.part.2) from [] (usb_stor_bulk_srb+0x58/0x84)
[828214.684594] r8:c1205048 r7:00000000 r6:c28e82a8 r5:c28e82a8 r4:c1205048
[828214.684616] [] (usb_stor_bulk_srb) from [] (usb_stor_Bulk_transport+0x128/0x384)
[828214.684633] r5:ded3b000 r4:c269ad40
[828214.684655] [] (usb_stor_Bulk_transport) from [] (usb_stor_invoke_transport+0x40/0x4c4)
[828214.684675] r10:c1b1197c r9:c269ad40 r8:00000000 r7:c1205048 r6:c1205048 r5:c28e82a8
[828214.684691] r4:c269ad40
[828214.684713] [] (usb_stor_invoke_transport) from [] (usb_stor_transparent_scsi_command+0x18/0x1c)
[828214.684733] r10:c1b1197c r9:c269ad40 r8:00000000 r7:c28e82a8 r6:c1205048 r5:c269ae0c
[828214.684749] r4:c269ad40
[828214.684771] [] (usb_stor_transparent_scsi_command) from [] (usb_stor_control_thread+0x19c/0x2a8)
[828214.684794] [] (usb_stor_control_thread) from [] (kthread+0x170/0x174)
[828214.684813] r8:c093b69c r7:c28a6000 r6:00000000 r5:c2793880 r4:c26fc680
[828214.684833] [] (kthread) from [] (ret_from_fork+0x14/0x28)
[828214.684850] Exception stack(0xc28a7fb0 to 0xc28a7ff8)
[828214.684868] 7fa0: 00000000 00000000 00000000 00000000
[828214.684887] 7fc0: 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000
[828214.684906] 7fe0: 00000000 00000000 00000000 00000000 00000013 00000000
[828214.684925] r10:00000000 r9:00000000 r8:00000000 r7:00000000 r6:00000000 r5:c02458e0
[828214.684941] r4:c2793880
[828214.684970] INFO: task pool:2726 blocked for more than 122 seconds.
[828214.684987] Tainted: G C 5.10.17-v7l+ #1403
[828214.685002] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
[828214.685018] task:pool state:D stack: 0 pid: 2726 ppid: 1 flags:0x00000000
[828214.685048] Backtrace:
[828214.685085] [] (__schedule) from [] (schedule+0x68/0xe4)
[828214.685106] r10:00000000 r9:00000000 r8:c20f4d90 r7:4800005d r6:c20f4d80 r5:d15e4d80
[828214.685121] r4:ffffe000
[828214.685145] [] (schedule) from [] (scsi_block_when_processing_errors+0xd0/0xd8)
[828214.685162] r5:c1205048 r4:c269b000
[828214.685186] [] (scsi_block_when_processing_errors) from [] (sd_open+0x38/0x14c)
[828214.685203] r5:c269b000 r4:c27a3000
[828214.685227] [] (sd_open) from [] (__blkdev_get+0x1fc/0x674)
[828214.685246] r7:00000000 r6:00000000 r5:c27a3400 r4:c20f4d80
[828214.685270] [] (__blkdev_get) from [] (blkdev_get+0x58/0xc8)
[828214.685290] r10:cfa2be10 r9:00000000 r8:c048aed0 r7:c6ceccc0 r6:00000000 r5:c20f4d80
[828214.685306] r4:4800005d
[828214.685329] [] (blkdev_get) from [] (blkdev_open+0x90/0x9c)
[828214.685347] r7:c6ceccc8 r6:c27a6eb8 r5:c20f4d80 r4:c6ceccc0
[828214.685373] [] (blkdev_open) from [] (do_dentry_open+0x148/0x3ec)
[828214.685391] r5:00020800 r4:c6ceccc0
[828214.685415] [] (do_dentry_open) from [] (vfs_open+0x3c/0x40)
[828214.685435] r9:00000000 r8:cfa2bef0 r7:c6ceccc0 r6:00000000 r5:00020800 r4:00000000
[828214.685459] [] (vfs_open) from [] (path_openat+0xb9c/0x1014)
[828214.685481] [] (path_openat) from [] (do_filp_open+0x84/0xec)
[828214.685501] r10:ffffff9c r9:00000000 r8:00000001 r7:cfa2bef0 r6:cfa2be10 r5:c1205048
[828214.685516] r4:c1205048
[828214.685538] [] (do_filp_open) from [] (do_sys_openat2+0x234/0x2f8)
[828214.685557] r8:00000000 r7:0185f2a0 r6:c277e000 r5:c1205048 r4:0000000e
[828214.685581] [] (do_sys_openat2) from [] (do_sys_open+0x98/0xd4)
[828214.685600] r10:00000142 r9:cfa2a000 r8:0185f2a0 r7:00000000 r6:00000000 r5:ffffff9c
[828214.685615] r4:c1205048
[828214.685639] [] (do_sys_open) from [] (sys_openat+0x1c/0x20)
[828214.685659] r8:c0200204 r7:00000142 r6:00000000 r5:0007b098 r4:00000000
[828214.685682] [] (sys_openat) from [] (ret_fast_syscall+0x0/0x28)
[828214.685699] Exception stack(0xcfa2bfa8 to 0xcfa2bff0)
[828214.685718] bfa0: 00000000 0007b098 ffffff9c 0185f2a0 00020800 00000000
[828214.685739] bfc0: 00000000 0007b098 00000000 00000142 0007b098 b57fec10 b57feb6c b57feb6c
[828214.685756] bfe0: 00000002 b57feab8 00000000 b6990da0

When I try to downgrade kernel with
sudo rpi-update e1050e94821a70b2e4c72b318d6c6c968552e9a2

i get the message :

*** Raspberry Pi firmware updater by Hexxeh, enhanced by AndrewS and Dom
*** Performing self-update
*** Relaunching after update
*** Raspberry Pi firmware updater by Hexxeh, enhanced by AndrewS and Dom
*** We're running for the first time
*** Backing up files (this will take a few minutes)
*** Backing up firmware
*** Backing up modules 5.10.17-v7l+
Partition size 255M may not be sufficient for new Pi4 files
This could result in a system that will not boot.
256M FAT partition is recommended. Ensure you have a backup if continuing.
Would you like to proceed? (y/N)

Is it safe to proceed?

@pelwell
Copy link
Contributor

pelwell commented Mar 31, 2021

Provided you've got about 60MB free in your boot partition you should be fine. It's disappointing that the creator of the distribution didn't make it 1MB larger just to avoid that warning.

@pelwell
Copy link
Contributor

pelwell commented Mar 31, 2021

How is the WD drive powered? The Pi's USB sockets can't provide enough current for HDDs under load, and even SSDs can be marginal.

Which chipset does the USB<->SATA adaptor use (lsusb)?

@PetrozPL
Copy link

PetrozPL commented Mar 31, 2021

How is the WD drive powered? The Pi's USB sockets can't provide enough current for HDDs under load, and even SSDs can be marginal.

Which chipset does the USB<->SATA adaptor use (lsusb)?

Both HDDs were externally powered. The USB <-> SATA adaptor is ASM1151, but with dedicated WD firmware programmed (as far as I know It locks adapter to particular HDD with specified size and serial number). That's why it's recognized as :

Bus 002 Device 002: ID 1058:1230 Western Digital Technologies, Inc. My Book (WDBFJK)
Device Descriptor:
bLength 18
bDescriptorType 1
bcdUSB 3.00
bDeviceClass 0
bDeviceSubClass 0
bDeviceProtocol 0
bMaxPacketSize0 9
idVendor 0x1058 Western Digital Technologies, Inc.
idProduct 0x1230 My Book (WDBFJK)
bcdDevice 10.65
iManufacturer 2 Western Digital
iProduct 3 My Book 1230
iSerial 1 574343344E36444356545039
bNumConfigurations 1
Configuration Descriptor:
bLength 9
bDescriptorType 2
wTotalLength 0x002c
bNumInterfaces 1
bConfigurationValue 1
iConfiguration 0
bmAttributes 0xc0
Self Powered
MaxPower 8mA
Interface Descriptor:
bLength 9
bDescriptorType 4
bInterfaceNumber 0
bAlternateSetting 0
bNumEndpoints 2
bInterfaceClass 8 Mass Storage
bInterfaceSubClass 6 SCSI
bInterfaceProtocol 80 Bulk-Only
iInterface 0
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x81 EP 1 IN
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0400 1x 1024 bytes
bInterval 0
bMaxBurst 15
Endpoint Descriptor:
bLength 7
bDescriptorType 5
bEndpointAddress 0x02 EP 2 OUT
bmAttributes 2
Transfer Type Bulk
Synch Type None
Usage Type Data
wMaxPacketSize 0x0400 1x 1024 bytes
bInterval 0
bMaxBurst 15
Binary Object Store Descriptor:
bLength 5
bDescriptorType 15
wTotalLength 0x0016
bNumDeviceCaps 2
USB 2.0 Extension Device Capability:
bLength 7
bDescriptorType 16
bDevCapabilityType 2
bmAttributes 0x0000f41e
BESL Link Power Management (LPM) Supported
BESL value 1024 us
Deep BESL value 61440 us
SuperSpeed USB Device Capability:
bLength 10
bDescriptorType 16
bDevCapabilityType 3
bmAttributes 0x00
wSpeedsSupported 0x000e
Device can operate at Full Speed (12Mbps)
Device can operate at High Speed (480Mbps)
Device can operate at SuperSpeed (5Gbps)
bFunctionalitySupport 1
Lowest fully-functional device speed is Full Speed (12Mbps)
bU1DevExitLat 10 micro seconds
bU2DevExitLat 2047 micro seconds
can't get debug descriptor: Resource temporarily unavailable
Device Status: 0x000d
Self Powered
U1 Enabled
U2 Enabled

Previous HDD I've tested was using the same chip, but with cleared EEPROM, so It wasn't recognized as WD anymore.

The same configuration was working great on RPI2. I've switched to RPI4 few months ago, for better wr/rd speeds over USB. And all this time I've struggled with this random USB crashes every 1-3 days. Few days ago I've switched to other HDD and the problem still occures.

Provided you've got about 60MB free in your boot partition you should be fine. It's disappointing that the creator of the distribution didn't make it 1MB larger just to avoid that warning.

I still have ~200MiB free on boot partition.

/dev/mmcblk0p6 258094 48784 209310 19% /boot

@pelwell
Copy link
Contributor

pelwell commented Mar 31, 2021

And which power supply is the Pi 4 using?

@PetrozPL
Copy link

PetrozPL commented Mar 31, 2021

And which power supply is the Pi 4 using?

It uses 5V 3A dedicated RPI4 power supply, same as this one:

https://kamami.pl/zasilacze/575564-zasilacz-5v3a-usb-c-do-raspberry-pi-4-czarny.html

@githubharald
Copy link
Author

githubharald commented Mar 31, 2021

I tested using an external powered USB hub, but this did not make a difference (see original post).
So it is really just the kernel and not something related to power.

popcornmix pushed a commit that referenced this issue Feb 6, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Feb 6, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Feb 6, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Feb 6, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Feb 13, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
backslashxx pushed a commit to backslashxx/android_karnol_ximi_fog that referenced this issue Feb 14, 2024
commit a01ba2a3378be85538e0183ae5367c1bc1d5aaf3 upstream.

See raspberrypi/linux#3981

Two read-modify-write cycles on ep->ep_state are not guarded by
xhci->lock. Fix these.

Fixes: f524946 ("xhci: Clear the host side toggle manually when endpoint is soft reset")
Cc: stable@vger.kernel.org
Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
Signed-off-by: Mathias Nyman <mathias.nyman@linux.intel.com>
Link: https://lore.kernel.org/r/20211008092547.3996295-2-mathias.nyman@linux.intel.com
Signed-off-by: Greg Kroah-Hartman <gregkh@linuxfoundation.org>
popcornmix pushed a commit that referenced this issue Feb 19, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Feb 19, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Feb 19, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Feb 23, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Feb 23, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Mar 5, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Mar 5, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Mar 5, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Mar 11, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Mar 11, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Mar 19, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Mar 19, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Mar 27, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Mar 27, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Mar 27, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Apr 3, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Apr 5, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Apr 5, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Apr 8, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Apr 11, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Apr 16, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Apr 16, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Apr 18, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
popcornmix pushed a commit that referenced this issue Apr 23, 2024
See #3981

An unknown unsafe memory access can result in the ep_state variable
in xhci_virt_ep being trampled with a stuck SET_DEQ_PENDING state
despite successful completion of a Set TR Deq Pointer command.

All URB enqueue/dequeue calls for the endpoint will fail in this state
so no transfers are possible until the device is reconnected.

As a workaround, clear the flag if we see it set and issue a new Set
TR Deq command anyway - this should be harmless, as a prior Set TR Deq
command will only have been issued in the Stopped state, and if the
endpoint is Running then the controller is required to ignore it and
respond with a Context State Error event TRB.

Signed-off-by: Jonathan Bell <jonathan@raspberrypi.com>
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests