From ad27bb2874a1cabb28ad9767206172f2e5a235a3 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Fe=CC=81lix=20Saparelli?= Date: Sun, 28 Apr 2024 15:02:23 +1200 Subject: [PATCH] Cleanup logging handling --- crates/cli/src/args.rs | 59 ++++----------- crates/cli/src/args/logging.rs | 128 +++++++++++++++++++++++++++++++++ crates/cli/src/dirs.rs | 4 +- crates/cli/src/lib.rs | 85 ++-------------------- 4 files changed, 148 insertions(+), 128 deletions(-) create mode 100644 crates/cli/src/args/logging.rs diff --git a/crates/cli/src/args.rs b/crates/cli/src/args.rs index cc6a8d9..69b52ee 100644 --- a/crates/cli/src/args.rs +++ b/crates/cli/src/args.rs @@ -9,8 +9,8 @@ use std::{ }; use clap::{ - builder::TypedValueParser, error::ErrorKind, Arg, ArgAction, Command, CommandFactory, Parser, - ValueEnum, ValueHint, + builder::TypedValueParser, error::ErrorKind, Arg, Command, CommandFactory, Parser, ValueEnum, + ValueHint, }; use miette::{IntoDiagnostic, Result}; use tokio::{fs::File, io::AsyncReadExt}; @@ -20,6 +20,8 @@ use watchexec_signals::Signal; use crate::filterer::parse::parse_filter_program; +mod logging; + const OPTSET_FILTERING: &str = "Filtering"; const OPTSET_COMMAND: &str = "Command"; const OPTSET_DEBUGGING: &str = "Debugging"; @@ -950,47 +952,6 @@ pub struct Args { )] pub print_events: bool, - /// Set diagnostic log level - /// - /// This enables diagnostic logging, which is useful for investigating bugs or gaining more - /// insight into faulty filters or "missing" events. Use multiple times to increase verbosity. - /// - /// Goes up to '-vvvv'. When submitting bug reports, default to a '-vvv' log level. - /// - /// You may want to use with '--log-file' to avoid polluting your terminal. - /// - /// Setting $RUST_LOG also works, and takes precedence, but is not recommended. However, using - /// $RUST_LOG is the only way to get logs from before these options are parsed. - #[arg( - long, - short, - help_heading = OPTSET_DEBUGGING, - action = ArgAction::Count, - num_args = 0, - )] - pub verbose: Option, - - /// Write diagnostic logs to a file - /// - /// This writes diagnostic logs to a file, instead of the terminal, in JSON format. If a log - /// level was not already specified, this will set it to '-vvv'. - /// - /// If a path is not provided, the default is the working directory. Note that with - /// '--ignore-nothing', the write events to the log will likely get picked up by Watchexec, - /// causing a loop; prefer setting a path outside of the watched directory. - /// - /// If the path provided is a directory, a file will be created in that directory. The file name - /// will be the current date and time, in the format 'watchexec.YYYY-MM-DDTHH-MM-SSZ.log'. - #[arg( - long, - help_heading = OPTSET_DEBUGGING, - num_args = 0..=1, - default_missing_value = ".", - value_hint = ValueHint::AnyPath, - value_name = "PATH", - )] - pub log_file: Option, - /// Show the manual page /// /// This shows the manual page for Watchexec, if the output is a terminal and the 'man' program @@ -1015,6 +976,9 @@ pub struct Args { conflicts_with_all = ["command", "manual"], )] pub completions: Option, + + #[command(flatten)] + pub logging: logging::LoggingArgs, } #[derive(Clone, Copy, Debug, Default, ValueEnum)] @@ -1182,8 +1146,9 @@ fn expand_args_up_to_doubledash() -> Result, std::io::Error> { #[inline] pub async fn get_args() -> Result { - if std::env::var("RUST_LOG").is_ok() { - warn!("⚠ RUST_LOG environment variable set, logging options have no effect"); + let prearg_logs = logging::preargs(); + if prearg_logs { + warn!("⚠ RUST_LOG environment variable set or hardcoded, logging options have no effect"); } debug!("expanding @argfile arguments if any"); @@ -1192,6 +1157,10 @@ pub async fn get_args() -> Result { debug!("parsing arguments"); let mut args = Args::parse_from(args); + if !prearg_logs { + logging::postargs(&args.logging).await?; + } + // https://no-color.org/ if args.color == ColourMode::Auto && std::env::var("NO_COLOR").is_ok() { args.color = ColourMode::Never; diff --git a/crates/cli/src/args/logging.rs b/crates/cli/src/args/logging.rs new file mode 100644 index 0000000..cd87a4b --- /dev/null +++ b/crates/cli/src/args/logging.rs @@ -0,0 +1,128 @@ +use std::{path::PathBuf, env::var, fs::File, sync::Mutex}; + +use clap::{ArgAction, Parser, ValueHint}; +use miette::{IntoDiagnostic, Result}; +use tokio::fs::metadata; +use tracing::{info, warn}; + +#[derive(Debug, Clone, Parser)] +pub struct LoggingArgs { + /// Set diagnostic log level + /// + /// This enables diagnostic logging, which is useful for investigating bugs or gaining more + /// insight into faulty filters or "missing" events. Use multiple times to increase args.verbose. + /// + /// Goes up to '-vvvv'. When submitting bug reports, default to a '-vvv' log level. + /// + /// You may want to use with '--log-file' to avoid polluting your terminal. + /// + /// Setting $RUST_LOG also works, and takes precedence, but is not recommended. However, using + /// $RUST_LOG is the only way to get logs from before these options are parsed. + #[arg( + long, + short, + help_heading = super::OPTSET_DEBUGGING, + action = ArgAction::Count, + default_value = "0", + num_args = 0, + )] + pub verbose: u8, + + /// Write diagnostic logs to a file + /// + /// This writes diagnostic logs to a file, instead of the terminal, in JSON format. If a log + /// level was not already specified, this will set it to '-vvv'. + /// + /// If a path is not provided, the default is the working directory. Note that with + /// '--ignore-nothing', the write events to the log will likely get picked up by Watchexec, + /// causing a loop; prefer setting a path outside of the watched directory. + /// + /// If the path provided is a directory, a file will be created in that directory. The file name + /// will be the current date and time, in the format 'watchexec.YYYY-MM-DDTHH-MM-SSZ.log'. + #[arg( + long, + help_heading = super::OPTSET_DEBUGGING, + num_args = 0..=1, + default_missing_value = ".", + value_hint = ValueHint::AnyPath, + value_name = "PATH", + )] + pub log_file: Option, +} + +pub fn preargs() -> bool { + 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}"), + } + } + + log_on +} + +pub async fn postargs(args: &LoggingArgs) -> Result<()> { + if args.verbose == 0 { + return Ok(()); + } + + let log_file = if let Some(file) = &args.log_file { + let is_dir = metadata(&file).await.map_or(false, |info| info.is_dir()); + let path = if is_dir { + let filename = format!( + "watchexec.{}.log", + chrono::Utc::now().format("%Y-%m-%dT%H-%M-%SZ") + ); + file.join(filename) + } else { + file.to_owned() + }; + + // TODO: use tracing-appender instead + Some(File::create(path).into_diagnostic()?) + } else { + None + }; + + let mut builder = tracing_subscriber::fmt().with_env_filter(match args.verbose { + 0 => unreachable!("checked by if earlier"), + 1 => "warn", + 2 => "info", + 3 => "debug", + _ => "trace", + }); + + if args.verbose > 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 args.verbose > 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}"), + } + + Ok(()) +} diff --git a/crates/cli/src/dirs.rs b/crates/cli/src/dirs.rs index d63e0f6..1eb1bbd 100644 --- a/crates/cli/src/dirs.rs +++ b/crates/cli/src/dirs.rs @@ -61,7 +61,7 @@ pub async fn project_origin(args: &Args) -> Result { .await .into_diagnostic()? }; - info!(?project_origin, "resolved common/project origin"); + debug!(?project_origin, "resolved common/project origin"); Ok(project_origin) } @@ -72,7 +72,7 @@ pub async fn vcs_types(origin: &Path) -> Vec { .into_iter() .filter(|pt| pt.is_vcs()) .collect::>(); - info!(?vcs_types, "resolved vcs types"); + info!(?vcs_types, "effective vcs types"); vcs_types } diff --git a/crates/cli/src/lib.rs b/crates/cli/src/lib.rs index ac4f45c..71431e0 100644 --- a/crates/cli/src/lib.rs +++ b/crates/cli/src/lib.rs @@ -1,7 +1,7 @@ #![deny(rust_2018_idioms)] #![allow(clippy::missing_const_for_fn, clippy::future_not_send)] -use std::{env::var, fs::File, io::Write, process::Stdio, sync::Mutex}; +use std::{io::Write, process::Stdio}; use args::{Args, ShellCompletion}; use clap::CommandFactory; @@ -9,8 +9,8 @@ use clap_complete::{Generator, Shell}; use clap_mangen::Man; use is_terminal::IsTerminal; use miette::{IntoDiagnostic, Result}; -use tokio::{fs::metadata, io::AsyncWriteExt, process::Command}; -use tracing::{debug, info, warn}; +use tokio::{io::AsyncWriteExt, process::Command}; +use tracing::{debug, info}; use watchexec::Watchexec; use watchexec_events::{Event, Priority}; @@ -23,82 +23,6 @@ mod emits; mod filterer; mod state; -async fn init() -> 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 args = args::get_args().await?; - let verbosity = args.verbose.unwrap_or(0); - - if log_on { - warn!("ignoring logging options from args"); - } else if verbosity > 0 { - let log_file = if let Some(file) = &args.log_file { - let is_dir = metadata(&file).await.map_or(false, |info| info.is_dir()); - let path = if is_dir { - let filename = format!( - "watchexec.{}.log", - chrono::Utc::now().format("%Y-%m-%dT%H-%M-%SZ") - ); - file.join(filename) - } else { - file.to_owned() - }; - - // TODO: use tracing-appender instead - Some(File::create(path).into_diagnostic()?) - } else { - None - }; - - let mut builder = tracing_subscriber::fmt().with_env_filter(match verbosity { - 0 => unreachable!("checked by if earlier"), - 1 => "warn", - 2 => "info", - 3 => "debug", - _ => "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}"), - } - } - - Ok(args) -} - async fn run_watchexec(args: Args) -> Result<()> { info!(version=%env!("CARGO_PKG_VERSION"), "constructing Watchexec from CLI"); @@ -192,8 +116,7 @@ async fn run_completions(shell: ShellCompletion) -> Result<()> { } pub async fn run() -> Result<()> { - let args = init().await?; - debug!(?args, "arguments"); + let args = args::get_args().await?; if args.manual { run_manpage(args).await