Skip to content

A number of journal fixes#4362

Merged
keszybz merged 12 commits intosystemd:masterfrom
poettering:journalbootlistfix
Oct 13, 2016
Merged

A number of journal fixes#4362
keszybz merged 12 commits intosystemd:masterfrom
poettering:journalbootlistfix

Conversation

@poettering
Copy link
Member

Various fixes for the journal, in particular covering #4088 #4278 #4059 #4060

Let's make it easier to figure out when we see an invalid journal file, why we
consider it invalid, and add some minimal debug logging for it.

This log output is normally not seen (after all, this all is library code),
unless debug logging is exlicitly turned on.
…y_index()

This allows us to share a bit more code between journal_file_next_entry() and
journal_file_next_entry_for_data().
…ction

This adds a new call check_properly_ordered(), which we can reuse later, and
makes the code a bit more readable.
Let's and extra check, reusing check_properly_ordered() also for
journal_file_next_entry_for_data().
Let's make dissecting of borked journal files more expressive: if we encounter
an object whose first 8 bytes are all zeroes, then let's assume the object was
simply never initialized, and say so.

Previously, this would be detected as "overly short object", which is true too
in a away, but it's a lot more helpful printing different debug options for the
case where the size is not initialized at all and where the size is initialized
to some bogus value.

No function behaviour change, only a different log messages for both cases.
…e keep going

When iterating through partially synced journal files we need to be prepared
for hitting with invalid entries (specifically: non-initialized). Instead of
generated an error and giving up, let's simply try to preceed with the next one
that is valid (and debug log about this).

This reworks the logic introduced with caeab8f
to iteration in both directions, and tries to look for valid entries located
after the invalid one. It also extends the behaviour to both iterating through
the global entry array and per-data object entry arrays.

Fixes: systemd#4088
Let's use the earliest linearized event timestamp for journal entries we have:
the event dispatch timestamp from the event loop, instead of requerying the
timestamp at the time of writing.

This makes the time a bit more accurate, allows us to query the kernel time one
time less per event loop, and also makes sure we always use the same timestamp
for both attempts to write an entry to a journal file.
…kwards

As soon as we notice that the clock jumps backwards, rotate journal files. This
is beneficial, as this makes sure that the entries in journal files remain
strictly ordered internally, and thus the bisection algorithm applied on it is
not confused.

This should help avoiding borked wallclock-based bisection on journal files as
witnessed in systemd#4278.
Never permit that we write to journal files that have newer timestamps than our
local wallclock has. If we'd accept that, then the entries in the file might
end up not being ordered strictly.

Let's refuse this with ETXTBSY, and then immediately rotate to use a new file,
so that each file remains strictly ordered also be wallclock internally.
Let's just say that the journal takes up space in the file system, not on disk,
as tmpfs is definitely a file system, but not a disk.

Fixes: systemd#4059
return true;

case -ETXTBSY: /* Journal file is from the future */
log_warning("%s: Journal file is from the future, rotateing.", f->path);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

rotateing

Typo?

@hese10
Copy link
Contributor

hese10 commented Oct 13, 2016

I tested these changes for that hanging "--list-boots" case (#4278), and these changes prevented the forever loop in journalctl.

@keszybz
Copy link
Member

keszybz commented Oct 13, 2016

Looks all good. Typo fixed in merge.

@hese10
Copy link
Contributor

hese10 commented Nov 22, 2016

It seems that these journald fixes do not help at least in openstack environment where we have different time zone (+8h into future) during boot up until VM gets correct time via NTP. In these cases we end up still hanging "journalctl --list-boots" command. Also we have problem with cursor parameter in journalctl in these cases.

@hese10
Copy link
Contributor

hese10 commented Nov 22, 2016

It seems "--list-boots" hangs due to corrupted journal file ("bad message" error for verify).

@poettering
Copy link
Member Author

@hese10 if you want your issues not being ignored, file proper issues for them. First reproduce them on the most recent systemd version, and then do provide a minimal set of journal files that exposes the misbheaviour you are seeing. Thanks. If you just comment on some already-closed PR nobody will take notice.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

Development

Successfully merging this pull request may close these issues.

4 participants