From 4970646f1ae3fe38ecb0e9a70ed5ed6d061ed6d8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?F=C3=A9lix=20Saparelli?= Date: Tue, 28 Jun 2022 12:21:19 +0000 Subject: [PATCH] Fix logging initialisation (#348) - Fixes #345 (first crash, related to `RUST_LOG` being set) - Adds multiple warnings when non-standard logging or build options are set - Fixes the (internal) crate name of the cli so that the log target `watchexec_cli` works - Fixes the verbosity config to target the actual crate names (snake vs kebab case) - Fixes a usage error related to tracing's `log` compatibility --- Cargo.lock | 1 - crates/cli/Cargo.toml | 2 +- crates/cli/src/args.rs | 12 +- crates/cli/src/lib.rs | 105 ++++++++++++++++++ crates/cli/src/main.rs | 91 +-------------- .../cli/tests/snapshots/help__help_unix.snap | 2 + .../tests/snapshots/help__help_windows.snap | 2 + 7 files changed, 123 insertions(+), 92 deletions(-) create mode 100644 crates/cli/src/lib.rs diff --git a/Cargo.lock b/Cargo.lock index cc9c0a7..8b575a5 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -2661,7 +2661,6 @@ dependencies = [ "project-origins", "tokio", "tracing", - "tracing-log", "tracing-subscriber", "watchexec", "watchexec-filterer-globset", diff --git a/crates/cli/Cargo.toml b/crates/cli/Cargo.toml index 495c2ca..9386f49 100644 --- a/crates/cli/Cargo.toml +++ b/crates/cli/Cargo.toml @@ -28,7 +28,6 @@ futures = "0.3.17" miette = { version = "4.7.1", features = ["fancy"] } notify-rust = "4.5.2" tracing = "0.1.26" -tracing-log = "0.1.3" [dependencies.clap] version = "3.1.18" @@ -72,6 +71,7 @@ features = [ "env-filter", "fmt", "json", + "tracing-log", ] [target.'cfg(target_env = "musl")'.dependencies] diff --git a/crates/cli/src/args.rs b/crates/cli/src/args.rs index 5affd55..62a55a7 100644 --- a/crates/cli/src/args.rs +++ b/crates/cli/src/args.rs @@ -17,7 +17,7 @@ const OPTSET_OUTPUT: &str = "Output options"; const OPTSET_BEHAVIOUR: &str = "Behaviour options"; pub fn get_args(tagged_filterer: bool) -> Result { - let app = Command::new("watchexec") + let mut app = Command::new("watchexec") .version(crate_version!()) .about("Execute commands when watched files change") .after_help("Use @argfile as first argument to load arguments from the file `argfile` (one argument per line) which will be inserted in place of the @argfile (further arguments on the CLI will override or add onto those in the file).") @@ -178,6 +178,16 @@ pub fn get_args(tagged_filterer: bool) -> Result { .number_of_values(1) .multiple_occurrences(true)); + // none of these are mutually exclusive, but it should be rare to unintentionally have two on + if cfg!(debug_assertions) { + app = app.before_help("⚠ DEBUG BUILD ⚠"); + } else if cfg!(feature = "dev-console") { + app = app.before_help("⚠ DEV CONSOLE ENABLED ⚠"); + } else if std::env::var("RUST_LOG").is_ok() { + app = + app.before_help("⚠ RUST_LOG environment variable set, logging options have no effect"); + } + let app = if tagged_filterer { app.arg( Arg::new("filter") diff --git a/crates/cli/src/lib.rs b/crates/cli/src/lib.rs new file mode 100644 index 0000000..756f711 --- /dev/null +++ b/crates/cli/src/lib.rs @@ -0,0 +1,105 @@ +#![deny(rust_2018_idioms)] + +use std::{env::var, fs::File, sync::Mutex}; + +use miette::{IntoDiagnostic, Result}; +use tracing::{debug, info, warn}; +use watchexec::{ + event::{Event, Priority}, + Watchexec, +}; + +mod args; +mod config; +mod filterer; + +#[cfg(target_env = "musl")] +#[global_allocator] +static GLOBAL: mimalloc::MiMalloc = mimalloc::MiMalloc; + +pub async fn run() -> Result<()> { + let mut log_on = false; + + #[cfg(feature = "dev-console")] + match console_subscriber::try_init() { + Ok(_) => { + warn!("dev-console enabled"); + log_on = true; + } + Err(e) => { + eprintln!("Failed to initialise tokio console, falling back to normal logging\n{e}") + } + } + + if !log_on && var("RUST_LOG").is_ok() { + match tracing_subscriber::fmt::try_init() { + Ok(_) => { + warn!(RUST_LOG=%var("RUST_LOG").unwrap(), "logging configured from RUST_LOG"); + log_on = true; + } + Err(e) => eprintln!("Failed to initialise logging with RUST_LOG, falling back\n{e}"), + } + } + + let tagged_filterer = var("WATCHEXEC_FILTERER") + .map(|v| v == "tagged") + .unwrap_or(false); + + let args = args::get_args(tagged_filterer)?; + + if log_on { + warn!("ignoring logging options from args"); + } else { + let verbosity = args.occurrences_of("verbose"); + let log_file = if let Some(file) = args.value_of_os("log-file") { + // TODO: use tracing-appender instead + Some(File::create(file).into_diagnostic()?) + } else { + None + }; + + let mut builder = tracing_subscriber::fmt().with_env_filter(match verbosity { + 0 => "watchexec_cli=warn", + 1 => "watchexec=debug,watchexec_filterer_globset=debug,watchexec_filterer_ignore=debug,watchexec_filterer_tagged=debug,watchexec_cli=debug", + 2 => "ignore_files=trace,project_origins=trace,watchexec=trace,watchexec_filterer_globset=trace,watchexec_filterer_ignore=trace,watchexec_filterer_tagged=trace,watchexec_cli=trace", + _ => "trace", + }); + + if verbosity > 2 { + use tracing_subscriber::fmt::format::FmtSpan; + builder = builder.with_span_events(FmtSpan::NEW | FmtSpan::CLOSE); + } + + match if let Some(writer) = log_file { + builder.json().with_writer(Mutex::new(writer)).try_init() + } else if verbosity > 3 { + builder.pretty().try_init() + } else { + builder.try_init() + } { + Ok(_) => info!("logging initialised"), + Err(e) => eprintln!("Failed to initialise logging, continuing with none\n{e}"), + } + } + + debug!(version=%env!("CARGO_PKG_VERSION"), ?args, "constructing Watchexec from CLI"); + + let init = config::init(&args)?; + let mut runtime = config::runtime(&args)?; + runtime.filterer(if tagged_filterer { + eprintln!("!!! EXPERIMENTAL: using tagged filterer !!!"); + filterer::tagged(&args).await? + } else { + filterer::globset(&args).await? + }); + + let wx = Watchexec::new(init, runtime)?; + + if !args.is_present("postpone") { + wx.send_event(Event::default(), Priority::Urgent).await?; + } + + wx.main().await.into_diagnostic()??; + + Ok(()) +} diff --git a/crates/cli/src/main.rs b/crates/cli/src/main.rs index 6138794..e917ed4 100644 --- a/crates/cli/src/main.rs +++ b/crates/cli/src/main.rs @@ -1,91 +1,4 @@ -#![deny(rust_2018_idioms)] - -use std::{env::var, fs::File, sync::Mutex}; - -use miette::{IntoDiagnostic, Result}; -use tracing::debug; -use tracing_log::LogTracer; -use watchexec::{ - event::{Event, Priority}, - Watchexec, -}; - -mod args; -mod config; -mod filterer; - -#[cfg(target_env = "musl")] -#[global_allocator] -static GLOBAL: mimalloc::MiMalloc = mimalloc::MiMalloc; - #[tokio::main] -async fn main() -> Result<()> { - LogTracer::init().into_diagnostic()?; - - #[cfg(feature = "dev-console")] - console_subscriber::init(); - - if var("RUST_LOG").is_ok() && cfg!(not(feature = "dev-console")) { - tracing_subscriber::fmt::init(); - } - - let tagged_filterer = var("WATCHEXEC_FILTERER") - .map(|v| v == "tagged") - .unwrap_or(false); - - let args = args::get_args(tagged_filterer)?; - - { - let verbosity = args.occurrences_of("verbose"); - let log_file = if let Some(file) = args.value_of_os("log-file") { - Some(File::create(file).into_diagnostic()?) - } else { - None - }; - - let mut builder = tracing_subscriber::fmt().with_env_filter(match verbosity { - 0 => "watchexec-cli=warn", - 1 => "watchexec=debug,watchexec-filterer-globset=debug,watchexec-filterer-ignore=debug,watchexec-filterer-tagged=debug,watchexec-cli=debug", - 2 => "ignore-files=trace,project-origins=trace,watchexec=trace,watchexec-filterer-globset=trace,watchexec-filterer-ignore=trace,watchexec-filterer-tagged=trace,watchexec-cli=trace", - _ => "trace", - }); - - if verbosity > 2 { - use tracing_subscriber::fmt::format::FmtSpan; - builder = builder.with_span_events(FmtSpan::NEW | FmtSpan::CLOSE); - } - - if let Some(writer) = log_file { - builder - .json() - .with_writer(Mutex::new(writer)) - .try_init() - .ok(); - } else if verbosity > 3 { - builder.pretty().try_init().ok(); - } else { - builder.try_init().ok(); - } - } - - debug!(version=%env!("CARGO_PKG_VERSION"), ?args, "constructing Watchexec from CLI"); - - let init = config::init(&args)?; - let mut runtime = config::runtime(&args)?; - runtime.filterer(if tagged_filterer { - eprintln!("!!! EXPERIMENTAL: using tagged filterer !!!"); - filterer::tagged(&args).await? - } else { - filterer::globset(&args).await? - }); - - let wx = Watchexec::new(init, runtime)?; - - if !args.is_present("postpone") { - wx.send_event(Event::default(), Priority::Urgent).await?; - } - - wx.main().await.into_diagnostic()??; - - Ok(()) +async fn main() -> miette::Result<()> { + watchexec_cli::run().await } diff --git a/crates/cli/tests/snapshots/help__help_unix.snap b/crates/cli/tests/snapshots/help__help_unix.snap index 8630e9f..349a0c7 100644 --- a/crates/cli/tests/snapshots/help__help_unix.snap +++ b/crates/cli/tests/snapshots/help__help_unix.snap @@ -2,6 +2,8 @@ source: crates/cli/tests/help.rs expression: "String::from_utf8(output.stdout).unwrap()" --- +⚠ DEBUG BUILD ⚠ + watchexec 1.20.0 Execute commands when watched files change diff --git a/crates/cli/tests/snapshots/help__help_windows.snap b/crates/cli/tests/snapshots/help__help_windows.snap index 2a82446..fa86713 100644 --- a/crates/cli/tests/snapshots/help__help_windows.snap +++ b/crates/cli/tests/snapshots/help__help_windows.snap @@ -3,6 +3,8 @@ source: crates/cli/tests/help.rs assertion_line: 16 expression: "String::from_utf8(output.stdout).unwrap()" --- +⚠ DEBUG BUILD ⚠ + watchexec 1.20.0 Execute commands when watched files change