Moppel
October 27, 2022, 8:40am
#1
Dear community,
After I put my T480s in standby (not suspend to RAM) it takes like 20 seconds to wake up again.
Are there possibilities to troubleshoot and tweak the wakeup process?
Thank you very much!
PS: It’s not a new problem.
inxi -Fz
System:
Kernel: 6.0.2-arch1-1 arch: x86_64 bits: 64 Desktop: KDE Plasma v: 5.26.1
Distro: EndeavourOS
Machine:
Type: Laptop System: LENOVO product: 20L8S9GC00 v: ThinkPad T480s
serial: <superuser required>
Mobo: LENOVO model: 20L8S9GC00 v: SDK0J40697 WIN
serial: <superuser required> UEFI: LENOVO v: N22ET72W (1.49 )
date: 11/17/2021
Battery:
ID-1: BAT0 charge: 16.4 Wh (31.5%) condition: 52.1/57.0 Wh (91.4%)
volts: 11.2 min: 11.6
CPU:
Info: quad core model: Intel Core i5-8350U bits: 64 type: MT MCP cache:
L2: 1024 KiB
Speed (MHz): avg: 1511 min/max: 400/3600 cores: 1: 1900 2: 867 3: 827
4: 1900 5: 1900 6: 900 7: 1900 8: 1900
Graphics:
Device-1: Intel UHD Graphics 620 driver: i915 v: kernel
Device-2: Chicony Integrated Camera (1280x720@30) type: USB
driver: uvcvideo
Display: x11 server: X.Org v: 21.1.4 driver: X: loaded: intel
unloaded: modesetting dri: i965 gpu: i915 resolution: 1920x1080~60Hz
OpenGL: renderer: Mesa Intel UHD Graphics 620 (KBL GT2) v: 4.6 Mesa
22.2.1
Audio:
Device-1: Intel Sunrise Point-LP HD Audio driver: snd_hda_intel
Sound API: ALSA v: k6.0.2-arch1-1 running: yes
Sound Server-1: PipeWire v: 0.3.59 running: yes
Network:
Device-1: Intel Ethernet I219-LM driver: e1000e
IF: enp0s31f6 state: down mac: <filter>
Device-2: Intel Wireless 8265 / 8275 driver: iwlwifi
IF: wlan0 state: up mac: <filter>
Drives:
Local Storage: total: 238.47 GiB used: 126.82 GiB (53.2%)
ID-1: /dev/nvme0n1 vendor: Lenovo model: LENSE30256GMSP34MEAT3TA
size: 238.47 GiB
Partition:
ID-1: / size: 238.08 GiB used: 126.82 GiB (53.3%) fs: btrfs dev: /dev/dm-0
ID-2: /boot/efi size: 399.2 MiB used: 1.1 MiB (0.3%) fs: vfat
dev: /dev/nvme0n1p1
ID-3: /home size: 238.08 GiB used: 126.82 GiB (53.3%) fs: btrfs
dev: /dev/dm-0
ID-4: /var/log size: 238.08 GiB used: 126.82 GiB (53.3%) fs: btrfs
dev: /dev/dm-0
Swap:
ID-1: swap-1 type: file size: 11 GiB used: 112.6 MiB (1.0%)
file: /swap/swapfile
Sensors:
System Temperatures: cpu: 36.0 C pch: 32.5 C mobo: N/A
Fan Speeds (RPM): fan-1: 0
Info:
Processes: 255 Uptime: 1d 1h 34m Memory: 7.51 GiB used: 4.08 GiB (54.4%)
Shell: Bash inxi: 3.3.22
Hi Moppel,
does your system hibernate after a certain time in suspend?
In KDE there’s a setting for that:
In my case (including a fully encrypted disc) I even need to enter the decryption password. With 32BG RAM this process nearly takes longer than a cold boot
Moppel
October 27, 2022, 9:32am
#3
No it does not.
The power LED keeps blinking and I do not need to put in my password again.
Hibernation works, but takes even longer than cold start. So i do not use it.
You don’t happen to have a micro sd card in the slot do you?
may be worth having a look at the bootlog with
sudo journalctl -b 0
you can redirect it to a fiile to analyze later. Have a look at the end of the file / output for the latest time stamp before suspending / resuming. The command logs everything starting from the last boot time.
After a complete resume run the command again and search for time gaps or errors / timeouts after your remembered suspent time - often network timeout to slowly responding mount points can be the culprit.
Moppel
November 2, 2022, 9:09am
#7
Here is what I found relevant to your advice.
Although I’m not able to tell if there is a real problem visible or not.
Also it seems like the resume time is highly dependent on how long the suspension lasted.
These where the biggest time gaps.
Nov 02 10:03:24 t480s kernel: Freezing user space processes ... (elapsed 0.001 seconds) done.
Nov 02 10:03:24 t480s kernel: OOM killer disabled.
Nov 02 10:03:24 t480s kernel: Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
Nov 02 10:03:24 t480s kernel: printk: Suspending console(s) (use no_console_suspend to debug)
Nov 02 10:03:24 t480s kernel: e1000e: EEE TX LPI TIMER: 00000011
Nov 02 10:03:24 t480s kernel: ACPI: EC: interrupt blocked
Nov 02 10:03:24 t480s kernel: ACPI: PM: Preparing to enter system sleep state S3
Nov 02 10:03:24 t480s kernel: ACPI: EC: event blocked
Nov 02 10:03:24 t480s kernel: ACPI: EC: EC stopped
Nov 02 10:03:24 t480s kernel: ACPI: PM: Saving platform NVS memory
Nov 02 10:03:24 t480s kernel: Disabling non-boot CPUs ...
Nov 02 10:03:24 t480s kernel: smpboot: CPU 1 is now offline
Nov 02 10:03:24 t480s kernel: smpboot: CPU 2 is now offline
Nov 02 10:03:24 t480s kernel: smpboot: CPU 3 is now offline
Nov 02 10:03:24 t480s kernel: smpboot: CPU 4 is now offline
Nov 02 10:03:24 t480s kernel: smpboot: CPU 5 is now offline
Nov 02 10:03:24 t480s kernel: smpboot: CPU 6 is now offline
Nov 02 10:03:24 t480s kernel: smpboot: CPU 7 is now offline
Nov 02 10:03:24 t480s kernel: ACPI: PM: Low-level resume complete
Nov 02 10:03:24 t480s kernel: ACPI: EC: EC started
Nov 02 10:03:24 t480s kernel: ACPI: PM: Restoring platform NVS memory
Nov 02 10:03:24 t480s kernel: Enabling non-boot CPUs ...
Nov 02 10:03:24 t480s kernel: x86: Booting SMP configuration:
Nov 02 10:03:24 t480s kernel: smpboot: Booting Node 0 Processor 1 APIC 0x2
Nov 02 10:03:24 t480s kernel: CPU1 is up
Nov 02 10:03:24 t480s kernel: smpboot: Booting Node 0 Processor 2 APIC 0x4
Nov 02 10:03:24 t480s kernel: CPU2 is up
Nov 02 10:03:24 t480s kernel: smpboot: Booting Node 0 Processor 3 APIC 0x6
Nov 02 10:03:24 t480s kernel: CPU3 is up
Nov 02 10:03:24 t480s kernel: smpboot: Booting Node 0 Processor 4 APIC 0x1
Nov 02 10:03:24 t480s kernel: CPU4 is up
Nov 02 10:03:24 t480s kernel: smpboot: Booting Node 0 Processor 5 APIC 0x3
Nov 02 10:03:24 t480s kernel: CPU5 is up
Nov 02 10:03:24 t480s kernel: smpboot: Booting Node 0 Processor 6 APIC 0x5
Nov 02 10:03:24 t480s kernel: CPU6 is up
Nov 02 10:03:24 t480s kernel: smpboot: Booting Node 0 Processor 7 APIC 0x7
Nov 02 10:03:24 t480s kernel: CPU7 is up
Nov 02 10:03:24 t480s kernel: ACPI: PM: Waking up from system sleep state S3
Nov 02 10:03:24 t480s kernel: ACPI: EC: interrupt unblocked
Nov 02 10:03:24 t480s kernel: ACPI: EC: event unblocked
Nov 02 10:03:24 t480s kernel: i915 0000:00:02.0: [drm] [ENCODER:94:DDI A/PHY A] is disabled/in DSI mode with an ungated DDI clock, gate it
Nov 02 10:03:24 t480s kernel: i915 0000:00:02.0: [drm] [ENCODER:102:DDI B/PHY B] is disabled/in DSI mode with an ungated DDI clock, gate it
Nov 02 10:03:24 t480s kernel: i915 0000:00:02.0: [drm] [ENCODER:118:DDI C/PHY C] is disabled/in DSI mode with an ungated DDI clock, gate it
Nov 02 10:03:24 t480s kernel: xhci_hcd 0000:3c:00.0: xHC error in resume, USBSTS 0x401, Reinit
Nov 02 10:03:24 t480s kernel: usb usb3: root hub lost power or was reset
Nov 02 10:03:24 t480s kernel: usb usb4: root hub lost power or was reset
Nov 02 10:03:24 t480s kernel: nvme nvme0: 8/0/0 default/read/poll queues
Nov 02 10:03:24 t480s kernel: usb 1-8: reset high-speed USB device number 3 using xhci_hcd
Nov 02 10:03:24 t480s kernel: thunderbolt 0000:06:00.0: failed to send driver ready to ICM
Nov 02 10:03:24 t480s kernel: OOM killer enabled.
Nov 02 10:03:24 t480s kernel: Restarting tasks ...
Nov 02 10:03:24 t480s kernel: pci_bus 0000:06: Allocating resources
Nov 02 10:03:24 t480s kernel: pci_bus 0000:3c: Allocating resources
Nov 02 10:03:24 t480s kernel: done.
Nov 02 10:03:24 t480s kernel: random: crng reseeded on system resumption
Nov 02 10:03:24 t480s kernel: mei_hdcp 0000:00:16.0-b638ab7e-94e2-4ea2-a552-d1c54b627f04: bound 0000:00:02.0 (ops i915_hdcp_component_ops [i915])
Nov 02 10:03:24 t480s kernel: audit: type=1131 audit(1667379804.529:92): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatc>
Nov 02 10:03:24 t480s audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr>
Nov 02 10:03:24 t480s systemd-logind[547]: Lid opened.
Nov 02 10:03:24 t480s systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
Nov 02 10:03:24 t480s kernel: pci_bus 0000:06: Allocating resources
Nov 02 10:03:24 t480s kernel: pci_bus 0000:3c: Allocating resources
Nov 02 10:03:24 t480s systemd-sleep[3711]: System returned from sleep state.
Nov 02 10:03:24 t480s kernel: PM: suspend exit
Nov 02 10:03:25 t480s systemd[1]: systemd-suspend.service: Deactivated successfully.
Nov 02 10:03:25 t480s systemd[1]: Finished System Suspend.
Nov 02 10:03:25 t480s audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-suspend comm="systemd" exe="/usr/lib/syst>
Nov 02 10:03:25 t480s audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-suspend comm="systemd" exe="/usr/lib/syste>
Nov 02 10:03:25 t480s systemd[1]: systemd-suspend.service: Consumed 1.144s CPU time.
Nov 02 10:03:25 t480s kernel: audit: type=1130 audit(1667379805.282:93): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-suspend comm=">
Nov 02 10:03:25 t480s kernel: audit: type=1131 audit(1667379805.282:94): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-suspend comm=">
Nov 02 10:03:25 t480s systemd[1]: Stopped target Sleep.
Nov 02 10:03:25 t480s systemd[1]: Reached target Suspend.
Nov 02 10:03:25 t480s systemd[1]: Stopped target Suspend.
Nov 02 10:03:25 t480s systemd-logind[547]: Operation 'sleep' finished.
Nov 02 10:03:25 t480s NetworkManager[552]: <info> [1667379805.2940] manager: sleep: wake requested (sleeping: yes enabled: yes)
Nov 02 10:03:25 t480s NetworkManager[552]: <info> [1667379805.2944] device (wlan0): state change: unmanaged -> unavailable (reason 'managed', sys-i>
Nov 02 10:03:25 t480s NetworkManager[552]: <info> [1667379805.3490] device (wlan0): set-hw-addr: set MAC address to 76:6E:9B:CD:04:57 (scanning)
Nov 02 10:03:25 t480s NetworkManager[552]: <info> [1667379805.5888] device (enp0s31f6): state change: unmanaged -> unavailable (reason 'managed', s>
Nov 02 10:03:25 t480s NetworkManager[552]: <info> [1667379805.7800] device (p2p-dev-wlan0): state change: unmanaged -> unavailable (reason 'managed>
Nov 02 10:03:25 t480s NetworkManager[552]: <info> [1667379805.7811] manager: NetworkManager state is now DISCONNECTED
Nov 02 10:03:25 t480s NetworkManager[552]: <info> [1667379805.8378] device (wlan0): supplicant interface state: internal-starting -> disconnected
Nov 02 10:03:25 t480s NetworkManager[552]: <info> [1667379805.8379] device (p2p-dev-wlan0): state change: unavailable -> unmanaged (reason 'removed>
Nov 02 10:03:25 t480s NetworkManager[552]: <info> [1667379805.8395] Wi-Fi P2P device controlled by interface wlan0 created
Nov 02 10:03:25 t480s NetworkManager[552]: <info> [1667379805.8405] manager: (p2p-dev-wlan0): new 802.11 Wi-Fi P2P device (/org/freedesktop/Network>
Nov 02 10:03:25 t480s NetworkManager[552]: <info> [1667379805.8415] device (p2p-dev-wlan0): state change: unmanaged -> unavailable (reason 'managed>
Nov 02 10:03:25 t480s NetworkManager[552]: <info> [1667379805.8432] device (wlan0): state change: unavailable -> disconnected (reason 'supplicant-a>
Nov 02 10:03:25 t480s NetworkManager[552]: <info> [1667379805.8450] device (p2p-dev-wlan0): state change: unavailable -> disconnected (reason 'none>
Nov 02 10:03:27 t480s dbus-daemon[544]: [system] Activating via systemd: service name='org.freedesktop.home1' unit='dbus-org.freedesktop.home1.servi>
Nov 02 10:03:27 t480s dbus-daemon[544]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.home1.service': Unit dbus-org.freedesk>
Nov 02 10:03:27 t480s kscreenlocker_greet[3679]: pam_systemd_home(kde:auth): systemd-homed is not available: Unit dbus-org.freedesktop.home1.service>
Nov 02 10:03:29 t480s wpa_supplicant[744]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=DRIVER type=COUNTRY alpha2=DE
PS: How can I force the journal to print the whole lines?
As far as I can see this only shows the suspend process (takes around 4 seconds)
Moppel
November 3, 2022, 7:25am
#9
Yes I’m quite sure from the time stamps.
Interestingly just now I booted after a whole night of standby and it was quite fast.
So at 14:21 I put it to sleep and woke it up at 8:14 again.
This is my output:
[jannisf@t480s ~]$ sudo journalctl -b 0
Nov 02 14:21:44 t480s kernel: Filesystems sync: 0.256 seconds
Nov 03 08:14:09 t480s kernel: Freezing user space processes ... (elapsed 0.002 seconds) done.
Nov 03 08:14:09 t480s kernel: OOM killer disabled.
Nov 03 08:14:09 t480s kernel: Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
Nov 03 08:14:09 t480s kernel: printk: Suspending console(s) (use no_console_suspend to debug)
Nov 03 08:14:09 t480s kernel: e1000e: EEE TX LPI TIMER: 00000011
Nov 03 08:14:09 t480s kernel: ACPI: EC: interrupt blocked
Nov 03 08:14:09 t480s kernel: ACPI: PM: Preparing to enter system sleep state S3
Nov 03 08:14:09 t480s kernel: ACPI: EC: event blocked
Nov 03 08:14:09 t480s kernel: ACPI: EC: EC stopped
Nov 03 08:14:09 t480s kernel: ACPI: PM: Saving platform NVS memory
Nov 03 08:14:09 t480s kernel: Disabling non-boot CPUs ...
Nov 03 08:14:09 t480s kernel: smpboot: CPU 1 is now offline
Nov 03 08:14:09 t480s kernel: smpboot: CPU 2 is now offline
Nov 03 08:14:09 t480s kernel: smpboot: CPU 3 is now offline
Nov 03 08:14:09 t480s kernel: smpboot: CPU 4 is now offline
Nov 03 08:14:09 t480s kernel: smpboot: CPU 5 is now offline
Nov 03 08:14:09 t480s kernel: smpboot: CPU 6 is now offline
Nov 03 08:14:09 t480s kernel: smpboot: CPU 7 is now offline
Nov 03 08:14:09 t480s kernel: ACPI: PM: Low-level resume complete
Nov 03 08:14:09 t480s kernel: ACPI: EC: EC started
Nov 03 08:14:09 t480s kernel: ACPI: PM: Restoring platform NVS memory
Nov 03 08:14:09 t480s kernel: Enabling non-boot CPUs ...
Nov 03 08:14:09 t480s kernel: x86: Booting SMP configuration:
Nov 03 08:14:09 t480s kernel: smpboot: Booting Node 0 Processor 1 APIC 0x2
Nov 03 08:14:09 t480s kernel: CPU1 is up
Nov 03 08:14:09 t480s kernel: smpboot: Booting Node 0 Processor 2 APIC 0x4
Nov 03 08:14:09 t480s kernel: CPU2 is up
Nov 03 08:14:09 t480s kernel: smpboot: Booting Node 0 Processor 3 APIC 0x6
Nov 03 08:14:09 t480s kernel: CPU3 is up
Nov 03 08:14:09 t480s kernel: smpboot: Booting Node 0 Processor 4 APIC 0x1
Nov 03 08:14:09 t480s kernel: CPU4 is up
Nov 03 08:14:09 t480s kernel: smpboot: Booting Node 0 Processor 5 APIC 0x3
Nov 03 08:14:09 t480s kernel: CPU5 is up
Nov 03 08:14:09 t480s kernel: smpboot: Booting Node 0 Processor 6 APIC 0x5
Nov 03 08:14:09 t480s kernel: CPU6 is up
Nov 03 08:14:09 t480s kernel: smpboot: Booting Node 0 Processor 7 APIC 0x7
Nov 03 08:14:09 t480s kernel: CPU7 is up
Nov 03 08:14:09 t480s kernel: ACPI: PM: Waking up from system sleep state S3
Nov 03 08:14:09 t480s kernel: ACPI: EC: interrupt unblocked
Nov 03 08:14:09 t480s kernel: ACPI: EC: event unblocked
Nov 03 08:14:09 t480s kernel: i915 0000:00:02.0: [drm] [ENCODER:94:DDI A/PHY A] is disabled/in DSI mode with an ungated DDI clock, gate it
Nov 03 08:14:09 t480s kernel: i915 0000:00:02.0: [drm] [ENCODER:102:DDI B/PHY B] is disabled/in DSI mode with an ungated DDI clock, gate it
Nov 03 08:14:09 t480s kernel: i915 0000:00:02.0: [drm] [ENCODER:118:DDI C/PHY C] is disabled/in DSI mode with an ungated DDI clock, gate it
Nov 03 08:14:09 t480s kernel: xhci_hcd 0000:3c:00.0: xHC error in resume, USBSTS 0x401, Reinit
Nov 03 08:14:09 t480s kernel: usb usb3: root hub lost power or was reset
Nov 03 08:14:09 t480s kernel: usb usb4: root hub lost power or was reset
Nov 03 08:14:09 t480s kernel: nvme nvme0: 8/0/0 default/read/poll queues
Nov 03 08:14:09 t480s kernel: usb 1-8: reset high-speed USB device number 3 using xhci_hcd
Nov 03 08:14:09 t480s kernel: thunderbolt 0000:06:00.0: failed to send driver ready to ICM
Nov 03 08:14:09 t480s kernel: OOM killer enabled.
Nov 03 08:14:09 t480s kernel: Restarting tasks ...
Nov 03 08:14:09 t480s kernel: pci_bus 0000:06: Allocating resources
Nov 03 08:14:09 t480s kernel: pci_bus 0000:3c: Allocating resources
Nov 03 08:14:09 t480s kernel: done.
Nov 03 08:14:09 t480s kernel: random: crng reseeded on system resumption
Nov 03 08:14:09 t480s kernel: mei_hdcp 0000:00:16.0-b638ab7e-94e2-4ea2-a552-d1c54b627f04: bound 0000:00:02.0 (ops i915_hdcp_component_ops [i915])
Nov 03 08:14:09 t480s systemd-logind[664]: Lid opened.
Nov 03 08:14:09 t480s kernel: pci_bus 0000:06: Allocating resources
Nov 03 08:14:09 t480s kernel: pci_bus 0000:3c: Allocating resources
Nov 03 08:14:09 t480s kernel: audit: type=1131 audit(1667459649.590:103): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/syste>
Nov 03 08:14:09 t480s audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=?>
Nov 03 08:14:09 t480s systemd[1020]: Starting EOS update notifier service...
Nov 03 08:14:09 t480s systemd[1]: NetworkManager-dispatcher.service: Deactivated successfully.
Nov 03 08:14:09 t480s systemd-sleep[8315]: System returned from sleep state.
Nov 03 08:14:09 t480s kernel: PM: suspend exit
Nov 03 08:14:09 t480s systemd[1]: Rotate log files was skipped because of a failed condition check (ConditionACPower=true).
Nov 03 08:14:09 t480s systemd[1]: Started Verify integrity of password and group files.
Nov 03 08:14:09 t480s audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=shadow comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=su>
Nov 03 08:14:09 t480s kernel: audit: type=1130 audit(1667459649.670:104): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=shadow comm="systemd" exe="/usr/lib/systemd/systemd" hostnam>
Nov 03 08:14:09 t480s audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=shadow comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=? res=suc>
Nov 03 08:14:09 t480s systemd[1]: shadow.service: Deactivated successfully.
Nov 03 08:14:09 t480s kernel: audit: type=1131 audit(1667459649.803:105): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=shadow comm="systemd" exe="/usr/lib/systemd/systemd" hostnam>
Nov 03 08:14:10 t480s systemd[1]: systemd-suspend.service: Deactivated successfully.
Nov 03 08:14:10 t480s systemd[1]: Finished System Suspend.
Nov 03 08:14:10 t480s audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-suspend comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal>
Nov 03 08:14:10 t480s audit[1]: SERVICE_STOP pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-suspend comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=? terminal=>
Nov 03 08:14:10 t480s systemd[1]: systemd-suspend.service: Consumed 1.172s CPU time.
Nov 03 08:14:10 t480s systemd[1]: Stopped target Sleep.
Nov 03 08:14:10 t480s systemd[1]: Reached target Suspend.
Nov 03 08:14:10 t480s systemd[1]: Stopped target Suspend.
Nov 03 08:14:10 t480s kernel: audit: type=1130 audit(1667459650.240:106): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-suspend comm="systemd" exe="/usr/lib/systemd/systemd>
Nov 03 08:14:10 t480s kernel: audit: type=1131 audit(1667459650.240:107): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=systemd-suspend comm="systemd" exe="/usr/lib/systemd/systemd>
Nov 03 08:14:10 t480s systemd-logind[664]: Operation 'sleep' finished.
Nov 03 08:14:10 t480s NetworkManager[700]: <info> [1667459650.2506] manager: sleep: wake requested (sleeping: yes enabled: yes)
Nov 03 08:14:10 t480s NetworkManager[700]: <info> [1667459650.2508] device (wlan0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Nov 03 08:14:10 t480s NetworkManager[700]: <info> [1667459650.3011] device (wlan0): set-hw-addr: set MAC address to 2E:2A:58:A7:E0:73 (scanning)
Nov 03 08:14:10 t480s NetworkManager[700]: <info> [1667459650.5310] device (enp0s31f6): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Nov 03 08:14:10 t480s kwin_x11[1064]: qt.qpa.xcb: QXcbConnection: XCB error: 3 (BadWindow), sequence: 10356, resource id: 75497473, major code: 18 (ChangeProperty), minor code: 0
Nov 03 08:14:10 t480s NetworkManager[700]: <info> [1667459650.7157] device (p2p-dev-wlan0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Nov 03 08:14:10 t480s NetworkManager[700]: <info> [1667459650.7166] manager: NetworkManager state is now DISCONNECTED
Nov 03 08:14:10 t480s NetworkManager[700]: <info> [1667459650.7756] device (wlan0): supplicant interface state: internal-starting -> disconnected
Nov 03 08:14:10 t480s NetworkManager[700]: <info> [1667459650.7757] device (p2p-dev-wlan0): state change: unavailable -> unmanaged (reason 'removed', sys-iface-state: 'removed')
Nov 03 08:14:10 t480s NetworkManager[700]: <info> [1667459650.7774] Wi-Fi P2P device controlled by interface wlan0 created
Nov 03 08:14:10 t480s NetworkManager[700]: <info> [1667459650.7795] manager: (p2p-dev-wlan0): new 802.11 Wi-Fi P2P device (/org/freedesktop/NetworkManager/Devices/6)
Nov 03 08:14:10 t480s NetworkManager[700]: <info> [1667459650.7809] device (p2p-dev-wlan0): state change: unmanaged -> unavailable (reason 'managed', sys-iface-state: 'external')
Nov 03 08:14:10 t480s NetworkManager[700]: <info> [1667459650.7824] device (wlan0): state change: unavailable -> disconnected (reason 'supplicant-available', sys-iface-state: 'managed')
Nov 03 08:14:10 t480s NetworkManager[700]: <info> [1667459650.7839] device (p2p-dev-wlan0): state change: unavailable -> disconnected (reason 'none', sys-iface-state: 'managed')
Nov 03 08:14:12 t480s dbus-daemon[662]: [system] Activating via systemd: service name='org.freedesktop.home1' unit='dbus-org.freedesktop.home1.service' requested by ':1.278' (uid=1000 pid>
Nov 03 08:14:12 t480s dbus-daemon[662]: [system] Activation via systemd failed for unit 'dbus-org.freedesktop.home1.service': Unit dbus-org.freedesktop.home1.service not found.
Nov 03 08:14:12 t480s kscreenlocker_greet[8279]: pam_systemd_home(kde:auth): systemd-homed is not available: Unit dbus-org.freedesktop.home1.service not found.
Nov 03 08:14:13 t480s wpa_supplicant[790]: wlan0: CTRL-EVENT-REGDOM-CHANGE init=DRIVER type=COUNTRY alpha2=DE
Nov 03 08:14:13 t480s NetworkManager[700]: <info> [1667459653.8654] policy: auto-activating connection 'eduroam' (870e10af-d973-4c49-adc6-c66a0f705c50)
Nov 03 08:14:13 t480s NetworkManager[700]: <info> [1667459653.8671] device (wlan0): Activation: starting connection 'eduroam' (870e10af-d973-4c49-adc6-c66a0f705c50)
Nov 03 08:14:13 t480s NetworkManager[700]: <info> [1667459653.8675] device (wlan0): state change: disconnected -> prepare (reason 'none', sys-iface-state: 'managed')
Nov 03 08:14:13 t480s NetworkManager[700]: <info> [1667459653.8684] manager: NetworkManager state is now CONNECTING
Nov 03 08:14:13 t480s NetworkManager[700]: <info> [1667459653.9017] device (wlan0): set-hw-addr: reset MAC address to DC:71:96:1D:3D:5F (preserve)
Nov 03 08:14:13 t480s NetworkManager[700]: <info> [1667459653.9082] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Nov 03 08:14:13 t480s NetworkManager[700]: <info> [1667459653.9090] device (wlan0): Activation: (wifi) access point 'eduroam' has security, but secrets are required.
Nov 03 08:14:13 t480s NetworkManager[700]: <info> [1667459653.9091] device (wlan0): state change: config -> need-auth (reason 'none', sys-iface-state: 'managed')
Nov 03 08:14:13 t480s NetworkManager[700]: <info> [1667459653.9104] device (wlan0): supplicant interface state: disconnected -> interface_disabled
Nov 03 08:14:13 t480s NetworkManager[700]: <info> [1667459653.9104] device (p2p-dev-wlan0): supplicant management interface state: disconnected -> interface_disabled
Nov 03 08:14:13 t480s NetworkManager[700]: <info> [1667459653.9153] device (wlan0): supplicant interface state: interface_disabled -> inactive
Nov 03 08:14:13 t480s NetworkManager[700]: <info> [1667459653.9154] device (p2p-dev-wlan0): supplicant management interface state: interface_disabled -> inactive
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.0259] device (wlan0): state change: need-auth -> prepare (reason 'none', sys-iface-state: 'managed')
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.0269] device (wlan0): state change: prepare -> config (reason 'none', sys-iface-state: 'managed')
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.0278] device (wlan0): Activation: (wifi) connection 'eduroam' has security, and secrets exist. No new secrets needed.
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.0279] Config: added 'ssid' value 'eduroam'
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.0280] Config: added 'scan_ssid' value '1'
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.0280] Config: added 'bgscan' value 'simple:30:-65:300'
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.0281] Config: added 'key_mgmt' value 'WPA-EAP FT-EAP FT-EAP-SHA384 WPA-EAP-SHA256'
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.0282] Config: added 'password' value '<hidden>'
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.0282] Config: added 'eap' value 'PEAP'
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.0283] Config: added 'fragment_size' value '1266'
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.0283] Config: added 'phase2' value 'auth=MSCHAPV2'
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.0284] Config: added 'ca_cert' value '/home/jannisf/Dokumente/Uni/T-TeleSec_GlobalRoot_Class_2.cer'
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.0284] Config: added 'identity' value 'jafriemo@uni-mainz.de'
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.0285] Config: added 'proactive_key_caching' value '1'
Nov 03 08:14:14 t480s wpa_supplicant[790]: wlan0: SME: Trying to authenticate with e8:26:89:bd:11:50 (SSID='eduroam' freq=5320 MHz)
Nov 03 08:14:14 t480s kernel: wlan0: authenticate with e8:26:89:bd:11:50
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.0725] device (wlan0): supplicant interface state: inactive -> authenticating
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.0726] device (p2p-dev-wlan0): supplicant management interface state: inactive -> authenticating
Nov 03 08:14:14 t480s kernel: wlan0: send auth to e8:26:89:bd:11:50 (try 1/3)
Nov 03 08:14:14 t480s wpa_supplicant[790]: wlan0: Trying to associate with e8:26:89:bd:11:50 (SSID='eduroam' freq=5320 MHz)
Nov 03 08:14:14 t480s kernel: wlan0: authenticated
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.1117] device (wlan0): supplicant interface state: authenticating -> associating
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.1118] device (p2p-dev-wlan0): supplicant management interface state: authenticating -> associating
Nov 03 08:14:14 t480s kernel: wlan0: associate with e8:26:89:bd:11:50 (try 1/3)
Nov 03 08:14:14 t480s kernel: wlan0: RX AssocResp from e8:26:89:bd:11:50 (capab=0x411 status=0 aid=1)
Nov 03 08:14:14 t480s wpa_supplicant[790]: wlan0: Associated with e8:26:89:bd:11:50
Nov 03 08:14:14 t480s kernel: wlan0: associated
Nov 03 08:14:14 t480s wpa_supplicant[790]: wlan0: CTRL-EVENT-SUBNET-STATUS-UPDATE status=0
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.1260] device (wlan0): supplicant interface state: associating -> associated
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.1261] device (p2p-dev-wlan0): supplicant management interface state: associating -> associated
Nov 03 08:14:14 t480s wpa_supplicant[790]: wlan0: CTRL-EVENT-EAP-STARTED EAP authentication started
Nov 03 08:14:14 t480s wpa_supplicant[790]: wlan0: CTRL-EVENT-EAP-PROPOSED-METHOD vendor=0 method=25
Nov 03 08:14:14 t480s wpa_supplicant[790]: OpenSSL: tls_connection_ca_cert - Failed to load root certificates error:0B084088:x509 certificate routines:X509_load_cert_crl_file:no certifica>
Nov 03 08:14:14 t480s wpa_supplicant[790]: wlan0: CTRL-EVENT-EAP-METHOD EAP vendor 0 method 25 (PEAP) selected
Nov 03 08:14:14 t480s wpa_supplicant[790]: wlan0: CTRL-EVENT-EAP-PEER-CERT depth=3 subject='/C=DE/O=T-Systems Enterprise Services GmbH/OU=T-Systems Trust Center/CN=T-TeleSec GlobalRoot Cl>
Nov 03 08:14:14 t480s wpa_supplicant[790]: wlan0: CTRL-EVENT-EAP-PEER-CERT depth=2 subject='/C=DE/O=Verein zur Foerderung eines Deutschen Forschungsnetzes e. V./OU=DFN-PKI/CN=DFN-Verein C>
Nov 03 08:14:14 t480s wpa_supplicant[790]: wlan0: CTRL-EVENT-EAP-PEER-CERT depth=1 subject='/C=DE/O=Verein zur Foerderung eines Deutschen Forschungsnetzes e. V./OU=DFN-PKI/CN=DFN-Verein G>
Nov 03 08:14:14 t480s wpa_supplicant[790]: wlan0: CTRL-EVENT-EAP-PEER-CERT depth=0 subject='/C=DE/ST=Rheinland-Pfalz/L=Mainz/O=Johannes Gutenberg-Universitaet Mainz/CN=radius.zdv.uni-main>
Nov 03 08:14:14 t480s wpa_supplicant[790]: wlan0: CTRL-EVENT-EAP-PEER-ALT depth=0 DNS:radius.zdv.uni-mainz.de
Nov 03 08:14:14 t480s wpa_supplicant[790]: EAP-MSCHAPV2: Authentication succeeded
Nov 03 08:14:14 t480s wpa_supplicant[790]: EAP-TLV: TLV Result - Success - EAP-TLV/Phase2 Completed
Nov 03 08:14:14 t480s wpa_supplicant[790]: wlan0: CTRL-EVENT-EAP-SUCCESS EAP authentication completed successfully
Nov 03 08:14:14 t480s wpa_supplicant[790]: wlan0: PMKSA-CACHE-ADDED e8:26:89:bd:11:50 0
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.3151] device (wlan0): supplicant interface state: associated -> 4way_handshake
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.3152] device (p2p-dev-wlan0): supplicant management interface state: associated -> 4way_handshake
Nov 03 08:14:14 t480s wpa_supplicant[790]: wlan0: WPA: Key negotiation completed with e8:26:89:bd:11:50 [PTK=CCMP GTK=CCMP]
Nov 03 08:14:14 t480s kernel: IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
Nov 03 08:14:14 t480s wpa_supplicant[790]: wlan0: CTRL-EVENT-CONNECTED - Connection to e8:26:89:bd:11:50 completed [id=0 id_str=]
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.3649] device (wlan0): supplicant interface state: 4way_handshake -> completed
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.3650] device (wlan0): Activation: (wifi) Stage 2 of 5 (Device Configure) successful. Connected to wireless network "eduroam"
Nov 03 08:14:14 t480s wpa_supplicant[790]: wlan0: CTRL-EVENT-SIGNAL-CHANGE above=0 signal=-46 noise=9999 txrate=6000
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.3650] device (p2p-dev-wlan0): supplicant management interface state: 4way_handshake -> completed
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.3654] device (wlan0): state change: config -> ip-config (reason 'none', sys-iface-state: 'managed')
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.3664] dhcp4 (wlan0): activation: beginning transaction (timeout in 45 seconds)
Nov 03 08:14:14 t480s avahi-daemon[658]: Joining mDNS multicast group on interface wlan0.IPv6 with address fe80::2b29:6ce5:d60c:eadc.
Nov 03 08:14:14 t480s avahi-daemon[658]: New relevant interface wlan0.IPv6 for mDNS.
Nov 03 08:14:14 t480s avahi-daemon[658]: Registering new address record for fe80::2b29:6ce5:d60c:eadc on wlan0.*.
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.3832] dhcp4 (wlan0): state changed new lease, address=134.93.113.170
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.3864] policy: set 'eduroam' (wlan0) as default for IPv4 routing and DNS
Nov 03 08:14:14 t480s avahi-daemon[658]: Joining mDNS multicast group on interface wlan0.IPv4 with address 134.93.113.170.
Nov 03 08:14:14 t480s avahi-daemon[658]: New relevant interface wlan0.IPv4 for mDNS.
Nov 03 08:14:14 t480s avahi-daemon[658]: Registering new address record for 134.93.113.170 on wlan0.IPv4.
Nov 03 08:14:14 t480s dbus-daemon[662]: [system] Activating via systemd: service name='org.freedesktop.nm_dispatcher' unit='dbus-org.freedesktop.nm-dispatcher.service' requested by ':1.5'>
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.4130] device (wlan0): state change: ip-config -> ip-check (reason 'none', sys-iface-state: 'managed')
Nov 03 08:14:14 t480s systemd[1]: Starting Network Manager Script Dispatcher Service...
Nov 03 08:14:14 t480s dbus-daemon[662]: [system] Successfully activated service 'org.freedesktop.nm_dispatcher'
Nov 03 08:14:14 t480s systemd[1]: Started Network Manager Script Dispatcher Service.
Nov 03 08:14:14 t480s audit[1]: SERVICE_START pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/systemd/systemd" hostname=? addr=>
Nov 03 08:14:14 t480s kernel: audit: type=1130 audit(1667459654.467:108): pid=1 uid=0 auid=4294967295 ses=4294967295 msg='unit=NetworkManager-dispatcher comm="systemd" exe="/usr/lib/syste>
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.4753] device (wlan0): state change: ip-check -> secondaries (reason 'none', sys-iface-state: 'managed')
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.4760] device (wlan0): state change: secondaries -> activated (reason 'none', sys-iface-state: 'managed')
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.4781] manager: NetworkManager state is now CONNECTED_SITE
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.4824] device (wlan0): Activation: successful, device activated.
Nov 03 08:14:14 t480s NetworkManager[700]: <info> [1667459654.5648] manager: NetworkManager state is now CONNECTED_GLOBAL
Nov 03 08:14:14 t480s audit[8839]: USER_AUTH pid=8839 uid=1000 auid=1000 ses=3 msg='op=PAM:unix_chkpwd acct="jannisf" exe="/usr/bin/unix_chkpwd" hostname=? addr=? terminal=? res=success'
Nov 03 08:14:14 t480s kernel: audit: type=1100 audit(1667459654.610:109): pid=8839 uid=1000 auid=1000 ses=3 msg='op=PAM:unix_chkpwd acct="jannisf" exe="/usr/bin/unix_chkpwd" hostname=? ad>
Nov 03 08:14:14 t480s kwin_x11[1064]: qt.qpa.xcb: QXcbConnection: XCB error: 3 (BadWindow), sequence: 11394, resource id: 73400374, major code: 18 (ChangeProperty), minor code: 0
Nov 03 08:14:17 t480s NetworkManager[700]: <info> [1667459657.1340] policy: set 'eduroam' (wlan0) as default for IPv6 routing and DNS
Nov 03 08:14:17 t480s avahi-daemon[658]: Leaving mDNS multicast group on interface wlan0.IPv6 with address fe80::2b29:6ce5:d60c:eadc.
Nov 03 08:14:17 t480s avahi-daemon[658]: Joining mDNS multicast group on interface wlan0.IPv6 with address 2001:4c80:40:539:a464:acc0:4ff5:e49a.
Nov 03 08:14:17 t480s avahi-daemon[658]: Registering new address record for 2001:4c80:40:539:a464:acc0:4ff5:e49a on wlan0.*.
Nov 03 08:14:17 t480s avahi-daemon[658]: Withdrawing address record for fe80::2b29:6ce5:d60c:eadc on wlan0.
Nov 03 08:14:18 t480s eos-update-notifier[8390]: Checking for updates ...
just another idea as log does not show anything relevant.
do you have network mounts / resources and did use them before suspend? may be after a resume the DE tries to reconnect and waits for a network resource to become ready…
Moppel
November 10, 2022, 8:22am
#11
Sorry for my late reply.
No, I don’t have any of these in use.
Lately I did not experience these prolonged resumes. Maybe something got fixed in the meantime.
Thank you all for your support!
Should I mark your suggestion with the journal as answer, so this may help others with persisting problems?
1 Like
yes you can do so as the command helped me recently, too
system
November 13, 2022, 8:24am
#13
This topic was automatically closed 2 days after the last reply. New replies are no longer allowed.
