Unreliable behaviour of suspend

razimantv · 2024-08-08 09:59:31

I use plasma 6 on Arch on my laptop (Lenovo Legion Y520). I like to use the "Sleep (suspend to RAM)" option but it is unreliable.

When it works, the screen turns off and the keyboard backlight turns off too. I can press the power button or spacebar to bring the screen back on and log back into my session.

But sometimes, the screen turns off but the backlight stays on. Pressing any key makes no difference. The only way out (that I know of) is to keep pressing the power button until the laptop switches off, and switch it back on.

Here is the relevant part of the output of journalctl for when it does not work (I have replaced IP/mac addresses with ADDR

Aug 07 20:17:12 laptop systemd-logind[499]: The system will suspend now!
Aug 07 20:17:12 laptop NetworkManager[493]: <info>  [1723058232.4728] manager: sleep: sleep requested (sleeping: no  enabled: yes)
Aug 07 20:17:12 laptop NetworkManager[493]: <info>  [1723058232.4730] device (enp3s0): state change: unavailable -> unmanaged (reason 'unmanaged-sleeping', sys-iface-state: 'managed')
Aug 07 20:17:12 laptop mpd-mpris[728]: 2024/08/07 20:17:12 Pause requested
Aug 07 20:17:12 laptop NetworkManager[493]: <info>  [1723058232.4833] device (p2p-dev-wlp2s0): state change: disconnected -> unmanaged (reason 'unmanaged-sleeping', sys-iface-state: 'managed')
Aug 07 20:17:12 laptop NetworkManager[493]: <info>  [1723058232.4845] manager: NetworkManager state is now ASLEEP
Aug 07 20:17:12 laptop NetworkManager[493]: <info>  [1723058232.4852] device (wlp2s0): state change: activated -> deactivating (reason 'sleeping', sys-iface-state: 'managed')
Aug 07 20:17:12 laptop NetworkManager[493]: <info>  [1723058232.4853] dhcp4 (wlp2s0): canceled DHCP transaction
Aug 07 20:17:12 laptop NetworkManager[493]: <info>  [1723058232.4854] dhcp4 (wlp2s0): activation: beginning transaction (timeout in 45 seconds)
Aug 07 20:17:12 laptop NetworkManager[493]: <info>  [1723058232.4854] dhcp4 (wlp2s0): state changed no lease
Aug 07 20:17:12 laptop avahi-daemon[495]: Withdrawing address record for ADDR on wlp2s0.
Aug 07 20:17:12 laptop avahi-daemon[495]: Leaving mDNS multicast group on interface wlp2s0.IPv4 with address ADDR.
Aug 07 20:17:12 laptop avahi-daemon[495]: Interface wlp2s0.IPv4 no longer relevant for mDNS.
Aug 07 20:17:12 laptop avahi-daemon[495]: Withdrawing address record for fe80::ADDR on wlp2s0.
Aug 07 20:17:12 laptop avahi-daemon[495]: Leaving mDNS multicast group on interface wlp2s0.IPv6 with address fe80::ADDR.
Aug 07 20:17:12 laptop avahi-daemon[495]: Interface wlp2s0.IPv6 no longer relevant for mDNS.
Aug 07 20:17:12 laptop kded6[866]: org.kde.plasma.nm.kded: Unhandled active connection state change:  3
Aug 07 20:17:12 laptop systemd-resolved[483]: wlp2s0: Bus client reset search domain list.
Aug 07 20:17:12 laptop systemd-resolved[483]: wlp2s0: Bus client set default route setting: no
Aug 07 20:17:12 laptop systemd-resolved[483]: wlp2s0: Bus client reset DNS server list.
Aug 07 20:17:12 laptop systemd[1]: Starting Network Manager Script Dispatcher Service...
Aug 07 20:17:12 laptop systemd[1]: Started Network Manager Script Dispatcher Service.
Aug 07 20:17:12 laptop kernel: wlp2s0: deauthenticating from ADDR by local choice (Reason: 3=DEAUTH_LEAVING)
Aug 07 20:17:12 laptop wpa_supplicant[573]: nl80211: send_event_marker failed: Source based routing not supported
Aug 07 20:17:12 laptop wpa_supplicant[573]: wlp2s0: CTRL-EVENT-DISCONNECTED bssid=ADDR reason=3 locally_generated=1
Aug 07 20:17:12 laptop wpa_supplicant[573]: wlp2s0: CTRL-EVENT-DSCP-POLICY clear_all
Aug 07 20:17:12 laptop NetworkManager[493]: <info>  [1723058232.6061] device (wlp2s0): state change: deactivating -> disconnected (reason 'sleeping', sys-iface-state: 'managed')
Aug 07 20:17:12 laptop wpa_supplicant[573]: wlp2s0: CTRL-EVENT-SIGNAL-CHANGE above=0 signal=-9999 noise=9999 txrate=0
Aug 07 20:17:12 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 07 20:17:12 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 07 20:17:12 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 07 20:17:12 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 07 20:17:12 laptop NetworkManager[493]: <info>  [1723058232.6328] device (wlp2s0): set-hw-addr: set MAC address to ADDR (scanning)
Aug 07 20:17:12 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 07 20:17:12 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 07 20:17:12 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 07 20:17:12 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 07 20:17:12 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 07 20:17:12 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 07 20:17:12 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 07 20:17:12 laptop NetworkManager[493]: <info>  [1723058232.6404] device (wlp2s0): supplicant interface state: completed -> disconnected
Aug 07 20:17:12 laptop NetworkManager[493]: <info>  [1723058232.6405] device (wlp2s0): state change: disconnected -> unmanaged (reason 'unmanaged-sleeping', sys-iface-state: 'managed')
Aug 07 20:17:12 laptop wpa_supplicant[573]: wlp2s0: CTRL-EVENT-SCAN-FAILED ret=-100
Aug 07 20:17:12 laptop NetworkManager[493]: <info>  [1723058232.6661] device (wlp2s0): set-hw-addr: reset MAC address to ADDR (unmanage)
Aug 07 20:17:12 laptop wpa_supplicant[573]: p2p-dev-wlp2s0: CTRL-EVENT-DSCP-POLICY clear_all
Aug 07 20:17:12 laptop wpa_supplicant[573]: p2p-dev-wlp2s0: CTRL-EVENT-DSCP-POLICY clear_all
Aug 07 20:17:12 laptop wpa_supplicant[573]: nl80211: deinit ifname=p2p-dev-wlp2s0 disabled_11b_rates=0
Aug 07 20:17:12 laptop wpa_supplicant[573]: wlp2s0: CTRL-EVENT-DSCP-POLICY clear_all
Aug 07 20:17:12 laptop wpa_supplicant[573]: wlp2s0: CTRL-EVENT-DSCP-POLICY clear_all
Aug 07 20:17:12 laptop wpa_supplicant[573]: nl80211: deinit ifname=wlp2s0 disabled_11b_rates=0
Aug 07 20:17:13 laptop systemd[1]: Reached target Sleep.
Aug 07 20:17:13 laptop systemd[1]: Starting System Suspend...
Aug 07 20:17:13 laptop systemd-sleep[3933658]: Successfully froze unit 'user.slice'.
Aug 07 20:17:13 laptop systemd-sleep[3933658]: Performing sleep operation 'suspend'...
-- Boot ace6944bb3d34642b06e036ff5e55629 --

To compare, here it is when it did work (same session, these were consecutive sleep attempts)

Aug 05 22:17:39 laptop systemd-logind[499]: The system will suspend now!
Aug 05 22:17:39 laptop NetworkManager[493]: <info>  [1722892659.0755] manager: sleep: sleep requested (sleeping: no  enabled: yes)
Aug 05 22:17:39 laptop NetworkManager[493]: <info>  [1722892659.0758] device (enp3s0): state change: unavailable -> unmanaged (reason 'unmanaged-sleeping', sys-iface-state: 'managed')
Aug 05 22:17:39 laptop mpd-mpris[728]: 2024/08/05 22:17:39 Pause requested
Aug 05 22:17:39 laptop NetworkManager[493]: <info>  [1722892659.0879] device (p2p-dev-wlp2s0): state change: disconnected -> unmanaged (reason 'unmanaged-sleeping', sys-iface-state: 'managed')
Aug 05 22:17:39 laptop avahi-daemon[495]: Withdrawing address record for ADDR on wlp2s0.
Aug 05 22:17:39 laptop NetworkManager[493]: <info>  [1722892659.0884] manager: NetworkManager state is now ASLEEP
Aug 05 22:17:39 laptop avahi-daemon[495]: Leaving mDNS multicast group on interface wlp2s0.IPv4 with address ADDR.
Aug 05 22:17:39 laptop NetworkManager[493]: <info>  [1722892659.0892] device (wlp2s0): state change: activated -> deactivating (reason 'sleeping', sys-iface-state: 'managed')
Aug 05 22:17:39 laptop NetworkManager[493]: <info>  [1722892659.0893] dhcp4 (wlp2s0): canceled DHCP transaction
Aug 05 22:17:39 laptop NetworkManager[493]: <info>  [1722892659.0893] dhcp4 (wlp2s0): activation: beginning transaction (timeout in 45 seconds)
Aug 05 22:17:39 laptop NetworkManager[493]: <info>  [1722892659.0894] dhcp4 (wlp2s0): state changed no lease
Aug 05 22:17:39 laptop avahi-daemon[495]: Interface wlp2s0.IPv4 no longer relevant for mDNS.
Aug 05 22:17:39 laptop kded6[866]: org.kde.plasma.nm.kded: Unhandled active connection state change:  3
Aug 05 22:17:39 laptop avahi-daemon[495]: Withdrawing address record for fe80::ADDR on wlp2s0.
Aug 05 22:17:39 laptop systemd-resolved[483]: wlp2s0: Bus client reset search domain list.
Aug 05 22:17:39 laptop avahi-daemon[495]: Leaving mDNS multicast group on interface wlp2s0.IPv6 with address fe80::ADDR.
Aug 05 22:17:39 laptop systemd-resolved[483]: wlp2s0: Bus client set default route setting: no
Aug 05 22:17:39 laptop avahi-daemon[495]: Interface wlp2s0.IPv6 no longer relevant for mDNS.
Aug 05 22:17:39 laptop systemd-resolved[483]: wlp2s0: Bus client reset DNS server list.
Aug 05 22:17:39 laptop systemd[1]: Starting Network Manager Script Dispatcher Service...
Aug 05 22:17:39 laptop systemd[1]: Started Network Manager Script Dispatcher Service.
Aug 05 22:17:39 laptop kernel: wlp2s0: deauthenticating from ADDR by local choice (Reason: 3=DEAUTH_LEAVING)
Aug 05 22:17:39 laptop wpa_supplicant[573]: nl80211: send_event_marker failed: Source based routing not supported
Aug 05 22:17:39 laptop wpa_supplicant[573]: wlp2s0: CTRL-EVENT-DISCONNECTED bssid=ADDR reason=3 locally_generated=1
Aug 05 22:17:39 laptop wpa_supplicant[573]: wlp2s0: CTRL-EVENT-DSCP-POLICY clear_all
Aug 05 22:17:39 laptop NetworkManager[493]: <info>  [1722892659.3474] device (wlp2s0): supplicant interface state: completed -> disconnected
Aug 05 22:17:39 laptop NetworkManager[493]: <info>  [1722892659.3475] device (wlp2s0): state change: deactivating -> disconnected (reason 'sleeping', sys-iface-state: 'managed')
Aug 05 22:17:39 laptop wpa_supplicant[573]: wlp2s0: CTRL-EVENT-SIGNAL-CHANGE above=0 signal=-9999 noise=9999 txrate=0
Aug 05 22:17:39 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 05 22:17:39 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 05 22:17:39 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 05 22:17:39 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 05 22:17:39 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 05 22:17:39 laptop NetworkManager[493]: <info>  [1722892659.3893] device (wlp2s0): set-hw-addr: set MAC address to ADDR (scanning)
Aug 05 22:17:39 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 05 22:17:39 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 05 22:17:39 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 05 22:17:39 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 05 22:17:39 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 05 22:17:39 laptop wpa_supplicant[573]: wlp2s0: PMKSA-CACHE-REMOVED ADDR 0
Aug 05 22:17:39 laptop NetworkManager[493]: <info>  [1722892659.3969] device (wlp2s0): state change: disconnected -> unmanaged (reason 'unmanaged-sleeping', sys-iface-state: 'managed')
Aug 05 22:17:39 laptop NetworkManager[493]: <info>  [1722892659.4266] device (wlp2s0): set-hw-addr: reset MAC address to ADDR (unmanage)
Aug 05 22:17:39 laptop wpa_supplicant[573]: p2p-dev-wlp2s0: CTRL-EVENT-DSCP-POLICY clear_all
Aug 05 22:17:39 laptop wpa_supplicant[573]: p2p-dev-wlp2s0: CTRL-EVENT-DSCP-POLICY clear_all
Aug 05 22:17:39 laptop wpa_supplicant[573]: nl80211: deinit ifname=p2p-dev-wlp2s0 disabled_11b_rates=0
Aug 05 22:17:39 laptop wpa_supplicant[573]: wlp2s0: CTRL-EVENT-DSCP-POLICY clear_all
Aug 05 22:17:39 laptop wpa_supplicant[573]: wlp2s0: CTRL-EVENT-DSCP-POLICY clear_all
Aug 05 22:17:39 laptop wpa_supplicant[573]: nl80211: deinit ifname=wlp2s0 disabled_11b_rates=0
Aug 05 22:17:39 laptop systemd[1]: Reached target Sleep.
Aug 05 22:17:39 laptop systemd[1]: Starting System Suspend...
Aug 05 22:17:39 laptop systemd-sleep[3718789]: Successfully froze unit 'user.slice'.
Aug 05 22:17:39 laptop systemd-sleep[3718789]: Performing sleep operation 'suspend'...
Aug 05 22:17:39 laptop kernel: PM: suspend entry (deep)
Aug 05 22:17:40 laptop systemd-resolved[483]: Flushed all caches.
Aug 05 22:17:40 laptop kernel: Filesystems sync: 0.423 seconds
Aug 06 19:18:44 laptop kernel: Freezing user space processes
Aug 06 19:18:44 laptop kernel: Freezing user space processes completed (elapsed 0.002 seconds)
Aug 06 19:18:44 laptop kernel: OOM killer disabled.
Aug 06 19:18:44 laptop kernel: Freezing remaining freezable tasks
Aug 06 19:18:44 laptop kernel: Freezing remaining freezable tasks completed (elapsed 0.002 seconds)
Aug 06 19:18:44 laptop kernel: printk: Suspending console(s) (use no_console_suspend to debug)
Aug 06 19:18:44 laptop kernel: sd 2:0:0:0: [sda] Synchronizing SCSI cache
Aug 06 19:18:44 laptop kernel: ata3.00: Entering standby power mode
Aug 06 19:18:44 laptop kernel: ACPI: EC: interrupt blocked
Aug 06 19:18:44 laptop kernel: ACPI: PM: Preparing to enter system sleep state S3
Aug 06 19:18:44 laptop kernel: ACPI: EC: event blocked
Aug 06 19:18:44 laptop kernel: ACPI: EC: EC stopped
Aug 06 19:18:44 laptop kernel: ACPI: PM: Saving platform NVS memory
Aug 06 19:18:44 laptop kernel: Disabling non-boot CPUs ...
Aug 06 19:18:44 laptop kernel: smpboot: CPU 1 is now offline
Aug 06 19:18:44 laptop kernel: smpboot: CPU 2 is now offline
Aug 06 19:18:44 laptop kernel: smpboot: CPU 3 is now offline
Aug 06 19:18:44 laptop kernel: smpboot: CPU 4 is now offline
Aug 06 19:18:44 laptop kernel: smpboot: CPU 5 is now offline
Aug 06 19:18:44 laptop kernel: smpboot: CPU 6 is now offline
Aug 06 19:18:44 laptop kernel: smpboot: CPU 7 is now offline
Aug 06 19:18:44 laptop kernel: [Firmware Bug]: TSC ADJUST differs: CPU0 0 --> -2506673926. Restoring
Aug 06 19:18:44 laptop kernel: ACPI: PM: Low-level resume complete
Aug 06 19:18:44 laptop kernel: ACPI: EC: EC started
Aug 06 19:18:44 laptop kernel: ACPI: PM: Restoring platform NVS memory
Aug 06 19:18:44 laptop kernel: Enabling non-boot CPUs ...
Aug 06 19:18:44 laptop kernel: smpboot: Booting Node 0 Processor 1 APIC 0x2
Aug 06 19:18:44 laptop kernel: CPU1 is up
Aug 06 19:18:44 laptop kernel: smpboot: Booting Node 0 Processor 2 APIC 0x4
Aug 06 19:18:44 laptop kernel: CPU2 is up
Aug 06 19:18:44 laptop kernel: smpboot: Booting Node 0 Processor 3 APIC 0x6
Aug 06 19:18:44 laptop kernel: CPU3 is up
Aug 06 19:18:44 laptop kernel: smpboot: Booting Node 0 Processor 4 APIC 0x1
Aug 06 19:18:44 laptop kernel: CPU4 is up
Aug 06 19:18:44 laptop kernel: smpboot: Booting Node 0 Processor 5 APIC 0x3
Aug 06 19:18:44 laptop kernel: CPU5 is up
Aug 06 19:18:44 laptop kernel: smpboot: Booting Node 0 Processor 6 APIC 0x5
Aug 06 19:18:44 laptop kernel: CPU6 is up
Aug 06 19:18:44 laptop kernel: smpboot: Booting Node 0 Processor 7 APIC 0x7
Aug 06 19:18:44 laptop kernel: CPU7 is up
Aug 06 19:18:44 laptop kernel: ACPI: PM: Waking up from system sleep state S3
Aug 06 19:18:44 laptop kernel: ACPI: EC: interrupt unblocked
Aug 06 19:18:44 laptop kernel: ACPI: EC: event unblocked
Aug 06 19:18:44 laptop kernel: sd 2:0:0:0: [sda] Starting disk
Aug 06 19:18:44 laptop kernel: i915 0000:00:02.0: [drm] [ENCODER:98:DDI A/PHY A] is disabled/in DSI mode with an ungated DDI clock, gate it
Aug 06 19:18:44 laptop kernel: i915 0000:00:02.0: [drm] [ENCODER:106:DDI B/PHY B] is disabled/in DSI mode with an ungated DDI clock, gate it
Aug 06 19:18:44 laptop kernel: i915 0000:00:02.0: [drm] [ENCODER:115:DDI C/PHY C] is disabled/in DSI mode with an ungated DDI clock, gate it
Aug 06 19:18:44 laptop kernel: nvme nvme0: 8/0/0 default/read/poll queues
Aug 06 19:18:44 laptop kernel: usb 1-11: reset full-speed USB device number 3 using xhci_hcd
Aug 06 19:18:44 laptop kernel: OOM killer enabled.
Aug 06 19:18:44 laptop kernel: Restarting tasks ... 
Aug 06 19:18:44 laptop kernel: mei_hdcp 0000:00:16.0-b638ab7e-94e2-4ea2-a552-d1c54b627f04: bound 0000:00:02.0 (ops i915_hdcp_ops [i915])
Aug 06 19:18:44 laptop kernel: done.
Aug 06 19:18:44 laptop kernel: random: crng reseeded on system resumption
Aug 06 19:18:44 laptop systemd-resolved[483]: Clock change detected. Flushing caches.
Aug 06 19:18:44 laptop bluetoothd[496]: Endpoint unregistered: sender=:1.38 path=/MediaEndpoint/A2DPSink/sbc
Aug 06 19:18:44 laptop systemd-resolved[483]: Grace period over, resuming full feature set (UDP+EDNS0) for DNS server ADDR.
Aug 06 19:18:44 laptop bluetoothd[496]: Endpoint unregistered: sender=:1.38 path=/MediaEndpoint/A2DPSource/sbc
Aug 06 19:18:44 laptop bluetoothd[496]: Endpoint unregistered: sender=:1.38 path=/MediaEndpoint/A2DPSink/sbc_xq_453
Aug 06 19:18:44 laptop bluetoothd[496]: Endpoint unregistered: sender=:1.38 path=/MediaEndpoint/A2DPSource/sbc_xq_453
Aug 06 19:18:44 laptop bluetoothd[496]: Endpoint unregistered: sender=:1.38 path=/MediaEndpoint/A2DPSink/sbc_xq_512
Aug 06 19:18:44 laptop bluetoothd[496]: Endpoint unregistered: sender=:1.38 path=/MediaEndpoint/A2DPSource/sbc_xq_512
Aug 06 19:18:44 laptop bluetoothd[496]: Endpoint unregistered: sender=:1.38 path=/MediaEndpoint/A2DPSink/sbc_xq_552
Aug 06 19:18:44 laptop bluetoothd[496]: Endpoint unregistered: sender=:1.38 path=/MediaEndpoint/A2DPSource/sbc_xq_552
Aug 06 19:18:44 laptop bluetoothd[496]: Endpoint unregistered: sender=:1.38 path=/MediaEndpoint/A2DPSink/faststream
Aug 06 19:18:44 laptop bluetoothd[496]: Endpoint unregistered: sender=:1.38 path=/MediaEndpoint/A2DPSource/faststream
Aug 06 19:18:44 laptop bluetoothd[496]: Battery Provider Manager destroyed
Aug 06 19:18:44 laptop systemd-sleep[3718789]: System returned from sleep operation 'suspend'.
Aug 06 19:18:44 laptop kernel: PM: suspend exit
Aug 06 19:18:44 laptop kernel: Bluetooth: hci0: Bootloader revision 0.0 build 26 week 38 2015
Aug 06 19:18:44 laptop kernel: Bluetooth: hci0: Device revision is 16
Aug 06 19:18:44 laptop kernel: Bluetooth: hci0: Secure boot is enabled
Aug 06 19:18:44 laptop kernel: Bluetooth: hci0: OTP lock is enabled
Aug 06 19:18:44 laptop kernel: Bluetooth: hci0: API lock is enabled
Aug 06 19:18:44 laptop kernel: Bluetooth: hci0: Debug lock is disabled
Aug 06 19:18:44 laptop kernel: Bluetooth: hci0: Minimum firmware build 1 week 10 2014
Aug 06 19:18:44 laptop kernel: Bluetooth: hci0: Found device firmware: intel/ibt-12-16.sfi
Aug 06 19:18:44 laptop systemd[1]: Starting Daily man-db regeneration...
Aug 06 19:18:44 laptop kernel: ata3: SATA link up 6.0 Gbps (SStatus 133 SControl 300)
Aug 06 19:18:44 laptop systemd[1]: Started Verify integrity of password and group files.
Aug 06 19:18:44 laptop systemd[1]: Starting Update locate database...
Aug 06 19:18:44 laptop systemd[634]: Stopped target Bluetooth.
Aug 06 19:18:44 laptop pulseaudio[731]: org.bluez.BatteryProviderManager1.UnregisterBatteryProvider() Failed: org.freedesktop.DBus.Error.UnknownObject:Method "UnregisterBatteryProvider" with signature "o" on interface "org.bluez.BatteryProviderManager1" doesn't exist
Aug 06 19:18:44 laptop systemd-sleep[3718789]: Successfully thawed unit 'user.slice'.
Aug 06 19:18:44 laptop systemd[1]: systemd-suspend.service: Deactivated successfully.
Aug 06 19:18:44 laptop systemd[1]: Finished System Suspend.
Aug 06 19:18:44 laptop systemd[1]: Stopped target Bluetooth Support.
Aug 06 19:18:44 laptop systemd[1]: Stopped target Sleep.
Aug 06 19:18:44 laptop systemd[1]: Reached target Suspend.
Aug 06 19:18:44 laptop systemd[1]: Stopped target Suspend.
Aug 06 19:18:44 laptop systemd-logind[499]: Operation 'suspend' finished.

As far as I see, the only significant difference is a CTRL-EVENT-SCAN-FAILED from wpa-supplicant but perhaps it is irrelevant.

Relevant system information

uname -a : Linux chilliarch 6.10.3-arch1-2 #1 SMP PREEMPT_DYNAMIC Tue, 06 Aug 2024 07:21:19 +0000 x86_64 GNU/Linux

Please let me know if you need anything further to diagnose the issue. I had tried using an lts kernel to avoid this issue, but it gave the same result.

seth · 2024-08-08 14:43:28

There's a bunch of threads about lenovo and S3 (and s2idle) issues, notably related to the involvement of the lid and a power charger/dock
1. can you spot any pattern wrt the latter
2. is s2idle more reliable (did you have to cheat the BIOS to even activate S3)?
3. ceterum censeo: is there a parallel windows installation?

Last edited by seth (2024-08-08 14:43:58)

razimantv · 2024-08-08 17:03:56

seth wrote:

There's a bunch of threads about lenovo and S3 (and s2idle) issues, notably related to the involvement of the lid and a power charger/dock
1. can you spot any pattern wrt the latter

No. I always have power and a mouse connected, but that's it. The lid is always open and I am trying to get to Sleep mode manually.

2. is s2idle more reliable (did you have to cheat the BIOS to even activate S3)?

I don't remember tinkering with these settings. /sys/power/mem_sleep shows

s2idle [deep]

So I assume that S3 sleep is the default. Should I try s2idle instead?

3. ceterum censeo: is there a parallel windows installation?

Yes but I only open it once a few months. What do you suspect?

seth · 2024-08-08 20:12:01

3rd link below. Mandatory.
Disable it (it's NOT the BIOS setting!) and reboot windows and linux twice for voodo reasons.

Usage frequency doesn't matter at all, also nb. that windows keeps re-enabling it with updates, so don't just rely on "I disabled that 2 years ago"

Is this doesn't help try s2idle, yes.

razimantv · 2024-08-08 20:58:07

I tried s2idle but the fan and the keyboard backlight remain on (though I am able to press the power button and log back in). So I am not sure that is the solution.

seth · 2024-08-08 21:34:34

Did you review the fast-start situation?

The notebook might not properly support s2idle, please post the complete system journals for an s2idle and an S3 boot (for the latter good & bad if you can) - google responds with completely differen HW for that model, apparently there's an intel+nvidia and an AMD version? At least?

razimantv · 2024-08-09 08:53:02

Apologies. I missed your previous message.

I booted into Windows 11 and checked that hyberfil.sys did not exist and that powercfg /h off did not change the output of powercfg /q (hybrid sleep was showing as disabled already). I am thus inclined to believe that Windows fast-start was not enabled.

The exact model I have is Lenovo Y520-15IKBN. It came with integrated intel GPU + Nvidia. But the Nvidia card burnt out a few years ago, so it is disabled in BIOS.

I will now try to generate the full logs (I suppose you just want the output of journalctl for a given boot?).

[Edit: This is taking a while as the failure happens randomly and is not easy to reproduce]

Last edited by razimantv (2024-08-09 08:58:34)

seth · 2024-08-09 14:46:09

Is this a recent development?
https://bbs.archlinux.org/viewtopic.php?id=296954

razimantv · 2024-08-09 23:09:45

No, it has been going on for months at least.

[Edit: All my sleep attempts have been successful since the last post. I will share the log here if/when there is a failure]

Last edited by razimantv (2024-08-09 23:10:53)

razimantv · 2024-08-11 08:06:46

Finally, suspend failed again. Here is the log from boot through multiple successful sleeps until the final failure.

seth · 2024-08-11 15:32:04

So there're 22 S3 cycles over ~48h, but most of them very short (probably for testing) one for like 45m and then we end

Aug 10 00:40:22 laptop systemd[1]: Reached target Sleep.
Aug 10 11:20:54 laptop systemd[1]: Stopped target Sleep.

Aug 10 14:48:15 laptop systemd[1]: Reached target Sleep.
Aug 10 19:14:23 laptop systemd[1]: Stopped target Sleep.

Aug 11 08:42:30 laptop systemd[1]: Reached target Sleep.

With two longer sleep cycles and the last one being the failure.
There's nothing obvious between the last wakeup and final failing attempt.

Generally:
- https://wiki.archlinux.org/title/Solid_ … leshooting
-

Aug 09 09:54:55 laptop udisksd[971]: Error probing device: Error sending ATA command IDENTIFY DEVICE to '/dev/sda': Unexpected sense data returned:
Aug 10 11:22:33 laptop udisksd[971]: Error probing device: Error sending ATA command IDENTIFY DEVICE to '/dev/sda': Unexpected sense data returned:
Aug 10 11:22:34 laptop udisksd[971]: Error probing device: Error sending ATA command IDENTIFY DEVICE to '/dev/sda': Unexpected sense data returned:

=> https://wiki.archlinux.org/title/SMART
- you re-lease about every 7.30 minutes with the AP - do you actually have this short of a lease time???

razimantv · 2024-08-12 10:23:19

Sorry, I did not understand parts of your comment.

seth wrote:

Generally:
- https://wiki.archlinux.org/title/Solid_ … leshooting
-
Aug 09 09:54:55 laptop udisksd[971]: Error probing device: Error sending ATA command IDENTIFY DEVICE to '/dev/sda': Unexpected sense data returned:
Aug 10 11:22:33 laptop udisksd[971]: Error probing device: Error sending ATA command IDENTIFY DEVICE to '/dev/sda': Unexpected sense data returned:
Aug 10 11:22:34 laptop udisksd[971]: Error probing device: Error sending ATA command IDENTIFY DEVICE to '/dev/sda': Unexpected sense data returned:
=> https://wiki.archlinux.org/title/SMART
- you re-lease about every 7.30 minutes with the AP - do you actually have this short of a lease time???

/dev/sda is an HDD, not an SSD. And I don't understand the sentence about re-lease with the AP at all. What do I need to check?

seth · 2024-08-12 14:30:38

You've an nvme which are frequent sources of trouble b/c of APST and your HDD somewhat acts up which is why I'd suggest to look at the smart data.

Wrt the re-lease situation, your system asks the router for a new permit every 7.30 minutes, what suggests an assumed lease time of 8 minutes or a network problem (possibly related to the previous fast-start situation, you might wanna reboot the router)
There's nothing per se wrong w/ 8 minute leases, but it's excessively low - you'd comonly expect anything between 30 minutes and 24h

And since there's no log hinting at what causes the suspend failure, we're approaching it with a shotgun and just look at everything that sticks out or could pot. be an issue.

razimantv · 2024-08-13 08:09:21

Here is the output of smartctl - x for the two drives. There is quite some pre-fail, but nothing unusual I suppose?

I use eduroam from the university with Zscaler on top to connect to the intranet of a different network (suspend issue persists without Zscaler). So the lease time is not under my control.

seth · 2024-08-15 14:26:20

You ran smartctl on the nvme, that's not the flaring up device

smartctl -a /dev/sda

For the nvme, just try to disable APST and iommu and see whether that has any positive impact.

razimantv · 2024-08-15 15:43:47

seth wrote:

You ran smartctl on the nvme, that's not the flaring up device
smartctl -a /dev/sda

The gist I shared has the result for both drives, in separate files.

seth · 2024-08-15 19:55:35

Sorry, ( i use a simple script to get the raw out of the gist. the first raw, that is… people post like 2.2MB journals and gists really suck for that )

199 UDMA_CRC_Error_Count    -OSRCK   200   199   000    -    52

would rather point to the bus than the drive (which otherwise looks healthy)

Have you
1. disabled APST & the IOMMU
2. experienced another wakeup failure (since)?

razimantv · 2024-08-16 10:29:44

1. Yes
2. Not yet.

razimantv · 2024-08-22 17:38:22

Ah well it happened again. I should just give up at this point. Thank you for the attempt.

seth · 2024-08-22 20:09:22

Would you say there's been any change in the frequency?
How often does this happen anyway (it's been a couple of days and if this only happens, say, every 30 suspends in a row, you might be dealing w/ a RAM refresh issue)

Any pattern to the occurrences? (Only when sleeping very long, only when short on battery, … stuff like that)

razimantv · 2024-08-23 09:17:44

I only suspend once or twice a day. Frequency is usually once every few (~5 perhaps) suspends, so I don't think it has changed. No identifiable pattern yet.

seth · 2024-08-23 13:09:15

If you've a spare moment you could try to force it by suspending for only 60s until you hit this or get tired of it.
Also

No. I always have power and a mouse connected, but that's it.

Does moving the mouse or unplugging it or the power connector break the suspend and wake the system?

razimantv · 2024-08-25 13:59:28

I think I tried 10 times back to back, all successful.

Mouse motion and unplugging power do not wake the laptop.

seth · 2024-08-25 14:09:01

Uptime? Can you keep the system running for 2-3 days w/o sleeping it and see whether the subsequent sleep is an immediate fail?

razimantv · 2024-08-28 18:04:30

Tried suspend after ~2 days without sleep and it failed.

Arch Linux

#1 2024-08-08 09:59:31

Unreliable behaviour of suspend

#2 2024-08-08 14:43:28

Re: Unreliable behaviour of suspend

#3 2024-08-08 17:03:56

Re: Unreliable behaviour of suspend

#4 2024-08-08 20:12:01

Re: Unreliable behaviour of suspend

#5 2024-08-08 20:58:07

Re: Unreliable behaviour of suspend

#6 2024-08-08 21:34:34

Re: Unreliable behaviour of suspend

#7 2024-08-09 08:53:02

Re: Unreliable behaviour of suspend

#8 2024-08-09 14:46:09

Re: Unreliable behaviour of suspend

#9 2024-08-09 23:09:45

Re: Unreliable behaviour of suspend

#10 2024-08-11 08:06:46

Re: Unreliable behaviour of suspend

#11 2024-08-11 15:32:04

Re: Unreliable behaviour of suspend

#12 2024-08-12 10:23:19

Re: Unreliable behaviour of suspend

#13 2024-08-12 14:30:38

Re: Unreliable behaviour of suspend

#14 2024-08-13 08:09:21

Re: Unreliable behaviour of suspend

#15 2024-08-15 14:26:20

Re: Unreliable behaviour of suspend

#16 2024-08-15 15:43:47

Re: Unreliable behaviour of suspend

#17 2024-08-15 19:55:35

Re: Unreliable behaviour of suspend

#18 2024-08-16 10:29:44

Re: Unreliable behaviour of suspend

#19 2024-08-22 17:38:22

Re: Unreliable behaviour of suspend

#20 2024-08-22 20:09:22

Re: Unreliable behaviour of suspend

#21 2024-08-23 09:17:44

Re: Unreliable behaviour of suspend

#22 2024-08-23 13:09:15

Re: Unreliable behaviour of suspend

#23 2024-08-25 13:59:28

Re: Unreliable behaviour of suspend

#24 2024-08-25 14:09:01

Re: Unreliable behaviour of suspend

#25 2024-08-28 18:04:30

Re: Unreliable behaviour of suspend

Board footer