Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Journalctl shows wrong timestamp on some hibernation-related log messages after waking from hibernation #32492

Closed
reallyimeric opened this issue Apr 26, 2024 · 2 comments · Fixed by #32592
Closed

Journalctl shows wrong timestamp on some hibernation-related log messages after waking from hibernation #32492

reallyimeric opened this issue Apr 26, 2024 · 2 comments · Fixed by #32592
Labels
hibernate-resume journal RFE 🎁 Request for Enhancement, i.e. a feature request sleep

Comments

@reallyimeric
Copy link

reallyimeric commented Apr 26, 2024 •
edited by yuwata

systemd version the issue has been seen with

systemd 255.4-2

Used distribution

Arch Linux

Linux kernel version used

6.8.5-arch1-1

CPU architectures issue was seen on

x86_64

Component

journalctl, systemd-journald

Expected behaviour you didn't see

Some log messages about preparing for hibernation like Freezing user space processes should be before I wake up the system at the next day

Unexpected behaviour you saw

Some of the messages described above are after the time I press power button at next day

see logs below

Steps to reproduce the problem

  1. press power button to show logoff screen of KDE 6
  2. click Hibernate
  3. press power button at next day
  4. view log using journalctl -b -e

Additional program output to the terminal or log subsystem illustrating the issue

The issue is observed on KDE 6 wayland session for this time, but I noticed the same behavior before on KDE 5 X11.

logs
https://fars.ee/Evb9
@reallyimeric reallyimeric added the bug 🐛 Programming errors, that need preferential fixing label Apr 26, 2024
@YHNdnzj
Copy link
Member

YHNdnzj commented Apr 26, 2024

Hmm, the frozen user processes also include journald, no? So it can only process the new logs after resuming from hibernation. I doubt if there's anything actionable for systemd?

@yuwata
Copy link
Member

yuwata commented Apr 28, 2024

Yeah, journald is freezed. I have no idea to 'fix' the issue. I guess journalctl -o show-monotonic will show these logs with a 'correct' timestamp.

@yuwata yuwata added RFE 🎁 Request for Enhancement, i.e. a feature request and removed bug 🐛 Programming errors, that need preferential fixing labels Apr 28, 2024
yuwata added a commit to yuwata/systemd that referenced this issue Apr 30, 2024
@yuwata
logs-show: adjust source timestamp with header timestamp
03237c0 
Previously, _SOURCE_REALTIME_TIMESTAMP was only used for realtime
timestamp, and _SOURCE_MONOTONIC_TIMESTAMP was for monotonic.

This make these journal field used more aggressively. If we need
realtime timestamp, but an entry has only _SOURCE_MONOTONIC_TIMESTAMP,
then now realtime timestamp is calculated based on
_SOURCE_MONOTONIC_TIMESTAMP and the header dual timestamp.
Similary, monotonic timestamp is obtained from
_SOURCE_REALTIME_TIMESTAMP and the header dual timestamp.

This should change shown timestamps not so much in most cases, but may
be improve the situation such as systemd#32492.
@yuwata yuwata mentioned this issue Apr 30, 2024
Merged
yuwata added a commit to yuwata/systemd that referenced this issue May 1, 2024
@yuwata
logs-show: adjust source timestamp with header timestamp
da5831b 
Previously, _SOURCE_REALTIME_TIMESTAMP was only used for realtime
timestamp, and _SOURCE_MONOTONIC_TIMESTAMP was for monotonic.

This make these journal field used more aggressively. If we need
realtime timestamp, but an entry has only _SOURCE_MONOTONIC_TIMESTAMP,
then now realtime timestamp is calculated based on
_SOURCE_MONOTONIC_TIMESTAMP and the header dual timestamp.
Similary, monotonic timestamp is obtained from
_SOURCE_REALTIME_TIMESTAMP and the header dual timestamp.

This should change shown timestamps not so much in most cases, but may
be improve the situation such as systemd#32492.
yuwata added a commit to yuwata/systemd that referenced this issue May 1, 2024
@yuwata
logs-show: adjust source timestamp with header timestamp
15cffe8 
Previously, _SOURCE_REALTIME_TIMESTAMP was only used for realtime
timestamp, and _SOURCE_MONOTONIC_TIMESTAMP was for monotonic.

This make these journal field used more aggressively. If we need
realtime timestamp, but an entry has only _SOURCE_MONOTONIC_TIMESTAMP,
then now realtime timestamp is calculated based on
_SOURCE_MONOTONIC_TIMESTAMP and the header dual timestamp.
Similary, monotonic timestamp is obtained from
_SOURCE_REALTIME_TIMESTAMP and the header dual timestamp.

This should change shown timestamps not so much in most cases, but may
be improve the situation such as systemd#32492.
yuwata added a commit to yuwata/systemd that referenced this issue May 1, 2024
@yuwata
logs-show: adjust source timestamp with header timestamp
affde1d 
Previously, _SOURCE_REALTIME_TIMESTAMP was only used for realtime
timestamp, and _SOURCE_MONOTONIC_TIMESTAMP was for monotonic.

This make these journal field used more aggressively. If we need
realtime timestamp, but an entry has only _SOURCE_MONOTONIC_TIMESTAMP,
then now realtime timestamp is calculated based on
_SOURCE_MONOTONIC_TIMESTAMP and the header dual timestamp.
Similary, monotonic timestamp is obtained from
_SOURCE_REALTIME_TIMESTAMP and the header dual timestamp.

This should change shown timestamps not so much in most cases, but may
be improve the situation such as systemd#32492.
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
hibernate-resume journal RFE 🎁 Request for Enhancement, i.e. a feature request sleep
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

journal: several timestamp cleanups and improvements yuwata/systemd
3 participants
@reallyimeric @yuwata @YHNdnzj