[systemd-devel] Antw: [EXT] Journal message timestamps

Mark Corbin mark at dibsco.co.uk
Tue Sep 8 11:02:22 UTC 2020


On 04/09/2020 17:19, Lennart Poettering wrote:
> On Fr, 28.08.20 14:34, Mark Corbin (mark at dibsco.co.uk) wrote:
> 
>> For example, when /run/log/journal/d197a2e910964a7f9a0de6462d0d7c62/
>> contains just 'system.journal' which has all log messages from:
>>
>> 'kernel: Booting Linux on physical CPU 0x0'
>> up to and including:
>> 'fake-hwclock[827]: Fri Aug 28 12:12:08 UTC 2020'
>>
>> then all messages displayed by journalctl are time stamped starting from
>> 'Fri Aug 28 12:12:08' onwards. This is good - no problem.
> 
> So, as mentioned, we do not rewrite entries once written to disk and
> they carry the original timestamp when they were gnerated, and if
> that's off it's off. We will not "correct" something that was the
> truth early on if we later figure out it wasn't actually true.
> 
> I think what you migh be seeing is the fact that we early on flush
> kernel msgs into the journal, and since kernel msgs carry no elaborate
> timestamps we generate them when we flush that. So maybe that flushing
> happens after the fake rtc thing?
> 

After more testing I think that you are right about this. If 
fake-hwclock manages to set the time before journald starts then the 
timestamps are all correct.

At the moment fake-hwclock doesn't have a dependency to start before 
journald on the RPI, so sometimes it does and sometimes it doesn't. I 
see that there is a call to clock_gettime in journald, so I guess that 
we are okay as long as fake-hwclock has set the time before this call.

Testing on both an RPI3 and RPI4 shows that the journal log timestamps 
fail intermittently (maybe once every 10 boots) with some messages 
displaying a date of Feb 14 2019 (for the Raspberry Pi OS Buster 
release). If I add an extra dependency to fake-hwclock.service, so that:

Before=sysinit.target systemd-fsck-root.service

becomes:

Before=sysinit.target systemd-fsck-root.service systemd-journald.service

Then the dates are always correct - I've been running fairly continuous 
reboots over the last day and it hasn't failed yet.

If you think that this dependency change makes sense, then I think it 
would be worth submitting an update to Debian/Raspberry Pi Os.

Regards

Mark



> Lennart
> 
> --
> Lennart Poettering, Berlin
> 


More information about the systemd-devel mailing list