On Sun, Apr 10, 2011 at 08:52:13PM -0400, CAI Qian wrote: > Hi Sarah, > > The following was output from the serial console during the second > hibernate/resume. Does it help? > > # echo disk >/sys/power/state > PM: Syncing filesystems ... done. > Freezing user space processes ... Apr 10 20:46:36 ibm-x3550m3-03 kernel: PM: Syncing filesystems ... done. > (elapsed 0.01 seconds) done. > Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done. > PM: Preallocating image memory... done (allocated 313188 pages) > PM: Allocated 1252752 kbytes in 0.60 seconds (2087.92 MB/s) > hub 9-1:1.0: suspend error -16 I think Alan said that usb9 or hub 9-0 would be the roothub, so hub 9-1 is most likely your VIA hub. The xHCI host was showing up as bus 8 before, according to your lsusb output, so on 2.6.39-rc2, the xHCI USB 2.0 roothub would still be bus8, and the xHCI USB 3.0 roothub would be bus9. So the device that is failing is probably the USB 3.0 portion of your VIA hub. Specifically the interface driver is refusing to suspend. > pm_op(): usb_dev_freeze+0x0/0x20 returns -16 usb_dev_freeze() attempts to suspend the USB device, eventually calling into khubd's suspend method, hub_suspend(). That looks at all the children of the hub, making sure that udev->can_submit isn't set for each valid usb_device. That will return -EBUSY (-16) if a device is active. I wonder if it's possible the USB 3.0 hub refused the Link PM command to put the port into a lower power state. Can you test that hypothesis by unloading the usb-storage driver and turning on autosuspend for the USB device? I.e. find the device's entry in /sys/bus/usb/ and `echo auto > power/control`. Send me dmesg from that attempt. > PM: Device 9-1 failed to freeze async: error -16 > hub 9-0:1.0: activate --> -22 > hub 9-1:1.0: hub_port_status failed (err = -22) > hub 9-1:1.0: hub_port_status failed (err = -22) > hub 9-1:1.0: hub_port_status failed (err = -22) > hub 9-1:1.0: hub_port_status failed (err = -22) > hub 9-1:1.0: activate --> -22 -22 is -EINVAL. I think hub_activate() tried to run before the xHCI host controller was completely restored, so the driver refused to submit any transfers to the USB 3.0 hub. Seems a bit odd though. > PM: restore of devices complete after 72.896 msecs > Restarting tasks ... > hub 9-1:1.0: hub_port_status failed (err = -22) > done. > Apr 10 20:46:38 ibm-x3550m3-03 kernel: Freezing user space processes ... (elapsed 0.01 seconds) done. > Apr 10 20:46:38 ibm-x3550m3-03 kernel: Freezing remaining freezable tasks ... (elapsed 0.01 seconds) done. > Apr 10 20:46:38 ibm-x3550m3-03 kernel: PM: Preallocating image memory... done (allocated 313188 pages) > Apr 10 20:46:38 ibm-x3550m3-03 kernel: PM: Allocated 1252752 kbytes in 0.60 seconds (2087.92 MB/s) > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 9-1:1.0: port 2 nyet suspended That message also appears to come from usb_dev_freeze(). Did you have the USB 3.0 hard drive attached to port 2, or was there no device attached? > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 9-1:1.0: suspend error -16 > Apr 10 20:46:38 ibm-x3550m3-03 kernel: uhci_hcd 0000:00:1d.2: release dev 2 ep82-INT, period 8, phase 4, 99 us > Apr 10 20:46:38 ibm-x3550m3-03 kernel: uhci_hcd 0000:00:1d.2: release dev 2 ep81-INT, period 8, phase 4, 118 us > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 7-0:1.0: hub_suspend > Apr 10 20:46:38 ibm-x3550m3-03 kernel: usb usb7: bus suspend > Apr 10 20:46:38 ibm-x3550m3-03 kernel: usb usb7: suspend_rh > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 5-0:1.0: hub_suspend > Apr 10 20:46:38 ibm-x3550m3-03 kernel: usb usb5: bus suspend > Apr 10 20:46:38 ibm-x3550m3-03 kernel: usb usb5: suspend_rh > Apr 10 20:46:38 ibm-x3550m3-03 kernel: pm_op(): usb_dev_freeze+0x0/0x20 returns -16 > Apr 10 20:46:38 ibm-x3550m3-03 kernel: PM: Device 9-1 failed to freeze async: error -16 > Apr 10 20:46:38 ibm-x3550m3-03 kernel: usb usb1: usb resume > Apr 10 20:46:38 ibm-x3550m3-03 kernel: ehci_hcd 0000:00:1a.7: resume root hub > Apr 10 20:46:38 ibm-x3550m3-03 kernel: usb usb2: usb resume > Apr 10 20:46:38 ibm-x3550m3-03 kernel: ehci_hcd 0000:00:1d.7: resume root hub > Apr 10 20:46:38 ibm-x3550m3-03 kernel: usb usb3: usb resume > Apr 10 20:46:38 ibm-x3550m3-03 kernel: usb usb3: wakeup_rh > Apr 10 20:46:38 ibm-x3550m3-03 kernel: usb usb4: usb resume > Apr 10 20:46:38 ibm-x3550m3-03 kernel: usb usb4: wakeup_rh > Apr 10 20:46:38 ibm-x3550m3-03 kernel: usb usb5: usb resume > Apr 10 20:46:38 ibm-x3550m3-03 kernel: usb usb5: wakeup_rh > Apr 10 20:46:38 ibm-x3550m3-03 kernel: usb usb6: usb resume > Apr 10 20:46:38 ibm-x3550m3-03 kernel: usb usb6: wakeup_rh > Apr 10 20:46:38 ibm-x3550m3-03 kernel: usb usb7: usb resume > Apr 10 20:46:38 ibm-x3550m3-03 kernel: usb usb7: wakeup_rh > Apr 10 20:46:38 ibm-x3550m3-03 kernel: usb usb8: usb resume > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: resume USB 2.0 root hub > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90012858020, 32'h1, 4'hf); > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90012858450, 32'h2a0, 4'hf); > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90012858440, 32'he61, 4'hf); > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90012858444, 32'h0, 4'hf); > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90012858020, 32'h5, 4'hf); > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 9-0:1.0: hub_resume > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: get port status, actual port 0 status = 0x1203 > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: Get port status returned 0x203 > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 9-0:1.0: port 1: status 0203 change 0000 > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: get port status, actual port 1 status = 0x2a0 > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: Get port status returned 0x2a0 > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 9-0:1.0: activate --> -22 So usb_submit_urb() was failing in hub_activate() with status -EINVAL for the xHCI USB 3.0 roothub. Usually if something goes wrong in the xHCI roothub functions, it will return -EPIPE, so the status return is farther up in the USB core. I'm not sure where though. In rh_queue_status(), it can return -EINVAL if hcd->urb is set to a previous urb. But we should have seen a message like "not queuing rh status urb" in that case. The only other place I see where the roothub URB submission could have failed with -EINVAL is in rh_urb_enqueue(), if the endpoint type is not control or interrupt. No idea how that could have happened. > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 9-1:1.0: hub_resume > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xHCI xhci_urb_enqueue called with unaddressed device Hmm, ok, that's also interesting. The xHCI driver thinks that the USB 3.0 hub doesn't have a slot context. The devices are usually disabled during hibernate, and their slots go away. On a successful resume, we're supposed to get them a new slot context. But the xHCI driver isn't supposed to disable the devices until both host controllers are suspended. So perhaps the device disconnected during hibernate? Or disconnected when we sent it the Link PM command? > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 9-1:1.0: hub_port_status failed (err = -22) > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xHCI xhci_urb_enqueue called with unaddressed device > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 9-1:1.0: hub_port_status failed (err = -22) > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 9-1:1.0: port 2: status 0000 change 0000 > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 8-0:1.0: hub_resume > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xHCI xhci_urb_enqueue called with unaddressed device > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: get port status, actual port 0 status = 0xe63 > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: Get port status returned 0x507 > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 9-1:1.0: hub_port_status failed (err = -22) > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 8-0:1.0: port 1: status 0507 change 0000 > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: get port status, actual port 1 status = 0x2a0 > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: Get port status returned 0x100 > -bash: echo: write error: Device or resource busy > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: get port status, actual port 0 status = 0xe63 > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: Get port status returned 0x507 > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: clear USB_PORT_FEAT_SUSPEND > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: PORTSC 0e63 > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90012858440, 32'h10fe1, 4'hf); > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xHCI xhci_urb_enqueue called with unaddressed device > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 9-1:1.0: hub_port_status failed (err = -22) > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xHCI xhci_urb_enqueue called with unaddressed device > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 9-1:1.0: activate --> -22 > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 1-0:1.0: hub_resume > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 7-0:1.0: hub_resume > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 5-0:1.0: hub_resume > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 7-0:1.0: port 2: status 0303 change 0000 > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 5-0:1.0: port 2: status 0103 change 0000 > Apr 10 20:46:38 ibm-x3550m3-03 kernel: hub 4-0:1.0: hub_resume > Apr 10 20:46:38 ibm-x3550m3-03 kernel: uhci_hcd 0000:00:1d.2: reserve dev 2 ep81-INT, period 8, phase 4, 118 us > Apr 10 20:46:38 ibm-x3550m3-03 kernel: uhci_hcd 0000:00:1d.2: reserve dev 2 ep82-INT, period 8, phase 4, 99 us > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90012858440, 32'h10e01, 4'hf); > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90012858804, 32'h1, 4'hf); > Apr 10 20:46:38 ibm-x3550m3-03 kernel: xhci_hcd 0000:1a:00.0: `MEM_WRITE_DWORD(3'b000, 32'hffffc90012858804, 32'h3, 4'hf); > Apr 10 20:46:38 ibm-x3550m3-03 kernel: usb 8-1: usb resume Looks like the USB 2.0 portion of the VIA hub resumed fine. I'm still not sure exactly what's going on here. My system is still not hibernating properly (even with the xHCI driver blacklisted) with 2.6.39-rc2, plus the patch revert you mentioned, so I can't test this myself. I'll try to compile on top of Linus' latest tree tomorrow. In the meantime, can you test the hypothesis I had about the VIA hub refusing the link PM commands? After that, would you please test Andiry's one work around patch on top of Linus' tree, instead of his five patches? It may help if the issue really is the USB 3.0 hub refusing to accept link PM commands. Sarah Sharo -- 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
