monitor doesn't wait while system prepares for hibernation

Kabir · 2018-11-17 18:43:26

Hi,

I've been noticing some odd behavior since a week or so while using hybrid-sleep and hibernation

With systemctl hybrid-sleep:
1. the power LED doesn't blink once the system enters hybrid-sleep, the LED remains constantly on
2. the input signal to the monitor cuts off immediately, instead of waiting for a few seconds with a blinking cursor in console while the system prepares for hybrid-sleep

With systemctl hibernate:
1. no issues with the power LED here, it turns off as it normally would
2. but in this case too the input to the monitor cuts off as soon as the command systemctl hibernate is run, while the system takes a few seconds to prepare for hibernation before powering off

The behavior I expect is for the monitor to wait while the system prepares for hybrid-sleep / hibernation, so that it can flash any errors that may pop up. And with regards to the power LED, I expect it to keep blinking as long as the system is connected to the main power and is in hybrid-sleep.

Hibernation / hybrid-sleep set up:

[Sleep]
# suspend=suspend
SuspendMode=suspend
# SuspendState=disk
# hibernate=hybrid-sleep
HibernateMode=shutdown
# HibernateMode=suspend
HibernateState=disk

I've set up suspend / hibernate such that suspend always goes to ram and instead of hibernate I use hybrid-sleep. But now I've commented out HibernateMode=suspend as I'm not using hybrid-sleep at the moment.

HOOKS=(base udev autodetect keyboard modconf block filesystems resume fsck)

# GRUB boot loader configuration

GRUB_DEFAULT=saved
GRUB_SAVEDEFAULT=true
GRUB_TIMEOUT=5
GRUB_DISTRIBUTOR="Arch"
GRUB_CMDLINE_LINUX_DEFAULT="quiet resume=UUID=2f05b65b-f42d-45ef-b887-7d46daff1203 nvidia-drm.modeset=1"
# GRUB_CMDLINE_LINUX_DEFAULT="quiet resume=/dev/sda2 nvidia-drm.modeset=1"
GRUB_CMDLINE_LINUX=""

`--> lsblk -f
NAME   FSTYPE LABEL UUID                                 FSAVAIL FSUSE% MOUNTPOINT
sda                                                                     
├─sda1 ext4         1c25165f-8c97-4d07-853c-02e0fb1bc0ab      9G    64% /
├─sda2 swap         2f05b65b-f42d-45ef-b887-7d46daff1203                [SWAP]
└─sda3 ext4         b7be9869-1c0a-400d-8589-9e093bae911d  503.4G    38% /home
sr0

I have tried using both values for resume, UUID and partition label.
And I tried changing the kernel to LTS but no change in behavior.

After resuming the system from hybrid-sleep or hibernation, I don't see any errors in the xlogs or the journal logs, either ways, here's a log after entering hybrid-sleep (note: at the time of this log, HibernateMode in sleep.conf was set to suspend):

Nov 17 19:29:23 aries systemd[1]: Reached target Sleep.
Nov 17 19:29:23 aries systemd[1]: Starting Hybrid Suspend+Hibernate...
Nov 17 19:29:23 aries systemd-sleep[1107]: Suspending system...
Nov 17 19:29:23 aries kernel: PM: Image not found (code -22)
Nov 17 19:29:23 aries kernel: PM: hibernation entry
Nov 17 19:29:23 aries kernel: PM: Syncing filesystems ... 
Nov 17 19:31:48 aries kernel: PM: done.
Nov 17 19:31:48 aries kernel: Freezing user space processes ... (elapsed 0.001 seconds) done.
Nov 17 19:31:48 aries kernel: OOM killer disabled.
Nov 17 19:31:48 aries kernel: PM: Marking nosave pages: [mem 0x00000000-0x00000fff]
Nov 17 19:31:48 aries kernel: PM: Marking nosave pages: [mem 0x00091000-0x000fffff]
Nov 17 19:31:48 aries kernel: PM: Marking nosave pages: [mem 0x9392b000-0x9392bfff]
Nov 17 19:31:48 aries kernel: PM: Marking nosave pages: [mem 0x93c57000-0x93c57fff]
Nov 17 19:31:48 aries kernel: PM: Marking nosave pages: [mem 0xbd0fb000-0xbdefefff]
Nov 17 19:31:48 aries kernel: PM: Marking nosave pages: [mem 0xbdf00000-0xffffffff]
Nov 17 19:31:48 aries kernel: PM: Basic memory bitmaps created
Nov 17 19:31:48 aries kernel: PM: Preallocating image memory... done (allocated 321572 pages)
Nov 17 19:31:48 aries kernel: PM: Allocated 1286288 kbytes in 0.11 seconds (11693.52 MB/s)
Nov 17 19:31:48 aries kernel: Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
Nov 17 19:31:48 aries kernel: Suspending console(s) (use no_console_suspend to debug)
Nov 17 19:31:48 aries kernel: ACPI: EC: interrupt blocked
Nov 17 19:31:48 aries kernel: Disabling non-boot CPUs ...
Nov 17 19:31:48 aries kernel: smpboot: CPU 1 is now offline
Nov 17 19:31:48 aries kernel: smpboot: CPU 2 is now offline
Nov 17 19:31:48 aries kernel: smpboot: CPU 3 is now offline
Nov 17 19:31:48 aries kernel: smpboot: CPU 4 is now offline
Nov 17 19:31:48 aries kernel: smpboot: CPU 5 is now offline
Nov 17 19:31:48 aries kernel: smpboot: CPU 6 is now offline
Nov 17 19:31:48 aries kernel: smpboot: CPU 7 is now offline
Nov 17 19:31:48 aries kernel: PM: Creating hibernation image:
Nov 17 19:31:48 aries kernel: PM: Need to copy 322348 pages
Nov 17 19:31:48 aries kernel: PM: Normal pages needed: 322348 + 1024, available pages: 1754308
Nov 17 19:31:48 aries kernel: Enabling non-boot CPUs ...
Nov 17 19:31:48 aries kernel: x86: Booting SMP configuration:
Nov 17 19:31:48 aries kernel: smpboot: Booting Node 0 Processor 1 APIC 0x2
Nov 17 19:31:48 aries kernel:  cache: parent cpu1 should not be sleeping
Nov 17 19:31:48 aries kernel: CPU1 is up
Nov 17 19:31:48 aries kernel: smpboot: Booting Node 0 Processor 2 APIC 0x4
Nov 17 19:31:48 aries kernel:  cache: parent cpu2 should not be sleeping
Nov 17 19:31:48 aries kernel: CPU2 is up
Nov 17 19:31:48 aries kernel: smpboot: Booting Node 0 Processor 3 APIC 0x6
Nov 17 19:31:48 aries kernel:  cache: parent cpu3 should not be sleeping
Nov 17 19:31:48 aries kernel: CPU3 is up
Nov 17 19:31:48 aries kernel: smpboot: Booting Node 0 Processor 4 APIC 0x1
Nov 17 19:31:48 aries kernel:  cache: parent cpu4 should not be sleeping
Nov 17 19:31:48 aries kernel: CPU4 is up
Nov 17 19:31:48 aries kernel: smpboot: Booting Node 0 Processor 5 APIC 0x3
Nov 17 19:31:48 aries kernel:  cache: parent cpu5 should not be sleeping
Nov 17 19:31:48 aries kernel: CPU5 is up
Nov 17 19:31:48 aries kernel: smpboot: Booting Node 0 Processor 6 APIC 0x5
Nov 17 19:31:48 aries kernel:  cache: parent cpu6 should not be sleeping
Nov 17 19:31:48 aries kernel: CPU6 is up
Nov 17 19:31:48 aries kernel: smpboot: Booting Node 0 Processor 7 APIC 0x7
Nov 17 19:31:48 aries kernel:  cache: parent cpu7 should not be sleeping
Nov 17 19:31:48 aries kernel: CPU7 is up
Nov 17 19:31:48 aries kernel: ACPI: EC: interrupt unblocked
Nov 17 19:31:48 aries kernel: usb usb1: root hub lost power or was reset
Nov 17 19:31:48 aries kernel: usb usb2: root hub lost power or was reset
Nov 17 19:31:48 aries kernel: sd 0:0:0:0: [sda] Starting disk
Nov 17 19:31:48 aries kernel: ata4: SATA link down (SStatus 4 SControl 300)
Nov 17 19:31:48 aries kernel: ata3: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
Nov 17 19:31:48 aries kernel: ata2: SATA link down (SStatus 4 SControl 300)
Nov 17 19:31:48 aries kernel: ata1: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
Nov 17 19:31:48 aries kernel: ata1.00: ACPI cmd f5/00:00:00:00:00:e0 (SECURITY FREEZE LOCK) filtered out
Nov 17 19:31:48 aries kernel: ata1.00: ACPI cmd b1/c1:00:00:00:00:e0 (DEVICE CONFIGURATION OVERLAY) filtered out
Nov 17 19:31:48 aries kernel: ata1.00: ACPI cmd f5/00:00:00:00:00:e0 (SECURITY FREEZE LOCK) filtered out
Nov 17 19:31:48 aries kernel: ata1.00: ACPI cmd b1/c1:00:00:00:00:e0 (DEVICE CONFIGURATION OVERLAY) filtered out
Nov 17 19:31:48 aries kernel: ata1.00: configured for UDMA/100
Nov 17 19:31:48 aries kernel: ata3.00: configured for UDMA/100
Nov 17 19:31:48 aries kernel: usb 1-14: reset low-speed USB device number 3 using xhci_hcd
Nov 17 19:31:48 aries kernel: usb 1-6: reset low-speed USB device number 2 using xhci_hcd
Nov 17 19:31:48 aries kernel: PM: Basic memory bitmaps freed
Nov 17 19:31:48 aries kernel: OOM killer enabled.
Nov 17 19:31:48 aries kernel: Restarting tasks ... done.
Nov 17 19:31:48 aries systemd-networkd[502]: eno1: Lost carrier
Nov 17 19:31:48 aries systemd-networkd[502]: eno1: DHCP lease lost
Nov 17 19:31:48 aries systemd-timesyncd[430]: No network connectivity, watching for changes.
Nov 17 19:31:48 aries systemd-sleep[1107]: System resumed.
Nov 17 19:31:48 aries kernel: PM: hibernation exit
Nov 17 19:31:48 aries systemd[1]: Started Hybrid Suspend+Hibernate.
Nov 17 19:31:48 aries audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-hybrid-slee>
Nov 17 19:31:48 aries audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-hybrid-sleep>
Nov 17 19:31:48 aries kernel: audit: type=1130 audit(1542463308.406:43): pid=1 uid=0 auid=4294967295 ses=4294967295 ms>
Nov 17 19:31:48 aries kernel: audit: type=1131 audit(1542463308.406:44): pid=1 uid=0 auid=4294967295 ses=4294967295 ms>
Nov 17 19:31:48 aries systemd[1]: Stopped target Sleep.
Nov 17 19:31:48 aries systemd[1]: Reached target Hybrid Suspend+Hibernate.
Nov 17 19:31:48 aries systemd[1]: Stopped target Hybrid Suspend+Hibernate.
Nov 17 19:31:48 aries acpid[434]: client 544[1000:1000] has disconnected
Nov 17 19:31:48 aries acpid[434]: client 544[1000:1000] has disconnected
Nov 17 19:31:48 aries acpid[434]: client connected from 544[1000:1000]
Nov 17 19:31:48 aries acpid[434]: 1 client rule loaded
Nov 17 19:31:48 aries acpid[434]: client connected from 544[1000:1000]
Nov 17 19:31:48 aries acpid[434]: 1 client rule loaded
Nov 17 19:31:48 aries systemd-logind[436]: Operation 'sleep' finished.
Nov 17 19:31:49 aries systemd-networkd[502]: eno1: Gained carrier
Nov 17 19:31:49 aries kernel: e1000e: eno1 NIC Link is Up 100 Mbps Full Duplex, Flow Control: Rx/Tx
Nov 17 19:31:49 aries kernel: e1000e 0000:00:1f.6 eno1: 10/100 speed: disabling TSO
Nov 17 19:31:49 aries systemd-timesyncd[430]: Network configuration changed, trying to establish connection.
Nov 17 19:31:57 aries systemd-networkd[502]: eno1: DHCPv4 address 192.168.1.5/24 via 192.168.1.1
Nov 17 19:31:57 aries systemd-timesyncd[430]: Network configuration changed, trying to establish connection.
Nov 17 19:31:57 aries systemd-networkd[502]: eno1: Configured
Nov 17 19:32:00 aries systemd-timesyncd[430]: Synchronized to time server 103.28.56.14:123 (0.arch.pool.ntp.org).
Nov 17 19:32:28 aries sudo[1213]:    kabir : TTY=pts/1 ; PWD=/home/kabir ; USER=root ; COMMAND=sudoedit /etc/systemd/s>
Nov 17 19:32:28 aries sudo[1213]: pam_unix(sudo:session): session opened for user root by (uid=0)
Nov 17 19:32:41 aries sudo[1213]: pam_unix(sudo:session): session closed for user root
Nov 17 19:32:49 aries systemd-logind[436]: System is rebooting.

Any suggestions as to what else I could try?
Thanks!

Arch Linux

#1 2018-11-17 18:43:26

monitor doesn't wait while system prepares for hibernation

Board footer