Add support for CARGO_BAZEL_DEBUG=TRACE level logging (#3238)

Some of the logging was insanely verbose, so I've opted to add it to
`Level::TRACE`. This level can be enabled by setting the environment
variable `CARGO_BAZEL_DEBUG=TRACE`.

crate_universe/src/cli.rs

@@ -7,13 +7,15 @@ mod splice;
 mod vendor;
 
 use clap::Parser;
-use tracing::{Level, Subscriber};
+use tracing::Subscriber;
 use tracing_subscriber::fmt::format::{Format, Full};
 use tracing_subscriber::fmt::time::SystemTime;
 use tracing_subscriber::fmt::{FormatEvent, FormatFields};
 use tracing_subscriber::registry::LookupSpan;
 use tracing_subscriber::FmtSubscriber;
 
+pub use tracing::Level as LogLevel;
+
 pub use self::generate::GenerateOptions;
 pub use self::query::QueryOptions;
 pub use self::render::RenderOptions;
@@ -92,21 +94,17 @@ impl LoggingFormatEvent {
 }
 
 /// Initialize logging for one of the cli options.
-pub fn init_logging(name: &str, verbose: bool) {
+pub fn init_logging(name: &str, level: LogLevel) {
     if !EXPECTED_LOGGER_NAMES.contains(&name) {
         panic!(
             "Unexpected logger name {}, use of one of {:?}",
             name, EXPECTED_LOGGER_NAMES
         );
     }
 
-    // a builder for `FmtSubscriber`.
     let subscriber = FmtSubscriber::builder()
-        // all spans/events with a level higher than TRACE (e.g, debug, info, warn, etc.)
-        // will be written to stdout.
-        .with_max_level(if verbose { Level::DEBUG } else { Level::INFO })
+        .with_max_level(level)
         .event_format(LoggingFormatEvent::new(name))
-        // completes the builder.
         .finish();
 
     tracing::subscriber::set_global_default(subscriber).expect("setting default subscriber failed");

crate_universe/src/main.rs

@@ -6,27 +6,36 @@ fn main() -> cli::Result<()> {
     // Parse arguments
     let opt = cli::parse_args();
 
-    let verbose_logging = std::env::var("CARGO_BAZEL_DEBUG").is_ok();
+    let level = match std::env::var("CARGO_BAZEL_DEBUG") {
+        Ok(var) => {
+            if var == "TRACE" {
+                crate::cli::LogLevel::TRACE
+            } else {
+                crate::cli::LogLevel::DEBUG
+            }
+        }
+        Err(_) => crate::cli::LogLevel::INFO,
+    };
 
     match opt {
         cli::Options::Generate(opt) => {
-            cli::init_logging("Generate", verbose_logging);
+            cli::init_logging("Generate", level);
             cli::generate(opt)
         }
         cli::Options::Splice(opt) => {
-            cli::init_logging("Splice", verbose_logging);
+            cli::init_logging("Splice", level);
             cli::splice(opt)
         }
         cli::Options::Query(opt) => {
-            cli::init_logging("Query", verbose_logging);
+            cli::init_logging("Query", level);
             cli::query(opt)
         }
         cli::Options::Vendor(opt) => {
-            cli::init_logging("Vendor", verbose_logging);
+            cli::init_logging("Vendor", level);
             cli::vendor(opt)
         }
         cli::Options::Render(opt) => {
-            cli::init_logging("Render", verbose_logging);
+            cli::init_logging("Render", level);
             cli::render(opt)
         }
     }

crate_universe/src/metadata/cargo_tree_resolver.rs

@@ -9,7 +9,7 @@ use anyhow::{anyhow, bail, Context, Result};
 use camino::Utf8Path;
 use semver::Version;
 use serde::{Deserialize, Serialize};
-use tracing::debug;
+use tracing::{debug, trace};
 use url::Url;
 
 use crate::config::CrateId;
@@ -137,6 +137,12 @@ impl TreeResolver {
             // number of processes (which can be +400 and hit operating system limitations).
             let mut target_triple_to_child = BTreeMap::<String, Child>::new();
 
+            debug!(
+                "Spawning `cargo tree` processes for host `{}`: {}",
+                host_triple,
+                cargo_target_triples.keys().len(),
+            );
+
             for target_triple in cargo_target_triples.keys() {
                 // We use `cargo tree` here because `cargo metadata` doesn't report
                 // back target-specific features (enabled with `resolver = "2"`).
@@ -178,12 +184,6 @@ impl TreeResolver {
                 target_triple_to_child.insert(target_triple.clone(), child);
             }
 
-            debug!(
-                "Spawned `cargo tree` processes for host `{}`: {}",
-                host_triple,
-                target_triple_to_child.len(),
-            );
-
             for (target_triple, child) in target_triple_to_child.into_iter() {
                 let output = child.wait_with_output().with_context(|| {
                     format!(
@@ -194,11 +194,13 @@ impl TreeResolver {
                     )
                 })?;
                 if !output.status.success() {
-                    eprintln!("{}", String::from_utf8_lossy(&output.stdout));
-                    eprintln!("{}", String::from_utf8_lossy(&output.stderr));
+                    tracing::error!("{}", String::from_utf8_lossy(&output.stdout));
+                    tracing::error!("{}", String::from_utf8_lossy(&output.stderr));
                     bail!(format!("Failed to run cargo tree: {}", output.status))
                 }
 
+                tracing::trace!("`cargo tree --target={}` completed.", target_triple);
+
                 // Replicate outputs for any de-duplicated platforms
                 for host_plat in cargo_host_triples[host_triple].iter() {
                     for target_plat in cargo_target_triples[&target_triple].iter() {
@@ -348,7 +350,7 @@ impl TreeResolver {
 
         for (host_triple, target_streams) in deps_tree_streams.into_iter() {
             for (target_triple, stdout) in target_streams.into_iter() {
-                debug!(
+                trace!(
                     "Parsing (host={}) `cargo tree --target {}` output:\n```\n{}\n```",
                     host_triple,
                     target_triple,