lib: Add --verbose flag to the CLI for providing a debug option

Signed-off-by: mabulgu <[email protected]>

Author: mabulgu

.gitignore

@@ -5,3 +5,6 @@ bootc.tar.zst
 
 # Added by cargo
 /target
+
+# IDEs / Editors
+.idea/

Cargo.lock

@@ -54,6 +54,7 @@ uuid = { version = "1.8.0", features = ["v4"] }
 tini = "1.3.0"
 comfy-table = "7.1.1"
 thiserror = { workspace = true }
+nix = "0.27.1"
 
 [dev-dependencies]
 similar-asserts = { workspace = true }

lib/Cargo.toml

@@ -55,6 +55,15 @@ impl TryFrom<ProgressOptions> for ProgressWriter {
     }
 }
 
+/// Global args that apply to all subcommands
+#[derive(clap::Args, Debug, Clone, Copy, Default)]
+#[command(about = None, long_about = None)]
+pub(crate) struct GlobalArgs {
+    /// Increase logging verbosity
+    #[arg(short = 'v', long = "verbose", action = clap::ArgAction::Count, global = true)]
+    pub(crate) verbose: u8, // Custom verbosity, counts occurrences of -v
+}
+
 /// Perform an upgrade operation
 #[derive(Debug, Parser, PartialEq, Eq)]
 pub(crate) struct UpgradeOpts {
@@ -460,10 +469,19 @@ impl InternalsOpts {
 /// whether directly via `bootc install` (executed as part of a container)
 /// or via another mechanism such as an OS installer tool, further
 /// updates can be pulled and `bootc upgrade`.
-#[derive(Debug, Parser, PartialEq, Eq)]
+#[derive(Debug, Parser)]
 #[clap(name = "bootc")]
 #[clap(rename_all = "kebab-case")]
 #[clap(version,long_version=clap::crate_version!())]
+pub(crate) struct Cli {
+    #[clap(flatten)]
+    pub(crate) global_args: GlobalArgs,
+
+    #[clap(subcommand)]
+    pub(crate) opt: Opt, // Wrap Opt inside Cli
+}
+
+#[derive(Debug, clap::Subcommand, PartialEq, Eq)]
 #[allow(clippy::large_enum_variant)]
 pub(crate) enum Opt {
     /// Download and queue an updated container image to apply.
@@ -988,7 +1006,7 @@ where
     I: IntoIterator,
     I::Item: Into<OsString> + Clone,
 {
-    run_from_opt(Opt::parse_including_static(args)).await
+    run_from_opt(Cli::parse_including_static(args).opt).await
 }
 
 /// Find the base binary name from argv0 (without a full path). The empty string
@@ -1003,7 +1021,7 @@ fn callname_from_argv0(argv0: &OsStr) -> &str {
         .unwrap_or(default)
 }
 
-impl Opt {
+impl Cli {
     /// In some cases (e.g. systemd generator) we dispatch specifically on argv0.  This
     /// requires some special handling in clap.
     fn parse_including_static<I>(args: I) -> Self
@@ -1027,13 +1045,26 @@ impl Opt {
             };
             if let Some(base_args) = mapped {
                 let base_args = base_args.iter().map(OsString::from);
-                return Opt::parse_from(base_args.chain(args.map(|i| i.into())));
+                return Cli::parse_from(base_args.chain(args.map(|i| i.into())));
             }
             Some(first)
         } else {
             None
         };
-        Opt::parse_from(first.into_iter().chain(args.map(|i| i.into())))
+        // Parse CLI to extract verbosity level
+        let cli = Cli::parse_from(first.into_iter().chain(args.map(|i| i.into())));
+
+        // Set log level based on `-v` occurrences
+        let log_level = match cli.global_args.verbose {
+            0 => tracing::Level::WARN,  // Default (no -v)
+            1 => tracing::Level::INFO,  // -v
+            2 => tracing::Level::DEBUG, // -vv
+            _ => tracing::Level::TRACE, // -vvv or more
+        };
+
+        bootc_utils::update_tracing(log_level);
+
+        cli
     }
 }
 
@@ -1240,14 +1271,15 @@ mod tests {
     #[test]
     fn test_parse_install_args() {
         // Verify we still process the legacy --target-no-signature-verification
-        let o = Opt::try_parse_from([
+        let o = Cli::try_parse_from([
             "bootc",
             "install",
             "to-filesystem",
             "--target-no-signature-verification",
             "/target",
         ])
-        .unwrap();
+        .unwrap()
+        .opt;
         let o = match o {
             Opt::Install(InstallOpts::ToFilesystem(fsopts)) => fsopts,
             o => panic!("Expected filesystem opts, not {o:?}"),
@@ -1264,7 +1296,7 @@ mod tests {
     #[test]
     fn test_parse_opts() {
         assert!(matches!(
-            Opt::parse_including_static(["bootc", "status"]),
+            Cli::parse_including_static(["bootc", "status"]).opt,
             Opt::Status(StatusOpts {
                 json: false,
                 format: None,
@@ -1273,7 +1305,7 @@ mod tests {
             })
         ));
         assert!(matches!(
-            Opt::parse_including_static(["bootc", "status", "--format-version=0"]),
+            Cli::parse_including_static(["bootc", "status", "--format-version=0"]).opt,
             Opt::Status(StatusOpts {
                 format_version: Some(0),
                 ..
@@ -1284,18 +1316,18 @@ mod tests {
     #[test]
     fn test_parse_generator() {
         assert!(matches!(
-            Opt::parse_including_static([
+            Cli::parse_including_static([
                 "/usr/lib/systemd/system/bootc-systemd-generator",
                 "/run/systemd/system"
-            ]),
+            ]).opt,
             Opt::Internals(InternalsOpts::SystemdGenerator { normal_dir, .. }) if normal_dir == "/run/systemd/system"
         ));
     }
 
     #[test]
     fn test_parse_ostree_ext() {
         assert!(matches!(
-            Opt::parse_including_static(["bootc", "internals", "ostree-container"]),
+            Cli::parse_including_static(["bootc", "internals", "ostree-container"]).opt,
             Opt::Internals(InternalsOpts::OstreeContainer { .. })
         ));
 
@@ -1305,25 +1337,147 @@ mod tests {
                 o => panic!("unexpected {o:?}"),
             }
         }
-        let args = peel(Opt::parse_including_static([
-            "/usr/libexec/libostree/ext/ostree-ima-sign",
-            "ima-sign",
-            "--repo=foo",
-            "foo",
-            "bar",
-            "baz",
-        ]));
+        let args = peel(
+            Cli::parse_including_static([
+                "/usr/libexec/libostree/ext/ostree-ima-sign",
+                "ima-sign",
+                "--repo=foo",
+                "foo",
+                "bar",
+                "baz",
+            ])
+            .opt,
+        );
         assert_eq!(
             args.as_slice(),
             ["ima-sign", "--repo=foo", "foo", "bar", "baz"]
         );
 
-        let args = peel(Opt::parse_including_static([
-            "/usr/libexec/libostree/ext/ostree-container",
-            "container",
-            "image",
-            "pull",
-        ]));
+        let args = peel(
+            Cli::parse_including_static([
+                "/usr/libexec/libostree/ext/ostree-container",
+                "container",
+                "image",
+                "pull",
+            ])
+            .opt,
+        );
         assert_eq!(args.as_slice(), ["container", "image", "pull"]);
     }
 }
+
+#[cfg(test)]
+mod tracing_tests {
+    #![allow(unsafe_code)]
+
+    use bootc_utils::{initialize_tracing, update_tracing};
+    use nix::unistd::{close, dup, dup2, pipe};
+    use std::fs::File;
+    use std::io::{self, Read};
+    use std::os::unix::io::{AsRawFd, FromRawFd};
+    use std::sync::Once;
+
+    // Ensure logging is initialized once to prevent conflicts across tests
+    static INIT: Once = Once::new();
+
+    /// Helper function to initialize tracing for tests
+    fn init_tracing_for_tests() {
+        INIT.call_once(|| {
+            std::env::remove_var("RUST_LOG");
+            initialize_tracing();
+        });
+    }
+
+    /// Captures `stderr` output using a pipe
+    fn capture_stderr<F: FnOnce()>(test_fn: F) -> String {
+        let (read_fd, write_fd) = pipe().expect("Failed to create pipe");
+
+        // Duplicate original stderr
+        let original_stderr = dup(io::stderr().as_raw_fd()).expect("Failed to duplicate stderr");
+
+        // Redirect stderr to the write end of the pipe
+        dup2(write_fd, io::stderr().as_raw_fd()).expect("Failed to redirect stderr");
+
+        // Close the write end in the parent to prevent deadlocks
+        close(write_fd).expect("Failed to close write end");
+
+        // Run the test function that produces logs
+        test_fn();
+
+        // Restore original stderr
+        dup2(original_stderr, io::stderr().as_raw_fd()).expect("Failed to restore stderr");
+        close(original_stderr).expect("Failed to close original stderr");
+
+        // Read from the pipe
+        let mut buffer = String::new();
+        // File::from_raw_fd() is considered unsafe in Rust, as it takes ownership of a raw file descriptor.
+        // However, in this case, it's safe because we're using a valid file descriptor obtained from pipe().
+        let mut file = unsafe { File::from_raw_fd(read_fd) };
+        file.read_to_string(&mut buffer)
+            .expect("Failed to read from pipe");
+
+        buffer
+    }
+
+    #[test]
+    fn test_default_tracing() {
+        init_tracing_for_tests();
+
+        let output = capture_stderr(|| {
+            tracing::warn!("Test log message to stderr");
+        });
+
+        assert!(
+            output.contains("Test log message to stderr"),
+            "Expected log message not found in stderr"
+        );
+    }
+
+    #[test]
+    fn test_update_tracing() {
+        init_tracing_for_tests();
+        std::env::remove_var("RUST_LOG");
+        update_tracing(tracing::Level::TRACE);
+
+        let output = capture_stderr(|| {
+            tracing::info!("Info message to stderr");
+            tracing::debug!("Debug message to stderr");
+            tracing::trace!("Trace message to stderr");
+        });
+
+        assert!(
+            output.contains("Info message to stderr"),
+            "Expected INFO message not found"
+        );
+        assert!(
+            output.contains("Debug message to stderr"),
+            "Expected DEBUG message not found"
+        );
+        assert!(
+            output.contains("Trace message to stderr"),
+            "Expected TRACE message not found"
+        );
+    }
+
+    #[test]
+    fn test_update_tracing_respects_rust_log() {
+        init_tracing_for_tests();
+        // Set RUST_LOG before initializing(not possible in this test) or after updating tracing
+        std::env::set_var("RUST_LOG", "info");
+        update_tracing(tracing::Level::DEBUG);
+
+        let output = capture_stderr(|| {
+            tracing::info!("Info message to stderr");
+            tracing::debug!("Debug message to stderr");
+        });
+
+        assert!(
+            output.contains("Info message to stderr"),
+            "Expected INFO message not found"
+        );
+        assert!(
+            !output.contains("Debug message to stderr"),
+            "Expected DEBUG message found"
+        );
+    }
+}

lib/src/cli.rs

@@ -1,19 +1,54 @@
 //! Helpers related to tracing, used by main entrypoints
 
+use std::sync::{Arc, OnceLock};
+use tracing::Level;
+use tracing_subscriber::{
+    filter::LevelFilter, fmt, layer::SubscriberExt, reload, EnvFilter, Registry,
+};
+
+/// Global reload handle for dynamically updating log levels
+static TRACING_RELOAD_HANDLE: OnceLock<Arc<reload::Handle<EnvFilter, Registry>>> = OnceLock::new();
+
 /// Initialize tracing with the default configuration.
 pub fn initialize_tracing() {
+    // Create a reloadable EnvFilter: Use `RUST_LOG` if available, otherwise default to WARN
+    let env_filter = EnvFilter::try_from_default_env()
+        .unwrap_or_else(|_| EnvFilter::new(LevelFilter::WARN.to_string()));
+    let (filter, reload_handle) = reload::Layer::new(env_filter);
+
     // Don't include timestamps and such because they're not really useful and
     // too verbose, and plus several log targets such as journald will already
     // include timestamps.
     let format = tracing_subscriber::fmt::format()
         .without_time()
         .with_target(false)
         .compact();
+
+    // Create a subscriber with a reloadable filter and formatted output
     // Log to stderr by default
-    tracing_subscriber::fmt()
-        .event_format(format)
-        .with_writer(std::io::stderr)
-        .with_max_level(tracing::Level::WARN)
-        .with_env_filter(tracing_subscriber::EnvFilter::from_default_env())
-        .init();
+    let subscriber = Registry::default().with(filter).with(
+        fmt::layer()
+            .event_format(format)
+            .with_writer(std::io::stderr),
+    );
+
+    // Set the subscriber globally
+    tracing::subscriber::set_global_default(subscriber).expect("Failed to set tracing subscriber");
+
+    // Store the reload handle in a global OnceLock
+    TRACING_RELOAD_HANDLE.set(Arc::new(reload_handle)).ok();
+}
+
+/// Update tracing log level dynamically.
+pub fn update_tracing(log_level: Level) {
+    if let Some(handle) = TRACING_RELOAD_HANDLE.get() {
+        // Create new filter. Use `RUST_LOG` if available
+        let new_filter = EnvFilter::try_from_default_env()
+            .unwrap_or_else(|_| EnvFilter::new(log_level.to_string()));
+        if let Err(e) = handle.modify(|filter| *filter = new_filter) {
+            eprintln!("Failed to update log level: {}", e);
+        }
+    } else {
+        eprintln!("Logging system not initialized yet.");
+    }
 }