David: This might be a good test case for determining what those crazy VIA EHCI controllers are doing.
On Sun, 18 Dec 2005, Andreas Klauer wrote: > Hi all, > > I'm new to this list. Please don't hurt me. m(_)m > > I've got a weird problem with one of my USB storage devices (a Trekstor > MP3 player which supports USB2). When I connect it to the computer while > the ehci_hcd module is loaded, some part of the USB subsystem seems to > freeze indefinitely. For example when calling 'lsusb', it just hangs, > until I physically disconnect the MP3 player. > > I've also got another usb-storage device (a card reader with 4 slots), > which gets detected fine using ehci. Four scsi disk devices are emulated. > So ehci and usb-storage can't be broken in general. > > The MP3 player itself doesn't seem to be defective either; it works fine > under Windows, as well as under Linux when I force it to use uhci instead > of ehci by simply removing the ehci module altogether. > > This is in vanilla kernel 2.6.14.4; but it's the same story in other > kernel versions (I also tested with a Knoppix DVD that uses 2.6.12). > I also tried 2.6.15-rc5-mm1, but this kernel actually panicked when I > connected the device. I attached the output in case it's of interest. > > In the following, I'm trying to provide some information about the problem. > Please tell me whatever else you may need for identifying the cause. > > ---- My hardware: ---- > Athlon XP, Chaintech Apogee 7VJL board, with VIA VT8235 southbridge. > > lspci says about USB: > 00:10.0 USB Controller: VIA Technologies, Inc. VT82xxxxx UHCI USB 1.1 > Controller (rev 80) > 00:10.1 USB Controller: VIA Technologies, Inc. VT82xxxxx UHCI USB 1.1 > Controller (rev 80) > 00:10.2 USB Controller: VIA Technologies, Inc. VT82xxxxx UHCI USB 1.1 > Controller (rev 80) > 00:10.3 USB Controller: VIA Technologies, Inc. USB 2.0 (rev 82) > ---- > > The following logs were produced using vanilla 2.6.14.4 kernel, USB debug > messages enabled, as well as timing information (uptime in seconds) for > kernel printk's. > > ---- When connecting the MP3 player with ehci enabled: ---- > [ 201.036582] hub 4-1:1.0: state 5 ports 4 chg 0000 evt 0008 > [ 201.036809] hub 4-1:1.0: port 3, status 0101, change 0001, 12 Mb/s > [ 201.140406] hub 4-1:1.0: debounce: port 3: total 100ms stable 100ms status > 0x101 > [ 201.202391] usb 4-1.3: new high speed USB device using ehci_hcd and > address 6 > [ 202.201912] usb 4-1.3: hcd_unlink_urb d2dfac40 fail -16 > [ 207.325971] usb 4-1.3: khubd timed out on ep0in len=9/9 > [ 212.323938] usb 4-1.3: khubd timed out on ep0in len=32/32 > [ 217.321914] usb 4-1.3: hcd_unlink_urb d2dfac40 fail -16 > ---- Those "fail -16" messages are the key, although I don't know what they mean. > ---- When disconnecting the MP3 player with ehci enabled: ---- > [ 274.199116] usb 4-1.3: default language 0x0409 > [ 274.199341] ehci_hcd 0000:00:10.3: devpath 1.3 ep0in 3strikes > [ 274.199590] ehci_hcd 0000:00:10.3: devpath 1.3 ep0in 3strikes > [ 274.199838] ehci_hcd 0000:00:10.3: devpath 1.3 ep0in 3strikes > [ 274.200088] ehci_hcd 0000:00:10.3: devpath 1.3 ep0in 3strikes > [ 274.209462] ehci_hcd 0000:00:10.3: devpath 1.3 ep0in 3strikes > [ 274.209711] ehci_hcd 0000:00:10.3: devpath 1.3 ep0in 3strikes > [ 274.209722] usb 4-1.3: new device strings: Mfr=1, Product=2, SerialNumber=3 > [ 274.209753] usb 4-1.3: hotplug > [ 274.209961] ehci_hcd 0000:00:10.3: devpath 1.3 ep0out 3strikes > [ 274.209974] usb 4-1.3: can't set config #1, error -71 > [ 274.210003] usb 4-1.3: hotplug > [ 274.232220] hub 4-1:1.0: state 5 ports 4 chg 0000 evt 0008 > [ 274.232586] hub 4-1:1.0: port 3, status 0300, change 0003, 1.5 Mb/s > [ 274.336434] hub 4-1:1.0: debounce: port 3: total 100ms stable 100ms status > 0x300 > ---- > > ---- When connecting the MP3 player with ehci disabled: ---- > [ 395.079856] hub 1-1:1.0: state 5 ports 4 chg 0000 evt 0008 > [ 395.082829] hub 1-1:1.0: port 3, status 0101, change 0001, 12 Mb/s > [ 395.188787] hub 1-1:1.0: debounce: port 3: total 100ms stable 100ms status > 0x101 > [ 395.251759] usb 1-1.3: new full speed USB device using uhci_hcd and > address 10 > [ 396.252358] usb 1-1.3: khubd timed out on ep0in len=18/64 This is strange. It resembles the EHCI problems, although here it worked out okay. The only way a short transfer like this can timeout is if the device NAKs the status stage, or the controller behaves as though the device did so. This could be either a controller bug or a device bug. The easiest way to tell would be to plug the player into a different computer, one with a non-VIA chipset. > [ 396.356303] usb 1-1.3: default language 0x0409 > [ 396.361302] usb 1-1.3: new device strings: Mfr=1, Product=2, SerialNumber=3 > [ 396.361307] usb 1-1.3: Product: i.Beat organix > [ 396.361309] usb 1-1.3: Manufacturer: TrekStor > [ 396.361312] usb 1-1.3: SerialNumber: 0002F685DB12088F ... The rest is all normal. > ---- When disconnecting the MP3 player with ehci disabled: ---- > [ 542.731122] hub 1-1:1.0: state 5 ports 4 chg 0000 evt 0008 > [ 542.734093] hub 1-1:1.0: port 3, status 0100, change 0001, 12 Mb/s > [ 542.735094] usb 1-1.3: USB disconnect, address 10 > [ 542.735098] usb 1-1.3: usb_disable_device nuking all URBs > [ 542.735105] usb 1-1.3: unregistering interface 1-1.3:1.0 > [ 542.735146] usb-storage: storage_disconnect() called > [ 542.735150] usb-storage: usb_stor_stop_transport called > [ 542.740879] usb-storage: -- usb_stor_release_resources > [ 542.740886] usb-storage: -- sending exit command to thread > [ 542.740891] usb-storage: -- dissociate_dev > [ 542.740914] usb 1-1.3:1.0: hotplug > [ 542.741214] usb 1-1.3: unregistering device > [ 542.743680] usb 1-1.3: hotplug > [ 542.743722] usb-storage: *** thread awakened. > [ 542.743725] usb-storage: -- exiting > [ 542.856057] hub 1-1:1.0: debounce: port 3: total 100ms stable 100ms status > 0x100 > ---- This is normal also. > ---- 2.6.15-rc5-mm1 kernel panic when connecting MP3 player: ---- > usb 1-1.3: new high speed USB device using ehci_hcd and address 6 > usb 1-1.3: configuration #1 chosen from 1 choice > Unable to handle kernel NULL pointer dereference at virtual address 00000000 > printing eip: > c015f878 > *pde = 00000000 > Oops: 0000 [#1] > PREEMPT > last sysfs file: /class/vc/vcsa6/dev > Modules linked in: it87 hwmon_vid eeprom lm90 hwmon i2c_isa i2c_viapro > i2c_core > CPU: 0 > EIP: 0060:[<c015f878>] Not tainted VLI > EFLAGS: 00010046 (2.6.15-rc5-mm1) > EIP is at kfree+0x38/0x70 > eax: 00000000 ebx: 0000018d ecx: dfcf6c20 edx: 00000001 > esi: 00000000 edi: 00000001 ebp: 00000202 esp: c1565e60 > ds: 007b es: 007b ss: 0068 > Process khubd (pid: 88, threadinfo=c1564000 task=c152b550) > Stack: <0>00000000 00000009 0000018d ffffffb9 dfa0e400 dec05c00 c03442ff > 00000001 > <0>80000600 00000009 00000000 00000001 00000000 00000000 00000000 > 00001388 > <0>dec05cf4 00000001 00000001 dfcf6c20 dfa0e400 00000000 dec05c00 > 00000001 > Call Trace: > [<c03442ff>] usb_set_configuration+0x39f/0x4a0 This is a known problem, and a patch has already been written to fix it: http://www.kernel.org/pub/linux/kernel/people/gregkh/gregkh-2.6/gregkh-04-usb/usbcore-fix-local-variable-clash.patch Alan Stern ------------------------------------------------------- This SF.net email is sponsored by: Splunk Inc. Do you grep through log files for problems? Stop! Download the new AJAX search engine that makes searching your log files as easy as surfing the web. DOWNLOAD SPLUNK! http://ads.osdn.com/?ad_id=7637&alloc_id=16865&op=click _______________________________________________ Linux-usb-users@lists.sourceforge.net To unsubscribe, use the last form field at: https://lists.sourceforge.net/lists/listinfo/linux-usb-users
