Suspend/hibernation: Laptop wakes up again immedeatly if power is connected

One of the things I still need to sort out is fixing suspend/hibernation.
I am on BTRFS with LUKS encryption so I know suspend to disk is going to be interesting, but first things first, which is fixing suspend to ram which currently only works when the machine is not connected to a power supply.

The machine will happily suspend with e.g. systemctrl suspend or via the DE sleep menu but whenever the power cable is connected it will wake up again immediately.
This is getting increasingly annoying as I started to use a docking station where I have to undock, suspend and wait for it to complete before docking in again.

Long story short, I have read up and down the internet, and there are many with similar issues, but all the answers are based on finding out which devices is blocking the suspension and then fix this part.
Usual suspects seem to be USB ports, but for me it doesn’t matter if I got some devices attached or not, and I can’t find anything meaningful to me in the logs.

Hence I thought I’d check here if someone has got additional thoughts.

Here’s what I have done so far:

  • pm-utils installed

  • ran systemctl suspend or from Plasma UI as root or user: works reliably w/o power, fails reliably with power connected.

  • Disabled all wakeup sources except the power button in /proc/acpi/wakeup via echo LID0 > /proc/acpi/wakeup
    Assuming that “PBTN” is the power button?
    No effect.

  • Ran PM_DEBUG=true pm-suspend with power cable plugged in and w/o and compared the logs
    The logs are identical up to the last line (#2939) of the failing log, no obvious error in the last lines.
    I added the dashlines for readability.
    Last entries of the failing log:

+ remove_suspend_lock
+ release_lock pm-suspend.lock
+ local lock=/var/run/pm-utils/locks/pm-suspend.lock
+ rm -f /var/run/pm-utils/locks/pm-suspend.lock
+ return 0

Working log (w/o power):


+ remove_suspend_lock
+ release_lock pm-suspend.lock
+ local lock=/var/run/pm-utils/locks/pm-suspend.lock
+ rm -f /var/run/pm-utils/locks/pm-suspend.lock
+ return 0
--------------------------------------
+ log 'Initial commandline parameters: '
+ is_set true
+ case ${1-UNSET} in
+ return 0
+ local 'fmt=%s\n'
+ '[' 'Initial commandline parameters: ' = -n ']'
+ printf '%s\n' 'Initial commandline parameters: '
Initial commandline parameters: 
+ load_hook_blacklist
+ '[' '' ']'
+ return
....lots of additional entries...

DMESG -T shows a succesful suspenion and then wakes up right away again
Failing:

[Fri Aug  9 11:43:38 2019] PM: suspend entry (deep)
[Fri Aug  9 11:43:38 2019] Filesystems sync: 0.008 seconds
[Fri Aug  9 11:43:38 2019] Freezing user space processes ... (elapsed 0.002 seconds) done.
[Fri Aug  9 11:43:38 2019] OOM killer disabled.
[Fri Aug  9 11:43:38 2019] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
[Fri Aug  9 11:43:38 2019] printk: Suspending console(s) (use no_console_suspend to debug)
[Fri Aug  9 11:43:38 2019] wlp2s0: deauthenticating from 2e:30:33:d9:6c:51 by local choice (Reason: 3=DEAUTH_LEAVING)
[Fri Aug  9 11:43:38 2019] sd 3:0:0:0: [sda] Synchronizing SCSI cache
[Fri Aug  9 11:43:38 2019] sd 3:0:0:0: [sda] Stopping disk
[Fri Aug  9 11:43:38 2019] e1000e: EEE TX LPI TIMER: 00000011
[Fri Aug  9 11:43:38 2019] ACPI: EC: interrupt blocked
[Fri Aug  9 11:43:38 2019] ACPI: Preparing to enter system sleep state S3
[Fri Aug  9 11:43:38 2019] ACPI: EC: event blocked
[Fri Aug  9 11:43:38 2019] ACPI: EC: EC stopped
[Fri Aug  9 11:43:38 2019] PM: Saving platform NVS memory
[Fri Aug  9 11:43:38 2019] Disabling non-boot CPUs ...
[Fri Aug  9 11:43:38 2019] smpboot: CPU 1 is now offline
[Fri Aug  9 11:43:38 2019] smpboot: CPU 2 is now offline
[Fri Aug  9 11:43:38 2019] smpboot: CPU 3 is now offline
[Fri Aug  9 11:43:38 2019] smpboot: CPU 4 is now offline
[Fri Aug  9 11:43:38 2019] smpboot: CPU 5 is now offline
[Fri Aug  9 11:43:38 2019] smpboot: CPU 6 is now offline
[Fri Aug  9 11:43:38 2019] smpboot: CPU 7 is now offline
--------------------------------
[Fri Aug  9 11:43:38 2019] ACPI: Low-level resume complete
[Fri Aug  9 11:43:38 2019] ACPI: EC: EC started
[Fri Aug  9 11:43:38 2019] PM: Restoring platform NVS memory
[Fri Aug  9 11:43:38 2019] Enabling non-boot CPUs ...
[Fri Aug  9 11:43:38 2019] x86: Booting SMP configuration:
[Fri Aug  9 11:43:38 2019] smpboot: Booting Node 0 Processor 1 APIC 0x2
[Fri Aug  9 11:43:38 2019] CPU1 is up
[Fri Aug  9 11:43:38 2019] smpboot: Booting Node 0 Processor 2 APIC 0x4
[Fri Aug  9 11:43:38 2019] CPU2 is up
[Fri Aug  9 11:43:38 2019] smpboot: Booting Node 0 Processor 3 APIC 0x6
[Fri Aug  9 11:43:38 2019] CPU3 is up
[Fri Aug  9 11:43:38 2019] smpboot: Booting Node 0 Processor 4 APIC 0x1
[Fri Aug  9 11:43:38 2019] CPU4 is up
[Fri Aug  9 11:43:38 2019] smpboot: Booting Node 0 Processor 5 APIC 0x3
[Fri Aug  9 11:43:38 2019] CPU5 is up
[Fri Aug  9 11:43:38 2019] smpboot: Booting Node 0 Processor 6 APIC 0x5
[Fri Aug  9 11:43:38 2019] CPU6 is up
[Fri Aug  9 11:43:38 2019] smpboot: Booting Node 0 Processor 7 APIC 0x7
[Fri Aug  9 11:43:38 2019] CPU7 is up
[Fri Aug  9 11:43:38 2019] ACPI: Waking up from system sleep state S3
[Fri Aug  9 11:43:39 2019] ACPI: EC: interrupt unblocked
[Fri Aug  9 11:43:40 2019] ACPI: EC: event unblocked
[Fri Aug  9 11:43:40 2019] usb usb1: root hub lost power or was reset
[Fri Aug  9 11:43:40 2019] usb usb2: root hub lost power or was reset
[Fri Aug  9 11:43:40 2019] sd 3:0:0:0: [sda] Starting disk
[Fri Aug  9 11:43:40 2019] tpm tpm0: tpm_try_transmit: send(): error -5
[Fri Aug  9 11:43:40 2019] nvme nvme0: 8/0/0 default/read/poll queues
[Fri Aug  9 11:43:40 2019] usb 1-11: reset high-speed USB device number 5 using xhci_hcd
[Fri Aug  9 11:43:40 2019] ata2: SATA link down (SStatus 0 SControl 300)
[Fri Aug  9 11:43:40 2019] ata5: SATA link down (SStatus 4 SControl 300)
[Fri Aug  9 11:43:40 2019] ata4: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[Fri Aug  9 11:43:41 2019] ata4.00: configured for UDMA/133
[Fri Aug  9 11:43:41 2019] usb 1-10: reset full-speed USB device number 4 using xhci_hcd
[Fri Aug  9 11:43:41 2019] OOM killer enabled.
[Fri Aug  9 11:43:41 2019] Restarting tasks ... done.
[Fri Aug  9 11:43:41 2019] acpi PNP0401:00: Already enumerated
[Fri Aug  9 11:43:41 2019] acpi PNP0501:00: Still not present
[Fri Aug  9 11:43:41 2019] PM: suspend exit

The timestamps below are a bit missleading but I guess that’s due to the fact that right after the wakeup the system is still operating with the time when the machine went to sleep?
Working (w/o power):

[Fri Aug  9 12:30:34 2019] PM: suspend entry (deep)
[Fri Aug  9 12:30:34 2019] Filesystems sync: 0.064 seconds
[Fri Aug  9 12:30:36 2019] Freezing user space processes ... (elapsed 0.004 seconds) done.
[Fri Aug  9 12:30:36 2019] OOM killer disabled.
[Fri Aug  9 12:30:36 2019] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
[Fri Aug  9 12:30:36 2019] printk: Suspending console(s) (use no_console_suspend to debug)
[Fri Aug  9 12:30:36 2019] wlp2s0: deauthenticating from 2e:30:33:d9:6c:51 by local choice (Reason: 3=DEAUTH_LEAVING)
[Fri Aug  9 12:30:36 2019] sd 3:0:0:0: [sda] Synchronizing SCSI cache
[Fri Aug  9 12:30:36 2019] sd 3:0:0:0: [sda] Stopping disk
[Fri Aug  9 12:30:36 2019] e1000e: EEE TX LPI TIMER: 00000011
[Fri Aug  9 12:30:36 2019] ACPI: EC: interrupt blocked
[Fri Aug  9 12:30:36 2019] ACPI: Preparing to enter system sleep state S3
[Fri Aug  9 12:30:36 2019] ACPI: EC: event blocked
[Fri Aug  9 12:30:36 2019] ACPI: EC: EC stopped
[Fri Aug  9 12:30:36 2019] PM: Saving platform NVS memory
[Fri Aug  9 12:30:36 2019] Disabling non-boot CPUs ...
[Fri Aug  9 12:30:36 2019] smpboot: CPU 1 is now offline
[Fri Aug  9 12:30:36 2019] smpboot: CPU 2 is now offline
[Fri Aug  9 12:30:36 2019] smpboot: CPU 3 is now offline
[Fri Aug  9 12:30:36 2019] smpboot: CPU 4 is now offline
[Fri Aug  9 12:30:36 2019] smpboot: CPU 5 is now offline
[Fri Aug  9 12:30:36 2019] smpboot: CPU 6 is now offline
[Fri Aug  9 12:30:36 2019] smpboot: CPU 7 is now offline
---------------------------------------------------------------- ?
[Fri Aug  9 12:30:36 2019] ACPI: Low-level resume complete
[Fri Aug  9 12:30:36 2019] ACPI: EC: EC started
[Fri Aug  9 12:30:36 2019] PM: Restoring platform NVS memory
[Fri Aug  9 12:30:36 2019] Enabling non-boot CPUs ...
[Fri Aug  9 12:30:36 2019] x86: Booting SMP configuration:
[Fri Aug  9 12:30:36 2019] smpboot: Booting Node 0 Processor 1 APIC 0x2
[Fri Aug  9 12:30:36 2019] CPU1 is up
[Fri Aug  9 12:30:36 2019] smpboot: Booting Node 0 Processor 2 APIC 0x4
[Fri Aug  9 12:30:36 2019] CPU2 is up
[Fri Aug  9 12:30:36 2019] smpboot: Booting Node 0 Processor 3 APIC 0x6
[Fri Aug  9 12:30:36 2019] CPU3 is up
[Fri Aug  9 12:30:36 2019] smpboot: Booting Node 0 Processor 4 APIC 0x1
[Fri Aug  9 12:30:36 2019] CPU4 is up
[Fri Aug  9 12:30:36 2019] smpboot: Booting Node 0 Processor 5 APIC 0x3
[Fri Aug  9 12:30:36 2019] CPU5 is up
[Fri Aug  9 12:30:36 2019] smpboot: Booting Node 0 Processor 6 APIC 0x5
[Fri Aug  9 12:30:36 2019] CPU6 is up
[Fri Aug  9 12:30:36 2019] smpboot: Booting Node 0 Processor 7 APIC 0x7
[Fri Aug  9 12:30:36 2019] CPU7 is up
[Fri Aug  9 12:30:36 2019] ACPI: Waking up from system sleep state S3
[Fri Aug  9 12:30:36 2019] ACPI: EC: interrupt unblocked
[Fri Aug  9 12:30:38 2019] usb usb1: root hub lost power or was reset
[Fri Aug  9 12:30:38 2019] usb usb2: root hub lost power or was reset
[Fri Aug  9 12:30:38 2019] ACPI: EC: event unblocked
[Fri Aug  9 12:30:38 2019] sd 3:0:0:0: [sda] Starting disk
[Fri Aug  9 12:30:38 2019] tpm tpm0: tpm_try_transmit: send(): error -5
[Fri Aug  9 12:30:38 2019] nvme nvme0: 8/0/0 default/read/poll queues
[Fri Aug  9 12:30:38 2019] usb 1-11: reset high-speed USB device number 5 using xhci_hcd
[Fri Aug  9 12:30:38 2019] ata4: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
[Fri Aug  9 12:30:38 2019] ata2: SATA link down (SStatus 0 SControl 300)
[Fri Aug  9 12:30:38 2019] ata5: SATA link down (SStatus 4 SControl 300)
[Fri Aug  9 12:30:38 2019] ata4.00: configured for UDMA/133
[Fri Aug  9 12:30:38 2019] usb 1-10: reset full-speed USB device number 4 using xhci_hcd
[Fri Aug  9 12:30:39 2019] OOM killer enabled.
[Fri Aug  9 12:30:39 2019] Restarting tasks ... 
[Fri Aug  9 12:30:39 2019] acpi PNP0401:00: Already enumerated
[Fri Aug  9 12:30:39 2019] done.
[Fri Aug  9 12:30:39 2019] acpi PNP0501:00: Still not present
[Fri Aug  9 12:30:39 2019] PM: suspend exit

Also tried a few non Arch specific ones, just in case
/etc/pm/config.d/usb_suspend_workaround as per https://bugs.launchpad.net/ubuntu/+source/linux/+bug/291300, didn’t work

Any ideas on where to look next?

@TomZ

Many times having TLP installed brings those problems, if so try uninstalling it.

You can also see here https://bbs.archlinux.org/viewtopic.php?id=214160

Thanks judd, it wasn’t TLP by the look of it because I didn’t have it installed.
And when trying to install I was told that I can only have either one…so I went ahead and installed TLP and removed pm-utils, but unfortunately no luck. Same behaviour…

sudo pacman -S tlp
resolving dependencies...
looking for conflicting packages...
:: tlp and pm-utils are in conflict. Remove pm-utils? [y/N] y

Packages (3) iw-5.3-1  pm-utils-1.4.1-8 [removal]  tlp-1.2.2-1

@TomZ

In certain cases, what for some does not work, for others it does. Since they say there to disable it (TLP) for the suspension to work (personally I never had problems)

Have you configured and enabled TLP correctly?
Well, the wiki says everything you need to do: https://wiki.archlinux.org/index.php/TLP

https://bbs.archlinux.org/viewtopic.php?id=223698
to complete…

Thanks for clarifying Joe. Looks like I was on the wrong path with pm-utils.

But it’s gone now, replaced by TLP, and when I use systemctl suspend now, it shows the same behaviour:
Stays suspended w/o power, and restarts immedeatly with power plugged in.

isn’t it logind handle this actions?
Power_management_with_systemd

That is a great post, I will need some time to work through…will report back!
Thanks again…

i was fighting with this too here to get a nice config work for XFCE4, and xfce4 is bringing in lot of oldshool stuff here too :wink:

Well, I spent a few more hours with this subject, configured TLP to the best of my knowledge @judd but unfortunately nothing would change the situation.
However, right now I am getting an error, too fast for my eyes and my camera but a video did the trick.

tpm tpm0: tpm_try_transmit: send(): error -5

And when looking for this error I found this one here: https://lkml.org/lkml/2019/3/18/1123
Now, that looks almost exactly like my issue, except I use different kernels and don’t get the error in dmesg.

So my conclusion is that I am dealing with a kernel issue which is way beyond my ability to solve.
I will hence give up on this for now, what would you guys recommend I do with this? Follow a thread somewhere to find out if and when the issue was solved? Should I add my case to this one somewhere?

LTS Kernel tested?

sudo pacman -S linux-lts linux-lts-headers
sudo grub-mkconfig -o /boot/grub/grub.cfg

reboot choose LTS kernel from grub boot menu and see if it change anything…

I installed the lts kernel a while back but the boot process gets stuck right before the graphical environment gets launched. Didn’t spend the time yet to troubleshoot this one. But I should be able to test the suspend issue from a tty I guess.
I’ll try and update this post…

Edit:
Not working either, the only exception is that the tty stays blank once the machine starts again.

Can you provide bootlog and systemspecs?

Absolutely, showing data for the LTS kernel or the current 5.2.8 one?

Here’s my inxi:

thomas@hermes:~$ inxi -Fxxc0
System:    Host: hermes Kernel: 5.2.8-arch1-1-ARCH x86_64 bits: 64 compiler: gcc v: 9.1.0 Desktop: KDE Plasma 5.16.4 
           tk: Qt 5.13.0 wm: kwin_x11 dm: SDDM Distro: Arch Linux 
Machine:   Type: Laptop System: Dell product: Precision 7510 v: N/A serial: <root required> Chassis: type: 9 
           serial: <root required> 
           Mobo: Dell model: 0M1YNP v: A00 serial: <root required> UEFI: Dell v: 1.17.7 date: 05/20/2019 
Battery:   ID-1: BAT0 charge: 53.2 Wh condition: 65.9/91.0 Wh (72%) volts: 11.8/11.4 model: LGC-LGC3.975 DELL RDYCT71 
           serial: 46146 status: Discharging 
CPU:       Topology: Quad Core model: Intel Core i7-6920HQ bits: 64 type: MT MCP arch: Skylake-S rev: 3 L2 cache: 8192 KiB 
           flags: avx avx2 lm nx pae sse sse2 sse3 sse4_1 sse4_2 ssse3 vmx bogomips: 46480 
           Speed: 800 MHz min/max: 800/3800 MHz Core speeds (MHz): 1: 801 2: 800 3: 800 4: 800 5: 800 6: 800 7: 800 8: 800 
Graphics:  Device-1: NVIDIA GM107GLM [Quadro M1000M] vendor: Dell driver: nvidia v: 430.40 bus ID: 01:00.0 chip ID: 10de:13b1 
           Display: x11 server: X.Org 1.20.5 driver: nvidia compositor: kwin_x11 resolution: 1920x1080~60Hz 
           Message: Unable to show advanced data. Required tool glxinfo missing. 
Audio:     Device-1: Intel 100 Series/C230 Series Family HD Audio vendor: Dell driver: snd_hda_intel v: kernel bus ID: 00:1f.3 
           chip ID: 8086:a170 
           Device-2: NVIDIA vendor: Dell driver: snd_hda_intel v: kernel bus ID: 01:00.1 chip ID: 10de:0fbc 
           Sound Server: ALSA v: k5.2.8-arch1-1-ARCH 
Network:   Device-1: Intel Ethernet I219-LM vendor: Dell driver: e1000e v: 3.2.6-k port: f000 bus ID: 00:1f.6 
           chip ID: 8086:15b7 
           IF: enp0s31f6 state: down mac: d4:81:d7:90:9f:c6 
           Device-2: Intel Wireless 8260 driver: iwlwifi v: kernel port: e000 bus ID: 02:00.0 chip ID: 8086:24f3 
           IF: wlp2s0 state: up mac: 28:16:ad:52:c8:12 
Drives:    Local Storage: total: 2.29 TiB used: 1.82 TiB (79.8%) 
           ID-1: /dev/nvme0n1 vendor: Toshiba model: KXG60ZNV512G NVMe 512GB size: 476.94 GiB speed: 31.6 Gb/s lanes: 4 
           serial: Y8MS107KTHBQ temp: 33 C 
           ID-2: /dev/sda vendor: Seagate model: ST2000LM015-2E8174 size: 1.82 TiB speed: 6.0 Gb/s serial: ZDZ3YYES 
Partition: ID-1: / size: 476.42 GiB used: 332.69 GiB (69.8%) fs: btrfs dev: /dev/dm-0 
           ID-2: /boot size: 510.7 MiB used: 54.9 MiB (10.8%) fs: vfat dev: /dev/nvme0n1p1 
           ID-3: /home size: 476.42 GiB used: 332.69 GiB (69.8%) fs: btrfs dev: /dev/dm-0 
           ID-4: /var size: 476.42 GiB used: 332.69 GiB (69.8%) fs: btrfs dev: /dev/dm-0 
Sensors:   System Temperatures: cpu: 43.5 C mobo: N/A gpu: nvidia temp: 44 C 
           Fan Speeds (RPM): cpu: 1999 fan-2: 2115 
Info:      Processes: 288 Uptime: 6m Memory: 31.35 GiB used: 2.43 GiB (7.8%) Init: systemd v: 242 Compilers: gcc: 9.1.0 
           Shell: bash v: 5.0.7 running in: konsole inxi: 3.0.35 

Try to check your bios and disable HT (hyperthreading) and options that are related to memory (oc, memory hole, interleaving and so on

Intel Hyperthreading on Skylake seems to cause such issues…

Disabled HT, unfortunately still no luck.
Here’s my boot log: http://dpaste.com//3B1WCN8

Aug 12 18:49:14 hermes kernel: acpi PNP0A08:00: _OSC: OS supports [ExtendedConfig ASPM ClockPM Segments MSI HPX-Type3]
Aug 12 18:49:14 hermes kernel: acpi PNP0A08:00: _OSC failed (AE_ERROR); disabling ASPM

Aug 12 18:50:36 hermes org_kde_powerdevil[1951]: powerdevil: Can't contact ck

may related but i have no idea at the moment.

also lot of unhandled device action "bind" in different ways may link to something misconfigured…

Ah, the kde _powerdevil one is probably a leftover from when Powerdevil was installed and KDE tried to pull it’s data in?
Yes, I am at a loss myself. But thanks for your help, really appreciated! I think I will leave this for now, already spent too much time with this…