usb/93496: USB2.0 umass stalls on VIA

Fri Feb 17 13:10:08 PST 2006

>Number:         93496
>Category:       usb
>Synopsis:       USB2.0 umass stalls on VIA
>Confidential:   no
>Severity:       serious
>Priority:       medium
>Responsible:    freebsd-usb
>State:          open
>Quarter:        
>Keywords:       
>Date-Required:
>Class:          sw-bug
>Submitter-Id:   current-users
>Arrival-Date:   Fri Feb 17 21:10:05 GMT 2006
>Closed-Date:
>Last-Modified:
>Originator:     Wesha
>Release:        6.0 RELEASE
>Organization:
>Environment:
FreeBSD xxxxx.xxxxxx.org 6.0-RELEASE FreeBSD 6.0-RELEASE #0: Wed Dec 14 02:20:06 CST 2005     xxxxxx at xxxxx.xxxxxx.org:/usr/src/sys/i386/compile/COMCAST_SB_EHCI  i386

>Description:
When transferring files to/from USB2.0 external device, after a random amount of data has been transferred (usually > 300Mb, but theres no dependency, sometimes it works well even after 5GB), transfers to/from device completely cease, and resume only after about 30...60 seconds. The rest of the system keeps working as usual. Here's what I see in the log at that moment (hw.usb.ehci.debug = 1):

-----------------------------------------(this is what it says while transfer is OK)
Feb 16 15:51:37 wesha kernel: ehci_alloc_sqtd_chain: start len=16384
Feb 16 15:52:08 wesha last message repeated 12563 times
Feb 16 15:54:09 wesha last message repeated 50086 times
Feb 16 16:03:37 wesha last message repeated 195168 times
-----------------------------------------(that's where it stalls)
Feb 16 16:04:42 wesha kernel: ehci_timeout: exfer=0xc19d7500
Feb 16 16:04:42 wesha kernel: ehci_timeout_task: xfer=0xc19d7500
Feb 16 16:04:42 wesha kernel: ehci_abort_xfer: xfer=0xc19d7500 pipe=0xc220ec00
Feb 16 16:04:42 wesha kernel: ehci_intr1: door bell
Feb 16 16:04:42 wesha kernel: ehci_idone: aborted xfer=0xc19d7500
Feb 16 16:04:42 wesha kernel: ehci_device_clear_toggle: epipe=0xc220ec00 status=0x0
Feb 16 16:04:42 wesha kernel: usbd_dump_pipe: pipe=0xc220ec00
Feb 16 16:04:42 wesha kernel: usbd_dump_iface: iface=0xc1faf520
Feb 16 16:04:42 wesha kernel: device=0xc1adf800 idesc=0xc1e6a1c9 index=0 altindex=0 priv=0
Feb 16 16:04:42 wesha kernel: usbd_dump_device: dev=0xc1adf800
Feb 16 16:04:42 wesha kernel: bus=0xc1593000 default_pipe=0xc17d3d80
Feb 16 16:04:42 wesha kernel: address=2 config=1 depth=1 speed=3 self_powered=1 power=0 langid=1033
Feb 16 16:04:42 wesha kernel: usbd_dump_endpoint: endp=0xc22284c8
Feb 16 16:04:42 wesha kernel: edesc=0xc1e6a1d9 refcnt=1
Feb 16 16:04:42 wesha kernel: bEndpointAddress=0x88
Feb 16 16:04:42 wesha kernel: (usbd_dump_pipe:)
Feb 16 16:04:42 wesha kernel: refcnt=1 running=1 aborting=0
Feb 16 16:04:42 wesha kernel: intrxfer=0, repeat=0, interval=-1
Feb 16 16:05:47 wesha kernel: ehci_timeout: exfer=0xc19d7400
Feb 16 16:05:47 wesha kernel: ehci_timeout_task: xfer=0xc19d7400
Feb 16 16:05:47 wesha kernel: ehci_abort_xfer: xfer=0xc19d7400 pipe=0xc220ec00
Feb 16 16:05:47 wesha kernel: ehci_intr1: door bell
Feb 16 16:05:47 wesha kernel: ehci_device_clear_toggle: epipe=0xc220ec00 status=0x0
Feb 16 16:05:47 wesha kernel: usbd_dump_pipe: pipe=0xc220ec00
Feb 16 16:05:47 wesha kernel: usbd_dump_iface: iface=0xc1faf520
Feb 16 16:05:47 wesha kernel: device=0xc1adf800 idesc=0xc1e6a1c9 index=0 altindex=0 priv=0
Feb 16 16:05:47 wesha kernel: usbd_dump_device: dev=0xc1adf800
Feb 16 16:05:47 wesha kernel: bus=0xc1593000 default_pipe=0xc17d3d80
Feb 16 16:05:47 wesha kernel: address=2 config=1 depth=1 speed=3 self_powered=1 power=0 langid=1033
Feb 16 16:05:47 wesha kernel: usbd_dump_endpoint: endp=0xc22284c8
Feb 16 16:05:47 wesha kernel: edesc=0xc1e6a1d9 refcnt=1
Feb 16 16:05:47 wesha kernel: bEndpointAddress=0x88
Feb 16 16:05:47 wesha kernel: (usbd_dump_pipe:)
Feb 16 16:05:47 wesha kernel: refcnt=1 running=0 aborting=0
Feb 16 16:05:47 wesha kernel: intrxfer=0, repeat=0, interval=-1
Feb 16 16:05:47 wesha kernel: ehci_device_clear_toggle: epipe=0xc1a61180 status=0x9c00
Feb 16 16:05:47 wesha kernel: usbd_dump_pipe: pipe=0xc1a61180
Feb 16 16:05:47 wesha kernel: usbd_dump_iface: iface=0xc1faf520
Feb 16 16:05:47 wesha kernel: device=0xc1adf800 idesc=0xc1e6a1c9 index=0 altindex=0 priv=0
Feb 16 16:05:47 wesha kernel: usbd_dump_device: dev=0xc1adf800
Feb 16 16:05:47 wesha kernel: bus=0xc1593000 default_pipe=0xc17d3d80
Feb 16 16:05:47 wesha kernel: address=2 config=1 depth=1 speed=3 self_powered=1 power=0 langid=1033
Feb 16 16:05:47 wesha kernel: usbd_dump_endpoint: endp=0xc22284c0
Feb 16 16:05:47 wesha kernel: edesc=0xc1e6a1d2 refcnt=1
Feb 16 16:05:47 wesha kernel: bEndpointAddress=0x02
Feb 16 16:05:47 wesha kernel: (usbd_dump_pipe:)
Feb 16 16:05:47 wesha kernel: refcnt=1 running=0 aborting=0
Feb 16 16:05:47 wesha kernel: intrxfer=0, repeat=0, interval=-1
Feb 16 16:05:47 wesha kernel: ehci_alloc_sqtd_chain: start len=16384
Feb 16 16:06:15 wesha last message repeated 18 times
Feb 16 16:06:30 wesha kernel: ehci_alloc_sqtd_chain: start len=16384
-----------------------------------------(operation resumed)

>How-To-Repeat:
Just hook up a USB2.0 umass device and start copying.

---------------------------------------------------
> usbdevs -v
Controller /dev/usb0:
addr 1: full speed, self powered, config 1, UHCI root hub(0x0000), VIA(0x0000), rev 1.00
 port 1 powered
 port 2 powered
Controller /dev/usb1:
addr 1: full speed, self powered, config 1, UHCI root hub(0x0000), VIA(0x0000), rev 1.00
 port 1 addr 2: low speed, power 2 mA, config 1, Back-UPS ES 725 FW:802.n2.D USB FW:n2(0x0002), APC(0x051d), rev 1.06
 port 2 powered
Controller /dev/usb2:
addr 1: high speed, self powered, config 1, EHCI root hub(0x0000), VIA(0x0000), rev 1.00
 port 1 addr 2: high speed, self powered, config 1, USB2.0 Storage Device(0x6830), Cypress Semiconductor(0x04b4), rev 0.01
 port 2 powered
 port 3 powered
 port 4 powered
-------------------------------------------------------


-------------------------------------------------------
> cat /var/run/dmesg.boot

Copyright (c) 1992-2005 The FreeBSD Project.
Copyright (c) 1979, 1980, 1983, 1986, 1988, 1989, 1991, 1992, 1993, 1994
	The Regents of the University of California. All rights reserved.
FreeBSD 6.0-RELEASE #0: Wed Dec 14 02:20:06 CST 2005
    xxxxxxxxxxx.xxxxxx.org:/usr/src/sys/i386/compile/COMCAST_SB_EHCI
Timecounter "i8254" frequency 1193182 Hz quality 0
CPU: VIA C3 Nehemiah+RNG (733.21-MHz 686-class CPU)
  Origin = "CentaurHauls"  Id = 0x694  Stepping = 4
  Features=0x380b03d<FPU,DE,PSE,TSC,MSR,MTRR,PGE,CMOV,MMX,FXSR,SSE>
real memory  = 251592704 (239 MB)
avail memory = 236716032 (225 MB)
ath_hal: 0.9.14.9 (AR5210, AR5211, AR5212, RF5111, RF5112, RF2413)
npx0: [FAST]
npx0: <math processor> on motherboard
npx0: INT 16 interface
acpi0: <WBIOS WHIZACPI> on motherboard
acpi0: Power Button (fixed)
pci_link0: <ACPI PCI Link LNKA> irq 11 on acpi0
pci_link1: <ACPI PCI Link LNKB> irq 10 on acpi0
pci_link2: <ACPI PCI Link LNKC> irq 7 on acpi0
pci_link3: <ACPI PCI Link LNKD> irq 5 on acpi0
pci_link4: <ACPI PCI Link ALKA> irq 0 on acpi0
pci_link5: <ACPI PCI Link ALKB> irq 1 on acpi0
pci_link6: <ACPI PCI Link ALKC> irq 1 on acpi0
pci_link7: <ACPI PCI Link ALKD> irq 1 on acpi0
Timecounter "ACPI-fast" frequency 3579545 Hz quality 1000
acpi_timer0: <24-bit timer at 3.579545MHz> port 0x5008-0x500b on acpi0
cpu0: <ACPI CPU> on acpi0
acpi_throttle0: <ACPI CPU Throttling> on cpu0
acpi_button0: <Power Button> on acpi0
pcib0: <ACPI Host-PCI bridge> port 0xcf8-0xcff,0x4000-0x407f,0x5000-0x505f on acpi0
pci0: <ACPI PCI bus> on pcib0
agp0: <VIA 862x (CLE266) host to PCI bridge> mem 0xe0000000-0xe7ffffff at device 0.0 on pci0
pcib1: <PCI-PCI bridge> at device 1.0 on pci0
pci1: <PCI bus> on pcib1
pci1: <display, VGA> at device 0.0 (no driver attached)
rl0: <RealTek 8139 10/100BaseTX> port 0xf000-0xf0ff mem 0xf0000000-0xf00000ff irq 10 at device 8.0 on pci0
miibus0: <MII bus> on rl0
rlphy0: <RealTek internal media interface> on miibus0
rlphy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
rl0: Ethernet address: 00:30:9d:81:00:10
cbb0: <O2Micro OZ6912/6972 PCI-CardBus Bridge> irq 7 at device 9.0 on pci0
cardbus0: <CardBus bus> on cbb0
pccard0: <16-bit PCCard bus> on cbb0
uhci0: <VIA 83C572 USB controller> port 0xf100-0xf11f irq 11 at device 16.0 on pci0
uhci0: [GIANT-LOCKED]
uhci0: LegSup = 0x0010
usb0: <VIA 83C572 USB controller> on uhci0
usb0: USB revision 1.0
usbd_get_string: getting lang failed, using 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 0xf120-0xf13f irq 10 at device 16.1 on pci0
uhci1: [GIANT-LOCKED]
uhci1: LegSup = 0x0010
usb1: <VIA 83C572 USB controller> on uhci1
usb1: USB revision 1.0
usbd_get_string: getting lang failed, using 0
uhub1: VIA UHCI root hub, class 9/0, rev 1.00/1.00, addr 1
uhub1: 2 ports with 2 removable, self powered
ehci0: <VIA VT6202 USB 2.0 controller> mem 0xf0000400-0xf00004ff irq 5 at device 16.3 on pci0
ehci0: [GIANT-LOCKED]
usb2: EHCI version 1.0
usb2: companion controllers, 2 ports each: usb0 usb1
usb2: <VIA VT6202 USB 2.0 controller> on ehci0
usb2: USB revision 2.0
uhub2: VIA EHCI root hub, class 9/0, rev 2.00/1.00, addr 1
uhub2: 4 ports with 4 removable, self powered
isab0: <PCI-ISA bridge> at device 17.0 on pci0
isa0: <ISA bus> on isab0
atapci0: <VIA 8235 UDMA133 controller> port 0x1f0-0x1f7,0x3f6,0x170-0x177,0x376,0xf160-0xf16f at device 17.1 on pci0
ata0: <ATA channel 0> on atapci0
ata1: <ATA channel 1> on atapci0
pcm0: <VIA VT8235> port 0xf200-0xf2ff irq 7 at device 17.5 on pci0
pcm0: [GIANT-LOCKED]
pcm0: <ICEnsemble VT1616 AC97 Codec>
vr0: <VIA VT6102 Rhine II 10/100BaseTX> port 0xf400-0xf4ff mem 0xf0000800-0xf00008ff irq 11 at device 18.0 on pci0
miibus1: <MII bus> on vr0
ukphy0: <Generic IEEE 802.3u media interface> on miibus1
ukphy0:  10baseT, 10baseT-FDX, 100baseTX, 100baseTX-FDX, auto
vr0: Ethernet address: 00:30:9d:82:00:10
acpi_tz0: <Thermal Zone> on acpi0
speaker0: <PC speaker> port 0x61 on acpi0
atkbdc0: <Keyboard controller (i8042)> port 0x60,0x64 irq 1 on acpi0
atkbd0: <AT Keyboard> irq 1 on atkbdc0
kbd0 at atkbd0
atkbd0: [GIANT-LOCKED]
psm0: <PS/2 Mouse> irq 12 on atkbdc0
psm0: [GIANT-LOCKED]
psm0: model Generic PS/2 mouse, device ID 0
pmtimer0 on isa0
orm0: <ISA Option ROM> at iomem 0xe0000-0xeffff on isa0
fdc0: No FDOUT register!
sc0: <System console> at flags 0x100 on isa0
sc0: VGA <16 virtual consoles, flags=0x300>
vga0: <Generic ISA VGA> at port 0x3c0-0x3df iomem 0xa0000-0xbffff on isa0
ugen0: APC Back-UPS ES 725 FW:802.n2.D USB FW:n2, rev 1.10/1.06, addr 2
Timecounter "TSC" frequency 733207166 Hz quality 800
Timecounters tick every 1.000 msec
ipfw2 (+ipv6) initialized, divert loadable, rule-based forwarding enabled, default to deny, logging disabled
ath0: <Atheros 5212> mem 0x88000000-0x8800ffff irq 7 at device 0.0 on cardbus0
ath0: Ethernet address: 00:0d:88:c7:51:19
ath0: mac 5.6 phy 4.1 radio 4.6
ad0: 28615MB <FUJITSU MHT2030AT 009A> at ata0-master UDMA100
-------------------------------------------------------

>Fix:
              
>Release-Note:
>Audit-Trail:
>Unformatted: