-
Notifications
You must be signed in to change notification settings - Fork 131
Add systemd structured logging for bootc state changes #1522
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Conversation
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Code Review
This pull request introduces structured logging to the systemd journal for key bootc operations, which is a significant improvement for system observability. The changes are consistently applied across various commands like upgrade
, switch
, install
, and deploy
, using a common pattern with MESSAGE_ID
s for easier log filtering. The logged fields are relevant and provide good context for each operation. I have one minor suggestion for improving consistency.
1e180a8
to
5222761
Compare
5222761
to
5fb66c3
Compare
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
This is a nice improvement. It will be good to have these messages nicely in the Journal!
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I'm largely OK with this as is, so marking approved. However one concern: We're not logging very much at all right now and I wonder how chatty this will feel in practice.
I think for example a no-op upgrade feels like it should log at most two messages:
- Starting a check for updates
- No updates found
I haven't looked if that's the case now.
In the changed image case it'd also be useful to take a look at how chatty it is. Offhand I think it'll be at least 5 messages? That's probably OK but still work looking at.
2735018
to
843e8fc
Compare
I looked at the test failures and did #1535 but not sure why this is just showing up now. |
crates/lib/src/install/completion.rs
Outdated
const COMPLETION_JOURNAL_ID: &str = "0f9a8b7c6d5e4f3a2b1c0d9e8f7a6b5c4"; | ||
let msg = "Starting bootc installation completion"; | ||
crate::journal::journal_send( | ||
Priority::Info, | ||
msg, | ||
[ | ||
("MESSAGE_ID", COMPLETION_JOURNAL_ID), | ||
("BOOTC_STATEROOT", stateroot.unwrap_or("default")), | ||
] | ||
.into_iter(), | ||
); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I'm OK to merge as is but one thing that would help readability a good bit here is for us to have a wrapper macro like journal_send!
that wraps the format!
infrastructure.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
And to go a bit more advanced, having it be something like
journal::message!(COMPLETION_JOURNAL_ID, "Starting installation completion", ...<other format args>).with(["BOOTC_STATEROOT", stateroot.unwrap_or("default")).send()
or so would look nicer, though definitely a bit more work to have the macro return a struct with methods etc.
843e8fc
to
5d6c258
Compare
crates/lib/src/install/completion.rs
Outdated
const COMPLETION_JOURNAL_ID: &str = "0f9a8b7c6d5e4f3a2b1c0d9e8f7a6b5c4"; | ||
let msg = "Starting bootc installation completion"; | ||
crate::journal::journal_send( | ||
Priority::Info, | ||
msg, | ||
[ | ||
("MESSAGE_ID", COMPLETION_JOURNAL_ID), | ||
("BOOTC_STATEROOT", stateroot.unwrap_or("default")), | ||
] | ||
.into_iter(), | ||
); |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
And to go a bit more advanced, having it be something like
journal::message!(COMPLETION_JOURNAL_ID, "Starting installation completion", ...<other format args>).with(["BOOTC_STATEROOT", stateroot.unwrap_or("default")).send()
or so would look nicer, though definitely a bit more work to have the macro return a struct with methods etc.
crates/lib/src/deploy.rs
Outdated
PreparedPullResult::Ready(prepared_image_meta) => { | ||
// Log that we're pulling a new image | ||
const PULL_JOURNAL_ID: &str = "5c4d3e2f1a0b9c8d7e6f5a4b3c2d1e0f9"; |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Why duplicate this const
? Though it does seem to me that "no changes" and "pulling a new image" are different events
5d6c258
to
ec01edb
Compare
crates/utils/src/tracing_util.rs
Outdated
} | ||
} | ||
|
||
// Fall back to the previous setup if journald isn't available |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Hmm interesting...this would be a pretty big workflow change for those who are used to doing e.g. env RUST_LOG=trace bootc ...
I wonder if we can set things up so that we log to the journal always for key messages, but still use stdout/stderr for debug/trace level?
2b95e42
to
c060bad
Compare
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Thanks! This is looking a lot nicer, wouldn't you agree? I just have one outstanding comment
crates/utils/src/tracing_util.rs
Outdated
// Always try to use journald subscriber if we're running under systemd | ||
// This ensures key messages (info, warn, error) go to the journal | ||
let journald_layer = if let Ok(()) = std::env::var("JOURNAL_STREAM").map(|_| ()) { | ||
tracing_journald::layer().ok() |
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
I think we want to have a filter here so that only info and above goes to the journal, right? I think it's possible with https://docs.rs/tracing-subscriber/latest/tracing_subscriber/layer/trait.Layer.html#method.with_filter - I can take a look if you want.
Otherwise someone debugging with e.g. env RUST_LOG=trace
will completely spam the journal.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
Basically same as this #1522 (comment)
b539d00
to
f365b70
Compare
Ah looks like this needs a rebase now |
d925b62
to
137b7d8
Compare
137b7d8
to
bf74ecb
Compare
Log key operations (deploy, upgrade, switch, install, etc.) to systemd journal with structured fields including image references, digests, and operation types. Uses existing journal infrastructure and follows ostree logging patterns.