On Thu, 6 May 2010, Rob Duncan wrote: > Now I get as far as autosuspend_check() looking to see whether the > device has been idle long enough to actually do the suspend. Something is > causing last_busy to increase, so the check is always failing. > > last_busy increments very regularly by almost exactly one second every time. I'll trim out the lines that don't refer to your device. > May 6 12:33:53 localhost kernel: usb 3-3: __pm_runtime_resume()! > May 6 12:33:53 localhost kernel: usb 3-3: __pm_runtime_resume() returns 1! > May 6 12:33:53 localhost kernel: usb 3-3: usb_autoresume_device: cnt 1 -> 1 > May 6 12:33:53 localhost kernel: usb 3-3: usb_autoresume_device intf 0 usage_count=0 > May 6 12:33:53 localhost kernel: usb 3-3: usb_autoresume_device intf 1 usage_count=0 The device was resumed. This sets last_busy to the current time. > May 6 12:33:53 localhost kernel: usb 3-3: autosuspend_check do_remote_wakeup=0 > May 6 12:33:53 localhost kernel: usb 3-3: autosuspend_check intf0.dev.power.disable_depth=0 > May 6 12:33:53 localhost kernel: usb 3-3: autosuspend_check intf1.dev.power.disable_depth=0 > May 6 12:33:53 localhost kernel: usb 3-3: autosuspend_check time_before j=4294839654 last_busy=4294839654 autosuspend_delay=2000 suspend_time=4294841654 > May 6 12:33:53 localhost kernel: usb 3-3: usb_autosuspend_device: cnt 0 -> 0 > May 6 12:33:53 localhost kernel: usb 3-3: usb_autosuspend_device intf 0 usage_count=0 > May 6 12:33:53 localhost kernel: usb 3-3: usb_autosuspend_device intf 1 usage_count=0 usb_autosuspend_device() also sets last_busy to the current time, so of course this suspend attempt doesn't go through. Normally there would be another attempt after 2 seconds have passed, and it would succeed. > May 6 12:33:54 localhost kernel: usb 3-3: __pm_runtime_resume()! > May 6 12:33:54 localhost kernel: usb 3-3: __pm_runtime_resume() returns 1! > May 6 12:33:54 localhost kernel: usb 3-3: usb_autoresume_device: cnt 1 -> 1 > May 6 12:33:54 localhost kernel: usb 3-3: usb_autoresume_device intf 0 usage_count=0 > May 6 12:33:54 localhost kernel: usb 3-3: usb_autoresume_device intf 1 usage_count=0 But something called usb_autoresume_device(). That sets last_busy to the current time. > May 6 12:33:54 localhost kernel: usb 3-3: autosuspend_check do_remote_wakeup=0 > May 6 12:33:54 localhost kernel: usb 3-3: autosuspend_check intf0.dev.power.disable_depth=0 > May 6 12:33:54 localhost kernel: usb 3-3: autosuspend_check intf1.dev.power.disable_depth=0 > May 6 12:33:54 localhost kernel: usb 3-3: autosuspend_check time_before j=4294839654 last_busy=4294839654 autosuspend_delay=2000 suspend_time=4294841654 > May 6 12:33:54 localhost kernel: usb 3-3: usb_autosuspend_device: cnt 0 -> 0 > May 6 12:33:54 localhost kernel: usb 3-3: usb_autosuspend_device intf 0 usage_count=0 > May 6 12:33:54 localhost kernel: usb 3-3: usb_autosuspend_device intf 1 usage_count=0 And then it called usb_autosuspend_device(). (I don't understand why the value of j here is the same as above. It should be somewhat larger.) > ... > May 6 12:33:54 localhost kernel: usb 3-3: __pm_runtime_resume()! > May 6 12:33:54 localhost kernel: usb 3-3: __pm_runtime_resume() returns 1! > May 6 12:33:54 localhost kernel: usb 3-3: usb_autoresume_device: cnt 1 -> 1 > May 6 12:33:55 localhost kernel: usb 3-3: usb_autoresume_device intf 0 usage_count=0 > May 6 12:33:55 localhost kernel: usb 3-3: usb_autoresume_device intf 1 usage_count=0 Before the 2-second delay elapsed, something called usb_autoresume_device(). > May 6 12:33:55 localhost kernel: usb 3-3: autosuspend_check do_remote_wakeup=0 > May 6 12:33:55 localhost kernel: usb 3-3: autosuspend_check intf0.dev.power.disable_depth=0 > May 6 12:33:55 localhost kernel: usb 3-3: autosuspend_check intf1.dev.power.disable_depth=0 > May 6 12:33:55 localhost kernel: usb 3-3: autosuspend_check time_before j=4294840656 last_busy=4294840656 autosuspend_delay=2000 suspend_time=4294842656 > May 6 12:33:55 localhost kernel: usb 3-3: usb_autosuspend_device: cnt 0 -> 0 > May 6 12:33:55 localhost kernel: usb 3-3: usb_autosuspend_device intf 0 usage_count=0 > May 6 12:33:55 localhost kernel: usb 3-3: usb_autosuspend_device intf 1 usage_count=0 And then it called usb_autosuspend_device(). > May 6 12:33:55 localhost kernel: usb 3-3: __pm_runtime_resume()! > May 6 12:33:55 localhost kernel: usb 3-3: __pm_runtime_resume() returns 1! > May 6 12:33:55 localhost kernel: usb 3-3: usb_autoresume_device: cnt 1 -> 1 > May 6 12:33:55 localhost kernel: usb 3-3: usb_autoresume_device intf 0 usage_count=0 > May 6 12:33:55 localhost kernel: usb 3-3: usb_autoresume_device intf 1 usage_count=0 Before the 2-second delay elapsed, something called usb_autoresume_device() yet again. ... You get the idea. > I'm trying to see what might be updating last_busy, but I'm having trouble > seeing the "big picture". The problem is that something is resuming your device once or twice per second, thereby preventing it from autosuspending. You'll have to figure out what's doing this. You can print the value of current->comm and add a dump_stack() call to usb_autoresume_device() -- try to trigger it only when the device in question is yours. 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
