[TRACKING] Waking from Sleep when plugged in (AMD/(K)Ubuntu 22.04)

I’m wondering if anyone has figured out how to have Sleep work properly when the laptop is plugged in?

I configured my laptop to Sleep when I close the lid when plugged in, however it seems to wake up after a few minutes.
This doesn’t seem to occur when the laptop is on battery.

I’m guessing this has something to do with the battery being fully charged and the charger switching on and off - but that’s just a guess.

Has anyone else figured out how to fix this?

I’m running Kubuntu 22.04 with the following Kernel:

Linux Sterling 6.1.0-1026-oem #26-Ubuntu SMP PREEMPT_DYNAMIC Wed Nov  1 14:06:23 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux

No external devices are plugged in.

Hi @Florian_Jensen ,

Can you attach the whole current journal logs, to check what’s happening in the bakcground?

jouranlctl -b 0

what are the apps running?

Hey,

here’s the relevant section of the logs with the sleep request and it waking back up ~15 minutes later.

ene 26 00:13:34 Sterling rtkit-daemon[1603]: Supervising 1 threads of 1 processes of 1 users.
ene 26 00:13:34 Sterling rtkit-daemon[1603]: Supervising 1 threads of 1 processes of 1 users.
ene 26 00:13:39 Sterling rtkit-daemon[1603]: Supervising 1 threads of 1 processes of 1 users.
ene 26 00:13:39 Sterling rtkit-daemon[1603]: Supervising 1 threads of 1 processes of 1 users.
ene 26 00:13:58 Sterling krunner[3055]: QCommandLineParser: argument list cannot be empty, it should contain at least the executable name
ene 26 00:13:58 Sterling kwin_x11[1936]: qt.qpa.xcb: QXcbConnection: XCB error: 9 (BadDrawable), sequence: 41620, resource id: 67109430, major code: 73 (GetImage), minor code: 0
ene 26 00:14:00 Sterling kwin_x11[1936]: qt.qpa.xcb: QXcbConnection: XCB error: 9 (BadDrawable), sequence: 41959, resource id: 67109440, major code: 14 (GetGeometry), minor code: 0
ene 26 00:14:00 Sterling kwin_x11[1936]: qt.qpa.xcb: QXcbConnection: XCB error: 9 (BadDrawable), sequence: 41960, resource id: 67109440, major code: 14 (GetGeometry), minor code: 0
ene 26 00:14:00 Sterling kwin_x11[1936]: qt.qpa.xcb: QXcbConnection: XCB error: 9 (BadDrawable), sequence: 41966, resource id: 67109440, major code: 14 (GetGeometry), minor code: 0
ene 26 00:14:05 Sterling kernel: Lockdown: systemd-logind: hibernation is restricted; see man kernel_lockdown.7
ene 26 00:14:05 Sterling NetworkManager[1266]: <info>  [1706224445.4993] manager: sleep: sleep requested (sleeping: no  enabled: yes)
ene 26 00:14:05 Sterling NetworkManager[1266]: <info>  [1706224445.4994] manager: NetworkManager state is now ASLEEP
ene 26 00:14:05 Sterling ModemManager[1357]: <info>  [sleep-monitor-systemd] system is about to suspend
ene 26 00:14:05 Sterling NetworkManager[1266]: <info>  [1706224445.4996] device (wlp1s0): state change: activated -> deactivating (reason 'sleeping', sys-iface-state: 'managed')
ene 26 00:14:05 Sterling kernel: Lockdown: systemd-logind: hibernation is restricted; see man kernel_lockdown.7
ene 26 00:14:05 Sterling kded5[1935]: org.kde.plasma.nm.kded: Unhandled active connection state change:  3
ene 26 00:14:05 Sterling dbus-daemon[1264]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.11' (uid=0 pid=1266 comm="/usr/sbin/NetworkManager --no-daemon " label="unconfined")
ene 26 00:14:05 Sterling systemd[1]: Starting Network Manager Script Dispatcher Service...
ene 26 00:14:05 Sterling dbus-daemon[1264]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
ene 26 00:14:05 Sterling systemd[1]: Started Network Manager Script Dispatcher Service.
ene 26 00:14:05 Sterling kernel: wlp1s0: deauthenticating from f8:32:e4:a6:da:c6 by local choice (Reason: 3=DEAUTH_LEAVING)
ene 26 00:14:05 Sterling ksmserver[21513]: Qt: Session management error: networkIdsList argument is NULL
ene 26 00:14:05 Sterling kernel: Lockdown: systemd-logind: hibernation is restricted; see man kernel_lockdown.7
ene 26 00:14:05 Sterling kernel: Lockdown: systemd-logind: hibernation is restricted; see man kernel_lockdown.7
ene 26 00:14:05 Sterling kernel: Lockdown: systemd-logind: hibernation is restricted; see man kernel_lockdown.7
ene 26 00:14:05 Sterling ksmserver[21513]: kf.kirigami: Failed to find a Kirigami platform plugin
ene 26 00:14:05 Sterling wpa_supplicant[1300]: wlp1s0: CTRL-EVENT-DISCONNECTED bssid=f8:32:e4:a6:da:c6 reason=3 locally_generated=1
ene 26 00:14:05 Sterling wpa_supplicant[1300]: wlp1s0: CTRL-EVENT-DSCP-POLICY clear_all
ene 26 00:14:05 Sterling wpa_supplicant[1300]: wlp1s0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
ene 26 00:14:05 Sterling NetworkManager[1266]: <info>  [1706224445.8661] device (wlp1s0): state change: deactivating -> disconnected (reason 'sleeping', sys-iface-state: 'managed')
ene 26 00:14:05 Sterling avahi-daemon[1260]: Withdrawing address record for 2001:470:1936::9102:eaea on wlp1s0.
ene 26 00:14:05 Sterling avahi-daemon[1260]: Withdrawing address record for 2001:470:1936:0:c171:5024:ae21:74ff on wlp1s0.
ene 26 00:14:05 Sterling avahi-daemon[1260]: Withdrawing address record for 2001:470:1936:0:9221:9ac0:f3e2:c5da on wlp1s0.
ene 26 00:14:05 Sterling avahi-daemon[1260]: Leaving mDNS multicast group on interface wlp1s0.IPv6 with address 2001:470:1936:0:9221:9ac0:f3e2:c5da.
ene 26 00:14:05 Sterling avahi-daemon[1260]: Joining mDNS multicast group on interface wlp1s0.IPv6 with address fe80::8b80:4c9a:6174:2460.
ene 26 00:14:05 Sterling avahi-daemon[1260]: Registering new address record for fe80::8b80:4c9a:6174:2460 on wlp1s0.*.
ene 26 00:14:05 Sterling avahi-daemon[1260]: Withdrawing address record for fe80::8b80:4c9a:6174:2460 on wlp1s0.
ene 26 00:14:05 Sterling avahi-daemon[1260]: Leaving mDNS multicast group on interface wlp1s0.IPv6 with address fe80::8b80:4c9a:6174:2460.
ene 26 00:14:05 Sterling avahi-daemon[1260]: Interface wlp1s0.IPv6 no longer relevant for mDNS.
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling NetworkManager[1266]: <info>  [1706224445.9015] dhcp4 (wlp1s0): canceled DHCP transaction
ene 26 00:14:05 Sterling NetworkManager[1266]: <info>  [1706224445.9016] dhcp4 (wlp1s0): activation: beginning transaction (timeout in 45 seconds)
ene 26 00:14:05 Sterling NetworkManager[1266]: <info>  [1706224445.9016] dhcp4 (wlp1s0): state changed no lease
ene 26 00:14:05 Sterling NetworkManager[1266]: <info>  [1706224445.9018] dhcp6 (wlp1s0): canceled DHCP transaction
ene 26 00:14:05 Sterling NetworkManager[1266]: <info>  [1706224445.9018] dhcp6 (wlp1s0): activation: beginning transaction (timeout in 45 seconds)
ene 26 00:14:05 Sterling NetworkManager[1266]: <info>  [1706224445.9018] dhcp6 (wlp1s0): state changed no lease
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling avahi-daemon[1260]: Withdrawing address record for 10.0.0.114 on wlp1s0.
ene 26 00:14:05 Sterling avahi-daemon[1260]: Leaving mDNS multicast group on interface wlp1s0.IPv4 with address 10.0.0.114.
ene 26 00:14:05 Sterling systemd-resolved[1189]: wlp1s0: Bus client reset search domain list.
ene 26 00:14:05 Sterling avahi-daemon[1260]: Interface wlp1s0.IPv4 no longer relevant for mDNS.
ene 26 00:14:05 Sterling systemd-resolved[1189]: wlp1s0: Bus client set default route setting: no
ene 26 00:14:05 Sterling systemd-resolved[1189]: wlp1s0: Bus client reset DNS server list.
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling plasmashell[1975]: QXcbClipboard::setMimeData: Cannot set X11 selection owner
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling plasmashell[1975]: QXcbClipboard::setMimeData: Cannot set X11 selection owner
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling ksmserver[21513]: QXcbClipboard: SelectionRequest too old
ene 26 00:14:05 Sterling NetworkManager[1266]: <info>  [1706224445.9644] device (wlp1s0): supplicant interface state: completed -> disconnected
ene 26 00:14:05 Sterling NetworkManager[1266]: <info>  [1706224445.9656] device (wlp1s0): state change: disconnected -> unmanaged (reason 'sleeping', sys-iface-state: 'managed')
ene 26 00:14:06 Sterling wpa_supplicant[1300]: wlp1s0: CTRL-EVENT-DSCP-POLICY clear_all
ene 26 00:14:06 Sterling systemd[1]: Reached target Sleep.
ene 26 00:14:06 Sterling systemd[1]: Starting Record successful boot for GRUB...
ene 26 00:14:06 Sterling systemd[1]: Starting System Suspend...
ene 26 00:14:06 Sterling systemd-sleep[21555]: Entering sleep state 'suspend'...
ene 26 00:14:06 Sterling kernel: PM: suspend entry (s2idle)
ene 26 00:14:06 Sterling systemd[1]: grub-common.service: Deactivated successfully.
ene 26 00:14:06 Sterling systemd[1]: Finished Record successful boot for GRUB.
ene 26 00:14:06 Sterling systemd[1]: Starting GRUB failed boot detection...
ene 26 00:14:06 Sterling systemd[1]: grub-initrd-fallback.service: Deactivated successfully.
ene 26 00:14:06 Sterling systemd[1]: Finished GRUB failed boot detection.
ene 26 00:14:06 Sterling kernel: Filesystems sync: 0.007 seconds
ene 26 00:14:06 Sterling wpa_supplicant[1300]: wlp1s0: CTRL-EVENT-DSCP-POLICY clear_all
ene 26 00:14:06 Sterling wpa_supplicant[1300]: nl80211: deinit ifname=wlp1s0 disabled_11b_rates=0
ene 26 00:31:27 Sterling kernel: Freezing user space processes
ene 26 00:31:27 Sterling kernel: Freezing user space processes completed (elapsed 0.002 seconds)
ene 26 00:31:27 Sterling kernel: OOM killer disabled.
ene 26 00:31:27 Sterling kernel: Freezing remaining freezable tasks
ene 26 00:31:27 Sterling kernel: Freezing remaining freezable tasks completed (elapsed 0.001 seconds)
ene 26 00:31:27 Sterling kernel: printk: Suspending console(s) (use no_console_suspend to debug)
ene 26 00:31:27 Sterling kernel: ACPI: EC: interrupt blocked
ene 26 00:31:27 Sterling kernel: ACPI: EC: interrupt unblocked
ene 26 00:31:27 Sterling kernel: nvme nvme0: 16/0/0 default/read/poll queues
ene 26 00:31:27 Sterling kernel: [drm:mes_v11_0_submit_pkt_and_poll_completion.constprop.0 [amdgpu]] *ERROR* MES failed to response msg=14
ene 26 00:31:27 Sterling kernel: [drm:amdgpu_mes_reg_write_reg_wait [amdgpu]] *ERROR* failed to reg_write_reg_wait
ene 26 00:31:27 Sterling kernel: [drm] PCIE GART of 512M enabled (table at 0x000000801FD00000).
ene 26 00:31:27 Sterling kernel: amdgpu 0000:c1:00.0: amdgpu: SMU is resuming...
ene 26 00:31:27 Sterling kernel: amdgpu 0000:c1:00.0: amdgpu: SMU is resumed successfully!
ene 26 00:31:27 Sterling kernel: [drm] Watermarks table not configured properly by SMU
ene 26 00:31:27 Sterling kernel: [drm] VCN decode and encode initialized successfully(under DPG Mode).
ene 26 00:31:27 Sterling kernel: amdgpu 0000:c1:00.0: [drm:jpeg_v4_0_hw_init [amdgpu]] JPEG decode initialized successfully.
ene 26 00:31:27 Sterling kernel: amdgpu 0000:c1:00.0: amdgpu: ring gfx_0.0.0 uses VM inv eng 0 on hub 0
ene 26 00:31:27 Sterling kernel: amdgpu 0000:c1:00.0: amdgpu: ring comp_1.0.0 uses VM inv eng 1 on hub 0
ene 26 00:31:27 Sterling kernel: amdgpu 0000:c1:00.0: amdgpu: ring comp_1.1.0 uses VM inv eng 4 on hub 0
ene 26 00:31:27 Sterling kernel: amdgpu 0000:c1:00.0: amdgpu: ring comp_1.2.0 uses VM inv eng 6 on hub 0
ene 26 00:31:27 Sterling kernel: amdgpu 0000:c1:00.0: amdgpu: ring comp_1.3.0 uses VM inv eng 7 on hub 0
ene 26 00:31:27 Sterling kernel: amdgpu 0000:c1:00.0: amdgpu: ring comp_1.0.1 uses VM inv eng 8 on hub 0
ene 26 00:31:27 Sterling kernel: amdgpu 0000:c1:00.0: amdgpu: ring comp_1.1.1 uses VM inv eng 9 on hub 0
ene 26 00:31:27 Sterling kernel: amdgpu 0000:c1:00.0: amdgpu: ring comp_1.2.1 uses VM inv eng 10 on hub 0
ene 26 00:31:27 Sterling kernel: amdgpu 0000:c1:00.0: amdgpu: ring comp_1.3.1 uses VM inv eng 11 on hub 0
ene 26 00:31:27 Sterling kernel: amdgpu 0000:c1:00.0: amdgpu: ring sdma0 uses VM inv eng 12 on hub 0
ene 26 00:31:27 Sterling kernel: amdgpu 0000:c1:00.0: amdgpu: ring vcn_unified_0 uses VM inv eng 0 on hub 1
ene 26 00:31:27 Sterling kernel: amdgpu 0000:c1:00.0: amdgpu: ring jpeg_dec uses VM inv eng 1 on hub 1
ene 26 00:31:27 Sterling kernel: amdgpu 0000:c1:00.0: amdgpu: ring mes_kiq_3.1.0 uses VM inv eng 13 on hub 0
ene 26 00:31:27 Sterling kernel: [drm] ring gfx_32793.1.1 was added
ene 26 00:31:27 Sterling kernel: [drm] ring compute_32793.2.2 was added
ene 26 00:31:27 Sterling kernel: [drm] ring sdma_32793.3.3 was added
ene 26 00:31:27 Sterling kernel: [drm] ring gfx_32793.1.1 test pass
ene 26 00:31:27 Sterling kernel: [drm] ring gfx_32793.1.1 ib test pass
ene 26 00:31:27 Sterling kernel: [drm] ring compute_32793.2.2 test pass
ene 26 00:31:27 Sterling kernel: [drm] ring compute_32793.2.2 ib test pass
ene 26 00:31:27 Sterling kernel: [drm] ring sdma_32793.3.3 test pass
ene 26 00:31:27 Sterling kernel: [drm] ring sdma_32793.3.3 ib test pass
ene 26 00:31:27 Sterling kernel: OOM killer enabled.
ene 26 00:31:27 Sterling systemd-resolved[1189]: Clock change detected. Flushing caches.
ene 26 00:31:27 Sterling rtkit-daemon[1603]: The canary thread is apparently starving. Taking action.
ene 26 00:31:27 Sterling rtkit-daemon[1603]: Demoting known real-time threads.
ene 26 00:31:27 Sterling rtkit-daemon[1603]: Successfully demoted thread 14886 of process 2173.
ene 26 00:31:27 Sterling rtkit-daemon[1603]: Demoted 1 threads.
ene 26 00:31:27 Sterling kernel: Restarting tasks ... done.
ene 26 00:31:27 Sterling kernel: random: crng reseeded on system resumption
ene 26 00:31:27 Sterling systemd-sleep[21555]: System returned from sleep state.
ene 26 00:31:27 Sterling kernel: PM: suspend exit
ene 26 00:31:27 Sterling bluetoothd[1261]: Controller resume with wake event 0x0
ene 26 00:31:27 Sterling systemd[1]: Starting Daily apt download activities...
ene 26 00:31:27 Sterling systemd[1]: systemd-suspend.service: Deactivated successfully.
ene 26 00:31:27 Sterling systemd[1]: Finished System Suspend.
ene 26 00:31:27 Sterling systemd[1]: Stopped target Sleep.
ene 26 00:31:27 Sterling systemd[1]: Reached target Suspend.
ene 26 00:31:27 Sterling systemd[1]: Stopped target Suspend.
ene 26 00:31:27 Sterling systemd-logind[1296]: Operation 'sleep' finished.
ene 26 00:31:27 Sterling ModemManager[1357]: <info>  [sleep-monitor-systemd] system is resuming
ene 26 00:31:27 Sterling NetworkManager[1266]: <info>  [1706225487.1613] manager: sleep: wake requested (sleeping: yes  enabled: yes)
ene 26 00:31:27 Sterling NetworkManager[1266]: <info>  [1706225487.1614] device (wlp1s0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
ene 26 00:31:27 Sterling PackageKit[2162]: get-updates transaction /2105_cedbdebb from uid 1000 finished with success after 4390ms
ene 26 00:31:27 Sterling NetworkManager[1266]: <info>  [1706225487.2502] manager: NetworkManager state is now DISCONNECTED
ene 26 00:31:27 Sterling wpa_supplicant[1300]: dbus: fill_dict_with_properties dbus_interface=fi.w1.wpa_supplicant1.Interface.P2PDevice dbus_property=P2PDeviceConfig getter failed
ene 26 00:31:27 Sterling NetworkManager[1266]: <info>  [1706225487.3036] device (wlp1s0): supplicant interface state: internal-starting -> disconnected
ene 26 00:31:27 Sterling NetworkManager[1266]: <info>  [1706225487.3037] device (wlp1s0): state change: unavailable -> disconnected (reason 'supplicant-available', sys-iface-state: 'managed')
ene 26 00:31:28 Sterling wpa_supplicant[1300]: wlp1s0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
ene 26 00:31:29 Sterling ModemManager[1357]: <info>  [base-manager] couldn't check support for device '/sys/devices/pci0000:00/0000:00:02.2/0000:01:00.0': not supported by any plugin
ene 26 00:31:32 Sterling systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
ene 26 00:31:37 Sterling plasmashell[1975]: Could not find the Plasmoid for Plasma::FrameSvgItem(0x5625258b0990) QQmlContext(0x5625230634b0) QUrl("file:///usr/share/plasma/plasmoids/org.kde.plasma.notifications/contents/ui/global/Globals.qml")
ene 26 00:31:37 Sterling wpa_supplicant[1300]: wlp1s0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
ene 26 00:31:38 Sterling wpa_supplicant[1300]: wlp1s0: CTRL-EVENT-REGDOM-CHANGE init=BEACON_HINT type=UNKNOWN
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.6329] policy: auto-activating connection 'Porque-Fi 5-1' (722cdfff-1009-419d-b2a3-1ad75fc29578)
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.6333] device (wlp1s0): Activation: starting connection 'Porque-Fi 5-1' (722cdfff-1009-419d-b2a3-1ad75fc29578)
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.6333] device (wlp1s0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.6335] manager: NetworkManager state is now CONNECTING
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.6336] device (wlp1s0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.6338] device (wlp1s0): Activation: (wifi) access point 'Porque-Fi 5-1' has security, but secrets are required.
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.6338] device (wlp1s0): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed')
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.6458] device (wlp1s0): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.6461] device (wlp1s0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.6463] device (wlp1s0): Activation: (wifi) connection 'Porque-Fi 5-1' has security, and secrets exist.  No new secrets needed.
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.6463] Config: added 'ssid' value 'Porque-Fi 5-1'
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.6464] Config: added 'scan_ssid' value '1'
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.6464] Config: added 'bgscan' value 'simple:30:-70:86400'
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.6464] Config: added 'key_mgmt' value 'WPA-PSK WPA-PSK-SHA256 FT-PSK SAE FT-SAE'
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.6464] Config: added 'auth_alg' value 'OPEN'
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.6464] Config: added 'psk' value '<hidden>'
ene 26 00:31:38 Sterling wpa_supplicant[1300]: wlp1s0: SME: Trying to authenticate with f8:32:e4:a6:da:c6 (SSID='Porque-Fi 5-1' freq=5260 MHz)
ene 26 00:31:38 Sterling kernel: wlp1s0: authenticate with f8:32:e4:a6:da:c6
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.6933] device (wlp1s0): supplicant interface state: disconnected -> authenticating
ene 26 00:31:38 Sterling kernel: wlp1s0: send auth to f8:32:e4:a6:da:c6 (try 1/3)
ene 26 00:31:38 Sterling kernel: wlp1s0: authenticated
ene 26 00:31:38 Sterling wpa_supplicant[1300]: wlp1s0: Trying to associate with f8:32:e4:a6:da:c6 (SSID='Porque-Fi 5-1' freq=5260 MHz)
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.6959] device (wlp1s0): supplicant interface state: authenticating -> associating
ene 26 00:31:38 Sterling kernel: wlp1s0: associate with f8:32:e4:a6:da:c6 (try 1/3)
ene 26 00:31:38 Sterling kernel: wlp1s0: RX AssocResp from f8:32:e4:a6:da:c6 (capab=0x11 status=0 aid=4)
ene 26 00:31:38 Sterling kernel: wlp1s0: associated
ene 26 00:31:38 Sterling wpa_supplicant[1300]: wlp1s0: Associated with f8:32:e4:a6:da:c6
ene 26 00:31:38 Sterling wpa_supplicant[1300]: wlp1s0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.7457] device (wlp1s0): supplicant interface state: associating -> 4way_handshake
ene 26 00:31:38 Sterling wpa_supplicant[1300]: wlp1s0: WPA: Key negotiation completed with f8:32:e4:a6:da:c6 [PTK=CCMP GTK=CCMP]
ene 26 00:31:38 Sterling kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlp1s0: link becomes ready
ene 26 00:31:38 Sterling wpa_supplicant[1300]: wlp1s0: CTRL-EVENT-CONNECTED - Connection to f8:32:e4:a6:da:c6 completed [id=0 id_str=]
ene 26 00:31:38 Sterling wpa_supplicant[1300]: bgscan simple: Failed to enable signal strength monitoring
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.9257] device (wlp1s0): supplicant interface state: 4way_handshake -> completed
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.9258] device (wlp1s0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Connected to wireless network "Porque-Fi 5-1"
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.9260] device (wlp1s0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
ene 26 00:31:38 Sterling NetworkManager[1266]: <info>  [1706225498.9265] dhcp4 (wlp1s0): activation: beginning transaction (timeout in 45 seconds)
ene 26 00:31:38 Sterling avahi-daemon[1260]: Joining mDNS multicast group on interface wlp1s0.IPv6 with address fe80::8b80:4c9a:6174:2460.
ene 26 00:31:38 Sterling avahi-daemon[1260]: New relevant interface wlp1s0.IPv6 for mDNS.
ene 26 00:31:38 Sterling avahi-daemon[1260]: Registering new address record for fe80::8b80:4c9a:6174:2460 on wlp1s0.*.
ene 26 00:31:40 Sterling NetworkManager[1266]: <info>  [1706225500.5936] dhcp6 (wlp1s0): activation: beginning transaction (timeout in 45 seconds)
ene 26 00:31:40 Sterling avahi-daemon[1260]: Leaving mDNS multicast group on interface wlp1s0.IPv6 with address fe80::8b80:4c9a:6174:2460.
ene 26 00:31:40 Sterling avahi-daemon[1260]: Joining mDNS multicast group on interface wlp1s0.IPv6 with address 2001:470:1936:0:9221:9ac0:f3e2:c5da.
ene 26 00:31:40 Sterling avahi-daemon[1260]: Registering new address record for 2001:470:1936:0:9221:9ac0:f3e2:c5da on wlp1s0.*.
ene 26 00:31:40 Sterling avahi-daemon[1260]: Withdrawing address record for fe80::8b80:4c9a:6174:2460 on wlp1s0.
ene 26 00:31:40 Sterling NetworkManager[1266]: <info>  [1706225500.5973] dhcp6 (wlp1s0): state changed new lease, address=2001:470:1936::9102:eaea
ene 26 00:31:40 Sterling dbus-daemon[1264]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.11' (uid=0 pid=1266 comm="/usr/sbin/NetworkManager --no-daemon " label="unconfined")
ene 26 00:31:40 Sterling avahi-daemon[1260]: Registering new address record for 2001:470:1936::9102:eaea on wlp1s0.*.
ene 26 00:31:40 Sterling systemd[1]: Starting Network Manager Script Dispatcher Service...
ene 26 00:31:40 Sterling dbus-daemon[1264]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
ene 26 00:31:40 Sterling systemd[1]: Started Network Manager Script Dispatcher Service.
ene 26 00:31:40 Sterling NetworkManager[1266]: <info>  [1706225500.9473] dhcp4 (wlp1s0): state changed new lease, address=10.0.0.114
ene 26 00:31:40 Sterling avahi-daemon[1260]: Joining mDNS multicast group on interface wlp1s0.IPv4 with address 10.0.0.114.
ene 26 00:31:40 Sterling avahi-daemon[1260]: New relevant interface wlp1s0.IPv4 for mDNS.
ene 26 00:31:40 Sterling avahi-daemon[1260]: Registering new address record for 10.0.0.114 on wlp1s0.IPv4.
ene 26 00:31:40 Sterling NetworkManager[1266]: <info>  [1706225500.9535] device (wlp1s0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
ene 26 00:31:40 Sterling NetworkManager[1266]: <info>  [1706225500.9560] device (wlp1s0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
ene 26 00:31:40 Sterling NetworkManager[1266]: <info>  [1706225500.9562] device (wlp1s0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')

In terms of apps running, Konsole, Firefox, Signal, Whatsie were open when going to sleep.

I suggest reproducing this using the s2idle debugging script to understand it.

Basically rather than close the lid use the script to suspend the machine. When it prompts you how long you want to suspend it mark it as longer than you intend it to be asleep.

When it wakes up the script will tell you which GPIO, IRQ and/or GPE woke the system. Everything is saved into a text file report that to can share.

If it turns out to be the ACPI SCI that woke the system then the next level of debugging would be ACPICA tracing to understand what the bios did.

If it turns out to be a GPE we might need Framework to explain what that GPE is.

If it’s a GPIO I might be able to explain it from the s2idle report.

1 Like

Nice script, thanks for the tip.

Here’s the result:

Terminal Log:

Started at 2024-01-28 09:25:38.490173 (cycle finish expected @ 2024-01-28 12:25:42.490188)
Results from last s2idle cycle
○ Suspend count: 1
○ Hardware sleep cycle count: 1
○ Wakeups triggered from IRQs: [1]
○ Woke up from IRQ 1 (IR-IO-APIC 1-edge i8042)
❌ Userspace suspended for 0:05:03.579845 (< minimum expected 2:42:00)
Unable to gather hardware sleep data with lockdown engaged
🔋 Battery BAT1 ( ) is operating at 100.89% of design
🚦 RTC driver `rtc_cmos` configured to use ACPI alarm
Explanations for your system
🚦 Userspace wasn't asleep at least 3:00:00
        The system was programmed to sleep for 3:00:00, but woke up prematurely.
        This typically happens when the system was woken up from a non-timer based source.

        If you didn't intentionally wake it up, then there may be a kernel or firmware bug

🚦 rtc_cmos is not configured to use ACPI alarm
        Some problems can occur during wakeup cycles if the HPET RTC emulation is used to
        wake systems. This can manifest in unexpected wakeups or high power consumption.

For more information on this failure see:
        https://github.com/systemd/systemd/issues/24279

The full report: s2idle_report-2024-01-28.txt · GitHub

Pick up that patch for rtc CMOS or change the kernel command line to add the option.

It’s either that or still something else blocking it after that.

How would I get that patch without recompiling the kernel, given I’m using the OEM kernel that Framework recommends?

You can use the kernel command line to add rtc_cmos.use_acpi_alarm=1 for now instead of the patch if you would prefer not to compile the kernel.

I’ve gone ahead and applied that change, but the problem seems to persist.

Here’s a new log from the script:

Location of log file (default s2idle_report-2024-01-29.txt)? 
Debugging script for s2idle on AMD systems
💻 Framework Laptop 13 (AMD Ryzen 7040Series) (Laptop) running BIOS 3.3 (03.03) released 10/17/2023 and EC unknown
🐧 Ubuntu 22.04.3 LTS
🐧 Kernel 6.1.0-1026-oem
🔋 Battery BAT1 ( ) is operating at 102.81% of design
Checking prerequisites for s2idle
✅ Logs are provided via systemd
✅ AMD Ryzen 7 7840U w/ Radeon  780M Graphics (family 19 model 74)
✅ LPS0 _DSM enabled
✅ ACPI FADT supports Low-power S0 idle
✅ HSMP driver `amd_hsmp` not detected (blocked: False)
✅ PMC driver `amd_pmc` loaded (Program 0 Firmware 76.70.0)
✅ USB4 driver `thunderbolt` loaded
✅ GPU driver `amdgpu` available
✅ System is configured for s2idle
✅ NVME SK hynix is configured for s2idle in BIOS
✅ GPIO driver `pinctrl_amd` available
How long should suspend cycles last in seconds (default 10)? 10800
How long to wait in between suspend cycles in seconds (default 4)? 
How many suspend cycles to run (default 1)? 
Started at 2024-01-29 08:28:53.082578 (cycle finish expected @ 2024-01-29 11:28:57.082594)
Results from last s2idle cycle
○ Suspend count: 1
○ Hardware sleep cycle count: 1
○ Wakeups triggered from IRQs: [9, 1]
○ Woke up from IRQ 9 (IR-IO-APIC 9-fasteoi acpi)
○ gpe0B increased from 33 to 50
❌ Userspace suspended for 0:20:48.029611 (< minimum expected 2:42:00)
Unable to gather hardware sleep data with lockdown engaged
🔋 Battery BAT1 ( ) is operating at 103.17% of design
Explanations for your system
🚦 Userspace wasn't asleep at least 3:00:00
        The system was programmed to sleep for 3:00:00, but woke up prematurely.
        This typically happens when the system was woken up from a non-timer based source.

        If you didn't intentionally wake it up, then there may be a kernel or firmware bug

Log file: s2idle_report-2024-01-29.txt · GitHub

As this only happens when the laptop is plugged in, I’m really thinking this has something to do with the battery starting or stopping to charge.
While I haven’t done this in any of these test before, the same behaviour happens when you unplug the charger while the laptop is asleep.

Okay this is matching what I expected the root cause is.

Long story short, it’s caused by a workaround in the Framework EC for another bug.

“Every” wakeup is marked as a keyboard wakeup even if it’s not.

There is a workaround landed in upstream kernel:

This isn’t backported to the OEM kernel.

You can also workaround it with the udev rule described here:

@Loell_Framework can you please raise this with your next sync with Ubuntu?

3 Likes

Done. :slight_smile: We’ll see what comes of it with their team. But they have it now.

Awesome. Fingers crossed it lands in the next kernel update.
Thanks for all your help guys!

1 Like