lib: Add --verbose flag to the CLI for providing a debug output option by mabulgu · Pull Request #1154 · bootc-dev/bootc

mabulgu · 2025-02-27T22:23:58Z

Description

This PR adds a --verbose flag with the short forms -v, -vv, -vvv.. to increase the logging verbosity as requested in #475.

With this PR, the current command structure looks as follows:

The verbose flag is matched to different levels of tracing levels from WARN to TRACE:

// lib/src/cli.rs:1058

// 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
};

So any user can change the tracing level at runtime by adding the flag and changing its count. In the following bootc switch example, -vvv is used for TRACING and sub level logs:

Users still can use RUST_LOG as they used to. Usage of RUST_LOG overrides the --verbose flag if used. So even if you run your command with a -vv level, if you set your RUST_LOG as info, you will only see the INFO and WARN logs, not the DEBUG ones. This case is provided with a unit test here.

Test Results

Unit tests (tracing only is shown here):

running 3 tests
test cli::tracing_tests::test_default_tracing ... ok
test cli::tracing_tests::test_update_tracing_respects_rust_log ... ok
test cli::tracing_tests::test_update_tracing ... ok

test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 64 filtered out; finished in 0.00s

Container tests:

➜  bootc git:(issue/475) podman run --rm -ti localhost/bootc bootc-integration-tests container

running 3 tests
test status         ... ok
test install config ... ok
test bootc upgrade  ... ok

test result: ok. 3 passed; 0 failed; 0 ignored; 0 measured; 0 filtered out; finished in 0.09s

Closes: #475

mabulgu · 2025-02-28T14:14:15Z

I am checking the failure messages

cgwalters

Thank you so much for working on this!!

cgwalters · 2025-03-01T18:30:25Z

utils/src/tracing_util.rs

+            eprintln!("Failed to update log level: {}", e);
+        }
+    } else {
+        eprintln!("Logging system not initialized yet.");


I think this should probably be fatal?

Good catch again! How about now?

I will also add a unit test for it.

cgwalters · 2025-03-01T18:32:08Z

lib/src/cli.rs

+    #![allow(unsafe_code)]
+
+    use bootc_utils::{initialize_tracing, update_tracing_log_level};
+    use nix::unistd::{close, dup, dup2, pipe};


I know we already have nix in our dependency graph, but I personally prefer rustix and it's much more widely used in this codebase.

I don't have a personal preference TBH. Let me check Rustix and implement it instead.

cgwalters · 2025-03-01T18:32:54Z

lib/src/cli.rs

+
+        // 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.


And specifically note that rustix's pipe API is already returning OwnedFd https://docs.rs/rustix/latest/rustix/pipe/fn.pipe.html which handles this.

cgwalters · 2025-03-01T18:37:29Z

lib/src/cli.rs

+    /// Helper function to initialize tracing for tests
+    fn init_tracing_for_tests() {
+        INIT.call_once(|| {
+            std::env::remove_var("RUST_LOG");


In 2024 edition this is going to be fully unsafe, see https://doc.rust-lang.org/edition-guide/rust-2024/newly-unsafe-functions.html#stdenvset_var-remove_var

And yeah...even though we're running this under a mutex, cargo is still going to run other tests in threads and so it is just unsafe.

Actually this comment relates to this whole topic - first, thank you for going to the effort of writing tests for the tracing code! (I honestly might have taken a patch without it with just some manual testing)

But I think to test this correctly we're going to need to fork off a helper process.

That said...there is also https://nexte.st/ and see specifically https://nexte.st/docs/design/why-process-per-test/ - we could investigate setting that up here and using it in CI, but skipping these tests when run directly via cargo test perhaps?

Got your point. How about this new proposal:

1- Remove the test_update_tracing_respects_rust_log as it is related to environment setting and cleanup. So that we wont hit the future unsafe issues.
2- Keep the other test functions here as keeping extra tests at unit level wont hurt.
3- Implement similar scenarios and more with the ENV ones at the place where you suggested. BUt I need to look at this first. I don't know much about https://nexte.st yet:) Let me figure it out how to run etc. I am familiar with GH actions.

.gitignore

cgwalters · 2025-03-01T18:42:16Z

lib/src/cli.rs

+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


I think this is probably OK as is, but...some bits of code here log quite a bit at debug level (especially when fetching containers). I wonder if we should also have a --log-level argument that is just the same as setting the RUST_LOG env var? Because then it's easier to do e.g. --log-level=bootc=debug which avoids debug logging from tokio or containers-image-proxy-rs say.

Makes a lot sense. We actually have a log level here but I think you want it to be configurable per component. -v is common amongst system-wise CLIs but I need to check how a flag like --log-level is used around. Depending on my research I might propose doing this in another PR, for the sake of separation of concerns:)

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

…m in the current scope Signed-off-by: mabulgu <[email protected]>

…hanges the log level Signed-off-by: mabulgu <[email protected]>

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

Also removed the test case for RUST_LOG as we will cover it via a highler level test Signed-off-by: mabulgu <[email protected]>

mabulgu · 2025-04-11T13:57:07Z

I will get back to this PR soon.

mabulgu changed the title ~~lib: Add --verbose flag to the CLI for providing a debug option~~ lib: Add --verbose flag to the CLI for providing a debug output option Feb 27, 2025

mabulgu force-pushed the issue/475 branch from 06d9343 to f7e98b2 Compare February 27, 2025 22:41

github-actions bot added the documentation label Feb 28, 2025

mabulgu force-pushed the issue/475 branch from 43a9410 to 5f4c219 Compare February 28, 2025 23:21

cgwalters requested changes Mar 1, 2025

View reviewed changes

mabulgu force-pushed the issue/475 branch 2 times, most recently from f693a14 to a3cfdf7 Compare March 7, 2025 11:24

mabulgu added 7 commits March 7, 2025 14:25

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

918d2f9

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

Fix docgen problem: no variant or associated item named found for enu…

d3f411d

…m in the current scope Signed-off-by: mabulgu <[email protected]>

Ensure the tracing tests run in an order | Rename the function that c…

f874139

…hanges the log level Signed-off-by: mabulgu <[email protected]>

Add new --verbose option to the docs

91108c0

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

add trailing new line

3c22305

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

Return fatal error when no tracing is initialized before the update

03dfd04

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

Create a test util for the cli tests for helping initializing tracing

7ce081c

Also removed the test case for RUST_LOG as we will cover it via a highler level test Signed-off-by: mabulgu <[email protected]>

mabulgu force-pushed the issue/475 branch from a3cfdf7 to 7ce081c Compare March 7, 2025 11:25

cgwalters mentioned this pull request Apr 16, 2025

Improve error reporting by printing error chain sources #1277

Closed

cgwalters marked this pull request as draft July 17, 2025 22:13

cgwalters removed the documentation label Sep 26, 2025

Conversation

mabulgu commented Feb 27, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Description

Test Results

Uh oh!

mabulgu commented Feb 28, 2025

Uh oh!

cgwalters left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

mabulgu Mar 7, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

mabulgu commented Apr 11, 2025

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

mabulgu commented Feb 27, 2025 •

edited

Loading

mabulgu Mar 7, 2025 •

edited

Loading