kernel crash/disc errors when unbinding USB devices

From: Helge Deller
Date: Sun Jan 23 2022 - 05:41:16 EST


On all kernels 5.15.x and 5.16.x I noticed that resetting
the USB devices with this shell script:

for i in $(ls /sys/bus/pci/drivers/ahci/|grep :)
do
echo $i
echo $i >/sys/bus/pci/drivers/ahci/unbind
sleep 1
echo $i >/sys/bus/pci/drivers/ahci/bind
done
# reseting USB3 ports (if there none you'll get errors)
for i in $(ls /sys/bus/pci/drivers/xhci_hcd/|grep :)
do
echo $i
echo $i >/sys/bus/pci/drivers/xhci_hcd/unbind
sleep 1
echo $i >/sys/bus/pci/drivers/xhci_hcd/bind
done

immediately leads to a non-functional system, because the discs
face I/O errors and will switch to read-only mode.
Effectively I have to reboot the machine.

It's reproduceable for me on two completely different x86 machines with
different USB devices.

[ 135.353699] ata2.00: disabled
[ 135.354086] blk_update_request: I/O error, dev sda, sector 0 op 0x1:(WRITE) flags 0x800 phys_seg 0 prio class 0
[ 135.362288] systemd-journald[692]: /var/log/journal/3420f8e4f3db4228b3a4dbc10b626a89/user-1000.journal: IO error, rotating.
[ 135.362402] Aborting journal on device dm-0-8.
[ 135.362405] Buffer I/O error on dev dm-0, logical block 8945664, lost sync page write
[ 135.362407] JBD2: Error -5 detected when updating journal superblock for dm-0-8.
[ 135.362433] EXT4-fs error (device dm-0): ext4_journal_check_start:83: comm systemd-journal: Detected aborted journal
[ 135.362444] Buffer I/O error on dev dm-0, logical block 0, lost sync page write
[ 135.362446] EXT4-fs (dm-0): I/O error while writing superblock
[ 135.362447] EXT4-fs (dm-0): Remounting filesystem read-only
[ 135.362488] systemd-journald[692]: Failed to create new system journal: Read-only file system
[ 135.362507] systemd-journald[692]: Failed to rotate /var/log/journal/3420f8e4f3db4228b3a4dbc10b626a89/user-1000.journal: Read-only file system
[ 135.362840] sd 1:0:0:0: [sda] Synchronizing SCSI cache
[ 135.362877] sd 1:0:0:0: [sda] Synchronize Cache(10) failed: Result: hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK
[ 135.362879] sd 1:0:0:0: [sda] Stopping disk
[ 135.362887] sd 1:0:0:0: [sda] Start/Stop Unit failed: Result: hostbyte=DID_BAD_TARGET driverbyte=DRIVER_OK
[ 135.367873] ata4.00: disabled
[ 135.460633] ahci 0000:00:1f.2: AHCI 0001.0300 32 slots 6 ports 6 Gbps 0x3f impl SATA mode
[ 135.460642] ahci 0000:00:1f.2: flags: 64bit ncq led clo pio slum part ems apst
[ 135.483579] scsi host0: ahci
[ 135.483727] scsi host2: ahci
[ 135.484634] scsi host3: ahci
[ 135.484863] scsi host4: ahci
[ 135.485011] scsi host5: ahci
[ 135.487211] scsi host6: ahci
[ 135.487277] ata7: SATA max UDMA/133 abar m2048@0xf7e12000 port 0xf7e12100 irq 27
[ 135.487281] ata8: SATA max UDMA/133 abar m2048@0xf7e12000 port 0xf7e12180 irq 27
[ 135.487283] ata9: SATA max UDMA/133 abar m2048@0xf7e12000 port 0xf7e12200 irq 27
[ 135.487286] ata10: SATA max UDMA/133 abar m2048@0xf7e12000 port 0xf7e12280 irq 27
[ 135.487288] ata11: SATA max UDMA/133 abar m2048@0xf7e12000 port 0xf7e12300 irq 27
[ 135.487290] ata12: SATA max UDMA/133 abar m2048@0xf7e12000 port 0xf7e12380 irq 27
[ 135.489530] xhci_hcd 0000:00:14.0: remove, state 4
[ 135.489536] usb usb4: USB disconnect, device number 1
[ 135.489676] xhci_hcd 0000:00:14.0: USB bus 4 deregistered
[ 135.489722] xhci_hcd 0000:00:14.0: remove, state 4
[ 135.489725] usb usb3: USB disconnect, device number 1
[ 135.491089] xhci_hcd 0000:00:14.0: USB bus 3 deregistered
[ 135.491799] xhci_hcd 0000:00:14.0: xHCI Host Controller
[ 135.491874] xhci_hcd 0000:00:14.0: new USB bus registered, assigned bus number 3
[ 135.589413] xhci_hcd 0000:00:14.0: hcc params 0x20007181 hci version 0x100 quirks 0x000000000000b930
[ 135.589551] usb usb3: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.15
[ 135.589553] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 135.589555] usb usb3: Product: xHCI Host Controller
[ 135.589555] usb usb3: Manufacturer: Linux 5.15.16-100.fc34.x86_64 xhci-hcd
[ 135.589556] usb usb3: SerialNumber: 0000:00:14.0
[ 135.589665] hub 3-0:1.0: USB hub found
[ 135.589673] hub 3-0:1.0: 4 ports detected
[ 135.589963] xhci_hcd 0000:00:14.0: xHCI Host Controller
[ 135.590023] xhci_hcd 0000:00:14.0: new USB bus registered, assigned bus number 4
[ 135.590027] xhci_hcd 0000:00:14.0: Host supports USB 3.0 SuperSpeed
[ 135.590052] usb usb4: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.15
[ 135.590053] usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 135.590054] usb usb4: Product: xHCI Host Controller
[ 135.590055] usb usb4: Manufacturer: Linux 5.15.16-100.fc34.x86_64 xhci-hcd
[ 135.590056] usb usb4: SerialNumber: 0000:00:14.0
[ 135.590163] hub 4-0:1.0: USB hub found
[ 135.590171] hub 4-0:1.0: 4 ports detected
[ 135.590679] xhci_hcd 0000:07:00.0: remove, state 4
[ 135.590682] usb usb6: USB disconnect, device number 1
[ 135.590973] xhci_hcd 0000:07:00.0: USB bus 6 deregistered
[ 135.591031] xhci_hcd 0000:07:00.0: remove, state 4
[ 135.591034] usb usb5: USB disconnect, device number 1
[ 135.652952] xhci_hcd 0000:07:00.0: USB bus 5 deregistered
[ 135.653711] xhci_hcd 0000:07:00.0: xHCI Host Controller
[ 135.653767] xhci_hcd 0000:07:00.0: new USB bus registered, assigned bus number 5
[ 135.714880] xhci_hcd 0000:07:00.0: hcc params 0x0200f180 hci version 0x96 quirks 0x0000000000080000
[ 135.715135] usb usb5: New USB device found, idVendor=1d6b, idProduct=0002, bcdDevice= 5.15
[ 135.715137] usb usb5: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 135.715138] usb usb5: Product: xHCI Host Controller
[ 135.715139] usb usb5: Manufacturer: Linux 5.15.16-100.fc34.x86_64 xhci-hcd
[ 135.715140] usb usb5: SerialNumber: 0000:07:00.0
[ 135.715233] hub 5-0:1.0: USB hub found
[ 135.715241] hub 5-0:1.0: 2 ports detected
[ 135.715349] xhci_hcd 0000:07:00.0: xHCI Host Controller
[ 135.715380] xhci_hcd 0000:07:00.0: new USB bus registered, assigned bus number 6
[ 135.715382] xhci_hcd 0000:07:00.0: Host supports USB 3.0 SuperSpeed
[ 135.715403] usb usb6: We don't know the algorithms for LPM for this host, disabling LPM.
[ 135.715420] usb usb6: New USB device found, idVendor=1d6b, idProduct=0003, bcdDevice= 5.15
[ 135.715422] usb usb6: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 135.715423] usb usb6: Product: xHCI Host Controller
[ 135.715423] usb usb6: Manufacturer: Linux 5.15.16-100.fc34.x86_64 xhci-hcd
[ 135.715424] usb usb6: SerialNumber: 0000:07:00.0
[ 135.715538] hub 6-0:1.0: USB hub found
[ 135.715546] hub 6-0:1.0: 2 ports detected
[ 135.796106] ata9: SATA link down (SStatus 0 SControl 300)
[ 135.796140] ata12: SATA link down (SStatus 0 SControl 300)
[ 135.796167] ata8: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[ 135.796192] ata7: SATA link down (SStatus 0 SControl 300)
[ 135.797107] ata11: SATA link down (SStatus 0 SControl 300)
[ 135.798169] ACPI BIOS Error (bug): Could not resolve symbol [\_SB.PCI0.SAT0.SPT1._GTF.DSSP], AE_NOT_FOUND (20210730/psargs-330)
[ 135.798182] ACPI Error: Aborting method \_SB.PCI0.SAT0.SPT1._GTF due to previous error (AE_NOT_FOUND) (20210730/psparse-529)
[ 135.798269] ata8.00: supports DRM functions and may not be fully accessible
[ 135.798275] ata8.00: ATA-9: Samsung SSD 850 PRO 512GB, EXM01B6Q, max UDMA/133
[ 135.803083] ata8.00: NCQ Send/Recv Log not supported
[ 135.803090] ata8.00: 1000215216 sectors, multi 1: LBA48 NCQ (depth 32), AA
[ 135.812995] ata8.00: Features: Trust Dev-Sleep
[ 135.813262] ACPI BIOS Error (bug): Could not resolve symbol [\_SB.PCI0.SAT0.SPT1._GTF.DSSP], AE_NOT_FOUND (20210730/psargs-330)
[ 135.813274] ACPI Error: Aborting method \_SB.PCI0.SAT0.SPT1._GTF due to previous error (AE_NOT_FOUND) (20210730/psparse-529)
[ 135.813332] ata8.00: supports DRM functions and may not be fully accessible
[ 135.818124] ata8.00: NCQ Send/Recv Log not supported
[ 135.827844] ata8.00: configured for UDMA/133
[ 135.828021] scsi 2:0:0:0: Direct-Access ATA Samsung SSD 850 1B6Q PQ: 0 ANSI: 5
[ 135.828331] sd 2:0:0:0: [sdb] 1000215216 512-byte logical blocks: (512 GB/477 GiB)
[ 135.828348] sd 2:0:0:0: [sdb] Write Protect is off
[ 135.828351] sd 2:0:0:0: [sdb] Mode Sense: 00 3a 00 00
[ 135.828372] sd 2:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[ 135.828392] sd 2:0:0:0: Attached scsi generic sg0 type 0
[ 135.838110] sdb: sdb1 sdb2
[ 135.857216] sd 2:0:0:0: [sdb] supports TCG Opal
[ 135.857220] sd 2:0:0:0: [sdb] Attached SCSI disk
[ 136.055836] ata10: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
[ 136.058655] ACPI BIOS Error (bug): Could not resolve symbol [\_SB.PCI0.SAT0.SPT3._GTF.DSSP], AE_NOT_FOUND (20210730/psargs-330)
[ 136.058667] ACPI Error: Aborting method \_SB.PCI0.SAT0.SPT3._GTF due to previous error (AE_NOT_FOUND) (20210730/psparse-529)
[ 136.058680] ata10.00: ATAPI: HL-DT-ST DVDRAM GH20NS10, EL01, max UDMA/100
[ 136.062508] ACPI BIOS Error (bug): Could not resolve symbol [\_SB.PCI0.SAT0.SPT3._GTF.DSSP], AE_NOT_FOUND (20210730/psargs-330)
[ 136.062521] ACPI Error: Aborting method \_SB.PCI0.SAT0.SPT3._GTF due to previous error (AE_NOT_FOUND) (20210730/psparse-529)
[ 136.062534] ata10.00: configured for UDMA/100
[ 136.174845] scsi 4:0:0:0: CD-ROM HL-DT-ST DVDRAM GH20NS10 EL01 PQ: 0 ANSI: 5
[ 136.322244] sr 4:0:0:0: [sr0] scsi3-mmc drive: 48x/48x writer dvd-ram cd/rw xa/form2 cdda tray
[ 136.450268] sr 4:0:0:0: Attached scsi CD-ROM sr0
[ 136.450352] sr 4:0:0:0: Attached scsi generic sg1 type 5
[ 139.870972] Buffer I/O error on dev dm-0, logical block 5242955, lost async page write
[ 139.870987] Buffer I/O error on dev dm-0, logical block 14157063, lost async page write