Tracing configuration for logfiles, per-target filters

Previously we could only configure one global tracing filter that
applied to stdout and journald.  There was no support for log files,
either.

This patch fixes both issues, by substantially revising the
configuration format: There are now separate filters for each log
file, for journald, and for the console log.  Because we want to
allow multiple logfiles, they have to go into an array in the
configuration.

The configuration logic has grown a bit complicated in its types,
since the tracing_subscriber crate would prefer to have the complete
structure of tracing Layers known statically. That's fine when you
know how many you have, and which kinds there will be, but for
the runtime-configuration case we need to mess around with
`Box<dyn Layer ...>`.

I also had to switch from tracing_subscriber's EnvFilter to its
Targets filter.  It seems "EnvFilter" can only be applied as a Layer
in itself, and won't work as a Filter on an individual Layer.

Closes #166.

Closes #170.
This commit is contained in:
Nick Mathewson 2022-01-07 10:52:43 -05:00
parent 736763fb51
commit 1a16f5a7d6
7 changed files with 279 additions and 56 deletions

22
Cargo.lock generated
View File

@ -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"

View File

@ -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.
#

View File

@ -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;

View File

@ -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
/// <https://docs.rs/tracing-subscriber/0.2.20/tracing_subscriber/filter/struct.EnvFilter.html>
/// <https://docs.rs/tracing-subscriber/latest/tracing_subscriber/filter/targets/struct.Targets.html#impl-FromStr>
///
/// 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<String>,
/// 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<String>,
/// Configuration for one or more logfiles.
#[serde(default)]
#[builder(default)]
pub journald: bool,
file: Vec<LogfileConfig>,
}
/// 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<String> {
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<LoggingConfig> 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]);

View File

@ -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 }

View File

@ -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 (

View File

@ -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> {
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<Option<Targets>> {
s.map(|s| filt_from_str_verbose(s, source)).transpose()
}
/// Try to construct a tracing [`Layer`] for logging to stdout.
fn console_layer<S>(config: &LoggingConfig, cli: Option<&str>) -> Result<impl Layer<S>>
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<S>(config: &LoggingConfig) -> Result<impl Layer<S>>
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<Layer> 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<S>(
config: &LogfileConfig,
) -> Result<(impl Layer<S> + 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)?;
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<S>(config: &LoggingConfig) -> Result<(impl Layer<S>, Vec<WorkerGuard>)>
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<Layer> 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<dyn Layer<S> + 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<WorkerGuard>,
}
/// 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<LogGuards> {
// 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)?);
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 registry = registry.with(journald_layer(config)?);
let (layer, guards) = logfile_layers(config)?;
let registry = registry.with(layer);
registry.init();
Ok(LogGuards { guards })
}