[systemd-devel] Timestamps in journal during suspend/resume

Paul Menzel pmenzel+systemd-devel at molgen.mpg.de
Tue Dec 1 11:45:52 UTC 2020


Dear systemd folks,


Using Debian sid/unstable with systemd 246.5, suspend and resuming a 
Dell Precision 3540 the timestamps below can be seen.

```
Nov 28 19:58:47.516555 morley systemd[1]: Reached target Sleep.
Nov 28 19:58:47.517585 morley systemd[1]: Starting Suspend...
Nov 28 19:58:47.525240 morley systemd[1]: Stopping Atop advanced 
performance monitor...
Nov 28 19:58:47.603491 morley wpa_supplicant[690]: nl80211: deinit 
ifname=p2p-dev-wlo1 disabled_11b_rates=0
Nov 28 19:58:47.759586 morley systemd[1]: atop.service: Succeeded.
Nov 28 19:58:47.759790 morley systemd[1]: Stopped Atop advanced 
performance monitor.
Nov 28 19:58:47.761552 morley systemd-sleep[15059]: Suspending system...
Nov 28 19:58:47.762380 morley kernel: PM: suspend entry (s2idle)
Nov 28 19:58:47.766488 morley wpa_supplicant[690]: nl80211: deinit 
ifname=wlo1 disabled_11b_rates=0
Nov 28 22:44:50.643707 morley kernel: Filesystems sync: 0.005 seconds
Nov 28 22:44:50.646269 morley kernel: (NULL device *): firmware: 
direct-loading firmware i915/kbl_dmc_ver1_04.bin
Nov 28 22:44:50.646329 morley kernel: (NULL device *): firmware: 
direct-loading firmware regulatory.db
Nov 28 22:44:50.646359 morley kernel: (NULL device *): firmware: 
direct-loading firmware regulatory.db.p7s
Nov 28 22:44:50.646384 morley kernel: (NULL device *): firmware: 
direct-loading firmware iwlwifi-9000-pu-b0-jf-b0-46.ucode
Nov 28 22:44:50.646417 morley kernel: Freezing user space processes ...
Nov 28 22:44:50.646451 morley kernel: [drm] PCIE GART of 256M enabled 
(table at 0x000000F400000000).
Nov 28 22:44:50.646479 morley kernel: [drm] UVD and UVD ENC initialized 
successfully.
Nov 28 22:44:50.646511 morley kernel: [drm] VCE initialized successfully.
Nov 28 22:44:50.646543 morley kernel: (elapsed 0.494 seconds) done.
Nov 28 22:44:50.646580 morley kernel: OOM killer disabled.
Nov 28 22:44:50.646613 morley kernel: Freezing remaining freezable tasks 
... (elapsed 0.001 seconds) done.
Nov 28 22:44:50.646646 morley kernel: printk: Suspending console(s) (use 
no_console_suspend to debug)
Nov 28 22:44:50.646667 morley kernel: e1000e: EEE TX LPI TIMER: 00000011
Nov 28 22:44:50.646688 morley kernel: ACPI: EC: interrupt blocked
Nov 28 22:44:50.646710 morley kernel: ACPI: EC: interrupt unblocked
Nov 28 22:44:50.646730 morley kernel: [drm] PCIE GART of 256M enabled 
(table at 0x000000F400000000).
Nov 28 22:44:50.646747 morley kernel: [drm] UVD and UVD ENC initialized 
successfully.
Nov 28 22:44:50.646764 morley kernel: [drm] VCE initialized successfully.
Nov 28 22:44:50.646781 morley kernel: OOM killer enabled.
Nov 28 22:44:50.646799 morley kernel: Restarting tasks ... done.
Nov 28 22:44:50.643826 morley rtkit-daemon[954]: The canary thread is 
apparently starving. Taking action.
Nov 28 22:44:50.646521 morley systemd-logind[688]: Lid opened.
Nov 28 22:44:50.643833 morley rtkit-daemon[954]: Demoting known 
real-time threads.
```

At least to me, some of the entries with timestamps from resuming should 
have timestamps from suspending. Is the reason, that “suspend message“ 
was only written to the journal after resume?

Is there a way to access the Linux kernel timestamp from within the journal?


Kind regards,

Paul


More information about the systemd-devel mailing list