From 8d9be3010ce201ea3bae19c446cd1eb60f7c9570 Mon Sep 17 00:00:00 2001 From: Wolf Vollprecht Date: Fri, 6 Oct 2023 17:35:13 +0200 Subject: [PATCH] feat: use tracing (#195) --- Cargo.lock | 65 +++++++++++++++++++++++++++++++++++++++++ Cargo.toml | 5 +++- src/build.rs | 6 ++-- src/console_utils.rs | 65 +++++++++++++++++++++++++++++++++++++++++ src/index.rs | 4 +-- src/main.rs | 69 +++++++++++++++++++++++++------------------- src/packaging.rs | 4 +-- src/render/solver.rs | 16 +++++----- src/source/mod.rs | 10 +++---- src/test.rs | 4 +-- src/windows/link.rs | 2 +- 11 files changed, 196 insertions(+), 54 deletions(-) create mode 100644 src/console_utils.rs diff --git a/Cargo.lock b/Cargo.lock index 644ac5afc..9caf53693 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -113,6 +113,12 @@ version = "1.0.75" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "a4668cab20f66d8d020e1fbc0ebe47217433c1b6c8f2040faf858554e394ace6" +[[package]] +name = "arrayvec" +version = "0.7.4" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "96d30a06541fbafbc7f82ed10c06164cfbd2c401138f6addd8404629c4b16711" + [[package]] name = "async-broadcast" version = "0.5.1" @@ -475,6 +481,16 @@ dependencies = [ "clap_derive", ] +[[package]] +name = "clap-verbosity-flag" +version = "2.0.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "1eef05769009513df2eb1c3b4613e7fad873a14c600ff025b08f250f59fee7de" +dependencies = [ + "clap", + "log", +] + [[package]] name = "clap_builder" version = "4.4.6" @@ -1382,6 +1398,7 @@ dependencies = [ "number_prefix", "portable-atomic", "unicode-width", + "vt100", ] [[package]] @@ -2275,6 +2292,7 @@ dependencies = [ "anyhow", "chrono", "clap", + "clap-verbosity-flag", "comfy-table", "console", "content_inspector", @@ -2314,6 +2332,8 @@ dependencies = [ "thiserror", "tokio", "tracing", + "tracing-core", + "tracing-indicatif", "tracing-subscriber", "url", "walkdir", @@ -3515,6 +3535,18 @@ dependencies = [ "valuable", ] +[[package]] +name = "tracing-indicatif" +version = "0.3.5" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "57e05fe4a1c906d94b275d8aeb8ff8b9deaca502aeb59ae8ab500a92b8032ac8" +dependencies = [ + "indicatif", + "tracing", + "tracing-core", + "tracing-subscriber", +] + [[package]] name = "tracing-log" version = "0.1.3" @@ -3660,6 +3692,39 @@ version = "0.9.4" source = "registry+https://github.com/rust-lang/crates.io-index" checksum = "49874b5167b65d7193b8aba1567f5c7d93d001cafc34600cee003eda787e483f" +[[package]] +name = "vt100" +version = "0.15.2" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "84cd863bf0db7e392ba3bd04994be3473491b31e66340672af5d11943c6274de" +dependencies = [ + "itoa", + "log", + "unicode-width", + "vte", +] + +[[package]] +name = "vte" +version = "0.11.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "f5022b5fbf9407086c180e9557be968742d839e68346af7792b8592489732197" +dependencies = [ + "arrayvec", + "utf8parse", + "vte_generate_state_changes", +] + +[[package]] +name = "vte_generate_state_changes" +version = "0.1.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "d257817081c7dffcdbab24b9e62d2def62e2ff7d00b1c20062551e6cccc145ff" +dependencies = [ + "proc-macro2", + "quote", +] + [[package]] name = "waker-fn" version = "1.1.1" diff --git a/Cargo.toml b/Cargo.toml index 42f4ec395..299941c35 100644 --- a/Cargo.toml +++ b/Cargo.toml @@ -38,7 +38,7 @@ url = "2.4.1" tracing = "0.1.37" clap = { version = "4.4.6", features = ["derive", "env", "cargo"] } minijinja = { version = "1.0.8", features = ["unstable_machinery"] } -tracing-subscriber = { version = "0.3.17", features = ["env-filter"] } +tracing-subscriber = { version = "0.3.17", features = ["env-filter", "fmt", "ansi"] } num_cpus = "1.16.0" goblin = "0.7.1" scroll = "0.11.0" @@ -56,6 +56,9 @@ git2 = { version = "0.18.1", features = ["vendored-openssl"] } fs_extra = "1.3.0" ignore = "0.4.20" globset = "0.4.13" +tracing-indicatif = "0.3.5" +clap-verbosity-flag = "2.0.1" +tracing-core = "0.1.31" [dev-dependencies] insta = {version = "1.33.0", features = ["yaml"] } diff --git a/src/build.rs b/src/build.rs index 40802b1c2..dd2751ec9 100644 --- a/src/build.rs +++ b/src/build.rs @@ -121,9 +121,9 @@ fn run_process_with_replacements( let filtered_line = replacements .iter() .fold(line, |acc, (from, to)| acc.replace(from, to)); - println!("{}", filtered_line); + tracing::info!("{}", filtered_line); } else { - eprintln!("Error reading output: {:?}", line); + tracing::warn!("Error reading output: {:?}", line); } } } @@ -235,7 +235,7 @@ pub async fn run_build( let test_dir = directories.work_dir.join("test"); fs::create_dir_all(&test_dir)?; - println!("{}", output); + tracing::info!("{}", output); tracing::info!("Running tests"); diff --git a/src/console_utils.rs b/src/console_utils.rs new file mode 100644 index 000000000..c59211509 --- /dev/null +++ b/src/console_utils.rs @@ -0,0 +1,65 @@ +use indicatif::MultiProgress; +use std::io; +use tracing_core::{Event, Subscriber}; +use tracing_subscriber::{ + fmt::{ + format::{self, Format}, + FmtContext, FormatEvent, FormatFields, MakeWriter, + }, + registry::LookupSpan, +}; + +#[derive(Clone)] +pub struct IndicatifWriter { + progress_bars: MultiProgress, +} + +impl IndicatifWriter { + pub(crate) fn new(pb: MultiProgress) -> Self { + Self { progress_bars: pb } + } +} + +impl io::Write for IndicatifWriter { + fn write(&mut self, buf: &[u8]) -> io::Result { + self.progress_bars.suspend(|| io::stderr().write(buf)) + } + + fn flush(&mut self) -> io::Result<()> { + self.progress_bars.suspend(|| io::stderr().flush()) + } +} + +impl<'a> MakeWriter<'a> for IndicatifWriter { + type Writer = IndicatifWriter; + + fn make_writer(&'a self) -> Self::Writer { + self.clone() + } +} + +pub struct TracingFormatter; + +impl FormatEvent for TracingFormatter +where + S: Subscriber + for<'a> LookupSpan<'a>, + N: for<'a> FormatFields<'a> + 'static, +{ + fn format_event( + &self, + ctx: &FmtContext<'_, S, N>, + mut writer: format::Writer<'_>, + event: &Event<'_>, + ) -> std::fmt::Result { + let metadata = event.metadata(); + if *metadata.level() == tracing_core::metadata::Level::INFO + && metadata.target().starts_with("rattler_build") + { + ctx.format_fields(writer.by_ref(), event)?; + writeln!(writer) + } else { + let default_format = Format::default(); + default_format.format_event(ctx, writer, event) + } + } +} diff --git a/src/index.rs b/src/index.rs index a211b8130..69d2aea40 100644 --- a/src/index.rs +++ b/src/index.rs @@ -171,7 +171,7 @@ pub fn index( .packages .insert(p.file_name().unwrap().to_string_lossy().into(), record); } else { - println!("Could not read package record from {:?}", p); + tracing::info!("Could not read package record from {:?}", p); } } ArchiveType::Conda => { @@ -180,7 +180,7 @@ pub fn index( .conda_packages .insert(p.file_name().unwrap().to_string_lossy().to_string(), record); } else { - println!("Could not read package record from {:?}", p); + tracing::info!("Could not read package record from {:?}", p); } } }; diff --git a/src/main.rs b/src/main.rs index 185f88fc4..6315f7599 100644 --- a/src/main.rs +++ b/src/main.rs @@ -3,6 +3,7 @@ use anyhow::Ok; use clap::{arg, crate_version, Parser}; +use clap_verbosity_flag::{InfoLevel, Verbosity}; use indicatif::MultiProgress; use rattler_conda_types::{package::ArchiveType, NoArchType, Platform}; use rattler_networking::AuthenticatedClient; @@ -17,10 +18,10 @@ use std::{ str::{self, FromStr}, }; use test::TestConfiguration; -use tracing::metadata::LevelFilter; -use tracing_subscriber::{prelude::*, EnvFilter}; +use tracing_subscriber::{filter::Directive, fmt, prelude::*, EnvFilter}; mod build; +mod console_utils; mod env_vars; mod hash; mod index; @@ -42,6 +43,7 @@ use build::run_build; mod test; use crate::{ + console_utils::{IndicatifWriter, TracingFormatter}, metadata::{BuildConfiguration, Directories, PackageIdentifier}, render::recipe::render_recipe, variant_config::VariantConfig, @@ -69,8 +71,8 @@ struct App { #[clap(subcommand)] subcommand: SubCommands, - #[clap(short, long, global(true))] - verbose: bool, + #[command(flatten)] + verbose: Verbosity, } #[derive(clap::ValueEnum, Clone)] @@ -127,30 +129,22 @@ struct TestOpts { async fn main() -> ExitCode { let args = App::parse(); - let default_filter = if args.verbose { - LevelFilter::DEBUG - } else { - LevelFilter::WARN - }; - - let env_filter = EnvFilter::builder() - .with_default_directive(default_filter.into()) - .from_env() - .expect("Could not parse RUST_LOG environment variable") - .add_directive("apple_codesign=off".parse().unwrap()); + let multi_progress = MultiProgress::new(); - tracing_subscriber::fmt() - .with_env_filter(env_filter) - .with_writer(std::io::stderr) - .without_time() - .finish() - .try_init() - .unwrap(); + // Setup tracing subscriber + tracing_subscriber::registry() + .with(get_default_env_filter(args.verbose.log_level_filter())) + .with( + fmt::layer() + .with_writer(IndicatifWriter::new(multi_progress.clone())) + .event_format(TracingFormatter), + ) + .init(); tracing::info!("Starting the build process"); let result = match args.subcommand { - SubCommands::Build(args) => run_build_from_args(args).await, + SubCommands::Build(args) => run_build_from_args(args, multi_progress).await, SubCommands::Test(args) => run_test_from_args(args).await, }; @@ -175,7 +169,7 @@ async fn run_test_from_args(args: TestOpts) -> anyhow::Result<()> { Ok(()) } -async fn run_build_from_args(args: BuildOpts) -> anyhow::Result<()> { +async fn run_build_from_args(args: BuildOpts, multi_progress: MultiProgress) -> anyhow::Result<()> { let recipe_path = fs::canonicalize(&args.recipe); if let Err(e) = &recipe_path { match e.kind() { @@ -249,7 +243,7 @@ async fn run_build_from_args(args: BuildOpts) -> anyhow::Result<()> { .find_variants(&recipe_text, &selector_config) .expect("Could not compute variants"); - println!("Found variants:"); + tracing::info!("Found variants:"); for variant in &variants { let mut table = comfy_table::Table::new(); table @@ -259,12 +253,12 @@ async fn run_build_from_args(args: BuildOpts) -> anyhow::Result<()> { for (key, value) in variant.iter() { table.add_row(vec![key, value]); } - println!("{}\n", table); + tracing::info!("{}\n", table); } let tool_config = tool_configuration::Configuration { client: AuthenticatedClient::default(), - multi_progress_indicator: MultiProgress::new(), + multi_progress_indicator: multi_progress, }; for variant in variants { @@ -298,9 +292,9 @@ async fn run_build_from_args(args: BuildOpts) -> anyhow::Result<()> { }; if args.render_only { - println!("{}", serde_yaml::to_string(&recipe).unwrap()); - println!("Variant: {:#?}", variant); - println!("Hash: {}", recipe.build.string.unwrap()); + tracing::info!("{}", serde_yaml::to_string(&recipe).unwrap()); + tracing::info!("Variant: {:#?}", variant); + tracing::info!("Hash: {}", recipe.build.string.unwrap()); continue; } @@ -355,3 +349,18 @@ async fn run_build_from_args(args: BuildOpts) -> anyhow::Result<()> { Ok(()) } + +/// Constructs a default [`EnvFilter`] that is used when the user did not specify a custom RUST_LOG. +pub fn get_default_env_filter(verbose: clap_verbosity_flag::LevelFilter) -> EnvFilter { + let mut result = EnvFilter::new("rattler_build=info"); + + if verbose >= clap_verbosity_flag::LevelFilter::Trace { + result = result.add_directive(Directive::from_str("resolvo=info").unwrap()); + result = result.add_directive(Directive::from_str("rattler=info").unwrap()); + } else { + result = result.add_directive(Directive::from_str("resolvo=warn").unwrap()); + result = result.add_directive(Directive::from_str("rattler=warn").unwrap()); + } + + result +} diff --git a/src/packaging.rs b/src/packaging.rs index 2e0e9b695..cf742deee 100644 --- a/src/packaging.rs +++ b/src/packaging.rs @@ -744,12 +744,12 @@ pub fn package_conda( } // print sorted files - println!("\nFiles in package:\n"); + tracing::info!("\nFiles in package:\n"); tmp_files .iter() .map(|x| x.strip_prefix(tmp_dir_path).unwrap()) .sorted() - .for_each(|f| println!(" - {}", f.to_string_lossy())); + .for_each(|f| tracing::info!(" - {}", f.to_string_lossy())); let output_folder = local_channel_dir.join(output.build_configuration.target_platform.to_string()); diff --git a/src/render/solver.rs b/src/render/solver.rs index 674b05735..93fe584ae 100644 --- a/src/render/solver.rs +++ b/src/render/solver.rs @@ -60,7 +60,7 @@ fn print_as_table(packages: &Vec) { ]); } - println!("\n{table}"); + tracing::info!("\n{table}"); } pub async fn create_environment( @@ -77,11 +77,11 @@ pub async fn create_environment( // Find the default cache directory. Create it if it doesn't exist yet. let cache_dir = rattler::default_cache_dir()?; - println!("\nResolving for environment specs:"); + tracing::info!("\nResolving for environment specs:"); for spec in specs { - println!(" - {}", spec); + tracing::info!(" - {}", spec); } - println!("\n"); + tracing::info!("\n"); std::fs::create_dir_all(&cache_dir) .map_err(|e| anyhow::anyhow!("could not create cache directory: {}", e))?; @@ -128,7 +128,7 @@ pub async fn create_environment( platform, &repodata_cache, download_client.clone(), - &tool_configuration.multi_progress_indicator, + tool_configuration.multi_progress_indicator.clone(), platform != Platform::NoArch, ) .await @@ -197,12 +197,12 @@ pub async fn create_environment( tool_configuration.multi_progress_indicator.clone(), ) .await?; - println!( + tracing::info!( "{} Successfully updated the environment", console::style(console::Emoji("✔", "")).green(), ); } else { - println!( + tracing::info!( "{} Already up to date", console::style(console::Emoji("✔", "")).green(), ); @@ -487,7 +487,7 @@ async fn fetch_repo_data_records_with_progress( platform: Platform, repodata_cache: &Path, client: AuthenticatedClient, - multi_progress: &indicatif::MultiProgress, + multi_progress: indicatif::MultiProgress, allow_not_found: bool, ) -> anyhow::Result> { // Create a progress bar diff --git a/src/source/mod.rs b/src/source/mod.rs index e1646de12..ee1d73165 100644 --- a/src/source/mod.rs +++ b/src/source/mod.rs @@ -220,23 +220,23 @@ mod test { super::copy_dir(&dir, &dest_dir, &[], &[], false).unwrap(); for entry in walkdir::WalkDir::new(dest_dir) { - println!("{}", entry.unwrap().path().display()); + tracing::info!("{}", entry.unwrap().path().display()); } let dest_dir_2 = tmp_dir_path.as_path().join("test_copy_dir_dest_2"); // ignore all txt files super::copy_dir(&dir, &dest_dir_2, &["*.txt"], &[], false).unwrap(); - println!("---------------------"); + tracing::info!("---------------------"); for entry in walkdir::WalkDir::new(dest_dir_2) { - println!("{}", entry.unwrap().path().display()); + tracing::info!("{}", entry.unwrap().path().display()); } let dest_dir_2 = tmp_dir_path.as_path().join("test_copy_dir_dest_2"); // ignore all txt files super::copy_dir(&dir, &dest_dir_2, &[], &["*.txt"], false).unwrap(); - println!("---------------------"); + tracing::info!("---------------------"); for entry in walkdir::WalkDir::new(dest_dir_2) { - println!("{}", entry.unwrap().path().display()); + tracing::info!("{}", entry.unwrap().path().display()); } } } diff --git a/src/test.rs b/src/test.rs index 8eb490b2d..c2d0a9c72 100644 --- a/src/test.rs +++ b/src/test.rs @@ -308,14 +308,14 @@ pub async fn run_test(package_file: &Path, config: &TestConfiguration) -> Result let cache_key = CacheKey::from(pkg); let dir = cache_dir.join("pkgs").join(cache_key.to_string()); - println!("Collecting tests from {:?}", dir); + tracing::info!("Collecting tests from {:?}", dir); let tests = tests_from_folder(&dir).await?; for test in tests { test.run(&prefix)?; } - println!( + tracing::info!( "{} all tests passed!", console::style(console::Emoji("✔", "")).green() ); diff --git a/src/windows/link.rs b/src/windows/link.rs index f841e7c51..00b87ec27 100644 --- a/src/windows/link.rs +++ b/src/windows/link.rs @@ -87,7 +87,7 @@ impl Dll { // "/Users/wolfv/Downloads/libmamba-0.24.0-h81a967f_1/Library/bin/libmamba.dll", // ); // let dll = Dll::new(&path).unwrap(); -// println!("{:?}", dll); +// tracing::info!("{:?}", dll); // // assert_eq!(dll.path, PathBuf::from("C:\\Windows\\System32\\kernel32.dll")); // // assert_eq!(dll.imports.len(), 0); // }