Arch Linux

abraxas-von-abrasax

Member

Registered: 2017-08-05

Posts: 1

systemd: suspend-to-hibernate.service with curious behavior

Hi, folks! Sorry for my language: this is my first post in this forum.

I have been using the wiki's suspend-to-hibernate.service for a couple of years now and everything worked fine until a month ago, when it began to behave very oddly. The issue: My laptop awakes from suspension as expected after the specified period of time but does not hibernate. However, if I manually stop the service (via sudo systemctl stop suspend-to-hibernate.service) it eventually enters hibernation.

Does anyone have a clue how to fix this issue?

Note:

• I'm using the appropriate kernel parameter (resume=/dev/sda2)

• I'm using the resume hook in my initramfs (HOOKS="base udev resume autodetect modconf block filesystems keyboard fsck")

• I copied /usr/lib/systemd/system/suspend.target to /etc/systemd/system/ and added the line: Requires=suspend-to-hibernate.service

Here my journalctl's output (created with journalctl -r):

First of all, here you can see that the delayed hibernation has been triggered by the laptop suspension. However, after its wake-up there seems to be a dependency issue (I don't know whether this is related to the delayed hibernation trigger's malfunction):

Aug 05 15:36:32 abraxas-base systemd[1]: suspend.target: Job suspend.target/start failed with result 'dependency'.
Aug 05 15:36:32 abraxas-base systemd-logind[257]: Operation 'sleep' finished.
Aug 05 15:36:32 abraxas-base systemd[1]: Dependency failed for Suspend.
Aug 05 15:36:32 abraxas-base systemd[1]: suspend.target: Bound to unit systemd-suspend.service, but unit isn't active.
Aug 05 15:36:32 abraxas-base systemd[1]: Started Suspend.
Aug 05 15:36:32 abraxas-base systemd-sleep[2147]: System resumed.
Aug 05 15:36:32 abraxas-base systemd[1]: Started Load/Save RF Kill Switch Status.
Aug 05 15:36:32 abraxas-base ntpd[283]: Deleting interface #5 wlp2s0, fe80::7bc2:89d4:2f7:607f%2#123, interface stats: received=0, sent=0, dropped=0, active_time=432 secs
Aug 05 15:36:32 abraxas-base ntpd[283]: 185.144.161.170 local addr 10.0.0.23 -> <null>
Aug 05 15:36:32 abraxas-base ntpd[283]: 92.63.212.161 local addr 10.0.0.23 -> <null>
Aug 05 15:36:32 abraxas-base ntpd[283]: 216.229.0.50 local addr 10.0.0.23 -> <null>
Aug 05 15:36:32 abraxas-base ntpd[283]: 91.206.8.36 local addr 10.0.0.23 -> <null>
Aug 05 15:36:32 abraxas-base systemd[1]: Starting Load/Save RF Kill Switch Status...
Aug 05 15:36:32 abraxas-base wpa_supplicant[292]: nl80211: deinit ifname=wlp2s0 disabled_11b_rates=0
Aug 05 15:36:32 abraxas-base ntpd[283]: Deleting interface #4 wlp2s0, 10.0.0.23#123, interface stats: received=28, sent=28, dropped=0, active_time=432 secs
Aug 05 15:36:32 abraxas-base plasmashell[436]: Time engine Clock skew signaled
Aug 05 15:36:32 abraxas-base kernel: Bluetooth: hci0: Intel Bluetooth firmware file: intel/ibt-hw-37.7.10-fw-1.80.2.3.d.bseq
Aug 05 15:36:32 abraxas-base kernel: Bluetooth: hci0: read Intel version: 370710018002030d00
Aug 05 15:36:32 abraxas-base kernel: done.
Aug 05 15:36:32 abraxas-base kernel: pci_bus 0000:03: Allocating resources
Aug 05 15:36:32 abraxas-base kernel: pci_bus 0000:02: Allocating resources
Aug 05 15:36:32 abraxas-base kernel: pci_bus 0000:01: Allocating resources
Aug 05 15:36:32 abraxas-base kernel: pci_bus 0000:03: Allocating resources
Aug 05 15:36:32 abraxas-base kernel: pci_bus 0000:02: Allocating resources
Aug 05 15:36:32 abraxas-base kernel: pci_bus 0000:01: Allocating resources
Aug 05 15:36:32 abraxas-base kernel: Restarting tasks ... 
Aug 05 15:36:32 abraxas-base kernel: PM: Finishing wakeup.
Aug 05 15:36:32 abraxas-base kernel: usb 2-6:1.1: rebind failed: -517
Aug 05 15:36:32 abraxas-base kernel: usb 2-6:1.0: rebind failed: -517
Aug 05 15:36:32 abraxas-base kernel: PM: resume of devices complete after 879.135 msecs
Aug 05 15:36:32 abraxas-base kernel: usb 2-5: reset high-speed USB device number 2 using xhci_hcd
Aug 05 15:36:32 abraxas-base kernel: usb 2-6: reset full-speed USB device number 3 using xhci_hcd
Aug 05 15:36:32 abraxas-base kernel: ata2.00: configured for UDMA/133
Aug 05 15:36:32 abraxas-base kernel: ata2.00: disabling queued TRIM support
Aug 05 15:36:32 abraxas-base kernel: ata2.00: supports DRM functions and may not be fully accessible
Aug 05 15:36:32 abraxas-base kernel: ata2.00: disabling queued TRIM support
Aug 05 15:36:32 abraxas-base kernel: ata2.00: supports DRM functions and may not be fully accessible
Aug 05 15:36:32 abraxas-base kernel: ata2: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
Aug 05 15:36:32 abraxas-base kernel: xhci_hcd 0000:00:14.0: port 5 resume PLC timeout
Aug 05 15:36:32 abraxas-base kernel: rtc_cmos 00:01: System wakeup disabled by ACPI
Aug 05 15:36:32 abraxas-base kernel: sd 1:0:0:0: [sda] Starting disk
Aug 05 15:36:32 abraxas-base kernel: pciehp 0000:00:1c.3:pcie004: Slot(3): Link Down event ignored; already powering off
Aug 05 15:36:32 abraxas-base kernel: ACPI : EC: event unblocked
Aug 05 15:36:32 abraxas-base kernel: PM: early resume of devices complete after 0.651 msecs
Aug 05 15:36:32 abraxas-base kernel: pciehp 0000:00:1c.3:pcie004: Slot(3): Link Down
Aug 05 15:36:32 abraxas-base kernel: pciehp 0000:00:1c.3:pcie004: Slot(3): Card not present
Aug 05 15:36:32 abraxas-base kernel: PM: noirq resume of devices complete after 159.728 msecs
Aug 05 15:36:32 abraxas-base kernel: xhci_hcd 0000:00:14.0: System wakeup disabled by ACPI
Aug 05 15:36:32 abraxas-base kernel: ehci-pci 0000:00:1d.0: System wakeup disabled by ACPI
Aug 05 15:36:32 abraxas-base kernel: ACPI: Waking up from system sleep state S3
Aug 05 15:36:32 abraxas-base kernel: CPU3 is up
Aug 05 15:36:32 abraxas-base kernel:  cache: parent cpu3 should not be sleeping
Aug 05 15:36:32 abraxas-base kernel: smpboot: Booting Node 0 Processor 3 APIC 0x3
Aug 05 15:36:32 abraxas-base kernel: CPU2 is up
Aug 05 15:36:32 abraxas-base kernel:  cache: parent cpu2 should not be sleeping
Aug 05 15:36:32 abraxas-base kernel: smpboot: Booting Node 0 Processor 2 APIC 0x2
Aug 05 15:36:32 abraxas-base kernel: CPU1 is up
Aug 05 15:36:32 abraxas-base kernel:  cache: parent cpu1 should not be sleeping
Aug 05 15:36:32 abraxas-base kernel: smpboot: Booting Node 0 Processor 1 APIC 0x1
Aug 05 15:36:32 abraxas-base kernel: x86: Booting SMP configuration:
Aug 05 15:36:32 abraxas-base kernel: Enabling non-boot CPUs ...
Aug 05 15:36:32 abraxas-base kernel: mce: [Hardware Error]: Machine check events logged
Aug 05 15:36:32 abraxas-base kernel: Suspended for 7.960 seconds
Aug 05 15:36:32 abraxas-base kernel: PM: Restoring platform NVS memory
Aug 05 15:36:32 abraxas-base kernel: ACPI : EC: EC started
Aug 05 15:36:32 abraxas-base kernel: ACPI: Low-level resume complete
Aug 05 15:36:32 abraxas-base kernel: smpboot: CPU 3 is now offline
Aug 05 15:36:32 abraxas-base kernel: smpboot: CPU 2 is now offline
Aug 05 15:36:32 abraxas-base kernel: smpboot: CPU 1 is now offline
Aug 05 15:36:32 abraxas-base kernel: Disabling non-boot CPUs ...
Aug 05 15:36:32 abraxas-base kernel: PM: Saving platform NVS memory
Aug 05 15:36:32 abraxas-base kernel: ACPI : EC: EC stopped
Aug 05 15:36:32 abraxas-base kernel: ACPI : EC: event blocked
Aug 05 15:36:32 abraxas-base kernel: ACPI: Preparing to enter system sleep state S3
Aug 05 15:36:32 abraxas-base kernel: PM: noirq suspend of devices complete after 30.447 msecs
Aug 05 15:36:32 abraxas-base kernel: xhci_hcd 0000:00:14.0: System wakeup enabled by ACPI
Aug 05 15:36:32 abraxas-base kernel: ehci-pci 0000:00:1d.0: System wakeup enabled by ACPI
Aug 05 15:36:32 abraxas-base kernel: PM: late suspend of devices complete after 28.124 msecs
Aug 05 15:36:32 abraxas-base kernel: PM: suspend of devices complete after 1481.979 msecs
Aug 05 15:36:32 abraxas-base kernel: sd 1:0:0:0: [sda] Stopping disk
Aug 05 15:36:32 abraxas-base kernel: sd 1:0:0:0: [sda] Synchronizing SCSI cache
Aug 05 15:36:32 abraxas-base kernel: Suspending console(s) (use no_console_suspend to debug)
Aug 05 15:36:32 abraxas-base kernel: PM: Suspending system (mem)
Aug 05 15:36:32 abraxas-base kernel: Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
Aug 05 15:36:32 abraxas-base kernel: Freezing user space processes ... (elapsed 0.037 seconds) done.
Aug 05 15:36:32 abraxas-base kernel: PM: Preparing system for sleep (mem)
Aug 05 15:36:32 abraxas-base kernel: PM: Syncing filesystems ... done.
Aug 05 15:36:21 abraxas-base systemd[1]: Started Delayed hibernation trigger.
Aug 05 15:36:21 abraxas-base sh[2148]: alarm set for 1501940191
Aug 05 15:36:21 abraxas-base systemd-sleep[2147]: Suspending system...
Aug 05 15:36:21 abraxas-base ksmserver[395]: CreateNotify: 106954770
Aug 05 15:36:21 abraxas-base systemd[1]: Starting Delayed hibernation trigger...
Aug 05 15:36:21 abraxas-base systemd[1]: Starting Suspend...

Here I manually stopped suspend-to-hibernate.service causing my laptop to hibernate immediately afterwards:

Aug 05 15:37:11 abraxas-base sh[2249]: hibernate triggered
Aug 05 15:37:11 abraxas-base systemd[1]: Stopping Delayed hibernation trigger...
Aug 05 15:37:11 abraxas-base sudo[2246]: pam_unix(sudo:session): session opened for user root by abraxas(uid=0)
Aug 05 15:37:11 abraxas-base sudo[2246]:  abraxas : TTY=pts/1 ; PWD=/etc/systemd/system ; USER=root ; COMMAND=/usr/bin/systemctl stop suspend-to-hibernate.service

Thanks in advance!

loqs

Member

Registered: 2014-03-06

Posts: 17,427

Re: systemd: suspend-to-hibernate.service with curious behavior

Welcome to the arch linux forums abraxas-von-abrasax.
https://github.com/systemd/systemd/issues/6419

solstice

Member

Registered: 2006-10-27

Posts: 235

Website

Re: systemd: suspend-to-hibernate.service with curious behavior

OK. I had the same issue and was about to post about it.

It was working fine for month, and it only recently that I noticed it breaked and does not hibernate like expected. I dind't see much in the log and the original poster found more thing than me, looking at the log.

I was assuming a systemd breakage. I was right. Thanks loqs