The Grumpy Editor's guide to surviving the systemd debate [LWN.net]

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 13, 2014 17:36 UTC (Thu) by jspaleta (subscriber, #50639)
In reply to: The Grumpy Editor's guide to surviving the systemd debate by cdmiller
Parent article: The Grumpy Editor's guide to surviving the systemd debate

There are bug reports? Can you point me to your favorite ones?

to post comments

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 14, 2014 4:20 UTC (Fri) by cdmiller (guest, #2813) [Link] (20 responses)

Since I mentioned the journal I'll take your bait and point you at one. Probably the most rehashed, bug 64116.

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 14, 2014 9:10 UTC (Fri) by niner (guest, #26151) [Link] (19 responses)

Can you please explain to me why the following comment from the bug report you mentioned, does not explain the rationale behind this design decision sufficiently?

Lennart Poettering 2014-10-08 20:27:49 UTC
Since this bugyilla report is apparently sometimes linked these days as an example how we wouldn't fix a major bug in systemd:

Journal files are mostly append-only files. We keep adding to the end as we go, only updating minimal indexes and bookkeeping in the front earlier parts of the files. These files are rotated (rotation = renamed and replaced by a new one) from time to time, based on certain conditions, such as time, file size, and also when we find the files to be corrupted. As soon as they rotate they are entirely read-only, never modified again. When you use a tool like "journalctl" to read the journal files both the active and the rotated files are implicitly merged, so that they appear as a single stream again.

Now, our strategy to rotate-on-corruption is the safest thing we can do, as we make sure that the internal corruption is frozen in time, and not attempted to be "fixed" by a tool, that might end up making things worse. After all, in the case the often-run writing code really fucks something up, then it is not necessarily a good idea to try to make it better by running a tool on it that tries to fix it up again, a tool that is necessarily a lot more complex, and also less tested.

Now, of course, having corrupted files isn't great, and we should make sure the files even when corrupted stay as accessible as possible. Hence: the code that reads the journal files is actually written in a way that tries to make the best of corrupted files, and tries to read of them as much as possible, with the the subset of the file that is still valid. We do this implicitly on every access.

Hence: journalctl implicitly does on read what a theoretical journal file fsck tool would do, but without actually making this persistent. This logic also has a major benefit: as our reader gets better and learns to deal with more types of corruptions you immediately benefit of it, even for old files!

File systems such as ext4 have an fsck tool since they don't have the luxury to just rotate the fs away and fix the structure on read: they have to use the same file system for all future writes, and they thus need to try hard to make the existing data workable again.

I hope this explains the rationale here a bit more.

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 17, 2014 23:45 UTC (Mon) by nix (subscriber, #2304) [Link] (5 responses)

Now, our strategy to rotate-on-corruption is the safest thing we can do, as we make sure that the internal corruption is frozen in time, and not attempted to be "fixed" by a tool, that might end up making things worse. After all, in the case the often-run writing code really fucks something up, then it is not necessarily a good idea to try to make it better by running a tool on it that tries to fix it up again, a tool that is necessarily a lot more complex, and also less tested.

I can't believe anyone thinks this argument has any merit at all. You could use the same words to argue that filesystems (a complex mass of binary data frequently written to which can suffer corruption) should never be repaired, because you can never get a fsck that always repairs all problems and never makes anything worse. Instead, we consider a filesystem sans fsck to be substandard.

Meanwhile, the format it's replacing, if corrupted, well, let's see -- you lose a line of syslog. Maybe you lose a bunch of other lines. But recovery from that is automatic; you only lose a line of syslog data around that touched by the corruption. You certainly don't lose a whole file. You *certainly* don't just rotate it away and, oh, I guess we should hope it wasn't an important log then.

This is not a sensible attitude to log data unless you consider log data fundamentally unimportant -- and in that case, why on earth are you recording it at all?

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 17, 2014 23:59 UTC (Mon) by Cyberax (✭ supporter ✭, #52523) [Link]

As far as I remember, X.org's repositories were corrupted beyond recovery after power failed multiple times during fsck.

I've also had a similar experiences (albeit with NTFS on Windows).

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 20, 2014 2:58 UTC (Thu) by raven667 (subscriber, #5198) [Link] (3 responses)

> Maybe you lose a bunch of other lines. But recovery from that is automatic; you only lose a line of syslog data around that touched by the corruption.

Maybe I misread but isn't that what journalctl does, skip invalid records and start back up at the next valid record, without touching the original file so you always have a pristine copy with the corruption intact? Logs are different than filesystems in that they are write once, read many, you never want to rewrite history, even if that history is corrupt due to a bug.

In fact if it were me, if you detect corruption on reading a journal log I would want to immediately kill journald and let systemd restart it, on startup the new copy can start a new log file Treat it like a microkernel server, die and reload quickly on error.

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 20, 2014 3:47 UTC (Thu) by dlang (guest, #313) [Link] (2 responses)

with a binary file format, finding the start of the next message is not that easy.

As for killing journald when you _read_ a bad message, that sure isn't the right thing to do because you can read the same message many times, and do it years after it was written. killing journald when you read a message that's written a significant time in the past is the WRONG thing to do.

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 20, 2014 4:28 UTC (Thu) by raven667 (subscriber, #5198) [Link]

sorry, I maybe should have been more clear, journalctl reads both the currently writing log and all previous ones that have been rotated and are still around, it should only restart journald if the corruption is in the log that journald is currently writing. The reason to implement this in the reader is that the I don't expect the log writer be reading often enough to notice if something has gone wrong.

I don't know if that's how it actually works, that's just my first idea of how I think it should work.

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 21, 2014 9:15 UTC (Fri) by zlynx (guest, #2285) [Link]

Finding stuff in "binary" files is no more difficult than text files. It depends on the particular format.

People tend to forget that text files ARE A BINARY FORMAT. You have your 7-bit ASCII message terminated by a new-line character.

You could also have an array of 4 byte little-endian unsigned integers, terminated by 4 bytes of zero. It would be just as easy to find the start of the next message as it is in text.

We're pretty spoiled these days and don't have to worry about our messages getting off by a bit or two. I recall modems where if you weren't using parity (or was it stop bits) you might lose sync and anything could happen.

Anyway, there might be valid complaints about the particular design of journald's binary format. But just because it is binary doesn't necessarily make it unusually hard to recover or read.

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 17, 2014 23:47 UTC (Mon) by nix (subscriber, #2304) [Link] (9 responses)

File systems such as ext4 have an fsck tool since they don't have the luxury to just rotate the fs away and fix the structure on read: they have to use the same file system for all future writes, and they thus need to try hard to make the existing data workable again.

This is, of course, a fallacious argument too. File systems such as ext4 have a fsck tool because it would be an appalling implementation which said, oh, the FS is corrupted, we'll hit you with an empty one and let you get at the old one with some special commands! Which is more-or-less what systemd's journal does.

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 18, 2014 0:07 UTC (Tue) by rahulsundaram (subscriber, #21946) [Link]

That is not what the bug report claims:

"of course, having corrupted files isn't great, and we should make sure the files even when corrupted stay as accessible as possible. Hence: the code that reads the journal files is actually written in a way that tries to make the best of corrupted files, and tries to read of them as much as possible, with the the subset of the file that is still valid. We do this implicitly on every access."

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 18, 2014 0:15 UTC (Tue) by mchapman (subscriber, #66589) [Link] (7 responses)

> oh, the FS is corrupted, we'll hit you with an empty one and let you get at the old one with some special commands! Which is more-or-less what systemd's journal does.

No, it doesn't end up empty.

In my experience, a corrupted journal file is still completely readable and searchable, except for its final entry. Since the tools don't expose how individual journal files are being accessed, this corruption simply appears as if you'd lost a single log message.

Yes, it's possible some header corruption could mean an entire file is unreadable. I haven't personally seen that, but I can imagine that it's a concern for some people. You can limit the damage by ensuring the files get rotated frequently. There's {System,RunTime}MaxFileSize config options available; perhaps corresponding {System,RunTime}MaxRotateInterval might be useful. Worst comes to worst, you could just SIGUSR2 the journald process regularly from Cron or a timer unit.

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 18, 2014 0:59 UTC (Tue) by dlang (guest, #313) [Link] (6 responses)

the instance of journald corruption that I saw ended up with the binary pointers going backwards and so walking the journal ended up with an endless loop

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 18, 2014 2:34 UTC (Tue) by mchapman (subscriber, #66589) [Link] (5 responses)

Right. I haven't seen that myself, but I could imagine it could happen.

But it sounds like something easily detectable by the libraries that read the journal files (so other apps, not just journalctl, would get the fix), and it still wouldn't result in an "empty" journal.

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 18, 2014 4:03 UTC (Tue) by dlang (guest, #313) [Link] (4 responses)

It does make it so that all log entries after the corruption are lost though.

This is one of the problems with binary logs

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 18, 2014 5:04 UTC (Tue) by mchapman (subscriber, #66589) [Link] (3 responses)

Only up until the next rotation... which would presumably happen when you update systemd to fix the bug, if not earlier.

Look, I'm not denying that there are bugs that can corrupt the logs or lose large numbers of log messages. But the original claim -- that corruption yields an "empty" journal that can only be made non-empty through the use of "special commands" -- is patently false.

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 18, 2014 11:59 UTC (Tue) by notninjaz (guest, #99725) [Link] (2 responses)

As I read it, the original "empty" statement was referring to the new journal which would be empty as in a clean slate, comparing it to offering the user a new clean slate filesystem rather than trying to repair a corrupted one.

This thread has brought out some of the tradeoffs, though, such as a recommendation to rotate the log frequently to minimize the impact of possible corruption. For the servers I administer, I would prefer logging to a text file and risking loss of a fraction of a second of logs if an entry is corrupt instead of rotating a journal hourly and potentially losing 59 minutes should there be corruption.

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 18, 2014 13:14 UTC (Tue) by mchapman (subscriber, #66589) [Link] (1 responses)

> As I read it, the original "empty" statement was referring to the new journal which would be empty as in a clean slate, comparing it to offering the user a new clean slate filesystem rather than trying to repair a corrupted one.

Maybe that was what it was referring to. At any rate, it's just not true. When a journal file is rotated (whether that be because journald has detected corruption in it, or because it's reached its maximum size, or because the admin has simply asked for it by sending SIGUSR2 to the journald process), its contents are still read automatically by journalctl when searching and iterating through the logs.

The journal is not a single file; it is the sum total of *all* journal files. As far as I know, the only way to create an empty journal is to literally remove all of these journal files.

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 18, 2014 14:51 UTC (Tue) by notninjaz (guest, #99725) [Link]

Right, I was referencing the statement: "Yes, it's possible some header corruption could mean an entire file is unreadable. I haven't personally seen that, but I can imagine that it's a concern for some people. You can limit the damage by ensuring the files get rotated frequently. There's {System,RunTime}MaxFileSize config options available; perhaps corresponding {System,RunTime}MaxRotateInterval might be useful. Worst comes to worst, you could just SIGUSR2 the journald process regularly from Cron or a timer unit."

I meant to express a design preference rather to critique any particular software with regard to text vs. binary logs.

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 18, 2014 22:52 UTC (Tue) by cdmiller (guest, #2813) [Link] (2 responses)

The technical side is still debatable as evidenced below. There is apparent confusion over common failure modes of the binary log and what log data is available or potentially lost after a failure. Folks appear to not fully understand or agree with the explanation. The timing of the more detailed response is troubling. What you posted above appeared over a year after the initial bug report. Suffice it to say I'm not convinced systemd-journald log corruption handling is sufficient for servers, or that anything more robust is being pursued.

According to one post below, interesting defaults are being set for logging configuration in RHEL7. The configuration described looks like a band aid to side step this and possibly other issues.

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 19, 2014 0:35 UTC (Wed) by rodgerd (guest, #58896) [Link] (1 responses)

TO be honest, journald *features* are nice, but the implementation detail still seems like the main weakness in systemd-the-suite-of-programs. I don't quite understand why the binary blob DB isn't based on an already extant DB, for example (Gnu DB, Berkely, whatever), and the corruption and lack of a remote logging mechanism undermine the work Lennart did to try and make it more useful as an audit tool.

The Grumpy Editor's guide to surviving the systemd debate

Posted Nov 19, 2014 11:07 UTC (Wed) by mchapman (subscriber, #66589) [Link]

> I don't quite understand why the binary blob DB isn't based on an already extant DB

The official answer to that can be found at http://thread.gmane.org/gmane.comp.sysutils.systemd.devel....

I have read through the journal file format specification [1] and the code that implements it [2], and from what I can tell it looks reasonably straight-forward. I have no doubt bugs will be discovered. That is inevitable with any non-trivial code. But there's really no reason to believe that these bugs will go unfixed. It's not as if it's "new" code, anyway -- people have been using it now for years.

[1] http://www.freedesktop.org/wiki/Software/systemd/journal-...
[2] http://cgit.freedesktop.org/systemd/systemd/plain/src/jou...