I wish systemd logged information about the source of "transactions"

November 23, 2021

I tweeted:

It would be nice if systemd would log a line when it starts a transaction to say what the transaction was and what asked it to do the transaction. Brought to you by the currently burning question of 'what asked systemd to reboot this system?'

Back long ago, the only thing that would reboot Linux machines in an orderly way was the system administrator logging in and running 'reboot' (or an equivalent). If a machine rebooted on you and the logs said it was an orderly reboot (instead of an abrupt crash), this meant you could see at least who was logged in or had just logged in, and figure out the source of the reboot. (Sometimes this might be someone typing a command on the wrong machine.)

Modern Linux doesn't work this way, especially with systemd involved. Systemd has a D-Bus interface that people can use, there's hardware events that may trigger a reboot, there are various programs that may decide to ask systemd to reboot the system, and under some circumstances systemd itself can decide that a particular, harmless looking process failure or 'systemctl' transaction actually will trigger a reboot through some weird chain of dependencies and systemd unit settings. These days, it's entirely possible to have a system go through an orderly shutdown and reboot with no clues in the logs as to what actually did it or why it happened.

However, systemd also has all of the information it needs to log a summary of this. Every time systemd starts a "transaction" (a set of changes to units), it knows what the starting request is and generally who asked for it (and how). It could routinely log this, which would make it much easier to trace back mysterious events later.

(Systemd has a LogLevel, but it's generally already as verbose as it can be (it defaults to 'info') without going all the way to copious debugging messages.)

PS: If there already is a way to get systemd to report this information, I'd be happy to know. Systemd has a lot of documentation and sometimes valuable information lurks in the corners.

(For obvious reasons this information should be recoverable after a reboot, not just available dynamically. Although for my purposes, I would be happy if we had something that ran during shutdowns to log the cause, since surprise shutdowns are what we're most interested in.)

Comments on this page:

I still have seemingly absurd wrappers “echo foo started”, “echo foo finished” around some jobs that are nowadays exclusively invoked via systemd to make log output more useful. I suspect that data lives somewhere in the journal but it’s not tagged with the unit.

By kevinoid at 2021-11-25 09:50:13:

For what it's worth, dorianmarie opened systemd/systemd#21497 to request this.

Written on 23 November 2021.
« Why it matters to us if exploits are available for security issues
Computation that needs to be "secure" is everywhere in practice »

Page tools: View Source, View Normal, Add Comment.
Login: Password:
Atom Syndication: Recent Comments.

Last modified: Tue Nov 23 23:23:33 2021
This dinky wiki is brought to you by the Insane Hackers Guild, Python sub-branch.