On Fri, Sep 4, 2020 at 6:59 PM Lennart Poettering <lenn...@poettering.net> wrote:
> On Do, 27.08.20 11:33, Mark Corbin (m...@dibsco.co.uk) wrote: > > > Hello > > > > I am working on time synchronisation issues at boot for systems without > an > > RTC (using balenaOS on a Raspberry Pi 3) and have some questions about > how > > journald assigns timestamps to log messages. > > > > When I boot my system and look at the journal I see an initial date/time > for > > kernel messages, e.g. '1 June 2020 10:00:00' followed by messages with > the > > 'correct' date/time once the system time has been set from another > source, > > e.g. build time, NTP, etc. This means that over several reboots I have > lots > > of sets of log messages from 1 June 2020 which understandably confuses > the > > 'journalctl --list-boots' command. I found an issue that describes the > > problem here https://github.com/systemd/systemd/issues/662 and had > assumed > > that there wasn't anything I could do about this. > > > > However, when running some tests on a board with Raspberry Pi OS I found > > that it didn't suffer from the same problem. RPI OS uses a 'fake-hwclock' > > service to restore the previous boot time from a file and this time gets > > applied to all messages in the journal prior to this point. I added the > > 'fake-hwclock' service to my system which resulted in the timestamps > being > > correct the majority of the time, but I was still seeing some boots where > > the initial messages were showing '1 June 2020'. I eventually tracked the > > intermittent behaviour down to whether the 'fake-hwclock' time setting > > occurred in the same system log file as the initial kernel boot > messages. On > > my RPI OS board the runtime journal was set to 8MB, so the date/time > setting > > always occurred in the first journal file. On my system the runtime > journal > > was set to 4MB, so the date/time setting was sometimes happening in the > > second journal file leaving the messages in the first file with a date > of '1 > > June 2020'. > > > > So my questions are... > > > > It seems that journald is using the date/time from the 'fake-hwclock' > > service to update the timestamps of earlier log messages within the same > > file. Is this correct? > > No. We do not retroactively change written out records. > > However, when comparing log entries we prefer the record sequence > number if two records come from the same system. And if that doesn't > work, then we prefer monotonic clocks if two records cme from the same > boot. Wallclock is only used for comparing two records if they are > from different boots altogether. > > > What would be the best technique for ensuring that my journal logs always > > display the 'best' time for log messages (either 'fake-hwclock' or NTP)? > Do > > I always have to ensure that the journal is large enough to capture my > > initial time setting event in the first file? > > There's no nice answer for that. We do not patch written out journal > records once they are written. They are considered immutable. This > means, from the journal's PoV if you generated a bunch of records in > the initrd or early boot (i.e. before /var/log/journal is available) > and you have no usable wallclock time, and you power cycle 10 times in a > row, then we have no indication about which of the 10 series of > recrods came in which order before the others. > > To fix that we'd have to keep a separate log of boot ids or so > somewhere, which we could use as auxiliary source of truth if all we > have are bootids+monotonic time which came first by comparing boot > ids. But that would still not be perfect since we could write that out > only late (i.e. after /var becomes writable), so the order before that > could not be reconstructed either if the system doesn't get that far. > Hmm, but if there's no /var in which to store the append-only log of boot IDs, then there's also no /var in which journal messages would persist either, is there? So one wouldn't be seeing messages from previous boots anyway. Also, if /var *is* available, didn't .journal files also have some sort of global sequence number that could be used when timestamps fail? -- Mantas Mikulėnas
_______________________________________________ systemd-devel mailing list systemd-devel@lists.freedesktop.org https://lists.freedesktop.org/mailman/listinfo/systemd-devel