Bug 1275040 - sudo /usr/lib/systemd/systemd-sleep hybrid-sleep should suspend even if hibernate fails
sudo /usr/lib/systemd/systemd-sleep hybrid-sleep should suspend even if hiber...
Status: CLOSED NOTABUG
Product: Fedora
Classification: Fedora
Component: systemd (Show other bugs)
23
Unspecified Unspecified
unspecified Severity unspecified
: ---
: ---
Assigned To: systemd-maint
Fedora Extras Quality Assurance
:
Depends On:
Blocks:
  Show dependency treegraph
 
Reported: 2015-10-25 05:53 EDT by sandeep
Modified: 2015-10-26 05:51 EDT (History)
7 users (show)

See Also:
Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of:
Environment:
Last Closed: 2015-10-26 05:51:25 EDT
Type: Bug
Regression: ---
Mount Type: ---
Documentation: ---
CRM:
Verified Versions:
Category: ---
oVirt Team: ---
RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: ---


Attachments (Terms of Use)

  None (edit)
Description sandeep 2015-10-25 05:53:14 EDT
hibernate does not work on my laptop. However, Upower's  CriticalPowerAction only allows HybridSleep/Hibernate/Poweroff.  So HybridSleep should suspend even if hibernate fails. Because the alternative is that the laptop shuts down.


Running sudo /usr/lib/systemd/systemd-sleep hybrid-sleep gives me the following

Oct 25 13:42:01 localhost.localdomain sudo[5987]:     user : TTY=pts/0 ; PWD=/home/user ; USER=root ; COMMAND=/usr/lib/systemd/systemd-sleep --help
Oct 25 13:42:01 localhost.localdomain audit[5987]: USER_CMD pid=5987 uid=1000 auid=1000 ses=1 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='cwd="/home/user" c
Oct 25 13:42:01 localhost.localdomain audit[5987]: CRED_REFR pid=5987 uid=0 auid=1000 ses=1 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op=PAM:setcred grant
Oct 25 13:42:01 localhost.localdomain sudo[5987]: pam_systemd(sudo:session): Cannot create session: Already running in a session
Oct 25 13:42:01 localhost.localdomain sudo[5987]: pam_unix(sudo:session): session opened for user root by (uid=0)
Oct 25 13:42:01 localhost.localdomain audit[5987]: USER_START pid=5987 uid=0 auid=1000 ses=1 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op=PAM:session_open
Oct 25 13:42:01 localhost.localdomain sudo[5987]: pam_unix(sudo:session): session closed for user root
Oct 25 13:42:01 localhost.localdomain audit[5987]: USER_END pid=5987 uid=0 auid=1000 ses=1 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op=PAM:session_close 
Oct 25 13:42:01 localhost.localdomain audit[5987]: CRED_DISP pid=5987 uid=0 auid=1000 ses=1 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op=PAM:setcred grant
Oct 25 13:42:08 localhost.localdomain sudo[5995]:     user : TTY=pts/0 ; PWD=/home/user ; USER=root ; COMMAND=/usr/lib/systemd/systemd-sleep hybrid-sleep
Oct 25 13:42:08 localhost.localdomain audit[5995]: USER_CMD pid=5995 uid=1000 auid=1000 ses=1 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='cwd="/home/user" c
Oct 25 13:42:08 localhost.localdomain audit[5995]: CRED_REFR pid=5995 uid=0 auid=1000 ses=1 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op=PAM:setcred grant
Oct 25 13:42:08 localhost.localdomain sudo[5995]: pam_systemd(sudo:session): Cannot create session: Already running in a session
Oct 25 13:42:08 localhost.localdomain sudo[5995]: pam_unix(sudo:session): session opened for user root by (uid=0)
Oct 25 13:42:08 localhost.localdomain audit[5995]: USER_START pid=5995 uid=0 auid=1000 ses=1 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op=PAM:session_open
Oct 25 13:42:08 localhost.localdomain kernel: PM: Hibernation mode set to 'suspend'
Oct 25 13:42:10 localhost.localdomain kernel: PM: Syncing filesystems ... done.
Oct 25 13:42:10 localhost.localdomain kernel: Freezing user space processes ... (elapsed 0.002 seconds) done.
Oct 25 13:42:10 localhost.localdomain kernel: PM: Marking nosave pages: [mem 0x00000000-0x00000fff]
Oct 25 13:42:10 localhost.localdomain kernel: PM: Marking nosave pages: [mem 0x00090000-0x000fffff]
Oct 25 13:42:10 localhost.localdomain kernel: PM: Marking nosave pages: [mem 0x20000000-0x201fffff]
Oct 25 13:42:10 localhost.localdomain kernel: PM: Marking nosave pages: [mem 0x40004000-0x40004fff]
Oct 25 13:42:10 localhost.localdomain kernel: PM: Marking nosave pages: [mem 0xd2656000-0xd2656fff]
Oct 25 13:42:10 localhost.localdomain kernel: PM: Marking nosave pages: [mem 0xd2666000-0xd2666fff]
Oct 25 13:42:10 localhost.localdomain kernel: PM: Marking nosave pages: [mem 0xd29af000-0xd2bb0fff]
Oct 25 13:42:10 localhost.localdomain kernel: PM: Marking nosave pages: [mem 0xd7f9f000-0xdabfefff]
Oct 25 13:42:10 localhost.localdomain kernel: PM: Marking nosave pages: [mem 0xdac00000-0xffffffff]
Oct 25 13:42:10 localhost.localdomain kernel: PM: Basic memory bitmaps created
Oct 25 13:42:10 localhost.localdomain kernel: PM: Preallocating image memory... 
Oct 25 13:42:10 localhost.localdomain kernel: PM: Basic memory bitmaps freed
Oct 25 13:42:10 localhost.localdomain kernel: Restarting tasks ... done.
Oct 25 13:42:10 localhost.localdomain kernel: video LNXVIDEO:00: Restoring backlight state
Oct 25 13:42:10 localhost.localdomain sudo[5995]: pam_unix(sudo:session): session closed for user root
Oct 25 13:42:10 localhost.localdomain audit[5995]: USER_END pid=5995 uid=0 auid=1000 ses=1 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op=PAM:session_close 
Oct 25 13:42:10 localhost.localdomain audit[5995]: CRED_DISP pid=5995 uid=0 auid=1000 ses=1 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op=PAM:setcred grant
lines 1411-1451/1451 (END)


However, running sudo /usr/lib/systemd/systemd-sleep suspend gives


Oct 25 13:44:50 localhost.localdomain sudo[6152]:     user : TTY=pts/0 ; PWD=/home/user ; USER=root ; COMMAND=/usr/lib/systemd/systemd-sleep suspend
Oct 25 13:44:50 localhost.localdomain audit[6152]: USER_CMD pid=6152 uid=1000 auid=1000 ses=1 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='cwd="/home/user" c
Oct 25 13:44:50 localhost.localdomain audit[6152]: CRED_REFR pid=6152 uid=0 auid=1000 ses=1 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op=PAM:setcred grant
Oct 25 13:44:50 localhost.localdomain sudo[6152]: pam_systemd(sudo:session): Cannot create session: Already running in a session
Oct 25 13:44:50 localhost.localdomain sudo[6152]: pam_unix(sudo:session): session opened for user root by (uid=0)
Oct 25 13:44:50 localhost.localdomain audit[6152]: USER_START pid=6152 uid=0 auid=1000 ses=1 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op=PAM:session_open
Oct 25 13:44:50 localhost.localdomain kernel: PM: Syncing filesystems ... done.
Oct 25 13:44:50 localhost.localdomain kernel: PM: Preparing system for sleep (mem)
Oct 25 13:44:53 localhost.localdomain kernel: Freezing user space processes ... (elapsed 0.002 seconds) done.
Oct 25 13:44:53 localhost.localdomain kernel: Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
Oct 25 13:44:54 localhost.localdomain kernel: PM: Suspending system (mem)
Oct 25 13:44:54 localhost.localdomain kernel: Suspending console(s) (use no_console_suspend to debug)
Oct 25 13:44:54 localhost.localdomain kernel: wlp3s0: deauthenticating from 64:66:b3:2b:69:9e by local choice (Reason: 3=DEAUTH_LEAVING)
Oct 25 13:44:54 localhost.localdomain kernel: sd 0:0:0:0: [sda] Synchronizing SCSI cache
Oct 25 13:44:54 localhost.localdomain kernel: sd 0:0:0:0: [sda] Stopping disk
Oct 25 13:44:54 localhost.localdomain kernel: e1000e: EEE TX LPI TIMER: 00000011
Oct 25 13:44:54 localhost.localdomain kernel: PM: suspend of devices complete after 1210.857 msecs
Oct 25 13:44:54 localhost.localdomain kernel: PM: late suspend of devices complete after 11.007 msecs
Oct 25 13:44:54 localhost.localdomain kernel: ehci-pci 0000:00:1d.0: System wakeup enabled by ACPI
Oct 25 13:44:54 localhost.localdomain kernel: ehci-pci 0000:00:1a.0: System wakeup enabled by ACPI
Oct 25 13:44:54 localhost.localdomain kernel: e1000e 0000:00:19.0: System wakeup enabled by ACPI
Oct 25 13:44:54 localhost.localdomain kernel: xhci_hcd 0000:00:14.0: System wakeup enabled by ACPI
Oct 25 13:44:54 localhost.localdomain kernel: PM: noirq suspend of devices complete after 14.214 msecs
Oct 25 13:44:54 localhost.localdomain kernel: ACPI: Preparing to enter system sleep state S3
Oct 25 13:44:54 localhost.localdomain kernel: ACPI : EC: EC stopped
Oct 25 13:44:54 localhost.localdomain kernel: PM: Saving platform NVS memory
Oct 25 13:44:54 localhost.localdomain kernel: Disabling non-boot CPUs ...
Oct 25 13:44:54 localhost.localdomain kernel: smpboot: CPU 1 is now offline
Oct 25 13:44:54 localhost.localdomain kernel: smpboot: CPU 2 is now offline
Oct 25 13:44:54 localhost.localdomain kernel: smpboot: CPU 3 is now offline
Oct 25 13:44:54 localhost.localdomain kernel: ACPI: Low-level resume complete
Oct 25 13:44:54 localhost.localdomain kernel: ACPI : EC: EC started
Oct 25 13:44:54 localhost.localdomain kernel: PM: Restoring platform NVS memory
Oct 25 13:44:54 localhost.localdomain kernel: microcode: CPU0 microcode updated early to revision 0x1b, date = 2014-05-29
Oct 25 13:44:54 localhost.localdomain kernel: Enabling non-boot CPUs ...
Oct 25 13:44:54 localhost.localdomain kernel: x86: Booting SMP configuration:
Oct 25 13:44:54 localhost.localdomain kernel: smpboot: Booting Node 0 Processor 1 APIC 0x1
Oct 25 13:44:54 localhost.localdomain kernel:  cache: parent cpu1 should not be sleeping
Oct 25 13:44:54 localhost.localdomain kernel: CPU1 is up
Oct 25 13:44:54 localhost.localdomain kernel: smpboot: Booting Node 0 Processor 2 APIC 0x2
Oct 25 13:44:54 localhost.localdomain kernel: microcode: CPU2 microcode updated early to revision 0x1b, date = 2014-05-29
Oct 25 13:44:54 localhost.localdomain kernel:  cache: parent cpu2 should not be sleeping
Oct 25 13:44:54 localhost.localdomain kernel: CPU2 is up
Oct 25 13:44:54 localhost.localdomain kernel: smpboot: Booting Node 0 Processor 3 APIC 0x3
Oct 25 13:44:54 localhost.localdomain kernel:  cache: parent cpu3 should not be sleeping
Oct 25 13:44:54 localhost.localdomain kernel: CPU3 is up
Oct 25 13:44:54 localhost.localdomain kernel: ACPI: Waking up from system sleep state S3
Oct 25 13:44:54 localhost.localdomain kernel: sdhci-pci 0000:04:00.0: MMC controller base frequency changed to 50Mhz.
Oct 25 13:44:54 localhost.localdomain kernel: ehci-pci 0000:00:1a.0: System wakeup disabled by ACPI
Oct 25 13:44:54 localhost.localdomain kernel: ehci-pci 0000:00:1d.0: System wakeup disabled by ACPI
Oct 25 13:44:54 localhost.localdomain kernel: xhci_hcd 0000:00:14.0: System wakeup disabled by ACPI
Oct 25 13:44:54 localhost.localdomain kernel: PM: noirq resume of devices complete after 18.114 msecs
Oct 25 13:44:54 localhost.localdomain kernel: PM: early resume of devices complete after 0.356 msecs
Oct 25 13:44:54 localhost.localdomain kernel: e1000e 0000:00:19.0: System wakeup disabled by ACPI
Oct 25 13:44:54 localhost.localdomain kernel: rtc_cmos 00:02: System wakeup disabled by ACPI
Oct 25 13:44:55 localhost.localdomain kernel: sd 0:0:0:0: [sda] Starting disk
Oct 25 13:44:55 localhost.localdomain kernel: usb 3-1.6: reset high-speed USB device number 4 using ehci-pci
Oct 25 13:44:55 localhost.localdomain kernel: ata3: SATA link down (SStatus 0 SControl 330)
Oct 25 13:44:55 localhost.localdomain kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Disabled
Oct 25 13:44:55 localhost.localdomain kernel: iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
Oct 25 13:44:55 localhost.localdomain kernel: psmouse serio1: synaptics: queried max coordinates: x [..5470], y [..4498]
Oct 25 13:44:55 localhost.localdomain kernel: iwlwifi 0000:03:00.0: L1 Enabled - LTR Disabled
Oct 25 13:44:55 localhost.localdomain kernel: iwlwifi 0000:03:00.0: Radio type=0x1-0x2-0x0
Oct 25 13:44:55 localhost.localdomain kernel: PM: resume of devices complete after 861.236 msecs
Oct 25 13:44:55 localhost.localdomain kernel: PM: Finishing wakeup.
Oct 25 13:44:55 localhost.localdomain kernel: Restarting tasks ... done.
Oct 25 13:44:55 localhost.localdomain kernel: video LNXVIDEO:00: Restoring backlight state
Oct 25 13:44:55 localhost.localdomain kernel: ata4: failed to resume link (SControl 30)
Oct 25 13:44:55 localhost.localdomain kernel: ata4: SATA link down (SStatus 4 SControl 30)
Oct 25 13:44:55 localhost.localdomain kernel: ata1.01: failed to resume link (SControl 0)
Oct 25 13:44:55 localhost.localdomain kernel: ata2.01: failed to resume link (SControl 0)
Oct 25 13:44:55 localhost.localdomain kernel: ata2.00: SATA link down (SStatus 0 SControl 330)
Oct 25 13:44:55 localhost.localdomain kernel: ata2.01: SATA link down (SStatus 0 SControl 0)
Oct 25 13:44:55 localhost.localdomain kernel: ata1.00: SATA link up 6.0 Gbps (SStatus 133 SControl 330)
Oct 25 13:44:55 localhost.localdomain kernel: ata1.01: SATA link down (SStatus 0 SControl 0)
Oct 25 13:44:55 localhost.localdomain kernel: ata1.00: ACPI cmd ef/02:00:00:00:00:a0 (SET FEATURES) succeeded
Oct 25 13:44:55 localhost.localdomain kernel: ata1.00: ACPI cmd f5/00:00:00:00:00:a0 (SECURITY FREEZE LOCK) filtered out
Oct 25 13:44:55 localhost.localdomain kernel: ata1.00: ACPI cmd ef/03:45:00:00:00:a0 (SET FEATURES) filtered out
Oct 25 13:44:55 localhost.localdomain kernel: ata1.00: ACPI cmd ef/03:0c:00:00:00:a0 (SET FEATURES) filtered out
Oct 25 13:44:55 localhost.localdomain kernel: ata1.00: configured for UDMA/133
Oct 25 13:44:55 localhost.localdomain kernel: ata1.00: Enabling discard_zeroes_data
Oct 25 13:44:53 localhost.localdomain systemd[1]: Time has been changed
-- Subject: Time change
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- The system clock has been changed to REALTIME microseconds after January 1st, 1970.
Oct 25 13:44:54 localhost.localdomain sudo[6152]: pam_unix(sudo:session): session closed for user root
Oct 25 13:44:54 localhost.localdomain audit[6152]: USER_END pid=6152 uid=0 auid=1000 ses=1 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op=PAM:session_close 
Oct 25 13:44:54 localhost.localdomain systemd[1887]: Time has been changed
-- Subject: Time change
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- The system clock has been changed to REALTIME microseconds after January 1st, 1970.
Oct 25 13:44:54 localhost.localdomain NetworkManager[1028]: <warn>  Connection disconnected (reason -3)
Oct 25 13:44:54 localhost.localdomain audit[6152]: CRED_DISP pid=6152 uid=0 auid=1000 ses=1 subj=unconfined_u:unconfined_r:unconfined_t:s0-s0:c0.c1023 msg='op=PAM:setcred grant
Oct 25 13:44:54 localhost.localdomain systemd[1171]: Time has been changed
-- Subject: Time change
-- Defined-By: systemd
-- Support: http://lists.freedesktop.org/mailman/listinfo/systemd-devel
-- 
-- The system clock has been changed to REALTIME microseconds after January 1st, 1970.
Oct 25 13:44:54 localhost.localdomain NetworkManager[1028]: <info>  (wlp3s0): supplicant interface state: completed -> disconnected
Oct 25 13:44:54 localhost.localdomain NetworkManager[1028]: <info>  (wlp3s0): supplicant interface state: disconnected -> scanning
Comment 1 Zbigniew Jędrzejewski-Szmek 2015-10-25 11:42:58 EDT
The idea of CriticalPowerAction is to get the system into a "safe" state, where there will be no loss of data. Normal suspend does not fit this criteria, so it is reasonable to shut down if the hybrid sleep action failed. Also, systemd is provides a low-level "dumb" interface, and if you tell it to do "hybrid-sleep", it should do that, or fail. So we are not going to change the semantics of hybrid-sleep.

Based on the logs you pasted, I don't see why the hibernation fails. If it is set up properly and should work, you might want to take it up with the kernel maintainers.
Comment 2 Jan Synacek 2015-10-26 05:51:25 EDT
You want your computer to perform hybrid-sleep, which consists of two distinct operations, one of which fails on your system. Therefore, hybrid-sleep fails on your machine. Doing only one part of the operation is not how it works. Definitely not a systemd bug.

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