Re: Occasional resume delays, possibly related to failure to resume internal USB devices?

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



On Sun, 1 Sep 2013, Bjørn Mork wrote:

> I've had this problem now and then for a couple of months: On system
> resume, my laptop will appear frozen for more than 30 seconds before
> finally responding. No keypress or other external input seems to have
> any effect. Pressing e.g. CapsLock will not lit the LED.  But when the
> laptop finally comes to life, every keypress is replayed.
> 
> I have tried to find out how to reliably trigger this, but haven't been
> successful.  It happens too infrequently for bisect to be effective.
> But what I have discovered is that it is related to problems with the
> internal USB webcam.  Whenever there is one of these delays, I also see
> this in the kernel log, always from the webcam device:

Clearly this results from a failure to put the webcam back to full 
power.

> Sep  1 12:32:39 nemi kernel: [174042.120072] usb 1-6: device descriptor read/64, error -110
> Sep  1 12:32:39 nemi kernel: [174057.336066] usb 1-6: device descriptor read/64, error -110
> Sep  1 12:32:39 nemi kernel: [174057.552069] usb 1-6: reset high-speed USB device number 11 using ehci-pci
> Sep  1 12:32:39 nemi kernel: [174072.664067] usb 1-6: device descriptor read/64, error -110
> Sep  1 12:32:39 nemi kernel: [174087.880154] usb 1-6: device descriptor read/64, error -110
> Sep  1 12:32:39 nemi kernel: [174088.096131] usb 1-6: reset high-speed USB device number 11 using ehci-pci
> Sep  1 12:32:39 nemi kernel: [174093.116266] usb 1-6: device descriptor read/8, error -110
> Sep  1 12:32:39 nemi kernel: [174098.236333] usb 1-6: device descriptor read/8, error -110
> Sep  1 12:32:39 nemi kernel: [174098.452066] usb 1-6: reset high-speed USB device number 11 using ehci-pci
> Sep  1 12:32:39 nemi kernel: [174103.472272] usb 1-6: device descriptor read/8, error -110
> Sep  1 12:32:39 nemi kernel: [174108.592328] usb 1-6: device descriptor read/8, error -110
> Sep  1 12:32:39 nemi kernel: [174108.808090] usb 4-2: reset full-speed USB device number 2 using uhci_hcd
> Sep  1 12:32:39 nemi kernel: [174109.052051] usb 7-1: reset full-speed USB device number 2 using uhci_hcd
> Sep  1 12:32:39 nemi kernel: [174109.204966] PM: resume of devices complete after 82555.697 msecs
> 
> As you can see from the last line, resuming devices takes ridiculously
> long time.  Normally it would take approximately on second on this old
> laptop.

This is a problem we have known about for many years, but nobody has
complained loudly enough for any changes to be made.  When initializing
or resetting a device, the USB core tries too hard and takes too long.  
It uses two different initialization algorithms, with various nested
retry loops and long timeouts.  If you want to look through the code
and try making your own changes, the guilty parties are hub_port_init()
and hub_port_connect_change() (which calls hub_port_init in a loop) in
drivers/usb/core/hub.c.

Normally this doesn't matter, because it happens more or less 
transparently in the background.  But during system resume it can be 
annoying, and during system suspend it can result in a freezer timeout 
and failure to suspend.

> The device connected to 1-6 is a Lenovo UVC webcam, and it seems the
> problem is related to this device somehow. As can be seen above, the
> webcam fails completely when this happens and just disappears - as
> expected when you cannot read the device descriptor.  But simply
> suspending and resuming again will always(?) fix the problem, so it is
> not a major issue. The real annoyance is the delay.
> 
> I did two changes which I guess could be important in the days before
> this problem started:
>  1) upgraded from v3.10-rc6 to v3.10-rc7
>  2) installed an Intel wlan card with a USB bluetooth device in one of
>     the internal mini-PCIe slots
> 
> I have never had any USB device in that mini-PCIe slot before, so the
> last change can potentionally reveal USB wiring problems which has
> always been there.  AFAIK the slot is not documented or officially
> supported as USB capable, although the bluetooth device seems to work
> fine.

It's possible that adding the new card could create enough interference 
to mess up the webcam during resume.

> This is how my bus layout normally looks when the webcam is working (the
> mini-PCIe bluetooth device is the one on bus 7):
> 
> bjorn@nemi:~$ lsusb -t
> /:  Bus 08.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
> /:  Bus 07.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
>     |__ Port 1: Dev 2, If 0, Class=Wireless, Driver=btusb, 12M
>     |__ Port 1: Dev 2, If 1, Class=Wireless, Driver=btusb, 12M
> /:  Bus 06.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
> /:  Bus 05.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
> /:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
>     |__ Port 2: Dev 2, If 0, Class=Wireless, Driver=btusb, 12M
>     |__ Port 2: Dev 2, If 1, Class=Wireless, Driver=btusb, 12M
>     |__ Port 2: Dev 2, If 2, Class=Vendor Specific Class, Driver=, 12M
>     |__ Port 2: Dev 2, If 3, Class=Application Specific Interface, Driver=, 12M
> /:  Bus 03.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/6p, 480M
>     |__ Port 4: Dev 46, If 12, Class=Communications, Driver=cdc_mbim, 480M
>     |__ Port 4: Dev 46, If 13, Class=CDC Data, Driver=cdc_mbim, 480M
> /:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
> /:  Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/6p, 480M
>     |__ Port 6: Dev 13, If 0, Class=Video, Driver=uvcvideo, 480M
>     |__ Port 6: Dev 13, If 1, Class=Video, Driver=uvcvideo, 480M
> 
> Is there any smart way to find out how the UHCI and EHCI ports are
> related to each other?

The kernel doesn't keep track of this directly.  You can determine it 
experimentally easily enough.  Plug both a high-speed device and a 
full/low-speed device into the same port in turn, and see where they 
end up in the device tree.

You can also get a pretty good idea by looking at the controllers' PCI
addresses.  An EHCI controller will occupy the same slot as its
companion UHCI/OHCI controllers, and the EHCI will have the largest
address.  For example, a 6-port EHCI controller at 0000:00:1a.7 might
have three 2-port companion UHCI controllers at 1a.0, 1a.1, and 1a.2.

>  Unloading ehci-pci results in this tree, which
> seems to imply that the two mini-PCIe slots are connected to one port
> each on the same UHCI bus, while the webcam seems unrelated on another
> controller:
> 
> bjorn@nemi:~$ lsusb -t
> /:  Bus 08.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
> /:  Bus 07.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
>     |__ Port 1: Dev 2, If 0, Class=Wireless, Driver=btusb, 12M
>     |__ Port 1: Dev 2, If 1, Class=Wireless, Driver=btusb, 12M
>     |__ Port 2: Dev 3, If 12, Class=Communications, Driver=cdc_mbim, 12M
>     |__ Port 2: Dev 3, If 13, Class=CDC Data, Driver=cdc_mbim, 12M
> /:  Bus 06.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
> /:  Bus 05.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
>     |__ Port 2: Dev 14, If 0, Class=Video, Driver=uvcvideo, 12M
>     |__ Port 2: Dev 14, If 1, Class=Video, Driver=uvcvideo, 12M
> /:  Bus 04.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
>     |__ Port 2: Dev 2, If 0, Class=Wireless, Driver=btusb, 12M
>     |__ Port 2: Dev 2, If 1, Class=Wireless, Driver=btusb, 12M
>     |__ Port 2: Dev 2, If 2, Class=Vendor Specific Class, Driver=, 12M
>     |__ Port 2: Dev 2, If 3, Class=Application Specific Interface, Driver=, 12M
> /:  Bus 02.Port 1: Dev 1, Class=root_hub, Driver=uhci_hcd/2p, 12M
> 
> 
> I really don't know where to go from here, and am posting this in the
> hope that anyone has some suggestion.  Or at least to document my
> problem in Google in case there are others with similar issues...
> 
> To give an impression of the frequency, here are the device resume times
> from the last two weeks:

...

> As you can see, there are typically 10+ successful resumes between every
> failure.  I am also noticing that the delays are not random.  They are
> either 31.5 seconds or 82.5 seconds.  I guess this is explained by some
> fixed timouts somewhere?

Yes, the timeouts and retry loops in the routines I mentioned above.

Alan Stern

--
To unsubscribe from this list: send the line "unsubscribe linux-usb" in
the body of a message to majordomo@xxxxxxxxxxxxxxx
More majordomo info at  http://vger.kernel.org/majordomo-info.html




[Index of Archives]     [Linux Media]     [Linux Input]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]     [Old Linux USB Devel Archive]

  Powered by Linux