From: Bruno Prémont on
On Mon, 03 May 2010 Alan Stern <stern(a)rowland.harvard.edu> wrote:

> On Mon, 3 May 2010, Bruno [UTF-8] Prémont wrote:
>
> > On Mon, 03 May 2010 Alan Stern <stern(a)rowland.harvard.edu> wrote:
> > > You might also want to #define VERBOSE_DEBUG at the start of
> > > drivers/usb/core/driver.c, before the first #include.
> >
> > Still no difference... (will retry with own printk's in ohci's suspend
> > code as suggested in other mail)
>
> First of all, have you tried disabling async suspend? Look at
> /sys/power/pm_async.
>
> > Suspend output as it goes:
>
> Let's just look at the USB entries:
>
> > [ 241.358651] usb usb1: preparing type suspend, may wakeup
> > [ 241.364247] usb usb2: preparing type suspend, may wakeup
> > [ 241.369847] usb usb3: preparing type suspend, may wakeup
> > [ 241.375443] usb usb4: preparing type suspend, may wakeup
> > [ 241.381044] usb usb5: preparing type suspend, may wakeup
> > [ 241.386643] usb usb6: preparing type suspend, may wakeup
> > [ 241.392244] usb 1-2: preparing type suspend, may wakeup
> > [ 241.397762] usb 1-2.1: preparing type suspend, may wakeup
>
> Those are normal.
>
> > [ 241.407504] usbhid 1-2.1:1.1: suspend
> > [ 241.407511] usbhid 1-2.1:1.0: suspend
>
> These are HID suspends for the keyboard and mouse interfaces.
>
> > [ 241.407516] usb 1-2.1: type suspend, may wakeup
>
> This is a USB suspend for the KB/mouse device.
>
> > [ 241.443340] hub 1-2:1.0: suspend
>
> Suspend for the embedded hub interface. Next we should see
>
> [....] usb 1-2: type suspend, may wakeup
>
> for the embedded hub device, but we don't. That's the problem. It
> must be waiting for something -- goodness knows what.

Could have to do with the node that hid can't initialize?

> > [ 241.911502] hub 6-0:1.0: suspend
> > [ 241.914928] usb usb6: type suspend, may wakeup
> > [ 241.919583] usb usb6: usb_suspend_both: status 0
> > [ 241.924448] usb usb6: suspend, may wakeup
> > [ 241.928663] hub 5-0:1.0: suspend
> > [ 241.932082] usb usb5: type suspend, may wakeup
> > [ 241.936794] usb usb5: usb_suspend_both: status 0
> > [ 241.941669] usb usb5: suspend, may wakeup
> > [ 241.945888] hub 4-0:1.0: suspend
> > [ 241.949294] usb usb4: type suspend, may wakeup
> > [ 241.953966] usb usb4: usb_suspend_both: status 0
> > [ 241.958814] usb usb4: suspend, may wakeup
> > [ 241.963069] hub 3-0:1.0: suspend
> > [ 241.966452] usb usb3: type suspend, may wakeup
> > [ 241.971126] usb usb3: usb_suspend_both: status 0
> > [ 241.976015] usb usb3: suspend, may wakeup
> > [ 241.980232] hub 2-0:1.0: suspend
> > [ 241.983662] usb usb2: type suspend, may wakeup
> > [ 241.988316] usb usb2: usb_suspend_both: status 0
> > [ 241.993192] usb usb2: suspend, may wakeup
> > [ 241.997418] hub 1-0:1.0: suspend
>
> And here we should see
>
> [....] usb usb1: type suspend, may wakeup
> etc.
>
> but we don't, because it's waiting for the 1-2 device.
>
> > [ 242.125768] ehci_hcd 0000:00:13.5: suspend
> > [ 242.130076] ehci_hcd 0000:00:13.5: PCI INT D disabled
> > [ 242.135410] ohci_hcd 0000:00:13.4: suspend
> > [ 242.139696] ohci_hcd 0000:00:13.4: PCI INT C disabled
> > [ 242.145035] ohci_hcd 0000:00:13.3: suspend
> > [ 242.149348] ohci_hcd 0000:00:13.3: PCI INT B disabled
> > [ 242.154705] ohci_hcd 0000:00:13.2: suspend
> > [ 242.159012] ohci_hcd 0000:00:13.2: PCI INT C disabled
> > [ 242.164342] ohci_hcd 0000:00:13.1: suspend
> > [ 242.168676] ohci_hcd 0000:00:13.1: PCI INT B disabled
>
> > I guess here PM is waiting for ohci_hcd 0000:00:13.0 to suspend
> > and disable its interrupt.
> > (and that last ohci device would match the usbhid_resume thread that's
> > frozen...)
>
> The 0000:00:13.0 device can't suspend until usb1 does, and usb1 can't
> suspend until 1-2 does.
>
> Can you boot the dmesg log for bootup and device detection? It may
> indicate what we're missing. Also include the contents of
> /sys/kernel/debug/usb/devices.


T: Bus=06 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#= 1 Spd=12 MxCh= 2
B: Alloc= 0/900 us ( 0%), #Int= 0, #Iso= 0
D: Ver= 1.10 Cls=09(hub ) Sub=00 Prot=00 MxPS=64 #Cfgs= 1
P: Vendor=1d6b ProdID=0001 Rev= 2.06
S: Manufacturer=Linux 2.6.34-rc6 ohci_hcd
S: Product=OHCI Host Controller
S: SerialNumber=0000:00:13.4
C:* #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr= 0mA
I:* If#= 0 Alt= 0 #EPs= 1 Cls=09(hub ) Sub=00 Prot=00 Driver=hub
E: Ad=81(I) Atr=03(Int.) MxPS= 2 Ivl=255ms

T: Bus=05 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#= 1 Spd=12 MxCh= 2
B: Alloc= 0/900 us ( 0%), #Int= 0, #Iso= 0
D: Ver= 1.10 Cls=09(hub ) Sub=00 Prot=00 MxPS=64 #Cfgs= 1
P: Vendor=1d6b ProdID=0001 Rev= 2.06
S: Manufacturer=Linux 2.6.34-rc6 ohci_hcd
S: Product=OHCI Host Controller
S: SerialNumber=0000:00:13.3
C:* #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr= 0mA
I:* If#= 0 Alt= 0 #EPs= 1 Cls=09(hub ) Sub=00 Prot=00 Driver=hub
E: Ad=81(I) Atr=03(Int.) MxPS= 2 Ivl=255ms

T: Bus=04 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#= 1 Spd=12 MxCh= 2
B: Alloc= 0/900 us ( 0%), #Int= 0, #Iso= 0
D: Ver= 1.10 Cls=09(hub ) Sub=00 Prot=00 MxPS=64 #Cfgs= 1
P: Vendor=1d6b ProdID=0001 Rev= 2.06
S: Manufacturer=Linux 2.6.34-rc6 ohci_hcd
S: Product=OHCI Host Controller
S: SerialNumber=0000:00:13.2
C:* #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr= 0mA
I:* If#= 0 Alt= 0 #EPs= 1 Cls=09(hub ) Sub=00 Prot=00 Driver=hub
E: Ad=81(I) Atr=03(Int.) MxPS= 2 Ivl=255ms

T: Bus=03 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#= 1 Spd=12 MxCh= 2
B: Alloc= 0/900 us ( 0%), #Int= 0, #Iso= 0
D: Ver= 1.10 Cls=09(hub ) Sub=00 Prot=00 MxPS=64 #Cfgs= 1
P: Vendor=1d6b ProdID=0001 Rev= 2.06
S: Manufacturer=Linux 2.6.34-rc6 ohci_hcd
S: Product=OHCI Host Controller
S: SerialNumber=0000:00:13.1
C:* #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr= 0mA
I:* If#= 0 Alt= 0 #EPs= 1 Cls=09(hub ) Sub=00 Prot=00 Driver=hub
E: Ad=81(I) Atr=03(Int.) MxPS= 2 Ivl=255ms

T: Bus=02 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#= 1 Spd=12 MxCh= 2
B: Alloc= 2/900 us ( 0%), #Int= 2, #Iso= 0
D: Ver= 1.10 Cls=09(hub ) Sub=00 Prot=00 MxPS=64 #Cfgs= 1
P: Vendor=1d6b ProdID=0001 Rev= 2.06
S: Manufacturer=Linux 2.6.34-rc6 ohci_hcd
S: Product=OHCI Host Controller
S: SerialNumber=0000:00:13.0
C:* #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr= 0mA
I:* If#= 0 Alt= 0 #EPs= 1 Cls=09(hub ) Sub=00 Prot=00 Driver=hub
E: Ad=81(I) Atr=03(Int.) MxPS= 2 Ivl=255ms

T: Bus=02 Lev=01 Prnt=01 Port=01 Cnt=01 Dev#= 2 Spd=12 MxCh= 3
D: Ver= 1.10 Cls=09(hub ) Sub=00 Prot=00 MxPS= 8 #Cfgs= 1
P: Vendor=058f ProdID=9462 Rev= 1.58
S: Manufacturer=Multimedia USB Keyboard
S: Product=Multimedia USB Keyboard
C:* #Ifs= 1 Cfg#= 1 Atr=a0 MxPwr= 50mA
I:* If#= 0 Alt= 0 #EPs= 1 Cls=09(hub ) Sub=00 Prot=00 Driver=hub
E: Ad=81(I) Atr=03(Int.) MxPS= 1 Ivl=255ms

T: Bus=02 Lev=02 Prnt=02 Port=00 Cnt=01 Dev#= 3 Spd=12 MxCh= 0
D: Ver= 1.10 Cls=00(>ifc ) Sub=00 Prot=00 MxPS= 8 #Cfgs= 1
P: Vendor=058f ProdID=9462 Rev= 4.10
S: Manufacturer=Multimedia USB Keyboard
S: Product=Multimedia USB Keyboard
S: SerialNumber=Multimedia USB Keyboard
C:* #Ifs= 2 Cfg#= 1 Atr=a0 MxPwr= 50mA
I:* If#= 0 Alt= 0 #EPs= 1 Cls=03(HID ) Sub=01 Prot=01 Driver=usbhid
E: Ad=81(I) Atr=03(Int.) MxPS= 8 Ivl=10ms
I:* If#= 1 Alt= 0 #EPs= 1 Cls=03(HID ) Sub=00 Prot=00 Driver=usbhid
E: Ad=82(I) Atr=03(Int.) MxPS= 4 Ivl=255ms

T: Bus=01 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#= 1 Spd=480 MxCh=10
B: Alloc= 0/800 us ( 0%), #Int= 0, #Iso= 0
D: Ver= 2.00 Cls=09(hub ) Sub=00 Prot=00 MxPS=64 #Cfgs= 1
P: Vendor=1d6b ProdID=0002 Rev= 2.06
S: Manufacturer=Linux 2.6.34-rc6 ehci_hcd
S: Product=EHCI Host Controller
S: SerialNumber=0000:00:13.5
C:* #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr= 0mA
I:* If#= 0 Alt= 0 #EPs= 1 Cls=09(hub ) Sub=00 Prot=00 Driver=hub
E: Ad=81(I) Atr=03(Int.) MxPS= 4 Ivl=256ms



Loading ubs support, ehci, then ohci:
[ 500.990545] usbcore: registered new interface driver usbfs
[ 500.996467] usbcore: registered new interface driver hub
[ 501.002309] usbcore: registered new device driver usb
[ 501.013910] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 501.021013] ehci_hcd 0000:00:13.5: PCI INT D -> GSI 19 (level, low) -> IRQ 19
[ 501.028714] ehci_hcd 0000:00:13.5: EHCI Host Controller
[ 501.034360] ehci_hcd 0000:00:13.5: new USB bus registered, assigned bus number 1
[ 501.042385] ehci_hcd 0000:00:13.5: applying AMD SB600/SB700 USB freeze workaround
[ 501.050441] ehci_hcd 0000:00:13.5: debug port 1
[ 501.055359] ehci_hcd 0000:00:13.5: irq 19, io mem 0xfdbff000
[ 501.072526] ehci_hcd 0000:00:13.5: USB 2.0 started, EHCI 1.00
[ 501.078619] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[ 501.085805] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 501.093407] usb usb1: Product: EHCI Host Controller
[ 501.093411] usb usb1: Manufacturer: Linux 2.6.34-rc6 ehci_hcd
[ 501.093413] usb usb1: SerialNumber: 0000:00:13.5
[ 501.093550] hub 1-0:1.0: USB hub found
[ 501.093554] hub 1-0:1.0: 10 ports detected
[ 505.900903] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[ 505.907619] ohci_hcd 0000:00:13.0: PCI INT A -> GSI 16 (level, low) -> IRQ 16
[ 505.915332] ohci_hcd 0000:00:13.0: OHCI Host Controller
[ 505.920972] ohci_hcd 0000:00:13.0: new USB bus registered, assigned bus number 2
[ 505.928986] ohci_hcd 0000:00:13.0: irq 16, io mem 0xfdbfe000
[ 505.994238] usb usb2: New USB device found, idVendor=1d6b, idProduct=0001
[ 506.001566] usb usb2: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 506.009324] usb usb2: Product: OHCI Host Controller
[ 506.014570] usb usb2: Manufacturer: Linux 2.6.34-rc6 ohci_hcd
[ 506.020765] usb usb2: SerialNumber: 0000:00:13.0
[ 506.026022] hub 2-0:1.0: USB hub found
[ 506.030071] hub 2-0:1.0: 2 ports detected
[ 506.034578] ohci_hcd 0000:00:13.1: PCI INT B -> GSI 17 (level, low) -> IRQ 17
[ 506.042275] ohci_hcd 0000:00:13.1: OHCI Host Controller
[ 506.047902] ohci_hcd 0000:00:13.1: new USB bus registered, assigned bus number 3
[ 506.055896] ohci_hcd 0000:00:13.1: irq 17, io mem 0xfdbfd000
[ 506.134192] usb usb3: New USB device found, idVendor=1d6b, idProduct=0001
[ 506.141497] usb usb3: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 506.149235] usb usb3: Product: OHCI Host Controller
[ 506.154478] usb usb3: Manufacturer: Linux 2.6.34-rc6 ohci_hcd
[ 506.160678] usb usb3: SerialNumber: 0000:00:13.1
[ 506.165828] hub 3-0:1.0: USB hub found
[ 506.169878] hub 3-0:1.0: 2 ports detected
[ 506.174395] ohci_hcd 0000:00:13.2: PCI INT C -> GSI 18 (level, low) -> IRQ 18
[ 506.182086] ohci_hcd 0000:00:13.2: OHCI Host Controller
[ 506.187720] ohci_hcd 0000:00:13.2: new USB bus registered, assigned bus number 4
[ 506.195708] ohci_hcd 0000:00:13.2: irq 18, io mem 0xfdbfc000
[ 506.254208] usb usb4: New USB device found, idVendor=1d6b, idProduct=0001
[ 506.261519] usb usb4: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 506.269280] usb usb4: Product: OHCI Host Controller
[ 506.274528] usb usb4: Manufacturer: Linux 2.6.34-rc6 ohci_hcd
[ 506.280724] usb usb4: SerialNumber: 0000:00:13.2
[ 506.285923] hub 4-0:1.0: USB hub found
[ 506.289957] hub 4-0:1.0: 2 ports detected
[ 506.294479] ohci_hcd 0000:00:13.3: PCI INT B -> GSI 17 (level, low) -> IRQ 17
[ 506.302171] ohci_hcd 0000:00:13.3: OHCI Host Controller
[ 506.307804] ohci_hcd 0000:00:13.3: new USB bus registered, assigned bus number 5
[ 506.315770] ohci_hcd 0000:00:13.3: irq 17, io mem 0xfdbfb000
[ 506.384187] usb usb5: New USB device found, idVendor=1d6b, idProduct=0001
[ 506.391508] usb usb5: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 506.399278] usb usb5: Product: OHCI Host Controller
[ 506.404518] usb usb5: Manufacturer: Linux 2.6.34-rc6 ohci_hcd
[ 506.410704] usb usb5: SerialNumber: 0000:00:13.3
[ 506.415903] hub 5-0:1.0: USB hub found
[ 506.419919] hub 5-0:1.0: 2 ports detected
[ 506.424444] ohci_hcd 0000:00:13.4: PCI INT C -> GSI 18 (level, low) -> IRQ 18
[ 506.432135] ohci_hcd 0000:00:13.4: OHCI Host Controller
[ 506.437771] ohci_hcd 0000:00:13.4: new USB bus registered, assigned bus number 6
[ 506.445745] ohci_hcd 0000:00:13.4: irq 18, io mem 0xfdbfa000
[ 506.462564] usb 2-2: new full speed USB device using ohci_hcd and address 2
[ 506.514186] usb usb6: New USB device found, idVendor=1d6b, idProduct=0001
[ 506.521527] usb usb6: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[ 506.529289] usb usb6: Product: OHCI Host Controller
[ 506.534519] usb usb6: Manufacturer: Linux 2.6.34-rc6 ohci_hcd
[ 506.540740] usb usb6: SerialNumber: 0000:00:13.4
[ 506.545966] hub 6-0:1.0: USB hub found
[ 506.550025] hub 6-0:1.0: 2 ports detected
[ 506.679090] usb 2-2: New USB device found, idVendor=058f, idProduct=9462
[ 506.686284] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[ 506.693954] usb 2-2: Product: Multimedia USB Keyboard
[ 506.699410] usb 2-2: Manufacturer: Multimedia USB Keyboard
[ 506.700520] hub 2-2:1.0: USB hub found
[ 506.704102] hub 2-2:1.0: 3 ports detected
[ 506.991083] usb 2-2.1: new full speed USB device using ohci_hcd and address 3
[ 507.159086] usb 2-2.1: New USB device found, idVendor=058f, idProduct=9462
[ 507.166464] usb 2-2.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 507.174345] usb 2-2.1: Product: Multimedia USB Keyboard
[ 507.179965] usb 2-2.1: Manufacturer: Multimedia USB Keyboard
[ 507.186051] usb 2-2.1: SerialNumber: Multimedia USB Keyboard
[ 507.230896] input: Multimedia USB Keyboard Multimedia USB Keyboard as /devices/pci0000:00/0000:00:13.0/u4
[ 507.244547] generic-usb 0003:058F:9462.0001: input: USB HID v1.10 Keyboard [Multimedia USB Keyboard Mult0
[ 507.288737] generic-usb: probe of 0003:058F:9462.0002 failed with error -22
^^^^^ this one was causing resume trouble in .33-rc
but has been fix since then.
c.f. thread http://lkml.org/lkml/2010/2/8/179
[ 507.296280] usbcore: registered new interface driver usbhid
[ 507.302242] usbhid: USB HID core driver


New suspend attempt, with a few printks added and async disabled:
....
[ 1280.630812] usb usb1: preparing type suspend, may wakeup
[ 1280.636435] usb usb2: preparing type suspend, may wakeup
[ 1280.642016] usb usb3: preparing type suspend, may wakeup
[ 1280.647631] usb usb4: preparing type suspend, may wakeup
[ 1280.653229] usb usb5: preparing type suspend, may wakeup
[ 1280.658813] usb usb6: preparing type suspend, may wakeup
[ 1280.664408] usb 2-2: preparing type suspend, may wakeup
[ 1280.669886] usb 2-2.1: preparing type suspend, may wakeup
[ 1280.675577] input input4: type suspend
[ 1280.679538] usbhid 2-2.1:1.1: suspend
[ 1280.683415] usbhid 2-2.1:1.0: suspend
[ 1280.687266] usb 2-2.1: type suspend, may wakeup
[ 1280.692044] hid 0003:058F:9462.0002: Suspending HID device...

So yeah, for some reason hid fails to suspend this device.

It's blocking somewhere in hid_suspend() of usbhid/hid-core.c
between function start and including call to hid_cease_io().

Going to add more printks in there in the hope to get more precise
location, also adding debug param to hid.ko ...

Bruno
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo(a)vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
From: Bruno Prémont on
On Mon, 03 May 2010 Bruno Prémont <bonbons(a)linux-vserver.org> wrote:
> New suspend attempt, with a few printks added and async disabled:
> ...
> [ 1280.630812] usb usb1: preparing type suspend, may wakeup
> [ 1280.636435] usb usb2: preparing type suspend, may wakeup
> [ 1280.642016] usb usb3: preparing type suspend, may wakeup
> [ 1280.647631] usb usb4: preparing type suspend, may wakeup
> [ 1280.653229] usb usb5: preparing type suspend, may wakeup
> [ 1280.658813] usb usb6: preparing type suspend, may wakeup
> [ 1280.664408] usb 2-2: preparing type suspend, may wakeup
> [ 1280.669886] usb 2-2.1: preparing type suspend, may wakeup
> [ 1280.675577] input input4: type suspend
> [ 1280.679538] usbhid 2-2.1:1.1: suspend
> [ 1280.683415] usbhid 2-2.1:1.0: suspend
> [ 1280.687266] usb 2-2.1: type suspend, may wakeup
> [ 1280.692044] hid 0003:058F:9462.0002: Suspending HID device...
>
> So yeah, for some reason hid fails to suspend this device.
>
> It's blocking somewhere in hid_suspend() of usbhid/hid-core.c
> between function start and including call to hid_cease_io().
>
> Going to add more printks in there in the hope to get more precise
> location, also adding debug param to hid.ko ...

Loading usbhid on top of hid with debug=1:

[ 473.786604] HID: hid_debug is now used solely for parser and driver debugging.
[ 473.786610] HID: debugfs is now used for inspecting the device (report descriptor, reports)
[ 477.455492] usbhid 1-2.1:1.0: usb_probe_interface
[ 477.455502] usbhid 1-2.1:1.0: usb_probe_interface - got id
[ 477.455510] usb 1-2.1: __pm_runtime_resume()!
[ 477.455516] usb 1-2.1: __pm_runtime_resume() returns 1!
[ 477.455522] usb 1-2.1: usb_autoresume_device: cnt 2 -> 1
[ 477.455531] /usr/src/linux-2.6-git/drivers/hid/usbhid/hid-core.c: HID probe called for ifnum 0
[ 477.463038] PM: Adding info for hid:0003:058F:9462.0001
[ 477.477614] /usr/src/linux-2.6-git/drivers/hid/usbhid/hid-core.c: submitting ctrl urb: Set_Report wValue=0x0200 wIndex=0x0000 wLength=1
[ 477.477829] PM: Adding info for No Bus:input4
[ 477.477917] input: Multimedia USB Keyboard Multimedia USB Keyboard as /devices/pci0000:00/0000:00:13.0/usb1/1-2/1-2.1/1-2.1:1.0/input/input4
[ 477.491554] usbhid 1-2.1:1.0: __pm_runtime_resume()!
[ 477.491560] usbhid 1-2.1:1.0: __pm_runtime_resume() returns 1!
[ 477.491566] usbhid 1-2.1:1.0: usb_autopm_get_interface: cnt 2 -> 1
[ 477.491579] usbhid 1-2.1:1.0: usb_autopm_put_interface: cnt 1 -> 0
[ 477.491645] PM: Adding info for No Bus:event3
[ 477.491681] generic-usb 0003:058F:9462.0001: input: USB HID v1.10 Keyboard [Multimedia USB Keyboard Multimedia USB Keyboard] on usb-0000:00:13.0-2.1/input0
[ 477.506754] usb 1-2.1: usb_autosuspend_device: cnt 1 -> 0
[ 477.506763] usbhid 1-2.1:1.0: __pm_runtime_suspend()!
[ 477.506771] usbhid 1-2.1:1.0: __pm_runtime_suspend() returns 0!
[ 477.506815] usbhid 1-2.1:1.1: usb_probe_interface
[ 477.506822] usbhid 1-2.1:1.1: usb_probe_interface - got id
[ 477.506827] usb 1-2.1: __pm_runtime_resume()!
[ 477.506831] usb 1-2.1: __pm_runtime_resume() returns 1!
[ 477.506836] usb 1-2.1: usb_autoresume_device: cnt 2 -> 1
[ 477.506843] /usr/src/linux-2.6-git/drivers/hid/usbhid/hid-core.c: HID probe called for ifnum 1
[ 477.515027] PM: Adding info for hid:0003:058F:9462.0002
[ 477.535614] /usr/src/linux-2.6-git/drivers/hid/hid-core.c: usage index exceeded
[ 477.535621] /usr/src/linux-2.6-git/drivers/hid/hid-core.c: hid_add_usage failed
[ 477.535627] /usr/src/linux-2.6-git/drivers/hid/hid-core.c: item 0 2 2 2 parsing failed
[ 477.535643] /usr/src/linux-2.6-git/drivers/hid/usbhid/hid-core.c: parsing report descriptor failed
[ 477.535656] generic-usb: probe of 0003:058F:9462.0002 failed with error -22
[ 477.543304] usb 1-2.1: usb_autosuspend_device: cnt 1 -> 0
[ 477.543316] usbhid 1-2.1:1.1: __pm_runtime_suspend()!
[ 477.543326] usbhid 1-2.1:1.1: __pm_runtime_suspend() returns 0!
[ 477.543380] usbcore: registered new interface driver usbhid
[ 477.549457] usbhid: USB HID core driver

And suspend is freezing inside of hid_cancel_delayed_stuff(usbhid) call
from hid_suspend() in drivers/hid/usbhid/hid-core.c ...

Is it worth continuing iteration and adding further printk's down there?
Jiri, what's your opinion on this?

Thanks,
Bruno
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo(a)vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
From: Oliver Neukum on
Am Montag, 3. Mai 2010 23:11:54 schrieb Bruno Prémont:
> [ 477.543304] usb 1-2.1: usb_autosuspend_device: cnt 1 -> 0
> [ 477.543316] usbhid 1-2.1:1.1: __pm_runtime_suspend()!
> [ 477.543326] usbhid 1-2.1:1.1: __pm_runtime_suspend() returns 0!
> [ 477.543380] usbcore: registered new interface driver usbhid
> [ 477.549457] usbhid: USB HID core driver
>
> And suspend is freezing inside of hid_cancel_delayed_stuff(usbhid) call
> from hid_suspend() in drivers/hid/usbhid/hid-core.c ...
>
> Is it worth continuing iteration and adding further printk's down there?
> Jiri, what's your opinion on this?

Ugh. That looks like a bug in usbhid that I introduced. A fix is not trivial.
In short, I did not think the device could be undergoing a queued resumption
while suspend() is being called. I wonder why this is happening.

Regards
Oliver
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo(a)vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
From: Jiri Kosina on
On Tue, 4 May 2010, Oliver Neukum wrote:

> > [ 477.543304] usb 1-2.1: usb_autosuspend_device: cnt 1 -> 0
> > [ 477.543316] usbhid 1-2.1:1.1: __pm_runtime_suspend()!
> > [ 477.543326] usbhid 1-2.1:1.1: __pm_runtime_suspend() returns 0!
> > [ 477.543380] usbcore: registered new interface driver usbhid
> > [ 477.549457] usbhid: USB HID core driver
> >
> > And suspend is freezing inside of hid_cancel_delayed_stuff(usbhid) call
> > from hid_suspend() in drivers/hid/usbhid/hid-core.c ...
> >
> > Is it worth continuing iteration and adding further printk's down there?
> > Jiri, what's your opinion on this?
>
> Ugh. That looks like a bug in usbhid that I introduced. A fix is not trivial.
> In short, I did not think the device could be undergoing a queued resumption
> while suspend() is being called. I wonder why this is happening.

Hmmm ... seems to me that in this case, the problem might be that there is
a device hanging in the air, for which the parsing of report descriptor
failed (interface .0002), but it's still somehow there on the bus.

It's a bit strange that we are not seeing

dev_err(&intf->dev, "can't add hid device: %d\n", ret);

message from usbhid_probe(), are we? That would mean, that we are
returning ENODEV from the usb_driver->probe routine properly.

Bruno, could you, for testing purposes, check, whether the patch below
changes the behavior you are seeing (and also check what the actual return
value from device_add() was, see the added printk()).
Thanks.



drivers/hid/hid-core.c | 5 +++--
drivers/hid/usbhid/hid-core.c | 4 ++--
2 files changed, 5 insertions(+), 4 deletions(-)

diff --git a/drivers/hid/hid-core.c b/drivers/hid/hid-core.c
index 2e2aa75..7186f9f 100644
--- a/drivers/hid/hid-core.c
+++ b/drivers/hid/hid-core.c
@@ -1770,10 +1770,11 @@ int hid_add_device(struct hid_device *hdev)
hdev->vendor, hdev->product, atomic_inc_return(&id));

ret = device_add(&hdev->dev);
+ printk(KERN_DEBUG "HID: device_add() returned %d\n", ret);
if (!ret)
hdev->status |= HID_STAT_ADDED;
-
- hid_debug_register(hdev, dev_name(&hdev->dev));
+ else
+ hid_debug_register(hdev, dev_name(&hdev->dev));

return ret;
}
diff --git a/drivers/hid/usbhid/hid-core.c b/drivers/hid/usbhid/hid-core.c
index 56d06cd..f33445a 100644
--- a/drivers/hid/usbhid/hid-core.c
+++ b/drivers/hid/usbhid/hid-core.c
@@ -1181,8 +1181,8 @@ static int usbhid_probe(struct usb_interface *intf, const struct usb_device_id *

ret = hid_add_device(hid);
if (ret) {
- if (ret != -ENODEV)
- dev_err(&intf->dev, "can't add hid device: %d\n", ret);
+ dev_err(&intf->dev, "can't add hid device: %d\n", ret);
+ ret = -ENODEV;
goto err_free;
}


--
Jiri Kosina
SUSE Labs, Novell Inc.
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo(a)vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
From: Bruno Prémont on
On Tue, 04 May 2010 Jiri Kosina <jkosina(a)suse.cz> wrote:

> On Tue, 4 May 2010, Oliver Neukum wrote:
>
> > > [ 477.543304] usb 1-2.1: usb_autosuspend_device: cnt 1 -> 0
> > > [ 477.543316] usbhid 1-2.1:1.1: __pm_runtime_suspend()!
> > > [ 477.543326] usbhid 1-2.1:1.1: __pm_runtime_suspend() returns 0!
> > > [ 477.543380] usbcore: registered new interface driver usbhid
> > > [ 477.549457] usbhid: USB HID core driver
> > >
> > > And suspend is freezing inside of hid_cancel_delayed_stuff(usbhid) call
> > > from hid_suspend() in drivers/hid/usbhid/hid-core.c ...
> > >
> > > Is it worth continuing iteration and adding further printk's down there?
> > > Jiri, what's your opinion on this?
> >
> > Ugh. That looks like a bug in usbhid that I introduced. A fix is not trivial.
> > In short, I did not think the device could be undergoing a queued resumption
> > while suspend() is being called. I wonder why this is happening.
>
> Hmmm ... seems to me that in this case, the problem might be that there is
> a device hanging in the air, for which the parsing of report descriptor
> failed (interface .0002), but it's still somehow there on the bus.
>
> It's a bit strange that we are not seeing
>
> dev_err(&intf->dev, "can't add hid device: %d\n", ret);
>
> message from usbhid_probe(), are we? That would mean, that we are
> returning ENODEV from the usb_driver->probe routine properly.
>
> Bruno, could you, for testing purposes, check, whether the patch below
> changes the behavior you are seeing (and also check what the actual return
> value from device_add() was, see the added printk()).

Well, it's said to return 0:

[ 286.872739] generic-usb 0003:058F:9462.0003: input: USB HID v1.10 Keyboard [Multimedia USB Keyboard Multimedia USB Keyboard] on usb-0000:00:13.0-2.1/input0
[ 286.890136] HID: device_add() returned 0

[ 286.919698] generic-usb: probe of 0003:058F:9462.0004 failed with error -22
[ 286.929363] HID: device_add() returned 0

or with debug=1 for HID:
[ 559.982958] /usr/src/linux-2.6-git/drivers/hid/usbhid/hid-core.c: HID probe called for ifnum 1
[ 560.011698] /usr/src/linux-2.6-git/drivers/hid/hid-core.c: usage index exceeded
[ 560.011704] /usr/src/linux-2.6-git/drivers/hid/hid-core.c: hid_add_usage failed
[ 560.011710] /usr/src/linux-2.6-git/drivers/hid/hid-core.c: item 0 2 2 2 parsing failed
[ 560.011732] /usr/src/linux-2.6-git/drivers/hid/usbhid/hid-core.c: parsing report descriptor failed
[ 560.011747] generic-usb: probe of 0003:058F:9462.0006 failed with error -22
[ 560.021718] HID: device_add() returned 0

Complete log of connecting keyboard is below (including hid debug, usb
debug and pm debug messages).

The patch does not change suspend behavior (as could be expected for a
return value of 0)

Thanks,
Bruno



[ 558.585559] usb usb2: usb wakeup-resume
[ 558.585569] usb usb2: __pm_runtime_resume()!
[ 558.585578] usb usb2: usb auto-resume
[ 558.585584] ehci_hcd 0000:00:13.5: resume root hub
[ 558.730038] ehci_hcd 0000:00:13.5: port 2 full speed --> companion
[ 558.730049] ehci_hcd 0000:00:13.5: GetStatus port 2 status 003801 POWER OWNER sig=j CONNECT
[ 558.750021] usb usb2: usb_resume_device: status 0
[ 558.750028] hub 2-0:1.0: hub_resume
[ 558.750086] hub 2-0:1.0: usb_resume_interface: status 0
[ 558.750091] usb usb2: usb_resume_both: status 0
[ 558.750103] hub 2-0:1.0: state 7 ports 10 chg 0000 evt 0000
[ 558.750112] usb usb2: __pm_runtime_resume() returns 0!
[ 558.750121] usb usb2: usb_autoresume_device: cnt 1 -> 0
[ 558.750131] usb usb2: usb_autosuspend_device: cnt 0 -> 0
[ 558.750141] usb usb1: usb wakeup-resume
[ 558.750146] usb usb1: __pm_runtime_resume()!
[ 558.750153] hub 2-0:1.0: __pm_runtime_resume()!
[ 558.750162] usb usb2: __pm_runtime_resume()!
[ 558.750169] usb usb2: __pm_runtime_resume() returns 1!
[ 558.750179] usb usb1: usb auto-resume
[ 558.750185] hub 2-0:1.0: __pm_runtime_resume() returns 0!
[ 558.750194] hub 2-0:1.0: usb_autopm_get_interface: cnt 2 -> 0
[ 558.750205] hub 2-0:1.0: __pm_runtime_suspend()!
[ 558.750213] hub 2-0:1.0: __pm_runtime_suspend() returns 0!
[ 558.750219] hub 2-0:1.0: usb_autopm_put_interface: cnt 0 -> 0
[ 558.770024] ohci_hcd 0000:00:13.0: wakeup root hub
[ 558.880021] usb usb1: usb_resume_device: status 0
[ 558.880026] hub 1-0:1.0: hub_resume
[ 558.880043] ohci_hcd 0000:00:13.0: GetStatus roothub.portstatus [1] = 0x00010101 CSC PPS CCS
[ 558.880052] hub 1-0:1.0: port 2: status 0101 change 0001
[ 558.990077] hub 1-0:1.0: usb_resume_interface: status 0
[ 558.990091] hub 1-0:1.0: state 7 ports 2 chg 0004 evt 0000
[ 558.990104] usb usb1: usb_resume_both: status 0
[ 558.990111] usb usb1: __pm_runtime_resume() returns 0!
[ 558.990118] usb usb1: usb_autoresume_device: cnt 1 -> 0
[ 558.990126] usb usb1: usb_autosuspend_device: cnt 0 -> 0
[ 558.990144] hub 1-0:1.0: __pm_runtime_resume()!
[ 558.990151] usb usb1: __pm_runtime_resume()!
[ 558.990156] usb usb1: __pm_runtime_resume() returns 1!
[ 558.990163] hub 1-0:1.0: __pm_runtime_resume() returns 0!
[ 558.990168] hub 1-0:1.0: usb_autopm_get_interface: cnt 2 -> 0
[ 558.990191] hub 1-0:1.0: port 2, status 0101, change 0000, 12 Mb/s
[ 559.100039] ohci_hcd 0000:00:13.0: GetStatus roothub.portstatus [1] = 0x00100103 PRSC PPS PES CCS
[ 559.160035] usb 1-2: new full speed USB device using ohci_hcd and address 6
[ 559.200055] ohci_hcd 0000:00:13.0: port[1] reset timeout, stat 00000113
[ 559.250037] ohci_hcd 0000:00:13.0: GetStatus roothub.portstatus [1] = 0x00100103 PRSC PPS PES CCS
[ 559.340023] usb 1-2: ep0 maxpacket = 8
[ 559.344060] usb 1-2: __pm_runtime_resume()!
[ 559.344065] usb 1-2: __pm_runtime_resume() returns 1!
[ 559.344071] usb 1-2: usb_autoresume_device: cnt 1 -> 1
[ 559.358061] usb 1-2: default language 0x0409
[ 559.376061] usb 1-2: udev 6, busnum 1, minor = 5
[ 559.376067] usb 1-2: New USB device found, idVendor=058f, idProduct=9462
[ 559.385547] usb 1-2: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[ 559.395601] usb 1-2: Product: Multimedia USB Keyboard
[ 559.403397] usb 1-2: Manufacturer: Multimedia USB Keyboard
[ 559.411794] PM: Adding info for usb:1-2
[ 559.411868] usb 1-2: usb_probe_device
[ 559.411877] usb 1-2: configuration #1 chosen from 1 choice
[ 559.411883] usb 1-2: __pm_runtime_resume()!
[ 559.411887] usb 1-2: __pm_runtime_resume() returns 1!
[ 559.411892] usb 1-2: usb_autoresume_device: cnt 4 -> 1
[ 559.412812] usb 1-2: adding 1-2:1.0 (config #1, interface 0)
[ 559.412886] PM: Adding info for usb:1-2:1.0
[ 559.412951] hub 1-2:1.0: usb_probe_interface
[ 559.412958] hub 1-2:1.0: usb_probe_interface - got id
[ 559.412964] usb 1-2: __pm_runtime_resume()!
[ 559.412969] usb 1-2: __pm_runtime_resume() returns 1!
[ 559.412974] usb 1-2: usb_autoresume_device: cnt 5 -> 1
[ 559.412983] usb 1-2: usb_autosuspend_device: cnt 4 -> 0
[ 559.412988] hub 1-2:1.0: USB hub found
[ 559.423076] hub 1-2:1.0: 3 ports detected
[ 559.429733] hub 1-2:1.0: compound device; port removable status: FRR
[ 559.429738] hub 1-2:1.0: individual port power switching
[ 559.429743] hub 1-2:1.0: individual port over-current protection
[ 559.429749] hub 1-2:1.0: power on to power good time: 44ms
[ 559.430072] hub 1-2:1.0: hub controller current requirement: 50mA
[ 559.430081] hub 1-2:1.0: 100mA bus power budget for each child
[ 559.432056] hub 1-2:1.0: enabling power on all ports
[ 559.438059] usb 1-2: usb_autosuspend_device: cnt 3 -> 0
[ 559.438119] PM: Adding info for No Bus:ep_81
[ 559.438126] usb 1-2: usb_autosuspend_device: cnt 2 -> 0
[ 559.438164] PM: Adding info for No Bus:ep_00
[ 559.438173] hub 1-0:1.0: usb_autopm_put_interface: cnt 1 -> 0
[ 559.438184] hub 1-0:1.0: state 7 ports 2 chg 0000 evt 0004
[ 559.438551] hub 1-0:1.0: __pm_runtime_resume()!
[ 559.438557] hub 1-0:1.0: __pm_runtime_resume() returns 1!
[ 559.438562] hub 1-0:1.0: usb_autopm_get_interface: cnt 2 -> 1
[ 559.438578] hub 1-0:1.0: __pm_runtime_suspend()!
[ 559.438585] hub 1-0:1.0: __pm_runtime_suspend() returns 0!
[ 559.438590] hub 1-0:1.0: usb_autopm_put_interface: cnt 0 -> 0
[ 559.531060] hub 1-2:1.0: port 1: status 0101 change 0001
[ 559.630040] hub 1-2:1.0: usb_autopm_put_interface_async: cnt 1 -> -11
[ 559.630050] hub 1-2:1.0: state 7 ports 3 chg 0002 evt 0000
[ 559.630055] hub 1-2:1.0: __pm_runtime_resume()!
[ 559.630059] hub 1-2:1.0: __pm_runtime_resume() returns 1!
[ 559.630066] hub 1-2:1.0: usb_autopm_get_interface: cnt 2 -> 1
[ 559.631055] hub 1-2:1.0: port 1, status 0101, change 0000, 12 Mb/s
[ 559.711062] usb 1-2.1: new full speed USB device using ohci_hcd and address 7
[ 559.830024] usb 1-2.1: ep0 maxpacket = 8
[ 559.834058] usb 1-2.1: __pm_runtime_resume()!
[ 559.834064] usb 1-2.1: __pm_runtime_resume() returns 1!
[ 559.834070] usb 1-2.1: usb_autoresume_device: cnt 1 -> 1
[ 559.849058] usb 1-2.1: skipped 1 descriptor after interface
[ 559.849067] usb 1-2.1: skipped 1 descriptor after interface
[ 559.852054] usb 1-2.1: default language 0x0409
[ 559.879060] usb 1-2.1: udev 7, busnum 1, minor = 6
[ 559.879066] usb 1-2.1: New USB device found, idVendor=058f, idProduct=9462
[ 559.888854] usb 1-2.1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[ 559.899132] usb 1-2.1: Product: Multimedia USB Keyboard
[ 559.907166] usb 1-2.1: Manufacturer: Multimedia USB Keyboard
[ 559.915691] usb 1-2.1: SerialNumber: Multimedia USB Keyboard
[ 559.924362] PM: Adding info for usb:1-2.1
[ 559.924430] usb 1-2.1: usb_probe_device
[ 559.924438] usb 1-2.1: configuration #1 chosen from 1 choice
[ 559.924446] usb 1-2.1: __pm_runtime_resume()!
[ 559.924450] usb 1-2.1: __pm_runtime_resume() returns 1!
[ 559.924455] usb 1-2.1: usb_autoresume_device: cnt 4 -> 1
[ 559.925259] usb 1-2.1: adding 1-2.1:1.0 (config #1, interface 0)
[ 559.925300] PM: Adding info for usb:1-2.1:1.0
[ 559.925351] usbhid 1-2.1:1.0: usb_probe_interface
[ 559.925357] usbhid 1-2.1:1.0: usb_probe_interface - got id
[ 559.925361] usb 1-2.1: __pm_runtime_resume()!
[ 559.925366] usb 1-2.1: __pm_runtime_resume() returns 1!
[ 559.925371] usb 1-2.1: usb_autoresume_device: cnt 5 -> 1
[ 559.925379] /usr/src/linux-2.6-git/drivers/hid/usbhid/hid-core.c: HID probe called for ifnum 0
[ 559.934104] PM: Adding info for hid:0003:058F:9462.0005
[ 559.948668] /usr/src/linux-2.6-git/drivers/hid/usbhid/hid-core.c: submitting ctrl urb: Set_Report wValue=0x0200 wIndex=0x0000 wLength=1
[ 559.948803] PM: Adding info for No Bus:input5
[ 559.948881] input: Multimedia USB Keyboard Multimedia USB Keyboard as /devices/pci0000:00/0000:00:13.0/usb1/1-2/1-2.1/1-2.1:1.0/input/input5
[ 559.964996] usbhid 1-2.1:1.0: __pm_runtime_resume()!
[ 559.965002] usbhid 1-2.1:1.0: __pm_runtime_resume() returns 1!
[ 559.965008] usbhid 1-2.1:1.0: usb_autopm_get_interface: cnt 3 -> 1
[ 559.965024] usbhid 1-2.1:1.0: usb_autopm_put_interface: cnt 2 -> 0
[ 559.965089] PM: Adding info for No Bus:event3
[ 559.965123] generic-usb 0003:058F:9462.0005: input: USB HID v1.10 Keyboard [Multimedia USB Keyboard Multimedia USB Keyboard] on usb-0000:00:13.0-2.1/input0
[ 559.982795] HID: device_add() returned 0
[ 559.982802] usb 1-2.1: usb_autosuspend_device: cnt 4 -> 0
[ 559.982810] usbhid 1-2.1:1.0: __pm_runtime_suspend()!
[ 559.982817] usbhid 1-2.1:1.0: __pm_runtime_suspend() returns 0!
[ 559.982847] PM: Adding info for No Bus:ep_81
[ 559.982854] usb 1-2.1: adding 1-2.1:1.1 (config #1, interface 1)
[ 559.982891] PM: Adding info for usb:1-2.1:1.1
[ 559.982932] usbhid 1-2.1:1.1: usb_probe_interface
[ 559.982938] usbhid 1-2.1:1.1: usb_probe_interface - got id
[ 559.982942] usb 1-2.1: __pm_runtime_resume()!
[ 559.982946] usb 1-2.1: __pm_runtime_resume() returns 1!
[ 559.982951] usb 1-2.1: usb_autoresume_device: cnt 5 -> 1
[ 559.982958] /usr/src/linux-2.6-git/drivers/hid/usbhid/hid-core.c: HID probe called for ifnum 1
[ 559.991096] PM: Adding info for hid:0003:058F:9462.0006
[ 560.011698] /usr/src/linux-2.6-git/drivers/hid/hid-core.c: usage index exceeded
[ 560.011704] /usr/src/linux-2.6-git/drivers/hid/hid-core.c: hid_add_usage failed
[ 560.011710] /usr/src/linux-2.6-git/drivers/hid/hid-core.c: item 0 2 2 2 parsing failed
[ 560.011732] /usr/src/linux-2.6-git/drivers/hid/usbhid/hid-core.c: parsing report descriptor failed
[ 560.011747] generic-usb: probe of 0003:058F:9462.0006 failed with error -22
[ 560.021718] HID: device_add() returned 0
[ 560.021724] usb 1-2.1: usb_autosuspend_device: cnt 4 -> 0
[ 560.021735] usbhid 1-2.1:1.1: __pm_runtime_suspend()!
[ 560.021745] usbhid 1-2.1:1.1: __pm_runtime_suspend() returns 0!
[ 560.021781] PM: Adding info for No Bus:ep_82
[ 560.021791] usb 1-2.1: usb_autosuspend_device: cnt 3 -> 0
[ 560.021832] PM: Adding info for No Bus:ep_00
[ 560.021840] hub 1-2:1.0: 400mA power budget left
[ 560.021847] hub 1-2:1.0: usb_autopm_put_interface: cnt 1 -> 0
[ 560.021855] hub 1-2:1.0: state 7 ports 3 chg 0000 evt 0002
[ 560.021860] hub 1-2:1.0: __pm_runtime_resume()!
[ 560.021864] hub 1-2:1.0: __pm_runtime_resume() returns 1!
[ 560.021869] hub 1-2:1.0: usb_autopm_get_interface: cnt 2 -> 1
[ 560.022431] hub 1-2:1.0: __pm_runtime_suspend()!
[ 560.022444] hub 1-2:1.0: __pm_runtime_suspend() returns 0!
[ 560.022451] hub 1-2:1.0: usb_autopm_put_interface: cnt 0 -> 0
[ 561.040033] usb usb2: __pm_runtime_suspend() from workqueue!
[ 561.040046] hub 2-0:1.0: hub_suspend
[ 561.040060] hub 2-0:1.0: usb_suspend_interface: status 0
[ 561.040066] usb usb2: bus auto-suspend
[ 561.040071] ehci_hcd 0000:00:13.5: suspend root hub
[ 561.040917] usb usb2: usb_suspend_device: status 0
[ 561.040923] usb usb2: usb_suspend_both: status 0
[ 561.040929] usb usb2: __pm_runtime_suspend() returns 0!



Sync suspend output, including my printk's in HID:
....
[ 915.245813] usb usb1: preparing type suspend, may wakeup
[ 915.253525] usb usb2: preparing type suspend, may wakeup
[ 915.261254] usb usb3: preparing type suspend, may wakeup
[ 915.268952] usb usb4: preparing type suspend, may wakeup
[ 915.276646] usb usb5: preparing type suspend, may wakeup
[ 915.284221] usb usb6: preparing type suspend, may wakeup
[ 915.291859] usb 1-2: preparing type suspend, may wakeup
[ 915.299424] usb 1-2.1: preparing type suspend, may wakeup
[ 915.307146] usbhid 1-2.1:1.1: suspend
[ 915.312959] input input5: type suspend
[ 915.318925] usbhid 1-2.1:1.0: suspend
[ 915.324719] usb 1-2.1: type suspend, may wakeup
[ 915.331496] hid 0003:058F:9462.0006: Suspending HID device...
[ 915.337614] hid 0003:058F:9462.0006: Waiting for pending IO...
[ 915.345803] hid 0003:058F:9462.0006: done waiting for pending IO...
[ 915.354477] hid 0003:058F:9462.0006: Going to cancel delayed stuff...
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo(a)vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/