Bug 81621 - [ehci] [hang] external hd hangs under load on ehci
Summary: [ehci] [hang] external hd hangs under load on ehci
Status: Open
Alias: None
Product: Base System
Classification: Unclassified
Component: usb (show other bugs)
Version: unspecified
Hardware: Any Any
: Normal Affects Only Me
Assignee: freebsd-usb mailing list
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2005-05-29 14:30 UTC by Gerrit Kühn
Modified: 2017-12-31 22:36 UTC (History)
0 users

See Also:


Attachments
smime.p7s (3.15 KB, application/x-pkcs7-signature)
2005-06-16 00:12 UTC, Deomid Ryabkov
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Gerrit Kühn 2005-05-29 14:30:02 UTC
I'm using a Vosoniq XS-DrivePro VP-300, which is basically an external
2.5"HD combined with a cardreader.

The device works perfectly with 500-600kB/s when connected to the internal
USB1 port of the mainboard (VIA chipset), and basically works with ~2MB/s
on a USB2 port of a DLink DU-520 card (NEC chipset). However, after
transferring some data via USB2/EHCI (usually some 10MB), the connection
locks up and waits for some kind of timeout (several minutes). After that,
transfer is resumed until the next lockup occurs.


uhci0@pci0:7:2: class=0x0c0300 card=0x12340925 chip=0x30381106 rev=0x16 hdr=0x00
    vendor   = 'VIA Technologies Inc'
    device   = 'VT82xxxxx UHCI USB 1.1 Controller (All VIA Chipsets)'
    class    = serial bus
    subclass = USB
uhci1@pci0:7:3: class=0x0c0300 card=0x12340925 chip=0x30381106 rev=0x16 hdr=0x00
    vendor   = 'VIA Technologies Inc'
    device   = 'VT82xxxxx UHCI USB 1.1 Controller (All VIA Chipsets)'
    class    = serial bus
    subclass = USB
ohci0@pci0:14:0:        class=0x0c0310 card=0x00351186 chip=0x00351033 rev=0x43 hdr=0x00
    vendor   = 'NEC Electronics Hong Kong'
    device   = 'uPD9210FGC-7EA / µPD720101 USB 1.0 Host Controller (OHCI compliant)'
    class    = serial bus
    subclass = USB
ohci1@pci0:14:1:        class=0x0c0310 card=0x00351186 chip=0x00351033 rev=0x43 hdr=0x00
    vendor   = 'NEC Electronics Hong Kong'
    device   = 'uPD9210FGC-7EA / µPD720101 USB 1.0 Host Controller (OHCI compliant)'
    class    = serial bus
    subclass = USB
ehci0@pci0:14:2:        class=0x0c0320 card=0xf1011186 chip=0x00e01033 rev=0x04 hdr=0x00
    vendor   = 'NEC Electronics Hong Kong'
    device   = 'uPD720100A/101 USB 2.0 Enhanced Host Controller'
    class    = serial bus
    subclass = USB


Please let me know if I can provide further information to solve this
problem.

How-To-Repeat: Just use the XS-Drive with USB2 and transfer an sufficient amount of data.
Comment 1 Gerrit Kühn 2005-05-29 17:07:56 UTC
I did some further testing and found out that the disk hangs on my usb1
ports, too. It just takes longer time to provoke this. When it hangs, I can
occasionally see the following in my syslog:

May 29 17:01:13 stardust kernel: umass0: BBB reset failed, TIMEOUT
May 29 17:09:53 stardust kernel: umass0: BBB reset failed, TIMEOUT
May 29 17:09:53 stardust last message repeated 3 times
May 29 17:21:12 stardust last message repeated 5 times
May 29 17:30:21 stardust last message repeated 4 times
May 29 17:35:10 stardust last message repeated 2 times


When I finally decided to unplug the device (unmounting was not possible),
the whole system rebooted (which is possible a consequence of the still
mounted fs, but annoying anyway):

May 29 17:35:58 stardust kernel: (da1:umass-sim0:0:0:0): lost device
May 29 17:35:58 stardust kernel: (da2:umass-sim0:0:0:1): lost device
May 29 17:35:58 stardust kernel: (da2:umass-sim0:0:0:1): removing device
entry
May 29 17:35:58 stardust kernel: (da3:umass-sim0:0:0:2): lost device
May 29 17:35:58 stardust kernel: (da3:umass-sim0:0:0:2): removing device
entry
May 29 17:35:58 stardust kernel: (da4:umass-sim0:0:0:3): lost device
May 29 17:35:58 stardust kernel: (da4:umass-sim0:0:0:3): removing device
entry
May 29 17:35:58 stardust kernel: umass0: detached
May 29 17:35:58 stardust kernel: fsync: giving up on dirty: 0xc3fc8528: tag
msdo
sfs, type VREG, usecount 1, writecount 0, refcount 1, flags (VV_OBJBUF),
lock ty
pe msdosfs: EXCL (count 1) by thread 0xc3c7f600 (pid 1307)
May 29 17:35:58 stardust kernel: startcluster 9760198, dircluster 746251,
diroff
set 1344, on dev (4, 45)
May 29 17:35:58 stardust kernel: fsync: giving up on dirty: 0xc3fc9738: tag
msdo
sfs, type VREG, usecount 1, writecount 0, refcount 1054, flags (VV_OBJBUF),
lock
 type msdosfs: EXCL (count 1) by thread 0xc3c7f600 (pid 1307)



Since I can see this problem on two different machines with altogether four
different chipsets (two usb1, two usb2) I think the problem is the XS-Drive
itself. Maybe there are other/more quirks needed? Here is how it shows up in
syslog:


May 29 18:03:14 stardust kernel: umass0: PNY USB, rev 2.00/1.00, addr 2
May 29 18:03:15 stardust kernel: da1 at umass-sim0 bus 0 target 0 lun 0
May 29 18:03:15 stardust kernel: da1: <USB USB 1.30> Removable Direct Access
SCS
I-0 device 
May 29 18:03:15 stardust kernel: da1: 40.000MB/s transfers
May 29 18:03:15 stardust kernel: da1: 38204MB (78242976 512 byte sectors:
255H 6
3S/T 4870C)
May 29 18:03:15 stardust kernel: da2 at umass-sim0 bus 0 target 0 lun 1
May 29 18:03:15 stardust kernel: da2: <USB USB 1.30> Removable Direct Access
SCS
I-0 device 
May 29 18:03:15 stardust kernel: da2: 40.000MB/s transfers
May 29 18:03:15 stardust kernel: da2: Attempt to query device size failed:
NOT R
EADY, Medium not present
May 29 18:03:15 stardust kernel: da3 at umass-sim0 bus 0 target 0 lun 2
May 29 18:03:15 stardust kernel: da3: <USB USB 1.30> Removable Direct Access
SCS
I-0 device 
May 29 18:03:15 stardust kernel: da3: 40.000MB/s transfers
May 29 18:03:15 stardust kernel: da3: Attempt to query device size failed:
NOT R
EADY, Medium not present
May 29 18:03:15 stardust kernel: da4 at umass-sim0 bus 0 target 0 lun 3
May 29 18:03:15 stardust kernel: da4: <USB USB 1.30> Removable Direct Access
SCS
I-0 device 
May 29 18:03:15 stardust kernel: da4: 40.000MB/s transfers
May 29 18:03:15 stardust kernel: da4: Attempt to query device size failed:
NOT R
EADY, Medium not present


usbdevs says

Controller /dev/usb4:
addr 1: high speed, self powered, config 1, EHCI root hub(0x0000),
NEC(0x0000), rev 1.00
 port 1 powered
 port 2 powered
 port 3 powered
 port 4 powered
 port 5 addr 2: high speed, power 350 mA, config 1, USB(0x1270),
PNY(0x0d7d), rev 1.00


Is there any further info I could provide?


cu
  Gerrit
--
Comment 2 Deomid Ryabkov 2005-06-16 00:12:20 UTC
same situation here.

ehci, transfers stalls for about a minute, then resumes, then stalls again...
finishes successfully, no errors.

additional observations:

1) the stall usually lasts about a minute.

2) it happens when accessing the device through filesystem (msdosfs in this case),
    it never happens when accessing the device directly and sequentially, e.g.:
# dd if=/dev/da0 of=/ftp/misc/ZZ bs=64k
^C49369+0 records in
49368+0 records out
3235381248 bytes transferred in 295.937268 secs (10932659 bytes/sec)

(the speed is bound mainly by the device itself in this case.)

# dd if=/mnt/IHP/testfile of=/dev/null bs=64k
load: 0.02  cmd: dd 2692 [getblk] 0.01u 3.26s 0% 712k
11171+0 records in
11171+0 records out
732102656 bytes transferred in 94.251015 secs (7767584 bytes/sec)
load: 0.01  cmd: dd 2692 [getblk] 0.01u 3.38s 0% 712k
load: 0.01  cmd: dd 2692 [getblk] 0.01u 3.38s 0% 712k
load: 0.01  cmd: dd 2692 [getblk] 0.01u 3.38s 0% 712k
11562+0 records in
11562+0 records out
757727232 bytes transferred in 162.903896 secs (4651376 bytes/sec)
load: 0.08  cmd: dd 2692 [getblk] 0.01u 3.94s 0% 712k
13478+0 records in
13478+0 records out
883294208 bytes transferred in 178.969938 secs (4935433 bytes/sec)
load: 0.12  cmd: dd 2692 [getblk] 0.01u 4.55s 0% 712k
load: 0.10  cmd: dd 2692 [getblk] 0.01u 4.55s 0% 712k
load: 0.07  cmd: dd 2692 [getblk] 0.01u 4.55s 0% 712k
load: 0.05  cmd: dd 2692 [getblk] 0.01u 4.55s 0% 712k
15527+0 records in
15527+0 records out
1017577472 bytes transferred in 261.654513 secs (3889012 bytes/sec)
16383+1 records in
16383+1 records out
1073739776 bytes transferred in 268.807717 secs (3994453 bytes/sec)

msdosfs cuts speed significantly (down to 7767584 bytes/sec) but that's bearably,
only if the transfer wouldn't stall completely shortly after.

3) it never happens when writing to the device.

# dd if=/dev/zero of=/mnt/IHP/testfile bs=64k count=16383
16383+0 records in
16383+0 records out
1073676288 bytes transferred in 166.050668 secs (6465956 bytes/sec)
# dd if=/dev/zero of=/mnt/IHP/testfile2 bs=64k count=16383
16383+0 records in
16383+0 records out
1073676288 bytes transferred in 166.053733 secs (6465836 bytes/sec)

the speed is low, but no stalls during transfer.

4) i have tried turning on various debug options. all in all,
i couldn't catch the moment transfer freezes - due to massive amounts of debug output
produced during transfer, the system is crawling and the stall just never happens.
however, with "camcontrol debug -ST all" turned on during the stall, the first few messages
of debug output look like these:

Jun 16 03:01:18 gw kernel: (xpt0:xpt0:0:-1:-1): debugging flags now 6
Jun 16 03:01:18 gw kernel: (xpt0:xpt0:0:-1:-1): xpt_free_path
Jun 16 03:01:18 gw kernel: (xpt0:xpt0:0:-1:-1): xpt_release_path
...
Jun 16 03:02:14 gw kernel: (da0:umass-sim0:0:0:0): xpt_done
Jun 16 03:02:14 gw kernel: (da0:umass-sim0:0:0:0): camisr
Jun 16 03:02:14 gw kernel: (da0:umass-sim0:0:0:0): xpt_action
Jun 16 03:02:15 gw kernel: (da0:umass-sim0:0:0:0): xpt_done
Jun 16 03:02:15 gw kernel: (da0:umass-sim0:0:0:0): camisr
Jun 16 03:02:15 gw kernel: (da0:umass-sim0:0:0:0): xpt_schedule
Jun 16 03:02:15 gw kernel: (da0:umass-sim0:0:0:0):    added periph to queue
Jun 16 03:02:15 gw kernel: (da0:umass-sim0:0:0:0):    calling xpt_run_devq
Jun 16 03:02:15 gw kernel: (da0:umass-sim0:0:0:0): xpt_setup_ccb
...

and with hw.usb.debug=0x00020000:

Jun 16 01:58:36 gw kernel: usb_add_task: task=0xc195346c
Jun 16 01:58:36 gw kernel: usb_task_thread: woke up task=0xc195346c
Jun 16 01:58:36 gw kernel: usb_schedsoftintr: polling=0
Jun 16 01:58:36 gw kernel: usb_transfer_complete: pipe=0xc1960280 xfer=0xc1953400 status=15 actlen=0
Jun 16 01:58:36 gw kernel: usb_freemem: large free
Jun 16 01:58:36 gw kernel: usb_block_freemem: size=8192
Jun 16 01:58:36 gw kernel: usb_transfer_complete: repeat=0 new head=0
Jun 16 01:58:36 gw kernel: usbd_transfer: xfer=0xc1926e00, flags=0, pipe=0xc1960780, running=0
...


given these observations, i suppose that this might not be usb problem after all,
rather msdosfs or buffer management code could cause this behavior.

what else can i do to track this problem further?

-- 
Deomid Ryabkov aka Rojer
myself@rojer.pp.ru
rojer@sysadmins.ru
ICQ: 8025844
Comment 3 John Pettitt 2005-06-16 00:36:27 UTC
You might want to try building a kernel with options PREEMPTION enabled
- it seems to mask the problem I was having with two USB drives in a
gstripe setup.
Comment 4 Deomid Ryabkov 2005-06-17 23:09:41 UTC
compiling with PREEMPTION did not help at all...

-- 
Deomid Ryabkov aka Rojer
myself@rojer.pp.ru
rojer@sysadmins.ru
ICQ: 8025844
Comment 5 Gerrit Kühn 2005-06-18 13:50:49 UTC
On Sat, Jun 18, 2005 at 02:09:41AM +0400, Rojer wrote:

> compiling with PREEMPTION did not help at all...

Besides, your problem seems to be different from the one I reported. I see
the stalls even when using dd, and they're limited to the mentioned Vosoniq
XS-drive; other devices like my iRiver player work fine (though a bit slow).
However, until now I've only tried writing to the device which gave those
stalls. Your mail gave me the idea that reading might be a different thing -
I'll try that.


cu
  Gerrit
--
Comment 6 Deomid Ryabkov 2005-08-31 19:55:43 UTC
the patch postde here might help with the problem:

http://lists.freebsd.org/mailman/htdig/freebsd-hackers/2005-August/013415.html

-- 
Deomid Ryabkov aka Rojer
myself@rojer.pp.ru
rojer@sysadmins.ru
ICQ: 8025844
Comment 7 dmehler26 2005-09-17 20:16:26 UTC
Hello,
    I've seen this behavior as well. In my case it's a 5-stable box with the
ehci driver. The controller is a VIA VT6202 USB2 controller.
If there's anything i can do to assist in resolving this let me know.
Dave.
Comment 8 mschout 2005-10-10 16:11:52 UTC
I have a VIA chipset as well, and the patch in the link above (posted by
Rojer, that adds the EHCI_SCFLG_LOSTINTRBUG workaround), fixes all of
the problems with my chipset.  Without this patch, my system will hang
and/or panic every single time a USB 2.0 device is used for more than a
few seconds.  I've been using the patch for 2 weeeks now with no
problems at all and ehci/USB 2.0 devices work perfectly now.

My controller is a VIA VT6202.

Regards,
Michael Schout
Comment 9 francoisk777 2005-10-10 20:50:56 UTC
Just wanted to also say that I just installed the patch linked to by
Rojer, and it seems to fix the problem nicely.

Thanks :)
Comment 10 iedowse freebsd_committer 2006-02-25 04:17:31 UTC
State Changed
From-To: open->feedback


Does this still occur with more recent sources?
Comment 11 Scott Mitchell freebsd_committer 2006-11-14 21:32:59 UTC
I'm seeing what appears to be the same problem on 6.1:

FreeBSD llama.fishballoon.org 6.1-SECURITY FreeBSD 6.1-SECURITY #0: Mon Aug 28 05:21:08 UTC 2006     root@builder.daemonology.net:/usr/obj/usr/src/sys/GENERIC  i386

The USB device is a Vosonic VP6230 (another HDD + card reader thing):

Nov 14 20:46:05 llama kernel: umass0: vendor 0x0d7d VP6230, rev 2.00/1.00, addr 2
Nov 14 20:46:05 llama kernel: da0 at umass-sim0 bus 0 target 0 lun 0
Nov 14 20:46:05 llama kernel: da0: < VP6230 1.09> Removable Direct Access SCSI-0 device
Nov 14 20:46:05 llama kernel: da0: 40.000MB/s transfers
Nov 14 20:46:05 llama kernel: da0: Attempt to query device size failed: NOT READY, Medium not present
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): READ CAPACITY. CDB: 25 0 0 0 0 0 0 0 0 0
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): CAM Status: SCSI Status Error
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): SCSI Status: Check Condition
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): NOT READY asc:3a,0
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): Medium not present
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): Unretryable error
Nov 14 20:46:05 llama kernel: Opened disk da0 -> 6
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): READ CAPACITY. CDB: 25 0 0 0 0 0 0 0 0 0
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): CAM Status: SCSI Status Error
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): SCSI Status: Check Condition
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): NOT READY asc:3a,0
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): Medium not present
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): Unretryable error
Nov 14 20:46:05 llama kernel: Opened disk da0 -> 6
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): READ CAPACITY. CDB: 25 0 0 0 0 0 0 0 0 0
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): CAM Status: SCSI Status Error
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): SCSI Status: Check Condition
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): NOT READY asc:3a,0
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): Medium not present
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): Unretryable error
Nov 14 20:46:05 llama kernel: Opened disk da0 -> 6
Nov 14 20:46:05 llama kernel: da1 at umass-sim0 bus 0 target 0 lun 1
Nov 14 20:46:05 llama kernel: da1: < VP6230 1.09> Removable Direct Access SCSI-0 device
Nov 14 20:46:05 llama kernel: da1: 40.000MB/s transfers
Nov 14 20:46:05 llama kernel: da1: Attempt to query device size failed: NOT READY, Medium not present
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): READ CAPACITY. CDB: 25 0 0 0 0 0 0 0 0 0
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): CAM Status: SCSI Status Error
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): SCSI Status: Check Condition
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): NOT READY asc:3a,0
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): Medium not present
Nov 14 20:46:05 llama kernel: (da0:umass-sim0:0:0:0): Unretryable error
Nov 14 20:46:05 llama kernel: Opened disk da0 -> 6
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): READ CAPACITY. CDB: 25 20 0 0 0 0 0 0 0 0
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): CAM Status: SCSI Status Error
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): SCSI Status: Check Condition
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): NOT READY asc:3a,0
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): Medium not present
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): Unretryable error
Nov 14 20:46:05 llama kernel: Opened disk da1 -> 6
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): READ CAPACITY. CDB: 25 20 0 0 0 0 0 0 0 0
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): CAM Status: SCSI Status Error
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): SCSI Status: Check Condition
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): NOT READY asc:3a,0
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): Medium not present
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): Unretryable error
Nov 14 20:46:05 llama kernel: Opened disk da1 -> 6
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): READ CAPACITY. CDB: 25 20 0 0 0 0 0 0 0 0
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): CAM Status: SCSI Status Error
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): SCSI Status: Check Condition
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): NOT READY asc:3a,0
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): Medium not present
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): Unretryable error
Nov 14 20:46:05 llama kernel: Opened disk da1 -> 6
Nov 14 20:46:05 llama kernel: da2 at umass-sim0 bus 0 target 0 lun 2
Nov 14 20:46:05 llama kernel: da2: < VP6230 1.09> Removable Direct Access SCSI-0 device
Nov 14 20:46:05 llama kernel: da2: 40.000MB/s transfers
Nov 14 20:46:05 llama kernel: da2: Attempt to query device size failed: NOT READY, Medium not present
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): READ CAPACITY. CDB: 25 20 0 0 0 0 0 0 0 0
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): CAM Status: SCSI Status Error
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): SCSI Status: Check Condition
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): NOT READY asc:3a,0
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): Medium not present
Nov 14 20:46:05 llama kernel: (da1:umass-sim0:0:0:1): Unretryable error
Nov 14 20:46:05 llama kernel: Opened disk da1 -> 6
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): READ CAPACITY. CDB: 25 40 0 0 0 0 0 0 0 0
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): CAM Status: SCSI Status Error
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): SCSI Status: Check Condition
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): NOT READY asc:3a,0
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): Medium not present
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): Unretryable error
Nov 14 20:46:05 llama kernel: Opened disk da2 -> 6
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): READ CAPACITY. CDB: 25 40 0 0 0 0 0 0 0 0
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): CAM Status: SCSI Status Error
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): SCSI Status: Check Condition
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): NOT READY asc:3a,0
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): Medium not present
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): Unretryable error
Nov 14 20:46:05 llama kernel: Opened disk da2 -> 6
Nov 14 20:46:05 llama kernel: da3 at umass-sim0 bus 0 target 0 lun 3
Nov 14 20:46:05 llama kernel: da3: < VP6230 1.09> Fixed Direct Access SCSI-0 device
Nov 14 20:46:05 llama kernel: da3: 40.000MB/s transfers
Nov 14 20:46:05 llama kernel: da3: 28615MB (58605120 512 byte sectors: 255H 63S/T 3648C)
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): READ CAPACITY. CDB: 25 40 0 0 0 0 0 0 0 0
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): CAM Status: SCSI Status Error
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): SCSI Status: Check Condition
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): NOT READY asc:3a,0
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): Medium not present
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): Unretryable error
Nov 14 20:46:05 llama kernel: Opened disk da2 -> 6
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): READ CAPACITY. CDB: 25 40 0 0 0 0 0 0 0 0
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): CAM Status: SCSI Status Error
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): SCSI Status: Check Condition
Nov 14 20:46:05 llama kernel: (da2:umass-sim0:0:0:2): NOT READY asc:3a,0
Nov 14 20:46:06 llama kernel: (da2:umass-sim0:0:0:2): Medium not present
Nov 14 20:46:06 llama kernel: (da2:umass-sim0:0:0:2): Unretryable error
Nov 14 20:46:06 llama kernel: Opened disk da2 -> 6

The machine is a VIA EPIA-ME600.  The USB controllers are probed as:

uhci0: <VIA 83C572 USB controller> port 0xd400-0xd41f irq 11 at device 16.0 on pci0
uhci0: [GIANT-LOCKED]
usb0: <VIA 83C572 USB controller> on uhci0
usb0: USB revision 1.0
uhub0: VIA UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub0: 2 ports with 2 removable, self powered
uhci1: <VIA 83C572 USB controller> port 0xd800-0xd81f irq 10 at device 16.1 on pci0
uhci1: [GIANT-LOCKED]
usb1: <VIA 83C572 USB controller> on uhci1
usb1: USB revision 1.0
uhub1: VIA UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub1: 2 ports with 2 removable, self powered
uhci2: <VIA 83C572 USB controller> port 0xdc00-0xdc1f irq 5 at device 16.2 on pci0
uhci2: [GIANT-LOCKED]
usb2: <VIA 83C572 USB controller> on uhci2
usb2: USB revision 1.0
uhub2: VIA UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub2: 2 ports with 2 removable, self powered
ehci0: <VIA VT6202 USB 2.0 controller> mem 0xdf102000-0xdf1020ff irq 12 at device 16.3 on pci0
ehci0: [GIANT-LOCKED]
usb3: EHCI version 1.0
usb3: companion controllers, 2 ports each: usb0 usb1 usb2
usb3: <VIA VT6202 USB 2.0 controller> on ehci0
usb3: USB revision 2.0
uhub3: VIA EHCI root hub, class 9/0, rev 2.00/1.00, addr 1
uhub3: 6 ports with 6 removable, self powered

USB 1.0 stuff (a printer, Ethernet adapter and various other umass devices)
seem to work fine.  I get the symptoms described by Gerrit when reading
from da3 (the HDD part of the Vosonic device) - a few MB of data is
transferred at reasonable speed, then the transfer hangs for a few
minutes.  Rinse and repeat until done.  The data appears to transfer just
fine and I can unmount the device successfully when done.  I've seen what I
think was the same behaviour with another no-name external HDD box attached
to the same machine.  Haven't tried any of the suggested workarounds yet,
and probably can't on this machine as it's also my firewall and router :)
I might have another box around with a VIA EHCI controller that I can test
on, will see what I can do.

Cheers,

	Scott
Comment 12 Scott Mitchell freebsd_committer 2006-11-22 13:20:16 UTC
A few more observations on this problem.  Firstly it seems that Ian's patch
for VIA EHCI controllers is already in 6.1, so that clearly isn't helping
in this case at least.  I also ran a few more tests with 3 different
machines and all the USB 2.0 devices I could scrape together.  The machines
and their EHCI controllers are:

#1
FreeBSD llama.fishballoon.org 6.1-SECURITY FreeBSD 6.1-SECURITY #0: Mon Aug 28 05:21:08 UTC 2006     root@builder.daemonology.net:/usr/obj/usr/src/sys/GENERIC  i386
ehci0: <VIA VT6202 USB 2.0 controller> mem 0xdf102000-0xdf1020ff irq 12 at device 16.3 on pci0
ehci0: [GIANT-LOCKED]
usb3: EHCI version 1.0
usb3: companion controllers, 2 ports each: usb0 usb1 usb2
usb3: <VIA VT6202 USB 2.0 controller> on ehci0
usb3: USB revision 2.0

#2
FreeBSD tuatara.fishballoon.org 6.1-SECURITY FreeBSD 6.1-SECURITY #0: Mon Aug 28 05:21:08 UTC 2006     root@builder.daemonology.net:/usr/obj/usr/src/sys/GENERIC  i386
ehci0: <VIA VT6202 USB 2.0 controller> mem 0xda008000-0xda0080ff irq 10 at device 17.2 on pci0
ehci0: [GIANT-LOCKED]
usb4: EHCI version 0.95
usb4: companion controllers, 2 ports each: usb2 usb3
usb4: <VIA VT6202 USB 2.0 controller> on ehci0
usb4: USB revision 2.0

#3
(Booted from a 6.1-R fixit CD - can't be bothered to type out the uname :-)
ehci0: <NEC uPD 720100 USB 2.0 controller>
usb2: EHCI version 0.95
usb2: companion controllers, 3 ports each: usb0 usb1
usb2: <NEC uPD 720100 USB 2.0 controller>
usb2: USB revision 2.0


I tried these umass devices (all claim to be USB2.0):

Vosonic VP6230 disk/card reader combo:
da5: < VP6230 1.09> Fixed Direct Access SCSI-0 device

Nikon D50 digital camera:
da2: <NIKON D50 1.00> Removable Direct Access SCSI-2 device

Seagate enclosure with 300GB disk:
da0: <ST330063 1A 3.04> Fixed Direct Access SCSI-0 device

Kingston 2GB flash drive:
da1: <Kingston DataTraveler 2.0 1.00> Removable Direct Access SCSI-2 device

Apple iPod:
da0: <Apple iPod 1.53> Removable Direct Access SCSI-0 device


Tested by reading a reasonable amount of data (500MB) from the raw device
and also by writing then reading back a 500MB file from the mounted
FAT filesystem, re-mounting it between the writing and reading steps.  The
300GB drive was apparently too big for mount_msdosfs to handle so I only
did the raw test there.  All the reading/writing was done with dd using a
1MB block size.

On machine #1 (VIA VT6202, EHCI 1.0) everything attached to ehci0 fine, but
would hang for several minutes with a lot of this on the console:

Nov 22 00:52:41 llama kernel: umass0: BBB reset failed, TIMEOUT
Nov 22 00:53:46 llama kernel: umass0: BBB bulk-in clear stall failed, TIMEOUT
Nov 22 00:54:51 llama kernel: umass0: BBB bulk-out clear stall failed, TIMEOUT

I got this with the raw and file transfer, sometimes immediately, sometimes
after transferring up to a couple of hundred MB.

On machine #2 (VIA VT6202, EHCI 0.95) everything attached to ehci0 except
for the VP6230 which insisted on attaching as a USB1.1 device instead (it
does this under Windows on the same machine too).  Apart from that all the
tests were successful, no hangs or other weirdness.

On machine #3 (NEC uPD 720100, EHCI 0.95) everything attached to ehci0 and
all the tests were completely successful.


I'm not sure what any of that proves except that VIA EHCI controllers
clearly have some issues that aren't restricted to FreeBSD MS-DOS
filesystem driver.  I'm open to suggestions for any additional debugging,
although not much is possible on machine #1 as it's my firewall/router :(

Cheers,

	Scott

-- 
===========================================================================
Scott Mitchell           | PGP Key ID | "Eagles may soar, but weasels
Cambridge, England       | 0x54B171B9 |  don't get sucked into jet engines"
scott at fishballoon.org | 0xAA775B8B |      -- Anon
Comment 13 Volker Werth freebsd_committer 2008-05-09 00:01:17 UTC
State Changed
From-To: feedback->open


Feedback has been provided, still an issue at least with 6.1.
Comment 14 Eitan Adler freebsd_committer freebsd_triage 2017-12-31 07:59:40 UTC
For bugs matching the following criteria:

Status: In Progress Changed: (is less than) 2014-06-01

Reset to default assignee and clear in-progress tags.

Mail being skipped