Getting UAS working on HK 4.9

Test and fix the Kernel 4.14 features

Moderators: mdrjr, odroid

Re: Getting UAS working on HK 4.9

Unread postby bronco » Thu Jul 27, 2017 2:57 pm

odroid wrote:Meanwhile, you can add this item coherent_pool=1M on the bootargs in boot.ini file as a workaround.


I've seen in OMV forum that this post was mentioned and new OMV image for XU4 available that is said to include this and few more UAS fixes: https://sourceforge.net/projects/openme ... d-XU3_XU4/
bronco
 
Posts: 27
Joined: Tue Jul 11, 2017 2:58 pm
languages_spoken: english

Re: Getting UAS working on HK 4.9

Unread postby odroid » Thu Jul 27, 2017 5:03 pm

Appreciate the information about the new image.
We will test the new OMV image for a few days and share the result early next week.

Update:
I've installed the new image and tested with an external Seagate 8TB HDD box.
I had no issue while formatting the full 8TB.
The coherent-pool size is correctly allocated.
Code: Select all
DMA: preallocated 1024 KiB pool for atomic coherent allocations

I've donated €100(EUR) to Openmediavault. https://www.openmediavault.org/donate.html :D

We will do further tests with some other enclosures.
User avatar
odroid
Site Admin
 
Posts: 25000
Joined: Fri Feb 22, 2013 11:14 pm
languages_spoken: English
ODROIDs: ODROID

Re: Getting UAS working on HK 4.9

Unread postby linuxest » Fri Jul 28, 2017 5:18 pm

Nice finding. :o
I can use the UAS driver after increasing the coherent memory.
I'm having a no-brand enclosure which has the ASM1153E chip. But lsusb shows a different ID.
Code: Select all
ID 174c:55aa ASMedia Technology Inc. ASMedia 2105 SATA bridge


Anyway, it really works well with my custom Kernel 4.9 on Arch Linux now.
I can see over 260MB/sec writing speed even with a very old intel 128GB SSD thanks to the UAS capability.
Before increasing the DMA pool, there were crashes from time to time. So I should disable the UAS driver.
I will build a trial 4.12 kernel and share my result this weekend.
XU4 seems to be a nice server grade 2Ghz computer.
linuxest
 
Posts: 37
Joined: Tue Nov 08, 2016 6:35 pm
languages_spoken: english
ODROIDs: 1 x HC1 and 2 x C2s with HiFi-Shield 2
And some RPi3 boards

Re: Getting UAS working on HK 4.9

Unread postby odroid » Fri Jul 28, 2017 6:04 pm

Thank you for sharing the test result.

We've also tested following controllers with an HGST 7200rpm 2.5inch 1TB HDD.
JMicron JMS578
JMicron JMS567
Initio INIC3609

All of them are working stably after increasing the coherent-pool size.
Note that JMS578 performance is slightly better than two others.

We also tried the NorelSys NS1068X chipset but it doesn't work with Linux even on the x86 system.
User avatar
odroid
Site Admin
 
Posts: 25000
Joined: Fri Feb 22, 2013 11:14 pm
languages_spoken: English
ODROIDs: ODROID

Re: Getting UAS working on HK 4.9

Unread postby adeuring » Sat Jul 29, 2017 8:47 am

I'm using this USB3/SATA adapter

Code: Select all
Bus 004 Device 003: ID 174c:55aa ASMedia Technology Inc. ASM1051E SATA 6Gb/s bridge, ASM1053Ee


with an old Hitachi Travelstar Z7K320 without any kernel problem. Only setting up a reliable power supply was a real trial and error game. But that's a story for another thread, I guess.
adeuring
 
Posts: 37
Joined: Sun Jul 09, 2017 9:50 pm
languages_spoken: english

Re: Getting UAS working on HK 4.9

Unread postby u-ra » Mon Jul 31, 2017 7:40 am

I can reproduce this problem using the usb-storage driver as well. The controller is a Norelsys NS1066, which apparently doesn't talk UAS.
Increasing the coherent DMA pool makes no difference.

Code: Select all
Jul 31 00:04:52 exodus kernel: usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
Jul 31 00:04:53 exodus kernel: usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
Jul 31 00:04:55 exodus kernel: usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
Jul 31 00:04:57 exodus kernel: usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
Jul 31 00:04:58 exodus kernel: usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
Jul 31 00:05:02 exodus kernel: usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
Jul 31 00:05:07 exodus kernel: usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
Jul 31 00:05:09 exodus kernel: usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
Jul 31 00:05:12 exodus kernel: usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
Jul 31 00:05:13 exodus kernel: usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
Jul 31 00:05:22 exodus kernel: usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
Jul 31 00:05:23 exodus kernel: usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
Jul 31 00:05:29 exodus kernel: usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
Jul 31 00:05:30 exodus kernel: usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
Jul 31 00:05:36 exodus kernel: usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
Jul 31 00:05:40 exodus kernel: hub 4-1:1.0: hub_ext_port_status failed (err = -71)
Jul 31 00:05:41 exodus kernel: usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
Jul 31 00:05:41 exodus kernel: usb 4-1.1: USB disconnect, device number 3
Jul 31 00:05:41 exodus kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x01 driverbyte=0x00
Jul 31 00:05:41 exodus kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x88 88 00 00 00 00 00 41 84 ff f8 00 00 01 00 00 00
Jul 31 00:05:41 exodus kernel: blk_update_request: I/O error, dev sda, sector 1099235320
Jul 31 00:05:41 exodus kernel: sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x01 driverbyte=0x00
Jul 31 00:05:41 exodus kernel: sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x88 88 00 00 00 00 00 41 85 00 f8 00 00 01 00 00 00
Jul 31 00:05:41 exodus kernel: blk_update_request: I/O error, dev sda, sector 1099235576
Jul 31 00:05:41 exodus kernel: EXT4-fs warning (device sda1): ext4_end_bio:314: I/O error -5 writing to inode 67895624 (offset 4599808 size 3788800 starting block 136253026)
Jul 31 00:05:41 exodus kernel: Buffer I/O error on device sda1, logical block 136252514
Jul 31 00:05:41 exodus kernel: Buffer I/O error on device sda1, logical block 136252515
Jul 31 00:05:41 exodus kernel: Buffer I/O error on device sda1, logical block 136252516
Jul 31 00:05:41 exodus kernel: Buffer I/O error on device sda1, logical block 136252517
Jul 31 00:05:41 exodus kernel: Buffer I/O error on device sda1, logical block 136252518
Jul 31 00:05:41 exodus kernel: Buffer I/O error on device sda1, logical block 136252519
Jul 31 00:05:41 exodus kernel: Buffer I/O error on device sda1, logical block 136252520
Jul 31 00:05:41 exodus kernel: Buffer I/O error on device sda1, logical block 136252521
Jul 31 00:05:41 exodus kernel: Buffer I/O error on device sda1, logical block 136252522
Jul 31 00:05:41 exodus kernel: Buffer I/O error on device sda1, logical block 136252523
Jul 31 00:05:41 exodus kernel: EXT4-fs warning (device sda1): ext4_end_bio:314: I/O error -5 writing to inode 67895624 (offset 4599808 size 3788800 starting block 136253282)
Jul 31 00:05:41 exodus kernel: EXT4-fs warning (device sda1): ext4_end_bio:314: I/O error -5 writing to inode 67895624 (offset 4599808 size 3788800 starting block 136253538)
Jul 31 00:05:41 exodus kernel: EXT4-fs warning (device sda1): ext4_end_bio:314: I/O error -5 writing to inode 67895624 (offset 4599808 size 3788800 starting block 136253696)
Jul 31 00:05:41 exodus kernel: EXT4-fs warning (device sda1): ext4_end_bio:314: I/O error -5 writing to inode 67895609 (offset 0 size 0 starting block 138529025)
Jul 31 00:05:41 exodus kernel: EXT4-fs warning (device sda1): ext4_end_bio:314: I/O error -5 writing to inode 67895624 (offset 251080704 size 577536 starting block 138823936)
Jul 31 00:05:41 exodus kernel: EXT4-fs warning (device sda1): ext4_end_bio:314: I/O error -5 writing to inode 67895609 (offset 36225024 size 5718016 starting block 138830987)
Jul 31 00:05:41 exodus kernel: EXT4-fs warning (device sda1): ext4_end_bio:314: I/O error -5 writing to inode 67895609 (offset 36225024 size 5718016 starting block 138831243)
Jul 31 00:05:41 exodus kernel: EXT4-fs warning (device sda1): ext4_end_bio:314: I/O error -5 writing to inode 67895609 (offset 36225024 size 5718016 starting block 138831499)
Jul 31 00:05:41 exodus kernel: EXT4-fs warning (device sda1): ext4_end_bio:314: I/O error -5 writing to inode 67895609 (offset 36225024 size 5718016 starting block 138831755)
Jul 31 00:05:41 exodus kernel: JBD2: Detected IO errors while flushing file data on sda1-8
Jul 31 00:05:41 exodus kernel: Aborting journal on device sda1-8.
Jul 31 00:05:41 exodus kernel: JBD2: Error -5 detected when updating journal superblock for sda1-8.
Jul 31 00:05:41 exodus kernel: usb 4-1.2: USB disconnect, device number 4
Jul 31 00:05:41 exodus kernel: EXT4-fs error (device sda1): ext4_journal_check_start:56: Detected aborted journal
Jul 31 00:05:41 exodus kernel: EXT4-fs (sda1): Remounting filesystem read-only
Jul 31 00:05:41 exodus kernel: ------------[ cut here ]------------
Jul 31 00:05:41 exodus kernel: WARNING: CPU: 4 PID: 378 at fs/fs-writeback.c:2154 __mark_inode_dirty+0x16c/0x200
Jul 31 00:05:41 exodus kernel: bdi-block not registered
Jul 31 00:05:41 exodus kernel: Modules linked in: ipt_MASQUERADE nf_nat_masquerade_ipv4 iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack joydev ads7846 spidev 8812au cfg80211 cdc_ether usbnet r8152 rfkill spi_s3c64xx w1_gpio exynos_gpiomem wire sch_fq_codel nfsd ip_tables ipv6
Jul 31 00:05:41 exodus kernel: CPU: 4 PID: 378 Comm: qbittorrent-nox Not tainted 4.9.37-1-ARCH #1
Jul 31 00:05:41 exodus kernel: Hardware name: SAMSUNG EXYNOS (Flattened Device Tree)
Jul 31 00:05:42 exodus kernel: [<c010efa4>] (unwind_backtrace) from [<c010b9fc>] (show_stack+0x10/0x14)
Jul 31 00:05:42 exodus kernel: [<c010b9fc>] (show_stack) from [<c0559138>] (dump_stack+0x78/0x8c)
Jul 31 00:05:42 exodus kernel: [<c0559138>] (dump_stack) from [<c012e9e8>] (__warn+0xe8/0x100)
Jul 31 00:05:42 exodus kernel: [<c012e9e8>] (__warn) from [<c012ea48>] (warn_slowpath_fmt+0x48/0x6c)
Jul 31 00:05:42 exodus kernel: [<c012ea48>] (warn_slowpath_fmt) from [<c02636dc>] (__mark_inode_dirty+0x16c/0x200)
Jul 31 00:05:42 exodus kernel: [<c02636dc>] (__mark_inode_dirty) from [<c0253d90>] (generic_update_time+0x74/0xa4)
Jul 31 00:05:42 exodus kernel: [<c0253d90>] (generic_update_time) from [<c0254098>] (file_update_time+0xf0/0x128)
Jul 31 00:05:42 exodus kernel: [<c0254098>] (file_update_time) from [<c01e0ef0>] (__generic_file_write_iter+0x90/0x1c4)
Jul 31 00:05:42 exodus kernel: [<c01e0ef0>] (__generic_file_write_iter) from [<c02b9ca4>] (ext4_file_write_iter+0xf0/0x404)
Jul 31 00:05:42 exodus kernel: [<c02b9ca4>] (ext4_file_write_iter) from [<c0238ac4>] (do_readv_writev+0x194/0x3e8)
Jul 31 00:05:42 exodus kernel: [<c0238ac4>] (do_readv_writev) from [<c0238fcc>] (vfs_writev+0x40/0x58)
Jul 31 00:05:42 exodus kernel: [<c0238fcc>] (vfs_writev) from [<c0239180>] (do_pwritev+0x94/0x114)
Jul 31 00:05:42 exodus kernel: [<c0239180>] (do_pwritev) from [<c0239d4c>] (SyS_pwritev+0x24/0x2c)
Jul 31 00:05:42 exodus kernel: [<c0239d4c>] (SyS_pwritev) from [<c0107c80>] (ret_fast_syscall+0x0/0x3c)
Jul 31 00:05:42 exodus kernel: ---[ end trace ca75b0650ef97e9a ]---
Jul 31 00:05:42 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #67895540: comm qbittorrent-nox: reading directory lblock 0
Jul 31 00:05:42 exodus kernel: usb 4-1: reset SuperSpeed USB device number 2 using xhci-hcd
Jul 31 00:05:42 exodus kernel: usb 4-1.1: new SuperSpeed USB device number 5 using xhci-hcd
Jul 31 00:05:42 exodus kernel: usb 4-1.1: New USB device found, idVendor=2537, idProduct=1066
Jul 31 00:05:42 exodus kernel: usb 4-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Jul 31 00:05:42 exodus kernel: usb 4-1.1: Product: NS1066
Jul 31 00:05:42 exodus kernel: usb 4-1.1: Manufacturer: Norelsys
Jul 31 00:05:42 exodus kernel: usb 4-1.1: SerialNumber: 0123456789ABCDE
Jul 31 00:05:42 exodus kernel: EXT4-fs error (device sda1): ext4_wait_block_bitmap:503: comm qbittorrent-nox: Cannot read block bitmap - block_group = 4237, block_bitmap = 138412045
Jul 31 00:05:42 exodus kernel: EXT4-fs error (device sda1): ext4_discard_preallocations:4046: comm qbittorrent-nox: Error -5 reading block bitmap for 4237
Jul 31 00:05:42 exodus kernel: EXT4-fs error (device sda1): ext4_wait_block_bitmap:503: comm qbittorrent-nox: Cannot read block bitmap - block_group = 4237, block_bitmap = 138412045
Jul 31 00:05:43 exodus kernel: EXT4-fs error (device sda1): ext4_discard_preallocations:4046: comm qbittorrent-nox: Error -5 reading block bitmap for 4237
Jul 31 00:05:43 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #67895549: comm qbittorrent-nox: reading directory lblock 0
Jul 31 00:05:43 exodus kernel: usb-storage 4-1.1:1.0: USB Mass Storage device detected
Jul 31 00:05:43 exodus kernel: scsi host1: usb-storage 4-1.1:1.0
Jul 31 00:05:43 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #67895549: comm qbittorrent-nox: reading directory lblock 0
Jul 31 00:05:43 exodus kernel: usb 4-1.2: new SuperSpeed USB device number 6 using xhci-hcd
Jul 31 00:05:43 exodus kernel: usb 4-1.2: Int endpoint with wBytesPerInterval of 512 in config 1 interface 0 altsetting 0 ep 133: setting to 64
Jul 31 00:05:43 exodus kernel: usb 4-1.2: New USB device found, idVendor=0bda, idProduct=8812
Jul 31 00:05:43 exodus kernel: usb 4-1.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Jul 31 00:05:43 exodus kernel: usb 4-1.2: Product: 802.11n NIC
Jul 31 00:05:43 exodus kernel: usb 4-1.2: Manufacturer: Realtek
Jul 31 00:05:43 exodus kernel: usb 4-1.2: SerialNumber: 123456
Jul 31 00:05:43 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #67895549: comm qbittorrent-nox: reading directory lblock 0
Jul 31 00:05:43 exodus kernel: IPv6: ADDRCONF(NETDEV_UP): wlan0: link is not ready
Jul 31 00:05:44 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #67895549: comm qbittorrent-nox: reading directory lblock 0
Jul 31 00:05:44 exodus kernel: scsi 1:0:0:0: Direct-Access     NORELSYS 106X             0A80 PQ: 0 ANSI: 6
Jul 31 00:05:44 exodus kernel: sd 1:0:0:0: [sdb] Very big device. Trying to use READ CAPACITY(16).
Jul 31 00:05:44 exodus kernel: sd 1:0:0:0: Attached scsi generic sg0 type 0
Jul 31 00:05:44 exodus kernel: sd 1:0:0:0: [sdb] 5860533168 512-byte logical blocks: (3.00 TB/2.73 TiB)
Jul 31 00:05:44 exodus kernel: sd 1:0:0:0: [sdb] 4096-byte physical blocks
Jul 31 00:05:44 exodus kernel: sd 1:0:0:0: [sdb] Write Protect is off
Jul 31 00:05:44 exodus kernel: sd 1:0:0:0: [sdb] Mode Sense: 43 00 00 00
Jul 31 00:05:44 exodus kernel: sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
Jul 31 00:05:44 exodus kernel: sd 1:0:0:0: [sdb] Very big device. Trying to use READ CAPACITY(16).
Jul 31 00:05:44 exodus kernel:  sdb: sdb1
Jul 31 00:05:44 exodus kernel: sd 1:0:0:0: [sdb] Very big device. Trying to use READ CAPACITY(16).
Jul 31 00:05:44 exodus kernel: sd 1:0:0:0: [sdb] Attached SCSI disk
Jul 31 00:05:47 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #67895540: comm qbittorrent-nox: reading directory lblock 0
Jul 31 00:05:51 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #67895549: comm qbittorrent-nox: reading directory lblock 0
Jul 31 00:05:51 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #67895540: comm qbittorrent-nox: reading directory lblock 0
Jul 31 00:05:51 exodus kernel: EXT4-fs error (device sda1): ext4_wait_block_bitmap:503: comm qbittorrent-nox: Cannot read block bitmap - block_group = 4236, block_bitmap = 138412044
Jul 31 00:05:51 exodus kernel: EXT4-fs error (device sda1): ext4_discard_preallocations:4046: comm qbittorrent-nox: Error -5 reading block bitmap for 4236
Jul 31 00:05:54 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #67895540: comm qbittorrent-nox: reading directory lblock 0
Jul 31 00:05:55 exodus kernel: EXT4-fs error (device sda1): ext4_wait_block_bitmap:503: comm qbittorrent-nox: Cannot read block bitmap - block_group = 4332, block_bitmap = 141557772
Jul 31 00:05:55 exodus kernel: EXT4-fs error (device sda1): ext4_discard_preallocations:4046: comm qbittorrent-nox: Error -5 reading block bitmap for 4332
Jul 31 00:05:55 exodus kernel: EXT4-fs error (device sda1): ext4_wait_block_bitmap:503: comm qbittorrent-nox: Cannot read block bitmap - block_group = 4332, block_bitmap = 141557772
Jul 31 00:05:55 exodus kernel: EXT4-fs error (device sda1): ext4_discard_preallocations:4046: comm qbittorrent-nox: Error -5 reading block bitmap for 4332
Jul 31 00:05:55 exodus kernel: EXT4-fs error (device sda1): ext4_wait_block_bitmap:503: comm qbittorrent-nox: Cannot read block bitmap - block_group = 4236, block_bitmap = 138412044
Jul 31 00:05:55 exodus kernel: EXT4-fs error (device sda1): ext4_discard_preallocations:4046: comm qbittorrent-nox: Error -5 reading block bitmap for 4236
Jul 31 00:05:55 exodus kernel: EXT4-fs error (device sda1): ext4_wait_block_bitmap:503: comm qbittorrent-nox: Cannot read block bitmap - block_group = 4236, block_bitmap = 138412044
Jul 31 00:05:55 exodus kernel: EXT4-fs error (device sda1): ext4_discard_preallocations:4046: comm qbittorrent-nox: Error -5 reading block bitmap for 4236
Jul 31 00:05:55 exodus kernel: EXT4-fs error (device sda1): ext4_wait_block_bitmap:503: comm qbittorrent-nox: Cannot read block bitmap - block_group = 4237, block_bitmap = 138412045
Jul 31 00:06:14 exodus kernel: EXT4-fs error: 3 callbacks suppressed
Jul 31 00:06:14 exodus kernel: EXT4-fs error (device sda1): ext4_wait_block_bitmap:503: comm qbittorrent-nox: Cannot read block bitmap - block_group = 4236, block_bitmap = 138412044
Jul 31 00:06:14 exodus kernel: EXT4-fs error (device sda1): ext4_discard_preallocations:4046: comm qbittorrent-nox: Error -5 reading block bitmap for 4236
Jul 31 00:06:14 exodus kernel: EXT4-fs error (device sda1): ext4_wait_block_bitmap:503: comm qbittorrent-nox: Cannot read block bitmap - block_group = 4236, block_bitmap = 138412044
Jul 31 00:06:14 exodus kernel: EXT4-fs error (device sda1): ext4_discard_preallocations:4046: comm qbittorrent-nox: Error -5 reading block bitmap for 4236
Jul 31 00:06:16 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #67895540: comm qbittorrent-nox: reading directory lblock 0
Jul 31 00:06:38 exodus kernel: ------------[ cut here ]------------
Jul 31 00:06:38 exodus kernel: WARNING: CPU: 0 PID: 0 at kernel/cgroup.c:492 cgroup_get+0xac/0xd4
Jul 31 00:06:38 exodus kernel: Modules linked in: ipt_MASQUERADE nf_nat_masquerade_ipv4 iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 nf_nat nf_conntrack joydev ads7846 spidev 8812au cfg80211 cdc_ether usbnet r8152 rfkill spi_s3c64xx w1_gpio exynos_gpiomem wire sch_fq_codel nfsd ip_tables ipv6
Jul 31 00:06:38 exodus kernel: CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W       4.9.37-1-ARCH #1
Jul 31 00:06:40 exodus kernel: Hardware name: SAMSUNG EXYNOS (Flattened Device Tree)
Jul 31 00:06:40 exodus kernel: [<c010efa4>] (unwind_backtrace) from [<c010b9fc>] (show_stack+0x10/0x14)
Jul 31 00:06:40 exodus kernel: [<c010b9fc>] (show_stack) from [<c0559138>] (dump_stack+0x78/0x8c)
Jul 31 00:06:40 exodus kernel: [<c0559138>] (dump_stack) from [<c012e9e8>] (__warn+0xe8/0x100)
Jul 31 00:06:40 exodus kernel: [<c012e9e8>] (__warn) from [<c012eaf8>] (warn_slowpath_null+0x20/0x28)
Jul 31 00:06:40 exodus kernel: [<c012eaf8>] (warn_slowpath_null) from [<c01adb98>] (cgroup_get+0xac/0xd4)
Jul 31 00:06:40 exodus kernel: [<c01adb98>] (cgroup_get) from [<c086aa30>] (sk_clone_lock+0x1f0/0x27c)
Jul 31 00:06:40 exodus kernel: [<c086aa30>] (sk_clone_lock) from [<c08cd104>] (inet_csk_clone_lock+0x10/0xac)
Jul 31 00:06:40 exodus kernel: [<c08cd104>] (inet_csk_clone_lock) from [<c08e8e48>] (tcp_create_openreq_child+0x1c/0x3e0)
Jul 31 00:06:40 exodus kernel: [<c08e8e48>] (tcp_create_openreq_child) from [<c08e6f38>] (tcp_v4_syn_recv_sock+0x34/0x320)
Jul 31 00:06:40 exodus kernel: [<c08e6f38>] (tcp_v4_syn_recv_sock) from [<c08e9674>] (tcp_check_req+0x2e8/0x4e8)
Jul 31 00:06:40 exodus kernel: [<c08e9674>] (tcp_check_req) from [<c08e8394>] (tcp_v4_rcv+0x4d4/0xd50)
Jul 31 00:06:40 exodus kernel: [<c08e8394>] (tcp_v4_rcv) from [<c08c0814>] (ip_local_deliver_finish+0x6c/0x300)
Jul 31 00:06:40 exodus kernel: [<c08c0814>] (ip_local_deliver_finish) from [<c08c1150>] (ip_local_deliver+0x84/0x100)
Jul 31 00:06:40 exodus kernel: exynos5-hsi2c 12ca0000.i2c:: rx timeout
Jul 31 00:06:40 exodus kernel: [<c08c1150>] (ip_local_deliver) from [<c08c1518>] (ip_rcv+0x34c/0x55c)
Jul 31 00:06:40 exodus kernel: [<c08c1518>] (ip_rcv) from [<c087e51c>] (__netif_receive_skb_core+0x4e0/0xb58)
Jul 31 00:06:40 exodus kernel: [<c087e51c>] (__netif_receive_skb_core) from [<c0880f60>] (netif_receive_skb_internal+0x78/0xf4)
Jul 31 00:06:40 exodus kernel: [<c0880f60>] (netif_receive_skb_internal) from [<c0881ee8>] (napi_gro_receive+0xac/0xd8)
Jul 31 00:06:40 exodus kernel: [<c0881ee8>] (napi_gro_receive) from [<bf0ed074>] (r8152_poll+0x44c/0xf68 [r8152])
Jul 31 00:06:40 exodus kernel: [<bf0ed074>] (r8152_poll [r8152]) from [<c0881660>] (net_rx_action+0x14c/0x358)
Jul 31 00:06:40 exodus kernel: [<c0881660>] (net_rx_action) from [<c0133b44>] (__do_softirq+0xf8/0x270)
Jul 31 00:06:40 exodus kernel: [<c0133b44>] (__do_softirq) from [<c0133fac>] (irq_exit+0xd4/0x11c)
Jul 31 00:06:40 exodus kernel: [<c0133fac>] (irq_exit) from [<c017b1d0>] (__handle_domain_irq+0x80/0xec)
Jul 31 00:06:40 exodus kernel: [<c017b1d0>] (__handle_domain_irq) from [<c01014c0>] (gic_handle_irq+0x54/0x98)
Jul 31 00:06:40 exodus kernel: [<c01014c0>] (gic_handle_irq) from [<c010c5cc>] (__irq_svc+0x6c/0xa8)
Jul 31 00:06:40 exodus kernel: Exception stack(0xc0e01f40 to 0xc0e01f88)
Jul 31 00:06:40 exodus kernel: 1f40: 00000001 00000000 00000000 c011a160 ffffe000 c0e030f4 00000001 c0e03148
Jul 31 00:06:40 exodus kernel: 1f60: 00000000 00000000 c0b57894 c0e03150 f0806340 c0e01f90 c0108784 c0108788
Jul 31 00:06:40 exodus kernel: exynos5-hsi2c 12ca0000.i2c:: tx timeout
Jul 31 00:06:40 exodus kernel: 1f80: 60010013 ffffffff
Jul 31 00:06:40 exodus kernel: [<c010c5cc>] (__irq_svc) from [<c0108788>] (arch_cpu_idle+0x38/0x3c)
Jul 31 00:06:40 exodus kernel: [<c0108788>] (arch_cpu_idle) from [<c01712a8>] (cpu_startup_entry+0x1ac/0x228)
Jul 31 00:06:40 exodus kernel: [<c01712a8>] (cpu_startup_entry) from [<c0d00cd0>] (start_kernel+0x3e4/0x404)
Jul 31 00:06:40 exodus kernel: ---[ end trace ca75b0650ef97e9b ]---
Jul 31 00:06:44 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #67895549: comm qbittorrent-nox: reading directory lblock 0
Jul 31 00:07:05 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #67895549: comm qbittorrent-nox: reading directory lblock 0
Jul 31 00:07:08 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #67895540: comm qbittorrent-nox: reading directory lblock 0
Jul 31 00:07:13 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #67895549: comm qbittorrent-nox: reading directory lblock 0
Jul 31 00:07:13 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #67895549: comm qbittorrent-nox: reading directory lblock 0
Jul 31 00:08:05 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #67895540: comm qbittorrent-nox: reading directory lblock 0
Jul 31 00:10:09 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #67895540: comm qbittorrent-nox: reading directory lblock 0
Jul 31 00:11:28 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #2: comm git: reading directory lblock 0
Jul 31 00:11:28 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #2: comm git: reading directory lblock 0
Jul 31 00:12:46 exodus kernel: EXT4-fs warning: 51 callbacks suppressed
Jul 31 00:12:46 exodus kernel: EXT4-fs warning (device sda1): htree_dirblock_to_tree:962: inode #67895553: lblock 0: comm python2: error -5 reading directory block
Jul 31 00:13:13 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #2: comm bash: reading directory lblock 0
Jul 31 00:13:13 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #2: comm bash: reading directory lblock 0
Jul 31 00:13:13 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #2: comm bash: reading directory lblock 0
Jul 31 00:13:38 exodus kernel: EXT4-fs error (device sda1): ext4_find_entry:1463: inode #2: comm less: reading directory lblock 0
Jul 31 00:15:09 exodus kernel: usb 4-1.1: USB disconnect, device number 5
Jul 31 00:15:35 exodus kernel: usb 1-1: new high-speed USB device number 2 using exynos-ehci
Jul 31 00:15:35 exodus kernel: usb 1-1: New USB device found, idVendor=2537, idProduct=1066
Jul 31 00:15:35 exodus kernel: usb 1-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
Jul 31 00:15:35 exodus kernel: usb 1-1: Product: NS1066
Jul 31 00:15:35 exodus kernel: usb 1-1: Manufacturer: Norelsys
Jul 31 00:15:35 exodus kernel: usb 1-1: SerialNumber: 0123456789ABCDE
Jul 31 00:15:35 exodus kernel: usb-storage 1-1:1.0: USB Mass Storage device detected
Jul 31 00:15:35 exodus kernel: scsi host1: usb-storage 1-1:1.0
Jul 31 00:15:38 exodus kernel: scsi 1:0:0:0: Direct-Access     NORELSYS 106X             0A80 PQ: 0 ANSI: 6
Jul 31 00:15:38 exodus kernel: sd 1:0:0:0: [sdb] Very big device. Trying to use READ CAPACITY(16).
Jul 31 00:15:38 exodus kernel: sd 1:0:0:0: Attached scsi generic sg0 type 0
Jul 31 00:15:38 exodus kernel: sd 1:0:0:0: [sdb] 5860533168 512-byte logical blocks: (3.00 TB/2.73 TiB)
Jul 31 00:15:38 exodus kernel: sd 1:0:0:0: [sdb] 4096-byte physical blocks
Jul 31 00:15:38 exodus kernel: sd 1:0:0:0: [sdb] Write Protect is off
Jul 31 00:15:38 exodus kernel: sd 1:0:0:0: [sdb] Mode Sense: 43 00 00 00
Jul 31 00:15:38 exodus kernel: sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
Jul 31 00:15:38 exodus kernel: sd 1:0:0:0: [sdb] Very big device. Trying to use READ CAPACITY(16).
Jul 31 00:15:38 exodus kernel:  sdb: sdb1
Jul 31 00:15:38 exodus kernel: sd 1:0:0:0: [sdb] Very big device. Trying to use READ CAPACITY(16).
Jul 31 00:15:38 exodus kernel: sd 1:0:0:0: [sdb] Attached SCSI disk
Jul 31 00:16:19 exodus kernel: EXT4-fs error (device sda1): ext4_wait_block_bitmap:503: comm qbittorrent-nox: Cannot read block bitmap - block_group = 4237, block_bitmap = 138412045
Jul 31 00:16:19 exodus kernel: EXT4-fs error (device sda1): ext4_discard_preallocations:4046: comm qbittorrent-nox: Error -5 reading block bitmap for 4237
Jul 31 00:16:19 exodus kernel: EXT4-fs error (device sda1): ext4_wait_block_bitmap:503: comm qbittorrent-nox: Cannot read block bitmap - block_group = 4236, block_bitmap = 138412044
Jul 31 00:16:19 exodus kernel: EXT4-fs error (device sda1): ext4_discard_preallocations:4046: comm qbittorrent-nox: Error -5 reading block bitmap for 4236
Jul 31 00:16:19 exodus kernel: EXT4-fs error (device sda1): ext4_wait_block_bitmap:503: comm qbittorrent-nox: Cannot read block bitmap - block_group = 4236, block_bitmap = 138412044
Jul 31 00:16:19 exodus kernel: EXT4-fs error (device sda1): ext4_discard_preallocations:4046: comm qbittorrent-nox: Error -5 reading block bitmap for 4236
Jul 31 00:16:19 exodus kernel: EXT4-fs error (device sda1): ext4_wait_block_bitmap:503: comm qbittorrent-nox: Cannot read block bitmap - block_group = 4236, block_bitmap = 138412044
Jul 31 00:16:19 exodus kernel: EXT4-fs error (device sda1): ext4_discard_preallocations:4046: comm qbittorrent-nox: Error -5 reading block bitmap for 4236
Jul 31 00:16:19 exodus kernel: EXT4-fs error (device sda1): ext4_wait_block_bitmap:503: comm qbittorrent-nox: Cannot read block bitmap - block_group = 4237, block_bitmap = 138412045
Jul 31 00:16:19 exodus kernel: nfsd: last server has exited, flushing export cache
Jul 31 00:16:19 exodus kernel: EXT4-fs error (device sda1): ext4_discard_preallocations:4046: comm qbittorrent-nox: Error -5 reading block bitmap for 4237
Jul 31 00:16:23 exodus kernel: systemd-shutdow: 35 output lines suppressed due to ratelimiting
u-ra
 
Posts: 12
Joined: Tue May 17, 2016 9:06 pm
languages_spoken: english
ODROIDs: C2, XU4

Re: Getting UAS working on HK 4.9

Unread postby crashoverride » Mon Jul 31, 2017 8:24 am

If UAS is not being used, then the symptoms, although similar, are not "this problem". It is a different problem.

Typical causes of USB disk problems are:
1) Connector problems. Try cleaning the USB host ports.
2) Cable problems. Try a different cable. Try a USB2 cable instead.
3) Power problems. Is the driver self powered or does it get its power from the XU4?

Also, you should test the drive on a PC running Linux. Does the drive also have problems there?
crashoverride
 
Posts: 3102
Joined: Tue Dec 30, 2014 8:42 pm
languages_spoken: english
ODROIDs: C1

Re: Getting UAS working on HK 4.9

Unread postby odroid » Mon Jul 31, 2017 11:32 am

Yes, it seems to be a power or physical interface issue.
Once I disabled the UAS option with usb-storage.quirks=2537:1068:u, the NS1068x worked with a 1TB HDD.
I could write/read 2GByte file without problem.
Code: Select all
root@odroidxu4:/srv/dev-disk-by-label-hgst# dd if=/dev/zero of=test oflag=direct bs=8M count=256
256+0 records in
256+0 records out
2147483648 bytes (2.1 GB) copied, 16.8569 s, 127 MB/s
root@odroidxu4:/srv/dev-disk-by-label-hgst# dd if=test of=/dev/null iflag=direct bs=8MB
268+1 records in
268+1 records out
2147483648 bytes (2.1 GB) copied, 14.6845 s, 146 MB/s


But if I enabled the UAS, the disk was not accessible just after showing below kernel message.
Code: Select all
[  143.851087] sd 0:0:0:0: [sda] tag#0 uas_eh_abort_handler 0 uas-tag 1 inflight: IN
[  143.851096] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 00 09 10 00 00 f0 00
[  143.851271] scsi host0: uas_eh_bus_reset_handler start
[  143.936185] usb 4-1.2: reset SuperSpeed USB device number 3 using xhci-hcd
[  143.957705] scsi host0: uas_eh_bus_reset_handler success
[  177.131094] sd 0:0:0:0: [sda] tag#0 uas_eh_abort_handler 0 uas-tag 1 inflight: IN
[  177.131103] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 00 0b e0 00 00 08 00
[  177.131209] scsi host0: uas_eh_bus_reset_handler start
[  177.211203] usb 4-1.2: reset SuperSpeed USB device number 3 using xhci-hcd
[  177.232903] scsi host0: uas_eh_bus_reset_handler success
[  210.411100] sd 0:0:0:0: [sda] tag#3 uas_eh_abort_handler 0 uas-tag 4 inflight: IN
[  210.411110] sd 0:0:0:0: [sda] tag#3 CDB: opcode=0x28 28 00 00 00 08 80 00 00 90 00
[  210.411228] scsi host0: uas_eh_bus_reset_handler start
[  210.491240] usb 4-1.2: reset SuperSpeed USB device number 3 using xhci-hcd
[  210.512580] scsi host0: uas_eh_bus_reset_handler success
[  243.691123] sd 0:0:0:0: [sda] tag#0 uas_eh_abort_handler 0 uas-tag 1 inflight: IN
[  243.691132] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 00 00 08 40 00 00 08 00
User avatar
odroid
Site Admin
 
Posts: 25000
Joined: Fri Feb 22, 2013 11:14 pm
languages_spoken: English
ODROIDs: ODROID

Re: Getting UAS working on HK 4.9

Unread postby u-ra » Mon Jul 31, 2017 7:28 pm

No, the cable and connectors are not the issue. Both the XU4 and the disk are powered by one of these, so that's not it either.
I can reliably trigger the problem with high traffic to both RTL8153 and the disk. If I move the disk to the USB2.0 port, the problem goes away.

I suspect this issue is common to both UAS and usb-storage, but feel free to move it to a separate thread if you don't think it belongs here.
u-ra
 
Posts: 12
Joined: Tue May 17, 2016 9:06 pm
languages_spoken: english
ODROIDs: C2, XU4

Re: Getting UAS working on HK 4.9

Unread postby odroid » Mon Jul 31, 2017 7:33 pm

@u-ra,
Please try other USB 3.0 cables if possible.

Anyway, do you have no issue if you don't use Ethernet traffic?
User avatar
odroid
Site Admin
 
Posts: 25000
Joined: Fri Feb 22, 2013 11:14 pm
languages_spoken: English
ODROIDs: ODROID

Re: Getting UAS working on HK 4.9

Unread postby joaofl » Tue Aug 01, 2017 1:26 am

@odroid
I have the exat same issue as @u-ra.
Have tried different cables, different Odoird-XU4 board, different ports, cleaning... HD is supplied from external power supply. The problem persists, even in the latest kernel release.

For example, right now, by simply downloading/uploading a torrent (@~10MB/s), I keep getting those errors at every 3 seconds almost.

Code: Select all
[Mon Jul 31 17:19:33 2017] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[Mon Jul 31 17:19:34 2017] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[Mon Jul 31 17:19:40 2017] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[Mon Jul 31 17:19:41 2017] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[Mon Jul 31 17:19:43 2017] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[Mon Jul 31 17:19:45 2017] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[Mon Jul 31 17:19:48 2017] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd


My external HD is:

Code: Select all
Bus 004 Device 003: ID 1058:25ee Western Digital Technologies, Inc.
Device Descriptor:
  bLength                18
  bDescriptorType         1
  bcdUSB               3.00
  bDeviceClass            0 (Defined at Interface level)
  bDeviceSubClass         0
  bDeviceProtocol         0
  bMaxPacketSize0         9
  idVendor           0x1058 Western Digital Technologies, Inc.
  idProduct          0x25ee
  bcdDevice           40.04
  iManufacturer           2 Western Digital
  iProduct                3 My Book 25EE
joaofl
 
Posts: 29
Joined: Sat Feb 27, 2016 2:29 am
Location: Portugal, Brasil
languages_spoken: english, portuguese, spanish
ODROIDs: XU4

Re: Getting UAS working on HK 4.9

Unread postby u-ra » Tue Aug 01, 2017 4:06 am

odroid wrote:@u-ra,
Please try other USB 3.0 cables if possible.

Anyway, do you have no issue if you don't use Ethernet traffic?


There is no difference with other USB cables. Neither is there an issue when RTL8153 is mostly idle.

A simple test which triggers the issue reliably for me is to start a large sequential read with dd, and then, in another tab or whatever, start any larger download.

Code: Select all
[root@exodus ~]# echo "START DD" > /dev/kmsg; dd if=/dev/sda of=/dev/null bs=32M status=progress
68753031168 bytes (69 GB, 64 GiB) copied, 494,039 s, 139 MB/s


As you can see, it's been going steady for over 8 minutes. Then:

Code: Select all
[root@exodus ~]# echo "START CURL" > /dev/kmsg; curl -o /dev/null http://lg.nl.ramnode.com/static/1000MB.test
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
 35  953M   35  342M    0     0  3253k      0  0:05:00  0:01:47  0:03:13 3371k


Which results in:

Code: Select all
dd: error reading '/dev/sda': Input/output error
2297+1 records in
2297+1 records out
77084753920 bytes (77 GB, 72 GiB) copied, 599,015 s, 129 MB/s
[root@exodus ~]#


Code: Select all
[root@exodus ~]# dmesg -w
[73736.390194] START DD
[74231.310684] START CURL
[74233.364775] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74236.929981] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74241.089871] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74242.409844] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74243.389840] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74244.764871] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74246.214904] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74247.224902] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74248.234935] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74249.459930] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74251.349944] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74253.395020] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74255.470176] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74261.365194] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74262.450064] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74265.220178] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74268.570224] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74272.645302] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74276.765272] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74279.080425] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74280.405585] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74284.580399] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74285.505403] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74286.925443] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74294.985578] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74296.785598] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74301.120588] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74302.150839] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74303.415709] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74305.135750] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74307.115729] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74311.250761] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74312.405820] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74313.565829] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74314.495912] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74315.995818] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74317.280886] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74319.490911] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74324.470935] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74326.390991] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74328.536010] usb 4-1.1: reset SuperSpeed USB device number 5 using xhci-hcd
[74330.212620] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74330.235993] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74330.451030] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74330.517789] usb 4-1.1: USB disconnect, device number 5
[74330.666054] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74330.881044] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74331.096161] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74331.104150] usb 4-1-port1: Cannot enable. Maybe the USB cable is bad?
[74331.113269] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74331.146100] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74331.361165] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74331.576099] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74331.791103] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74332.006094] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74332.013671] usb 4-1-port1: Cannot enable. Maybe the USB cable is bad?
[74332.022170] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74332.051102] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74332.266085] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74332.481077] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74332.696167] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74332.911087] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74332.918157] usb 4-1-port1: Cannot enable. Maybe the USB cable is bad?
[74332.926063] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74332.951105] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74333.166138] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74333.381134] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74333.596099] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74333.811086] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[74333.817593] usb 4-1-port1: Cannot enable. Maybe the USB cable is bad?
[74333.840950] sd 1:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x01 driverbyte=0x00
[74333.850001] sd 1:0:0:0: [sda] tag#0 CDB: opcode=0x88 88 00 00 00 00 00 08 f9 4e 00 00 00 01 00 00 00
[74333.860100] blk_update_request: I/O error, dev sda, sector 150556160
[74333.867696] sd 1:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x01 driverbyte=0x00
[74333.877106] sd 1:0:0:0: [sda] tag#0 CDB: opcode=0x88 88 00 00 00 00 00 08 f9 4f 00 00 00 01 00 00 00
[74333.887568] blk_update_request: I/O error, dev sda, sector 150556416
[74340.726280] xhci-hcd xhci-hcd.2.auto: Timeout while waiting for setup device command
[74340.956347] usb 4-1: reset SuperSpeed USB device number 2 using xhci-hcd
[74341.311100] usb 4-1.1: new SuperSpeed USB device number 7 using xhci-hcd
[74341.342695] usb 4-1.1: New USB device found, idVendor=2537, idProduct=1066
[74341.360611] usb 4-1.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[74341.379307] usb 4-1.1: Product: NS1066
[74341.395068] usb 4-1.1: Manufacturer: Norelsys
[74341.411088] usb 4-1.1: SerialNumber: 0123456789ABCDE
[74341.431190] usb-storage 4-1.1:1.0: USB Mass Storage device detected
[74341.452563] scsi host1: usb-storage 4-1.1:1.0
[74343.019126] scsi 1:0:0:0: Direct-Access     NORELSYS 106X             0A80 PQ: 0 ANSI: 6
[74343.052684] sd 1:0:0:0: [sdb] Very big device. Trying to use READ CAPACITY(16).
[74343.052909] sd 1:0:0:0: Attached scsi generic sg0 type 0
[74343.086540] sd 1:0:0:0: [sdb] 5860533168 512-byte logical blocks: (3.00 TB/2.73 TiB)
[74343.105663] sd 1:0:0:0: [sdb] 4096-byte physical blocks
[74343.123649] sd 1:0:0:0: [sdb] Write Protect is off
[74343.140211] sd 1:0:0:0: [sdb] Mode Sense: 43 00 00 00
[74343.143051] sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[74343.164764] sd 1:0:0:0: [sdb] Very big device. Trying to use READ CAPACITY(16).
[74343.265478]  sdb: sdb1
[74343.269994] sd 1:0:0:0: [sdb] Very big device. Trying to use READ CAPACITY(16).
[74343.279496] sd 1:0:0:0: [sdb] Attached SCSI disk


I normally have an RTL8812AU based WLAN adapter plugged in the other USB3.0 port which makes the hub reset happen even quicker.
u-ra
 
Posts: 12
Joined: Tue May 17, 2016 9:06 pm
languages_spoken: english
ODROIDs: C2, XU4

Re: Getting UAS working on HK 4.9

Unread postby odroid » Tue Aug 01, 2017 1:25 pm

@u-ra and @joaofl,

Thank you for the detailed inputs.
We will try to reproduce the issue.

@joaofl
BTW, does your WD HDD support UAS mode?
Do you have the issue regardless of the UAS mode?
User avatar
odroid
Site Admin
 
Posts: 25000
Joined: Fri Feb 22, 2013 11:14 pm
languages_spoken: English
ODROIDs: ODROID

Re: Getting UAS working on HK 4.9

Unread postby crashoverride » Tue Aug 01, 2017 3:52 pm

u-ra wrote:dd: error reading '/dev/sda': Input/output error

It is also possible that the HDD has bad sectors. The retry attempts also show up as USB resets. You should check the SMART info or try a different HDD.
crashoverride
 
Posts: 3102
Joined: Tue Dec 30, 2014 8:42 pm
languages_spoken: english
ODROIDs: C1

Re: Getting UAS working on HK 4.9

Unread postby odroid » Tue Aug 01, 2017 4:19 pm

We've done the same test with our CloudShell2 over 10 minutes on Kernel 4.9.37 with UAS.
But we couldn't reproduce the issue.

I'm also running the same test with JMS578 bridge and 2.5" HGST 1TB HDD for 8 minutes with UAS feature.
There is no issue so far. I will run it 15minutes more and I get back to you soon.
User avatar
odroid
Site Admin
 
Posts: 25000
Joined: Fri Feb 22, 2013 11:14 pm
languages_spoken: English
ODROIDs: ODROID

Re: Getting UAS working on HK 4.9

Unread postby odroid » Tue Aug 01, 2017 4:45 pm

For the DD test on the first SSH. Near 250GB copying for 30minutes at 145 MB/sec speed.
Code: Select all
263972716544 bytes (264 GB, 246 GiB) copied, 1814.9 s, 145 MB/s

For the LAN test on the second SSH for 30minutes.
Code: Select all
root@odroid:~# echo "START CURL" > /dev/kmsg; curl -o /dev/null http://lg.nl.ramnode.com/static/1000MB.test
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
 13  953M   13  131M    0     0  76948      0  3:36:35  0:29:49  3:06:46 91378
There was no single bit error on my dmesg output.


I think the USB driver seems not to be compatible with some bridge controllers or cable was bad or power source was bad or HDD/SSD was bad.
It is really hard to support many different cases. :(
User avatar
odroid
Site Admin
 
Posts: 25000
Joined: Fri Feb 22, 2013 11:14 pm
languages_spoken: English
ODROIDs: ODROID

Re: Getting UAS working on HK 4.9

Unread postby odroid » Tue Aug 01, 2017 5:57 pm

One people in our neighbour office has this WD external 8TB HDD.
https://www.amazon.com/Book-Desktop-Ext ... B01LQQHLGC
I will try to borrow it for testing within a few days.

@joaofl
What is the model name of your WD HDD box?
User avatar
odroid
Site Admin
 
Posts: 25000
Joined: Fri Feb 22, 2013 11:14 pm
languages_spoken: English
ODROIDs: ODROID

Re: Getting UAS working on HK 4.9

Unread postby u-ra » Tue Aug 01, 2017 6:16 pm

odroid wrote:For the DD test on the first SSH. Near 250GB copying for 30minutes at 145 MB/sec speed.
Code: Select all
263972716544 bytes (264 GB, 246 GiB) copied, 1814.9 s, 145 MB/s

For the LAN test on the second SSH for 30minutes.
Code: Select all
root@odroid:~# echo "START CURL" > /dev/kmsg; curl -o /dev/null http://lg.nl.ramnode.com/static/1000MB.test
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
 13  953M   13  131M    0     0  76948      0  3:36:35  0:29:49  3:06:46 91378
There was no single bit error on my dmesg output.


I think the USB driver seems not to be compatible with some bridge controllers or cable was bad or power source was bad or HDD/SSD was bad.
It is really hard to support many different cases. :(


Could you try with a server closer to you, or a local network http transfer? I see curl is averaging ~75KiB/s, that won't be enough to trigger the issue.

Meanwhile:
Code: Select all
[root@exodus ~]# dd if=/dev/sdb of=/dev/null bs=32M status=progress
671155748864 bytes (671 GB, 625 GiB) copied, 4929,01 s, 136 MB/s


It's been going without any issues for almost an hour and a half.

Code: Select all
120387.572774] START DD
[125706.626206] START CURL
[125707.997882] usb 4-1.1: reset SuperSpeed USB device number 7 using xhci-hcd
...


The disk itself is not the issue here. It's either the RTL8153, the XHCI host, the storage controller, or some weird interaction between the three.

Code: Select all
  5 Reallocated_Sector_Ct   0x0033   200   200   140    Pre-fail  Always       -       0
u-ra
 
Posts: 12
Joined: Tue May 17, 2016 9:06 pm
languages_spoken: english
ODROIDs: C2, XU4

Re: Getting UAS working on HK 4.9

Unread postby odroid » Tue Aug 01, 2017 6:38 pm

Good point.
We will try to setup an HTTP server on our local CloudShell2 server tomorrow since it is already PM 6:30 here Korea.
I hope to generate 1TB file finishes before morning.
User avatar
odroid
Site Admin
 
Posts: 25000
Joined: Fri Feb 22, 2013 11:14 pm
languages_spoken: English
ODROIDs: ODROID

Re: Getting UAS working on HK 4.9

Unread postby u-ra » Tue Aug 01, 2017 6:50 pm

odroid wrote:Good point.
We will try to setup an HTTP server on our local CloudShell2 server tomorrow since it is already PM 6:30 here Korea.
I hope to generate 1TB file finishes before morning.


Thank you for the support.
u-ra
 
Posts: 12
Joined: Tue May 17, 2016 9:06 pm
languages_spoken: english
ODROIDs: C2, XU4

Re: Getting UAS working on HK 4.9

Unread postby joaofl » Wed Aug 02, 2017 12:10 am

odroid wrote:One people in our neighbour office has this WD external 8TB HDD.
https://www.amazon.com/Book-Desktop-Ext ... B01LQQHLGC
I will try to borrow it for testing within a few days.

@joaofl
What is the model name of your WD HDD box?


@odroid
It is this WD My Book 8TB https://www.amazon.com/Book-Desktop-External-Drive-WDBBGB0080HBK-NESN/dp/B01LQQHLGC Not sure, but I dont think it is UAS compatible. It is disabled anyway. How can I confirm that?

The issues happen specially when IO happens simultaneously from/to the hard drive and ethernet. Note that I also have a USB3 pen drive as my root file system, which probably demands even more from the USB3 internal controllers.
It is most likely related to the driver of the SATA bridge. That because the same issues does not happen with another externel 2T USB Powered HD i have here. But with the 8TB externally powered. Same cables, same power supply...

I found this http://linux-scsi.vger.kernel.narkive.com/B3jfin3j/xhci-issues-wd-mybook-1230-reset-superspeed-usb-device.
An old issue that seems to be related to this one. Note that the "latest" firmware for this drive provided by WD dates back to 2014
joaofl
 
Posts: 29
Joined: Sat Feb 27, 2016 2:29 am
Location: Portugal, Brasil
languages_spoken: english, portuguese, spanish
ODROIDs: XU4

Re: Getting UAS working on HK 4.9

Unread postby odroid » Wed Aug 02, 2017 10:06 am

@joaofl
I heard it doesn't support the UAS mode.
Try "dmesg | grep -i uas" to check it.

Today, we will try @u-ra's method to confirm that very heavy traffic on USB Storage + USB Network both can cause the serious issue.
User avatar
odroid
Site Admin
 
Posts: 25000
Joined: Fri Feb 22, 2013 11:14 pm
languages_spoken: English
ODROIDs: ODROID

Re: Getting UAS working on HK 4.9

Unread postby odroid » Wed Aug 02, 2017 6:17 pm

@u-ra,

We've run the test over several hours on the latest OMV image and we couldn't reproduce the issue.
We used the JMS578 + Seagate 2.5inch 2TB HDD for the test.
Code: Select all
root@odroidxu4:~# echo "START DD" &gt; /dev/kmsg; dd if=/dev/sda | pv | dd of=/dev/null bs=32M
^C13TiB 7:59:20 [44.6MiB/s] [                                                            &lt;=&gt;          ]
0+498168391 records in
0+498168390 records out
1247903608320 bytes (1.2 TB) copied, 28760.1 s, 43.4 MB/s
2437311744+0 records in
2437311744+0 records out
1247903612928 bytes (1.2 TB) copied, 28761 s, 43.4 MB/s


Code: Select all
root@odroidxu4:~# ./170802_network_test_1TB.sh
Start infinite curl command
count:1
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100 1024G  100 1024G    0     0  86.2M      0  3:22:41  3:22:41 --:--:-- 88.5M
count:2
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100 1024G  100 1024G    0     0  85.4M      0  3:24:29  3:24:29 --:--:-- 85.3M
count:3
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
 11 1024G   11  113G    0     0  85.3M      0  3:24:42  0:22:42  3:02:00 88.4M^C

That script kept running echo "START CURL count:"$count &gt; /dev/kmsg; curl -o /dev/null http://192.168.50.10:8001/1TB.test.


Note that the OMV/Debian has no "status=progress" option and we had to use "pv".
We will try the same test on our Ubuntu image with "status=progress" tomorrow again.
User avatar
odroid
Site Admin
 
Posts: 25000
Joined: Fri Feb 22, 2013 11:14 pm
languages_spoken: English
ODROIDs: ODROID

Re: Getting UAS working on HK 4.9

Unread postby u-ra » Wed Aug 02, 2017 7:53 pm

I think your test is somewhat flawed since you did not specify bs on the input dd. This, together with two pipes is considerably limiting the throughput. For example:

Your test: (I have omitted the pv output and added iflag=fullblock so the output dd doesn't get partial reads.)
Code: Select all
[root@exodus ~]# dd if=/dev/sdb | pv | dd of=/dev/null bs=32M count=100 iflag=fullblock
100+0 records in
100+0 records out
3355443200 bytes (3,4 GB, 3,1 GiB) copied, 73,1592 s, 45,9 MB/s


Your test with bs=32M on the input dd as well:
Code: Select all
[root@exodus ~]# dd if=/dev/sdb bs=32M | pv | dd of=/dev/null bs=32M count=100 iflag=fullblock
100+0 records in
100+0 records out
3355443200 bytes (3,4 GB, 3,1 GiB) copied, 36,7293 s, 91,4 MB/s


Finally, plain dd with no pipes:
Code: Select all
[root@exodus ~]# dd if=/dev/sdb of=/dev/null bs=32M count=100
100+0 records in
100+0 records out
3355443200 bytes (3,4 GB, 3,1 GiB) copied, 24,9866 s, 134 MB/s


However, even the first case is enough to trigger the resets here.
I have another enclosure which supports UAS, but it's 2.5" and isn't externally powered. I will test the behaviour with it as well.
u-ra
 
Posts: 12
Joined: Tue May 17, 2016 9:06 pm
languages_spoken: english
ODROIDs: C2, XU4

Re: Getting UAS working on HK 4.9

Unread postby joaofl » Thu Aug 03, 2017 6:04 am

@odroid @u-ra
I got some VERY interesting results on the tests I've just run. I think it gives a good clue on the problem.

First, I've run the 3 tests u-ra mentioned in the last post, and got ZERO resets or errors. The numbers were actually good. For example the last test:
Code: Select all
dd if=/dev/sda of=/dev/null bs=32M count=100
100+0 records in
100+0 records out
3355443200 bytes (3.4 GB) copied, 18.3696 s, 183 MB/s


then I run iperf between my machine and the odroid, and got:
Code: Select all
[ ID] Interval       Transfer     Bandwidth
[  3]  0.0-10.0 sec   398 MBytes   334 Mbits/sec


Next, I run an iperf in parallel with the exact same dd last test. Steps were:
on the odroid:
Code: Select all
iperf -s

on my machine with fast wifi:
Code: Select all
iperf -c ip

on the odroid:
Code: Select all
dd if=/dev/sda of=/dev/null bs=32M count=100


From that i got
Code: Select all
dd if=/dev/sda of=/dev/null bs=32M count=200
200+0 records in
200+0 records out
6710886400 bytes (6.7 GB) copied, 68.6161 s, 97.8 MB/s

Which is the half of the throughput of the previous scenario.

and

Code: Select all
[ ID] Interval       Transfer     Bandwidth
[  3]  0.0-10.0 sec   339 MBytes   284 Mbits/sec


and hundreds if not thousand of resets, and a couple of errors. Like:
Code: Select all
[Wed Aug  2 21:51:15 2017] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[Wed Aug  2 21:51:15 2017] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[Wed Aug  2 21:51:15 2017] sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x07 driverbyte=0x00
[Wed Aug  2 21:51:15 2017] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x88 88 00 00 00 00 00 00 5e 28 00 00 00 01 00 00 00
[Wed Aug  2 21:51:15 2017] blk_update_request: I/O error, dev sda, sector 6170624
[Wed Aug  2 21:51:15 2017] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[Wed Aug  2 21:51:15 2017] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd


More interestingly, I had my computer and the odroid+external_hd just next to me, and exactly when iperf kiked in, with dd already running, I could clearly listen that the needle of the HD started to buzz around. At the end of iperf it stoped, and went smooth again. I think this clearly shows that the issue is due to eth+us3, which I guess to be the same as saying multiple USB3 in parallel (since the eth is behind a usb3) right?

Another interesting result is that by running the exact same test, but by replacing the HD with a USB3 fast pen drive I have here, and got no errors (what confuses me).

Also interesting to notice that the performance of the ethernet did not drop much compared to the drop on the HD. maybe the eth has better error recovering of some sort... Or have some priority? just guessing.

I never had such an issue on the previous kernel, that in the other hand only offered like half of the performance on the eth compared to what we get with this.

what do you think about it?
joaofl
 
Posts: 29
Joined: Sat Feb 27, 2016 2:29 am
Location: Portugal, Brasil
languages_spoken: english, portuguese, spanish
ODROIDs: XU4

Re: Getting UAS working on HK 4.9

Unread postby u-ra » Thu Aug 03, 2017 7:32 am

The UAS enclosure (the controller is ASMedia ASM1351, for what it's worth) did not fare much better when curl started:
Code: Select all
[  940.253784] sd 0:0:0:0: [sda] tag#1 data cmplt err -71 uas-tag 2 inflight: CMD
[  940.259877] sd 0:0:0:0: [sda] tag#1 CDB: opcode=0x28 28 00 0b 01 5f 00 00 01 00 00
[  973.324516] sd 0:0:0:0: [sda] tag#0 uas_eh_abort_handler 0 uas-tag 1 inflight: CMD IN
[  973.331083] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 0b 01 60 00 00 01 00 00
[  973.338927] sd 0:0:0:0: [sda] tag#1 uas_eh_abort_handler 0 uas-tag 2 inflight: CMD
[  973.346238] sd 0:0:0:0: [sda] tag#1 CDB: opcode=0x28 28 00 0b 01 5f 00 00 01 00 00
[  973.353868] scsi host0: uas_eh_bus_reset_handler start
[  973.439677] usb 4-1.2: reset SuperSpeed USB device number 3 using xhci-hcd
[  973.468220] scsi host0: uas_eh_bus_reset_handler success

It's interesting that if I limit the link speed to 10Base-T with mii-tool, then things behave well with the Norelsys enclosure.
dd is going at full speed for as long as I let it run, while the curl download is of course limited to ~900 kbit/s.

Also, it would appear that backporting this commit seems to help things a little:
Code: Select all
[root@exodus ~]# echo "START DD" > /dev/kmsg ; dd if=/dev/sda of=/dev/null bs=32M status=progress49049763840 bytes (49 GB, 46 GiB) copied, 381,202 s, 129 MB/s
dd: error reading '/dev/sda': Input/output error
1461+1 records in
1461+1 records out
49049763840 bytes (49 GB, 46 GiB) copied, 382,712 s, 128 MB/s


Code: Select all
[root@exodus ~]# while true; do echo "START CURL" > /dev/kmsg; curl -o /dev/null http://lg.nl.ramnode.com/static/1000MB.test; done
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100  953M  100  953M    0     0  11.6M      0  0:01:22  0:01:22 --:--:-- 12.1M
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100  953M  100  953M    0     0  9883k      0  0:01:38  0:01:38 --:--:-- 10.2M
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100  953M  100  953M    0     0  10.1M      0  0:01:34  0:01:34 --:--:-- 10.7M
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100  953M  100  953M    0     0  11.1M      0  0:01:25  0:01:25 --:--:-- 8993k
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
 18  953M   18  174M    0     0  7525k      0  0:02:09  0:00:23  0:01:46 7419k


Code: Select all
[   35.309016] START DD
[   47.373326] START CURL
[   49.420747] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   60.450766] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   71.330887] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   76.475805] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   80.410823] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   84.505905] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   90.131602] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   94.447445] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  115.345293] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  116.960502] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  123.651095] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  129.599157] START CURL
[  135.561960] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  139.337224] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  151.112894] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  160.023320] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  161.828401] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  213.325163] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  227.930516] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  228.441710] START CURL
[  233.390669] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  265.091469] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  290.372092] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  301.267365] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  302.227402] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  303.177408] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  313.402696] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  318.227774] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  322.839027] START CURL
[  336.418196] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  344.333377] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  350.398567] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  355.553717] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  378.669309] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  379.769288] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  388.919527] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  397.784730] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  408.293665] START CURL
[  412.945338] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[  412.970173] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[  413.180188] hub 4-1:1.0: hub_ext_port_status failed (err = -71)
[  413.253943] usb 4-1.1: USB disconnect, device number 3
...


The test survives for much longer than before. Could be a fluke, though...
u-ra
 
Posts: 12
Joined: Tue May 17, 2016 9:06 pm
languages_spoken: english
ODROIDs: C2, XU4

Re: Getting UAS working on HK 4.9

Unread postby crashoverride » Thu Aug 03, 2017 10:14 am

u-ra wrote:uas_eh_abort_handler 0 uas-tag 1 inflight: CMD IN

Try disabling UAS.
crashoverride
 
Posts: 3102
Joined: Tue Dec 30, 2014 8:42 pm
languages_spoken: english
ODROIDs: C1

Re: Getting UAS working on HK 4.9

Unread postby crashoverride » Thu Aug 03, 2017 10:16 am

joaofl wrote:I could clearly listen that the needle of the HD started to buzz around.

Try running a full SMART test to see if the HDD is failing or has bad sectors.
crashoverride
 
Posts: 3102
Joined: Tue Dec 30, 2014 8:42 pm
languages_spoken: english
ODROIDs: C1

Re: Getting UAS working on HK 4.9

Unread postby crashoverride » Thu Aug 03, 2017 10:22 am

I should note that I have tested another USB3 ARM board, and the exact same issues are present there. There are no platforms, including PC, where UAS is not problematic for many devices.

To verify UAS is disabled:
Code: Select all
$ dmesg | grep "UAS is blacklisted"
[   10.176104] usb 5-1: UAS is blacklisted for this device, using usb-storage instead

If you do not see the phrase "UAS is blacklisted" in the log, then UAS is enabled.
(Note the above is from a different board and will not be an exact match on XU4)

[edit]
Also note that disabling UAS is per USB device. Each controller (VID:PID) needs to be explicitly disabled in boot.ini. There is currently no option to globally disable UAS for all devices.
crashoverride
 
Posts: 3102
Joined: Tue Dec 30, 2014 8:42 pm
languages_spoken: english
ODROIDs: C1

Re: Getting UAS working on HK 4.9

Unread postby odroid » Thu Aug 03, 2017 6:47 pm

We tested again with ubuntu-16.04.2-minimal-odroid-xu4-20170516.img + update (Ubuntu 16.04.3 LTS, 4.9.37)
We used a Seagte 2TB 2.5" HDD with JMS578 bridge for the test. UAS was enabled.

Run below two commands in parallel.
Code: Select all
echo "START DD" &gt; /dev/kmsg; dd if=/dev/sda of=/dev/null bs=32M status=progress
echo "START CURL count:"$count  &gt; /dev/kmsg; curl -o /dev/null http://192.168.50.10:8001/1TB.test


Run over 8 hours. Total ~3TB data transferred via USB 3.0. Average HDD access speed is around 115MB/sec. We had to run it twice because 2TB HDD reading was done earlier.
Code: Select all
root@odroid:~# echo "START DD" &gt; /dev/kmsg; dd if=/dev/sda of=/dev/null bs=32M status=progress
2000398934016 bytes (2.0 TB, 1.8 TiB) copied, 19458.2 s, 103 MB/s
59616+1 records in
59616+1 records out
root@odroid:~# echo "START DD" &gt; /dev/kmsg; dd if=/dev/sda of=/dev/null bs=32M status=progress
1290067247104 bytes (1.3 TB, 1.2 TiB) copied, 10466.3 s, 123 MB/s
38448+0 records in
38447+0 records out


Total ~3TB data transferred via Ethernet port. Average network speed is near 1Gbps.
Code: Select all
root@odroid:~# ./170802_network_test_1TB.sh
Start infinite curl command
count:1
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100 1024G  100 1024G    0     0   103M      0  2:48:50  2:48:50 --:--:--  111M
count:2
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
            Dload  Upload   Total   Spent    Left  Speed
100 1024G  100 1024G    0     0   108M      0  2:40:21  2:40:21 --:--:--  103M
count:3
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
100 1024G  100 1024G    0     0   102M      0  2:50:27  2:50:27 --:--:--  110M


We couldn't find any error in the log output.
Code: Select all
[  105.632560] START DD
[  111.982390] START CURL count:1
[10242.316368] START CURL count:2
[19670.966110] START DD
[19863.502841] START CURL count:3


We will keep running this test by early next week to make sure.
I hope 30TB test should be enough.
User avatar
odroid
Site Admin
 
Posts: 25000
Joined: Fri Feb 22, 2013 11:14 pm
languages_spoken: English
ODROIDs: ODROID

Re: Getting UAS working on HK 4.9

Unread postby joaofl » Thu Aug 03, 2017 11:45 pm

@odroid
This clearly shows that the issue manifest on specific usb3-sata bridges only. I dont think there is even need for you to test any longer, considering that just a few megabytes is enough to completely destabilize my XU4 setup here.

I would like to dig a bit deeper on this problem if I could, maybe on the driver of the controller I'm using. What do you suggest? How can I debug it more deeply?

Thanks!
Last edited by joaofl on Fri Aug 04, 2017 12:11 am, edited 1 time in total.
joaofl
 
Posts: 29
Joined: Sat Feb 27, 2016 2:29 am
Location: Portugal, Brasil
languages_spoken: english, portuguese, spanish
ODROIDs: XU4

Re: Getting UAS working on HK 4.9

Unread postby moon.linux » Thu Aug 03, 2017 11:57 pm

I agree with @joaofl,
In my testing using rsync to miscroSD card the performance is quit good but when I try to
rsync on sata drive is not able to complete the write to the disk efficiently.

Code: Select all
[   16.794564] fuse init (API version 7.26)
[   17.556880] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   22.132020] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   22.256839] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   26.731921] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   31.836830] usb 4-1.2: Disable of device-initiated U1 failed.
[   36.956777] usb 4-1.2: Disable of device-initiated U2 failed.
[   37.037180] usb 4-1.2: reset SuperSpeed USB device number 4 using xhci-hcd
[   37.136953] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   41.612187] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   46.087165] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   46.114001] sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x07 driverbyte=0x00
[   46.114058] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 3a 38 5d d0 00 00 08 00
[   46.114098] blk_update_request: I/O error, dev sda, sector 976772560
[   50.567088] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   50.697099] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   55.172075] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   59.647155] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   64.122046] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   68.602059] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   73.076569] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   73.100569] sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x07 driverbyte=0x00
[   73.100578] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 3a 38 5d d0 00 00 08 00
[   73.100585] blk_update_request: I/O error, dev sda, sector 976772560
[   73.105493] Buffer I/O error on dev sda, logical block 122096570, async page read
[   77.551519] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   77.986553] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   82.461534] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   86.936512] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   91.411493] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[   95.886521] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  100.361472] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  100.384847] sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x07 driverbyte=0x00
[  100.384856] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 3a 38 5d d0 00 00 08 00
[  100.384862] blk_update_request: I/O error, dev sda, sector 976772560
[  100.389765] Buffer I/O error on dev sda, logical block 122096570, async page read
[  104.841432] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  109.316425] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  113.791425] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  118.271378] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  122.746395] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  127.221374] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  131.696367] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  131.719950] sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x07 driverbyte=0x00
[  131.719958] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 3a 38 5f 80 00 00 08 00
[  131.719965] blk_update_request: I/O error, dev sda, sector 976772992
[  136.171293] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  140.646092] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  145.120893] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  149.595695] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  154.070520] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  158.545330] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  158.568949] sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x07 driverbyte=0x00
[  158.568958] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 3a 38 5f 80 00 00 08 00
[  158.568964] blk_update_request: I/O error, dev sda, sector 976772992
[  158.573866] Buffer I/O error on dev sda1, logical block 122096368, async page read
[  163.020158] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  167.494945] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  171.969789] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  176.449576] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  180.924462] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  185.399253] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  189.874117] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[  189.897587] sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x07 driverbyte=0x00
[  189.897596] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x28 28 00 3a 38 5f 80 00 00 08 00
[  189.897602] blk_update_request: I/O error, dev sda, sector 976772992
[  194.348957] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd

I am also trying to find a perfect solution to the problem.
moon.linux
 
Posts: 919
Joined: Thu Oct 02, 2014 11:42 pm
languages_spoken: english

Re: Getting UAS working on HK 4.9

Unread postby joaofl » Fri Aug 04, 2017 3:25 am

I've figured out that the USB3-SATA controller from WD My Book 8TB (My Book 25EE), is actually based on a Asmedia ASM1051 chip. I still have to open it up to confirm, but thats what I read around. This seems to be a problematic controller, since Asmedia used the exact same identifier on many different controllers, which seems to have massed up linux drivers for it.

But if the issue is driver-related, I would happen to this model only, and would also happen in a normal linux x64 machine. Right?

Some guy somewhere in an old post (which I lost the link to), had similar issues of USB resets, back in 2012. What solved his issue was to decrease the max sectors size, by editing the file: /sys/block/sda/device/max_sectors
Although I could not confirm this, because even if you change the value there, the same 2048 is loaded there back again after reboot. Also, I have no idea what this parameters function is, and its impact on the overall performance.
joaofl
 
Posts: 29
Joined: Sat Feb 27, 2016 2:29 am
Location: Portugal, Brasil
languages_spoken: english, portuguese, spanish
ODROIDs: XU4

Re: Getting UAS working on HK 4.9

Unread postby mad_ady » Fri Aug 04, 2017 3:42 am

Can you try this advice I received a few months ago on irc?
(18:24:41) Vzox01: ngkaho1234: what do you have in /sys/bus/usb/devices/*/avoid_reset_quirk? where * is the usb port number
(18:26:41) Vzox01: ngkaho1234: it's just that I had a similar problem with an external hardrive, luckily it did not result in any data loss or FS curruption, but the OS could no longer see the FS until reboot, then everything mounted ok. I have echo 1 > avoid_reset_quirk put during boot and this problem with bus reset never occurred
(18:27:58) Vzox01: oooh, sorry, those two messages were intended for mad_ady
(18:31:10) Vzox01: mad_ady: it seems that some USB3 controllers have a problem with Linux, and cause bus resets occasionally, which is a bad thing with an external hard drive. so there's a flag to avoid resets and it's located in /sys/bus/usb/devices/N-M/avoid_reset_quirk
User avatar
mad_ady
 
Posts: 2748
Joined: Wed Jul 15, 2015 5:00 pm
Location: Bucharest, Romania
languages_spoken: english
ODROIDs: XU4, C1+, C2

Re: Getting UAS working on HK 4.9

Unread postby joaofl » Fri Aug 04, 2017 10:01 am

@mad_ady

It actually works. By placing '1' at sys/bus/usb/devices//4-1.1/avoid_reset_quirk , it actually stops reseting as often, and I stop to listen the needle buzzing in the HD. But there are some other consequences. There are still IO errors, but it seems that the OS no longer recovers from it. The errors are:

Code: Select all
[  283.995568] sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x07 driverbyte=0x00
[  283.995579] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x88 88 00 00 00 00 00 00 00 00 00 00 00 02 00 00 00
[  283.995590] blk_update_request: I/O error, dev sda, sector 0
[  551.515546] sd 0:0:0:0: [sda] tag#0 UNKNOWN(0x2003) Result: hostbyte=0x07 driverbyte=0x00
[  551.515555] sd 0:0:0:0: [sda] tag#0 CDB: opcode=0x88 88 00 00 00 00 00 00 53 35 00 00 00 01 00 00 00
[  551.515561] blk_update_request: I/O error, dev sda, sector 5453056


And the transfer rate using dd from the HD drop down to zero at some point. dd outputs this:

Without iperf running in parallel:
Code: Select all
root@odroid:~# dd if=/dev/sda of=/dev/null bs=32M count=200
200+0 records in
200+0 records out
6710886400 bytes (6.7 GB) copied, 36.5995 s, 183 MB/s

With iperf in parallel:
Code: Select all
root@odroid:~# dd if=/dev/sda of=/dev/null bs=32M count=200
200+0 records in
200+0 records out
6710886400 bytes (6.7 GB) copied, 223.285 s, 30.1 MB/s


So the problem is still there, clearly. But no more resets..
joaofl
 
Posts: 29
Joined: Sat Feb 27, 2016 2:29 am
Location: Portugal, Brasil
languages_spoken: english, portuguese, spanish
ODROIDs: XU4

Re: Getting UAS working on HK 4.9

Unread postby joaofl » Fri Aug 04, 2017 12:32 pm

Just tested 4 more different USB3-SATA bridges.

In summary, only 1 of them all worked. The two from WD (My Book 8T, and My Passport 2T) had both the same issues as discussed.
Then I took the 8T HD from the enclosure, and connected to another controller. Also an ASMedia based. Had the exact same issues.

Then I connect a USB powered SSD to a third controller (used on this Orico bridge recognized as Toshiba). It does not even load the device. It is not reconized neither initiated as a mass-storage device. On my pc runing ubuntu it runs smooth.

It seems that the issue happens not in a single controller after all. This ASMedia ones seems to be a bit problematic on the ARM...

Follows attached some details and the errors I got from the tests (it is a bit rough).
Attachments
Testes USB3 com HD externos + OdroidXU4.txt
(6.79 KiB) Downloaded 25 times
joaofl
 
Posts: 29
Joined: Sat Feb 27, 2016 2:29 am
Location: Portugal, Brasil
languages_spoken: english, portuguese, spanish
ODROIDs: XU4

Re: Getting UAS working on HK 4.9

Unread postby mad_ady » Fri Aug 04, 2017 2:52 pm

@joaofl: yes, it seems the quirks setting masks the problem rather than fixing it... You may want to try it on the ethernet usb port as well, though I doubt it will improve things.

One more thing to consider - can you try moving the USB interrupts for the ethernet on a different core than USB interrupts for the USB ports? Something like this: https://raw.githubusercontent.com/mad-a ... ty.service

Maybe it's caused by an interrupt running on the same CPU for both network and storage...
User avatar
mad_ady
 
Posts: 2748
Joined: Wed Jul 15, 2015 5:00 pm
Location: Bucharest, Romania
languages_spoken: english
ODROIDs: XU4, C1+, C2

Re: Getting UAS working on HK 4.9

Unread postby joaofl » Mon Aug 07, 2017 8:50 am

mad_ady wrote:One more thing to consider - can you try moving the USB interrupts for the ethernet on a different core than USB interrupts for the USB ports? Something like this: https://raw.githubusercontent.com/mad-a ... ty.service
Maybe it's caused by an interrupt running on the same CPU for both network and storage...


Just tried it. I added the following service (into the file /etc/systemd/system/cpu_affinity.service). I tried to place each USB in a different CPU counting from 4 to 6. Is that correct?

Code: Select all
[Unit]
Description=Setup special irq affinity
Before=sysinit.target
After=local-fs.target
DefaultDependencies=no

[Service]
Type=oneshot
ExecStart=/bin/true
ExecStartPost=-/bin/sh -c 'j=4; for i in `cat /proc/interrupts | grep usb | cut -d ":" -f 1`; do echo "$j" > /proc/irq/$i/smp_affinity_list; j=$((j+1)); done'

[Install]
WantedBy=sysinit.target


It really seems it improved a bit the throughput of both run simultaneously (dd and iperf, as tested before). The degradation on performace of dd due to iperf is not as big as before, it seem.

However, I still get the resets:
Code: Select all
[Mon Aug  7 00:42:59 2017] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[Mon Aug  7 00:43:03 2017] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[Mon Aug  7 00:43:05 2017] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[Mon Aug  7 00:43:08 2017] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[Mon Aug  7 00:43:10 2017] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
[Mon Aug  7 00:43:10 2017] usb 4-1.1: reset SuperSpeed USB device number 3 using xhci-hcd
joaofl
 
Posts: 29
Joined: Sat Feb 27, 2016 2:29 am
Location: Portugal, Brasil
languages_spoken: english, portuguese, spanish
ODROIDs: XU4

Re: Getting UAS working on HK 4.9

Unread postby mad_ady » Mon Aug 07, 2017 2:19 pm

Ok, so it's not caused by interrupts. Sorry, I'm out of ideas.
User avatar
mad_ady
 
Posts: 2748
Joined: Wed Jul 15, 2015 5:00 pm
Location: Bucharest, Romania
languages_spoken: english
ODROIDs: XU4, C1+, C2

Re: Getting UAS working on HK 4.9

Unread postby bronco » Mon Aug 07, 2017 3:33 pm

joaofl wrote:Just tested 4 more different USB3-SATA bridges.


Your debug output is somewhat lacking (you pasted wrong information when testing on a PC and chose the host controller and not the enclosure). Besides that I really wonder why generic USB hassles are discussed in a driver related thread talking about UAS. Care to check your logs:
Code: Select all
             configuration: driver=usb-storage speed=5000Mbit/s
             configuration: driver=usb-storage speed=5000Mbit/s
             configuration: driver=uas maxpower=896mA speed=5000Mbit/s
             configuration: driver=xhci_hcd latency=0
             configuration: driver=usb-storage speed=5000Mbit/s


The one time when UAS was used your log is filled with stuff like this:
Code: Select all
[ 2241.495373] sd 0:0:0:0: Device offlined - not ready after error recovery
[ 2241.495379] sd 0:0:0:0: Device offlined - not ready after error recovery
[ 2241.495484] sd 0:0:0:0: rejecting I/O to offline device
[ 2241.495508] sd 0:0:0:0: rejecting I/O to offline device
[ 2241.495534] sd 0:0:0:0: rejecting I/O to offline device
[ 2241.495543] sd 0:0:0:0: rejecting I/O to offline device
[ 2241.495562] sd 0:0:0:0: rejecting I/O to offline device
[ 2241.495578] sd 0:0:0:0: [sda] Read Capacity(16) failed: Result: hostbyte=0x01 driverbyte=0x00
[ 2241.495585] sd 0:0:0:0: [sda] Sense not available.
[ 2241.495596] sd 0:0:0:0: rejecting I/O to offline device
[ 2241.495608] sd 0:0:0:0: rejecting I/O to offline device
[ 2241.495629] sd 0:0:0:0: rejecting I/O to offline device
[ 2241.495669] sd 0:0:0:0: [sda] Read Capacity(10) failed: Result: hostbyte=0x01 driverbyte=0x00
[ 2241.495689] sd 0:0:0:0: [sda] Sense not available.
[ 2241.495709] sd 0:0:0:0: rejecting I/O to offline device
[ 2241.495735] sd 0:0:0:0: rejecting I/O to offline device
[ 2241.495758] sd 0:0:0:0: rejecting I/O to offline device
[ 2241.495773] sd 0:0:0:0: [sda] Write Protect is off
[ 2241.495787] sd 0:0:0:0: [sda] Mode Sense: 00 00 00 00
[ 2241.495801] sd 0:0:0:0: rejecting I/O to offline device
[ 2241.495816] sd 0:0:0:0: [sda] Asking for cache data failed
[ 2241.495826] sd 0:0:0:0: [sda] Assuming drive cache: write through
[ 2241.495840] sd 0:0:0:0: rejecting I/O to offline device
[ 2241.495857] sd 0:0:0:0: rejecting I/O to offline device
[ 2241.495872] sd 0:0:0:0: rejecting I/O to offline device
[ 2241.496400] sd 0:0:0:0: [sda] Attached SCSI disk


When I read 'Device offlined' I start immediately to check cables/connectors...

When you talk about 'tested 4 more different USB3-SATA bridges' that also means 4 times interconnecting cables and receptacles. Please see here https://forum.openmediavault.org/index. ... post148500 at the bottom of this post why USB3 connector issues are quite common.
bronco
 
Posts: 27
Joined: Tue Jul 11, 2017 2:58 pm
languages_spoken: english

Re: Getting UAS working on HK 4.9

Unread postby joaofl » Mon Aug 07, 2017 10:04 pm

bronco wrote:Your debug output is somewhat lacking (you pasted wrong information when testing on a PC and chose the host controller and not the enclosure). Besides that I really wonder why generic USB hassles are discussed in a driver related thread talking about UAS.


Like I said, the log was rough. Those were more to take some conclusions, and narrow down the possibilities. The discussions is not about driver related issues, but to the possible causes of issues on USB devices. Maybe that the issue related to UAS, also affects in different ways mass storage and possibly other devices on the USB. No need to wonder.

bronco wrote:When I read 'Device offlined' I start immediately to check cables/connectors...
When you talk about 'tested 4 more different USB3-SATA bridges' that also means 4 times interconnecting cables and receptacles. Please see here https://forum.openmediavault.org/index. ... post148500 at the bottom of this post why USB3 connector issues are quite common.


Believe me, I've done every test with cables. I have at least 6 of them here. Long, short, old, new... It happens in all of them.. Also tested on 2 different XU4 running the same image, to make sure the issue was not on the USB3 connector of the board. Exact same issue on both boards.
joaofl
 
Posts: 29
Joined: Sat Feb 27, 2016 2:29 am
Location: Portugal, Brasil
languages_spoken: english, portuguese, spanish
ODROIDs: XU4

Previous

Return to Linux Kernel 4.14 Debugging Party

Who is online

Users browsing this forum: No registered users and 2 guests