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

@@ -24,7 +24,6 @@ use ostree_ext::container as ostree_container;
 use ostree_ext::container_utils::ostree_booted;
 use ostree_ext::keyfileext::KeyFileExt;
 use ostree_ext::ostree;
-use ostree_ext::sysroot::SysrootLock;
 use schemars::schema_for;
 use serde::{Deserialize, Serialize};
 
@@ -785,7 +784,10 @@ fn has_soft_reboot_capability(deployment: Option<&crate::spec::BootEntry>) -> bo
 
 /// Prepare a soft reboot for the given deployment
 #[context("Preparing soft reboot")]
-fn prepare_soft_reboot(sysroot: &SysrootLock, deployment: &ostree::Deployment) -> Result<()> {
+fn prepare_soft_reboot(
+    sysroot: &ostree_ext::sysroot::SysrootLock,
+    deployment: &ostree::Deployment,
+) -> Result<()> {
     let cancellable = ostree::gio::Cancellable::NONE;
     sysroot
         .deployment_set_soft_reboot(deployment, false, cancellable)
@@ -832,7 +834,7 @@ where
 /// Handle soft reboot for staged deployments (used by upgrade and switch)
 #[context("Handling staged soft reboot")]
 fn handle_staged_soft_reboot(
-    sysroot: &SysrootLock,
+    sysroot: &ostree_ext::sysroot::SysrootLock,
     soft_reboot_mode: Option<SoftRebootMode>,
     host: &crate::spec::Host,
 ) -> Result<()> {
@@ -846,7 +848,7 @@ fn handle_staged_soft_reboot(
 
 /// Perform a soft reboot for a staged deployment
 #[context("Soft reboot staged deployment")]
-fn soft_reboot_staged(sysroot: &SysrootLock) -> Result<()> {
+fn soft_reboot_staged(sysroot: &ostree_ext::sysroot::SysrootLock) -> Result<()> {
     println!("Staged deployment is soft-reboot capable, preparing for soft-reboot...");
 
     let deployments_list = sysroot.deployments();
@@ -861,7 +863,7 @@ fn soft_reboot_staged(sysroot: &SysrootLock) -> Result<()> {
 
 /// Perform a soft reboot for a rollback deployment
 #[context("Soft reboot rollback deployment")]
-fn soft_reboot_rollback(sysroot: &SysrootLock) -> Result<()> {
+fn soft_reboot_rollback(sysroot: &ostree_ext::sysroot::SysrootLock) -> Result<()> {
     println!("Rollback deployment is soft-reboot capable, preparing for soft-reboot...");
 
     let deployments_list = sysroot.deployments();
@@ -990,6 +992,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;
@@ -1067,6 +1072,26 @@ 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");
+
+    tracing::info!(
+        message_id = SWITCH_JOURNAL_ID,
+        bootc.old_image_reference = old_image,
+        bootc.new_image_reference = &target.image,
+        bootc.new_image_transport = &target.transport,
+        "Switching from image {} to {}",
+        old_image,
+        target.image
+    );
+
     let new_spec = RequiredHostSpec::from_spec(&new_spec)?;
 
     let fetched = crate::deploy::pull(repo, &target, None, opts.quiet, prog.clone()).await?;
@@ -1364,7 +1389,7 @@ async fn run_from_opt(opt: Opt) -> Result<()> {
         Opt::ExecInHostMountNamespace { args } => {
             crate::install::exec_in_host_mountns(args.as_slice())
         }
-        Opt::Status(opts) => super::status::status(opts).await,
+        Opt::Status(opts) => crate::status::status(opts).await,
         Opt::Internals(opts) => match opts {
             InternalsOpts::SystemdGenerator {
                 normal_dir,

crates/lib/src/cli.rs

@@ -98,22 +98,18 @@ 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,
-                &format!(
+            o => {
+                tracing::warn!(
                     "notice: Unknown {} value {}",
                     crate::metadata::BOOTC_COMPAT_LABEL,
                     o
-                ),
-            ),
+                );
+            }
         }
     } else {
-        crate::journal::journal_print(
-            libsystemd::logging::Priority::Warning,
-            &format!(
-                "notice: Image is missing label: {}",
-                crate::metadata::BOOTC_COMPAT_LABEL
-            ),
+        tracing::warn!(
+            "notice: Image is missing label: {}",
+            crate::metadata::BOOTC_COMPAT_LABEL
         )
     }
 }
@@ -429,11 +425,24 @@ 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";
+
+    tracing::info!(
+        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,
+        "Successfully imported image: {}",
+        imgref
+    );
+
     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);
+        tracing::info!("{}", msg);
     }
     Ok(Box::new((*import).into()))
 }
@@ -447,8 +456,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?)
         }
     }
@@ -466,6 +497,14 @@ 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";
+
+    tracing::info!(
+        message_id = CLEANUP_JOURNAL_ID,
+        "Starting cleanup of old images and deployments"
+    );
+
     let bound_prune = prune_container_store(sysroot);
 
     // We create clones (just atomic reference bumps) here to move to the thread.
@@ -615,6 +654,20 @@ 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";
+
+    tracing::info!(
+        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,
+        "Staging image for deployment: {} (digest: {})",
+        spec.image,
+        image.manifest_digest
+    );
+
     let ostree = sysroot.get_ostree()?;
     let mut subtask = SubTaskStep {
         subtask: "merging".into(),
@@ -773,19 +826,26 @@ 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"))?;
-    let msg = format!("Rolling back to image: {}", rollback_image.manifest_digest);
-    libsystemd::logging::journal_send(
-        libsystemd::logging::Priority::Info,
-        &msg,
-        [
-            ("MESSAGE_ID", ROLLBACK_JOURNAL_ID),
-            (
-                "BOOTC_MANIFEST_DIGEST",
-                rollback_image.manifest_digest.as_ref(),
-            ),
-        ]
-        .into_iter(),
-    )?;
+
+    // Get current booted image for comparison
+    let current_image = host
+        .status
+        .booted
+        .as_ref()
+        .and_then(|b| b.query_image(repo).ok()?);
+
+    tracing::info!(
+        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"),
+        "Rolling back to image: {}",
+        rollback_image.manifest_digest
+    );
     // 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 {
@@ -833,6 +893,18 @@ 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";
+
+    tracing::info!(
+        message_id = SWITCH_INPLACE_JOURNAL_ID,
+        bootc.image.reference = &imgref.image,
+        bootc.image.transport = &imgref.transport,
+        bootc.switch_type = "in_place",
+        "Performing in-place switch to image: {}",
+        imgref
+    );
+
     // First, just create the new origin file
     let origin = origin_from_imageref(imgref)?;
     let serialized_origin = origin.to_data();