3

I have a problem of battery drain during suspend (~10% in 5 hours) in Ubuntu 18.04 running on a Thinkpad L390. I excluded wake ups during sleep and checking the logs I have realized that the kernel suspends too fast, before the full system is put to sleep.

Here are the syslogs after initiating the suspend mode:

Apr 19 11:59:53 ThinkPad-L390 systemd[1]: Starting TLP suspend/resume...
Apr 19 11:59:53 ThinkPad-L390 systemd[1]: Started TLP suspend/resume.
Apr 19 11:59:53 ThinkPad-L390 systemd[1]: Reached target Sleep.
Apr 19 11:59:53 ThinkPad-L390 systemd[1]: Starting Suspend...
Apr 19 11:59:53 ThinkPad-L390 kernel: [15459.897941] PM: suspend entry (deep)
Apr 19 11:59:53 ThinkPad-L390 systemd-sleep[28261]: Suspending system...
Apr 19 11:59:53 ThinkPad-L390 kernel: [15459.897944] PM: Syncing filesystems ... done.

And here the syslogs directly after waking up

Apr 19 12:37:50 ThinkPad-L390 kernel: [15459.906928] Freezing user space processes ... (elapsed 0.004 seconds) done.
Apr 19 12:37:50 ThinkPad-L390 kernel: [15459.910995] OOM killer disabled.
Apr 19 12:37:50 ThinkPad-L390 kernel: [15459.910996] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
Apr 19 12:37:50 ThinkPad-L390 kernel: [15459.912868] Suspending console(s) (use no_console_suspend to debug)
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.032873] e1000e: EEE TX LPI TIMER: 00000011
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.204567] ACPI: EC: interrupt blocked
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.243401] ACPI: Preparing to enter system sleep state S3
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.249397] ACPI: EC: event blocked
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.249398] ACPI: EC: EC stopped
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.249399] PM: Saving platform NVS memory
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.249432] Disabling non-boot CPUs ...
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.263401] irq_migrate_all_off_this_cpu: 5 callbacks suppressed
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.263403] IRQ 141: no longer affine to CPU1
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.264445] smpboot: CPU 1 is now offline
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.296469] smpboot: CPU 2 is now offline
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.320478] smpboot: CPU 3 is now offline
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.343319] IRQ 149: no longer affine to CPU4
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.345025] smpboot: CPU 4 is now offline
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.375279] IRQ 17: no longer affine to CPU5
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.375285] IRQ 18: no longer affine to CPU5
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.375298] IRQ 148: no longer affine to CPU5
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.376311] smpboot: CPU 5 is now offline
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.399234] IRQ 124: no longer affine to CPU6
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.400265] smpboot: CPU 6 is now offline
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.423211] IRQ 123: no longer affine to CPU7
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.423222] IRQ 139: no longer affine to CPU7
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.423228] IRQ 140: no longer affine to CPU7
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.423235] IRQ 142: no longer affine to CPU7
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.424278] smpboot: CPU 7 is now offline
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.428456] ACPI: Low-level resume complete
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.428541] ACPI: EC: EC started
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.428541] PM: Restoring platform NVS memory
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.429356] Enabling non-boot CPUs ...
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.429403] x86: Booting SMP configuration:
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.429404] smpboot: Booting Node 0 Processor 1 APIC 0x2
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.429761]  cache: parent cpu1 should not be sleeping
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.429898] CPU1 is up
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.429929] smpboot: Booting Node 0 Processor 2 APIC 0x4
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.430294]  cache: parent cpu2 should not be sleeping
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.430439] CPU2 is up
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.430461] smpboot: Booting Node 0 Processor 3 APIC 0x6
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.430822]  cache: parent cpu3 should not be sleeping
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.430978] CPU3 is up
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.430999] smpboot: Booting Node 0 Processor 4 APIC 0x1
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.431434]  cache: parent cpu4 should not be sleeping
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.431601] CPU4 is up
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.431624] smpboot: Booting Node 0 Processor 5 APIC 0x3
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.431995]  cache: parent cpu5 should not be sleeping
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.432165] CPU5 is up
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.432187] smpboot: Booting Node 0 Processor 6 APIC 0x5
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.432563]  cache: parent cpu6 should not be sleeping
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.432743] CPU6 is up
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.432764] smpboot: Booting Node 0 Processor 7 APIC 0x7
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.433143]  cache: parent cpu7 should not be sleeping
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.433337] CPU7 is up
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.438599] ACPI: Waking up from system sleep state S3
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.456686] ACPI: EC: interrupt unblocked
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.501513] ACPI: EC: event unblocked
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.502094] iwlwifi 0000:00:14.3: RF_KILL bit toggled to enable radio.
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.716012] nvme nvme0: Shutdown timeout set to 8 seconds
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.735618] usb 1-5: reset high-speed USB device number 3 using xhci_hcd
Apr 19 12:37:50 ThinkPad-L390 kernel: [15461.011609] usb 1-7: reset full-speed USB device number 5 using xhci_hcd
Apr 19 12:37:50 ThinkPad-L390 kernel: [15461.287637] usb 1-10: reset full-speed USB device number 7 using xhci_hcd
Apr 19 12:37:50 ThinkPad-L390 kernel: [15461.440864] acpi LNXPOWER:05: Turning OFF
Apr 19 12:37:50 ThinkPad-L390 kernel: [15461.441846] OOM killer enabled.
Apr 19 12:37:50 ThinkPad-L390 kernel: [15461.441847] Restarting tasks ... 
Apr 19 12:37:50 ThinkPad-L390 kernel: [15461.443317] Bluetooth: hci0: Bootloader revision 0.1 build 42 week 52 2015
Apr 19 12:37:50 ThinkPad-L390 kernel: [15461.444825] Bluetooth: hci0: Device revision is 2
Apr 19 12:37:50 ThinkPad-L390 kernel: [15461.444830] Bluetooth: hci0: Secure boot is enabled
Apr 19 12:37:50 ThinkPad-L390 kernel: [15461.444832] Bluetooth: hci0: OTP lock is enabled
Apr 19 12:37:50 ThinkPad-L390 kernel: [15461.444833] Bluetooth: hci0: API lock is enabled
Apr 19 12:37:50 ThinkPad-L390 kernel: [15461.444835] Bluetooth: hci0: Debug lock is disabled
Apr 19 12:37:50 ThinkPad-L390 kernel: [15461.444838] Bluetooth: hci0: Minimum firmware build 1 week 10 2014
Apr 19 12:37:50 ThinkPad-L390 kernel: [15461.444845] Bluetooth: hci0: Found device firmware: intel/ibt-17-16-1.sfi
Apr 19 12:37:50 ThinkPad-L390 bluetoothd[951]: Endpoint unregistered: sender=:1.82 path=/MediaEndpoint/A2DPSource
Apr 19 12:37:50 ThinkPad-L390 bluetoothd[951]: Endpoint unregistered: sender=:1.82 path=/MediaEndpoint/A2DPSink
Apr 19 12:37:50 ThinkPad-L390 NetworkManager[1008]: <info>  [1555673870.0221] bluez5: NAP: removed interface 48:F1:7F:83:35:C8
Apr 19 12:37:50 ThinkPad-L390 systemd-sleep[28261]: System resumed.
Apr 19 12:37:50 ThinkPad-L390 kernel: [15461.451251] done.
Apr 19 12:37:50 ThinkPad-L390 kernel: [15461.451504] thermal thermal_zone7: failed to read out thermal zone (-61)
Apr 19 12:37:50 ThinkPad-L390 kernel: [15461.452657] PM: suspend exit
Apr 19 12:37:50 ThinkPad-L390 systemd[1]: Started Suspend.
Apr 19 12:37:50 ThinkPad-L390 systemd[1]: sleep.target: Unit not needed anymore. Stopping.
Apr 19 12:37:50 ThinkPad-L390 systemd[1]: Stopped target Sleep.
Apr 19 12:37:50 ThinkPad-L390 systemd[1]: tlp-sleep.service: Unit not needed anymore. Stopping.
Apr 19 12:37:50 ThinkPad-L390 systemd[1]: Stopping TLP suspend/resume...
Apr 19 12:37:50 ThinkPad-L390 systemd[1]: Reached target Suspend.
Apr 19 12:37:50 ThinkPad-L390 systemd[1]: suspend.target: Unit not needed anymore. Stopping.
Apr 19 12:37:50 ThinkPad-L390 systemd[1]: Stopped target Suspend.

Note: Between the two syslog extracts are no further events.

As it can be seen in the logs, the CPU cores are only put the sleep after the suspend is finished, which leads to the messages like:

Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.429761]  cache: parent cpu1 should not be sleeping
Apr 19 12:37:50 ThinkPad-L390 kernel: [15460.429898] CPU1 is up

Same or similar behavior is reported in

However I didn't come across a fix it. What is the state of this problem in 2019? Somebody has an idea how to solve this problem?

5
  • I had this post already linked in the initial question. The last response was ~6 months ago. I wanted to give this problem more visibility and therefore I created a new question about it to ask for the state of this problem in 2019.
    – sknzl
    Apr 20, 2019 at 10:20
  • 1
    I understand the logic behind more visibility. Another course of action is to upvote all the questions too. The best course of action is to put a bounty on an old question which I did about 2 years ago. You don't have enough points for that though. I revisit the suspend/freeze/resume problem a couple / few times per year and have had no luck solving it :( Apr 20, 2019 at 15:08
  • 1
    I subscribed to the bug report you filed here: bugs.launchpad.net/ubuntu/+source/linux-signed-hwe/+bug/1825636 Apr 21, 2019 at 18:49
  • thanks for the support! I wonder if everybody is affected by this bug or just a few?
    – sknzl
    Apr 23, 2019 at 15:38
  • 1
    I'm affected. I'm not on Ubuntu though. I'm using LMDE 3 (cindy), which is Debian stretch via Mint.
    – mc0e
    Apr 24, 2019 at 11:25

0

Browse other questions tagged or ask your own question.