Bug 1036810

Summary: suspend fails intermittently: wakes immediately
Product: [Fedora] Fedora Reporter: dhardy <redhat>
Component: kernelAssignee: Kernel Maintainer List <kernel-maint>
Status: CLOSED CURRENTRELEASE QA Contact: Fedora Extras Quality Assurance <extras-qa>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 20CC: gansalmon, hugh, itamar, jaskerx, jonathan, kernel-maint, madhu.chinakonda
Target Milestone: ---   
Target Release: ---   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2014-02-25 22:56:19 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description dhardy 2013-12-02 16:27:42 UTC
Description of problem:

When putting the laptop into suspend mode (lid-close), it intermittently (more often than not) resumes automatically after a few seconds, with the result that the battery runs down if I don't notice.


Version-Release number of selected component (if applicable):

Fedora 20 beta, kernel 3.11.9-300.fc20 .


How reproducible:

Happens frequently, more often than not.


Steps to Reproduce:
1. Install Fedora 20 on Yoga 2 Pro (haven't tested other versions/distributions)
2. Close the lid
3.

Actual results:

Close the lid. After about 3 seconds the power light goes off (indicating standby mode), then after about 1 second it comes back on.

Expected results:

Laptop stays in standby mode.

Additional info:

The most similar reports I can find relate to the USB system or nouveau driver (but this laptop has no NVidia graphics so the latter is not related):
https://bugzilla.redhat.com/show_bug.cgi?id=921993
https://bugzilla.redhat.com/show_bug.cgi?id=557192
https://bugzilla.redhat.com/show_bug.cgi?id=921993
https://bugzilla.redhat.com/show_bug.cgi?id=1025976

Dmesg (looks like suspend starts at 48882):

[48417.834408] IPv6: ADDRCONF(NETDEV_UP): wlp1s0: link is not ready
[48418.041743] [drm] Enabling RC6 states: RC6 on, RC6p off, RC6pp off
[48420.486921] ACPI: \_SB_.PCI0: ACPI_NOTIFY_BUS_CHECK event: unsupported
[48420.486934] ACPI: \_SB_.PCI0: Bus check notify on _handle_hotplug_event_root
[48424.389361] usb 2-1: new full-speed USB device number 28 using xhci_hcd
[48424.403613] usb 2-1: New USB device found, idVendor=046d, idProduct=c52b
[48424.403616] usb 2-1: New USB device strings: Mfr=1, Product=2, SerialNumber=0
[48424.403618] usb 2-1: Product: USB Receiver
[48424.403619] usb 2-1: Manufacturer: Logitech
[48424.413974] logitech-djreceiver 0003:046D:C52B.000B: hiddev0,hidraw1: USB HID v1.11 Device [Logitech USB Receiver] on usb-0000:00:14.0-1/input2
[48424.417440] input: Logitech Unifying Device. Wireless PID:4013 as /devices/pci0000:00/0000:00:14.0/usb2/2-1/2-1:1.2/0003:046D:C52B.000B/input/input16
[48424.417906] logitech-djdevice 0003:046D:C52B.000C: input,hidraw2: USB HID v1.11 Mouse [Logitech Unifying Device. Wireless PID:4013] on usb-0000:00:14.0-1:1
[48424.419589] input: Logitech Unifying Device. Wireless PID:1028 as /devices/pci0000:00/0000:00:14.0/usb2/2-1/2-1:1.2/0003:046D:C52B.000B/input/input17
[48424.420050] logitech-djdevice 0003:046D:C52B.000D: input,hidraw3: USB HID v1.11 Mouse [Logitech Unifying Device. Wireless PID:1028] on usb-0000:00:14.0-1:2
[48425.210496] wlp1s0: authenticate with 00:1a:8c:06:43:01
[48425.211531] wlp1s0: send auth to 00:1a:8c:06:43:01 (try 1/3)
[48425.216957] wlp1s0: authenticated
[48425.217974] wlp1s0: associate with 00:1a:8c:06:43:01 (try 1/3)
[48425.223568] wlp1s0: RX AssocResp from 00:1a:8c:06:43:01 (capab=0x401 status=0 aid=3)
[48425.224313] wlp1s0: associated
[48425.224337] IPv6: ADDRCONF(NETDEV_CHANGE): wlp1s0: link becomes ready
[48542.955155] mce: [Hardware Error]: Machine check events logged
[48876.939374] ACPI: \_SB_.PCI0: ACPI_NOTIFY_BUS_CHECK event: unsupported
[48876.939388] ACPI: \_SB_.PCI0: Bus check notify on _handle_hotplug_event_root
[48877.856335] wlp1s0: deauthenticating from 00:1a:8c:06:43:01 by local choice (reason=3)
[48877.860697] cfg80211: Calling CRDA to update world regulatory domain
[48877.882548] cfg80211: World regulatory domain updated:
[48877.882553] cfg80211:   (start_freq - end_freq @ bandwidth), (max_antenna_gain, max_eirp)
[48877.882555] cfg80211:   (2402000 KHz - 2472000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[48877.882558] cfg80211:   (2457000 KHz - 2482000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[48877.882559] cfg80211:   (2474000 KHz - 2494000 KHz @ 20000 KHz), (300 mBi, 2000 mBm)
[48877.882561] cfg80211:   (5170000 KHz - 5250000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[48877.882563] cfg80211:   (5735000 KHz - 5835000 KHz @ 40000 KHz), (300 mBi, 2000 mBm)
[48882.661868] PM: Syncing filesystems ... done.
[48882.918930] PM: Preparing system for mem sleep
[48882.919834] Freezing user space processes ... (elapsed 0.001 seconds) done.
[48882.921837] Freezing remaining freezable tasks ... (elapsed 0.000 seconds) done.
[48882.922650] PM: Entering mem sleep
[48882.922718] Suspending console(s) (use no_console_suspend to debug)
[48882.960954] ehci-pci 0000:00:1d.0: setting latency timer to 64
[48882.962835] sd 1:0:0:0: [sda] Synchronizing SCSI cache
[48882.967514] sd 1:0:0:0: [sda] Stopping disk
[48883.018800] mei_me 0000:00:16.0: suspend
[48884.051187] PM: suspend of devices complete after 1090.597 msecs
[48884.051442] PM: late suspend of devices complete after 0.251 msecs
[48884.062352] ehci-pci 0000:00:1d.0: System wakeup enabled by ACPI
[48884.084067] xhci_hcd 0000:00:14.0: System wakeup enabled by ACPI
[48884.112955] xhci_hcd 0000:00:14.0: power state changed by ACPI to D3cold
[48884.113050] PM: noirq suspend of devices complete after 61.635 msecs
[48884.113785] ACPI: Preparing to enter system sleep state S3
[48884.114511] PM: Saving platform NVS memory
[48884.116464] Disabling non-boot CPUs ...
[48884.118992] smpboot: CPU 1 is now offline
[48884.121706] smpboot: CPU 2 is now offline
[48884.123642] smpboot: CPU 3 is now offline
[48884.127097] ACPI: Low-level resume complete
[48884.127243] PM: Restoring platform NVS memory
[48884.128120] microcode: CPU0 sig=0x40651, pf=0x40, revision=0x15
[48884.128201] Enabling non-boot CPUs ...
[48884.128266] smpboot: Booting Node 0 Processor 1 APIC 0x1
[48884.144167] microcode: CPU1 sig=0x40651, pf=0x40, revision=0x14
[48884.147846] microcode: CPU1 updated to revision 0x15, date = 2013-07-02
[48884.147869] CPU1 is up
[48884.147901] smpboot: Booting Node 0 Processor 2 APIC 0x2
[48884.162990] microcode: CPU2 sig=0x40651, pf=0x40, revision=0x14
[48884.164684] microcode: CPU2 updated to revision 0x15, date = 2013-07-02
[48884.164698] CPU2 is up
[48884.164723] smpboot: Booting Node 0 Processor 3 APIC 0x3
[48884.179630] microcode: CPU3 sig=0x40651, pf=0x40, revision=0x15
[48884.179639] CPU3 is up
[48884.185775] ACPI: Waking up from system sleep state S3
[48884.231814] xhci_hcd 0000:00:14.0: power state changed by ACPI to D0
[48884.242917] xhci_hcd 0000:00:14.0: System wakeup disabled by ACPI
[48884.275911] ehci-pci 0000:00:1d.0: System wakeup disabled by ACPI
[48884.298012] PM: noirq resume of devices complete after 107.947 msecs
[48884.298230] PM: early resume of devices complete after 0.179 msecs
[48884.298283] i915 0000:00:02.0: setting latency timer to 64
[48884.298334] xhci_hcd 0000:00:14.0: setting latency timer to 64
[48884.298454] mei_me 0000:00:16.0: irq 60 for MSI/MSI-X
[48884.298878] snd_hda_intel 0000:00:1b.0: irq 61 for MSI/MSI-X
[48884.299130] ehci-pci 0000:00:1d.0: setting latency timer to 64
[48884.299177] ahci 0000:00:1f.2: setting latency timer to 64
[48884.300497] snd_hda_intel 0000:00:03.0: irq 63 for MSI/MSI-X
[48884.306290] dpm_run_callback(): pnp_bus_resume+0x0/0x80 returns -19
[48884.306291] PM: Device 00:06 failed to resume: error -19
[48884.603706] ata2: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[48884.604799] ata2.00: ACPI cmd ef/10:09:00:00:00:b0 (SET FEATURES) succeeded
[48884.610691] ata2.00: ACPI cmd ef/10:09:00:00:00:b0 (SET FEATURES) succeeded
[48884.610939] ata2.00: configured for UDMA/133
[48884.611092] sd 1:0:0:0: [sda] Starting disk
[48884.690891] usb 2-4: reset full-speed USB device number 2 using xhci_hcd
[48884.702386] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff8802505c0cc0
[48884.702390] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff8802505c0d00
[48884.702393] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff8802505c0d40
[48884.702396] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff880253117e80
[48884.702399] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff880253117ec0
[48884.854695] usb 2-6: reset full-speed USB device number 3 using xhci_hcd
[48884.867110] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88025048c140
[48884.867114] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff88025048c100
[48884.867124] usb 2-6: ep 0x81 - rounding interval to 128 microframes, ep desc says 160 microframes
[48884.867129] usb 2-6: ep 0x1 - rounding interval to 128 microframes, ep desc says 160 microframes
[48885.018682] usb 2-7: reset full-speed USB device number 24 using xhci_hcd
[48885.030172] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff8802517e1f00
[48885.030176] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff8802517e1f40
[48885.030186] usb 2-7: ep 0x2 - rounding interval to 64 microframes, ep desc says 80 microframes
[48885.182581] usb 2-1: reset full-speed USB device number 28 using xhci_hcd
[48885.194963] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff8801a91d7e40
[48885.194967] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff8801a91d7dc0
[48885.194970] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff8801a91d7e80
[48885.346427] usb 2-8: reset high-speed USB device number 7 using xhci_hcd
[48885.387941] xhci_hcd 0000:00:14.0: xHCI xhci_drop_endpoint called with disabled ep ffff880250680740
[48885.391904] PM: resume of devices complete after 1094.239 msecs
[48885.392333] PM: Finishing wakeup.
[48885.392336] Restarting tasks ... done.
[48885.407313] video LNXVIDEO:00: Restoring backlight state
[48885.427942] iwlwifi 0000:01:00.0: L1 Disabled; Enabling L0S
[48885.428087] iwlwifi 0000:01:00.0: L1 Disabled; Enabling L0S
[48885.436775] IPv6: ADDRCONF(NETDEV_UP): wlp1s0: link is not ready
[48885.773048] [drm] Enabling RC6 states: RC6 on, RC6p off, RC6pp off
[48889.894901] ACPI: \_SB_.PCI0: ACPI_NOTIFY_BUS_CHECK event: unsupported
[48889.894921] ACPI: \_SB_.PCI0: Bus check notify on _handle_hotplug_event_root
[48892.813221] wlp1s0: authenticate with 00:1a:8c:06:43:01
[48892.814188] wlp1s0: send auth to 00:1a:8c:06:43:01 (try 1/3)
[48892.823486] wlp1s0: authenticated
[48892.824321] wlp1s0: associate with 00:1a:8c:06:43:01 (try 1/3)
[48892.829421] wlp1s0: RX AssocResp from 00:1a:8c:06:43:01 (capab=0x401 status=0 aid=3)
[48892.830128] wlp1s0: associated
[48892.830152] IPv6: ADDRCONF(NETDEV_CHANGE): wlp1s0: link becomes ready
[48992.526896] mce: [Hardware Error]: Machine check events logged

The only obvious failure message concerns device 00:06, but I don't know what that is. It's not listed in lspci:

00:00.0 Host bridge: Intel Corporation Haswell-ULT DRAM Controller (rev 09)
00:02.0 VGA compatible controller: Intel Corporation Haswell-ULT Integrated Graphics Controller (rev 09)
00:03.0 Audio device: Intel Corporation Haswell-ULT HD Audio Controller (rev 09)
00:04.0 Signal processing controller: Intel Corporation Device 0a03 (rev 09)
00:14.0 USB controller: Intel Corporation Lynx Point-LP USB xHCI HC (rev 04)
00:16.0 Communication controller: Intel Corporation Lynx Point-LP HECI #0 (rev 04)
00:1b.0 Audio device: Intel Corporation Lynx Point-LP HD Audio Controller (rev 04)
00:1c.0 PCI bridge: Intel Corporation Lynx Point-LP PCI Express Root Port 1 (rev e4)
00:1d.0 USB controller: Intel Corporation Lynx Point-LP USB EHCI #1 (rev 04)
00:1f.0 ISA bridge: Intel Corporation Lynx Point-LP LPC Controller (rev 04)
00:1f.2 SATA controller: Intel Corporation Lynx Point-LP SATA Controller 1 [AHCI mode] (rev 04)
00:1f.3 SMBus: Intel Corporation Lynx Point-LP SMBus Controller (rev 04)
00:1f.6 Signal processing controller: Intel Corporation Lynx Point-LP Thermal (rev 04)
01:00.0 Network controller: Intel Corporation Wireless 7260 (rev 6b)

or lsusb:

Bus 001 Device 002: ID 8087:8000 Intel Corp. 
Bus 001 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub
Bus 003 Device 001: ID 1d6b:0003 Linux Foundation 3.0 root hub
Bus 002 Device 007: ID 5986:0535 Acer, Inc 
Bus 002 Device 024: ID 04f3:016f Elan Microelectronics Corp. 
Bus 002 Device 003: ID 2047:0855 Texas Instruments 
Bus 002 Device 002: ID 8087:07dc Intel Corp. 
Bus 002 Device 028: ID 046d:c52b Logitech, Inc. Unifying Receiver
Bus 002 Device 001: ID 1d6b:0002 Linux Foundation 2.0 root hub

Any other ideas?

Comment 1 dhardy 2013-12-06 10:32:44 UTC
It seems that the laptop suspends fine when told to do so via another method (e.g. KDE menu).

But I see this in journalctl, could this be the problem? New laptop :-(

Dec 06 11:04:52 yoga.dhardy kernel: mei_me 0000:00:16.0: suspend
Dec 06 11:04:52 yoga.dhardy mcelog[647]: Hardware event. This is not a software error.
Dec 06 11:04:52 yoga.dhardy mcelog[647]: MCE 0
Dec 06 11:04:52 yoga.dhardy mcelog[647]: CPU 0 BANK 6
Dec 06 11:04:52 yoga.dhardy mcelog[647]: MISC f8a0000086 ADDR ffb03840
Dec 06 11:04:52 yoga.dhardy mcelog[647]: TIME 1386324290 Fri Dec  6 11:04:50 2013
Dec 06 11:04:52 yoga.dhardy mcelog[647]: MCG status:
Dec 06 11:04:52 yoga.dhardy mcelog[647]: MCi status:
Dec 06 11:04:52 yoga.dhardy mcelog[647]: Uncorrected error
Dec 06 11:04:52 yoga.dhardy mcelog[647]: MCi_MISC register valid
Dec 06 11:04:52 yoga.dhardy mcelog[647]: MCi_ADDR register valid
Dec 06 11:04:52 yoga.dhardy mcelog[647]: Processor context corrupt
Dec 06 11:04:52 yoga.dhardy mcelog[647]: MCA: corrected filtering (some unreported errors in same region)
Dec 06 11:04:52 yoga.dhardy mcelog[647]: Generic CACHE Level-2 Generic Error
Dec 06 11:04:52 yoga.dhardy mcelog[647]: STATUS ae0000000040110a MCGSTATUS 0
Dec 06 11:04:52 yoga.dhardy mcelog[647]: MCGCAP c07 APICID 0 SOCKETID 0
Dec 06 11:04:52 yoga.dhardy mcelog[647]: CPUID Vendor Intel Family 6 Model 69

Comment 2 jaskerx 2013-12-14 17:22:14 UTC
I can attest to this bug as well am using:

Yoga 2 Pro (i5, 8gb)
Kde 4.11.4
Kernel 3.12.3

I am not using fedora/red hat though just wanted to post a link to the kde forums:

http://forum.kde.org/viewtopic.php?f=225&t=118745

My experience with this issue. Might help, might not.

Comment 3 Justin M. Forbes 2014-02-24 13:52:04 UTC
*********** MASS BUG UPDATE **************

We apologize for the inconvenience.  There is a large number of bugs to go through and several of them have gone stale.  Due to this, we are doing a mass bug update across all of the Fedora 20 kernel bugs.

Fedora 20 has now been rebased to 3.13.4-200.fc20.  Please test this kernel update and let us know if you issue has been resolved or if it is still present with the newer kernel.

If you experience different issues, please open a new bug report for those.

Comment 4 D. Hugh Redelmeier 2014-02-25 03:19:40 UTC
note: with the Yoga 2 pro, it seems that it is important to blacklist the ideapad_laptop module.  Apparently the Y2p looks like an Ideapad to that module but it then does some inappropriate things.

My Y2p sleeps well with current Fedora 20 (I have blacklisted that module).

Comment 5 dhardy 2014-02-25 22:56:19 UTC
The 3.13.4-200.fc20 kernel seems to fix this issue (3.12.3-1.fc21 still has it).

Redelmeier: I also have ideapad_laptop disabled. Even with 3.12.4 it breaks wifi.

Comment 6 D. Hugh Redelmeier 2014-02-26 02:18:15 UTC
dhardy: OK.

My Yoga 2 pro had a WiFi firmware problem that https://admin.fedoraproject.org/updates/kernel-3.13.5-200.fc20 fixes.

See https://bugzilla.redhat.com/show_bug.cgi?id=1069403

Comment 7 dhardy 2014-02-26 07:43:09 UTC
Hugh: Awesome, even if for me this mostly just means less log noise. The linked bug doesn't mention ideapad_laptop — is that related?

Comment 8 D. Hugh Redelmeier 2014-02-26 15:59:32 UTC
dhardy: I haven't heard of any linkage.  (I'm just a user and a googler.)

The new kernel made a screen problem go away for me.  And made booting faster.  I don't know why.  My superstitious explanation is that firmware crashes disrupted booting.  ABRT told me I had unreportable kernel crashes, with hardware errors (Machine Check Error).  Not very comforting!

I think that my previous kernel was 3.13.3-201.fc20.x86_64 based on the second choice in the grub menu.  It was the latest version in Fedora Updates a couple of days ago.

Comment 9 dhardy 2014-02-26 16:09:12 UTC
Could be the case. I haven't really paid attention to boot time, but I definitely have had MCE errors in my log.

Comment 10 D. Hugh Redelmeier 2014-03-29 06:48:37 UTC
dhardy: the MCE errors are concerning.  It is useful to know that I'm not alone.

I've created a new bz about this.  Please report your observations.

https://bugzilla.redhat.com/show_bug.cgi?id=1082211