Bug 8023

Summary: ehci_hcd driver bug
Product: Drivers Reporter: Alexander N. Golovko (alexandro)
Component: USBAssignee: David Brownell (dbrownell)
Status: CLOSED CODE_FIX    
Severity: high CC: greg, protasnb, raquacontact
Priority: P2    
Hardware: i386   
OS: Linux   
Kernel Version: 2.6.20 Subsystem:
Regression: --- Bisected commit-id:
Bug Depends on:    
Bug Blocks: 5089    
Attachments: This is normal start without any kernel params, when I get this bug
lspci
lsusb with my Ralink usb dongle attached
ifconfig after my wireless stops working
dmesg with acpi=noirg
dmesg with irqpoll, gives some errors
dmesg with noacpi
dmesg with pci=noacpi
dmesg with pci=routeirq

Description Alexander N. Golovko 2007-02-16 12:56:12 UTC
Most recent kernel where this bug did *NOT* occur: 
Distribution: debian
Hardware Environment: i815 motherboard, celeron coppermine.
Software Environment:

Problem Description:
Don't work hi-speed usb storage devices with pci usb controller.
With unloaded ehci_hcd module device work without problem, but it use uhci_hcd 
and full-speed.

Steps to reproduce:
plug device and try to read information from it.



% modprobe ehci_hcd

Feb 16 23:06:44 glaurung kernel: ACPI: PCI Interrupt 0000:02:04.2[C] -> Link 
[LNK0] -> GSI 10 (level, low) -> IRQ 10
Feb 16 23:06:44 glaurung kernel: ehci_hcd 0000:02:04.2: EHCI Host Controller
Feb 16 23:06:44 glaurung kernel: ehci_hcd 0000:02:04.2: new USB bus registered, 
assigned bus number 5
Feb 16 23:06:44 glaurung kernel: ehci_hcd 0000:02:04.2: irq 10, io mem 
0xef202000
Feb 16 23:06:44 glaurung kernel: ehci_hcd 0000:02:04.2: USB 2.0 started, EHCI 
1.00, driver 10 Dec 2004
Feb 16 23:06:44 glaurung kernel: usb usb5: Product: EHCI Host Controller
Feb 16 23:06:44 glaurung kernel: usb usb5: Manufacturer: Linux 2.6.20-glaurung 
ehci_hcd
Feb 16 23:06:44 glaurung kernel: usb usb5: SerialNumber: 0000:02:04.2
Feb 16 23:06:44 glaurung kernel: usb usb5: configuration #1 chosen from 1 choice
Feb 16 23:06:44 glaurung kernel: hub 5-0:1.0: USB hub found
Feb 16 23:06:44 glaurung kernel: hub 5-0:1.0: 4 ports detected



<plug device>

Feb 16 23:06:58 glaurung kernel: usb 5-2: new high speed USB device using 
ehci_hcd and address 2
Feb 16 23:06:58 glaurung kernel: usb 5-2: Product: USB to Serial-ATA bridge
Feb 16 23:06:58 glaurung kernel: usb 5-2: Manufacturer: Sunplus Technology Inc.
Feb 16 23:06:58 glaurung kernel: usb 5-2: SerialNumber: ST3200822A            
3LJ2A8XW
Feb 16 23:06:58 glaurung kernel: usb 5-2: configuration #1 chosen from 1 choice
Feb 16 23:06:58 glaurung kernel: scsi12 : SCSI emulation for USB Mass Storage 
devices
Feb 16 23:07:03 glaurung kernel: scsi 12:0:0:0: Direct-Access     ST320082 
2AS                   PQ: 0 ANSI: 2
Feb 16 23:07:03 glaurung kernel: SCSI device sda: 390721968 512-byte hdwr 
sectors (200050 MB)
Feb 16 23:07:03 glaurung kernel: sda: Write Protect is off
Feb 16 23:07:03 glaurung kernel: SCSI device sda: 390721968 512-byte hdwr 
sectors (200050 MB)
Feb 16 23:07:03 glaurung kernel: sda: Write Protect is off
Feb 16 23:07:03 glaurung kernel:  sda:<7>usb-storage: queuecommand called
Feb 16 23:07:03 glaurung kernel:  sda1 < sda5 >
Feb 16 23:07:03 glaurung kernel: sd 12:0:0:0: Attached scsi disk sda



% dd if=/dev/sda of=/dev/null (exit with error)

Feb 16 23:07:48 glaurung kernel: usb 5-2: reset high speed USB device using 
ehci_hcd and address 2
Feb 16 23:08:00 glaurung kernel: usb 5-2: USB disconnect, address 2
Feb 16 23:08:00 glaurung kernel: sd 12:0:0:0: SCSI error: return code = 
0x00010000
Feb 16 23:08:00 glaurung kernel: end_request: I/O error, dev sda, sector 48240
Feb 16 23:08:00 glaurung kernel: printk: 33 messages suppressed.
Feb 16 23:08:00 glaurung kernel: sd 12:0:0:0: SCSI error: return code = 
0x00010000
Feb 16 23:08:00 glaurung kernel: end_request: I/O error, dev sda, sector 48480
Feb 16 23:08:00 glaurung kernel: usb 5-2: new high speed USB device using 
ehci_hcd and address 3
Feb 16 23:08:00 glaurung kernel: usb 5-2: Product: USB to Serial-ATA bridge
Feb 16 23:08:00 glaurung kernel: usb 5-2: Manufacturer: Sunplus Technology Inc.
Feb 16 23:08:00 glaurung kernel: usb 5-2: SerialNumber: ST3200822A            
3LJ2A8XW
Feb 16 23:08:00 glaurung kernel: usb 5-2: configuration #1 chosen from 1 choice
Feb 16 23:08:00 glaurung kernel: scsi13 : SCSI emulation for USB Mass Storage 
devices
Feb 16 23:08:05 glaurung kernel: scsi 13:0:0:0: Direct-Access     ST320082 
2AS                   PQ: 0 ANSI: 2
Feb 16 23:08:05 glaurung kernel: SCSI device sda: 390721968 512-byte hdwr 
sectors (200050 MB)
Feb 16 23:08:05 glaurung kernel: sda: Write Protect is off
Feb 16 23:08:05 glaurung kernel: SCSI device sda: 390721968 512-byte hdwr 
sectors (200050 MB)
Feb 16 23:08:06 glaurung kernel: sda: Write Protect is off
Feb 16 23:08:06 glaurung kernel:  sda:<7>usb-storage: queuecommand called
Feb 16 23:08:06 glaurung kernel:  sda1 < sda5 >
Feb 16 23:08:06 glaurung kernel: sd 13:0:0:0: Attached scsi disk sda



% dd if=/dev/sda of=/dev/null (exit with error)

Feb 16 23:08:33 glaurung kernel: sd 13:0:0:0: SCSI error: return code = 
0x00070000
Feb 16 23:08:33 glaurung kernel: end_request: I/O error, dev sda, sector 17408
Feb 16 23:08:33 glaurung kernel: printk: 49 messages suppressed.
Feb 16 23:08:33 glaurung kernel: sd 13:0:0:0: SCSI error: return code = 
0x00070000
Feb 16 23:08:33 glaurung kernel: end_request: I/O error, dev sda, sector 17648
Feb 16 23:08:33 glaurung kernel: sd 13:0:0:0: SCSI error: return code = 
0x00070000
Feb 16 23:08:33 glaurung kernel: end_request: I/O error, dev sda, sector 17888
Feb 16 23:08:33 glaurung kernel: sd 13:0:0:0: SCSI error: return code = 
0x00070000
Feb 16 23:08:33 glaurung kernel: end_request: I/O error, dev sda, sector 17408
Feb 16 23:08:33 glaurung kernel: usb 3-2: new full speed USB device using 
uhci_hcd and address 14
Feb 16 23:08:33 glaurung kernel: sd 13:0:0:0: SCSI error: return code = 
0x00070000
Feb 16 23:08:33 glaurung kernel: end_request: I/O error, dev sda, sector 17408
Feb 16 23:08:34 glaurung kernel: usb 3-2: new full speed USB device using 
uhci_hcd and address 15
Feb 16 23:08:34 glaurung kernel: usb 3-2: new full speed USB device using 
uhci_hcd and address 16
Feb 16 23:08:35 glaurung kernel: usb 3-2: new full speed USB device using 
uhci_hcd and address 17
Feb 16 23:08:35 glaurung kernel: usb 5-2: USB disconnect, address 3
Feb 16 23:08:45 glaurung kernel: usb 5-2: new high speed USB device using 
ehci_hcd and address 4
Feb 16 23:08:45 glaurung kernel: usb 5-2: Product: USB to Serial-ATA bridge
Feb 16 23:08:45 glaurung kernel: usb 5-2: Manufacturer: Sunplus Technology Inc.
Feb 16 23:08:45 glaurung kernel: usb 5-2: SerialNumber: ST3200822A            
3LJ2A8XW
Feb 16 23:08:45 glaurung kernel: usb 5-2: configuration #1 chosen from 1 choice
Feb 16 23:08:45 glaurung kernel: scsi14 : SCSI emulation for USB Mass Storage 
devices
Feb 16 23:08:50 glaurung kernel: scsi 14:0:0:0: Direct-Access     ST320082 
2AS                   PQ: 0 ANSI: 2
Feb 16 23:08:50 glaurung kernel: SCSI device sda: 390721968 512-byte hdwr 
sectors (200050 MB)
Feb 16 23:08:50 glaurung kernel: sda: Write Protect is off
Feb 16 23:08:50 glaurung kernel: SCSI device sda: 390721968 512-byte hdwr 
sectors (200050 MB)
Feb 16 23:08:50 glaurung kernel: sda: Write Protect is off
Feb 16 23:08:50 glaurung kernel:  sda:<7>usb-storage: queuecommand called
Feb 16 23:08:50 glaurung kernel:  sda1 < sda5 >
Feb 16 23:08:50 glaurung kernel: sd 14:0:0:0: Attached scsi disk sda
Feb 16 23:08:51 glaurung kernel: usb 5-2: reset high speed USB device using 
ehci_hcd and address 4
Feb 16 23:09:02 glaurung kernel: usb 5-2: USB disconnect, address 4
Feb 16 23:09:02 glaurung kernel: sd 14:0:0:0: SCSI error: return code = 
0x00010000
Feb 16 23:09:02 glaurung kernel: end_request: I/O error, dev sda, sector 47730
Feb 16 23:09:02 glaurung kernel: printk: 60 messages suppressed.
Feb 16 23:09:02 glaurung kernel: usb 5-2: new high speed USB device using 
ehci_hcd and address 5
Feb 16 23:09:03 glaurung kernel: usb 5-2: Product: USB to Serial-ATA bridge
Feb 16 23:09:03 glaurung kernel: usb 5-2: Manufacturer: Sunplus Technology Inc.
Feb 16 23:09:03 glaurung kernel: usb 5-2: SerialNumber: ST3200822A            
3LJ2A8XW
Feb 16 23:09:03 glaurung kernel: usb 5-2: configuration #1 chosen from 1 choice
Feb 16 23:09:03 glaurung kernel: scsi15 : SCSI emulation for USB Mass Storage 
devices
Feb 16 23:09:08 glaurung kernel: scsi 15:0:0:0: Direct-Access     ST320082 
2AS                   PQ: 0 ANSI: 2
Feb 16 23:09:08 glaurung kernel: SCSI device sda: 390721968 512-byte hdwr 
sectors (200050 MB)
Feb 16 23:09:08 glaurung kernel: sda: Write Protect is off
Feb 16 23:09:08 glaurung kernel: SCSI device sda: 390721968 512-byte hdwr 
sectors (200050 MB)
Feb 16 23:09:08 glaurung kernel: sda: Write Protect is off
Feb 16 23:09:08 glaurung kernel:  sda:<7>usb-storage: queuecommand called
Feb 16 23:09:08 glaurung kernel:  sda1 < sda5 >
Feb 16 23:09:08 glaurung kernel: sd 15:0:0:0: Attached scsi disk sda



<unplug device>

Feb 16 23:09:18 glaurung kernel: usb 5-2: USB disconnect, address 5



% lsmod

ehci_hcd               45676  0 
sd_mod                 20144  0 
usb_storage            47492  0 
scsi_mod              142252  2 sd_mod,usb_storage
ipt_MASQUERADE          3328  1 
xt_state                2368  1 
ipt_REJECT              4288  2 
xt_tcpudp               3200  18 
iptable_mangle          2720  0 
iptable_nat             7492  1 
nf_conntrack_ipv4      16332  2 iptable_nat
iptable_filter          2880  1 
ip_tables              12200  3 iptable_mangle,iptable_nat,iptable_filter
x_tables               15396  6 
ipt_MASQUERADE,xt_state,ipt_REJECT,xt_tcpudp,iptable_nat,ip_tables
xfs                   542516  1 
reiserfs              236096  3 
nf_nat_ftp              3488  0 
nf_nat                 17484  3 ipt_MASQUERADE,iptable_nat,nf_nat_ftp
nf_conntrack_ftp        9440  1 nf_nat_ftp
nf_conntrack           57096  7 
ipt_MASQUERADE,xt_state,iptable_nat,nf_conntrack_ipv4,nf_nat_ftp,nf_nat,nf_conntrack_ftp
ppp_async              11488  1 
crc_ccitt               2016  1 ppp_async
ppp_generic            27572  5 ppp_async
slhc                    6688  1 ppp_generic
snd_emu10k1_synth       7072  0 
snd_emux_synth         35072  1 snd_emu10k1_synth
snd_seq_virmidi         6880  1 snd_emux_synth
snd_seq_midi_emul       6720  1 snd_emux_synth
snd_seq_dummy           3684  0 
snd_seq_oss            32000  0 
snd_seq_midi            8480  0 
snd_seq_midi_event      7360  3 snd_seq_virmidi,snd_seq_oss,snd_seq_midi
snd_seq                50256  9 
snd_emux_synth,snd_seq_virmidi,snd_seq_midi_emul,snd_seq_dummy,snd_seq_oss,snd_seq_midi,snd_seq_midi_event
snd_emu10k1           120544  3 snd_emu10k1_synth
snd_rawmidi            24352  3 snd_seq_virmidi,snd_seq_midi,snd_emu10k1
snd_ac97_codec         94048  1 snd_emu10k1
ac97_bus                2176  1 snd_ac97_codec
snd_pcm_oss            43360  0 
snd_mixer_oss          16704  1 snd_pcm_oss
hci_usb                16924  0 
snd_pcm                78024  4 snd_emu10k1,snd_ac97_codec,snd_pcm_oss
snd_seq_device          8108  8 
snd_emu10k1_synth,snd_emux_synth,snd_seq_dummy,snd_seq_oss,snd_seq_midi,snd_seq,snd_emu10k1,snd_rawmidi
bluetooth              53444  1 hci_usb
snd_timer              22980  3 snd_seq,snd_emu10k1,snd_pcm
snd_page_alloc          9896  2 snd_emu10k1,snd_pcm
snd_util_mem            4704  2 snd_emux_synth,snd_emu10k1
i2c_i801                7820  0 
snd_hwdep               9156  2 snd_emux_synth,snd_emu10k1
snd                    51972  16 
snd_emux_synth,snd_seq_virmidi,snd_seq_oss,snd_seq,snd_emu10k1,snd_rawmidi,snd_ac97_codec,snd_pcm_oss,snd_mixer_oss,snd_pcm,snd_seq_device,snd_timer,snd_hwdep
soundcore               7968  1 snd
psmouse                37736  0 
intel_agp              23772  1 
agpgart                32176  1 intel_agp
i2c_core               22096  1 i2c_i801
evdev                  10016  4 
ext3                  123112  1 
jbd                    58920  1 ext3
mbcache                 8740  1 ext3
dm_mirror              20724  0 
dm_snapshot            16704  0 
dm_mod                 56876  5 dm_mirror,dm_snapshot
ide_disk               15904  8 
e100                   34248  0 
uhci_hcd               32208  0 
usbcore               146104  5 ehci_hcd,usb_storage,hci_usb,uhci_hcd
piix                   10020  0 [permanent]
ide_core              118648  2 ide_disk,piix



% cat /boot/config-2.6.20-glaurung |grep USB |grep DEBUG

CONFIG_USB_DEBUG=y
CONFIG_USB_STORAGE_DEBUG=y



% lspci

00:00.0 Host bridge: Intel Corporation 82815 815 Chipset Host Bridge and Memory 
Controller Hub (rev 04)
00:01.0 PCI bridge: Intel Corporation 82815 815 Chipset AGP Bridge (rev 04)
00:1e.0 PCI bridge: Intel Corporation 82801 PCI Bridge (rev 05)
00:1f.0 ISA bridge: Intel Corporation 82801BA ISA Bridge (LPC) (rev 05)
00:1f.1 IDE interface: Intel Corporation 82801BA IDE U100 (rev 05)
00:1f.2 USB Controller: Intel Corporation 82801BA/BAM USB (Hub #1) (rev 05)
00:1f.3 SMBus: Intel Corporation 82801BA/BAM SMBus (rev 05)
00:1f.4 USB Controller: Intel Corporation 82801BA/BAM USB (Hub #2) (rev 05)
01:00.0 VGA compatible controller: nVidia Corporation NV34 [GeForce FX 
5200] (rev a1)
02:01.0 Ethernet controller: Intel Corporation 82557/8/9 [Ethernet Pro 
100] (rev 08)
02:02.0 Ethernet controller: Intel Corporation 82557/8/9 [Ethernet Pro 
100] (rev 08)
02:03.0 Multimedia audio controller: Creative Labs SB Live! EMU10k1 (rev 07)
02:03.1 Input device controller: Creative Labs SB Live! Game Port (rev 07)
02:04.0 USB Controller: VIA Technologies, Inc. VT82xxxxx UHCI USB 1.1 
Controller (rev 61)
02:04.1 USB Controller: VIA Technologies, Inc. VT82xxxxx UHCI USB 1.1 
Controller (rev 61)
02:04.2 USB Controller: VIA Technologies, Inc. USB 2.0 (rev 63)



I get very similar simtoms with usb flash. Debian kernel package (linux-image-
2.6.18-2-686, package version: 2.6.18-5) have the same bug.
Very similar problem described in bug 7533

Manufacturer of pci usb controler is Highpack.
Comment 1 Alexander N. Golovko 2007-02-16 13:26:52 UTC
PCI USB controller based on VIA VT6212L chip.
Comment 2 Natalie Protasevich 2007-08-11 10:33:44 UTC
Alexander, can you please test with the latest kernel (2.6.23+)?
Thanks.
Comment 3 Martin Dratva 2008-01-27 09:41:00 UTC
I have similar problem to this, so instead of opening a new bug report, I will add it here as the original reporter seems to be not interested in this bug anymore.
 
Most recent kernel where this bug did *NOT* occur: ??
Distribution: arch linux
Hardware Environment: celeron coppermine 2x, Abit VP6 motherboard, Edimax (Via chipset) USB 2.0 controller
Software Environment:

Problem Description: same as original reporter

This computer does not have USB 2.0 on a motherboard. I wanted to use wireless USB card (rt73 chipset) at high speed, because on usb 1.1 speed I could not use my internet conection to its full potencial. 
I bought Edimax USB 2.0 PCI card with 4 USB slots. 
My wireless card stops working after couple of seconds, mostly under 2 minutes of uptime. If I unload ehci_hcd module, everything is fine and working, except for the slow speed, which is why I bought this new controller at first. 

I did a search on this bug and found various methods to solve it, so I tried all of those without success.
I tried booting with these parameters (each one separately) :

acpi=noirq
irqpoll
noacpi
pci=noacpi
pci=routeirq

None of those helped, some even made things worse.
I will add dmesg and other info here.
Comment 4 Martin Dratva 2008-01-27 09:46:02 UTC
Created attachment 14597 [details]
This is normal start without any kernel params, when I get this bug
Comment 5 Martin Dratva 2008-01-27 09:48:46 UTC
Created attachment 14598 [details]
lspci

Seems like most of the people having this problem have VIA chipsets on usb controller.
Comment 6 Martin Dratva 2008-01-27 09:49:33 UTC
Created attachment 14599 [details]
lsusb with my Ralink usb dongle attached
Comment 7 Martin Dratva 2008-01-27 09:51:13 UTC
Created attachment 14600 [details]
ifconfig after my wireless stops working

Card seems to be reckognized and working, but I can not ping anything.
Comment 8 Martin Dratva 2008-01-27 09:52:10 UTC
Created attachment 14601 [details]
dmesg with acpi=noirg
Comment 9 Martin Dratva 2008-01-27 09:53:40 UTC
Created attachment 14602 [details]
dmesg with irqpoll, gives some errors

My computer was very slow with this parameter.
Comment 10 Martin Dratva 2008-01-27 09:55:02 UTC
Created attachment 14603 [details]
dmesg with noacpi
Comment 11 Martin Dratva 2008-01-27 09:57:32 UTC
Created attachment 14604 [details]
dmesg with pci=noacpi
Comment 12 Martin Dratva 2008-01-27 09:58:38 UTC
Created attachment 14605 [details]
dmesg with pci=routeirq

This time it did not work since boot. Normally it does and the dies after a while.
Comment 13 Martin Dratva 2008-01-27 10:12:53 UTC
One last thing - after my device stops working, lsusb command gives me these errors:
can't get hub descriptor: Operation not permitted
cannot read device status, Operation not permitted (1)

The desired output is still there though. I am not sure if this means something. 

This problem is not related only to wireless card, I get troublesome performance also with usb disk and flash memory.
I tested this usb controller in other computer with Windows installed and it worked fine, so it is not a HW problem.
Comment 14 Martin Dratva 2008-02-12 14:22:17 UTC
I switched to new 2.6.24 kernel and it seems to be working ok. This report should be closed I asume.
Comment 15 J T P Garmendia 2008-04-15 17:46:40 UTC
$ lsusb 
Bus 005 Device 032: ID 04fc:0c15 Sunplus Technology Co., Ltd 
Bus 005 Device 031: ID 04fc:0c15 Sunplus Technology Co., Ltd 

and from the dmesg, errors like:
[25566.613764] hub 5-0:1.0: Cannot enable port 2.  Maybe the USB cable is bad?
[25568.162343] hub 5-0:1.0: connect-debounce failed, port 2 disabled

This happens with two Zaapa 750GB USB 2.0 (SATA to USB) drives. They are directly connected to the backplate, and have a power supply of their own. If I have four of these connected simultaneously, the error happens even earlier.
Comment 16 David Brownell 2008-08-26 12:47:13 UTC
I'm marking this closed, since 2.6.24 seems to behave.  The issue in comment #15 is completely unrelated.