diff --git a/Cargo.lock b/Cargo.lock index 84c91908e..488fcfde7 100644 --- a/Cargo.lock +++ b/Cargo.lock @@ -78,6 +78,7 @@ dependencies = [ "tor-rtcompat", "tor-socksproto", "tracing", + "tracing-appender", "tracing-journald", "tracing-subscriber", "winapi", @@ -618,6 +619,16 @@ dependencies = [ "cfg-if", ] +[[package]] +name = "crossbeam-channel" +version = "0.5.1" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "06ed27e177f16d65f0f0c22a213e17c696ace5dd64b14258b52f9417ccb52db4" +dependencies = [ + "cfg-if", + "crossbeam-utils", +] + [[package]] name = "crossbeam-queue" version = "0.3.2" @@ -3010,6 +3021,17 @@ dependencies = [ "tracing-core", ] +[[package]] +name = "tracing-appender" +version = "0.2.0" +source = "registry+https://github.com/rust-lang/crates.io-index" +checksum = "94571df2eae3ed4353815ea5a90974a594a1792d8782ff2cbcc9392d1101f366" +dependencies = [ + "crossbeam-channel", + "time", + "tracing-subscriber", +] + [[package]] name = "tracing-attributes" version = "0.1.18" diff --git a/crates/arti-config/src/arti_defaults.toml b/crates/arti-config/src/arti_defaults.toml index 9ac6c67be..192e5f363 100644 --- a/crates/arti-config/src/arti_defaults.toml +++ b/crates/arti-config/src/arti_defaults.toml @@ -11,10 +11,8 @@ socks_port = 9150 # Configure logging [logging] -# Enable logging to journald where available -journald = false - -# Specify filtering directives for tracing. +# Specify filtering directives for sending trace messages to the console +# (via standard output). # # It can be as simple as a single loglevel, or as complicated as a # list with per-module settings. @@ -25,7 +23,20 @@ journald = false # trace_filter = "info,tor_proto::channel=trace" # # For more information, see https://docs.rs/tracing-subscriber/0.2.20/tracing_subscriber/filter/struct.EnvFilter.html -trace_filter = "debug" +console = "debug" + +# As above, but specify filtering directives for sending trace messages to +# the journald logging system. +# +#journald = "" + +# You can also configure one or more log files, with different filters, and optional +# rotation. +# +#file = [ +# {path = "~/logs/debug.log", filter="debug"}, +# {path = "~/logs/trace.log", filter="trace", rotate="daily"}, +#] # Locations to use for storing things on disk. # diff --git a/crates/arti-config/src/lib.rs b/crates/arti-config/src/lib.rs index dee8964bf..3654a966f 100644 --- a/crates/arti-config/src/lib.rs +++ b/crates/arti-config/src/lib.rs @@ -45,8 +45,8 @@ mod options; pub use cmdline::CmdLine; pub use options::{ - ArtiConfig, ArtiConfigBuilder, LoggingConfig, LoggingConfigBuilder, ProxyConfig, - ProxyConfigBuilder, + ArtiConfig, ArtiConfigBuilder, LogRotation, LogfileConfig, LogfileConfigBuilder, LoggingConfig, + LoggingConfigBuilder, ProxyConfig, ProxyConfigBuilder, }; use tor_config::CfgPath; diff --git a/crates/arti-config/src/options.rs b/crates/arti-config/src/options.rs index 1202fbb31..346134f14 100644 --- a/crates/arti-config/src/options.rs +++ b/crates/arti-config/src/options.rs @@ -9,7 +9,7 @@ use arti_client::config::{ use derive_builder::Builder; use serde::Deserialize; use std::collections::HashMap; -use tor_config::ConfigBuildError; +use tor_config::{CfgPath, ConfigBuildError}; /// Default options to use for our configuration. pub(crate) const ARTI_DEFAULTS: &str = concat!(include_str!("./arti_defaults.toml"),); @@ -21,26 +21,32 @@ pub(crate) const ARTI_DEFAULTS: &str = concat!(include_str!("./arti_defaults.tom #[builder(build_fn(error = "ConfigBuildError"))] pub struct LoggingConfig { /// Filtering directives that determine tracing levels as described at - /// + /// /// /// You can override this setting with the -l, --log-level command line parameter. /// /// Example: "info,tor_proto::channel=trace" - // TODO(nickm) remove public elements when I revise this. - #[serde(default = "default_trace_filter")] - #[builder(default = "default_trace_filter()")] - pub trace_filter: String, + #[serde(default = "default_console_filter")] + #[builder(default = "default_console_filter()", setter(into, strip_option))] + console: Option, - /// Whether to log to journald - // TODO(nickm) remove public elements when I revise this. + /// Filtering directives for the journald logger. + /// + /// Only takes effect if Arti is built with the `journald` filter. + #[serde(default)] + #[builder(default, setter(into, strip_option))] + journald: Option, + + /// Configuration for one or more logfiles. #[serde(default)] #[builder(default)] - pub journald: bool, + file: Vec, } -/// Return a default value for `trace_filter`. -fn default_trace_filter() -> String { - "debug".to_owned() +/// Return a default tracing filter value for `logging.console`. +#[allow(clippy::unnecessary_wraps)] +fn default_console_filter() -> Option { + Some("debug".to_owned()) } impl Default for LoggingConfig { @@ -54,15 +60,93 @@ impl LoggingConfig { pub fn builder() -> LoggingConfigBuilder { LoggingConfigBuilder::default() } + + /// Return the configured journald filter, if one is present + pub fn journald_filter(&self) -> Option<&str> { + match self.journald { + Some(ref s) if !s.is_empty() => Some(s.as_str()), + _ => None, + } + } + + /// Return the configured stdout filter, if one is present + pub fn console_filter(&self) -> Option<&str> { + match self.console { + Some(ref s) if !s.is_empty() => Some(s.as_str()), + _ => None, + } + } + + /// Return a list of the configured log files + pub fn logfiles(&self) -> &[LogfileConfig] { + &self.file + } } impl From for LoggingConfigBuilder { fn from(cfg: LoggingConfig) -> LoggingConfigBuilder { let mut builder = LoggingConfigBuilder::default(); + if let Some(console) = cfg.console { + builder.console(console); + } + if let Some(journald) = cfg.journald { + builder.journald(journald); + } builder - .trace_filter(cfg.trace_filter) - .journald(cfg.journald); - builder + } +} + +/// Configuration information for an (optionally rotating) logfile. +#[derive(Deserialize, Debug, Builder, Clone, Eq, PartialEq)] +pub struct LogfileConfig { + /// How often to rotate the file? + #[serde(default)] + #[builder(default)] + rotate: LogRotation, + /// Where to write the files? + path: CfgPath, + /// Filter to apply before writing + filter: String, +} + +/// How often to rotate a log file +#[derive(Deserialize, Debug, Clone, Copy, Eq, PartialEq)] +#[non_exhaustive] +#[serde(rename_all = "lowercase")] +pub enum LogRotation { + /// Rotate logs daily + Daily, + /// Rotate logs hourly + Hourly, + /// Never rotate the log + Never, +} + +impl Default for LogRotation { + fn default() -> Self { + Self::Never + } +} + +impl LogfileConfig { + /// Return a new [`LogfileConfigBuilder`] + pub fn builder() -> LogfileConfigBuilder { + LogfileConfigBuilder::default() + } + + /// Return the configured rotation interval. + pub fn rotate(&self) -> LogRotation { + self.rotate + } + + /// Return the configured path to the log file. + pub fn path(&self) -> &CfgPath { + &self.path + } + + /// Return the configured filter. + pub fn filter(&self) -> &str { + &self.filter } } @@ -465,7 +549,7 @@ mod test { let mut bld = ArtiConfig::builder(); bld.proxy().socks_port(Some(9999)); - bld.logging().journald(true).trace_filter("warn".to_owned()); + bld.logging().console("warn"); bld.tor_network() .authorities(vec![auth]) .fallback_caches(vec![fallback]); diff --git a/crates/arti/Cargo.toml b/crates/arti/Cargo.toml index f8d5a84e8..f5c9188a9 100644 --- a/crates/arti/Cargo.toml +++ b/crates/arti/Cargo.toml @@ -35,6 +35,7 @@ tracing-subscriber = { version = "0.3.0", features = ["env-filter"] } tokio-crate = { package = "tokio", version = "1.4", optional = true, features = ["signal"] } clap = "2.33.0" tracing-journald = { version = "0.2.0", optional = true } +tracing-appender = "0.2.0" [target.'cfg(unix)'.dependencies] libc = { version = "0.2", default-features = false } diff --git a/crates/arti/src/main.rs b/crates/arti/src/main.rs index 76737835c..4df079e3f 100644 --- a/crates/arti/src/main.rs +++ b/crates/arti/src/main.rs @@ -202,7 +202,7 @@ fn main() -> Result<()> { let config: ArtiConfig = cfg.try_into()?; - trace::setup_logging(config.logging(), matches.value_of("loglevel")); + let _log_guards = trace::setup_logging(config.logging(), matches.value_of("loglevel"))?; if let Some(proxy_matches) = matches.subcommand_matches("proxy") { let socks_port = match ( diff --git a/crates/arti/src/trace.rs b/crates/arti/src/trace.rs index 3e529240d..4b728fdb0 100644 --- a/crates/arti/src/trace.rs +++ b/crates/arti/src/trace.rs @@ -1,46 +1,151 @@ //! Configure tracing subscribers for Arti -use arti_config::LoggingConfig; +use anyhow::{anyhow, Context, Result}; +use arti_config::{LogRotation, LogfileConfig, LoggingConfig}; +use std::path::Path; +use std::str::FromStr; +use tracing::Subscriber; +use tracing_appender::non_blocking::WorkerGuard; use tracing_subscriber::layer::SubscriberExt; use tracing_subscriber::prelude::*; -use tracing_subscriber::{fmt, registry, EnvFilter}; +use tracing_subscriber::{filter::Targets, fmt, registry, Layer}; -/// As [`EnvFilter::new`], but print a message if any directive in the -/// log is invalid. -fn filt_from_str_verbose(s: &str, source: &str) -> EnvFilter { - match EnvFilter::try_new(s) { - Ok(s) => s, - Err(_) => { - eprintln!("Problem in {}:", source); - EnvFilter::new(s) - } +/// As [`Targets::from_str`], but wrapped in an [`anyhow::Result`]. +// +// (Note that we have to use `Targets`, not `EnvFilter`: see comment in +// `setup_logging()`.) +fn filt_from_str_verbose(s: &str, source: &str) -> Result { + Targets::from_str(s).with_context(|| format!("in {}", source)) +} + +/// As filt_from_str_verbose, but treat an absent filter (or an empty string) as +/// None. +fn filt_from_opt_str(s: Option<&str>, source: &str) -> Result> { + s.map(|s| filt_from_str_verbose(s, source)).transpose() +} + +/// Try to construct a tracing [`Layer`] for logging to stdout. +fn console_layer(config: &LoggingConfig, cli: Option<&str>) -> Result> +where + S: Subscriber + for<'span> tracing_subscriber::registry::LookupSpan<'span>, +{ + let filter = cli + .map(|s| filt_from_str_verbose(s, "--log-level command line parameter")) + .or_else(|| filt_from_opt_str(config.console_filter(), "logging.console").transpose()) + .unwrap_or_else(|| Ok(Targets::from_str("debug").expect("bad default")))?; + Ok(fmt::Layer::default().with_filter(filter)) +} + +/// Try to construct a tracing [`Layer`] for logging to journald, if one is +/// configured. +#[cfg(feature = "journald")] +fn journald_layer(config: &LoggingConfig) -> Result> +where + S: Subscriber + for<'span> tracing_subscriber::registry::LookupSpan<'span>, +{ + if let Some(filter) = filt_from_opt_str(config.journald_filter(), "logging.journald")? { + Ok(Some(tracing_journald::layer()?.with_filter(filter))) + } else { + // Fortunately, Option implements Layer, so we can just return None here. + Ok(None) } } -/// Set up logging -pub(crate) fn setup_logging(config: &LoggingConfig, cli: Option<&str>) { - let env_filter = - match cli.map(|s| filt_from_str_verbose(s, "--log-level command line parameter")) { - Some(f) => f, - None => filt_from_str_verbose( - config.trace_filter.as_str(), - "trace_filter configuration option", - ), - }; +/// Try to construct a non-blocking tracing [`Layer`] for writing data to an +/// optionally rotating logfile. +/// +/// On success, return that layer, along with a WorkerGuard that needs to be +/// dropped when the program exits. +fn logfile_layer( + config: &LogfileConfig, +) -> Result<(impl Layer + Send + Sync + Sized, WorkerGuard)> +where + S: Subscriber + for<'span> tracing_subscriber::registry::LookupSpan<'span> + Send + Sync, +{ + use tracing_appender::{ + non_blocking, + rolling::{RollingFileAppender, Rotation}, + }; - let registry = registry().with(fmt::Layer::default()).with(env_filter); + let filter = filt_from_str_verbose(config.filter(), "logging.files.filter")?; + let rotation = match config.rotate() { + LogRotation::Daily => Rotation::DAILY, + LogRotation::Hourly => Rotation::HOURLY, + _ => Rotation::NEVER, + }; + let path = config.path().path()?; + let directory = path.parent().unwrap_or_else(|| Path::new(".")); + let fname = path + .file_name() + .ok_or_else(|| anyhow!("No path for log file")) + .map(Path::new)?; - if config.journald { - #[cfg(feature = "journald")] - if let Ok(journald) = tracing_journald::layer() { - registry.with(journald).init(); - return; - } - #[cfg(not(feature = "journald"))] - tracing::warn!( - "journald logging was selected, but arti was built without journald support." - ); + let appender = RollingFileAppender::new(rotation, directory, fname); + let (nonblocking, guard) = non_blocking(appender); + let layer = fmt::layer().with_writer(nonblocking).with_filter(filter); + Ok((layer, guard)) +} + +/// Try to construct a tracing [`Layer`] for all of the configured logfiles. +/// +/// On success, return that layer along with a list of [`WorkerGuard`]s that +/// need to be dropped when the program exits. +fn logfile_layers(config: &LoggingConfig) -> Result<(impl Layer, Vec)> +where + S: Subscriber + for<'span> tracing_subscriber::registry::LookupSpan<'span> + Send + Sync, +{ + let mut guards = Vec::new(); + if config.logfiles().is_empty() { + // As above, we have Option implements Layer, so we can return + // None in this case. + return Ok((None, guards)); } + let (layer, guard) = logfile_layer(&config.logfiles()[0])?; + guards.push(guard); + + // We have to use a dyn pointer here so we can build up linked list of + // arbitrary depth. + let mut layer: Box + Send + Sync + 'static> = Box::new(layer); + + for logfile in &config.logfiles()[1..] { + let (new_layer, guard) = logfile_layer(logfile)?; + layer = Box::new(layer.and_then(new_layer)); + guards.push(guard); + } + + Ok((Some(layer), guards)) +} + +/// Opaque structure that gets dropped only when the logs are no longer needed. +pub(crate) struct LogGuards { + /// The actual list of guards we're returning. + #[allow(unused)] + guards: Vec, +} + +/// Set up logging. +/// +/// Note that the returned LogGuard shouldn't be dropped while the program +/// is running; they're used to ensure that all the log files are cleaned up. +pub(crate) fn setup_logging(config: &LoggingConfig, cli: Option<&str>) -> Result { + // Important: We have to make sure that the individual layers we add here + // are not filters themselves. That means, for example, that we can't add + // an `EnvFilter` layer unless we want it to apply globally to _all_ layers. + // + // For a bit of discussion on the difference between per-layer filters and filters + // that apply to the entire registry, see + // https://docs.rs/tracing-subscriber/0.3.5/tracing_subscriber/layer/index.html#global-filtering + + let registry = registry().with(console_layer(config, cli)?); + + #[cfg(feature = "journald")] + let registry = registry.with(journald_layer(config)?); + + let (layer, guards) = logfile_layers(config)?; + let registry = registry.with(layer); + registry.init(); + + Ok(LogGuards { guards }) }