diff --git a/crates/puffin-cli/src/commands/clean.rs b/crates/puffin-cli/src/commands/clean.rs index d25be4b4e..5cd4d2268 100644 --- a/crates/puffin-cli/src/commands/clean.rs +++ b/crates/puffin-cli/src/commands/clean.rs @@ -12,10 +12,11 @@ pub(crate) async fn clean(cache: Option<&Path>) -> Result { }; if !cache.exists() { + info!("No cache found at: {}", cache.display()); return Ok(ExitStatus::Success); } - info!("Clearing cache at {}", cache.display()); + info!("Clearing cache at: {}", cache.display()); for entry in cache .read_dir() diff --git a/crates/puffin-cli/src/commands/compile.rs b/crates/puffin-cli/src/commands/compile.rs index 2bb689e10..44cc3eed5 100644 --- a/crates/puffin-cli/src/commands/compile.rs +++ b/crates/puffin-cli/src/commands/compile.rs @@ -2,7 +2,7 @@ use std::path::Path; use std::str::FromStr; use anyhow::Result; -use tracing::debug; +use tracing::{debug, info}; use platform_host::Platform; use platform_tags::Tags; @@ -10,16 +10,23 @@ use puffin_client::PypiClientBuilder; use puffin_interpreter::PythonExecutable; use puffin_package::requirements::Requirements; -use crate::commands::ExitStatus; +use crate::commands::{elapsed, ExitStatus}; /// Resolve a set of requirements into a set of pinned versions. pub(crate) async fn compile(src: &Path, cache: Option<&Path>) -> Result { + let start = std::time::Instant::now(); + // Read the `requirements.txt` from disk. let requirements_txt = std::fs::read_to_string(src)?; // Parse the `requirements.txt` into a list of requirements. let requirements = Requirements::from_str(&requirements_txt)?; + if requirements.is_empty() { + info!("No requirements found"); + return Ok(ExitStatus::Success); + } + // Detect the current Python interpreter. let platform = Platform::current()?; let python = PythonExecutable::from_env(platform, cache)?; @@ -53,6 +60,14 @@ pub(crate) async fn compile(src: &Path, cache: Option<&Path>) -> Result for ExitCode { } } } + +/// Format a duration as a human-readable string, Cargo-style. +pub(super) fn elapsed(duration: Duration) -> String { + let secs = duration.as_secs(); + + if secs >= 60 { + format!("{}m {:02}s", secs / 60, secs % 60) + } else if secs > 0 { + format!("{}.{:02}s", secs, duration.subsec_nanos() / 10_000_000) + } else { + format!("{}ms", duration.subsec_millis()) + } +} diff --git a/crates/puffin-cli/src/commands/sync.rs b/crates/puffin-cli/src/commands/sync.rs index b914a79ff..f2bbaa290 100644 --- a/crates/puffin-cli/src/commands/sync.rs +++ b/crates/puffin-cli/src/commands/sync.rs @@ -3,7 +3,7 @@ use std::str::FromStr; use anyhow::Result; use bitflags::bitflags; -use tracing::debug; +use tracing::{debug, info}; use platform_host::Platform; use platform_tags::Tags; @@ -12,7 +12,7 @@ use puffin_interpreter::{PythonExecutable, SitePackages}; use puffin_package::package_name::PackageName; use puffin_package::requirements::Requirements; -use crate::commands::ExitStatus; +use crate::commands::{elapsed, ExitStatus}; bitflags! { #[derive(Debug, Copy, Clone, Default)] @@ -24,14 +24,16 @@ bitflags! { /// Install a set of locked requirements into the current Python environment. pub(crate) async fn sync(src: &Path, cache: Option<&Path>, flags: SyncFlags) -> Result { + let start = std::time::Instant::now(); + // Read the `requirements.txt` from disk. let requirements_txt = std::fs::read_to_string(src)?; // Parse the `requirements.txt` into a list of requirements. let requirements = Requirements::from_str(&requirements_txt)?; + let initial_requirements = requirements.len(); // Detect the current Python interpreter. - // TODO(charlie): This is taking a _lot_ of time, like 20ms. let platform = Platform::current()?; let python = PythonExecutable::from_env(platform, cache)?; debug!( @@ -49,7 +51,7 @@ pub(crate) async fn sync(src: &Path, cache: Option<&Path>, flags: SyncFlags) -> if let Some(version) = site_packages.get(&package) { #[allow(clippy::print_stdout)] { - println!("Requirement already satisfied: {package} ({version})"); + info!("Requirement already satisfied: {package} ({version})"); } false } else { @@ -59,6 +61,13 @@ pub(crate) async fn sync(src: &Path, cache: Option<&Path>, flags: SyncFlags) -> }; if requirements.is_empty() { + let s = if initial_requirements == 1 { "" } else { "s" }; + info!( + "Audited {} package{} in {}", + initial_requirements, + s, + elapsed(start.elapsed()) + ); return Ok(ExitStatus::Success); } @@ -91,10 +100,13 @@ pub(crate) async fn sync(src: &Path, cache: Option<&Path>, flags: SyncFlags) -> let wheels = resolution.into_files().collect::>(); puffin_installer::install(&wheels, &python, &client, cache).await?; - #[allow(clippy::print_stdout)] - { - println!("Installed {} wheels", wheels.len()); - } + let s = if requirements.len() == 1 { "" } else { "s" }; + info!( + "Installed {} package{} in {}", + requirements.len(), + s, + elapsed(start.elapsed()) + ); Ok(ExitStatus::Success) } diff --git a/crates/puffin-cli/src/logging.rs b/crates/puffin-cli/src/logging.rs index 2449b0400..19916615f 100644 --- a/crates/puffin-cli/src/logging.rs +++ b/crates/puffin-cli/src/logging.rs @@ -1,27 +1,79 @@ -use anyhow::Result; use tracing::level_filters::LevelFilter; -use tracing_subscriber::filter::Targets; use tracing_subscriber::layer::SubscriberExt; -use tracing_subscriber::{EnvFilter, Layer, Registry}; +use tracing_subscriber::util::SubscriberInitExt; +use tracing_subscriber::EnvFilter; use tracing_tree::time::Uptime; +use tracing_tree::HierarchicalLayer; -pub(crate) fn setup_logging() -> Result<()> { - let targets = Targets::new() - .with_target("hyper", LevelFilter::WARN) - .with_target("reqwest", LevelFilter::WARN) - .with_target("tokio", LevelFilter::WARN) - .with_target("blocking", LevelFilter::OFF) - .with_default(LevelFilter::TRACE); - - let subscriber = Registry::default().with( - tracing_tree::HierarchicalLayer::default() - .with_targets(true) - .with_writer(|| Box::new(std::io::stderr())) - .with_timer(Uptime::default()) - .with_filter(EnvFilter::from_default_env()) - .with_filter(targets), - ); - tracing::subscriber::set_global_default(subscriber)?; - - Ok(()) +#[derive(Debug, Default, Clone, Copy, PartialEq, Eq)] +pub(crate) enum Level { + /// Show deliberately user-facing messages and errors. + #[default] + Default, + /// Suppress all user-facing output. + Quiet, + /// Show all messages, including debug messages. + Verbose, +} + +/// Configure `tracing` based on the given [`Level`], taking into account the `RUST_LOG` environment +/// variable. +/// +/// 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, while [`Level::Default`] excludes both. +pub(crate) fn setup_logging(level: Level) { + match level { + Level::Default => { + // Show `INFO` messages from the CLI crate, but allow `RUST_LOG` to override. + let filter = EnvFilter::try_from_default_env() + .or_else(|_| EnvFilter::try_new("puffin=info")) + .unwrap(); + + // Regardless of the tracing level, show messages without any adornment. + tracing_subscriber::registry() + .with(filter) + .with( + tracing_subscriber::fmt::layer() + .without_time() + .with_target(false) + .with_writer(std::io::stderr), + ) + .init(); + } + Level::Quiet => { + // Show nothing, but allow `RUST_LOG` to override. + let filter = EnvFilter::builder() + .with_default_directive(LevelFilter::OFF.into()) + .from_env_lossy(); + + // Regardless of the tracing level, show messages without any adornment. + tracing_subscriber::registry() + .with(filter) + .with( + tracing_subscriber::fmt::layer() + .without_time() + .with_target(false) + .with_writer(std::io::sink), + ) + .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("puffin=debug")) + .unwrap(); + + // Regardless of the tracing level, include the uptime and target for each message. + tracing_subscriber::registry() + .with(filter) + .with( + HierarchicalLayer::default() + .with_targets(true) + .with_timer(Uptime::default()) + .with_writer(std::io::stderr), + ) + .init(); + } + } } diff --git a/crates/puffin-cli/src/main.rs b/crates/puffin-cli/src/main.rs index 52ccbb8e0..222d9ce86 100644 --- a/crates/puffin-cli/src/main.rs +++ b/crates/puffin-cli/src/main.rs @@ -16,6 +16,14 @@ mod logging; struct Cli { #[command(subcommand)] command: Commands, + + /// Do not print any output. + #[arg(global = true, long, short, conflicts_with = "verbose")] + quiet: bool, + + /// Use verbose output. + #[arg(global = true, long, short, conflicts_with = "quiet")] + verbose: bool, } #[derive(Subcommand)] @@ -65,7 +73,13 @@ struct FreezeArgs { async fn main() -> ExitCode { let cli = Cli::parse(); - let _ = logging::setup_logging(); + logging::setup_logging(if cli.quiet { + logging::Level::Quiet + } else if cli.verbose { + logging::Level::Verbose + } else { + logging::Level::Default + }); let dirs = ProjectDirs::from("", "", "puffin"); diff --git a/crates/puffin-installer/src/lib.rs b/crates/puffin-installer/src/lib.rs index 12cd6c8d6..f3eba166b 100644 --- a/crates/puffin-installer/src/lib.rs +++ b/crates/puffin-installer/src/lib.rs @@ -7,7 +7,7 @@ use rayon::iter::ParallelBridge; use rayon::iter::ParallelIterator; use tokio::task::JoinSet; use tokio_util::compat::FuturesAsyncReadCompatExt; -use tracing::debug; +use tracing::{debug, info}; use url::Url; use zip::ZipArchive; @@ -35,6 +35,10 @@ pub async fn install( tokio::fs::create_dir_all(cache.join(WHEEL_CACHE)).await?; } + if wheels.is_empty() { + return Ok(()); + } + // Phase 1: Fetch the wheels in parallel. debug!("Phase 1: Fetching wheels"); let mut fetches = JoinSet::new(); @@ -44,12 +48,12 @@ pub async fn install( let key = cache_key(wheel)?; if let Some(cache) = cache { if cache.join(WHEEL_CACHE).join(&key).exists() { - debug!("Found wheel in cache: {:?}", wheel.filename); + debug!("Found wheel in cache: {}", wheel.filename); continue; } } - debug!("Fetching wheel: {:?}", wheel.filename); + debug!("Downloading: {}", wheel.filename); fetches.spawn(fetch_wheel( wheel.clone(), @@ -57,6 +61,12 @@ pub async fn install( cache.map(Path::to_path_buf), )); } + + if !fetches.is_empty() { + let s = if fetches.len() == 1 { "" } else { "s" }; + info!("Downloading {} wheel{}", fetches.len(), s); + } + while let Some(result) = fetches.join_next().await.transpose()? { downloads.push(result?); } @@ -69,7 +79,7 @@ pub async fn install( let filename = wheel.file.filename.clone(); let key = cache_key(&wheel.file)?; - debug!("Unpacking wheel: {:?}", filename); + debug!("Unpacking: {}", filename); // Unzip the wheel. tokio::task::spawn_blocking({ @@ -80,7 +90,7 @@ pub async fn install( // Write the unzipped wheel to the cache (atomically). if let Some(cache) = cache { - debug!("Caching wheel: {:?}", filename); + debug!("Caching wheel: {}", filename); tokio::fs::rename( temp_dir.path().join(&key), cache.join(WHEEL_CACHE).join(&key), @@ -89,6 +99,17 @@ pub async fn install( } } + let s = if wheels.len() == 1 { "" } else { "s" }; + info!( + "Linking package{}: {}", + s, + wheels + .iter() + .map(cache_key) + .collect::>>()? + .join(" ") + ); + // Phase 3: Install each wheel. debug!("Phase 3: Installing wheels"); let location = InstallLocation::Venv { diff --git a/crates/puffin-resolver/src/lib.rs b/crates/puffin-resolver/src/lib.rs index c7c2dbd1c..a1e551241 100644 --- a/crates/puffin-resolver/src/lib.rs +++ b/crates/puffin-resolver/src/lib.rs @@ -6,7 +6,7 @@ use bitflags::bitflags; use futures::future::Either; use futures::{StreamExt, TryFutureExt}; use thiserror::Error; -use tracing::debug; +use tracing::{debug, info}; use pep440_rs::Version; use pep508_rs::{MarkerEnvironment, Requirement, VersionOrUrl}; @@ -30,6 +30,16 @@ impl Resolution { pub fn into_files(self) -> impl Iterator { self.0.into_values().map(|package| package.file) } + + /// Return the number of pinned packages in this resolution. + pub fn len(&self) -> usize { + self.0.len() + } + + /// Return `true` if there are no pinned packages in this resolution. + pub fn is_empty(&self) -> bool { + self.0.is_empty() + } } #[derive(Debug)] @@ -158,6 +168,11 @@ pub async fn resolve( metadata.version, requirement ); + info!( + "Selecting: {}=={} ({})", + metadata.name, metadata.version, file.filename + ); + // Add to the resolved set. let normalized_name = PackageName::normalize(&requirement.name); in_flight.remove(&normalized_name); diff --git a/requirements.txt b/requirements.txt index e62f440f0..03eabff4e 100644 --- a/requirements.txt +++ b/requirements.txt @@ -2,7 +2,7 @@ # This file is autogenerated by pip-compile with Python 3.11 # by the following command: # -# pip-compile --pip-args='--no-cache-dir' requirements.in +# pip-compile requirements.in # attrs==23.1.0 # via