composefs: Add structured logging

Similar to the ostree install path, log the main operations
install/switch/update/finalize with a unique journal id

Signed-off-by: Pragyan Poudyal <pragyanpoudyal41999@gmail.com>

Author: Johan-Liebert1

crates/lib/src/bootc_composefs/boot.rs

@@ -1224,6 +1224,16 @@ pub(crate) async fn setup_composefs_boot(
     image_id: &str,
     allow_missing_fsverity: bool,
 ) -> Result<()> {
+    const COMPOSEFS_BOOT_SETUP_JOURNAL_ID: &str = "1f0e9d8c7b6a5f4e3d2c1b0a9f8e7d6c5";
+
+    tracing::info!(
+        message_id = COMPOSEFS_BOOT_SETUP_JOURNAL_ID,
+        bootc.operation = "boot_setup",
+        bootc.image_id = image_id,
+        bootc.allow_missing_fsverity = allow_missing_fsverity,
+        "Setting up composefs boot",
+    );
+
     let mut repo = open_composefs_repo(&root_setup.physical_root)?;
     repo.set_insecure(allow_missing_fsverity);
 

crates/lib/src/bootc_composefs/delete.rs

@@ -315,6 +315,17 @@ pub(crate) async fn delete_composefs_deployment(
     storage: &Storage,
     booted_cfs: &BootedComposefs,
 ) -> Result<()> {
+    const COMPOSEFS_DELETE_JOURNAL_ID: &str = "2a1f0e9d8c7b6a5f4e3d2c1b0a9f8e7d6";
+
+    tracing::info!(
+        message_id = COMPOSEFS_DELETE_JOURNAL_ID,
+        bootc.operation = "delete",
+        bootc.current_deployment = booted_cfs.cmdline.digest,
+        bootc.target_deployment = deployment_id,
+        "Starting composefs deployment deletion for {}",
+        deployment_id
+    );
+
     let host = get_composefs_status(storage, booted_cfs).await?;
 
     let booted = host.require_composefs_booted()?;

crates/lib/src/bootc_composefs/finalize.rs

@@ -52,17 +52,35 @@ pub(crate) async fn composefs_backend_finalize(
     storage: &Storage,
     booted_cfs: &BootedComposefs,
 ) -> Result<()> {
+    const COMPOSEFS_FINALIZE_JOURNAL_ID: &str = "0e9d8c7b6a5f4e3d2c1b0a9f8e7d6c5b4";
+
+    tracing::info!(
+        message_id = COMPOSEFS_FINALIZE_JOURNAL_ID,
+        bootc.operation = "finalize",
+        bootc.current_deployment = booted_cfs.cmdline.digest,
+        "Starting composefs staged deployment finalization"
+    );
+
     let host = get_composefs_status(storage, booted_cfs).await?;
 
     let booted_composefs = host.require_composefs_booted()?;
 
     let Some(staged_depl) = host.status.staged.as_ref() else {
-        tracing::debug!("No staged deployment found");
+        tracing::info!(
+            message_id = COMPOSEFS_FINALIZE_JOURNAL_ID,
+            bootc.operation = "finalize",
+            "No staged deployment found"
+        );
         return Ok(());
     };
 
     if staged_depl.download_only {
-        tracing::debug!("Staged deployment is marked download only. Won't finalize");
+        tracing::info!(
+            message_id = COMPOSEFS_FINALIZE_JOURNAL_ID,
+            bootc.operation = "finalize",
+            bootc.download_only = "true",
+            "Staged deployment is marked download only. Won't finalize"
+        );
         return Ok(());
     }
 

crates/lib/src/bootc_composefs/gc.rs

@@ -166,6 +166,15 @@ pub(crate) fn gc_objects(sysroot: &Dir) -> Result<()> {
 /// perform GC
 #[fn_error_context::context("Running composefs garbage collection")]
 pub(crate) async fn composefs_gc(storage: &Storage, booted_cfs: &BootedComposefs) -> Result<()> {
+    const COMPOSEFS_GC_JOURNAL_ID: &str = "3b2a1f0e9d8c7b6a5f4e3d2c1b0a9f8e7";
+
+    tracing::info!(
+        message_id = COMPOSEFS_GC_JOURNAL_ID,
+        bootc.operation = "gc",
+        bootc.current_deployment = booted_cfs.cmdline.digest,
+        "Starting composefs garbage collection"
+    );
+
     let host = get_composefs_status(storage, booted_cfs).await?;
     let booted_cfs_status = host.require_composefs_booted()?;
 

crates/lib/src/bootc_composefs/repo.rs

@@ -25,7 +25,22 @@ pub(crate) async fn initialize_composefs_repository(
     root_setup: &RootSetup,
     allow_missing_fsverity: bool,
 ) -> Result<(String, impl FsVerityHashValue)> {
+    const COMPOSEFS_REPO_INIT_JOURNAL_ID: &str = "5d4c3b2a1f0e9d8c7b6a5f4e3d2c1b0a9";
+
     let rootfs_dir = &root_setup.physical_root;
+    let image_name = &state.source.imageref.name;
+    let transport = &state.source.imageref.transport;
+
+    tracing::info!(
+        message_id = COMPOSEFS_REPO_INIT_JOURNAL_ID,
+        bootc.operation = "repository_init",
+        bootc.source_image = %image_name,
+        bootc.transport = %transport,
+        bootc.allow_missing_fsverity = allow_missing_fsverity,
+        "Initializing composefs repository for image {}:{}",
+        transport,
+        image_name
+    );
 
     crate::store::ensure_composefs_dir(rootfs_dir)?;
 
@@ -80,6 +95,19 @@ pub(crate) async fn pull_composefs_repo(
     Sha512HashValue,
     crate::store::ComposefsFilesystem,
 )> {
+    const COMPOSEFS_PULL_JOURNAL_ID: &str = "4c3b2a1f0e9d8c7b6a5f4e3d2c1b0a9f8";
+
+    tracing::info!(
+        message_id = COMPOSEFS_PULL_JOURNAL_ID,
+        bootc.operation = "pull",
+        bootc.source_image = image,
+        bootc.transport = transport,
+        bootc.allow_missing_fsverity = allow_missing_fsverity,
+        "Pulling composefs image {}:{}",
+        transport,
+        image
+    );
+
     let rootfs_dir = Dir::open_ambient_dir("/sysroot", ambient_authority())?;
 
     let mut repo = open_composefs_repo(&rootfs_dir).context("Opening composefs repo")?;
@@ -93,7 +121,12 @@ pub(crate) async fn pull_composefs_repo(
         .await
         .context("Pulling composefs repo")?;
 
-    tracing::info!("ID: {id}, Verity: {}", verity.to_hex());
+    tracing::info!(
+        message_id = COMPOSEFS_PULL_JOURNAL_ID,
+        id = id,
+        verity = verity.to_hex(),
+        "Pulled image into repository"
+    );
 
     let mut repo = open_composefs_repo(&rootfs_dir)?;
     repo.set_insecure(allow_missing_fsverity);

crates/lib/src/bootc_composefs/rollback.rs

@@ -186,6 +186,14 @@ pub(crate) async fn composefs_rollback(
     storage: &Storage,
     booted_cfs: &BootedComposefs,
 ) -> Result<()> {
+    const COMPOSEFS_ROLLBACK_JOURNAL_ID: &str = "6f5e4d3c2b1a0f9e8d7c6b5a4e3d2c1b0";
+
+    tracing::info!(
+        message_id = COMPOSEFS_ROLLBACK_JOURNAL_ID,
+        bootc.operation = "rollback",
+        "Starting composefs rollback operation"
+    );
+
     let host = get_composefs_status(storage, booted_cfs).await?;
 
     let new_spec = {

crates/lib/src/bootc_composefs/switch.rs

@@ -18,8 +18,8 @@ pub(crate) async fn switch_composefs(
     booted_cfs: &BootedComposefs,
 ) -> Result<()> {
     let target = imgref_for_switch(&opts)?;
-    // TODO: Handle in-place
 
+    // TODO: Handle in-place
     let host = get_composefs_status(storage, booted_cfs)
         .await
         .context("Getting composefs deployment status")?;
@@ -39,6 +39,16 @@ pub(crate) async fn switch_composefs(
         anyhow::bail!("Target image is undefined")
     };
 
+    const COMPOSEFS_SWITCH_JOURNAL_ID: &str = "7a6b5c4d3e2f1a0b9c8d7e6f5a4b3c2d1";
+
+    tracing::info!(
+        message_id = COMPOSEFS_SWITCH_JOURNAL_ID,
+        bootc.operation = "switch",
+        bootc.target_image = target_imgref.to_string(),
+        bootc.apply_mode = opts.apply,
+        "Starting composefs switch operation",
+    );
+
     let repo = &*booted_cfs.repo;
     let (image, img_config) = is_image_pulled(repo, &target_imgref).await?;
 

crates/lib/src/bootc_composefs/update.rs

@@ -311,6 +311,17 @@ pub(crate) async fn upgrade_composefs(
     storage: &Storage,
     composefs: &BootedComposefs,
 ) -> Result<()> {
+    const COMPOSEFS_UPGRADE_JOURNAL_ID: &str = "9c8d7f6e5a4b3c2d1e0f9a8b7c6d5e4f3";
+
+    tracing::info!(
+        message_id = COMPOSEFS_UPGRADE_JOURNAL_ID,
+        bootc.operation = "upgrade",
+        bootc.apply_mode = opts.apply,
+        bootc.download_only = opts.download_only,
+        bootc.from_downloaded = opts.from_downloaded,
+        "Starting composefs upgrade operation"
+    );
+
     let host = get_composefs_status(storage, composefs)
         .await
         .context("Getting composefs deployment status")?;

crates/lib/src/install.rs

@@ -1704,13 +1704,10 @@ async fn prepare_install(
     if composefs_options.composefs_backend && !composefs_options.allow_missing_verity && !is_uki {
         composefs_options.allow_missing_verity = !root_filesystem.supports_fsverity();
 
-        tracing::debug!(
-            "Missing fsverity {}",
-            if composefs_options.allow_missing_verity {
-                "allowed"
-            } else {
-                "not allowed"
-            }
+        tracing::info!(
+            allow_missing_fsverity = composefs_options.allow_missing_verity,
+            uki = is_uki,
+            "ComposeFS install prep",
         );
     }