Bug 795944 - [abrt] kernel: WARNING: at kernel/power/suspend_test.c:53 suspend_test_finish+0x8c/0x90()
Summary: [abrt] kernel: WARNING: at kernel/power/suspend_test.c:53 suspend_test_finish...
Keywords:
Status: CLOSED INSUFFICIENT_DATA
Alias: None
Product: Fedora
Classification: Fedora
Component: kernel
Version: 17
Hardware: i686
OS: Unspecified
unspecified
unspecified
Target Milestone: ---
Assignee: Kernel Maintainer List
QA Contact: Fedora Extras Quality Assurance
URL:
Whiteboard: abrt_hash:e849d300b1ae9b8508dc771fd83...
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2012-02-21 20:44 UTC by Jaroslaw Gorny
Modified: 2013-01-02 13:11 UTC (History)
9 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2013-01-02 13:11:46 UTC
Type: ---


Attachments (Terms of Use)

Description Jaroslaw Gorny 2012-02-21 20:44:05 UTC
libreport version: 2.0.8
abrt_version:   2.0.7
cmdline:        BOOT_IMAGE=/vmlinuz-3.3.0-0.rc3.git7.2.fc17.i686.PAE root=/dev/mapper/vg_masala-lv_root ro rd.md=0 rd.dm=0 KEYTABLE=pl2 SYSFONT=True rd.luks=0 rd.lvm.lv=vg_masala/lv_swap rd.lvm.lv=vg_masala/lv_root LANG=en_US.UTF-8 rhgb quiet
comment:        LID close, in order to suspend.
event_log:      2012-02-21-21:40:24> Smolt profile successfully saved
kernel:         3.3.0-0.rc3.git7.2.fc17.i686.PAE
reason:         WARNING: at kernel/power/suspend_test.c:53 suspend_test_finish+0x8c/0x90()
time:           Tue 21 Feb 2012 08:46:12 PM CET

backtrace:
:WARNING: at kernel/power/suspend_test.c:53 suspend_test_finish+0x8c/0x90()
:Hardware name: 7665D71
:Component: suspend devices, time: 11681
:Modules linked in: fuse binfmt_misc lockd sunrpc xts gf128mul dm_crypt arc4 snd_hda_codec_analog microcode iwl4965 iwlegacy i2c_i801 snd_hda_intel iTCO_wdt iTCO_vendor_support mac80211 snd_hda_codec snd_hwdep cfg80211 snd_pcm snd_page_alloc snd_timer e1000e thinkpad_acpi snd soundcore rfkill uinput yenta_socket nouveau mxm_wmi wmi video drm_kms_helper ttm drm i2c_core [last unloaded: scsi_wait_scan]
:Pid: 2144, comm: pm-suspend Not tainted 3.3.0-0.rc3.git7.2.fc17.i686.PAE #1
:Call Trace:
: [<c044df12>] warn_slowpath_common+0x72/0xa0
: [<c049c0ac>] ? suspend_test_finish+0x8c/0x90
: [<c049c0ac>] ? suspend_test_finish+0x8c/0x90
: [<c044dfe3>] warn_slowpath_fmt+0x33/0x40
: [<c049c0ac>] suspend_test_finish+0x8c/0x90
: [<c049ba80>] suspend_devices_and_enter+0x80/0x3f0
: [<c09d479f>] ? printk+0x30/0x32
: [<c049bf60>] enter_state+0x170/0x1b0
: [<c049a7f5>] state_store+0x85/0x110
: [<c049a770>] ? pm_trace_dev_match_show+0x20/0x20
: [<c06b147b>] kobj_attr_store+0x1b/0x30
: [<c05dbd73>] sysfs_write_file+0xa3/0x100
: [<c05dbcd0>] ? sysfs_schedule_callback_work+0x50/0x50
: [<c0576d4c>] vfs_write+0x8c/0x160
: [<c05dbcd0>] ? sysfs_schedule_callback_work+0x50/0x50
: [<c057702d>] sys_write+0x3d/0x70
: [<c09e701f>] sysenter_do_call+0x12/0x38

smolt_data:
:
:
:General
:=================================
:UUID: 166ee7f9-8849-4ebb-9592-6c927e3e3f7d
:OS: Fedora release 17 (Beefy Miracle)
:Default run level: Unknown
:Language: en_US.UTF-8
:Platform: i686
:BogoMIPS: 3989.86
:CPU Vendor: GenuineIntel
:CPU Model: Intel(R) Core(TM)2 Duo CPU     T7300  @ 2.00GHz
:CPU Stepping: 11
:CPU Family: 6
:CPU Model Num: 15
:Number of CPUs: 2
:CPU Speed: 2001
:System Memory: 3961
:System Swap: 4095
:Vendor: LENOVO
:System: 7665D71 ThinkPad T61
:Form factor: Notebook
:Kernel: 3.3.0-0.rc3.git7.2.fc17.i686.PAE
:SELinux Enabled: 1
:SELinux Policy: targeted
:SELinux Enforce: Enforcing
:MythTV Remote: Unknown
:MythTV Role: Unknown
:MythTV Theme: Unknown
:MythTV Plugin: 
:MythTV Tuner: -1
:
:
:Devices
:=================================
:(32902:10752:6058:8369) pci, None, HOST/PCI, ThinkPad T61
:(32902:10753:6058:8370) pci, pcieport, PCI/PCI, Mobile PM965/GM965/GL960 PCI Express Root Port
:(32902:10302:6058:8361) pci, i801_smbus, SERIAL, ThinkPad T61
:(32902:10281:6058:8359) pci, ahci, STORAGE, ThinkPad T61
:(32902:10320:6058:8358) pci, ata_piix, STORAGE, ThinkPad T61
:(32902:10257:6058:8374) pci, None, PCI/ISA, T61
:(32902:4169:6058:8377) pci, e1000e, ETHERNET, ThinkPad T61
:(32902:9288:6058:8366) pci, None, PCI/PCI, ThinkPad T61
:(32902:10289:6058:8362) pci, uhci_hcd, USB, ThinkPad T61
:(32902:10288:6058:8362) pci, uhci_hcd, USB, ThinkPad T61
:(32902:10290:6058:8362) pci, uhci_hcd, USB, ThinkPad T61
:(32902:10294:6058:8363) pci, ehci_hcd, USB, ThinkPad T61
:(32902:10298:6058:8363) pci, ehci_hcd, USB, ThinkPad T61
:(32902:16944:32902:4369) pci, iwl4965, NETWORK, Lenovo ThinkPad T61
:(32902:10307:6058:8365) pci, pcieport, PCI/PCI, ThinkPad T61
:(32902:10309:6058:8365) pci, pcieport, PCI/PCI, ThinkPad T61
:(32902:10303:6058:8365) pci, pcieport, PCI/PCI, ThinkPad T61
:(32902:10305:6058:8365) pci, pcieport, PCI/PCI, ThinkPad T61
:(32902:10311:6058:8365) pci, pcieport, PCI/PCI, ThinkPad T61
:(32902:10315:6058:8364) pci, snd_hda_intel, MULTIMEDIA, ThinkPad T61
:(32902:10292:6058:8362) pci, uhci_hcd, USB, ThinkPad T61
:(32902:10293:6058:8362) pci, uhci_hcd, USB, ThinkPad T60
:(4318:1065:6058:8408) pci, nouveau, VIDEO, ThinkPad T61
:(4480:1142:6058:8390) pci, yenta_cardbus, PCI/CARDBUS, RL5c476 II
:
:
:Filesystem Information
:=================================
:device mtpt type bsize frsize blocks bfree bavail file ffree favail
:-------------------------------------------------------------------
:/dev/mapper/vg_masala-lv_root / ext4 4096 4096 3918671 3026543 2829935 983040 861021 861021
:/dev/sda1 /boot ext4 1024 1024 508745 458018 432418 128016 127799 127799
:/dev/mapper/luks-f9d57948-381a-4c04-9b8f-85ca897e293d /home ext4 4096 4096 26174432 25677237 24366543 6553600 6553370 6553370
:

Comment 1 Josh Boyer 2012-02-21 20:59:40 UTC
This translates to:

        /* Warning on suspend means the RTC alarm period needs to be
         * larger -- the system was sooo slooowwww to suspend that the
         * alarm (should have) fired before the system went to sleep!
         *
         * Warning on either suspend or resume also means the system
         * has some performance issues.  The stack dump of a WARN_ON
         * is more likely to get the right attention than a printk...
         */
        WARN(msec > (TEST_SUSPEND_SECONDS * 1000),
             "Component: %s, time: %u\n", label, msec);

which means some device took a really long time.  Do you have anything in
/var/log/pm-suspend.log?  What were you doing at the time the machine suspend?

Comment 2 Jaroslaw Gorny 2012-02-21 21:36:00 UTC
Nothing interesting in pm-suspend.log Unfortunately it doesn't have timestamps per hook, so I don't know what was actually so sloooow. But you are right.... suspend took ~1 minute to finish.
Generally on RC3 kernel, because of debugging (I guess) system is hardly usable for me.
What was I doing? Actually, after first boot of the system (install from boot.iso, f17 + updates + updates-testing), I just opened gnome-terminal, installed couple of packages, and decided to try suspend :)

Comment 3 Dave Jones 2012-02-23 22:34:55 UTC
I wonder if this was related to the other rcu related slowdowns that people saw.

does it happen with the latest builds ?

Comment 4 John Reiser 2012-02-24 20:58:27 UTC
Resume from suspend: move the keyboard (PS/2), which may have triggered a key by static electricity.

Package: kernel
OS Release: Fedora release 17 (Beefy Miracle)

Comment 5 Dave Jones 2012-03-06 01:57:41 UTC
is this still happening on the update kernel ? (there's an rc6 build in testing today)

Comment 6 John Reiser 2012-03-06 18:05:02 UTC
Still happens in 3.3.0-0.rc5.git3.1.fc17.x86_64,  I'll go looking for rc6 [grrr Fedora mirror system, which does not yet show rc6 to my "yum update"which includes updates-testing.]

[ cut here ]------------
[  136.948129] WARNING: at kernel/power/suspend_test.c:53 suspend_test_finish+0x86/0x90()
[  136.948131] Hardware name: P5Q-PRO
[  136.948132] Component: suspend devices, time: 12811
[  136.948133] Modules linked in: fuse lockd be2iscsi iscsi_boot_sysfs sunrpc rfcomm bnx2i cnic uio bnep cxgb4i cxgb4 cxgb3i cxgb3 mdio libcxgbi ib_iser rdma_cm ib_addr iw_cm ib_cm ib_sa ib_mad ib_core iscsi_tcp libiscsi_tcp libiscsi scsi_transport_iscsi snd_hda_codec_hdmi snd_hda_codec_realtek btusb snd_hda_intel bluetooth snd_hda_codec snd_hwdep snd_pcm iTCO_wdt rfkill iTCO_vendor_support microcode i2c_i801 serio_raw snd_page_alloc snd_timer snd e1000e atl1e asus_atk0110 soundcore uinput firewire_ohci firewire_core sata_sil24 crc_itu_t nouveau mxm_wmi wmi video drm_kms_helper ttm drm i2c_core [last unloaded: scsi_wait_scan]
[  136.948172] Pid: 1508, comm: pm-suspend Not tainted 3.3.0-0.rc5.git3.1.fc17.x86_64 #1
[  136.948174] Call Trace:
[<ffffffff81060d6f>] warn_slowpath_common+0x7f/0xc0
[<ffffffff81060e66>] warn_slowpath_fmt+0x46/0x50
[<ffffffff810b5176>] suspend_test_finish+0x86/0x90
[<ffffffff810b4a92>] suspend_devices_and_enter+0x92/0x4a0
[<ffffffff810b5036>] enter_state+0x196/0x1d0
[<ffffffff810b356a>] state_store+0xba/0x130
[<ffffffff8131f17f>] kobj_attr_store+0xf/0x20
[<ffffffff81234986>] sysfs_write_file+0xe6/0x160
[<ffffffff811bb33f>] vfs_write+0xaf/0x190
[<ffffffff811bb67d>] sys_write+0x4d/0x90
[<ffffffff816a68e9>] system_call_fastpath+0x16/0x1b
[ end trace 9b33e13f457aa219 ]---

Comment 7 Jaroslaw Gorny 2012-03-06 19:23:09 UTC
Exactly same situation here. On rc5 I've just had the same issue. RC6 not available for me atm. Will test ASAP.

Comment 8 Dave Jones 2012-03-06 20:56:47 UTC
you can get the builds directly from koji
http://koji.fedoraproject.org/koji/buildinfo?buildID=304743

the process of getting builds into updates is kinda slow right now.

Comment 9 John Reiser 2012-03-08 18:51:15 UTC
kernel-3.3.0-0.rc6.git0.2.fc17.x86_64 fails to get completely into Suspend state.  The harddrives do not power down, the DVI monitor does not power down, the fans do not stop.  The display has changed to text mode and shows something like "Cannot open font file True."

kernel-3.3.0-0.rc5.git3.1.fc17.x86_64 works for Suspend + Resume.

See also bug 736839.

Comment 10 Mikko Tiihonen 2012-04-21 12:57:27 UTC
I go the same warning an a newer kernel. The pm-suspend.log has nothing but success messages.

PM: suspend of devices complete after 32979.009 msecs
PM: suspend devices took 32.980 seconds
WARNING: at kernel/power/suspend_test.c:53 suspend_test_finish+0x86/0x90()
Hardware name: 42844DG
Component: suspend devices, time: 32980
Modules linked in: usb_storage uas fuse nf_conntrack_netbios_ns nf_conntrack_broadcast ipt_MASQUERADE ip6table_mangle ip6t_REJECT nf_conntrack_ipv6 n
f_defrag_ipv6 iptable_nat nf_nat iptable_mangle lockd sunrpc nf_conntrack_ipv4 nf_defrag_ipv4 xt_conntrack nf_conntrack ip6table_filter ip6_tables ebtable_nat ebtables arc4 uvcvideo snd_hda_codec_hd
mi videobuf2_vmalloc videobuf2_memops videobuf2_core videodev cdc_acm media cdc_ncm cdc_wdm usbnet mii snd_hda_codec_conexant coretemp microcode i2c_i801 iwlwifi mac80211 iTCO_wdt iTCO_vendor_suppor
t snd_hda_intel cfg80211 snd_hda_codec snd_hwdep snd_pcm snd_page_alloc snd_timer e1000e thinkpad_acpi snd soundcore rfkill binfmt_misc vhost_net tun macvtap macvlan kvm_intel kvm uinput btrfs libcr
c32c zlib_deflate crc32c_intel ghash_clmulni_intel sdhci_pci firewire_ohci sdhci firewire_core mmc_core crc_itu_t nouveau mxm_wmi wmi video drm_kms_helper ttm drm i2c_core [last unloaded: scsi_wait_
scan]
Pid: 16433, comm: pm-suspend Not tainted 3.4.0-0.rc3.git2.1.fc18.x86_64 #1
Call Trace:
 [<ffffffff8106183f>] warn_slowpath_common+0x7f/0xc0
 [<ffffffff81061936>] warn_slowpath_fmt+0x46/0x50
 [<ffffffff810b7216>] suspend_test_finish+0x86/0x90
 [<ffffffff810b6af2>] suspend_devices_and_enter+0x92/0x4e0
 [<ffffffff810b70d4>] pm_suspend+0x194/0x230
 [<ffffffff810b5c3a>] state_store+0xba/0xf0
 [<ffffffff8132a70f>] kobj_attr_store+0xf/0x20
 [<ffffffff8123ad00>] sysfs_write_file+0xe0/0x150
 [<ffffffff811bf64f>] vfs_write+0xaf/0x190
 [<ffffffff811bf98d>] sys_write+0x4d/0x90
 [<ffffffff816c11a9>] system_call_fastpath+0x16/0x1b
---[ end trace e52cecb0e54f33d6 ]---
PM: late suspend of devices complete after 0.931 msecs

Comment 11 Justin M. Forbes 2012-12-07 15:52:50 UTC
Is this still happening in 3.6.9?


Note You need to log in before you can comment on or make changes to this bug.