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

[mabulgu]

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]

I am checking the failure messages

[cgwalters]

Thank you so much for working on this!!

[cgwalters]

I think this should probably be fatal?

[mabulgu]

Good catch again! How about now?

[mabulgu]

I will also add a unit test for it.

[cgwalters]

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.

[mabulgu]

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

[cgwalters]

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]

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?

[mabulgu]

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.

[cgwalters]

minor nit: let's add a trailing newline here

[mabulgu]

Good catch! Done.

[cgwalters]

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.

[mabulgu]

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:)