N2 hangs during local "rsync" or "cp" from external USB3.0 HDDs.

[Moan]

I'm using Armbian for Odroid N2 4GB with the official kernel from Hardkernel. I've got 2 external HDDs: WD My Book 4TB and WD My Book 8TB (they both have their own power source).
They're connected by USB3.0 directly to Odroid N2.

Whenever I run the local rsync job (or set cp command manually to backup folders) it crashes sooner or later. The speed during copying is 90-120MB/s.
I updated file boot.ini, added "usb-xhci.tablesize=2" at the end of the file, rebooted, etc. but it didn't help.

Today at night I ran a "cp" of a big fle (around 1TB) and it crashed at ~700GB. All USB3.0 disks were unresponsive and were keep spinning (not going into the sleep mode).

messages:

Code: Select all

Aug 29 05:09:06 localhost kernel: [ 7679.633486@0] xhci-hcd xhci-hcd.0.auto: xHCI host not responding to stop endpoint command.
Aug 29 05:09:06 localhost kernel: [ 7679.633495@0] xhci-hcd xhci-hcd.0.auto: Assuming host is dying, halting host.
Aug 29 05:09:06 localhost kernel: [ 7679.649516@0] xhci-hcd xhci-hcd.0.auto: Host not halted after 16000 microseconds.
Aug 29 05:09:06 localhost kernel: [ 7679.649527@0] xhci-hcd xhci-hcd.0.auto: Non-responsive xHCI host is not halting.
Aug 29 05:09:06 localhost kernel: [ 7679.649533@0] xhci-hcd xhci-hcd.0.auto: Completing active URBs anyway.
Aug 29 05:09:06 localhost kernel: [ 7679.649855@0] xhci-hcd xhci-hcd.0.auto: xHCI host not responding to stop endpoint command.
Aug 29 05:09:06 localhost kernel: [ 7679.649859@0] xhci-hcd xhci-hcd.0.auto: Assuming host is dying, halting host.
Aug 29 05:09:06 localhost kernel: [ 7679.649931@1] usb 2-1.1: USB disconnect, device number 4
Aug 29 05:09:06 localhost kernel: [ 7679.658230@0] usb 1-1: USB disconnect, device number 2
Aug 29 05:09:06 localhost kernel: [ 7679.658242@0] usb 1-1.3: USB disconnect, device number 5
Aug 29 05:09:06 localhost kernel: [ 7679.661602@0] usb 2-1: USB disconnect, device number 2
Aug 29 05:09:06 localhost kernel: [ 7679.665628@0] EXT4-fs warning (device sda1): ext4_end_bio:313: I/O error -5 writing to inode 12 (offset 753942921216 size 8388608 starting block 306350080)
Aug 29 05:09:06 localhost kernel: [ 7679.667655@1] EXT4-fs warning (device sda1): ext4_end_bio:313: I/O error -5 writing to inode 12 (offset 753942921216 size 8388608 starting block 306350336)
Aug 29 05:09:06 localhost kernel: [ 7679.668350@1] JBD2: Detected IO errors while flushing file data on sda1-8
Aug 29 05:09:06 localhost kernel: [ 7679.737590@0] sd 1:0:0:0: [sdb] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
Aug 29 05:09:06 localhost kernel: [ 7679.737600@0] sd 1:0:0:0: [sdb] tag#0 CDB: Read(16) 88 00 00 00 00 02 b9 e9 5f 80 00 00 01 00 00 00
Aug 29 05:09:06 localhost kernel: [ 7679.817603@0] sd 1:0:0:0: [sdb] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
Aug 29 05:09:06 localhost kernel: [ 7679.817614@0] sd 1:0:0:0: [sdb] tag#0 CDB: Read(16) 88 00 00 00 00 02 b9 e9 60 80 00 00 01 00 00 00
Aug 29 05:09:06 localhost kernel: [ 7679.836385@1] usb 2-1.2: USB disconnect, device number 5
Aug 29 05:09:07 localhost kernel: [ 7681.004296@1] usb 2-1.3: USB disconnect, device number 3
Aug 29 07:06:58 localhost kernel: [14751.105728@0] hrtimer: interrupt took 288722 ns

syslog:

Code: Select all

Aug 29 05:09:00 localhost systemd[1]: Starting Clean php session files...
Aug 29 05:09:01 localhost systemd[1]: Started Clean php session files.
Aug 29 05:09:01 localhost CRON[18199]: (root) CMD (  [ -x /usr/lib/php/sessionclean ] && if [ ! -d /run/systemd/system ]; then /usr/lib/php/sessionclean; fi)
Aug 29 05:09:06 localhost kernel: [ 7679.633486@0] xhci-hcd xhci-hcd.0.auto: xHCI host not responding to stop endpoint command.
Aug 29 05:09:06 localhost kernel: [ 7679.633495@0] xhci-hcd xhci-hcd.0.auto: Assuming host is dying, halting host.
Aug 29 05:09:06 localhost kernel: [ 7679.649516@0] xhci-hcd xhci-hcd.0.auto: Host not halted after 16000 microseconds.
Aug 29 05:09:06 localhost kernel: [ 7679.649527@0] xhci-hcd xhci-hcd.0.auto: Non-responsive xHCI host is not halting.
Aug 29 05:09:06 localhost kernel: [ 7679.649533@0] xhci-hcd xhci-hcd.0.auto: Completing active URBs anyway.
Aug 29 05:09:06 localhost kernel: [ 7679.649710@1] hub 2-1:1.0: hub_ext_port_status failed (err = -108)
Aug 29 05:09:06 localhost kernel: [ 7679.649724@1] usb 2-1-port1: cannot reset (err = -108)
Aug 29 05:09:06 localhost kernel: [ 7679.649734@1] usb 2-1-port1: cannot reset (err = -108)
Aug 29 05:09:06 localhost kernel: [ 7679.649743@1] usb 2-1-port1: cannot reset (err = -108)
Aug 29 05:09:06 localhost kernel: [ 7679.649752@1] usb 2-1-port1: cannot reset (err = -108)
Aug 29 05:09:06 localhost kernel: [ 7679.649760@1] usb 2-1-port1: cannot reset (err = -108)
Aug 29 05:09:06 localhost kernel: [ 7679.649764@1] usb 2-1-port1: Cannot enable. Maybe the USB cable is bad?
Aug 29 05:09:06 localhost kernel: [ 7679.649775@1] usb 2-1-port1: cannot disable (err = -108)
Aug 29 05:09:06 localhost kernel: [ 7679.649798@1] hub 2-1:1.0: hub_ext_port_status failed (err = -108)
Aug 29 05:09:06 localhost kernel: [ 7679.649807@1] usb 2-1-port1: cannot reset (err = -108)
Aug 29 05:09:06 localhost kernel: [ 7679.649816@1] usb 2-1-port1: cannot reset (err = -108)
Aug 29 05:09:06 localhost kernel: [ 7679.649825@1] usb 2-1-port1: cannot reset (err = -108)
Aug 29 05:09:06 localhost kernel: [ 7679.649831@0] xhci-hcd xhci-hcd.0.auto: HC died; cleaning up
Aug 29 05:09:06 localhost kernel: [ 7679.649834@1] usb 2-1-port1: cannot reset (err = -108)
Aug 29 05:09:06 localhost kernel: [ 7679.649839@1] usb 2-1-port1: cannot reset (err = -108)
Aug 29 05:09:06 localhost kernel: [ 7679.649842@1] usb 2-1-port1: Cannot enable. Maybe the USB cable is bad?
Aug 29 05:09:06 localhost kernel: [ 7679.649848@1] usb 2-1-port1: cannot disable (err = -108)
Aug 29 05:09:06 localhost kernel: [ 7679.649855@0] xhci-hcd xhci-hcd.0.auto: xHCI host not responding to stop endpoint command.
Aug 29 05:09:06 localhost kernel: [ 7679.649859@0] xhci-hcd xhci-hcd.0.auto: Assuming host is dying, halting host.
Aug 29 05:09:06 localhost kernel: [ 7679.649931@1] usb 2-1.1: USB disconnect, device number 4
Aug 29 05:09:06 localhost kernel: [ 7679.657732@0] xhci-hcd xhci-hcd.0.auto: HC died; cleaning up
Aug 29 05:09:06 localhost kernel: [ 7679.658230@0] usb 1-1: USB disconnect, device number 2
Aug 29 05:09:06 localhost kernel: [ 7679.658242@0] usb 1-1.3: USB disconnect, device number 5
Aug 29 05:09:06 localhost kernel: [ 7679.661602@0] usb 2-1: USB disconnect, device number 2
Aug 29 05:09:06 localhost kernel: [ 7679.665605@0] blk_update_request: I/O error, dev sda, sector 2450798592
Aug 29 05:09:06 localhost kernel: [ 7679.665628@0] EXT4-fs warning (device sda1): ext4_end_bio:313: I/O error -5 writing to inode 12 (offset 753942921216 size 8388608 starting block 306350080)
Aug 29 05:09:06 localhost kernel: [ 7679.665639@0] Buffer I/O error on device sda1, logical block 306349568
Aug 29 05:09:06 localhost kernel: [ 7679.665658@0] Buffer I/O error on device sda1, logical block 306349569
Aug 29 05:09:06 localhost kernel: [ 7679.665663@0] Buffer I/O error on device sda1, logical block 306349570
Aug 29 05:09:06 localhost kernel: [ 7679.665670@0] Buffer I/O error on device sda1, logical block 306349571
Aug 29 05:09:06 localhost kernel: [ 7679.665681@0] Buffer I/O error on device sda1, logical block 306349572
Aug 29 05:09:06 localhost kernel: [ 7679.665686@0] Buffer I/O error on device sda1, logical block 306349573
Aug 29 05:09:06 localhost kernel: [ 7679.665691@0] Buffer I/O error on device sda1, logical block 306349574
Aug 29 05:09:06 localhost kernel: [ 7679.665698@0] Buffer I/O error on device sda1, logical block 306349575
Aug 29 05:09:06 localhost kernel: [ 7679.665709@0] Buffer I/O error on device sda1, logical block 306349576
Aug 29 05:09:06 localhost kernel: [ 7679.665717@0] Buffer I/O error on device sda1, logical block 306349577
Aug 29 05:09:06 localhost kernel: [ 7679.667634@1] blk_update_request: I/O error, dev sda, sector 2450800640
Aug 29 05:09:06 localhost kernel: [ 7679.667655@1] EXT4-fs warning (device sda1): ext4_end_bio:313: I/O error -5 writing to inode 12 (offset 753942921216 size 8388608 starting block 306350336)
Aug 29 05:09:06 localhost kernel: [ 7679.668350@1] JBD2: Detected IO errors while flushing file data on sda1-8
Aug 29 05:09:06 localhost kernel: [ 7679.668367@1] blk_update_request: I/O error, dev sda, sector 3905239528
Aug 29 05:09:06 localhost kernel: [ 7679.668441@1] Aborting journal on device sda1-8.
Aug 29 05:09:06 localhost kernel: [ 7679.668457@1] blk_update_request: I/O error, dev sda, sector 3905161216
Aug 29 05:09:06 localhost kernel: [ 7679.668464@1] Buffer I/O error on dev sda1, logical block 488144896, lost sync page write
Aug 29 05:09:06 localhost kernel: [ 7679.668470@1] JBD2: Error -5 detected when updating journal superblock for sda1-8.
Aug 29 05:09:06 localhost kernel: [ 7679.668532@1] EXT4-fs (sda1): Delayed block allocation failed for inode 12 at logical offset 184070144 with max blocks 2048 with error 30
Aug 29 05:09:06 localhost kernel: [ 7679.681659@2] EXT4-fs (sda1): This should not happen!! Data will be lost
Aug 29 05:09:06 localhost kernel: [ 7679.681659@2] 
Aug 29 05:09:06 localhost kernel: [ 7679.695284@2] EXT4-fs error (device sda1) in ext4_writepages:2853: Journal has aborted
Aug 29 05:09:06 localhost kernel: [ 7679.702545@2] blk_update_request: I/O error, dev sda, sector 2048
Aug 29 05:09:06 localhost kernel: [ 7679.702551@2] Buffer I/O error on dev sda1, logical block 0, lost sync page write
Aug 29 05:09:06 localhost kernel: [ 7679.707478@2] EXT4-fs (sda1): previous I/O error to superblock detected
Aug 29 05:09:06 localhost kernel: [ 7679.707525@2] blk_update_request: I/O error, dev sda, sector 2048
Aug 29 05:09:06 localhost kernel: [ 7679.707530@2] Buffer I/O error on dev sda1, logical block 0, lost sync page write
Aug 29 05:09:06 localhost kernel: [ 7679.707551@2] EXT4-fs error (device sda1): ext4_journal_check_start:56: Detected aborted journal
Aug 29 05:09:06 localhost kernel: [ 7679.714244@2] EXT4-fs (sda1): Remounting filesystem read-only
Aug 29 05:09:06 localhost kernel: [ 7679.720750@2] EXT4-fs (sda1): previous I/O error to superblock detected
Aug 29 05:09:06 localhost kernel: [ 7679.720766@2] blk_update_request: I/O error, dev sda, sector 2048
Aug 29 05:09:06 localhost kernel: [ 7679.720769@2] Buffer I/O error on dev sda1, logical block 0, lost sync page write
Aug 29 05:09:06 localhost kernel: [ 7679.720782@2] EXT4-fs (sda1): ext4_writepages: jbd2_start: 9223372036854775807 pages, ino 12; err -30
Aug 29 05:09:06 localhost kernel: [ 7679.737590@0] sd 1:0:0:0: [sdb] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
Aug 29 05:09:06 localhost kernel: [ 7679.737600@0] sd 1:0:0:0: [sdb] tag#0 CDB: Read(16) 88 00 00 00 00 02 b9 e9 5f 80 00 00 01 00 00 00
Aug 29 05:09:06 localhost kernel: [ 7679.737605@0] blk_update_request: I/O error, dev sdb, sector 11709013888
Aug 29 05:09:06 localhost kernel: [ 7679.817603@0] sd 1:0:0:0: [sdb] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
Aug 29 05:09:06 localhost kernel: [ 7679.817614@0] sd 1:0:0:0: [sdb] tag#0 CDB: Read(16) 88 00 00 00 00 02 b9 e9 60 80 00 00 01 00 00 00
Aug 29 05:09:06 localhost kernel: [ 7679.817619@0] blk_update_request: I/O error, dev sdb, sector 11709014144

I bought this device shortly after release (directly from Hardkernel), for NAS purposes. I was experiencing the random hangs before, but I thought it will be fixed with time as the device was "new". Unfortunately all USB3.0 problems are still present, and for me this device is simply useless... can't trust it anymore.

Is there anything else I can try to fix this problem?

[mad_ady]

Run a full update or try the newest image. There have been some uboot changes as well.

[odroid]

Please try our latest minimal Ubuntu image to narrow down root causes since we don't use Armbian internally.
https://wiki.odroid.com/odroid-n2/os_im ... u/20190806

[elatllat]

@odroid that issue is not yet fixed on the minimal image

viewtopic.php?f=181&t=35031&start=250#p266012

@Moan try --bwlimit=5000 as a workaround or the 5.3 kernel as a solution

viewtopic.php?f=176&t=33993&start=300#p266798

[Moan]

Run a full update or try the newest image. There have been some uboot changes as well.

I ran the full update of the "nighty" armbian, and updated uboot to "travis/odroidn2-57", before error occurred.

Please try our latest minimal Ubuntu image to narrow down root causes since we don't use Armbian internally.
https://wiki.odroid.com/odroid-n2/os_im ... u/20190806

Thanks, but the current kernel version is:

Linux 4.9.182-odroidn2 aarch64

Does it mean that Ubuntu has some other system tweaks to workaround this issue? Besides that, workarounds don't solve the root cause? Do they?
I will try to make tests later on the mentioned image, but currently I need NAS access daily, so can't really run long tests on different OS.

Could you also please reply to @igorpec question regarding default IRQs in this topic: viewtopic.php?p=267019#p267019 ?

@Moan try 5.3

viewtopic.php?f=176&t=33993&start=300#p266798

Oh, thank you, but I think it's not for me. I'm quite bad at Linux and would probably fail. Unless it's enough to flash "boot.7z" with balenaEtcher on an existing image (of course making a full backup before)? Would that work without losing the current OS?

[elatllat]

...5.3...Would that work without losing the current OS?

yes, the kernel and operating system are mostly independent of each other.
Arabians mount points may differ from the example.

[Moan]

Unfortunately, installing kernel 5.3 failed on armbian.

The boot.ini in armbian was updated ( viewtopic.php?p=267019#p267019 ) to add "usb-xhci.tablesize=2". I added it wrongly myself, because it should be in "setenv bootargs", not at the end of file.

Anyway, with "usb-xhci.tablesize=2" the rsync speed is 50% slower... 110MB/s vs 50MB/s. This is totally unacceptable for me and this is not a solution for this problem.

I'm a bit frustrated with those issues. Waiting since early May, shamefully I even stopped NAS backups waiting for a "fix" for USB crashes. 5 months later it's still not working. What to do now? Wait longer? Will it EVER be FIXED (not work-arounded by reducing speed by 50%)?

[elatllat]

...What to do now?...

Use the official img and switch to my 5.3 build.

You really can't complain to HK that a 3rd party OS is not performing.
Either PM @igorpec or ask on the armbian forums for them to address the issue.

Unfortunately a bunch of early testers (myself included) missed these bugs so HK is only dealing with it now, and the 4.9 branch they are working with is substantially different from upstream 4.9 so it may take them a while to find which commit is causing the crashing. IMO switching to 5.3 would be less work for them but that may be hard if AML promised them GPU/VPU improvements only for 4.9.

[odroid]

There will be a Kernel update to fix the "rsync" stability issue in the next week hopefully.
We've been testing a patch from Amlogic for a few days and looks very promising.
But we need to test it a few more days to make sure.

[Moan]

Use the official img and switch to my 5.3 build.

You really can't complain to HK that a 3rd party OS is not performing.
Either PM @igorpec or ask on the armbian forums for them to address the issue.

We have discussed it with @igorpec in: viewtopic.php?p=267019#p267019
(that's how "usb-xhci.tablesize=2" was added).

The problem with the official img is, we can't easily install OMV on it. Of course it's possible to install Samba and other things to configure files sharing, but I think everyone admits that it's a very time consuming process (especially permission tests, fixing shares owners, etc.).
To backup files without the "crash" I can use my laptop (N2 -> HDD in laptop -> N2), that would be faster than tablesize=2 "fix", but still it's annoying to focus so much on things that worked fine for the whole life using other devices (including my old XU4).

There will be a Kernel update to fix the "rsync" stability issue in the next week hopefully.
We've been testing a patch from Amlogic for a few days and looks very promising.
But we need to test it a few more days to make sure.

Great to hear that. Does that mean "usb-xhci.tablesize=2" will be removed from boot.ini (won't longer be needed), or still performance will be reduced by at least 50%?

[odroid]

Performance will be better since the XHCI table size option has disappeared.

[Moan]

I'd like to share an interesting information:
I removed "usb-xhci.tablesize=2" and I only used an USB HUB (Unitek Y-3197) to connect all 3 external drives (so only 1 USB port on N2 was used).
A 2TB backup finished successfully in around 9 hours, with the full speed (80-110MB/s).
So it really might be something wrong with the onboard HUB.

[alvarow]

I use only a single USB3 drive (10TB WD Easy with external power), and it still crashes while I perform either a simply cp over NFS, rsync over rsyncd, over NFS or over SSH.

I managed to get it crash while copying stuff from another computer to a samba share on the N2, but that was only to test and confirm it crashes, my main use case would be rsyncd running on another Linux and saving the backups on the N2.

[elatllat]

...still crashes...

That's expected unless you are using the 5.3 or patched 4.9 kernel.

[tobetter]

I use only a single USB3 drive (10TB WD Easy with external power), and it still crashes while I perform either a simply cp over NFS, rsync over rsyncd, over NFS or over SSH.

I managed to get it crash while copying stuff from another computer to a samba share on the N2, but that was only to test and confirm it crashes, my main use case would be rsyncd running on another Linux and saving the backups on the N2.

viewtopic.php?f=181&t=35031#p267660

Please refer the link in case you are running 4.9 stock kernel.

[elatllat]

...
viewtopic.php?f=181&t=35031#p267660

Please refer the link in case you are running 4.9 stock kernel.

I think you meant to link to here;
viewtopic.php?f=177&t=36251&p=267563#p267559

[alvarow]

I also have good news, using the kernel from odroidn2-4.9.190-usb-patch.tar.gz solves the reboots I've been having, I haven't done a full backup of my NAS into the Odroid yet, but it was able to grab 16gb worth of data without crashing, and that is a first.

Thumbs up for the patch so far, I'll report back if the full backup fails, if not assume all good!

[elatllat]

I have been stressing the patched 5.3 kernel for a few days. Looks like the USB issues will be over whenever HK decides testing the patch is done.

[tobetter]

Since I have positive feedback about the USB fixes from more users, the patches will be merged into the branch and the kernel update would happen next week as @odroid said. Thank you for all your tests.