Add systemd structured logging for bootc state changes

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 pattern.

Author: gursewak1997

Cargo.lock

@@ -65,6 +65,7 @@ tokio-util = { features = ["io-util"], version = "0.7.10" }
 toml = "0.9.5"
 tracing = "0.1.40"
 tracing-subscriber = { version = "0.3.18", features = ["env-filter"] }
+tracing-journald = "0.3.1"
 uzers = "0.12"
 xshell = "0.2.6"
 

Cargo.toml

@@ -39,7 +39,23 @@ pub(crate) struct ResolvedBoundImage {
 
 /// Given a deployment, pull all container images it references.
 pub(crate) async fn pull_bound_images(sysroot: &Storage, deployment: &Deployment) -> Result<()> {
-    let bound_images = query_bound_images_for_deployment(sysroot.get_ostree()?, deployment)?;
+    // Log the bound images operation to systemd journal
+    const BOUND_IMAGES_JOURNAL_ID: &str = "1a0b9c8d7e6f5a4b3c2d1e0f9a8b7c6d5";
+    tracing::info!(
+        message_id = BOUND_IMAGES_JOURNAL_ID,
+        bootc.deployment.osname = deployment.osname().as_str(),
+        bootc.deployment.checksum = deployment.csum().as_str(),
+        "Starting pull of bound images for deployment"
+    );
+
+    let ostree = sysroot.get_ostree()?;
+    let bound_images = query_bound_images_for_deployment(ostree, deployment)?;
+    tracing::info!(
+        message_id = BOUND_IMAGES_JOURNAL_ID,
+        bootc.bound_images_count = bound_images.len(),
+        "Found {} bound images to pull",
+        bound_images.len()
+    );
     pull_images(sysroot, bound_images).await
 }
 

crates/lib/src/boundimage.rs

@@ -15,6 +15,7 @@ use clap::Parser;
 use clap::ValueEnum;
 use fn_error_context::context;
 use indoc::indoc;
+use libsystemd::logging::Priority;
 use ostree::gio;
 use ostree_container::store::PrepareResult;
 use ostree_ext::composefs::fsverity;
@@ -992,6 +993,9 @@ async fn upgrade(opts: UpgradeOpts) -> Result<()> {
         } else if booted_unchanged {
             println!("No update available.")
         } else {
+            // Note: Individual operation logging (pull, stage, deploy) will provide detailed information
+            // No need for a separate "upgrading" message here since we're not adding new information
+
             let osname = booted_deployment.osname();
             crate::deploy::stage(sysroot, &osname, &fetched, &spec, prog.clone()).await?;
             changed = true;
@@ -1069,6 +1073,28 @@ async fn switch(opts: SwitchOpts) -> Result<()> {
         println!("Image specification is unchanged.");
         return Ok(());
     }
+
+    // Log the switch operation to systemd journal
+    const SWITCH_JOURNAL_ID: &str = "7a6b5c4d3e2f1a0b9c8d7e6f5a4b3c2d1";
+    let old_image = host
+        .spec
+        .image
+        .as_ref()
+        .map(|i| i.image.as_str())
+        .unwrap_or("none");
+    let msg = format!("Switching from image {} to {}", old_image, target.image);
+    crate::journal::journal_send(
+        Priority::Info,
+        &msg,
+        [
+            ("MESSAGE_ID", SWITCH_JOURNAL_ID),
+            ("BOOTC_OLD_IMAGE_REFERENCE", old_image),
+            ("BOOTC_NEW_IMAGE_REFERENCE", &target.image),
+            ("BOOTC_NEW_IMAGE_TRANSPORT", &target.transport),
+        ]
+        .into_iter(),
+    );
+
     let new_spec = RequiredHostSpec::from_spec(&new_spec)?;
 
     let fetched = crate::deploy::pull(repo, &target, None, opts.quiet, prog.clone()).await?;

crates/lib/src/cli.rs

@@ -11,6 +11,7 @@ use cap_std::fs::{Dir, MetadataExt};
 use cap_std_ext::cap_std;
 use cap_std_ext::dirext::CapStdExtDirExt;
 use fn_error_context::context;
+use libsystemd::logging::Priority;
 use ostree::{gio, glib};
 use ostree_container::OstreeImageReference;
 use ostree_ext::container as ostree_container;
@@ -99,7 +100,7 @@ pub(crate) fn check_bootc_label(config: &ostree_ext::oci_spec::image::ImageConfi
         match label.as_str() {
             crate::metadata::COMPAT_LABEL_V1 => {}
             o => crate::journal::journal_print(
-                libsystemd::logging::Priority::Warning,
+                Priority::Warning,
                 &format!(
                     "notice: Unknown {} value {}",
                     crate::metadata::BOOTC_COMPAT_LABEL,
@@ -109,7 +110,7 @@ pub(crate) fn check_bootc_label(config: &ostree_ext::oci_spec::image::ImageConfi
         }
     } else {
         crate::journal::journal_print(
-            libsystemd::logging::Priority::Warning,
+            Priority::Warning,
             &format!(
                 "notice: Image is missing label: {}",
                 crate::metadata::BOOTC_COMPAT_LABEL
@@ -424,11 +425,27 @@ pub(crate) async fn pull_from_prepared(
     let imgref_canonicalized = imgref.clone().canonicalize()?;
     tracing::debug!("Canonicalized image reference: {imgref_canonicalized:#}");
 
+    // Log successful import completion
+    const IMPORT_COMPLETE_JOURNAL_ID: &str = "4d3e2f1a0b9c8d7e6f5a4b3c2d1e0f9a8";
+    let msg = format!("Successfully imported image: {}", imgref);
+    crate::journal::journal_send(
+        Priority::Info,
+        &msg,
+        [
+            ("MESSAGE_ID", IMPORT_COMPLETE_JOURNAL_ID),
+            ("BOOTC_IMAGE_REFERENCE", &imgref.image),
+            ("BOOTC_IMAGE_TRANSPORT", &imgref.transport),
+            ("BOOTC_MANIFEST_DIGEST", import.manifest_digest.as_ref()),
+            ("BOOTC_OSTREE_COMMIT", &import.merge_commit),
+        ]
+        .into_iter(),
+    );
+
     if let Some(msg) =
         ostree_container::store::image_filtered_content_warning(&import.filtered_files)
             .context("Image content warning")?
     {
-        crate::journal::journal_print(libsystemd::logging::Priority::Notice, &msg);
+        crate::journal::journal_print(Priority::Notice, &msg);
     }
     Ok(Box::new((*import).into()))
 }
@@ -442,8 +459,30 @@ pub(crate) async fn pull(
     prog: ProgressWriter,
 ) -> Result<Box<ImageState>> {
     match prepare_for_pull(repo, imgref, target_imgref).await? {
-        PreparedPullResult::AlreadyPresent(existing) => Ok(existing),
+        PreparedPullResult::AlreadyPresent(existing) => {
+            // Log that the image was already present (Debug level since it's not actionable)
+            const IMAGE_ALREADY_PRESENT_ID: &str = "5c4d3e2f1a0b9c8d7e6f5a4b3c2d1e0f9";
+            tracing::debug!(
+                message_id = IMAGE_ALREADY_PRESENT_ID,
+                bootc.image.reference = &imgref.image,
+                bootc.image.transport = &imgref.transport,
+                bootc.status = "already_present",
+                "Image already present: {}",
+                imgref
+            );
+            Ok(existing)
+        }
         PreparedPullResult::Ready(prepared_image_meta) => {
+            // Log that we're pulling a new image
+            const PULLING_NEW_IMAGE_ID: &str = "6d5e4f3a2b1c0d9e8f7a6b5c4d3e2f1a0";
+            tracing::info!(
+                message_id = PULLING_NEW_IMAGE_ID,
+                bootc.image.reference = &imgref.image,
+                bootc.image.transport = &imgref.transport,
+                bootc.status = "pulling_new",
+                "Pulling new image: {}",
+                imgref
+            );
             Ok(pull_from_prepared(imgref, quiet, prog, prepared_image_meta).await?)
         }
     }
@@ -461,6 +500,15 @@ pub(crate) async fn wipe_ostree(sysroot: Sysroot) -> Result<()> {
 }
 
 pub(crate) async fn cleanup(sysroot: &Storage) -> Result<()> {
+    // Log the cleanup operation to systemd journal
+    const CLEANUP_JOURNAL_ID: &str = "2f1a0b9c8d7e6f5a4b3c2d1e0f9a8b7c6";
+    let msg = "Starting cleanup of old images and deployments";
+    crate::journal::journal_send(
+        Priority::Info,
+        msg,
+        [("MESSAGE_ID", CLEANUP_JOURNAL_ID)].into_iter(),
+    );
+
     let bound_prune = prune_container_store(sysroot);
 
     // We create clones (just atomic reference bumps) here to move to the thread.
@@ -610,6 +658,25 @@ pub(crate) async fn stage(
     spec: &RequiredHostSpec<'_>,
     prog: ProgressWriter,
 ) -> Result<()> {
+    // Log the staging operation to systemd journal with comprehensive upgrade information
+    const STAGE_JOURNAL_ID: &str = "8f7a2b1c3d4e5f6a7b8c9d0e1f2a3b4c";
+    let msg = format!(
+        "Staging image for deployment: {} (digest: {})",
+        spec.image, image.manifest_digest
+    );
+    crate::journal::journal_send(
+        Priority::Info,
+        &msg,
+        [
+            ("MESSAGE_ID", STAGE_JOURNAL_ID),
+            ("BOOTC_IMAGE_REFERENCE", &spec.image.image),
+            ("BOOTC_IMAGE_TRANSPORT", &spec.image.transport),
+            ("BOOTC_MANIFEST_DIGEST", image.manifest_digest.as_ref()),
+            ("BOOTC_STATEROOT", stateroot),
+        ]
+        .into_iter(),
+    );
+
     let ostree = sysroot.get_ostree()?;
     let mut subtask = SubTaskStep {
         subtask: "merging".into(),
@@ -768,19 +835,39 @@ pub(crate) async fn rollback(sysroot: &Storage) -> Result<()> {
     let rollback_image = rollback_status
         .query_image(repo)?
         .ok_or_else(|| anyhow!("Rollback is not container image based"))?;
+
+    // Get current booted image for comparison
+    let current_image = host
+        .status
+        .booted
+        .as_ref()
+        .and_then(|b| b.query_image(repo).ok()?);
+
     let msg = format!("Rolling back to image: {}", rollback_image.manifest_digest);
-    libsystemd::logging::journal_send(
-        libsystemd::logging::Priority::Info,
+    crate::journal::journal_send(
+        Priority::Info,
         &msg,
         [
             ("MESSAGE_ID", ROLLBACK_JOURNAL_ID),
             (
                 "BOOTC_MANIFEST_DIGEST",
                 rollback_image.manifest_digest.as_ref(),
             ),
+            ("BOOTC_OSTREE_COMMIT", &rollback_image.merge_commit),
+            (
+                "BOOTC_ROLLBACK_TYPE",
+                if reverting { "revert" } else { "rollback" },
+            ),
+            (
+                "BOOTC_CURRENT_MANIFEST_DIGEST",
+                current_image
+                    .as_ref()
+                    .map(|i| i.manifest_digest.as_ref())
+                    .unwrap_or("none"),
+            ),
         ]
         .into_iter(),
-    )?;
+    );
     // SAFETY: If there's a rollback status, then there's a deployment
     let rollback_deployment = deployments.rollback.expect("rollback deployment");
     let new_deployments = if reverting {
@@ -828,6 +915,21 @@ fn find_newest_deployment_name(deploysdir: &Dir) -> Result<String> {
 
 // Implementation of `bootc switch --in-place`
 pub(crate) fn switch_origin_inplace(root: &Dir, imgref: &ImageReference) -> Result<String> {
+    // Log the in-place switch operation to systemd journal
+    const SWITCH_INPLACE_JOURNAL_ID: &str = "3e2f1a0b9c8d7e6f5a4b3c2d1e0f9a8b7";
+    let msg = format!("Performing in-place switch to image: {}", imgref);
+    crate::journal::journal_send(
+        Priority::Info,
+        &msg,
+        [
+            ("MESSAGE_ID", SWITCH_INPLACE_JOURNAL_ID),
+            ("BOOTC_IMAGE_REFERENCE", &imgref.image),
+            ("BOOTC_IMAGE_TRANSPORT", &imgref.transport),
+            ("BOOTC_SWITCH_TYPE", "in_place"),
+        ]
+        .into_iter(),
+    );
+
     // First, just create the new origin file
     let origin = origin_from_imageref(imgref)?;
     let serialized_origin = origin.to_data();