Re: Monotonic time went backwards, rotating log

[Lennart Poettering <lennart@xxxxxxxxxxxxxx>]

On Do, 25.05.23 14:32, Phillip Susi (phill@xxxxxxxxxxxx) wrote:

>
> Lennart Poettering <lennart@xxxxxxxxxxxxxx> writes:
>
> > We want that within each file all records are strictly ordered by all
> > clocks, so that we can find specific entries via bisection.
>
> Why *all* clocks?  Even if you want to search on the monotonic time, you
> first have to specify a boot ID within which that monotonic time is
> valid, don't you?  So the first step in your search would be to find the
> boot records, then bisect from there.

We didn't use to do this, but it makes things a lot easier to say "one
boot id per file", since we nowadays have a concept for dealing with
systems that lack a battery-buffered RTC and which hence of a
CLOCK_REALTIME that initially starts at zero. We will nowadays use the
monotonic timestamp of log records for them and adjust them by the
most recent delta between CLOCK_REALTIME and CLOCK_MONOTONIC for the
specific boot id. If we can look this up directly in the journal file
header is relatively cheap and easy. But once we store more than one
boot id in a file this becomes harder, because we now have to search
for the boot ID inside the file.

> > The message is debug level, no?
>
> log_ratelimit_info(), which appears to be printed by default when I log
> in, and I presume my session systemd instance is started.  I guess
> that's the problem: it should be debug.

File a bug, or better file a PR.

> Also though, why doesn't it first note that the boot ID changed?

It actually checks that first:

https://github.com/systemd/systemd/blob/main/src/libsystemd/sd-journal/journal-file.c#L2201

Lennart

--
Lennart Poettering, Berlin