[USB VL805 RPI4] Unexpected USB ports failure during high speed USB transfer from Kingston MobileLite Plus USB3.2 card reader

The report names no source file or test. Start by reproducing the failure on a Raspberry Pi 4 with the Kingston reader, concurrent RTLSDR use, and f3write/f3read, then inspect the kernel USB and storage logs alongside issue 5926. Done means the VL805 USB failure is understood and f3read/f3write complete without the reported I/O errors.

Describe the bug

I'm copied data from sdcard using Kingston MobileLite Plus USB3.2 UHS-II micriSD card reader. In background RTLSDR dongle was used.
At some point some unexpected sdcard read failure occurs (the card is ok and reading ok), RTLSDR also stopped to work and disappears from tree.
After that I reconnected RTLSDR and card reader both are detected ok. But when I started f3write test it fails to write at second file.

After reboot all works ok.

I'm using this USB card reader: https://www.aliexpress.com/item/1005004681111603.html

Steps to reproduce the behaviour

Updated: here is steps to reproduce:

1. Install Kingston MobileLite Plus USB3.2 UHS-II micriSD card reader (I bought it here: https://www.aliexpress.com/item/1005004681111603.html)
2. Put Samsung EVO A1 64GB sdcard (I bought it here: https://www.aliexpress.com/item/1005005744366645.html)
3. Run f3write to write test sequence on sdcard
4. Run f3read to read and check the data

Expected result: f3write and f3read is done with no errors

Actual result: I/O error occurs during f3read operation at random position

Device (s)

Raspberry Pi 4 Mod. B

System

$ cat /etc/rpi-issue
Raspberry Pi reference 2023-09-22
Generated using pi-gen, https://github.com/RPi-Distro/pi-gen, 40f37458ae7cadea1aec913ae10b5e7008ebce0a, stage4

$ vcgencmd version
Dec 8 2023 12:36:15
Copyright (c) 2012 Broadcom
version e02d33b3122450accf9dea471a177d3b5623f5ad (clean) (release) (start)

$ uname -a
Linux raspi 6.6.17-v8+ #1 SMP PREEMPT Mon Feb 19 12:11:19 UTC 2024 aarch64 GNU/Linux

Logs

Feb 22 20:44:39 raspi kernel: usb 2-1: new SuperSpeed USB device number 5 using xhci_hcd
Feb 22 20:44:39 raspi kernel: usb 2-1: New USB device found, idVendor=11b0, idProduct=3307, bcdDevice= 0.14
Feb 22 20:44:39 raspi kernel: usb 2-1: New USB device strings: Mfr=3, Product=4, SerialNumber=2
Feb 22 20:44:39 raspi kernel: usb 2-1: Product: UHSII uSD Reader
Feb 22 20:44:39 raspi kernel: usb 2-1: Manufacturer: Kingston
Feb 22 20:44:39 raspi kernel: usb 2-1: SerialNumber: 2021050000****
Feb 22 20:44:39 raspi kernel: usb-storage 2-1:1.0: USB Mass Storage device detected
Feb 22 20:44:39 raspi kernel: scsi host0: usb-storage 2-1:1.0
Feb 22 20:44:39 raspi mtp-probe[359887]: checking bus 2, device 5: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb2/2-1"
Feb 22 20:44:39 raspi mtp-probe[359887]: bus: 2, device: 5 was not an MTP device
Feb 22 20:44:39 raspi mtp-probe[359897]: checking bus 2, device 5: "/sys/devices/platform/scb/fd500000.pcie/pci0000:00/0000:00:00.0/0000:01:00.0/usb2/2-1"
Feb 22 20:44:39 raspi mtp-probe[359897]: bus: 2, device: 5 was not an MTP device
Feb 22 20:44:40 raspi kernel: scsi 0:0:0:0: Direct-Access     Kingston UHSII uSD Reader 0014 PQ: 0 ANSI: 6
Feb 22 20:44:40 raspi kernel: sd 0:0:0:0: Attached scsi generic sg0 type 0
Feb 22 20:44:41 raspi kernel: sd 0:0:0:0: [sda] Spinning up disk...
Feb 22 20:44:44 raspi kernel: ..
Feb 22 20:44:44 raspi kernel: sd 0:0:0:0: [sda] Media removed, stopped polling
Feb 22 20:44:44 raspi kernel: sd 0:0:0:0: [sda] Attached SCSI removable disk
Feb 22 20:44:49 raspi kernel: sd 0:0:0:0: [sda] 61067264 512-byte logical blocks: (31.3 GB/29.1 GiB)
Feb 22 20:44:49 raspi kernel: sda: detected capacity change from 0 to 61067264
Feb 22 20:44:49 raspi kernel:  sda: sda1
Feb 22 20:44:50 raspi kernel: EXT4-fs (sda1): mounted filesystem 9aee****-42f6-4063-b7ac-707944b**** r/w with ordered data mode. Quota mode: none.
Feb 22 20:44:50 raspi udisksd[636]: Mounted /dev/sda1 at /media/pi/arch-usb2023 on behalf of uid 1000
Feb 22 20:45:00 raspi xdg-desktop-por[1309]: A backend call failed: Inhibiting other than idle not supported
Feb 22 20:45:34 raspi kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s
Feb 22 20:45:34 raspi kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x2 [current] 
Feb 22 20:45:34 raspi kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x3a ASCQ=0x0 
Feb 22 20:45:34 raspi kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 00 01 08 00 00 f8 00
Feb 22 20:45:34 raspi kernel: I/O error, dev sda, sector 264 op 0x0:(READ) flags 0x80700 phys_seg 31 prio class 2
Feb 22 20:45:34 raspi kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s
Feb 22 20:45:34 raspi kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x2 [current] 
Feb 22 20:45:34 raspi kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x3a ASCQ=0x0 
Feb 22 20:45:34 raspi kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 00 01 08 00 00 08 00
Feb 22 20:45:34 raspi kernel: I/O error, dev sda, sector 264 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2
Feb 22 20:45:34 raspi kernel: Buffer I/O error on dev sda, logical block 33, async page read
Feb 22 20:45:34 raspi kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s
Feb 22 20:45:34 raspi kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x2 [current] 
Feb 22 20:45:34 raspi kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x3a ASCQ=0x0 
Feb 22 20:45:34 raspi kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 00 01 08 00 00 08 00
Feb 22 20:45:34 raspi kernel: I/O error, dev sda, sector 264 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2
Feb 22 20:45:34 raspi kernel: Buffer I/O error on dev sda, logical block 33, async page read
Feb 22 20:45:34 raspi kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x00 driverbyte=DRIVER_OK cmd_age=0s
Feb 22 20:45:34 raspi kernel: sd 0:0:0:0: [sda] tag#0 Sense Key : 0x2 [current] 
Feb 22 20:45:34 raspi kernel: sd 0:0:0:0: [sda] tag#0 ASC=0x3a ASCQ=0x0 
Feb 22 20:45:34 raspi kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 00 01 08 00 00 08 00
Feb 22 20:45:34 raspi kernel: I/O error, dev sda, sector 264 op 0x0:(READ) flags 0x0 phys_seg 1 prio class 2
Feb 22 20:45:34 raspi kernel: Buffer I/O error on dev sda, logical block 33, async page read
Feb 22 20:45:34 raspi kernel: sda: detected capacity change from 61067264 to 0
Feb 22 20:45:34 raspi udisksd[636]: Cleaning up mount point /media/pi/arch-usb2023 (device 8:1 no longer exists)
Feb 22 20:45:34 raspi kernel: EXT4-fs (sda1): unmounting filesystem 9aee****-42f6-4063-b7ac-707944be****.
Feb 22 20:45:34 raspi systemd[1]: media-pi-arch\x2dusb2023.mount: Deactivated successfully.
Feb 22 20:45:34 raspi kernel: sd 0:0:0:0: [sda] tag#0 access beyond end of device
Feb 22 20:45:34 raspi kernel: I/O error, dev sda, sector 2048 op 0x1:(WRITE) flags 0x800 phys_seg 1 prio class 2
Feb 22 20:45:34 raspi kernel: Buffer I/O error on dev sda1, logical block 0, lost sync page write
Feb 22 20:45:34 raspi kernel: EXT4-fs (sda1): I/O error while writing superblock
Feb 22 20:46:24 raspi kernel: usb 1-1.4.1: USB disconnect, device number 9
Feb 22 20:46:56 raspi kernel: sd 0:0:0:0: [sda] 15523840 512-byte logical blocks: (7.95 GB/7.40 GiB)
Feb 22 20:46:56 raspi kernel: sda: detected capacity change from 0 to 15523840
Feb 22 20:46:56 raspi kernel:  sda: sda1
Feb 22 20:46:56 raspi kernel: FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck.
Feb 22 20:46:56 raspi udisksd[636]: Mounted /dev/sda1 at /media/pi/****-0064 on behalf of uid 1000
Feb 22 20:47:07 raspi xdg-desktop-por[1309]: A backend call failed: Inhibiting other than idle not supported

Additional context

This issue may be related with this one: https://github.com/raspberrypi/linux/issues/5926

It has very different log errors, but there is definitely some critical bug in USB driver for RPI4 VL805 chip which cause a lot of USB failure errors.