Current Tumbleweed fails to suspend & hibernate - powers down before suspend/hibernate is completed

Hi!

Recently my laptop started to not come back from hibernation (or suspend-then-hibernate) and instead booted up fresh, as if there was no hibernation data written to the encrypted swap partition. This used to work perfectly (after learning I need to unload the touchpad driver before suspending - it’s a Tongfang GK5CP0Z).

kernel:

5.6.4-1-default

boot parameters:

dracut-cmdline[307]: Using kernel command line parameters: rd.luks.uuid=luks-3482b2b4-9af9-4969-8c49-c07d1364e06f rd.lvm.lv=system/root root=/dev/mapper/system-root rootfstype=btrfs rootflags=rw,noatime,ssd,space_cache,subvolid=1800,subvol=/@/.snapshots/253/snapshot,subvol=@/.snapshots/253/snapshot BOOT_IMAGE=/boot/vmlinuz-5.6.4-1-default root=/dev/mapper/system-root resume=/dev/system/swap acpi_osi=! acpi_osi=Linux acpi_os_name=Linux acpi_rev_override=1 nouveau.modeset=0 nouveau.runpm=0 pcie_aspm=force drm.vblankoffdelay=1 scsi_mod.use_blk_mq=1 mem_sleep_default=deep mitigations=auto

systemd:

systemd 245 (+suse.83.gc5aa158173)
+PAM -AUDIT +SELINUX -IMA +APPARMOR -SMACK +SYSVINIT +UTMP +LIBCRYPTSETUP +GCRYPT +GNUTLS +ACL +XZ +LZ4 +SECCOMP +BLKID +ELFUTILS +KMOD -IDN2 -IDN +PCRE2 default-hierarchy=hybrid

When I had my system hibernated and I start it up again it boots normally instead of resuming. Doing a

journalctl -b-1

I could see that hibernation and sleep were both never finished.

For example, here from last night - I have suspend-then-hibernate enabled, with mem_sleep_default=deep (this config has worked perfectly in the past).

First, here the process of suspend:

https://pastebin.com/EcqV0rGq

Note how abrupt the suspend log ends. The process is not finished!

Then, two hours later (the default delay for suspend-then-resume) and with not a single log line in between, follows this (note how it starts by continuing the suspend process at resume time!):

https://pastebin.com/GBva6bEK

Here is the end of the log. The next thing is starting a new boot, where I as a user expect to resume from hibernation but instead the laptop boots up normally, losing all runtime data!

You can see that when the laptop wakes up from deep mem sleep (S3) after 2h to hibernate, it starts by finishing the suspend process! Then, the hibernation image is never written, so the machine has nothing to resume from.

What can I do to fix this? I have not been able to find a known bug, but I also was not entirely sure where to look or if to report this as an opensuse tumbleweed bug. I am not aware of any changes I would have made myself to cause this.

I would very much appreciate your help!

Leonie

PS:

Here is a quick suspend / resume cycle:

https://pastebin.com/EMfaeAXr

Especially check out 15:18:56 - 15:19:19, the seconds when the system is suspended. (This is me waiting for 25 sec before re-opening the laptop lid.)

“Freezing user space processes”, “Freezing remaining freezable tasks” and “Disabling non-boot CPUs …” all happen only after I re-open the lid, not before the system goes to sleep, like it should be!

Anyone?

Do you have an idea which component would be the cause and where I should ask if not here in the openSUSE forum?

I had troubles with a sleep mode with 5.6.x kernels, but not with 5.5.5 - 5.5.13.
Try to use 5.5.13 kernel.

BTW, 25.04 - 26.04 was weekend.
Don’t live in a hurry.

Hi again,

You’re right - sorry for the rush. I saw this thread being pushed down by lots of activity on many other threads in the same forum section and got worried that it will be overlooked this way. That should mean no need to panic, though. =)

Thank you for the hint about 5.5! Result: Same broken behavior on that kernel version, unfortunately.

I tried Kernel 5.5.13 from Takashi Iwai , but the behavior was identical to the current kernel.

Log:
https://pastebin.com/zEkaeEfg

The system is suspended from 18:04:23 until 18:04:52.

My desktop running Tumbleweed is currently not providing Hibernate, I see it is possible and likely will give it a try.

You indicate hibernate is not working anymore, so I assume it did work in the past.
If that is the case, can you find in the journal a log for a previous hibernate that was successful and diff it with the problematic one?

I also would have a look at warnings I see in your log:


Apr 25 01:31:07 felicity systemd-sleep[3623]: WARNING: Detected GRUB environment block on lvm device
Apr 25 01:31:07 felicity systemd-sleep[3623]: openSUSE  Tumbleweed will remain the default boot entry until manually cleared  with:
Apr 25 01:31:07 felicity systemd-sleep[3623]:     grub-editenv /boot/grub2/grubenv unset next_entry
Apr 25 01:31:07 felicity systemd-sleep[3339]:     time needed for sync: 0.0 seconds, time needed for grub: 1.0 seconds.

Could the hibernate process decide not to commence because of this? Not sure, but I would spend some effort to solve it.

Looking at my suspend log I see basically the same as what I see in your last log:

Apr 30 21:30:54 systemd[1]: Reached target Sleep.
Apr 30 21:30:54 systemd[1]: Starting Suspend...
Apr 30 21:30:54 systemd-sleep[7835]: INFO: Skip running /usr/lib/systemd/system-sleep/grub2.sleep for suspend
Apr 30 21:30:54 systemd-sleep[7833]: Suspending system...
Apr 30 21:30:54 kernel: PM: suspend entry (deep)
Apr 30 21:32:51 kernel: Filesystems sync: 0.056 seconds
Apr 30 21:32:51 kernel: Freezing user space processes ... (elapsed 0.001 seconds) done.
Apr 30 21:32:51 kernel: OOM killer disabled.
Apr 30 21:32:51 kernel: Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
Apr 30 21:32:51 kernel: printk: Suspending console(s) (use no_console_suspend to debug)
Apr 30 21:32:51 kernel: wlp0s20u5: deauthenticating from 00:9a:d5:50:3d:ba by local choice (Reason: 3=DEAUTH_LEAVING)
Apr 30 21:32:51 kernel: parport_pc 00:06: disabled
Apr 30 21:32:51 kernel: serial 00:05: disabled
Apr 30 21:32:51 kernel: sd 0:0:0:0: [sda] Synchronizing SCSI cache
Apr 30 21:32:51 kernel: sd 1:0:0:0: [sdb] Synchronizing SCSI cache
Apr 30 21:32:51 kernel: sd 2:0:0:0: [sdc] Synchronizing SCSI cache
Apr 30 21:32:51 kernel: sd 1:0:0:0: [sdb] Stopping disk
Apr 30 21:32:51 kernel: sd 0:0:0:0: [sda] Stopping disk
Apr 30 21:32:51 kernel: sd 2:0:0:0: [sdc] Stopping disk
Apr 30 21:32:51 kernel: ACPI: Preparing to enter system sleep state S3
Apr 30 21:32:51 kernel: PM: Saving platform NVS memory
Apr 30 21:32:51 kernel: Disabling non-boot CPUs ...
Apr 30 21:32:51 kernel: IRQ 34: no longer affine to CPU1
Apr 30 21:32:51 kernel: smpboot: CPU 1 is now offline
Apr 30 21:32:51 kernel: IRQ 29: no longer affine to CPU2
Apr 30 21:32:51 kernel: IRQ 30: no longer affine to CPU2
Apr 30 21:32:51 kernel: smpboot: CPU 2 is now offline
Apr 30 21:32:51 kernel: IRQ 16: no longer affine to CPU3
Apr 30 21:32:51 kernel: IRQ 18: no longer affine to CPU3
Apr 30 21:32:51 kernel: smpboot: CPU 3 is now offline
Apr 30 21:32:51 kernel: ACPI: Low-level resume complete
Apr 30 21:32:51 kernel: PM: Restoring platform NVS memory
Apr 30 21:32:51 kernel: Enabling non-boot CPUs ...
Apr 30 21:32:51 kernel: x86: Booting SMP configuration:
Apr 30 21:32:51 kernel: smpboot: Booting Node 0 Processor 1 APIC 0x2
Apr 30 21:32:51 kernel: CPU1 is up
Apr 30 21:32:51 kernel: smpboot: Booting Node 0 Processor 2 APIC 0x4
Apr 30 21:32:51 kernel: CPU2 is up
Apr 30 21:32:51 kernel: smpboot: Booting Node 0 Processor 3 APIC 0x6
Apr 30 21:32:51 kernel: CPU3 is up
Apr 30 21:32:51 kernel: ACPI: Waking up from system sleep state S3
Apr 30 21:32:51 kernel: serial 00:05: activated
Apr 30 21:32:51 kernel: parport_pc 00:06: activated
Apr 30 21:32:51 kernel: sd 2:0:0:0: [sdc] Starting disk
Apr 30 21:32:51 kernel: sd 0:0:0:0: [sda] Starting disk
Apr 30 21:32:51 kernel: sd 1:0:0:0: [sdb] Starting disk

The end of the cut-out of the log shows I think what is the reason for the last part of the suspend to show up as first part of the un-suspend: The disks were already suspend so the log could not be written, but these log entries were not lost and after the disks became online again the were written to the log.