Tracing usage

(Jin Qing's Column, Jan., 2022)

Tracing is Rust log crate: https://github.com/tokio-rs/tracing

This example code outputs log to stdout and a log file, using a log filter config file, which can be automatically reloaded on change.

https://gitee.com/jinq0123/tracing-example

Dependencies

Add these dependencies to Cargo.toml:

      [dependencies]
anyhow = "1.0.52"
hotwatch = "0.4.6"
tracing = "0.1.29"
tracing-appender = "0.2.0"
tracing-subscriber = { version = "0.3.5", features = [ "env-filter", "json" ] }

    

main.rs

      mod log;
use anyhow::Result;
use std::{thread, time::Duration};
use tracing::info;
fn main() -> Result<()> {
    let _guard = log::init("./log", "example.log", "config/log_filter.txt")?;
    for i in 0..999 {
        info!(i, "Hello, world!");
        thread::sleep(Duration::from_secs(1));
    }
    Ok(())
}

    

log.rs

      //! Init log.
//!
use anyhow::{anyhow, Context as _, Result};
use hotwatch::{Event, Hotwatch};
use std::fs;
use std::path::Path;
use tracing::{debug, warn, Subscriber};
use tracing_appender::{non_blocking::WorkerGuard, rolling};
use tracing_subscriber::{fmt, layer::SubscriberExt, reload::Handle, EnvFilter};
/// Inits log.
/// Returns a WorkerGuard to ensure buffered logs are flushed,
///  and a Hotwatch to watch the log filter file.
pub fn init(
    directory: impl AsRef<Path>,
    file_name_prefix: impl AsRef<Path>,
    log_filter_file: impl AsRef<Path>,
) -> Result<(WorkerGuard, Hotwatch)> {
    let file_appender = rolling::daily(directory, file_name_prefix);
    let (non_blocking, worker_guard) = tracing_appender::non_blocking(file_appender);
    let file_layer = fmt::Layer::default()
        .with_writer(non_blocking)
        .json()
        .flatten_event(true)
        .with_ansi(false);
    let builder = tracing_subscriber::fmt()
        .pretty()
        .with_env_filter(EnvFilter::from_default_env())
        .with_filter_reloading();
    let handle = builder.reload_handle();
    let subscriber = builder.finish();
    let subscriber = subscriber.with(file_layer);
    tracing::subscriber::set_global_default(subscriber).context("set global default subscriber")?;
    reload_filter(handle.clone(), log_filter_file.as_ref());
    let log_filter_path_buf = log_filter_file.as_ref().to_path_buf();
    let mut hotwatch = Hotwatch::new().context("hotwatch failed to initialize!")?;
    hotwatch
        .watch(log_filter_file.as_ref(), move |event: Event| {
            debug!("log filter file event: {:?}", event);
            if let Event::Write(_) = event {
                reload_filter(handle.clone(), log_filter_path_buf.clone());
            }
        })
        .with_context(|| format!("failed to watch file: {:?}", log_filter_file.as_ref()))?;
    Ok((worker_guard, hotwatch))
}
fn reload_filter<S: Subscriber + 'static>(
    handle: Handle<EnvFilter, S>,
    log_filter_file: impl AsRef<Path>,
) {
    let res = try_reload_filter(handle, log_filter_file);
    match res {
        Ok(_) => debug!("reload log filter OK"),
        Err(e) => warn!("reload log filter error: {:?}", e),
    }
}
fn try_reload_filter<S: Subscriber + 'static>(
    handle: Handle<EnvFilter, S>,
    log_filter_file: impl AsRef<Path>,
) -> Result<()> {
    let contents = fs::read_to_string(log_filter_file.as_ref()).with_context(|| {
        format!(
            "something went wrong reading the file: {:?}",
            log_filter_file.as_ref()
        )
    })?;
    let contents = contents.trim();
    debug!("reload log filter: {:?}", contents);
    let new_filter = contents
        .parse::<EnvFilter>()
        .map_err(|e| anyhow!(e))
        .context("failed to parse env filter")?;
    handle.reload(new_filter).context("handle reload error")
}

    

log_filter.txt

log_filter.txt is the configure file for log. The change of this file will trigger the reload.

The log filter file must exist, otherwise it will be error:

      Error: failed to watch file: "config/log_filter.txt"
Caused by:
    系统找不到指定的路径。 (os error 3)

    

The content of log_filter.txt is a single line of filter string. A filter string consists of one or more comma-separated directives. The directive syntax is similar to RUST_LOG env val of env_logger’s.

      target[span{field=value}]=level

    

See: https://docs.rs/tracing-subscriber/latest/tracing_subscriber/struct.EnvFilter.html

Example

• tracing_example enables logs that:
  • target is modules of tracing_example*
• info will enable logs that:
  • level is info
• tracing_ex=info enables logs that:
  • target is modules of tracing_ex*
  • level is info or above
• info,tracing_ex=debug enables logs that:
  • level is info or above
  • or target is tracing_ex* and level is debug
• [foo]=trace enables logs that:
  • within the span foo
  • level is trace or above
• [span_b{name=\"bob\"}] enables logs that:
  • have any target,
  • are inside a span named span_b,
  • which has a field named name with value bob,
  • at any level.

Note: span filter directive will keep effective until it exits the span.