Add a -vv log level and make -v more readable

Cargo.toml

@@ -103,7 +103,7 @@ toml = { version = "0.8.8" }
 tracing = { version = "0.1.40" }
 tracing-durations-export = { version = "0.2.0", features = ["plot"] }
 tracing-indicatif = { version = "0.3.6" }
-tracing-subscriber = { version = "0.3.18", features = ["env-filter"] }
+tracing-subscriber = { version = "0.3.18", features = ["env-filter", "json"] }
 tracing-tree = { version = "0.3.0" }
 unicode-width = { version = "0.1.11" }
 unscanny = { version = "0.1.0" }

crates/uv-interpreter/src/interpreter.rs

@@ -16,7 +16,7 @@ use platform_host::Platform;
 use platform_tags::{Tags, TagsError};
 use pypi_types::Scheme;
 use uv_cache::{Cache, CacheBucket, CachedByTimestamp, Freshness, Timestamp};
-use uv_fs::write_atomic_sync;
+use uv_fs::{write_atomic_sync, Simplified};
 
 use crate::Error;
 use crate::Virtualenv;
@@ -453,20 +453,20 @@ impl InterpreterInfo {
                             debug!(
                                 "Cached interpreter info for Python {}, skipping probing: {}",
                                 cached.data.markers.python_full_version,
-                                executable.display()
+                                executable.simplified_display()
                             );
                             return Ok(cached.data);
                         }
 
                         debug!(
                             "Ignoring stale cached markers for: {}",
-                            executable.display()
+                            executable.simplified_display()
                         );
                     }
                     Err(err) => {
                         warn!(
                             "Broken cache entry at {}, removing: {err}",
-                            cache_entry.path().display()
+                            cache_entry.path().simplified_display()
                         );
                         let _ = fs_err::remove_file(cache_entry.path());
                     }

crates/uv-resolver/src/resolver/mod.rs

@@ -809,11 +809,11 @@ impl<'a, Provider: ResolverProvider> Resolver<'a, Provider> {
                         self.markers,
                     )?;
 
-                    for (package, version) in constraints.iter() {
-                        debug!("Adding transitive dependency: {package}{version}");
+                    for (dep_package, dep_version) in constraints.iter() {
+                        debug!("Adding transitive dependency for {package}{version}: {dep_package}{dep_version}");
 
                         // Emit a request to fetch the metadata for this package.
-                        self.visit_package(package, priorities, request_sink)
+                        self.visit_package(dep_package, priorities, request_sink)
                             .await?;
                     }
 

crates/uv/Cargo.toml

@@ -67,7 +67,7 @@ tokio = { workspace = true }
 toml = { workspace = true }
 tracing = { workspace = true }
 tracing-durations-export = { workspace = true, features = ["plot"], optional = true }
-tracing-subscriber = { workspace = true }
+tracing-subscriber = { workspace = true, features = ["json"] }
 tracing-tree = { workspace = true }
 unicode-width = { workspace = true }
 url = { workspace = true }

crates/uv/src/logging.rs

@@ -1,9 +1,21 @@
+use anstream::ColorChoice;
+use std::fmt;
+use std::str::FromStr;
+
+use anyhow::Context;
+use chrono::Utc;
+use owo_colors::OwoColorize;
 use tracing::level_filters::LevelFilter;
+use tracing::{Event, Subscriber};
 #[cfg(feature = "tracing-durations-export")]
 use tracing_durations_export::{
     plot::PlotConfig, DurationsLayer, DurationsLayerBuilder, DurationsLayerDropGuard,
 };
+use tracing_subscriber::filter::Directive;
+use tracing_subscriber::fmt::format::Writer;
+use tracing_subscriber::fmt::{FmtContext, FormatEvent, FormatFields};
 use tracing_subscriber::layer::SubscriberExt;
+use tracing_subscriber::registry::LookupSpan;
 use tracing_subscriber::util::SubscriberInitExt;
 use tracing_subscriber::{EnvFilter, Layer, Registry};
 use tracing_tree::time::Uptime;
@@ -16,6 +28,83 @@ pub(crate) enum Level {
     Default,
     /// Show debug messages by default (overridable by `RUST_LOG`).
     Verbose,
+    /// Show messages in a hierarchical span tree. By default, debug messages are shown (overridable by `RUST_LOG`).
+    ExtraVerbose,
+}
+
+struct UvFormat {
+    display_timestamp: bool,
+    display_level: bool,
+    show_spans: bool,
+}
+
+/// See <https://docs.rs/tracing-subscriber/0.3.18/src/tracing_subscriber/fmt/format/mod.rs.html#1026-1156>
+impl<S, N> FormatEvent<S, N> for UvFormat
+where
+    S: Subscriber + for<'a> LookupSpan<'a>,
+    N: for<'a> FormatFields<'a> + 'static,
+{
+    fn format_event(
+        &self,
+        ctx: &FmtContext<'_, S, N>,
+        mut writer: Writer<'_>,
+        event: &Event<'_>,
+    ) -> fmt::Result {
+        let meta = event.metadata();
+        let ansi = writer.has_ansi_escapes();
+
+        if self.display_timestamp {
+            if ansi {
+                write!(writer, "{} ", Utc::now().dimmed())?;
+            } else {
+                write!(writer, "{} ", Utc::now())?;
+            }
+        }
+
+        if self.display_level {
+            let level = meta.level();
+            // Same colors as tracing
+            if ansi {
+                match *level {
+                    tracing::Level::TRACE => write!(writer, "{} ", level.purple())?,
+                    tracing::Level::DEBUG => write!(writer, "{} ", level.blue())?,
+                    tracing::Level::INFO => write!(writer, "{} ", level.green())?,
+                    tracing::Level::WARN => write!(writer, "{} ", level.yellow())?,
+                    tracing::Level::ERROR => write!(writer, "{} ", level.red())?,
+                }
+            } else {
+                write!(writer, "{level} ")?;
+            }
+        }
+
+        if self.show_spans {
+            let span = event.parent();
+            let mut seen = false;
+
+            let span = span
+                .and_then(|id| ctx.span(id))
+                .or_else(|| ctx.lookup_current());
+
+            let scope = span.into_iter().flat_map(|span| span.scope().from_root());
+
+            for span in scope {
+                seen = true;
+                if ansi {
+                    write!(writer, "{}:", span.metadata().name().bold())?;
+                } else {
+                    write!(writer, "{}:", span.metadata().name())?;
+                }
+            }
+
+            if seen {
+                writer.write_char(' ')?;
+            }
+        }
+
+        ctx.field_format().format_fields(writer.by_ref(), event)?;
+
+        writeln!(writer)
+    }
 }
 
 /// Configure `tracing` based on the given [`Level`], taking into account the `RUST_LOG` environment
@@ -24,32 +113,52 @@ pub(crate) enum Level {
 /// The [`Level`] is used to dictate the default filters (which can be overridden by the `RUST_LOG`
 /// environment variable) along with the formatting of the output. For example, [`Level::Verbose`]
 /// includes targets and timestamps, along with all `uv=debug` messages by default.
-pub(crate) fn setup_logging(level: Level, duration: impl Layer<Registry> + Send + Sync) {
-    match level {
+pub(crate) fn setup_logging(
+    level: Level,
+    duration: impl Layer<Registry> + Send + Sync,
+) -> anyhow::Result<()> {
+    let default_directive = match level {
         Level::Default => {
             // Show nothing, but allow `RUST_LOG` to override.
-            let filter = EnvFilter::builder()
-                .with_default_directive(LevelFilter::OFF.into())
-                .from_env_lossy();
+            LevelFilter::OFF.into()
+        }
+        Level::Verbose | Level::ExtraVerbose => {
+            // Show `DEBUG` messages from the CLI crate, but allow `RUST_LOG` to override.
+            Directive::from_str("uv=debug").unwrap()
+        }
+    };
+
+    let filter = EnvFilter::builder()
+        .with_default_directive(default_directive)
+        .from_env()
+        .context("Invalid RUST_LOG directives")?;
 
+    match level {
+        Level::Default | Level::Verbose => {
             // Regardless of the tracing level, show messages without any adornment.
+            let format = UvFormat {
+                display_timestamp: false,
+                display_level: true,
+                show_spans: false,
+            };
+            let ansi = match anstream::Stderr::choice(&std::io::stderr()) {
+                ColorChoice::Always | ColorChoice::AlwaysAnsi => true,
+                ColorChoice::Never => false,
+                // We just asked anstream for a choice, that can't be auto
+                ColorChoice::Auto => unreachable!(),
+            };
             tracing_subscriber::registry()
                 .with(duration)
                 .with(filter)
                 .with(
                     tracing_subscriber::fmt::layer()
-                        .without_time()
-                        .with_target(false)
-                        .with_writer(std::io::sink),
+                        .event_format(format)
+                        .with_writer(std::io::stderr)
+                        .with_ansi(ansi),
                 )
                 .init();
         }
-        Level::Verbose => {
-            // Show `DEBUG` messages from the CLI crate, but allow `RUST_LOG` to override.
-            let filter = EnvFilter::try_from_default_env()
-                .or_else(|_| EnvFilter::try_new("uv=debug"))
-                .unwrap();
-
+        Level::ExtraVerbose => {
             // Regardless of the tracing level, include the uptime and target for each message.
             tracing_subscriber::registry()
                 .with(duration)
@@ -63,6 +172,8 @@ pub(crate) fn setup_logging(level: Level, duration: impl Layer<Registry> + Send
                 .init();
         }
     }
+
+    Ok(())
 }
 
 /// Setup the `TRACING_DURATIONS_FILE` environment variable to enable tracing durations.

crates/uv/src/main.rs

@@ -68,8 +68,11 @@ struct Cli {
     quiet: bool,
 
     /// Use verbose output.
-    #[arg(global = true, long, short, conflicts_with = "quiet")]
-    verbose: bool,
+    ///
+    /// You can configure fine-grained logging using the `RUST_LOG` environment variable.
+    /// (<https://docs.rs/tracing-subscriber/latest/tracing_subscriber/filter/struct.EnvFilter.html#directives>)
+    #[arg(global = true, action = clap::ArgAction::Count, long, short, conflicts_with = "quiet")]
+    verbose: u8,
 
     /// Disable colors; provided for compatibility with `pip`.
     #[arg(global = true, long, hide = true, conflicts_with = "color")]
@@ -1255,18 +1258,18 @@ async fn run() -> Result<ExitStatus> {
     #[cfg(not(feature = "tracing-durations-export"))]
     let duration_layer = None::<tracing_subscriber::layer::Identity>;
     logging::setup_logging(
-        if cli.verbose {
-            logging::Level::Verbose
-        } else {
-            logging::Level::Default
+        match cli.verbose {
+            0 => logging::Level::Default,
+            1 => logging::Level::Verbose,
+            2.. => logging::Level::ExtraVerbose,
         },
         duration_layer,
-    );
+    )?;
 
     // Configure the `Printer`, which controls user-facing output in the CLI.
     let printer = if cli.quiet {
         printer::Printer::Quiet
-    } else if cli.verbose {
+    } else if cli.verbose > 0 {
         printer::Printer::Verbose
     } else {
         printer::Printer::Default