On Wed, 21 Dec 2005, Brown, Len wrote:
> Here you go.
> Note that this is the configuration with the devices
> plugged directly into the laptop, and the laptop also
> plugged into the docking station. Seems that the USB
> keyboard takes about 20 sec to come to life.
Actually that's the time it takes to give up on the docking station's hub.
Obviously it's far too long. The pattern of retries and timeouts is
supposed to go like this:
Select address
1 s, 1 s, 1 s Read/64
5 s, 5 s, 5 s Read/64
Select another address
1 s, 1 s, 1 s Read/64
5 s, 5 s, 5 s Read/64
Select another address
5 s, 5 s Set address
Select another address
5 s, 5 s Set address
Give up
There are various port resets and things in there also, but they only take
a few hundred ms.
Here are the corresponding entries filtered out from your log:
> [ 40.369567] usb 3-5: new high speed USB device using ehci_hcd and address 4
> [ 41.377425] usb 3-5: khubd timed out on ep0in len=0/64
> [ 42.377175] usb 3-5: khubd timed out on ep0in len=0/64
> [ 43.375165] usb 3-5: khubd timed out on ep0in len=0/64
> [ 43.431263] ehci_hcd 0000:00:02.2: port 5 high speed
> [ 48.594206] usb 3-5: khubd timed out on ep0in len=0/64
> [ 53.594759] usb 3-5: khubd timed out on ep0in len=0/64
> [ 63.968203] usb 3-5: khubd timed out on ep0in len=0/64
Note that this last timeout was 10 s instead of 5. I can't explain why
that happened; it doesn't make sense.
> [ 64.240277] ehci_hcd 0000:00:02.2: port 5 high speed
> [ 64.240289] ehci_hcd 0000:00:02.2: GetStatus port 5 status 001005 POWER
> sig=se0 PE CONNECT
> [ 64.296051] usb 3-5: new high speed USB device using ehci_hcd and address 5
> [ 65.295883] usb 3-5: khubd timed out on ep0in len=0/64
> [ 66.295771] usb 3-5: khubd timed out on ep0in len=0/64
> [ 67.295535] usb 3-5: khubd timed out on ep0in len=0/64
> [ 67.351745] ehci_hcd 0000:00:02.2: port 5 high speed
> [ 72.510693] usb 3-5: khubd timed out on ep0in len=0/64
> [ 77.509762] usb 3-5: khubd timed out on ep0in len=0/64
> [ 82.508834] usb 3-5: khubd timed out on ep0in len=0/64
This time it was 5 s, as expected.
> [ 82.780962] ehci_hcd 0000:00:02.2: port 5 high speed
> [ 82.780973] ehci_hcd 0000:00:02.2: GetStatus port 5 status 001005 POWER
> sig=se0 PE CONNECT
> [ 82.836743] usb 3-5: new high speed USB device using ehci_hcd and address 6
> [ 87.835956] usb 3-5: khubd timed out on ep0out len=0/0
> [ 93.038981] usb 3-5: khubd timed out on ep0out len=0/0
> [ 93.299111] ehci_hcd 0000:00:02.2: port 5 high speed
> [ 93.299125] ehci_hcd 0000:00:02.2: GetStatus port 5 status 001005 POWER
> sig=se0 PE CONNECT
> [ 93.354867] usb 3-5: new high speed USB device using ehci_hcd and address 7
> [ 98.354106] usb 3-5: khubd timed out on ep0out len=0/0
> [ 103.557130] usb 3-5: khubd timed out on ep0out len=0/0
That period from timestamp 40.3 to 103.5 was all useless waiting.
You can get rid of some of those retries by editing drivers/usb/core/hub.c
and changing the #define of GET_DESCRIPTOR_TRIES from 2 to 1. The USB
specification gives an upper limit of 5 seconds for devices to process
commands in general, although the commands being used here actually have
lower limits. We should be able to reduce all these timeouts to 1 second,
in principle.
Even so, this doesn't answer the real question...
> I guess the question then are what changed such that it worked
> on SL10 and it fails now,
Exactly. I have no idea. Can you identify the most recent kernel version
where it worked okay?
> and why the HW works when ohci-hcd
> talks to it but fails when ehci-hcd talks to it.
And to make it even more confusing, why does the hardware fail when
ehci-hcd talks to it during boot-up but work when you modprobe ehci-hcd
later on? Maybe it has something to do with the fact that in between, the
hardware was successfully initialized by ohci-hcd.
That suggests an interesting experiment. Rename both ehci-hcd.ko and
ohci-hcd.ko so that neither of them is loaded automatically at boot-up.
Then a few minutes after the startup is completed, via a network login,
manually insmod ehci-hcd.ko and see what happens. As an alternate
experiment, first manually insmod ohci-hcd.ko and then insmod ehci-hcd.ko.
This may tell us whether something special is happening during boot-up, or
if the hub just prefers to be initialized at full speed before working at
high speed.
It wouldn't hurt to try the same experiment with the last-known-good Linux
kernel as well. Ideally the change in behavior can be localized to some
particular change in ehci-hcd.
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-devel@lists.sourceforge.net
To unsubscribe, use the last form field at:
https://lists.sourceforge.net/lists/listinfo/linux-usb-devel
