USB APM suspend

USB APM suspend

[Alan Stern]

Here's a piece from my system log, when I did "apm --suspend".  The 
usb_device_suspend/resume messages are things I added for debugging.

Sep 19 17:02:35 ida kernel: uhci-hcd 0000:00:07.2: suspend to state 3
Sep 19 17:02:35 ida kernel: drivers/usb/host/uhci-hcd.c: 6400: suspend_hc
Sep 19 17:02:35 ida kernel: usb_device_suspend: 1-1:0
Sep 19 17:02:35 ida kernel: usb_device_suspend: 1-1
Sep 19 17:02:35 ida kernel: usb_device_suspend: 1-0:0
Sep 19 17:02:35 ida kernel: usb_device_suspend: usb1
Sep 19 17:02:45 ida kernel: uhci-hcd 0000:00:07.2: suspend D4 --> D3
Sep 19 17:02:45 ida kernel: drivers/usb/host/uhci-hcd.c: 6400: wakeup_hc
Sep 19 17:02:45 ida kernel: usb_device_resume: usb1
Sep 19 17:02:45 ida kernel: usb_device_resume: 1-0:0
Sep 19 17:02:45 ida kernel: usb_device_resume: 1-1
Sep 19 17:02:45 ida kernel: usb_device_resume: 1-1:0
Sep 19 17:02:45 ida kernel: uhci-hcd 0000:00:07.2: can't resume, not suspended!

This has several odd things.  Note that both the first two "0000:00:07.2"  
messages were created by hcd-pci.c, in its usb_hcd_pci_suspend() routine.  

Why was this routine called twice?  (Don't be fooled by the timestamps; I 
think the "suspend D4 --> D3" message was created during the suspend but 
not read by syslogd until after the resume.)

Why doesn't usb_hcd_pci_resume() log a similar message when it is called?
A simple oversight?

Why was the host controller suspended _before_ its child USB devices?  

And why was it woken up twice?

Alan Stern


P.S.: Greg, what on Earth does "GREG: gregindex = 0" mean?

Re: USB APM suspend

[Greg KH]

On Fri, Sep 19, 2003 at 06:14:29PM -0400, Alan Stern wrote:
> 
> P.S.: Greg, what on Earth does "GREG: gregindex = 0" mean?

Heh, using the linuxusb.bkbits.net/usb-2.5 tree are ya?  :)

It's some debugging code left in by me for some module loading code
changes I've been working on in my spare time.  It's to implement only
loading signed kernel modules.  That message means that the "gregindex"
section in the elf records of the kernel module was not found.  It if
is, lots of other code gets kicked off.  I'll try to clean it all up
into a reasonable state next week and make a patch available for those
that want to play with it.

Sorry about leaving that in there, I'll go delete it.  I try to make all
my debugging code start with GREG: so I'll never send it off for
inclusion in someone else's tree.

greg k-h

Re: USB APM suspend

[David Brownell]

Alan Stern wrote:
> Here's a piece from my system log, when I did "apm --suspend".  The 
> usb_device_suspend/resume messages are things I added for debugging.

That's progress ... last time I tried APM on 2.6 it failed horribly.
(This was after working fine until recently.)


> Why was this routine called twice?  (Don't be fooled by the timestamps; I 
> think the "suspend D4 --> D3" message was created during the suspend but 
> not read by syslogd until after the resume.)

That's happened for as long as I remember (2.4 also).
Still seems buglike to me, maybe 2.6 will finally squish it...

> Why doesn't usb_hcd_pci_resume() log a similar message when it is called?
> A simple oversight?

You mean, why didn't it announce its first resume?  Basically, yes.

> Why was the host controller suspended _before_ its child USB devices?  

Seems buglike to me, with the first call being wrong (before the
children were suspended) and the second being right (after).

> And why was it woken up twice?

The converse of the "suspended-twice" problem:  first call right,
second call (after children) wrong.

- Dave

PATCH (as112) Re: USB APM suspend

[Alan Stern]

On Sun, 21 Sep 2003, David Brownell wrote:

> Alan Stern wrote:
> > Here's a piece from my system log, when I did "apm --suspend".  The 
> > usb_device_suspend/resume messages are things I added for debugging.
> 
> > Why was this routine called twice?  (Don't be fooled by the timestamps; I 
> > think the "suspend D4 --> D3" message was created during the suspend but 
> > not read by syslogd until after the resume.)
> 
> That's happened for as long as I remember (2.4 also).
> Still seems buglike to me, maybe 2.6 will finally squish it...

Well, the code path is easy enough to find.  If you look at suspend() in
arch/i386/kernel/apm.c, you'll see calls to pm_send_all() and
device_suspend().  They both end up filtering down to the USB HC drivers.  
The bad one is pm_send_all(); it comes too soon.

By the way, David, apparently core/hcd-pci.c wants the HC drivers to set 
the hcd state to USB_STATE_SUSPENDED, but a simple grep shows that neither 
the EHCI nor the OHCI driver does so.  That certainly looks like an 
oversight, though I'm not sure in which source file.

Meanwhile, here's a simple patch to improve logging during suspend and
resume.  Greg, if David approves please apply it.

Alan Stern


===== hcd-pci.c 1.35 vs edited =====
--- 1.35/drivers/usb/core/hcd-pci.c	Wed Sep  3 11:47:17 2003
+++ edited/drivers/usb/core/hcd-pci.c	Mon Sep 22 11:02:37 2003
@@ -273,17 +273,17 @@
 	int			retval = 0;
 
 	hcd = pci_get_drvdata(dev);
+	dev_dbg (hcd->controller, "suspend D%d --> D%d\n",
+			dev->current_state, state);
+
 	switch (hcd->state) {
 	case USB_STATE_HALT:
 		dev_dbg (hcd->controller, "halted; hcd not suspended\n");
 		break;
 	case USB_STATE_SUSPENDED:
-		dev_dbg (hcd->controller, "suspend D%d --> D%d\n",
-				dev->current_state, state);
+		dev_dbg (hcd->controller, "hcd already suspended\n");
 		break;
 	default:
-		dev_dbg (hcd->controller, "suspend to state %d\n", state);
-
 		/* remote wakeup needs hub->suspend() cooperation */
 		// pci_enable_wake (dev, 3, 1);
 
@@ -292,6 +292,9 @@
 		/* driver may want to disable DMA etc */
 		hcd->state = USB_STATE_QUIESCING;
 		retval = hcd->driver->suspend (hcd, state);
+		if (retval)
+			dev_dbg (hcd->controller, "suspend fail, retval %d\n",
+					retval);
 	}
 
  	pci_set_power_state (dev, state);
@@ -311,6 +314,9 @@
 	int			retval;
 
 	hcd = pci_get_drvdata(dev);
+	dev_dbg (hcd->controller, "resume from state D%d\n",
+			dev->current_state);
+
 	if (hcd->state != USB_STATE_SUSPENDED) {
 		dev_dbg (hcd->controller, "can't resume, not suspended!\n");
 		return -EL3HLT;

Re: PATCH (as112) Re: USB APM suspend

[David Brownell]

Alan Stern wrote:
> On Sun, 21 Sep 2003, David Brownell wrote:
> 
>>>Why was this routine called twice?  (Don't be fooled by the timestamps; I 
>>>think the "suspend D4 --> D3" message was created during the suspend but 
>>>not read by syslogd until after the resume.)
>>
>>That's happened for as long as I remember (2.4 also).
>>Still seems buglike to me, maybe 2.6 will finally squish it...
> 
> 
> Well, the code path is easy enough to find.  If you look at suspend() in
> arch/i386/kernel/apm.c, you'll see calls to pm_send_all() and
> device_suspend().  They both end up filtering down to the USB HC drivers.  
> The bad one is pm_send_all(); it comes too soon.

Rather, "it comes at all".  Call device_{suspend,resume} should
suffice.  It shouldn't pm_send_all() -- either of the two calls.
(The 2.4 bug is necessarily a different issue.)

Does it work if you remove those calls?


> By the way, David, apparently core/hcd-pci.c wants the HC drivers to set 
> the hcd state to USB_STATE_SUSPENDED, but a simple grep shows that neither 
> the EHCI nor the OHCI driver does so.  That certainly looks like an 
> oversight, though I'm not sure in which source file.

And what's odd is that it was working before, too!  I'll have a look,
next I get a chance.  It's good to know that APM is almost behaving again.


> Meanwhile, here's a simple patch to improve logging during suspend and
> resume.  Greg, if David approves please apply it.

Reads OK to me -- go for it!

- Dave

Re: PATCH (as112) Re: USB APM suspend

[Greg KH]

On Mon, Sep 22, 2003 at 11:09:16AM -0400, Alan Stern wrote:
> 
> Meanwhile, here's a simple patch to improve logging during suspend and
> resume.  Greg, if David approves please apply it.

Applied, thanks.

greg k-h

Re: USB APM suspend

[David Brownell]

Alan Stern wrote:

> 
> I tried the experiment of getting rid of the calls to pm_send_all().  
> Surprisingly enough, it worked.  That is, when I typed:
> 
> 	apm --suspend
> 
> everything was suspended, in the correct order; and when I pressed a key 
> everything awoke and seemed to be functioning properly.  

Just for the record:  I tried this on 2.6.0-test7, on a system where
APM has worked reliably forever, and it failed.  (That was without even
involving USB -- there are still non-USB PM problems.)

The device_suspend() logic did seem to call things in the right order,
on one machine I hacked with some printks, but when the moment came to
actually enter the APM suspend mode nothing happened ... except for a
delay of maybe a minute, before the system resumed itself.  (FWIW the
PCI suspend methods involved were for yenta_cardbus and agpgart-intel.
Both of those were called after "hda" spun itself down.)

What should happen of course is the APM BIOS takes over and blanks the
display, and the power indicator changes (in my case to a low-frequency
amber blink, no longer solid green).

- Dave