Comment 90 for bug 1039143

There hasn't been much progress for a while, so I read up on ubuntu kernel building and bisecting (https://wiki.ubuntu.com/Kernel/KernelBisection), finding that I needed to bisect the upstream kernel to find the right commit, then ending up on a 'default configs' commit that the kteam-tools mainline-build-one script makes (...), so doing it again with a separate repo for buillding, and finally landing on this result:

Bisect log attached. The bug is introduced in the commit that adds the hid-logitech-dj driver:

-------------
534a7b8e10ec55d9f521e68c20dbb3634c25b98a is the first bad commit
commit 534a7b8e10ec55d9f521e68c20dbb3634c25b98a
Date: Thu Sep 15 11:34:49 2011 +0200

HID: Add full support for Logitech Unifying receivers
--------------

Which makes sense in hindsight looking at the kernel messages of the good vs bad report, because the good report shows that it's using a generic HID driver, and the bad report shows that it's using the hid-logitech-dj driver.

Then inspecting the logs of the 'bad' case in more detail shows something else interesting:

--------
[ 17.867585] xhci_hcd 0000:00:14.0: WARN: short transfer on control ep
[ 17.867856] xhci_hcd 0000:00:14.0: WARN: short transfer on control ep
[ 17.867980] xhci_hcd 0000:00:14.0: WARN: Stalled endpoint
[ 17.868105] xhci_hcd 0000:00:14.0: WARN: Stalled endpoint
[ 17.868235] logitech-djreceiver 0003:046D:C52B.0003: hiddev0,hidraw1: USB HID v1.11 Device [Logitech USB Receiver] on usb-0000:00:14.0-4/input2
[ 17.868502] xhci_hcd 0000:00:14.0: WARN: Stalled endpoint
[ 17.868511] logitech-djreceiver 0003:046D:C52B.0003: logi_dj_probe:logi_dj_recv_query_paired_devices error:-32
[ 17.868639] logitech-djreceiver: probe of 0003:046D:C52B.0003 failed with error -32
[ 18.893031] xhci_hcd 0000:00:14.0: WARN: short transfer on control ep
[ 18.893287] xhci_hcd 0000:00:14.0: WARN: short transfer on control ep
[ 18.893390] xhci_hcd 0000:00:14.0: WARN: Stalled endpoint
[ 18.893501] xhci_hcd 0000:00:14.0: WARN: Stalled endpoint
[ 18.893719] logitech-djreceiver 0003:046D:C52B.0003: hiddev0,hidraw1: USB HID v1.11 Device [Logitech USB Receiver] on usb-0000:00:14.0-4/input2
[ 18.893982] xhci_hcd 0000:00:14.0: WARN: Stalled endpoint
[ 18.894015] logitech-djreceiver 0003:046D:C52B.0003: logi_dj_probe:logi_dj_recv_query_paired_devices error:-32
[ 18.894291] logitech-djreceiver: probe of 0003:046D:C52B.0003 failed with error -32
[ 19.925347] xhci_hcd 0000:00:14.0: WARN: short transfer on control ep
[ 19.925611] xhci_hcd 0000:00:14.0: WARN: short transfer on control ep
[ 19.925725] xhci_hcd 0000:00:14.0: WARN: Stalled endpoint
[ 19.925832] xhci_hcd 0000:00:14.0: WARN: Stalled endpoint
[ 19.926080] logitech-djreceiver 0003:046D:C52B.0003: hiddev0,hidraw1: USB HID v1.11 Device [Logitech USB Receiver] on usb-0000:00:14.0-4/input2
[ 19.929079] input: Logitech Unifying Device. Wireless PID:4007 as /devices/pci0000:00/0000:00:14.0/usb3/3-4/3-4:1.2/0003:046D:C52B.0003/input/input18
[ 19.929186] logitech-djdevice 0003:046D:C52B.0005: input,hidraw2: USB HID v1.11 Keyboard [Logitech Unifying Device. Wireless PID:4007] on usb-0000:00:14.0-4:1
-------

Those xhci_hcd messages are from drivers/usb/host/xhci-ring.c. Note: In the 3.7 kernel, the 'short transfer' warning isn't there anymore and the 'Stalled endpoint' is a debug message instead of a warning.

Note that when the driver load fails, there is always a "Stalled endpoint" message after the first message from the logitech-djreceiver driver, and when it is successful, there is no such message.

Note the small time differences (<1ms) between many of these xhci messages. IIRC, USB2 has a roundtrip time of around 1ms, longer than these time differences. So, perhaps if USB3 has a shorter roundtrip time, then this bug could simply be one where the hardware is still initializing or something and the driver simply needs a millisecond or so more patience at some point during the device probe.

So I think next I'll try to add some delays in the probe to see if it makes the problem go away.