Rust libs day1

这是一个用于学习和使用 rust crates tracing 包，然后总结一些特点和使用方法以及资料的一个系列。

• Rust libs day1
  • tracing
    • tracing 核心概念
      • tracing 核心基本使用
    • tracing marcos
      - span
      - event
    • tracing subscriber(s) and layers
      • Subscriber
      • layer
      • 常用的定义 subscriber(s) 和 layer 的配置方式
  • tracing 最佳实践
    • 基本逻辑和实现逻辑
    • 我自己的常用配置
  • 参考

tracing

简介： tracing is a framework for instrumenting Rust programs to collect structured, event-based diagnostic information. It is designed to support both synchronous and asynchronous code. Rust 的 tracing 这个库和 log, log4rs 的定位是类似的，都是用于日志记录以及信息追踪。因而将其看作日志库也是可以的。但是 tracing 还进一步拓展了 log 的功能，使其可以实现一些动态调整，以及错误调试等功能。

链接：

1. https://docs.rs/tracing/0.1.40/tracing/
2. https://docs.rs/tracing-subscriber/0.3.18/tracing_subscriber/

一般来说，都会把 tracing 和 tracing-subscriber 组合使用

注意事项： tracing 带来了跨度/时间段 (span) 的概念，这不同于 log 的当前时刻的信息的概念，而是表示这一段时间的内容。

在使用 async/await 异步编程范式时，使用 Span::enter 需格外小心，最好避免使用。如果在.await 处持有由 Span::enter 提供的守护对象，可能会导致追踪信息失真

例如：

async fn my_async_function() {
    let span = info_span!("my_async_function");

    // 注意：此 span 将持续处于激活 (已进入) 状态，直至此守护对象被释放...
    let _enter = span.enter();
    // ...然而，`await`关键字可能会触发让步，
    // 使得运行时转而执行其他任务，但同时依然处于当前 span 之内！
    // 因此，span 的内部可能包含了其他 tasks 的信息。
    some_other_async_function().await

    // ...
}

当 Span::enter 提供的守护对象被释放时，它将结束 span 的激活状态。在异步函数或异步块在.await 点让步时，当前的作用域会被退出，但其中的值并不会被销毁（因为异步块将从这个 await 点继续执行）。这表示在 span 激活期间，其他任务可能会开始执行，从而导致追踪信息不准确。

重点：为了在 asynchronous 中使用 tracing, 可以使用 Future::instrument combinator 来实现。后续会讲到

tracing 核心概念

span：span 是一个表示一个时间段，它包含一些信息，例如：span 的名称，span 的父 span，span 的开始时间，span 的结束时间，span 的优先级，span 的属性等。
event：event 是一个表示一个事件，它包含一些信息，例如：event 的名称，event 的时间，event 的优先级，event 的属性等。
subscriber：subscriber 是一个表示一个订阅者，它用于接收 span 和 event，例如：subscriber 可以将 span 和 event 发送到日志系统，可以将 span 和 event 发送到数据库，可以将 span 和 event 发送到文件，可以将 span 和 event 发送到网络等。

layer 也是一个核心概念，但是其被放于 tracing-subscriber 这个库里。

• layer 主要是一个用于过滤 span 和 event 的工具，它用于确定是否将 span 和 event 发送到订阅者。例如：layer 可以根据 span 的名称/目标过滤，也可以根据 span 的优先级过滤，也可以根据 event 的名称/目标过滤，也可以根据 event 的优先级过滤。

layer：layer 是一个表示一个过滤器，它用于过滤 span 和 event，例如：layer 可以根据 span 的名称过滤，也可以根据 span 的优先级过滤，也可以根据 event 的名称过滤，也可以根据 event 的优先级过滤。

tracing 核心基本使用

tracing marcos

• span!
• event! | trace! | debug! | info! | warn! | error!

在 span, event 中不仅可以设置内容 content，还可以设置 target, level, name, parent 等等…

// 例如
let ABC = XXX;
span!(target:"api", Level::DEBUG,"-X" = ABC, user.name = "Hello", user.desc = "World");

event!(target:"api", Level::DEBUG,"-X" = ABC, user.name = "Hello", user.desc = "World");

// 这里的 user 对象并不存在，这是没问题的。因为这也是 marco! 支持的，
// 进而其输出的时候也会是 `.... -X = ABC  user.name = ....  user.desc =...`

span

1. in_scope closure
2. Future::instrument combinator
3. tracing::Instrument attr

in_scope closure:

fn main() {
  let span = info_span!("my_span", key1 = "value1", key2 = "value2", name = "Alex", age = 42); // 创建一个 Level::INFO 的 span 并且设置一些想要记录的键值对

  span.in_scope(|| {
    // 创建一个 span 的作用域
    // 这里的代码将运行在 span 的作用域内，并且 span 将被自动激活。
    // 如果内部没有 event! 发生，那么 span 也不会被激活。
    // 并且这里使用了 .in_scope 的方式，就可以解决 async/await 带来的 span 信息失真问题
    event!(Level::DEBUG,"Hello, 这里是 span 的 in_scope 函数的开始！");
    
    /***
      这里可以执行一些操作...
    ***/
    info!("像 log 一样输出一个 info 级别的消息");

    /*** 
      继续做些事儿
    ***/
    debug!("...");

    event!(Level::INFO,"Hello, 这里是 span 的 in_scope 函数的结束！");
  })
}

/***
  output:
  ... INFO my_span:  Hello, 这里是 span 的 in_scope 函数的开始！key1 = "value1", key2 = "value2", name = "Alex", age = 42
  ... INFO my_span:  像 log 一样输出一个 info 级别的消息
  ... DEBUG my_span:  ...
  ... INFO my_span:  Hello, 这里是 span 的 in_scope 函数的结束！
***/

Future::instrument combinator:

use tracing::Instrument;

async fn my_async_function() {
    let span = info_span!("my_async_function");
    async move {
        // 正确的做法！如果我们在这里 yield，span 将会退出，
        // 当我们恢复时，它将再次进入。
        some_other_async_function().await;

        // 在 span 内部更多的异步代码...
    }
    // 使用 span 控制 (instrument) 这个异步块...
    .instrument(span) // 
    // ...然后等待它。
    .await
}

// or 
// 使用 instrument 方法在调用点检测异步函数：

use tracing::Instrument;

async fn my_async_function() {
    let some_value = some_other_async_function()
        .instrument(debug_span!("some_other_async_function"))
        .await;

    // ...
}

tracing::Instrument attr:

/// 当 span 用于异步函数时：使用 #[instrument] 属性宏来自动生成正确的代码，
#[tracing::instrument(level = "info")]
async fn my_async_function() {
    // 如果我们在这里 yield，span 将会退出，
    // 当我们恢复时，它将再次进入。
    some_other_async_function().await;

    // ...
}
/// 在这个例子中，#[instrument] 属性宏会自动为 my_async_function 函数创建一个 span，
/// 并在函数执行期间保持这个 span 的激活状态。
/// 如果函数在 await 点让出，span 会相应地退出，并在函数恢复执行时重新进入。
/// 这样可以确保追踪信息正确地反映了异步操作的执行流程。

event

event 的使用就更容易了，直接使用 event! 即可。

其中：trace!/debug!/info!/warn!/error! 等宏，会自动创建一个 event，并且设置好对应的 Level

例如：

    event!(Level::XXX,"event!");
    trace!("trace!");   // event!(Level::TRACE);
    debug!("debug!");   // event!(Level::DEBUG);
    info!("info!");     // event!(Level::INFO);
    warn!("warn!");     // event!(Level::WARN);
    error!("error!");   // event!(Level::ERROR);


    // output:
    // 2024-10-22T13:09:38.633710Z XXX target: This is a XXX emitted by event!
    // 2024-10-22T13:09:38.633503Z TRACE target: This is a trace!
    // 2024-10-22T13:09:38.633570Z DEBUG target: This is a debug!
    // 2024-10-22T13:09:38.633605Z  INFO target: This is a info!
    // 2024-10-22T13:09:38.633667Z  WARN target: This is a warning!
    // 2024-10-22T13:09:38.633636Z ERROR target: This is a error!

tracing subscriber(s) and layers

layers 和 subscribers/glob_subscriber, 这两个东西就是 senders 和 receivers/glob_receiver。

• layer 可以设置输出格式 fmt, 输出 writer, 可以设置 filter, 可以 compose (组合/将多个 layers 组合在一起)
• subscribers/glob_subscriber, 为什么要用 ‘/’ 分开呢？因为，每个 thread 都可以设置一个 subscriber, 而 glob_subscriber 只能设置一个，如果尝试设置第二个，会报错。

Subscriber

// 自定义 subscriber, 但是一般都不用...
pub struct MySubscriber {
    // ...
}

impl Subscriber for MySubscriber {
    // ...
}

let subscriber = MySubscriber::new()
    .with(MyLayer::new());

tracing::subscriber::set_global_default(subscriber);

layer

// 自定义 layers, 并且都将其设置在 subscriber 中
pub struct MyOtherLayer {
    // ...
    // 例如这个是把 tracing 的内容输出到 log.txt
}

impl<S: Subscriber> Layer<S> for MyOtherLayer {
    // ...
}

pub struct MyThirdLayer {
    // ...
    // 例如这个是 filter target start_with "api" 的内容
    // 并且输出到 log.db
}

impl<S: Subscriber> Layer<S> for MyThirdLayer {
    // ...
}
}

let subscriber = MySubscriber::new()
    .with(MyLayer::new())
    .with(MyOtherLayer::new())
    .with(MyThirdLayer::new());

// 设置全局的 subscriber
tracing::subscriber::set_global_default(subscriber);

常用的定义 subscriber(s) 和 layer 的配置方式

use std::fs::File;
use tracing_subscriber::{Registry, prelude::*};

let cfg = load_config(); // 从配置文件加载一些 tracing 的预配置

let stdout_log = tracing_subscriber::fmt::layer().pretty(); // pretty 的输出格式，tracing 内置的一个 fmt 输出格式。
let subscriber = Registry::default().with(stdout_log); // registry 就是常用的创建 subscriber 的方式

// 如果 cfg。is_prod`为 true，将 JSON 格式的日志记录到文件中。
let json_log = if cfg.is_prod {
    let file = File::create(cfg.path)?;
    let json_log = tracing_subscriber::fmt::layer() // 创建了一个 layer
        // .with_target(true)                       // 显示 target 
        // .with_thread_names(true);                // 显示 thread name
        .json()                                     // 该 layer 为 json format
        .with_writer(file);                         // writer 是一个文件，也就是将 tracing 的 msgs 输出到该文件
    Some(json_log)
} else {
    None
};

// 如果 `cfg.is_prod` 为假，那么 `json` 将会是 `None`，此层将不会执行任何操作。
//不过，无论 `Option` 的值是 `None` 还是 `Some`，订阅者的类型都将保持不变。
let subscriber = subscriber.with(json_log);

tracing::subscriber::set_global_default(subscriber)
   .expect("Unable to set global subscriber");

tracing 最佳实践

基本逻辑和实现逻辑

use tracing_subscriber::{filter::LevelFilter, Layer, prelude::*};
use std::fs::File;
struct Config {
    enable_log_file: bool,
    enable_stdout: bool,
    enable_stderr: bool,
    // ...
}

let cfg = Config::from_config_file()?;

// 创建一个用于存储 layers 的 Vec
let mut layers = Vec::new();

if cfg.enable_log_file {
    let file = File::create("app.log")?;
    let layer = tracing_subscriber::fmt::layer()
        .with_thread_names(true)
        .with_target(true)
        .json()
        .with_writer(file)
        // 将层包装为一个类型擦除的 trait 对象，
        // 以便它可以被推入到 Vec 中。
        .boxed();
    layers.push(layer);
}

if cfg.enable_stdout {
    let layer = tracing_subscriber::fmt::layer()
        .pretty()
        .with_filter(LevelFilter::INFO)
        // 将层包装为一个类型擦除的 trait 对象，
        // 以便它可以被推入到 Vec 中。
        .boxed();
    layers.push(layer);
}

if cfg.enable_stderr {
    let layer = tracing_subscriber::fmt::layer()
        .with_target(false)
        .with_filter(LevelFilter::WARN)
        // 将层包装为一个类型擦除的 trait 对象，
        // 以便它可以被推入到 Vec 中。
        .boxed();
    layers.push(layer);
}

tracing_subscriber::registry()
    .with(layers)  // 直接传入 Vec, 从而实现多个 layers 的组合和使用
    .init();

我自己的常用配置

config.toml:

[project]
authors = ["unic"]

[log_config]
# fields: { enable, level, file_path, env },
# -------------------------------------------------
# enable: bool
# level: Option<Level>, trace | debug | info | warn | error
# file_path: Option<String>,
# env: Option<String>,
stdout = { enable = true, level = "trace" }
stderr = { enable = false, level = "trace" }
log_file = { enable = true, level = "trace", file_path = "./filesmarn.log" }
database = { enable = false, level = "trace", file_path = "./filesmarn_log.db", env = "./.env" }
metrics_target = { enable = true, level = "trace", file_path = "./metrics.log" }

log.rs:

use super::error::TracingError;
use serde::Deserialize;
use std::fs::OpenOptions;
use std::io;
use std::io::ErrorKind;
use std::path::Path;
use std::sync::Arc;
use tracing::level_filters::LevelFilter;
use tracing::Level;
use tracing_subscriber::{filter, fmt, layer::SubscriberExt, util::SubscriberInitExt, Layer};

extern crate serde;
extern crate thiserror;
extern crate tracing;
extern crate tracing_subscriber;

pub const METRICS_TARGET: &'static str = "metrics";
pub const METRICS_LOG_PATH: &'static str = "./metrics.log";

/// Get the default configuration content based on the target OS on compilation.
///
/// const LOG_CONFIG: &'static str = "config.toml";
fn get_default_config_content() -> &'static str {
    #[cfg(not(target_os = "windows"))]
    let content = include_str!("../../../config.toml");

    #[cfg(target_os = "windows")]
    let content = include_str!(r#"..\..\..\config.toml"#);

    content
}

#[derive(Debug, Deserialize)]
struct Config {
    log_config: LogConfig,
}

#[derive(Debug, Deserialize)]
struct LogConfig {
    stdout: EnableConfig,
    stderr: EnableConfig,
    log_file: EnableConfig,
    database: EnableConfig,
    metrics_target: EnableConfig,
}

#[derive(Debug, Deserialize)]
#[serde(rename_all = "lowercase")]
enum TLevel {
    Trace = 0,
    Debug = 1,
    Info = 2,
    Warn = 3,
    Error = 4,
}

impl TLevel {
    /// Convert the given TLevel to a tracing::Level and then return the corresponding LevelFilter.
    ///
    /// If the given TLevel is None, return the default LevelFilter.
    pub fn cvt_tracing_level(t_level: &Option<TLevel>, default: LevelFilter) -> LevelFilter {
        match t_level {
            Some(l) => LevelFilter::from(Into::<Level>::into(l)),
            None => default,
        }
    }
}

impl Into<Level> for &TLevel {
    fn into(self) -> Level {
        match self {
            TLevel::Trace => Level::TRACE,
            TLevel::Debug => Level::DEBUG,
            TLevel::Info => Level::INFO,
            TLevel::Warn => Level::WARN,
            TLevel::Error => Level::ERROR,
        }
    }
}

#[derive(Debug, Deserialize)]
struct EnableConfig {
    pub enable: bool,
    pub level: Option<TLevel>,
    pub file_path: Option<String>,
    pub env: Option<String>,
}

impl Config {
    pub fn from_custom_config<T: AsRef<Path>>(file: T) -> Result<Config, TracingError> {
        if file.as_ref().is_file() {
            let config_file = std::fs::read_to_string(file)?;
            let config: Config = toml::from_str(&config_file)?;
            Ok(config)
        } else {
            let e = TracingError::InvalidConfigFile(io::Error::new(
                ErrorKind::NotFound,
                format!("{} is not a valid file", file.as_ref().display()),
            ));
            eprintln!("Error on loading custom config file:{:?}", e);
            eprintln!("Using default config file...");
            Err(e)
        }
    }

    pub fn from_default_config() -> Result<Config, TracingError> {
        // let mut cwd =
        //     std::env::current_dir().unwrap_or(dirs::config_dir().expect("No config dir found"));
        // cwd.push(LOG_CONFIG);
        // Self::from_custom_config(cwd)
        Ok(toml::from_str(get_default_config_content())?)
    }
}

/// Initialize the default logger.
pub fn init_default_logger() -> Result<(), TracingError> {
    let cfg = Config::from_default_config()?;
    init_by_config(&cfg)
}

/// Initialize the logger with the given configuration.
///
/// If no configuration file is found, use the default configuration.
pub fn init_custom_logger<T: AsRef<Path>>(file: T) -> Result<(), TracingError> {
    let cfg = Config::from_custom_config(file).unwrap_or_else(|_| {
        Config::from_default_config().expect("Failed to load default config file")
    });

    init_by_config(&cfg)
}

/// Initialize the logger with the given configuration.
fn init_by_config(cfg: &Config) -> Result<(), TracingError> {
    let mut layers = Vec::new();

    let metrics_enabled = cfg.log_config.metrics_target.enable;

    // filter out metrics target if it is enabled
    let filter_metrics = filter::filter_fn(move |metadata| {
        !metrics_enabled || !metadata.target().starts_with(METRICS_TARGET)
    });

    if cfg.log_config.stdout.enable {
        let level_filter =
            TLevel::cvt_tracing_level(&cfg.log_config.stdout.level, LevelFilter::INFO);

        let stdout_layer = fmt::layer()
            // .pretty()
            .compact()
            .with_filter(level_filter)
            .with_filter(filter_metrics.clone())
            .boxed();
        layers.push(stdout_layer);
    }

    // write to stderr
    if cfg.log_config.stderr.enable {
        // TODO: Find a better way to integrate with stdout
        let level_filter =
            TLevel::cvt_tracing_level(&cfg.log_config.stderr.level, LevelFilter::ERROR);

        let stderr_layer = fmt::layer()
            .pretty()
            .with_filter(level_filter)
            .with_filter(filter_metrics.clone())
            .boxed();
        layers.push(stderr_layer);
    }

    // write to log file
    if cfg.log_config.log_file.enable {
        if let Some(file_path) = &cfg.log_config.log_file.file_path {
            let log_file = OpenOptions::new()
                .create(true)
                .append(true)
                .open(file_path)
                .expect("Unable to open log file");

            let level_filter =
                TLevel::cvt_tracing_level(&cfg.log_config.log_file.level, LevelFilter::DEBUG);

            let file_layer = fmt::layer()
                .pretty()
                .with_ansi(false)
                .with_writer(Arc::new(log_file))
                .with_filter(level_filter)
                .with_filter(filter_metrics)
                .boxed();

            layers.push(file_layer);
        }
    }

    // write to database
    if cfg.log_config.database.enable {
        todo!("database logging not implemented yet");
    }

    // write to metrics target
    if cfg.log_config.metrics_target.enable {
        if let Some(metrics_target_file) = &cfg.log_config.metrics_target.file_path {
            let metrics_file = OpenOptions::new()
                .create(true)
                .append(true)
                .open(metrics_target_file)
                .expect("Unable to open metrics file");

            let metrics_filtered_layer = fmt::layer()
                .compact()
                .with_ansi(false)
                .with_target(true)
                .with_thread_ids(true)
                .with_line_number(true)
                .with_thread_names(true)
                .with_writer(Arc::new(metrics_file))
                .with_filter(filter::filter_fn(|metadata| {
                    metadata.target().starts_with(METRICS_TARGET)
                }))
                .boxed();

            layers.push(metrics_filtered_layer);
        }
    }

    // set the global subscriber
    tracing_subscriber::registry().with(layers).init();

    Ok(())
}

参考

1. Tracing
2. Tracing - Getting Started