Rust 日志（log 与 tracing）

程序出问题的时候，你最想知道的是它出事前在做什么。日志（logging）就是干这个的。日志就像船上的航海日志：一条条简短的记录，每条都带着时间和重要程度，事后翻看就能弄清楚发生了什么。

你当然可以到处写 println!，但很快就会碰到它的局限：不改代码就没法关掉它；没法说“只给我看警告”；而且调试用的信息会和程序真正的输出混在一起。Rust 的日志 crate 把这三个问题都解决了。这一页会介绍最流行的两个：log（配合 env_logger）和 tracing。

为什么不直接用 println!？

用一张表就能看出区别：

	println!	日志 crate
不重新编译就能打开或关闭	不能	能，用 RUST_LOG 环境变量
级别（error、warn、info……）	没有	有
显示消息来自哪里	不显示	显示（模块名）
输出到哪里	stdout	默认是 stderr（env_logger）

最后一行比看上去更重要。stdout（标准输出）是程序真正的结果，别人可能会把它重定向到文件或者传给另一个程序。stderr（标准错误）是旁路，用来输出关于这次运行的信息。日志应该写到 stderr，这样 my_app > result.txt 只会保存结果，而日志照样显示在终端里。

log 门面与 env_logger

log crate 提供了 5 个宏，每个级别一个，按严重程度从高到低依次是：error!、warn!、info!、debug! 和 trace!。它们用起来和 println! 一模一样，{} 格式化的写法也相同。

但单靠 log 什么也打印不出来。它是一个门面（facade）：一套所有库都能使用的标准宏，却不决定消息怎么显示。真正把消息写出来的是日志器（logger），由你的应用来选。最简单的一个是 env_logger。把两个 crate 都加进项目：

cargo add log env_logger

[dependencies]
log = "0.4"
env_logger = "0.11"

然后在 main 的开头调用一次 env_logger::init()，就可以尽情记录日志了：

use log::{debug, error, info, warn};

fn divide(a: f64, b: f64) -> Option<f64> {
    debug!("divide 被调用：a={a}, b={b}");
    if b == 0.0 {
        warn!("拒绝把 {a} 除以零");
        return None;
    }
    Some(a / b)
}

fn main() {
    env_logger::init();
    info!("计算器启动");

    println!("10 / 4 = {:?}", divide(10.0, 4.0));
    println!("1 / 0 = {:?}", divide(1.0, 0.0));

    error!("错误日志就长这样");
}

输出：

10 / 4 = Some(2.5)
1 / 0 = None

▶ 动手试一试

上面的输出只有 stdout，也就是程序真正的结果。日志行写到了 stderr，在 Playground 里它们显示在单独的“Standard Error”区域。

注意一点：env_logger 默认只显示错误。想看到更多，运行程序时要设置 RUST_LOG 环境变量。下面是我们在终端里用 RUST_LOG=debug cargo run 运行时，stderr 和 stdout 合在一起的样子（每个时间戳都换成了 …，你看到的会是当前的日期和时间）：

[… INFO  my_app] 计算器启动
[… DEBUG my_app] divide 被调用：a=10, b=4
10 / 4 = Some(2.5)
[… DEBUG my_app] divide 被调用：a=1, b=0
[… WARN  my_app] 拒绝把 1 除以零
1 / 0 = None
[… ERROR my_app] 错误日志就长这样

每一行日志都显示了级别和它来自的模块（my_app，也就是 crate 的名字）。没有方括号的普通行是 println! 的输出。

用 RUST_LOG 选择要看的内容

设置一个级别，会显示这个级别以及所有更严重的级别。所以 RUST_LOG=warn 显示警告和错误，RUST_LOG=trace 显示全部。

RUST_LOG=debug cargo run     # debug、info、warn、error
RUST_LOG=warn cargo run      # 只有 warn 和 error
RUST_LOG=off cargo run       # 完全没有日志

在 Windows PowerShell 里，要先设置变量：$env:RUST_LOG="debug"; cargo run。

你还可以按模块过滤。某个库的日志太多，或者你只关心自己代码的某一部分时，这个功能特别好用。下面这个程序有一个 db 模块：

use log::{debug, info};

mod db {
    use log::{debug, trace};

    pub fn find_user(id: u32) -> Option<&'static str> {
        trace!("查找用户 {id}");
        let name = match id {
            1 => Some("Ada"),
            2 => Some("Linus"),
            _ => None,
        };
        debug!("查找结果：{name:?}");
        name
    }
}

fn main() {
    env_logger::init();
    info!("服务器启动");

    for id in [1, 3] {
        match db::find_user(id) {
            Some(name) => println!("用户 {id}：{name}"),
            None => println!("用户 {id}：未找到"),
        }
    }

    debug!("所有查找完成");
}

输出：

用户 1：Ada
用户 3：未找到

▶ 动手试一试

下面是我们试过的几个过滤规则，以及它们输出到 stderr 的内容（时间戳换成了 …）：

$ RUST_LOG=my_app=trace cargo run       # 我们 crate 的所有日志
[… INFO  my_app] 服务器启动
[… TRACE my_app::db] 查找用户 1
[… DEBUG my_app::db] 查找结果：Some("Ada")
用户 1：Ada
[… TRACE my_app::db] 查找用户 3
[… DEBUG my_app::db] 查找结果：None
用户 3：未找到
[… DEBUG my_app] 所有查找完成

$ RUST_LOG=my_app::db=debug cargo run   # 只看 db 模块，debug 及以上
[… DEBUG my_app::db] 查找结果：Some("Ada")
用户 1：Ada
[… DEBUG my_app::db] 查找结果：None
用户 3：未找到

多条规则可以用逗号组合：RUST_LOG=info,my_app::db=trace 的意思是“所有地方都显示 info，但 db 模块显示到 trace”。有个小陷阱：过滤规则里用的是带下划线的 crate 名。一个叫 my-app 的包，记录日志时的名字是 my_app。

在代码里设置默认级别

很多时候，你希望即使没设置 RUST_LOG，也能看到 info 级别的日志。这时用 env_logger::Builder 代替 init()。还可以顺便关掉时间戳，对小工具来说很方便：

use env_logger::Env;
use log::{debug, info};

fn main() {
    // 没有设置 RUST_LOG 时，显示 `info` 及以上级别。
    env_logger::Builder::from_env(Env::default().default_filter_or("info"))
        .format_timestamp(None)
        .init();

    info!("应用已启动");
    debug!("只有设置 RUST_LOG=debug 才能看到这一行");

    let total: u32 = (1..=10).sum();
    println!("合计 = {total}");
}

输出：

合计 = 55

▶ 动手试一试

没有时间戳，cargo run 实际输出到 stderr 的内容就很简短清爽：

[INFO  my_app] 应用已启动

用 tracing 做结构化日志

log 给你的是一行行文本。tracing 给你的是带数据的事件（event），并把它们归入一个个 span。它由 Tokio 团队开发，axum 这类异步 Web 框架用的就是它。这样添加：

cargo add tracing tracing-subscriber

要掌握三个概念：

• 事件（event）就像日志行：info!、warn! 等等，名字和 log 里的一样。
• 字段（field）以 key = value 的形式附带数据：info!(user_id = 42, "已登录")。工具可以直接按这些字段搜索和过滤，不用去解析文本。
• span 描述一段工作，比如“正在处理 7 号订单”。span 里的每个事件都会打上它的标记。

和 log 一样，tracing 也需要一个 subscriber（订阅者）才能显示内容。tracing_subscriber::fmt() 是标准的那个。有一点出乎意料：它默认写到 stdout，所以我们用 .with_writer(std::io::stderr) 把它改到 stderr：

use tracing::{info, info_span, warn};

fn main() {
    tracing_subscriber::fmt()
        .with_writer(std::io::stderr)
        .init();

    info!(user_id = 42, "已登录");

    let span = info_span!("checkout", order_id = 7);
    let _guard = span.enter();

    let items = [1200, 350, 999];
    let total: u32 = items.iter().sum();
    info!(items = items.len(), total, "购物车已算好总额");

    if total > 2000 {
        warn!(total, limit = 2000, "订单需要人工审核");
    }

    println!("订单总额：{total}");
}

输出：

订单总额：2549

▶ 动手试一试

这是我们运行时 stderr 的内容（时间戳换成了 …，去掉了颜色）：

…  INFO my_app: 已登录 user_id=42
…  INFO checkout{order_id=7}: my_app: 购物车已算好总额 items=3 total=2549
…  WARN checkout{order_id=7}: my_app: 订单需要人工审核 total=2549 limit=2000

看到后两行开头的 checkout{order_id=7} 了吗？那就是 span。只要 _guard 还活着，每个事件都在 checkout “里面”。只写 total 是 total = total 的简写。

#[instrument]：每次调用一个 span

手动创建 span 很快就会让人厌烦。在函数上加 #[instrument]，tracing 就会为每次调用创建一个 span，并把参数记录为字段（参数需要实现 Debug）：

use tracing::{debug, info, instrument};

#[instrument]
fn apply_discount(price: u32, percent: u32) -> u32 {
    let off = price * percent / 100;
    debug!(off, "折扣已算好");
    price - off
}

fn main() {
    tracing_subscriber::fmt()
        .with_max_level(tracing::Level::DEBUG)
        .with_writer(std::io::stderr)
        .init();

    let final_price = apply_discount(2500, 10);
    info!(final_price, "完成");
    println!("最终价格：{final_price}");
}

输出：

最终价格：2250

▶ 动手试一试

我们运行时 stderr 的内容：

… DEBUG apply_discount{price=2500 percent=10}: my_app: 折扣已算好 off=250
…  INFO my_app: 完成 final_price=2250

除非你另行设置，fmt() 这个 subscriber 只显示 info 及以上级别，所以我们加了 .with_max_level(tracing::Level::DEBUG)。如果想让 RUST_LOG 像在 env_logger 里那样生效，就打开 env-filter 这个 feature，并使用 EnvFilter：

[dependencies]
tracing = "0.1"
tracing-subscriber = { version = "0.3", features = ["env-filter"] }

use tracing_subscriber::EnvFilter;

tracing_subscriber::fmt()
    .with_env_filter(EnvFilter::from_default_env())
    .with_writer(std::io::stderr)
    .init();

该选哪一个？

• 小型命令行工具或脚本？ 用 log + env_logger。配置简单，纯文本，搞定。
• Web 服务器、异步代码，或者同时运行很多任务？ 用 tracing。span 会记住一条消息属于哪个请求，即使有几百个请求同时在跑。
• 在写库？ 只使用宏（log 或 tracing），永远不要调用 init()。日志怎么显示，由应用来决定。

这个选择也不是一锤子买卖。tracing-subscriber 的默认配置也会接收来自 log crate 的消息，所以不管库用的是哪一个，日志都会显示在一起。

常见误区

忘了设置日志器。如果你从来没调用过 env_logger::init()（或者 tracing subscriber 的 init()），这些宏照样能编译通过，然后……什么也不打印。没有错误，也没有警告。日志不见了的时候，先检查这一点，再检查 RUST_LOG。

调用两次 init()。全局只能有一个日志器，第二次调用会 panic。真实的信息是这样的：

thread 'main' (12345) panicked at …/env_logger-0.11.11/src/logger.rs:901:16:
env_logger::init should not be called after logger initialized: SetLoggerError(())

意思是“日志器已经初始化过了，不应该再调用 env_logger::init”。只在 main 的最开头调用一次。在测试里，用 let _ = env_logger::builder().is_test(true).try_init();，它会返回一个错误，而不是 panic。

span 的 guard 一创建就被丢弃了。let _ = span.enter(); 看起来没什么问题，但 _ 并不是变量名：guard 在同一行就被丢弃了，所以 span 立刻结束。我们运行时打印出来的是 INFO my_app: 正在处理请求，完全没有 span。给 guard 起个名字，比如 let _guard = span.enter();，这样它就会一直活到作用域结束。

总结

• 用日志 crate 代替 println!，就能按级别过滤，还能把日志放在 stderr，和真正的输出分开。
• log 提供 error!、warn!、info!、debug!、trace!；env_logger::init() 负责把它们打印出来。
• RUST_LOG 控制你能看到什么：RUST_LOG=debug、RUST_LOG=my_app=trace、RUST_LOG=info,my_app::db=trace。
• tracing 增加了结构化字段（info!(user_id = 42, "已登录")）和 span；#[instrument] 为每次函数调用创建一个 span。
• 库只使用宏；由应用在一开始设置一次日志器。

小测验

小测验

1. 运行一个使用 env_logger 的程序，没有设置 RUST_LOG。你能看到哪些日志行？

全部 只有 info! 及以上 只有 error! 一条也没有

2. env_logger 默认把日志消息写到哪里？

stdout stderr 一个叫 log.txt 的文件

3. RUST_LOG=warn 会显示什么？

只有警告 警告以及所有不那么严重的级别 警告和错误

4. 在函数上加 #[instrument] 有什么作用？

给函数计时并打印耗时 为每次调用创建一个 span，并把参数作为字段 让函数运行得更快 为整个程序打开日志

5. 你在写一个库 crate。它应该怎样处理日志？

使用日志宏，但让应用来设置日志器 库加载时调用 env_logger::init() 使用 println!，这样总能显示出来

得分: 0 / 5

延伸阅读

• log crate 文档（英文）：5 个宏和门面的工作原理，还有写给库作者的建议。
• env_logger 文档（英文）：完整的 RUST_LOG 语法和 Builder 的所有选项。
• tracing 文档（英文）：深入讲解 span、事件、字段和 #[instrument]。
• tracing-subscriber 文档（英文）：格式化选项、EnvFilter 和 JSON 输出。
• Getting started with Tracing — Tokio（英文）：维护 tracing 的团队写的入门教程，很友好。