配置 Rust Tracing 库

rust / tracing

有段日子没有用到 rust 了，最近想折腾一下日志配置，结果又用掉了不少时间。

前言

日志应该是目前公认程序中的一个重要部分，rust 甚至很早就有了 log crate， 不过 log crate 只定义了记 log 的方式，真正输出的工作还要有 fern、 log4rs 这些 crate 来进行实操，这些我以前也都用过，时间应该有个两年了， 不晓得现在会不会简单一点。

调研

随便搜了下 rust 什么日志库好用，一个新的系列被很多人推荐：tracing。

splash.svg

Tracing 虽然不是官方库，但是由 tokio 项目维护， tokio 的名字相信 rust 用比较多的朋友会比较熟悉了， 我觉得基本可以认为是半个官方库了，可以放心使用。

不过 tracing 的使用方式相对于 log crate 却没有什么变化， 一样是 tracing crate 定义使用方式，tracing-subscriber 实现日志的输出， 由于我还需要输出日志到文件，所以还用到了另一个 crate：tracing-appender。 相对于其他有类似懒人包或者已经内嵌日志模块的部分语言或框架， 这属实是不够新手友好了，别难过，因为这还不是最坏的部分，后面还有更不友好的内容， 那时候难过也不迟。

需求

简单总结下我的需求，我需要程序同时在控制台和文件中输出日志， 日志中需要包含本地时间、代码位置、以及线程的名字。

本地时间这一点其实是后面加上去的，因为默认的 tracing 输出的时间是格林威治时间， 我觉得还是本地时间看着舒服一些。

配置

Cargo.toml

加依赖一般情况下，不是一个很难的事情，多数时间我们 cargo add 几下也就可以了， 不过对于 tracing 来说也没那么简单，可能一些朋友很快会猜到，是的， tracing-subscriber 和 time 都需要指定 feature：

[package]
name = "tracing-test"
version = "0.1.0"
edition = "2021"

[dependencies]
time = { version = "0.3.36", features = ["std", "formatting", "parsing", "local-offset"] }
tracing = "0.1.41"
tracing-appender = "0.2.3"
tracing-subscriber = { version = "0.3.19", features = ["std", "registry", "fmt", "local-time"] }

这是我实验成功的版本，还有不少水分，如果你只是想快速建立一个输出日志的环境， 文章末尾有一个更精简的版本，下面一点篇幅我想讲一下我的思路， 给不熟悉 rust 的朋友们一些提示，来帮助我们确定自己需要的 feature， feature 是 rust 很有意思的一个设定，我们可以通过这个设定， 只选择库中自己需要的功能，很多库都提供了 feature 的配置方式， 但是这个设定无疑增加了新手的入门门槛，rust 小白多数时间需要的是开箱即用的配置， 而不是去慢慢研究哪个 feature 是我所需要的。不同的库对这一功能实现的偏好也不相同， 有些库会默认开启所有功能，有些库则不会，比如我们今天遇到的这个。

确定 feature 首先当然是要阅读说明，如果说明解释得比较详尽， 看说明可以让我们少走很多弯路。不过也是有因为我们不熟悉， 或是说明写得不够透彻的情况。

main.rs

另一个确定 feature 的方法就是从代码入手了， 一般情况下我的做法是找一个比较简洁的 demo，先把它编过，然后再改成我想要的样子， 比如这段是我已经改好的代码：

use tracing_subscriber::fmt;
use tracing_subscriber::layer::SubscriberExt;
use tracing_subscriber::util::SubscriberInitExt;

fn main() {
    init_log();
    tracing::info!("Hello, world!");
}

fn init_log() {
    let timer_fmt = time::format_description::parse(
        "[year]-[month padding:zero]-[day padding:zero] [hour]:[minute]:[second].[subsecond digits:6]",
    )
    .expect("Failed to parse time format");

    let time_offset =
        time::UtcOffset::current_local_offset().unwrap_or_else(|_| time::UtcOffset::UTC);
    let timer = fmt::time::OffsetTime::new(time_offset, timer_fmt);

    let file_appender = tracing_appender::rolling::daily("logs", "test.log");

    let file_layer = tracing_subscriber::fmt::Layer::new()
        .compact()
        .with_timer(timer.clone())
        .with_file(true)
        .with_line_number(true)
        .with_thread_names(true)
        .with_ansi(false)
        .with_writer(file_appender);

    let console_layer = tracing_subscriber::fmt::Layer::new()
        .pretty()
        .with_timer(timer)
        .with_file(true)
        .with_line_number(true)
        .with_thread_names(true);

    tracing_subscriber::Registry::default()
        .with(file_layer)
        .with(console_layer)
        .init();
}

应该比较容易理解，这段代码配置了日志的输出方式，输出方式就是需求中描述的内容， 接着输出一行日志，然后退出。

还原过程

那么为了还原确定 feature 的过程，我们把所有 feature 全部删掉， 代码中 use 的内容我们也去掉，为什么去掉 use，其实这也是其中的一个坑位， 我们先把它挖开，重编，很自然会报错，不过我们每次都只看第一个报错：

error[E0433]: failed to resolve: use of undeclared crate or module `fmt`
  --> src/main.rs:14:17
   |
14 |     let timer = fmt::time::OffsetTime::new(time_offset, timer_fmt);
   |                 ^^^ use of undeclared crate or module `fmt`

这个是因为它不认识 fmt，fmt 是 tracing_subscriber 的一个模块， 我们加上 use tracing_subscriber::fmt;，重编：

error[E0433]: failed to resolve: could not find `OffsetTime` in `time`
  --> src/main.rs:15:28
   |
15 |     let timer = fmt::time::OffsetTime::new(time_offset, timer_fmt);
   |                            ^^^^^^^^^^ could not find `OffsetTime` in `time`
   |
note: found an item that was configured out
  --> C:\Users\tricks1\scoop\persist\rustup\.cargo\registry\src\index.crates.io-6f17d22bba15001f\tracing-subscriber-0.3.19\src\fmt\time\mod.rs:21:21
   |
21 | pub use time_crate::OffsetTime;
   |                     ^^^^^^^^^^
note: the item is gated behind the `time` feature
  --> C:\Users\tricks1\scoop\persist\rustup\.cargo\registry\src\index.crates.io-6f17d22bba15001f\tracing-subscriber-0.3.19\src\fmt\time\mod.rs:19:7
   |
19 | #[cfg(feature = "time")]
   |       ^^^^^^^^^^^^^^^^

仔细阅读输出错误，你会发现，不认识 OffsetTime 的原因 cargo 说了， 要打开 tracing-subscriber 的 time feature，打开后再重编：

error[E0599]: no function or associated item named `current_local_offset` found for struct `UtcOffset` in the current scope
   --> src/main.rs:14:26
    |
14  |         time::UtcOffset::current_local_offset().unwrap_or_else(|_| time::UtcOffset::UTC);
    |                          ^^^^^^^^^^^^^^^^^^^^ function or associated item not found in `UtcOffset`
    |
note: if you're trying to build a new `UtcOffset` consider using one of the following associated functions:
      UtcOffset::__from_hms_unchecked
      UtcOffset::from_hms
      UtcOffset::from_whole_seconds
      UtcOffset::parse
   --> C:\Users\tricks1\scoop\persist\rustup\.cargo\registry\src\index.crates.io-6f17d22bba15001f\time-0.3.37\src\utc_offset.rs:85:5
    |
85  |       pub const unsafe fn __from_hms_unchecked(hours: i8, minutes: i8, seconds: i8) -> Self {
    |       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
...
108 | /     pub const fn from_hms(
109 | |         hours: i8,
110 | |         minutes: i8,
111 | |         seconds: i8,
112 | |     ) -> Result<Self, error::ComponentRange> {
    | |____________________________________________^
...
184 |       pub const fn from_whole_seconds(seconds: i32) -> Result<Self, error::ComponentRange> {
    |       ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
...
409 | /     pub fn parse(
410 | |         input: &str,
411 | |         description: &(impl Parsable + ?Sized),
412 | |     ) -> Result<Self, error::Parse> {
    | |___________________________________^

这个错误就没有那么明显了对不对， 但是它同样是找不到函数 time::UtcOffset::current_local_offset， 我们可以 F12 打开 UtcOffset 的代码文件，来寻找 current_local_offset 函数， 注意如果你不是在用 VSCode，那可能转向定义的快捷键不是 F12：

    #[cfg(feature = "local-offset")]
    pub fn current_local_offset() -> Result<Self, error::IndeterminateOffset> {
        let now = OffsetDateTime::now_utc();
        local_offset_at(now).ok_or(error::IndeterminateOffset)
    }

所以我们要打开 time 的 local-offset feature，再重编：

error[E0599]: no method named `with` found for struct `Registry` in the current scope
    --> src/main.rs:36:10
     |
35   | /     tracing_subscriber::Registry::default()
36   | |         .with(file_layer)
     | |         -^^^^ method not found in `Registry`
     | |_________|
     |
     |
    ::: C:\Users\tricks1\scoop\persist\rustup\.cargo\registry\src\index.crates.io-6f17d22bba15001f\tracing-subscriber-0.3.19\src\layer\mod.rs:1502:8
     |
1502 |       fn with<L>(self, layer: L) -> Layered<L, Self>
     |          ---- the method is available for `Registry` here
     |
     = help: items from traits can only be used if the trait is in scope
help: trait `SubscriberExt` which provides `with` is implemented but not in scope; perhaps you want to import it
     |
1    + use tracing_subscriber::prelude::__tracing_subscriber_SubscriberExt;
     |

For more information about this error, try `rustc --explain E0599`.

help 有一个提示，我们要 import SubscriberExt， 源代码补一个 use tracing_subscriber::layer::SubscriberExt，再编译：

error[E0599]: no method named `init` found for struct `Layered` in the current scope
  --> src/main.rs:39:10
   |
36 | /     tracing_subscriber::Registry::default()
37 | |         .with(file_layer)
38 | |         .with(console_layer)
39 | |         .init();
   | |_________-^^^^
   |
  ::: C:\Users\tricks1\scoop\persist\rustup\.cargo\registry\src\index.crates.io-6f17d22bba15001f\tracing-subscriber-0.3.19\src\util.rs:89:8
   |
89 |       fn init(self) {
   |          ---- the method is available for `Layered<tracing_subscriber::fmt::Layer<Layered<tracing_subscriber::fmt::Layer<Registry, DefaultFields, tracing_subscriber::fmt::format::Format<Compact, OffsetTime<Vec<BorrowedFormatItem<'_>>>>, RollingFileAppender>, Registry>, Pretty, tracing_subscriber::fmt::format::Format<Pretty, OffsetTime<Vec<BorrowedFormatItem<'_>>>>>, Layered<tracing_subscriber::fmt::Layer<Registry, DefaultFields, tracing_subscriber::fmt::format::Format<Compact, OffsetTime<Vec<BorrowedFormatItem<'_>>>>, RollingFileAppender>, Registry>>` here
   |
   = note: the full type name has been written to 'D:\src\rs\tracing-test\target\debug\deps\tracing_test.long-type-11157003815784641205.txt'
   = note: consider using `--verbose` to print the full type name to the console
   = help: items from traits can only be used if the trait is in scope
help: trait `SubscriberInitExt` which provides `init` is implemented but not in scope; perhaps you want to import it
   |
1  + use tracing_subscriber::util::SubscriberInitExt;
   |
help: there is a method `try_init` with a similar name
   |
39 |         .try_init();
   |          ~~~~~~~~

For more information about this error, try `rustc --explain E0599`.
error: could not compile `tracing-test` (bin "tracing-test") due to 1 previous error

这个应该不用解释了， use tracing_subscriber::util::SubscriberInitExt 都给我们写好了，直接加上去重编：

   Compiling tracing-test v0.1.0 (D:\src\rs\tracing-test)
    Finished `dev` profile [unoptimized + debuginfo] target(s) in 0.88s

非常神奇，没有报错了，以防万一我们 cargo run 跑一下程序：

    Finished `dev` profile [unoptimized + debuginfo] target(s) in 0.05s
     Running `target\debug\tracing-test.exe`
  2025-01-16 20:32:19.069147  INFO tracing_test: Hello, world!
    at src/main.rs:6 on main

终端日志正常，再看一下文件日志：

2025-01-16 20:32:19.069028  INFO main tracing_test: src/main.rs:6: Hello, world!

你可能会注意到一个问题，两个日志记录的时间不同， 这应该是日志输出到控制台和文件的时间是不一样的，这是个不大不小的问题， 但是想解决却比较困难，我们可能要定制一个 timer，来确保两次输出的时间完全相同， 这个细节我们就不展开了。经过我们的又一番折腾，代码没有什么变化， 但是 feature 少了很多，现在的 Cargo.toml 清爽了不少：

[package]
name = "tracing-test"
version = "0.1.0"
edition = "2021"

[dependencies]
time = { version = "0.3.36", features = ["local-offset"] }
tracing = "0.1.41"
tracing-appender = "0.2.3"
tracing-subscriber = { version = "0.3.19", features = ["time"] }

总结

其实写这段 demo 的时候也有些插曲，比如如何配置同时输出终端和文件的功能， 因为多数是二选一，而不是二合一，然后就是日志的格式如何配置， 基本上是通过阅读说明和找 demo 试出来的，不再赘述。Rust 总是被吐槽入门门槛高， 其实相对于最开始的版本，rust 的难度已经降了很多，但是因为一些语言本身的设计， 对于新手来说还是略显复杂。不过从新手的角度来看的话，如果没有过早放弃， 其实入门也只是时间问题，一切基本上都是有迹可循的，总结一下我的处理方式：

  1. 阅读说明
  2. 寻找 demo
  3. cargo run，找出第一个报错原因，修复，再 cargo run
  4. 完善为自己的版本。

以上是我这次从头探索 tracing 的一段记录，希望能让 rust 对新手更友好一些。 我也放了一份在 github，有需要可以自取。