Problem with USB 2.0 disk: reset high-speed USB device number 3 using xhci-hcd

Post Reply
etcetera
Posts: 7
Joined: Fri Feb 15, 2019 11:31 pm
languages_spoken: english, german
ODROIDs: 3 x N2
Location: Switzerland
Has thanked: 4 times
Been thanked: 1 time
Contact:

Problem with USB 2.0 disk: reset high-speed USB device number 3 using xhci-hcd

Unread post by etcetera » Wed May 01, 2019 5:57 pm

Dear Reader


I have attached an external USB 2.0 disk to one of my Odroid-N2 and encounter a problem. The following is logged repeatedly (with different times of course) in /var/log/syslog:

Code: Select all

May  1 10:30:02 odroid3 kernel: [  163.965764@0] usb 1-1.3: reset high-speed USB device number 3 using xhci-hcd
The command lsusb -t shows the following:

Code: Select all

root@odroid3:~# lsusb -t
/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 5000M
    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 5000M
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/2p, 480M
    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 480M
        |__ Port 3: Dev 3, If 0, Class=Mass Storage, Driver=usb-storage, 480M
I am running Ubuntu Mate with the latest updates and upgrades on a 32 GB eMMC (based on ubuntu-18.04.2-4.9-mate-odroid-n2-20190325.img):

Code: Select all

root@odroid3:~# uname -a
Linux odroid3 4.9.170-27 #1 SMP PREEMPT Mon Apr 29 12:45:24 -03 2019 aarch64 aarch64 aarch64 GNU/Linux
There are no other things (no screen, no keyboard, no mouse) connected to the Odroid-N2 except ethernet. I am accessing the Odroid-N2 via ssh.

The external USB 2.0 disk is running without problems on another Intel based Ubuntu 18.04.2 machine with the same cables.

I tried two different USB 2.0 cables with the same result.

External USB 3.0 disks seem to run flawlessly.

Any help or pointers are greatly appreciated since I am not yet familiar with either the Odroid world or Ubuntu Mate. Thank you.


Regards
etcetera

User avatar
odroid
Site Admin
Posts: 30638
Joined: Fri Feb 22, 2013 11:14 pm
languages_spoken: English
ODROIDs: ODROID
Has thanked: 13 times
Been thanked: 91 times
Contact:

Re: Problem with USB 2.0 disk: reset high-speed USB device number 3 using xhci-hcd

Unread post by odroid » Thu May 02, 2019 10:22 am

When we tested a USB 2.0 flash storage, we had no such issue.

Do you use USB 2.0 and USB 3.0 disks together?

Do you have an OTG-to-Host cable something like this to narrow down root causes?
https://www.hardkernel.com/shop/usb2-0-otg-cable/
If yes, please try it on the OGT port.

etcetera
Posts: 7
Joined: Fri Feb 15, 2019 11:31 pm
languages_spoken: english, german
ODROIDs: 3 x N2
Location: Switzerland
Has thanked: 4 times
Been thanked: 1 time
Contact:

Re: Problem with USB 2.0 disk: reset high-speed USB device number 3 using xhci-hcd

Unread post by etcetera » Fri May 03, 2019 2:25 am

Thank you Mr. odroid for the fast response.

Briefly said, the problem occurs only when the USB 2.0 disk is connected to one of the USB 3.0 ports. I tried the Micro USB 2.0 OTG port with an additional cable (like Mr. odroid has suggested) and no problem is logged.

The USB 2.0 disk is the only USB device connected to the Odroid-N2 for these tests. There are no other devices (no screen, no keyboard, no mouse) connected to the Odroid-N2 except ethernet. I am accessing the Odroid-N2 via ssh.

Following are some excerpts to document the tests.


USB 2.0 disk connected to USB 3.0 port

The following error is logged repeatedly (with differend times) in /var/log/syslog:

Code: Select all

May  2 17:01:55 odroid3 kernel: [  545.138732@0] usb 1-1.3: reset high-speed USB device number 3 using xhci-hcd
The command lsusb -t shows the following:

Code: Select all

root@odroid3:~# lsusb -t
/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 5000M
    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 5000M
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/2p, 480M
    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 480M
        |__ Port 3: Dev 3, If 0, Class=Mass Storage, Driver=usb-storage, 480M
Doing some simple benchmark:

Code: Select all

root@odroid3:~# hdparm -tT /dev/sda

/dev/sda:
 Timing cached reads:   708 MB in  2.00 seconds = 353.58 MB/sec
 Timing buffered disk reads:  74 MB in  3.08 seconds =  24.01 MB/sec

USB 2.0 disk connected to Micro USB 2.0 OTG port

Using an additional USB 2.0 OTG cable like Mr. odroid mentioned above. No errors.

The command lsusb -t shows the following:

Code: Select all

root@odroid3:~# lsusb -t
/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 5000M
    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 5000M
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/2p, 480M
    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 480M
    |__ Port 2: Dev 3, If 0, Class=Mass Storage, Driver=usb-storage, 480M
Doing some simple benchmark:

Code: Select all

root@odroid3:~# hdparm -tT /dev/sda

/dev/sda:
 Timing cached reads:   720 MB in  2.01 seconds = 359.05 MB/sec
 Timing buffered disk reads:  74 MB in  3.05 seconds =  24.29 MB/sec

I am happy to investigate further if it helps. Thank you.


Regards,
etcetera

back2future
Posts: 209
Joined: Sun Jul 23, 2017 3:19 pm
languages_spoken: english
Has thanked: 8 times
Been thanked: 0
Contact:

Re: Problem with USB 2.0 disk: reset high-speed USB device number 3 using xhci-hcd

Unread post by back2future » Fri May 03, 2019 5:35 am

Might help towards solution:

Code: Select all

 lsusb -v | grep -e id  -e bHubContrCurrent -e col -e ow 

User avatar
odroid
Site Admin
Posts: 30638
Joined: Fri Feb 22, 2013 11:14 pm
languages_spoken: English
ODROIDs: ODROID
Has thanked: 13 times
Been thanked: 91 times
Contact:

Re: Problem with USB 2.0 disk: reset high-speed USB device number 3 using xhci-hcd

Unread post by odroid » Fri May 03, 2019 9:28 am

Thank you for the test result.
We will buy a USB 2.0 HDD enclosure to reproduce the issue here.
These users thanked the author odroid for the post:
etcetera (Tue May 07, 2019 4:43 am)

joshua.yang
Posts: 197
Joined: Fri Sep 22, 2017 5:54 pm
languages_spoken: Korean, English
ODROIDs: XU4, XU4Q + Cloudshell2, H2
Has thanked: 0
Been thanked: 9 times
Contact:

Re: Problem with USB 2.0 disk: reset high-speed USB device number 3 using xhci-hcd

Unread post by joshua.yang » Tue May 07, 2019 10:13 am

etcetera wrote:
Wed May 01, 2019 5:57 pm
External USB 3.0 disks seem to run flawlessly.
Hi.

I've tested about for 1~2days but it looks fine.

Could you share the results of lsusb -t or dmesg when you connects external USB 3.0 drive?

etcetera
Posts: 7
Joined: Fri Feb 15, 2019 11:31 pm
languages_spoken: english, german
ODROIDs: 3 x N2
Location: Switzerland
Has thanked: 4 times
Been thanked: 1 time
Contact:

Re: Problem with USB 2.0 disk: reset high-speed USB device number 3 using xhci-hcd

Unread post by etcetera » Wed May 08, 2019 9:18 pm

Dear joshua.yang

Thank you for your request. Please see below for the results.


Connecting USB 3.0 disk to USB 3.0 port

The following is from /var/log/syslog:

Code: Select all

May  8 13:52:27 odroid3 kernel: [  138.864045@0] usb 2-1.3: new SuperSpeed USB device number 3 using xhci-hcd
May  8 13:52:27 odroid3 kernel: [  138.887997@0] usb 2-1.3: New USB device found, idVendor=0bc2, idProduct=3312
May  8 13:52:27 odroid3 kernel: [  138.888076@0] usb 2-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
May  8 13:52:27 odroid3 kernel: [  138.888126@0] usb 2-1.3: Product: Expansion Desk
May  8 13:52:27 odroid3 kernel: [  138.888173@0] usb 2-1.3: Manufacturer: Seagate 
May  8 13:52:27 odroid3 kernel: [  138.888220@0] usb 2-1.3: SerialNumber: XXXXXXXX
May  8 13:52:27 odroid3 kernel: [  138.980175@0] scsi host0: uas
May  8 13:52:27 odroid3 kernel: [  138.993866@2] scsi 0:0:0:0: Direct-Access     Seagate  Expansion Desk   0739 PQ: 0 ANSI: 6
May  8 13:52:27 odroid3 mtp-probe: checking bus 2, device 3: "/sys/devices/platform/ff500000.dwc3/xhci-hcd.0.auto/usb2/2-1/2-1.3"
May  8 13:52:27 odroid3 mtp-probe: bus: 2, device: 3 was not an MTP device
May  8 13:52:27 odroid3 kernel: [  139.052268@0] sd 0:0:0:0: Attached scsi generic sg0 type 0
May  8 13:52:27 odroid3 kernel: [  139.103497@0] sd 0:0:0:0: [sda] Spinning up disk...
May  8 13:52:44 odroid3 kernel: [  144.520031@0] ...........ready
May  8 13:52:44 odroid3 kernel: [  155.388074@0] sd 0:0:0:0: [sda] 1220942645 4096-byte logical blocks: (5.00 TB/4.55 TiB)
May  8 13:52:44 odroid3 kernel: [  155.403593@0] sd 0:0:0:0: [sda] Write Protect is off
May  8 13:52:44 odroid3 kernel: [  155.403697@0] sd 0:0:0:0: [sda] Mode Sense: 2b 00 10 08
May  8 13:52:44 odroid3 kernel: [  155.411515@0] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, supports DPO and FUA
May  8 13:52:44 odroid3 kernel: [  155.411905@0] xhci-hcd xhci-hcd.0.auto: ERROR Transfer event for disabled endpoint or incorrect stream ring
May  8 13:52:44 odroid3 kernel: [  155.416069@0] xhci-hcd xhci-hcd.0.auto: @00000000cf612e00 00000000 00000000 1b000000 03078001
May  8 13:52:44 odroid3 kernel: [  155.988072@0]  sda: sda1
May  8 13:52:44 odroid3 kernel: [  156.029600@0] sd 0:0:0:0: [sda] Attached SCSI disk
May  8 13:52:45 odroid3 systemd[1]: Created slice system-usbmount.slice.
May  8 13:52:45 odroid3 systemd[1]: Starting usbmount@dev-sda.service...
May  8 13:52:45 odroid3 usbmount[3058]: usbmount is disabled, see /etc/usbmount/usbmount.conf
May  8 13:52:45 odroid3 systemd[1]: Started usbmount@dev-sda.service.
May  8 13:52:45 odroid3 systemd[1]: Found device Expansion_Desk st5t-1.
May  8 13:52:45 odroid3 systemd[1]: Starting usbmount@dev-sda1.service...
May  8 13:52:45 odroid3 systemd[1]: Mounting /media/st5t-1...
May  8 13:52:45 odroid3 usbmount[3069]: usbmount is disabled, see /etc/usbmount/usbmount.conf
May  8 13:52:45 odroid3 systemd[1]: Started usbmount@dev-sda1.service.
May  8 13:52:45 odroid3 kernel: [  156.718789@2] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
May  8 13:52:45 odroid3 systemd[1]: Mounted /media/st5t-1.
The following is from dmesg

Code: Select all

[  138.864045] usb 2-1.3: new SuperSpeed USB device number 3 using xhci-hcd
[  138.887997] usb 2-1.3: New USB device found, idVendor=0bc2, idProduct=3312
[  138.888076] usb 2-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[  138.888126] usb 2-1.3: Product: Expansion Desk
[  138.888173] usb 2-1.3: Manufacturer: Seagate 
[  138.888220] usb 2-1.3: SerialNumber: XXXXXXXX
[  138.980175] scsi host0: uas
[  138.993866] scsi 0:0:0:0: Direct-Access     Seagate  Expansion Desk   0739 PQ: 0 ANSI: 6
[  139.052268] sd 0:0:0:0: Attached scsi generic sg0 type 0
[  139.103497] sd 0:0:0:0: [sda] Spinning up disk...
[  144.520031] ...........ready
[  155.388074] sd 0:0:0:0: [sda] 1220942645 4096-byte logical blocks: (5.00 TB/4.55 TiB)
[  155.403593] sd 0:0:0:0: [sda] Write Protect is off
[  155.403697] sd 0:0:0:0: [sda] Mode Sense: 2b 00 10 08
[  155.411515] sd 0:0:0:0: [sda] Write cache: enabled, read cache: enabled, supports DPO and FUA
[  155.411905] xhci-hcd xhci-hcd.0.auto: ERROR Transfer event for disabled endpoint or incorrect stream ring
[  155.416069] xhci-hcd xhci-hcd.0.auto: @00000000cf612e00 00000000 00000000 1b000000 03078001
[  155.988072]  sda: sda1
[  156.029600] sd 0:0:0:0: [sda] Attached SCSI disk
[  156.718789] EXT4-fs (sda1): mounted filesystem with ordered data mode. Opts: (null)
The following is from lsusb -t:

Code: Select all

root@odroid3:~# lsusb -t
/:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/1p, 5000M
    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 5000M
        |__ Port 3: Dev 3, If 0, Class=Mass Storage, Driver=uas, 5000M
/:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci-hcd/2p, 480M
    |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/4p, 480M

Regards
etcetera

rosenrot
Posts: 13
Joined: Wed Apr 10, 2019 2:37 am
languages_spoken: english
ODROIDs: n2
Has thanked: 0
Been thanked: 0
Contact:

Re: Problem with USB 2.0 disk: reset high-speed USB device number 3 using xhci-hcd

Unread post by rosenrot » Thu May 09, 2019 3:58 am

Please check here: same error messages. We are currently running stability tests...

viewtopic.php?f=181&t=34849

joshua.yang
Posts: 197
Joined: Fri Sep 22, 2017 5:54 pm
languages_spoken: Korean, English
ODROIDs: XU4, XU4Q + Cloudshell2, H2
Has thanked: 0
Been thanked: 9 times
Contact:

Re: Problem with USB 2.0 disk: reset high-speed USB device number 3 using xhci-hcd

Unread post by joshua.yang » Fri May 10, 2019 10:09 am

@etcetera, @rosenrot

viewtopic.php?f=181&t=34849#p255308
I've started a test. Feel free to give feedback if you have a better idea about the test. :)

mastini
Posts: 1
Joined: Sat May 11, 2019 11:17 am
languages_spoken: english
ODROIDs: N2
Has thanked: 0
Been thanked: 0
Contact:

Re: Problem with USB 2.0 disk: reset high-speed USB device number 3 using xhci-hcd

Unread post by mastini » Sat May 11, 2019 11:31 am

I can also confirm that I have USB resets/disconnects issues with H2, i'll be also testing on XU4 next week.
I'm running 10 USB LTE modems with powered 60W usb-hub, and modems would randomly reset every 30-60m. once USB device goes dead, LA would go +1 for each device. So after the day i would have LA 10.

Same setup works on regular laptop and orange pi 3 with armbian.

Logs:
dmesg https://termbin.com/3i8g
lsusb https://termbin.com/di21

Soleil
Posts: 32
Joined: Tue Apr 30, 2019 9:20 am
languages_spoken: english
Has thanked: 0
Been thanked: 2 times
Contact:

Re: Problem with USB 2.0 disk: reset high-speed USB device number 3 using xhci-hcd

Unread post by Soleil » Sun May 12, 2019 9:30 am

Another test case - WiFi excluded even without Farraday cage :)
N2 moved 1.2m away from 2.4Ghz access point - same issue.

Easier reproduction steps, almost instant failure.
USB connectivity:
- AmazonBasics 1GE adapter
- 3 USB3 disks - different vendors (details below).

Steps to crash:
1. luksFormat (might be in previous boot - details provided earlier - iteration steps skipped)
2. luksOpen the two disks (each is 1TB). The "production" one is plugged but unused (Luks not even opened).
3. mkfs.ext4 /dev/mapper/<luks_device_1TB> -L <anything>
4. mkfs.ext4 /dev/mapper/<luks_second_device_1TB> -L <anything2>

During second mkfs.ext4 system gets unstable and gets into OOM.

Big question is why we're getting into OOM with freshly booted system and just mkfs?
This is not usual. This smells very badly as memory leak.

Prior submit, did further tests - just 2xUSB drives connected. Each 1TB only.
All what was done was:

Code: Select all

1. luksOpen (created in earlier step)
2. mkfs.ext4 -L test /dev/mapper/<first_device>
# observations: mem usage went sky high as for simple mkfs - up to 3GB.
# after mkfs was finished used memory dropped down, rest remained in buffers/cache.
3. mkfs.ext4 -L test /dev/mapper/<second_device>
# during mkfs.ext4 system runs into OOM. And goes on killing spree. Killing everything, including simple top, systemd processes, etc.
This seems to have nothing to do with power supply, power usage, or length of copy/usage.

This screams like memory leak. Questions is where and why/how.
Since reproduction is relatively simple - let me know what else would you need to collect enough evidence.
p.s. I don't have USB-UART but can provide anything else what might be needed.

Board is completely unstable as for me for today.

joshua.yang
Posts: 197
Joined: Fri Sep 22, 2017 5:54 pm
languages_spoken: Korean, English
ODROIDs: XU4, XU4Q + Cloudshell2, H2
Has thanked: 0
Been thanked: 9 times
Contact:

Re: Problem with USB 2.0 disk: reset high-speed USB device number 3 using xhci-hcd

Unread post by joshua.yang » Tue May 14, 2019 3:08 pm

Soleil wrote:
Sun May 12, 2019 9:30 am
Another test case - WiFi excluded even without Farraday cage :)
N2 moved 1.2m away from 2.4Ghz access point - same issue.

Easier reproduction steps, almost instant failure.
USB connectivity:
- AmazonBasics 1GE adapter
- 3 USB3 disks - different vendors (details below).

Steps to crash:
1. luksFormat (might be in previous boot - details provided earlier - iteration steps skipped)
2. luksOpen the two disks (each is 1TB). The "production" one is plugged but unused (Luks not even opened).
3. mkfs.ext4 /dev/mapper/<luks_device_1TB> -L <anything>
4. mkfs.ext4 /dev/mapper/<luks_second_device_1TB> -L <anything2>

During second mkfs.ext4 system gets unstable and gets into OOM.

Big question is why we're getting into OOM with freshly booted system and just mkfs?
This is not usual. This smells very badly as memory leak.

Prior submit, did further tests - just 2xUSB drives connected. Each 1TB only.
All what was done was:

Code: Select all

1. luksOpen (created in earlier step)
2. mkfs.ext4 -L test /dev/mapper/<first_device>
# observations: mem usage went sky high as for simple mkfs - up to 3GB.
# after mkfs was finished used memory dropped down, rest remained in buffers/cache.
3. mkfs.ext4 -L test /dev/mapper/<second_device>
# during mkfs.ext4 system runs into OOM. And goes on killing spree. Killing everything, including simple top, systemd processes, etc.
This seems to have nothing to do with power supply, power usage, or length of copy/usage.

This screams like memory leak. Questions is where and why/how.
Since reproduction is relatively simple - let me know what else would you need to collect enough evidence.
p.s. I don't have USB-UART but can provide anything else what might be needed.

Board is completely unstable as for me for today.
Thanks for your detailed steps to reproduce crash.

I have done your crash steps with 256 SSD and 5TB HDD, it just works without any issues. I typed your command (viewtopic.php?f=181&t=34849&p=255922#p255444) to encrypt SSD and HDD.
Memory consumption reaches above 3GB during formatting 5TB encrypted HDD to EXT4, it was a very short time, but it wasn't into OOM.

Started the test again: viewtopic.php?f=181&t=34849&p=255922#p255922

BTW, to make sure, what is your running kernel on N2? Is it the latest one?

joshua.yang
Posts: 197
Joined: Fri Sep 22, 2017 5:54 pm
languages_spoken: Korean, English
ODROIDs: XU4, XU4Q + Cloudshell2, H2
Has thanked: 0
Been thanked: 9 times
Contact:

Re: Problem with USB 2.0 disk: reset high-speed USB device number 3 using xhci-hcd

Unread post by joshua.yang » Wed May 15, 2019 10:36 am

@Soleil,

I've just noticed some repeated message on dmesg, and that message contains memory allocation related things to do with uas. But it still keeps on testing.
So this seems like ain't that fatal for me, and mine isn't OOM. But this will be reported and we would look into this.

Soleil
Posts: 32
Joined: Tue Apr 30, 2019 9:20 am
languages_spoken: english
Has thanked: 0
Been thanked: 2 times
Contact:

Re: Problem with USB 2.0 disk: reset high-speed USB device number 3 using xhci-hcd

Unread post by Soleil » Thu May 16, 2019 7:19 am

@joshua.yang

Thanks for everything.
My system is on Linux N2 4.9.170-27 #1 SMP PREEMPT Mon Apr 29 12:45:24 -03 2019 aarch64 aarch64 aarch64 GNU/Linux

btw. system is stable for last couple 3 days and the only difference is that no USB hdd is connected to the system.

One thought on the OOM - might be completely unrelated to USB issues the more I think about even if on itself it is big issue.
Below is current memory info - if required can try to reproduce OOM issue.

Code: Select all

# cat /proc/meminfo 
MemTotal:        3801344 kB
MemFree:         1860420 kB
MemAvailable:    3295384 kB
Buffers:          160092 kB
Cached:          1284772 kB
SwapCached:            0 kB
Active:           853036 kB
Inactive:         822120 kB
Active(anon):     272360 kB
Inactive(anon):    12808 kB
Active(file):     580676 kB
Inactive(file):   809312 kB
Unevictable:           0 kB
Mlocked:               0 kB
SwapTotal:             0 kB
SwapFree:              0 kB
Dirty:              4776 kB
Writeback:             0 kB
AnonPages:        230368 kB
Mapped:           214792 kB
Shmem:             54816 kB
Slab:             148520 kB
SReclaimable:      79812 kB
SUnreclaim:        68708 kB
KernelStack:        5216 kB
PageTables:         4592 kB
NFS_Unstable:          0 kB
Bounce:                0 kB
WritebackTmp:          0 kB
CommitLimit:     1900672 kB
Committed_AS:    1256516 kB
VmallocTotal:   263061440 kB
VmallocUsed:           0 kB
VmallocChunk:          0 kB
CmaTotal:         507904 kB
CmaFree:              32 kB

Post Reply

Return to “Ubuntu”

Who is online

Users browsing this forum: No registered users and 0 guests