USB3.0 to SATA adapter causes problems

[M-Reimer]

Describe the bug

I have a SATA SSD connected to a USB3.0 to SATA converter.

If I connect this to my Raspberry Pi 4, then the "Access" LED flashes pretty long and I get errors logged (uas_eh_device_reset_handler start)

To reproduce

This is the adapter:
https://www.amazon.de/dp/B079QQJB9L/

If this is used on the Raspberry Pi, it takes pretty long for the kernel to "detect" the SSD drive correctly. I haven't tested reliability while using the drive, so far.

I have tried a powered hub but the errors keep exactly the same.

System

Tried several systems. Up-to-date Raspbian and Arch Linux with several self-compiled kernels. Always the same problem.

Logs

Jul 12 20:38:34 alarmpi kernel: usb 2-1: new SuperSpeed Gen 1 USB device number 4 using xhci_hcd
Jul 12 20:38:34 alarmpi kernel: usb 2-1: New USB device found, idVendor=2109, idProduct=8110, bcdDevice=91.04
Jul 12 20:38:34 alarmpi kernel: usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
Jul 12 20:38:34 alarmpi kernel: usb 2-1: Product: USB3.0 Hub
Jul 12 20:38:34 alarmpi kernel: usb 2-1: Manufacturer: VIA Labs, Inc.
Jul 12 20:38:34 alarmpi kernel: hub 2-1:1.0: USB hub found
Jul 12 20:38:34 alarmpi kernel: hub 2-1:1.0: 4 ports detected
Jul 12 20:38:34 alarmpi kernel: usb 2-1.1: new SuperSpeed Gen 1 USB device number 5 using xhci_hcd
Jul 12 20:38:34 alarmpi kernel: usb 2-1.1: New USB device found, idVendor=152d, idProduct=0578, bcdDevice=32.02
Jul 12 20:38:34 alarmpi kernel: usb 2-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Jul 12 20:38:34 alarmpi kernel: usb 2-1.1: Product: JMS579
Jul 12 20:38:34 alarmpi kernel: usb 2-1.1: Manufacturer: JMicron
Jul 12 20:38:34 alarmpi kernel: usb 2-1.1: SerialNumber: 191951815235
Jul 12 20:38:34 alarmpi kernel: scsi host0: uas
Jul 12 20:38:34 alarmpi kernel: scsi 0:0:0:0: Direct-Access CT240BX5 00SSD1 3202 PQ: 0 ANSI: 6
Jul 12 20:38:34 alarmpi kernel: sd 0:0:0:0: [sda] 468862128 512-byte logical blocks: (240 GB/224 GiB)
Jul 12 20:38:34 alarmpi kernel: sd 0:0:0:0: [sda] 4096-byte physical blocks
Jul 12 20:38:34 alarmpi kernel: sd 0:0:0:0: [sda] Write Protect is off
Jul 12 20:38:34 alarmpi kernel: sd 0:0:0:0: [sda] Mode Sense: 53 00 00 08
Jul 12 20:38:34 alarmpi kernel: sd 0:0:0:0: [sda] Disabling FUA
Jul 12 20:38:34 alarmpi kernel: sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
Jul 12 20:38:34 alarmpi kernel: sd 0:0:0:0: [sda] Optimal transfer size 33553920 bytes not a multiple of physical block size (4096 bytes)
Jul 12 20:38:34 alarmpi kernel: sda: sda1
Jul 12 20:38:34 alarmpi kernel: sd 0:0:0:0: [sda] Attached SCSI disk
Jul 12 20:39:05 alarmpi kernel: sd 0:0:0:0: [sda] tag#5 uas_eh_abort_handler 0 uas-tag 6 inflight: CMD IN
Jul 12 20:39:05 alarmpi kernel: sd 0:0:0:0: [sda] tag#5 CDB: opcode=0x28 28 00 1b f2 41 d8 00 00 28 00
Jul 12 20:39:05 alarmpi kernel: sd 0:0:0:0: [sda] tag#4 uas_eh_abort_handler 0 uas-tag 5 inflight: CMD IN
Jul 12 20:39:05 alarmpi kernel: sd 0:0:0:0: [sda] tag#4 CDB: opcode=0x28 28 00 1b f2 41 28 00 00 a8 00
Jul 12 20:39:05 alarmpi kernel: scsi host0: uas_eh_device_reset_handler start
Jul 12 20:39:05 alarmpi kernel: usb 2-1.1: reset SuperSpeed Gen 1 USB device number 5 using xhci_hcd
Jul 12 20:39:05 alarmpi kernel: scsi host0: uas_eh_device_reset_handler success
Jul 12 20:39:35 alarmpi systemd-udevd[221]: sda: Worker [295] processing SEQNUM=2007 is taking a long time
Jul 12 20:39:36 alarmpi kernel: sd 0:0:0:0: [sda] tag#1 uas_eh_abort_handler 0 uas-tag 2 inflight: CMD IN
Jul 12 20:39:36 alarmpi kernel: sd 0:0:0:0: [sda] tag#1 CDB: opcode=0x28 28 00 1b f2 44 78 00 00 28 00
Jul 12 20:39:36 alarmpi kernel: sd 0:0:0:0: [sda] tag#0 uas_eh_abort_handler 0 uas-tag 1 inflight: CMD IN
Jul 12 20:39:36 alarmpi kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 1b f2 44 08 00 00 68 00
Jul 12 20:39:36 alarmpi kernel: sd 0:0:0:0: [sda] tag#2 uas_eh_abort_handler 0 uas-tag 3 inflight: CMD IN
Jul 12 20:39:36 alarmpi kernel: sd 0:0:0:0: [sda] tag#2 CDB: opcode=0x28 28 00 1b f2 43 b8 00 00 48 00
Jul 12 20:39:36 alarmpi kernel: scsi host0: uas_eh_device_reset_handler start
Jul 12 20:39:36 alarmpi kernel: usb 2-1.1: reset SuperSpeed Gen 1 USB device number 5 using xhci_hcd
Jul 12 20:39:36 alarmpi kernel: scsi host0: uas_eh_device_reset_handler success

[M-Reimer]

I still have the board with the "network problems":
#3034
So I moved the SD card to this board and tried the same SATA adapter.
I have exactly the same problems on this second board.
I can offer the same as I did in #3034: If it helps I can ship this hardware combination if I get paid for the hardware.

The bug is gone if I add an "usb-storage.quirks=152d:0578:u" entry to cmdline.txt but this actually disables the USB 3.0 mode (slower speed).

I guess getting the new RPi 4 working directly from the start was just too good to be true. There seem to be some driver (or even hardware?) issues left. Maybe one of the downsides of being an early adopter.

[M-Reimer]

I got another USB3 to SATA adapter (different chipset). With this one it works immediately without errors and without additional power supply.
Maybe some kind of incompatibility between the JMicron chipset and the VIA USB host?

[P33M]

The quirk setting doesn't disable "USB3.0" mode, it disables UAS. Mass-storage accesses still go at USB3.0 speeds but things like multiple IO threads will be slower.

The adapter VID:PID already has a quirk to disable forced unit addressing but why isn't there a line appearing about a quirks match?

Can you post the output of dmesg after you've plugged the drive in with UAS disabled?

[M-Reimer]

[ 67.911864] usb 2-1: new SuperSpeed Gen 1 USB device number 3 using xhci_hcd
[ 67.942905] usb 2-1: New USB device found, idVendor=152d, idProduct=0578, bcdDevice=32.02
[ 67.942921] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 67.942933] usb 2-1: Product: JMS579
[ 67.942945] usb 2-1: Manufacturer: JMicron
[ 67.942957] usb 2-1: SerialNumber: 191951815235
[ 67.945341] usb 2-1: UAS is blacklisted for this device, using usb-storage instead
[ 67.945425] usb 2-1: UAS is blacklisted for this device, using usb-storage instead
[ 67.945439] usb-storage 2-1:1.0: USB Mass Storage device detected
[ 67.946656] usb-storage 2-1:1.0: Quirks match for vid 152d pid 0578: 1800000
[ 67.946782] scsi host0: usb-storage 2-1:1.0
[ 68.952249] scsi 0:0:0:0: Direct-Access CT240BX5 00SSD1 3202 PQ: 0 ANSI: 6
[ 68.953116] sd 0:0:0:0: Attached scsi generic sg0 type 0
[ 68.953948] sd 0:0:0:0: [sda] 468862128 512-byte logical blocks: (240 GB/224 GiB)
[ 68.955015] sd 0:0:0:0: [sda] Write Protect is off
[ 68.955033] sd 0:0:0:0: [sda] Mode Sense: 47 00 00 08
[ 68.955769] sd 0:0:0:0: [sda] Disabling FUA
[ 68.955786] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[ 68.962294] sda: sda1
[ 68.965266] sd 0:0:0:0: [sda] Attached SCSI disk

[M-Reimer]

OK. I think I can close this one. Either a broken USB 3.0 to SATA adapter or bad Linux support at all. I tried the adapter on my Linux desktop system again. It is detected fast and without errors, but so far I never tried to write to the connected SSD. When doing so, I get the error messages I've added below. I I'll send this adapter back to Amazon.

[ 501.549830] usb 2-4: new SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[ 501.567512] usb 2-4: New USB device found, idVendor=152d, idProduct=0578, bcdDevice=32.02
[ 501.567517] usb 2-4: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 501.567520] usb 2-4: Product: JMS579
[ 501.567523] usb 2-4: Manufacturer: JMicron
[ 501.567526] usb 2-4: SerialNumber: 191951815235
[ 501.594683] usbcore: registered new interface driver usb-storage
[ 501.599729] scsi host6: uas
[ 501.599800] usbcore: registered new interface driver uas
[ 501.600185] scsi 6:0:0:0: Direct-Access CT240BX5 00SSD1 3202 PQ: 0 ANSI: 6
[ 501.600827] sd 6:0:0:0: Attached scsi generic sg2 type 0
[ 501.601439] sd 6:0:0:0: [sdb] 468862128 512-byte logical blocks: (240 GB/224 GiB)
[ 501.601441] sd 6:0:0:0: [sdb] 4096-byte physical blocks
[ 501.601582] sd 6:0:0:0: [sdb] Write Protect is off
[ 501.601583] sd 6:0:0:0: [sdb] Mode Sense: 53 00 00 08
[ 501.601846] sd 6:0:0:0: [sdb] Disabling FUA
[ 501.601847] sd 6:0:0:0: [sdb] Write cache: enabled, read cache: enabled, doesn't support DPO or FUA
[ 501.602086] sd 6:0:0:0: [sdb] Optimal transfer size 33553920 bytes not a multiple of physical block size (4096 bytes)
[ 501.604584] sdb: sdb1
[ 501.605841] sd 6:0:0:0: [sdb] Attached SCSI disk
[ 521.675076] EXT4-fs (sdb1): mounted filesystem with ordered data mode. Opts: (null)
[ 573.203294] sd 6:0:0:0: [sdb] tag#29 uas_eh_abort_handler 0 uas-tag 9 inflight: CMD OUT
[ 573.203302] sd 6:0:0:0: [sdb] tag#29 CDB: Write(10) 2a 00 00 4f a0 00 00 04 00 00
[ 573.205063] sd 6:0:0:0: [sdb] tag#28 uas_eh_abort_handler 0 uas-tag 10 inflight: CMD OUT
[ 573.205070] sd 6:0:0:0: [sdb] tag#28 CDB: Write(10) 2a 00 00 4f a4 00 00 04 00 00
[ 573.208537] sd 6:0:0:0: [sdb] tag#27 uas_eh_abort_handler 0 uas-tag 6 inflight: CMD OUT
[ 573.208544] sd 6:0:0:0: [sdb] tag#27 CDB: Write(10) 2a 00 00 4f 9c 00 00 04 00 00
[ 573.212061] sd 6:0:0:0: [sdb] tag#26 uas_eh_abort_handler 0 uas-tag 5 inflight: CMD OUT
[ 573.212068] sd 6:0:0:0: [sdb] tag#26 CDB: Write(10) 2a 00 00 4f 98 00 00 04 00 00
[ 573.215562] sd 6:0:0:0: [sdb] tag#25 uas_eh_abort_handler 0 uas-tag 4 inflight: CMD OUT
[ 573.215568] sd 6:0:0:0: [sdb] tag#25 CDB: Write(10) 2a 00 00 4f 94 00 00 04 00 00
[ 573.219065] sd 6:0:0:0: [sdb] tag#24 uas_eh_abort_handler 0 uas-tag 3 inflight: CMD OUT
[ 573.219072] sd 6:0:0:0: [sdb] tag#24 CDB: Write(10) 2a 00 00 4f 90 00 00 04 00 00
[ 573.222567] sd 6:0:0:0: [sdb] tag#23 uas_eh_abort_handler 0 uas-tag 8 inflight: CMD OUT
[ 573.222573] sd 6:0:0:0: [sdb] tag#23 CDB: Write(10) 2a 00 00 4f 84 00 00 04 00 00
[ 573.226065] sd 6:0:0:0: [sdb] tag#22 uas_eh_abort_handler 0 uas-tag 7 inflight: CMD OUT
[ 573.226072] sd 6:0:0:0: [sdb] tag#22 CDB: Write(10) 2a 00 00 4f 80 00 00 04 00 00
[ 573.229566] sd 6:0:0:0: [sdb] tag#21 uas_eh_abort_handler 0 uas-tag 2 inflight: CMD OUT
[ 573.229572] sd 6:0:0:0: [sdb] tag#21 CDB: Write(10) 2a 00 00 4f 8c 00 00 04 00 00
[ 573.233067] sd 6:0:0:0: [sdb] tag#20 uas_eh_abort_handler 0 uas-tag 1 inflight: CMD OUT
[ 573.233074] sd 6:0:0:0: [sdb] tag#20 CDB: Write(10) 2a 00 00 4f 88 00 00 04 00 00
[ 573.236568] sd 6:0:0:0: [sdb] tag#0 uas_eh_abort_handler 0 uas-tag 11 inflight: CMD OUT
[ 573.236575] sd 6:0:0:0: [sdb] tag#0 CDB: Write(10) 2a 00 00 4f a8 00 00 04 00 00
[ 573.269992] scsi host6: uas_eh_device_reset_handler start
[ 573.393710] usb 2-4: reset SuperSpeed Gen 1 USB device number 2 using xhci_hcd
[ 573.414256] scsi host6: uas_eh_device_reset_handler success
[ 588.128848] audit: type=1130 audit(1563123443.566:45): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=getty@tty5 comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=success'
[ 591.551783] audit: type=1006 audit(1563123446.989:46): pid=1673 uid=0 old-auid=4294967295 auid=0 tty=tty5 old-ses=4294967295 ses=6 res=1
[ 605.630016] sd 6:0:0:0: [sdb] tag#29 uas_eh_abort_handler 0 uas-tag 1 inflight: CMD OUT
[ 605.630024] sd 6:0:0:0: [sdb] tag#29 CDB: Write(10) 2a 00 00 57 08 00 00 04 00 00
[ 605.630813] sd 6:0:0:0: [sdb] tag#28 uas_eh_abort_handler 0 uas-tag 6 inflight: CMD OUT
[ 605.630820] sd 6:0:0:0: [sdb] tag#28 CDB: Write(10) 2a 00 00 56 d4 00 00 04 00 00
[ 605.634285] sd 6:0:0:0: [sdb] tag#25 uas_eh_abort_handler 0 uas-tag 2 inflight: CMD OUT
[ 605.634292] sd 6:0:0:0: [sdb] tag#25 CDB: Write(10) 2a 00 00 56 f0 00 00 04 00 00
[ 605.637815] sd 6:0:0:0: [sdb] tag#24 uas_eh_abort_handler 0 uas-tag 3 inflight: CMD OUT
[ 605.637821] sd 6:0:0:0: [sdb] tag#24 CDB: Write(10) 2a 00 00 56 e8 00 00 04 00 00
[ 605.641291] sd 6:0:0:0: [sdb] tag#6 uas_eh_abort_handler 0 uas-tag 5 inflight: CMD OUT
[ 605.641298] sd 6:0:0:0: [sdb] tag#6 CDB: Write(10) 2a 00 00 56 f4 00 00 04 00 00
[ 605.644810] sd 6:0:0:0: [sdb] tag#5 uas_eh_abort_handler 0 uas-tag 4 inflight: CMD OUT
[ 605.644817] sd 6:0:0:0: [sdb] tag#5 CDB: Write(10) 2a 00 00 57 0c 00 00 04 00 00
[ 605.648319] sd 6:0:0:0: [sdb] tag#4 uas_eh_abort_handler 0 uas-tag 11 inflight: CMD OUT
[ 605.648325] sd 6:0:0:0: [sdb] tag#4 CDB: Write(10) 2a 00 00 56 ec 00 00 04 00 00
[ 605.651810] sd 6:0:0:0: [sdb] tag#3 uas_eh_abort_handler 0 uas-tag 10 inflight: CMD OUT
[ 605.651817] sd 6:0:0:0: [sdb] tag#3 CDB: Write(10) 2a 00 00 56 e4 00 00 04 00 00
[ 605.655309] sd 6:0:0:0: [sdb] tag#2 uas_eh_abort_handler 0 uas-tag 9 inflight: CMD OUT
[ 605.655316] sd 6:0:0:0: [sdb] tag#2 CDB: Write(10) 2a 00 00 56 e0 00 00 04 00 00
[ 605.658810] sd 6:0:0:0: [sdb] tag#1 uas_eh_abort_handler 0 uas-tag 8 inflight: CMD OUT
[ 605.658816] sd 6:0:0:0: [sdb] tag#1 CDB: Write(10) 2a 00 00 56 dc 00 00 04 00 00
[ 605.662313] sd 6:0:0:0: [sdb] tag#0 uas_eh_abort_handler 0 uas-tag 7 inflight: CMD OUT
[ 605.662320] sd 6:0:0:0: [sdb] tag#0 CDB: Write(10) 2a 00 00 56 d8 00 00 04 00 00

[scottsweb]

I have a USB device with the same chipset and I am seeing similar issues:

[ 4877.471127] sd 1:0:0:0: [sdb] Attached SCSI disk
[ 4908.074308] sd 1:0:0:0: [sdb] tag#21 uas_eh_abort_handler 0 uas-tag 6 inflight: CMD IN 
[ 4908.074326] sd 1:0:0:0: [sdb] tag#21 CDB: opcode=0x28 28 00 1b f2 41 d8 00 00 28 00
[ 4908.074463] sd 1:0:0:0: [sdb] tag#20 uas_eh_abort_handler 0 uas-tag 5 inflight: CMD IN 
[ 4908.074477] sd 1:0:0:0: [sdb] tag#20 CDB: opcode=0x28 28 00 1b f2 41 28 00 00 a8 00
[ 4908.114331] scsi host1: uas_eh_device_reset_handler start
[ 4908.265195] usb 2-2: reset SuperSpeed Gen 1 USB device number 4 using xhci_hcd
[ 4908.300379] scsi host1: uas_eh_device_reset_handler success
[ 4938.794714] sd 1:0:0:0: [sdb] tag#25 uas_eh_abort_handler 0 uas-tag 1 inflight: CMD IN 
[ 4938.794731] sd 1:0:0:0: [sdb] tag#25 CDB: opcode=0x28 28 00 00 00 00 00 00 00 08 00
[ 4938.794861] sd 1:0:0:0: [sdb] tag#23 uas_eh_abort_handler 0 uas-tag 3 inflight: CMD IN 
[ 4938.794875] sd 1:0:0:0: [sdb] tag#23 CDB: opcode=0x28 28 00 1b f2 3f 88 00 00 68 00
[ 4938.834710] scsi host1: uas_eh_device_reset_handler start
[ 4938.985557] usb 2-2: reset SuperSpeed Gen 1 USB device number 4 using xhci_hcd

From lsusb:

lsusb
Bus 003 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 002 Device 002: ID 05dc:a83a Lexar Media, Inc. 
Bus 002 Device 003: ID 152d:0578 JMicron Technology Corp. / JMicron USA Technology Corp. JMS567 SATA 6Gb/s bridge
Bus 002 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 001 Device 002: ID 2109:3431 VIA Labs, Inc. Hub
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

Other commands like blkid are locking up the device.

Is it simply a case of this device being not supported correctly?

[M-Reimer]

Is it simply a case of this device being not supported correctly?

I guess so. At least this is not a "Raspberry Issue". I have exactly the same issue on my Linux desktop system (Intel i5). The correct discussion platform would be maybe the kernel mailing list or I think they also have a BugZilla setup somewhere. But I'm too busy to dig deeper into this. Was way easier to order something different and return the problematic adapter to Amazon.

[yevmoroz]

Have you guys checked this thread https://www.raspberrypi.org/forums/viewtopic.php?t=219434 ?
My current adapter is following https://www.amazon.de/dp/B00OJ3UJ2S where I have issues just as you describe.
I'm thinking of taking this one https://www.amazon.de/gp/product/B018G1RLYC/ as suggested on a thread and try it out.

[yevmoroz]

Also found this thread that provides some explanation to the problem https://www.raspberrypi.org/forums/viewtopic.php?t=245931.

[yevmoroz]

I tried the solution from mentioned thread, just forgot to plug in USB 2.0 port when was testing first. This is actually fine for now until, Thursday when I expect a new adapter :)

[yevmoroz]

Adapter arrived earlier 😏 I can confirm this is working like a charm with a new one. 😎

[pelwell]

What does lsusb show for the new adapter?

[yevmoroz]

Bus 002 Device 002: ID 174c:1153 ASMedia Technology Inc. ASM1153 SATA 3Gb/s bridge

[pelwell]

Thanks - from memory, I also have an adaptor with an ASMedia bridge that works well