Hi!
I have an external 2 disk hd enclosure with a UASP capable JMicron USB 3 bridge:
[ 1.271826] usb 4-1: New USB device found, idVendor=152d, idProduct=9561
[ 1.271952] usb 4-1: New USB device strings: Mfr=1, Product=2, SerialNumber=5
[ 1.272075] usb 4-1: Product: JMS56x Series
[ 1.272180] usb 4-1: Manufacturer: JMicron
As the disks are only used for backup, I stop them after some idle time using "sg_start -readonly --stop".
Normally, the drive automatically spins up in about 5 seconds at the first IO and everything works fine.
Unfortunately, every now and then, though the drive spins up as usually, IO hangs, followed by an IO error and a USB bus reset:
Feb 28 09:15:42 apu kernel: [130773.500866] sd 2:0:0:1: [sdc] tag#0 uas_eh_abort_handler 0 uas-tag 1 inflight: CMD IN
Feb 28 09:15:42 apu kernel: [130773.500869] sd 2:0:0:1: [sdc] tag#0 CDB: Read(16) 88 00 00 00 00 00 08 00 10 02 00 00 00 01 00 00
Feb 28 09:15:42 apu kernel: [130773.500992] scsi host2: uas_eh_bus_reset_handler start
Feb 28 09:15:42 apu kernel: [130773.606321] usb 4-1: reset SuperSpeed USB device number 2 using xhci_hcd
Feb 28 09:15:42 apu kernel: [130773.624511] scsi host2: uas_eh_bus_reset_handler success
Feb 28 09:15:46 apu kernel: [130777.867050] xhci_hcd 0000:03:00.0: Cannot set link state.
Feb 28 09:15:46 apu kernel: [130777.867056] usb usb4-port1: cannot disable (err = -32)
Feb 28 09:15:46 apu kernel: [130777.867061] usb 4-1: USB disconnect, device number 2
Feb 28 09:15:46 apu kernel: [130777.867174] xhci_hcd 0000:03:00.0: ERROR Transfer event for disabled endpoint or incorrect stream ring
Feb 28 09:15:46 apu kernel: [130777.867178] xhci_hcd 0000:03:00.0: @000000045852e810 00000000 00000000 1a000000 01058001
Feb 28 09:15:46 apu kernel: [130777.867218] sd 2:0:0:1: [sdc] tag#0 uas_zap_pending 0 uas-tag 1 inflight: CMD
Feb 28 09:15:46 apu kernel: [130777.867221] sd 2:0:0:1: [sdc] tag#0 CDB: Test Unit Ready 00 00 00 00 00 00
Feb 28 09:15:46 apu kernel: [130777.867240] sd 2:0:0:1: Device offlined - not ready after error recovery
Feb 28 09:15:46 apu kernel: [130777.867246] sd 2:0:0:1: [sdc] tag#0 FAILED Result: hostbyte=DID_OK driverbyte=DRIVER_TIMEOUT
Feb 28 09:15:46 apu kernel: [130777.867248] sd 2:0:0:1: [sdc] tag#0 CDB: Read(16) 88 00 00 00 00 00 08 00 10 02 00 00 00 01 00 00
Feb 28 09:15:46 apu kernel: [130777.867250] blk_update_request: I/O error, dev sdc, sector 134221826
Feb 28 09:15:46 apu kernel: [130777.868007] XFS (dm-4): metadata I/O error: block 0x8000002 ("xfs_trans_read_buf_map") error 5 numblks 1
Feb 28 09:15:46 apu kernel: [130777.868038] sd 2:0:0:1: rejecting I/O to offline device
[...]
Feb 28 09:15:46 apu kernel: [130777.994342] sd 2:0:0:0: [sdb] Synchronize Cache(10) failed: Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
Feb 28 09:15:46 apu kernel: [130778.031714] sd 2:0:0:1: [sdc] Synchronizing SCSI cache
Feb 28 09:15:46 apu kernel: [130778.155155] sd 2:0:0:1: [sdc] Synchronize Cache(10) failed: Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
Feb 28 09:15:54 apu kernel: [130785.962545] usb 4-1: new SuperSpeed USB device number 3 using xhci_hcd
Feb 28 09:15:54 apu kernel: [130785.979595] usb 4-1: New USB device found, idVendor=152d, idProduct=9561
Feb 28 09:15:54 apu kernel: [130785.979598] usb 4-1: New USB device strings: Mfr=1, Product=2, SerialNumber=5
Feb 28 09:15:54 apu kernel: [130785.979599] usb 4-1: Product: JMS56x Series
Feb 28 09:15:54 apu kernel: [130785.979601] usb 4-1: Manufacturer: JMicron
Feb 28 09:15:54 apu kernel: [130785.979602] usb 4-1: SerialNumber: 00000000000000000000
Feb 28 09:15:54 apu kernel: [130785.984579] scsi host4: uas
Feb 28 09:15:54 apu kernel: [130785.985113] scsi 4:0:0:0: Direct-Access WDC WD30 PURX-64P6ZY0 0106 PQ: 0 ANSI: 6
Feb 28 09:15:54 apu kernel: [130786.025035] scsi 4:0:0:1: Direct-Access WDC WD30 PURX-64P6ZY0 0106 PQ: 0 ANSI: 6
Feb 28 09:15:54 apu kernel: [130786.071679] sd 4:0:0:0: Attached scsi generic sg1 type 0
Feb 28 09:15:54 apu kernel: [130786.072295] sd 4:0:0:0: [sde] 5860533168 512-byte logical blocks: (3.00 TB/2.73 TiB)
Feb 28 09:15:54 apu kernel: [130786.072548] sd 4:0:0:1: Attached scsi generic sg2 type 0
Feb 28 09:15:54 apu kernel: [130786.079545] sd 4:0:0:1: [sdf] 5860533168 512-byte logical blocks: (3.00 TB/2.73 TiB)
Feb 28 09:15:54 apu kernel: [130786.080979] sd 4:0:0:0: [sde] Write Protect is off
Feb 28 09:15:54 apu kernel: [130786.080982] sd 4:0:0:0: [sde] Mode Sense: 67 00 10 08
Feb 28 09:15:54 apu kernel: [130786.081748] sd 4:0:0:0: [sde] Write cache: enabled, read cache: enabled, supports DPO and FUA
Feb 28 09:15:54 apu kernel: [130786.082351] sd 4:0:0:1: [sdf] Write Protect is off
Feb 28 09:15:54 apu kernel: [130786.082354] sd 4:0:0:1: [sdf] Mode Sense: 67 00 10 08
Feb 28 09:15:54 apu kernel: [130786.083100] sd 4:0:0:1: [sdf] Write cache: enabled, read cache: enabled, supports DPO and FUA
Feb 28 09:15:54 apu kernel: [130786.159798] sde: sde1
Feb 28 09:15:54 apu kernel: [130786.209407] sdf: sdf1
Feb 28 09:15:54 apu kernel: [130786.259963] sd 4:0:0:0: [sde] Attached SCSI disk
Feb 28 09:15:54 apu kernel: [130786.338650] sd 4:0:0:1: [sdf] Attached SCSI disk
or, if not using UAS:
Mar 6 05:01:14 apu spindown.py[19112]: sdc I Drive spun up after 56690 seconds.
Mar 6 05:01:58 apu kernel: [220718.710006] usb 4-1: reset SuperSpeed USB device number 2 using xhci_hcd
Mar 6 05:02:35 apu kernel: [220755.565450] usb 4-1: reset SuperSpeed USB device number 2 using xhci_hcd
Mar 6 05:02:40 apu kernel: [220760.219209] xhci_hcd 0000:03:00.0: Cannot set link state.
Mar 6 05:02:40 apu kernel: [220760.219212] usb usb4-port1: cannot disable (err = -32)
Mar 6 05:02:40 apu kernel: [220760.219217] usb 4-1: USB disconnect, device number 2
Mar 6 05:02:40 apu kernel: [220760.219458] sd 2:0:0:0: Device offlined - not ready after error recovery
Mar 6 05:02:40 apu kernel: [220760.219495] sd 2:0:0:1: [sdc] tag#0 FAILED Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK
Mar 6 05:02:40 apu kernel: [220760.219497] sd 2:0:0:1: [sdc] tag#0 CDB: Read(16) 88 00 00 00 00 00 04 00 10 60 00 00 00 20 00 00
Mar 6 05:02:40 apu kernel: [220760.219498] blk_update_request: I/O error, dev sdc, sector 67113056
Mar 6 05:02:40 apu kernel: [220760.219518] sd 2:0:0:1: [sdc] tag#0 FAILED Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK
Mar 6 05:02:40 apu kernel: [220760.219520] sd 2:0:0:1: [sdc] tag#0 CDB: Write(16) 8a 00 00 00 00 00 10 02 ab 68 00 00 08 00 00 00
Mar 6 05:02:40 apu kernel: [220760.219521] blk_update_request: I/O error, dev sdc, sector 268610408
Mar 6 05:02:40 apu kernel: [220760.219538] sd 2:0:0:1: [sdc] tag#0 FAILED Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK
Mar 6 05:02:40 apu kernel: [220760.219539] sd 2:0:0:1: [sdc] tag#0 CDB: Write(16) 8a 00 00 00 00 00 10 02 b3 68 00 00 08 00 00 00
Mar 6 05:02:40 apu kernel: [220760.219539] blk_update_request: I/O error, dev sdc, sector 268612456
Mar 6 05:02:40 apu kernel: [220760.219555] sd 2:0:0:1: [sdc] tag#0 FAILED Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK
Mar 6 05:02:40 apu kernel: [220760.219556] sd 2:0:0:1: [sdc] tag#0 CDB: Write(16) 8a 00 00 00 00 00 10 02 bb 68 00 00 05 68 00 00
Mar 6 05:02:40 apu kernel: [220760.219557] blk_update_request: I/O error, dev sdc, sector 268614504
Mar 6 05:02:40 apu kernel: [220760.219564] sd 2:0:0:1: [sdc] tag#0 FAILED Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK
Mar 6 05:02:40 apu kernel: [220760.219565] sd 2:0:0:1: [sdc] tag#0 CDB: Write(16) 8a 00 00 00 00 00 40 05 35 26 00 00 00 14 00 00
Mar 6 05:02:40 apu kernel: [220760.219566] blk_update_request: I/O error, dev sdc, sector 1074083110
Mar 6 05:02:40 apu kernel: [220760.219576] XFS (dm-5): metadata I/O error: block 0x40052526 ("xlog_iodone") error 5 numblks 64
Mar 6 05:02:40 apu kernel: [220760.219580] XFS (dm-5): xfs_do_force_shutdown(0x2) called from line 1200 of file fs/xfs/xfs_log.c. Return address = 0xffffffffc05bf38c
Mar 6 05:02:40 apu kernel: [220760.219594] XFS (dm-5): Log I/O Error Detected. Shutting down filesystem
Mar 6 05:02:40 apu kernel: [220760.219595] XFS (dm-5): Please umount the filesystem and rectify the problem(s)
Mar 6 05:02:40 apu kernel: [220760.219603] Buffer I/O error on dev dm-5, logical block 33575789, lost async page write
Mar 6 05:02:40 apu kernel: [220760.219605] XFS (dm-5): xfs_imap_to_bp: xfs_trans_read_buf() returned error -5.
Mar 6 05:02:40 apu kernel: [220760.219607] XFS (dm-5): xfs_do_force_shutdown(0x8) called from line 3420 of file fs/xfs/xfs_inode.c. Return address = 0xffffffffc05b45e1
Mar 6 05:02:40 apu kernel: [220760.219608] Buffer I/O error on dev dm-5, logical block 33575790, lost async page write
[...]
6 05:02:40 apu kernel: [220760.219624] Buffer I/O error on dev dm-5, logical block 33575798, lost async page write
Mar 6 05:02:40 apu kernel: [220760.223238] scsi 2:0:0:0: rejecting I/O to offline device
Mar 6 05:02:40 apu kernel: [220760.223242] scsi 2:0:0:0: [sdb] killing request
Mar 6 05:02:40 apu kernel: [220760.223251] scsi 2:0:0:0: [sdb] FAILED Result: hostbyte=DID_NO_CONNECT driverbyte=DRIVER_OK
Mar 6 05:02:40 apu kernel: [220760.223253] scsi 2:0:0:0: [sdb] CDB: Read(16) 88 00 00 00 00 00 14 00 10 60 00 00 00 20 00 00
Mar 6 05:02:40 apu kernel: [220760.223254] blk_update_request: I/O error, dev sdb, sector 335548512
This is a Zotac ZBOX-CI523NANO box (Intel Skylake):
-[0000:00]-+-00.0 Intel Corporation Skylake Host Bridge/DRAM Registers [8086:1904]
+-02.0 Intel Corporation HD Graphics 520 [8086:1916]
+-08.0 Intel Corporation Skylake Gaussian Mixture Model [8086:1911]
+-14.0 Intel Corporation Sunrise Point-LP USB 3.0 xHCI Controller [8086:9d2f]
If I connect the enclosure to another box (my lenovo x1 carbon) laptop running fedora 24, harddisk spinup seems to work fine, I couldn't reproduce the problem.
I am using a fedora kernel 4.8.16-200.fc24.x86_64 but also tried with several other 4.x kernel versions.
I already tried to
- disable UAS by usb_storage quirk u.
- disable USB autosuspend (power/autosuspend_delay_ms=-1 and power/control=on)
- increase usbcore.initial_descriptor_timeout
Do you have any hints?
Is there any other quirk or retry/timeout parameter I could try?
Thanks,
--leo
--
e-mail ::: Leo.Bergolth (at) wu.ac.at
fax ::: +43-1-31336-906050
location ::: IT-Services | Vienna University of Economics | Austria
--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
