2.6.27 seems to be taking long time to resume, it hits this WARN_ON in
kernel/power/main.c:176 suspend_test_finish -
Never seen earlier.
[ 295.600086] PM: resume devices took 10.180 seconds
[ 295.600091] ------------[ cut here ]------------
[ 295.600092] WARNING: at kernel/power/main.c:176
suspend_test_finish+0x70/0x80()
[ 295.600094] Modules linked in: i2c_i801 i2c_core nls_iso8859_1
nls_cp437 vfat fat isofs udf af_packet binfmt_misc ipv6 sco bnep
rfcomm l2cap bluetooth ipt_MASQUERADE iptable_nat nf_nat
nf_conntrack_ipv4 xt_state nf_conntrack ipt_REJECT xt_tcpudp bridge
stp llc kvm_intel kvm ppdev acpi_cpufreq cpufreq_conservative
cpufreq_ondemand cpufreq_stats freq_table cpufreq_userspace
cpufreq_powersave wmi video output pci_slot container battery
iptable_filter ip_tables x_tables ac firewire_sbp2 lp snd_hda_intel
snd_pcm_oss snd_mixer_oss snd_pcm snd_seq_dummy snd_seq_oss
snd_seq_midi serio_raw snd_rawmidi evdev dm_multipath psmouse pcspkr
scsi_dh snd_seq_midi_event snd_seq snd_timer snd_seq_device
appledisplay snd parport_serial parport_pc soundcore parport shpchp
snd_page_alloc pci_hotplug button iTCO_wdt iTCO_vendor_support
intel_agp sd_mod sr_mod crc_t10dif cdrom usb_storage usbhid libusual
hid sg firewire_ohci firewire_core crc_itu_t ahci libata scsi_mod dock
ehci_hcd uhci_hcd usbcore e1000e dm_mirror dm_log dm_snapshot dm_mod
thermal processor fan fuse
[ 295.600141] Pid: 7470, comm: pm-suspend Not tainted 2.6.27 #2
[ 295.600142]
[ 295.600142] Call Trace:
[ 295.600147] [<ffffffff802471ff>] warn_on_slowpath+0x5f/0x90
[ 295.600150] [<ffffffff804be7de>] ? printk+0x67/0x69
[ 295.600164] [<ffffffffa006fc10>] ? usb_autopm_do_device+0xc0/0x110 [usbcore]
[ 295.600166] [<ffffffff80377307>] ? kobject_put+0x27/0x60
[ 295.600169] [<ffffffff803f95c5>] ? put_device+0x15/0x20
[ 295.600172] [<ffffffff804017ba>] ? device_resume+0x39a/0x460
[ 295.600174] [<ffffffff802742e0>] suspend_test_finish+0x70/0x80
[ 295.600176] [<ffffffff802743d4>] suspend_devices_and_enter+0xe4/0x200
[ 295.600178] [<ffffffff80274666>] enter_state+0x146/0x1d0
[ 295.600180] [<ffffffff802747aa>] state_store+0xba/0x100
[ 295.600181] [<ffffffff803771c7>] kobj_attr_store+0x17/0x20
[ 295.600184] [<ffffffff80326475>] sysfs_write_file+0xc5/0x140
[ 295.600186] [<ffffffff802cd14b>] vfs_write+0xcb/0x190
[ 295.600188] [<ffffffff802cd300>] sys_write+0x50/0x90
[ 295.600191] [<ffffffff8021168a>] system_call_fastpath+0x16/0x1b
[ 295.600192]
[ 295.600193] ---[ end trace 8a154931a4b75ee4 ]---
[ 295.600333] PM: Finishing wakeup.
On Friday, 10 of October 2008, Parag Warudkar wrote:
> 2.6.27 seems to be taking long time to resume, it hits this WARN_ON in
> kernel/power/main.c:176 suspend_test_finish -
> Never seen earlier.
Resuming devices takes too much time (more than 5 sec. actually)
and the stack trace indicates USB.
Can you test with the USB modules unloaded?
> [ 295.600086] PM: resume devices took 10.180 seconds
> [ 295.600091] ------------[ cut here ]------------
> [ 295.600092] WARNING: at kernel/power/main.c:176
> suspend_test_finish+0x70/0x80()
> [ 295.600094] Modules linked in: i2c_i801 i2c_core nls_iso8859_1
> nls_cp437 vfat fat isofs udf af_packet binfmt_misc ipv6 sco bnep
> rfcomm l2cap bluetooth ipt_MASQUERADE iptable_nat nf_nat
> nf_conntrack_ipv4 xt_state nf_conntrack ipt_REJECT xt_tcpudp bridge
> stp llc kvm_intel kvm ppdev acpi_cpufreq cpufreq_conservative
> cpufreq_ondemand cpufreq_stats freq_table cpufreq_userspace
> cpufreq_powersave wmi video output pci_slot container battery
> iptable_filter ip_tables x_tables ac firewire_sbp2 lp snd_hda_intel
> snd_pcm_oss snd_mixer_oss snd_pcm snd_seq_dummy snd_seq_oss
> snd_seq_midi serio_raw snd_rawmidi evdev dm_multipath psmouse pcspkr
> scsi_dh snd_seq_midi_event snd_seq snd_timer snd_seq_device
> appledisplay snd parport_serial parport_pc soundcore parport shpchp
> snd_page_alloc pci_hotplug button iTCO_wdt iTCO_vendor_support
> intel_agp sd_mod sr_mod crc_t10dif cdrom usb_storage usbhid libusual
> hid sg firewire_ohci firewire_core crc_itu_t ahci libata scsi_mod dock
> ehci_hcd uhci_hcd usbcore e1000e dm_mirror dm_log dm_snapshot dm_mod
> thermal processor fan fuse
> [ 295.600141] Pid: 7470, comm: pm-suspend Not tainted 2.6.27 #2
> [ 295.600142]
> [ 295.600142] Call Trace:
> [ 295.600147] [<ffffffff802471ff>] warn_on_slowpath+0x5f/0x90
> [ 295.600150] [<ffffffff804be7de>] ? printk+0x67/0x69
> [ 295.600164] [<ffffffffa006fc10>] ? usb_autopm_do_device+0xc0/0x110 [usbcore]
> [ 295.600166] [<ffffffff80377307>] ? kobject_put+0x27/0x60
> [ 295.600169] [<ffffffff803f95c5>] ? put_device+0x15/0x20
> [ 295.600172] [<ffffffff804017ba>] ? device_resume+0x39a/0x460
> [ 295.600174] [<ffffffff802742e0>] suspend_test_finish+0x70/0x80
> [ 295.600176] [<ffffffff802743d4>] suspend_devices_and_enter+0xe4/0x200
> [ 295.600178] [<ffffffff80274666>] enter_state+0x146/0x1d0
> [ 295.600180] [<ffffffff802747aa>] state_store+0xba/0x100
> [ 295.600181] [<ffffffff803771c7>] kobj_attr_store+0x17/0x20
> [ 295.600184] [<ffffffff80326475>] sysfs_write_file+0xc5/0x140
> [ 295.600186] [<ffffffff802cd14b>] vfs_write+0xcb/0x190
> [ 295.600188] [<ffffffff802cd300>] sys_write+0x50/0x90
> [ 295.600191] [<ffffffff8021168a>] system_call_fastpath+0x16/0x1b
> [ 295.600192]
> [ 295.600193] ---[ end trace 8a154931a4b75ee4 ]---
> [ 295.600333] PM: Finishing wakeup.
>
>
On Fri, 10 Oct 2008, Rafael J. Wysocki wrote:
> On Friday, 10 of October 2008, Parag Warudkar wrote:
> > 2.6.27 seems to be taking long time to resume, it hits this WARN_ON in
> > kernel/power/main.c:176 suspend_test_finish -
> > Never seen earlier.
>
> Resuming devices takes too much time (more than 5 sec. actually)
> and the stack trace indicates USB.
>
> Can you test with the USB modules unloaded?
There's a bug that affects USB power management: commmit
f9dd45ce10a014bdfd5432828c44630ea7fefedd needs to be reverted. Greg KH
has been asked to do this a few times but he hasn't gotten around to it
yet.
Alan Stern
On Fri, Oct 10, 2008 at 10:31 AM, Alan Stern <[email protected]> wrote:
> There's a bug that affects USB power management: commmit
> f9dd45ce10a014bdfd5432828c44630ea7fefedd needs to be reverted. Greg KH
> has been asked to do this a few times but he hasn't gotten around to it
> yet.
Hi Alan,
Thanks for the info.
I can't seem to find that commit in mainline. If you have pointer to
the patch I will submit a revert.
Parag
On Fri, 10 Oct 2008, Parag Warudkar wrote:
> On Fri, Oct 10, 2008 at 10:31 AM, Alan Stern <[email protected]> wrote:
>
> > There's a bug that affects USB power management: commmit
> > f9dd45ce10a014bdfd5432828c44630ea7fefedd needs to be reverted. Greg KH
> > has been asked to do this a few times but he hasn't gotten around to it
> > yet.
>
> Hi Alan,
>
> Thanks for the info.
>
> I can't seem to find that commit in mainline. If you have pointer to
> the patch I will submit a revert.
It isn't in mainline; it's in linux-next. Sorry, I wasn't sure which
kernel you were using.
Alan Stern
On Friday, 10 of October 2008, Alan Stern wrote:
> On Fri, 10 Oct 2008, Parag Warudkar wrote:
>
> > On Fri, Oct 10, 2008 at 10:31 AM, Alan Stern <[email protected]> wrote:
> >
> > > There's a bug that affects USB power management: commmit
> > > f9dd45ce10a014bdfd5432828c44630ea7fefedd needs to be reverted. Greg KH
> > > has been asked to do this a few times but he hasn't gotten around to it
> > > yet.
> >
> > Hi Alan,
> >
> > Thanks for the info.
> >
> > I can't seem to find that commit in mainline. If you have pointer to
> > the patch I will submit a revert.
>
> It isn't in mainline; it's in linux-next. Sorry, I wasn't sure which
> kernel you were using.
I understood it was the mainline from the report.
Parag, could you please try to suspend without the USB drivers and see if the
delay is still there?
Thanks,
Rafael
On Fri, 10 Oct 2008, Rafael J. Wysocki wrote:
> I understood it was the mainline from the report.
>
> Parag, could you please try to suspend without the USB drivers and see if the
> delay is still there?
Or even better, suspend with the USB drivers present, and with
CONFIG_USB_DEBUG, CONFIG_PM_SLEEP, and CONFIG_PRINTK_TIME all enabled.
The resulting detailed timing information should pinpoint the problem.
Alan Stern
On Fri, Oct 10, 2008 at 3:34 PM, Rafael J. Wysocki <[email protected]> wrote:
>> It isn't in mainline; it's in linux-next. Sorry, I wasn't sure which
>> kernel you were using.
>
> I understood it was the mainline from the report.
>
> Parag, could you please try to suspend without the USB drivers and see if the
> delay is still there?
>
Hi Rafael,
I did and it still does it of course with different stack trace -
[ 3929.502328] Pid: 8069, comm: pm-suspend Not tainted 2.6.27 #3
[ 3929.502329] Call Trace:
[ 3929.502334] [<ffffffff8024721f>] warn_on_slowpath+0x5f/0x90
[ 3929.502337] [<ffffffff804beb2e>] ? printk+0x67/0x69
[ 3929.502340] [<ffffffff80377437>] ? kobject_put+0x27/0x60
[ 3929.502343] [<ffffffff803f9905>] ? put_device+0x15/0x20
[ 3929.502345] [<ffffffff80401afa>] ? device_resume+0x39a/0x460
[ 3929.502347] [<ffffffff80274300>] suspend_test_finish+0x70/0x80
[ 3929.502349] [<ffffffff802743f4>] suspend_devices_and_enter+0xe4/0x200
[ 3929.502351] [<ffffffff80274686>] enter_state+0x146/0x1d0
[ 3929.502353] [<ffffffff802747ca>] state_store+0xba/0x100
[ 3929.502354] [<ffffffff803772f7>] kobj_attr_store+0x17/0x20
[ 3929.502357] [<ffffffff803265a5>] sysfs_write_file+0xc5/0x140
[ 3929.502360] [<ffffffff802cd18b>] vfs_write+0xcb/0x190
[ 3929.502362] [<ffffffff802cd340>] sys_write+0x50/0x90
[ 3929.502365] [<ffffffff8021163a>] system_call_fastpath+0x16/0x1b
[ 3929.502366] ---[ end trace 16538c71b37f9061 ]---
[ 3929.502557] PM: Finishing wakeup.
[ 3929.502558] Restarting tasks ... done.
Thanks
Parag
On Fri, Oct 10, 2008 at 3:44 PM, Alan Stern <[email protected]> wrote:
> Or even better, suspend with the USB drivers present, and with
> CONFIG_USB_DEBUG, CONFIG_PM_SLEEP, and CONFIG_PRINTK_TIME all enabled.
> The resulting detailed timing information should pinpoint the problem.
As of now it is reproducible without USB modules loaded. But any way
will try this over weekend.
Parag