    use tracing::{span, Level};
    // 必选参数：Level 和 Span id（name）
    let span = span!(Level::TRACE, "my_span");

    // enter() 返回一个 RAII guard，当它被 drop 时，span 自动退出。
    let _enter = span.enter();
    // 在 span 上下文记录 event。

Events ：Event 表示特定时刻的事件，通常位于 span context 中（非必须）。

    use tracing::{event, span, Level};

    // Event 可以位于 span context 之外
    event!(Level::INFO, "something happened");

    let span = span!(Level::INFO, "my_span");
    let _guard = span.enter();
    // 在 my_span context 中记录一个 event。
    event!(Level::DEBUG, "something happened inside my_span");

Subscribers ：Subscriber 用于记录或聚合 span 和 event。Subscribers 提供了 enabled()/event()/enter()/exit() 等方法。

span!/event!()
#

使用 span!() 来创建特定 Level 和 id 的 span，然后调用它的 enter() 方法来创建一个 span context，后续该 span 对象被 drop 前，所有 event 都属于该 span。

span 的 enter() 可以嵌套, 子 span 打印 event 时会自动显示父 span;
span 的 fields 会自动被其中的 event 继承；
event 和 span 都需要指定 Level 级别；

use tracing::{span, Level};

let span = span!(Level::TRACE, "my span");
let _enter = span.enter();
// Any trace events that occur before the guard is dropped will occur within the span.  Dropping the guard will exit the span.

event 可以没有 span，例如在创建和 enter span 前创建的 event，这时 target span 默认为所在的 crate::module。

event 可以使用 target: "span_name" 或 parent: &span 来指定父span。

// 创建一个 myerrorspan span
tracing::error_span!("myerrorspan", ?s);
// event 关联上面创建的 span
tracing::error!(target: "myerrorspan", ?s, s.field_a, "just a debug message2");

对于自定义函数，可以使用 #[instrument] 属性宏来自动创建 span，它使用函数名作为 span name, 函数参数将作为 span 的 fields。函数内的 event 自动位于这个 span context 中。

skip()：要去掉的参数名；
fields(): 指定要新加的 field=value；

由于 #[instrument] 默认将所有函数参数添加到日志输出，对于 HTTP Handler 函数来说，可能包含敏感信息（如用户提交的表单或 Body 数据等），可以使用 secrecy crate 来解决这个问题（它通过重新定义嵌入的字段类型的 Debug trait 来实现隐藏数据输出）。

use tracing::{Level, event, instrument};

#[instrument(fields(http.uri = req.uri(), http.method = req.method()))]
pub fn handle_request<B>(req: http::Request<B>) -> http::Response<B> {
    // ... handle the request ...
}

// instrument 支持丰富的配置参数
impl Handler {
    #[instrument(
        level="debug",
        target="this_crate::some_span",
        name = "Handler::run",
        skip(self),
        fields(
            // `%` serializes the peer IP addr with `Display`
            peer_addr = %self.connection.peer_addr().unwrap()
        ),
    )]
    async fn run(&mut self) -> mini_redis::Result<()> {
        // 这个 event 位于 my_function span 下，具有 my_arg field
        event!(Level::INFO, "inside my_function!");
        //...
    }
}

//! src/routes/subscriptions.rs
#[tracing::instrument(
    name = "Adding a new subscriber",
    skip(form, pool),
    fields(
        request_id = %Uuid::new_v4(),
        subscriber_email = %form.email,
        subscriber_name= %form.name
    )
)]
pub async fn subscribe(form: web::Form<FormData>, pool: web::Data<PgPool>,) -> HttpResponse {
    match insert_subscriber(&pool, &form).await
    {
        Ok(_) => HttpResponse::Ok().finish(),
        Err(_) => HttpResponse::InternalServerError().finish()
    }
}

对于不能使用 #[instrument] 的第三方函数，可以使用 span 的 in_scope() 方法:

use tracing::info_span;
let json = info_span!("json.parse").in_scope(|| serde_json::from_slice(&buf))?;

span 和 event 都需要指定 Level，其它可选:

message：可选；
name：默认为 file:line;
target：默认为 crate::module；
parent：current span；

use tracing::{event, Level};

// span 必选: Level 和 span name/id
let span = span!(Level::TRACE, "my span");

// event：Level 必选, message 可选
// 对于 event，字符串字面量默认为 message，故 `message` key 可以忽略。
event!(Level::INFO, "something has happened!");
// 等效为
event!(Level::INFO, message = "something has happened!")
event!(Level::INFO, key = "value") // 没有 message（为空）

// event 可选：parent span
event!(parent: &span, Level::INFO, "something has happened!");

// event 可选：target
event!(target: "app_events", Level::INFO, "something has happened!");

// event 可选：name，默认为 file:line
event!(name: "some_info", Level::INFO, "something has happened!");

span 和 event 还可以使用逗号分割的 field_name=field_value 来指定自定义属性，span 的 field 都会被 event 继承：

// 对于 span, 自定义 field 必须位于 span name/id 之后；
tracing::error_span!("myerrorspan", ?s);  // OK
// tracing::error_span!(?s, "myerrorspan"); // 错误

// 对于 event，自定义 field 必须位于 message 之前， Level 之后;
tracing::error!(target: "myerrorspan", ?s, s.field_a, "just a debug message2");
tracing::error!(target: "myerrorspan", ?s, s.field_a, a = "b");  // 没有 message

// 在 enter _span drop 前, 后续的 event 都自动关联该 span
let _span = tracing::error_span!("my_enter_span", ?s).entered();
tracing::error!(?s, s.field_a, a = "c");

let user = "ferris";
span!(Level::TRACE, "login", user);
// 等效于
span!(Level::TRACE, "login", user = user);

let user = "ferris";
let email = "[email protected]";
// field name 中间可以有 .
span!(Level::TRACE, "login", user, user.email = email);

let user = User { name: "ferris", email: "[email protected]", };
// span 具有两个 fields `user.name = "ferris"` 和 `user.email = "[email protected]"`.
span!(Level::TRACE, "login", user.name, user.email);

对于自定义类型，没有实现 tracing::Value trait 时，不能直接显示，否则报错：the trait tracing::Value is not implemented for XX。但是可以为自定义类型实现 Debug 或 Display 后，在 value 名称前使用？和 % 来指定显示方式（？使用 Debug，% 使用 Display）。

#[derive(Debug)]
struct MyStruct { field: &'static str, }
let my_struct = MyStruct { field: "Hello world!"};

// ？使用 Debug
event!(Level::TRACE, greeting = ?my_struct);
// 等效于
event!(Level::TRACE, greeting = tracing::field::debug(&my_struct));

// % 使用 Display
event!(Level::TRACE, greeting = %my_struct.field);
// 等效于
event!(Level::TRACE, greeting = tracing::field::display(&my_struct.field)

// ？和 % 也可以用在 key 前
event!(Level::TRACE, %my_struct.field);

如果为 span field 指定特殊的 tracing::field::Empty 值，则后续可以再设置：

use tracing::{trace_span, field};

// 创建一个 span, 具有两个 field，其中 greeting 具有值，而 parting 需要后续设置值
let span = trace_span!("my_span", greeting = "hello world", parting = field::Empty);

// 后续使用 span.record() 方法为 Empty field 指定具体的值
span.record("parting", &"goodbye world!");

event message 可以使用 format 字符串（span name/id 不支持格式化），这也是 field 必须位于 level 和 message 中间 的原因：后续的参数是 format 字符串的参数：

let question = "the ultimate question of life, the universe, and everything";
let answer = 42;
event!(
    Level::DEBUG,
    question.answer = answer,
    question.tricky = true,
    "the answer to {} is {}.", question, answer  // message
);

为了方便创建指定 Level 的 span 和 event, 可以使用带 level 的特殊宏, 如：

event : trace!, debug!, info!, warn!, error!
span : trace_span!, debug_span!, info_span!, warn_span!, error_span!

对于 span 的 enter/exit event，默认在 trace 级别才打印（-> 和 <-），可以设置 RUST_LOG=trace cargo run 来查看。

[.. INFO zero2prod] Adding a new subscriber.; request_id=f349b0fe.. subscriber_email=[email protected] subscriber_name=le guin
[.. TRACE zero2prod] -> Adding a new subscriber.
[.. INFO zero2prod] request_id f349b0fe.. - Saving new subscriber details in the database
[.. INFO zero2prod] request_id f349b0fe.. - New subscriber details have been saved
[.. TRACE zero2prod] <- Adding a new subscriber.
[.. TRACE zero2prod] -- Adding a new subscriber.
[.. INFO actix_web] .. "POST /subscriptions HTTP/1.1" 200 .

metadata
#

span 和 event 都关联有 Metadata 类型信息：

impl<'a> Metadata<'a>

// 创建 Metadata 对象
pub const fn new(
    name: &'static str, // 缺省：file:line
    target: &'a str, // 缺省：crate::module
    level: Level,
    fields: FieldSet,
    kind: Kind， // 可选值: EVENT，SPAN，HINT
    // 以下可选的参数，为 Metadata 指定源码位置：
    file: Option<&'a str>,
    line: Option<u32>,
    module_path: Option<&'a str>,
) -> Metadata<'a>

Subscriber::enable() 方法可以使用 span 或 event 关联的 Metadata 来对它们进行过滤。

log crate 互操作
#

创建 event 的 trace!, debug!, info! 等宏名称和 log crate 提供日志宏名称相同, 可以直接替换它们,但 tracing 的 event 包含了更丰富的结构化信息（Metadata）。

use std::{error::Error, io};
use tracing::{debug, error, info, span, warn, Level};

#[tracing::instrument]
pub fn shave(yak: usize) -> Result<(), Box<dyn Error + 'static>> {
    debug!(excitement = "yay!", "hello! I'm gonna shave a yak.");
    if yak == 3 {
        warn!("could not locate yak!");
        return Err(io::Error::new(io::ErrorKind::Other, "shaving yak failed!").into());
    } else {
        debug!("yak shaved successfully");
    }
    Ok(())
}

pub fn shave_all(yaks: usize) -> usize {
    let _span = span!(Level::TRACE, "shaving_yaks", yaks).entered();
    info!("shaving yaks");
    let mut yaks_shaved = 0;
    for yak in 1..=yaks {
        let res = shave(yak);
        debug!(yak, shaved = res.is_ok());

        if let Err(ref error) = res {
            error!(yak, error = error.as_ref(), "failed to shave yak!");
        } else {
            yaks_shaved += 1;
        }
        debug!(yaks_shaved);
    }
    yaks_shaved
}

tracing crate 和 log crate 互操作：

tracing 可以将自身的 span 和 event 转换为 log crate 消费的 log records；
反过来，tracing subscribers 可以将 log crate 发送的 log records 当作 tracing events 来消费 (需要使用 tracing-log crate)；

tracing 将 span 和 event 转换为 log record：需要配置如下两个 feature：

log feature: 在没有激活 tracing Subscriber 的情况下，将 tracing event/span 转换为 log record;
log-always feature: 在激活了 tracing Subscriber 的情况下，也将 tracing event/span 转换为 log record;

生成的 log record 包含 span/event 的 fileds 和 metadata（如 target，level，module path，file，line 和 number 等）。span 的 entered/exited/close()也会创建 log record，它们的 log target 为 tracing::span。

消费 log records：tracing-log crate 提供了兼容层，它让 tracing subscriber 使用 tracing event 来消费和记录 log crate 发送的 records。适合于使用 log crate 的 APIs (而不是 tracing event APIs）来记录日志的库，否则会导致这些日志记录不被输出打印。

//! src/main.rs
use tracing::subscriber::set_global_default;
// path 是标识符，不支持短横杠，需要将 cargo 的 package name 中的短横杠转为下划线。
use tracing_bunyan_formatter::{BunyanFormattingLayer, JsonStorageLayer};
use tracing_subscriber::{layer::SubscriberExt, EnvFilter, Registry};
use tracing_log::LogTracer;

#[tokio::main]
async fn main() -> std::io::Result<()> {
    // Redirect all `log`'s events to our subscriber
    LogTracer::init().expect("Failed to set logger");

    let env_filter = EnvFilter::try_from_default_env()
        .unwrap_or_else(|_| EnvFilter::new("info"));

    let formatting_layer = BunyanFormattingLayer::new(
        "zero2prod".into(),
        std::io::stdout
    );

    let subscriber = Registry::default()
        .with(env_filter)
        .with(JsonStorageLayer)
        .with(formatting_layer);

    set_global_default(subscriber).expect("Failed to set subscriber");
    // [...]
}

subscriber
#

tracing::subscriber::Subscriber trait 定义了收集 trace/event 的函数接口：

enabled() : 根据 Metadata 来判断是否要记录该 record；
new_span(): 根据 Attributes 返回一个 span ID；
enter(): 开启一个新的 span；
exit(): 退出（完成）一个 span；

tracing crate 没有实现 该 trait，而是由其它 crate 实现，如 tracing-subscriber crate。

pub trait Subscriber: 'static {
    // Required methods
    fn enabled(&self, metadata: &Metadata<'_>) -> bool;
    fn new_span(&self, span: &Attributes<'_>) -> Id;
    fn record(&self, span: &Id, values: &Record<'_>);
    fn record_follows_from(&self, span: &Id, follows: &Id);
    fn event(&self, event: &Event<'_>);
    fn enter(&self, span: &Id);
    fn exit(&self, span: &Id);

    // Provided methods
    fn on_register_dispatch(&self, subscriber: &Dispatch) { ... }
    fn register_callsite(&self, metadata: &'static Metadata<'static> ) -> Interest { ... }
    fn max_level_hint(&self) -> Option<LevelFilter> { ... }
    fn event_enabled(&self, event: &Event<'_>) -> bool { ... }
    fn clone_span(&self, id: &Id) -> Id { ... }
    fn drop_span(&self, _id: Id) { ... }
    fn try_close(&self, id: Id) -> bool { ... }
    fn current_span(&self) -> Current { ... }
    unsafe fn downcast_raw(&self, id: TypeId) -> Option<*const ()> { ... }
}

tracing::subscriber::set_default()/set_global_default()/with_default() 函数用于设置当前线程或全局的 subscriber（一般由 subscriber 的 init() 等方法自动设置）：

set_default()：为当前线程设置缺省的 Subscribe 实现；
set_global_default()：为程序所有线程设置缺省的 Subscribe 实现；
with_default()：为闭包代码指定使用的缺省 Subscribe 实现；

// FooSubscriber 实现了 Subscriber
let my_subscriber = FooSubscriber::new();

// 全局 subscriber
tracing::subscriber::set_global_default(my_subscriber).expect("setting tracing default failed");

// 局部闭包 Subscribe，可以按需创建多个 subscriber，分别来使用。
tracing::subscriber::with_default(my_subscriber, || {
    // 闭包内的 trace/event 将被 my_subscriber 记录
})

set_global_default() 的底层创建一个 tracing::dispatcher::Dispatch 对象，然后设置它为全局 dispatcher：

pub fn set_global_default<S>(subscriber: S) -> Result<(), SetGlobalDefaultError> where S: Subscriber + Send + Sync + 'static,
{
    crate::dispatcher::set_global_default(crate::Dispatch::new(subscriber))
}

tracing::dispatcher::Dispatch 对象负责发送 trace 数据给 Subscriber 实现：

set_default()：为当前线程设置缺省的 Dispatch；
set_global_default()：为程序所有线程设置缺省的 Dispatch；
with_default() ：为闭包代码指定使用的缺省 Dispatch；
get_default()：返回当前线程使用的 Dispatch；

pub struct Dispatch { /* private fields */ }
// 从 Subscriber 实现来创建 Dispatch
pub fn new<S>(subscriber: S) -> Dispatch where S: Subscriber + Send + Sync + 'static,

// 创建一个 dispatch
use dispatcher::Dispatch;
let my_subscriber = FooSubscriber::new();
let my_dispatch = Dispatch::new(my_subscriber);

// 使用方式 1: 为闭包函数设置缺省 Subscribe
dispatcher::with_default(&my_dispatch, || {
    // my_subscriber is the default
});

// 使用方式 2: 为全局所有线程设置缺省 Subscribe
dispatcher::set_global_default(my_dispatch)
    .expect("global default was already set!");
// `my_subscriber` is now the default

// 使用方式 3: 为当前线程设置缺省 Subscribe
dispatcher::set_default(my_dispatch)
    .expect("default was already set!");

例子
#

#![allow(dead_code)]

#[tracing::instrument]
fn trace_me(a: u32, b: u32) -> u32 {
    tracing::info!("trace_me info message");
    a + b
}

#[derive(Debug)]
struct MyStruct {
    field_a: u8,
    field_b: String,
}

#[tokio::main]
pub async fn main() {
    //let subscriber = tracing_subscriber::FmtSubscriber::new();

    let subscriber = tracing_subscriber::fmt()
        .compact()
        .with_file(true)
        .with_line_number(true)
        .with_thread_ids(true)
        .with_target(true)
        .with_ansi(true)
        // tracing=trace 的 key 为 crate 或 module 名称，这时指定运行的 --binary tracing 的日志级别
        .with_env_filter("tracing=trace,tokio=trace,runtime=trace")
        //.pretty()
        .finish();

    tracing::subscriber::set_global_default(subscriber).unwrap();

    //console_subscriber::init();

    tracing::warn!("just a test");

    trace_me(2, 3);

    let s = MyStruct{field_a: 8, field_b: "fieldB value".to_string()};

    // 对于 span, 必须在 name/id 后添加 k=v
    tracing::error_span!("myerrorspan", ?s);  // 这个不会出发打印日志，但指定了后续 event 的 span context
    // tracing::error_span!(?s, "myerrorspan"); // 报错

    // 对于 event, 分两种情况:
    // 1. 如果有 mesage, 自定义 field 都必须位于 message 之前;
    // 2. 如果没有 message, 则可以使用 field=value 形式来定义任意 field.
    tracing::error!(target: "myerrorspan", ?s, s.field_a, "just a debug message2"); // 有 message
    tracing::error!(target: "myerrorspan", ?s, s.field_a, a = "b");  // 没有 message

    // 在 enter _span drop 前, 后续的 event 都自动关联该 span
    let _span = tracing::error_span!("my_enter_span", ?s).entered();
    tracing::error!(?s, s.field_a, a = "c");

    // 子 span, 打印 event 时会自动先后打印所属的 span
    let _span = tracing::error_span!("my_enter_span2", ?s).entered();
    tracing::error!(?s, s.field_a, a = "d");

    //std::thread::sleep_ms(200000);
}

输出日志:

zj@a:~/codes/rust/mydemo$ cargo run --bin tracing
# 没有 span，tracing module
2024-03-07T11:54:16.136269Z  WARN ThreadId(01) tracing: src/bin/tracing.rs:42: just a test
# span trace_me 下的 tracing module
2024-03-07T11:54:16.136417Z  INFO ThreadId(01) trace_me: tracing: src/bin/tracing.rs:5: trace_me info message a=2 b=3
2024-03-07T11:54:16.136475Z ERROR ThreadId(01) tracing: src/bin/tracing.rs:49: just a debug message1 s=MyStruct { field_a: 8, field_b: "fieldB value" }
2024-03-07T11:54:16.136558Z ERROR ThreadId(01) myerrorspan: src/bin/tracing.rs:52: just a debug message2 s=MyStruct { field_a: 8, field_b: "fieldB value" } s.field_a=8
2024-03-07T11:54:16.136585Z ERROR ThreadId(01) myerrorspan: src/bin/tracing.rs:53: s=MyStruct { field_a: 8, field_b: "fieldB value" } s.field_a=8 a="b"
2024-03-07T11:54:16.136791Z ERROR ThreadId(01) my_enter_span: tracing: src/bin/tracing.rs:56: s=MyStruct { field_a: 8, field_b: "fieldB value" } s.field_a=8 a="c" s=MyStruct { field_a: 8, field_b: "fieldB value" }
# my_enter_span 下的 my_enter_span2 下的 tracing module
2024-03-07T11:54:16.136844Z ERROR ThreadId(01) my_enter_span:my_enter_span2: tracing: src/bin/tracing.rs:59: s=MyStruct { field_a: 8, field_b: "fieldB value" } s.field_a=8 a="d" s=MyStruct { field_a: 8, field_b: "fieldB value" } s=MyStruct { field_a: 8, field_b: "fieldB value" }

secrecy crate
#

由于 tracing 的 #[instrument] 默认将所有函数参数添加到日志输出，对于 HTTP Handler 函数来说，可能包含敏感信息（如用户提交的表单或 Body 数据等），可以使用 secrecy crate 来解决这个问题（它通过重新定义嵌入的字段类型的 Debug trait 来实现隐藏数据输出）。

注意：secrecty 不能和 clip 的 Args 联合使用，会提示不满足 trait bound。

//! src/configuration.rs
use secrecy::SecretBox;

// [..]
#[derive(serde::Deserialize)]
pub struct DatabaseSettings {
  // [...]
  pub password: SecretBox<String>,
}

//! src/configuration.rs
use secrecy::ExposeSecret;

// [...]

impl DatabaseSettings {
  pub fn connection_string(&self) -> Secret<String> {
      Secret::new(format!(
      "postgres://{}:{}@{}:{}/{}",
      // [...]
      self.password.expose_secret(),
      // [...]
      ))
    }
  pub fn connection_string_without_db(&self) -> Secret<String> {
      Secret::new(format!(
      "postgres://{}:{}@{}:{}",
      // [...]
      self.password.expose_secret(),
      // [...]
      ))
  }
}

log crate
#

log crate 是 Rust core team 维护的轻量级日志门面框架（lightweight logging facade），它自定义了 log 相关的 API 而不包含实现。所以需要和其它 log 实现库，如 log4s，一起使用。

use log;

pub fn shave_the_yak(yak: &mut Yak) {
    log::trace!("Commencing yak shaving");

    loop {
        match find_a_razor() {
            Ok(razor) => {
                log::info!("Razor located: {}", razor);
                yak.shave(razor);
                break;
            }
            Err(err) => {
                log::warn!("Unable to locate a razor: {}, retrying", err);
            }
        }
    }
}

log4rs 集成
#

# set a refresh rate
refresh_rate: 30 seconds

# appenders
appenders:
# this appender will append to the console
  stdout:
    kind: console
# this appender will append to a log file
  requests:
    kind: file
    path: "log/requests.log"
# this is a simple string encoder - this will be explained below
    encoder:
      pattern: "{d} - {m}{n}"

# the appender that prints to stdout will only print if the log level of the message is warn or above
root:
  level: warn
  appenders:
    - stdout

# set minimum logging level - log messages below the mnimum won't be recorded
loggers:
  app::backend::db:
    level: info

  app::requests:
    level: info
    appenders:
      - requests
    additive: false

rolling_appender:
 kind: rolling_file
 path: log/foo.log
 append: true
 encoder:
   kind: pattern
   pattern: "{d} - {m}{n}"
 policy:
   kind: compound
   trigger:
     kind: size
     limit: 10 mb
 # upon reaching the max log size, the file simply gets deleted on successful roll
   roller:
     kind: delete