Rust 可观测性实战：别再 println 了

"线上 P99 延迟飙了，日志里什么都没有。"

这句话我听过不下十次。每次排查下来，原因都一样——要么是日志不够，出了问题两眼一抹黑；要么是日志太多，关键信息被淹没在 debug 输出的海洋里。

更常见的情况是：本地跑得好好的，上了生产就开始出幺蛾子，但你根本看不到哪里出了问题。

先说结论：可观测性 = 日志（Logs）+ 指标（Metrics）+ 链路追踪（Traces）。 三者缺一不可。Rust 生态在这三个维度上都有成熟工具，而且性能开销可以做到接近零——字面意义上的零。

这篇文章不是 API 文档搬运。我想讲的是：怎么从 println!("请求进来了") 进化到生产级可观测性，中间踩了哪些坑，以及哪些东西其实不需要。

告别 println，拥抱 tracing

Rust 的可观测性基本只有一条路：tokio 的 tracing crate。

不是说 log 不好，而是 tracing 在 log 的基础上加了一个关键能力：Span（跨度）。

Event vs Span：一张图说清楚

时间轴 ─────────────────────────────────────►

Span:  ┌──────────── HTTP POST /users ────────────┐
       │                                            │
       │  Event: 收到请求                            │
       │       ┌── Span: 数据库查询 ──┐              │
       │       │  Event: SELECT ...   │              │
       │       │  Event: 返回 1 行    │              │
       │       └──────────────────────┘              │
       │  Event: 返回 201                            │
       └────────────────────────────────────────────┘

• Event = 一条日志记录，一个时间点。info!("收到请求") 就是一个 Event。
• Span = 一个有开始和结束的时间段，可以嵌套。一次 HTTP 请求、一次数据库查询，都是 Span。

Event 发生在 Span 的上下文里。这意味着你不需要在每条日志里手动写 request_id=xxx——只要在 Span 里记录一次，所有子 Event 自动继承。

这就是 tracing 比 log 强大的根本原因：结构化上下文，而不是平面日志。

最简配置

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

use tracing_subscriber::{layer::SubscriberExt, util::SubscriberInitExt, EnvFilter};
 
fn init_tracing() {
    tracing_subscriber::registry()
        .with(EnvFilter::from_default_env())  // 读 RUST_LOG 环境变量
        .with(tracing_subscriber::fmt::layer())  // 输出到终端
        .init();
}

然后用环境变量控制日志级别：

RUST_LOG=info cargo run           # 只看 info 及以上
RUST_LOG=my_crate=debug cargo run # 只有你的 crate 输出 debug
RUST_LOG=debug,hyper=warn cargo run # 混合配置

一行代码替代所有的 println! 和 env_logger::init()。

#[instrument]：一行代码搞定函数级追踪

这是 tracing 最好用的宏，没有之一：

use tracing::{info, instrument};
 
#[instrument]
async fn create_user(name: &str, email: &str) -> Result<User, Error> {
    info!("开始创建用户");
    // ...
}

调用时自动创建 Span，记录函数名和参数，函数结束时自动关闭 Span。对 async fn 也正确处理了 poll/yield 边界（后面会讲为什么这很重要）。

但默认行为有个问题：它会记录所有参数。 如果参数里有密码、大 JSON body、或者数据库连接池，你就踩坑了。

// ❌ 千万别这样写
#[instrument]
async fn login(user: &str, password: &str) -> Result<Token, Error> {
    // password 会被记录到日志里！
}
 
// ✅ 正确写法
#[instrument(skip(password), fields(user_id = %user))]
async fn login(user: &str, password: &str) -> Result<Token, Error> {
    // password 被跳过，user_id 显式记录
}

#[instrument] 的常用参数：

坑！（重头戏来了）

span.enter() 跨 .await——最经典的异步陷阱

我第一次写 tracing 的时候，这么写的：

// ❌ 这是一个 BUG
let span = tracing::info_span!("process_request");
let _guard = span.enter();
let result = db.query("SELECT ...").await;  // 💥

看起来没问题对吧？Span 进入了，查询做了，guard 离开作用域时自动退出 Span。

问题在于：.await 会让出当前线程。 你的 task 可能被调度到另一个线程上继续执行，但 _guard 还绑定在原来的线程上。结果就是：

• Span 在线程 A 上"进入"了，但在线程 B 上"退出"
• 线程 A 上的 Span 永远不会退出，污染了后续所有请求的上下文
• 线程 B 上根本看不到这个 Span，链路追踪直接断掉

表现： 日志里偶尔出现莫名其妙的嵌套关系，或者某个请求的 Span 突然消失了。

正确写法：

// ✅ 方法一：用 .instrument()
use tracing::Instrument;
 
let result = db.query("SELECT ...")
    .instrument(tracing::info_span!("process_request"))
    .await;
 
// ✅ 方法二：用 #[instrument]（推荐）
#[instrument]
async fn process_request() {
    let result = db.query("SELECT ...").await;  // Span 自动正确管理
}

.instrument() 方法会把 Span 绑定到 Future 上，而不是线程上。每次 poll 时自动进入，yield 时自动退出。

教训：在异步代码里，永远不要手动 span.enter() 然后 .await。用 #[instrument] 或 .instrument()。

Clippy 从 1.61 开始自带 clippy::await_holding_span_guard 检查，建议直接开成 deny。

测试里日志全丢了

写测试的时候加了一堆 info!、debug!，跑测试时终端一片空白。

原因很简单：没有安装 subscriber，所有事件被静默丢弃。

// ❌ 测试里看不到任何日志
#[tokio::test]
async fn test_create_user() {
    info!("开始测试");  // 你看不到这行
    // ...
}

// ✅ 在测试里初始化 subscriber
#[tokio::test]
async fn test_create_user() {
    let _ = tracing_subscriber::fmt()
        .with_test_writer()  // 关键：输出到测试的 stdout
        .try_init();
    info!("开始测试");  // 现在能看到了
    // ...
}

try_init() 而不是 init()，因为多个测试并行时 init() 会 panic（subscriber 只能初始化一次）。

更省事的做法是用 test-log crate：

// 自动初始化，自动输出到测试 stdout
#[test_log::test(tokio::test)]
async fn test_create_user() {
    info!("自动可见");
}

教训：测试里看不到日志，99% 是因为没装 subscriber。用 try_init() 或 test-log。

生产环境开了 debug 级别

microservices 文章里已经提过这个，但我想展开讲一下——因为很多人觉得"开 debug 级别只是多点日志"。

不是的。开 debug 级别的代价比你想的大得多：

1. 磁盘 I/O 暴增：debug 日志量可能是 info 的 10-100 倍
2. CPU 开销：即使没有 subscriber，tracing 也要评估 Interest（虽然很快，但不是零）
3. 内存压力：JSON 格式化、大字段序列化都在堆上分配
4. 关键信息被淹没：出了问题你要在海量 debug 输出里找 error

编译时直接砍掉 debug/trace 级别，零成本：

# Cargo.toml
[dependencies]
tracing = { version = "0.1", features = ["max_level_info"] }

这样 debug!() 和 trace!() 在编译时就被移除了，连 Interest 检查都不会执行。真正的零成本。

教训：发布版本用 max_level_info 编译，开发时再开 debug。两个世界的好处都要。

指标（Metrics）

日志告诉你"发生了什么"，指标告诉你"有多严重"。

两条路：metrics crate vs OpenTelemetry Metrics

建议：如果你已经在用 OpenTelemetry 做链路追踪，指标走同一条管线更干净。如果只需要简单的 Prometheus 指标，metrics crate 更省事。

用 metrics + metrics-exporter-prometheus 两个 crate 就够了。初始化只需一行：

PrometheusBuilder::new()
    .with_http_listener(([0, 0, 0, 0], 9090))
    .install()
    .expect("failed to install Prometheus exporter");

然后在代码里用 counter!、histogram!、gauge! 三个宏记录指标，Grafana 配一个 Prometheus 数据源就能画图了。

关键：指标命名要规范。 我见过太多项目用 request_count、req_cnt、requests 混着来，最后 Grafana dashboard 一塌糊涂。建议一开始就定好命名规范，比如 http_requests_total、http_request_duration_seconds。

三种指标类型

教训：不要只看平均值。P99 和 P999 才是真正告诉你"用户在经历什么"的指标。

microservices 文章里那个 P99 vs P999 的例子很好——P99 正常但 P999 飙了，说明有少量请求在做全表扫描。Histogram 就是为这个场景而生的。

链路追踪（Distributed Tracing）

这是可观测性里最有价值但也最复杂的部分。

为什么需要链路追踪？

假设你的微服务架构是这样的：

用户请求 → API Gateway → User Service → PostgreSQL
                       ↘ Email Service → SMTP

一个请求经过了 4 个服务。如果延迟飙了，是哪个服务的问题？

没有链路追踪： 你只能一个一个服务翻日志，靠时间戳猜。 有链路追踪： 一张图看到整个调用链，每个环节花了多少时间。

Trace: abc-123
├── API Gateway (120ms)
│   ├── User Service (80ms)
│   │   └── PostgreSQL query (45ms)  ← 这里慢了
│   └── Email Service (30ms)
│       └── SMTP send (25ms)

OpenTelemetry 的现状

先说一个很多人不知道的事：OpenTelemetry Rust 的 Traces API/SDK 到现在还是 Beta 状态。

但别被"Beta"吓到。Jaeger、Grafana Tempo 都原生支持 OTLP 协议，生态已经成熟。只是说 API 可能还会有小调整，升级时需要注意。

重要的事情说三遍：旧的 opentelemetry-jaeger 已经废弃了，用 OTLP。旧的 opentelemetry-jaeger 已经废弃了，用 OTLP。旧的 opentelemetry-jaeger 已经废弃了，用 OTLP。

tracing-opentelemetry：一行代码把 tracing 导出到 OTLP

这个 crate 是整个链路追踪的关键——它是一个 tracing::Layer，把你的 tracing Span 自动转成 OpenTelemetry Span 并导出。

核心代码只有三步：

// 1. 创建 OTLP exporter
let exporter = opentelemetry_otlp::SpanExporter::builder()
    .with_http().build().expect("failed to build exporter");
 
// 2. 创建 TracerProvider
let provider = opentelemetry_sdk::trace::SdkTracerProvider::builder()
    .with_batch_exporter(exporter)
    .with_resource(opentelemetry_sdk::Resource::builder()
        .with_service_name("my-service").build())
    .build();
 
// 3. 加一层 OpenTelemetryLayer，完事
tracing_subscriber::registry()
    .with(EnvFilter::from_default_env())
    .with(tracing_subscriber::fmt::layer())
    .with(OpenTelemetryLayer::new(provider.tracer("my-service")))
    .init();

你的 #[instrument]、info!()、error!() 不用改一行代码，Span 自动导出到 Jaeger/Grafana Tempo。

坑：OTel 的依赖树很重。 opentelemetry-otlp 默认拉 grpc-tonic（gRPC），如果你只需要 HTTP 导出，记得 default-features = false，只开 http-proto。不然编译时间多 30 秒都是轻的。

跨服务传播 Context

链路追踪的核心是 Context Propagation——把 trace_id 通过 HTTP 请求头传给下游服务，让所有 Span 挂在同一个 Trace 下。

axum 的 tower-http 提供了 TraceLayer + PropagateRequestIdLayer，两行代码搞定：

Router::new()
    .route("/api/users/{id}", get(get_user))
    .layer(TraceLayer::new_for_http())  // 自动为每个请求创建 Span
    .layer(PropagateRequestIdLayer::x_request_id())  // 自动注入/提取 x-request-id

TraceLayer 自动为每个 HTTP 请求创建 Span，记录 method、uri、status_code。PropagateRequestIdLayer 自动在请求头里注入/提取 x-request-id。

下游服务用 reqwest + opentelemetry-http 的 propagator 自动提取 traceparent header，Span 就串起来了。

坑：TraceLayer 默认不记录请求体和响应体。 这是好事——记录请求体会严重影响性能，而且可能泄露敏感数据。如果你确实需要，自己在 handler 里用 debug!() 记录关键字段。

生产环境完整配置

把上面所有东西串起来，一个 axum 微服务的完整可观测性配置只需要：

1. 初始化：init_tracing() 返回 SdkTracerProvider（前面已经给过代码）
2. 路由层：加上 TraceLayer + PropagateRequestIdLayer
3. 优雅关闭：provider.shutdown() flush 遥测数据

#[tokio::main]
async fn main() {
    let provider = init_tracing();  // 前面给过的代码，加个 .json() 就行
 
    let app = Router::new()
        .route("/health", get(|| async { "ok" }))
        .route("/api/users/{id}", get(get_user))
        .layer(TraceLayer::new_for_http())
        .layer(PropagateRequestIdLayer::x_request_id());
 
    let listener = tokio::net::TcpListener::bind("0.0.0.0:3000").await.unwrap();
 
    axum::serve(listener, app)
        .with_graceful_shutdown(shutdown_signal())
        .await
        .unwrap();
 
    provider.shutdown().expect("failed to flush traces");
}

这十几行代码给你： 结构化 JSON 日志、链路追踪导出到 OTLP、每个 HTTP 请求自动创建 Span、Request ID 自动传播、环境变量控制日志级别、优雅关闭时 flush 遥测数据。

坑：别忘了 provider.shutdown()。 不 flush 就退出进程，最后一批遥测数据就丢了。我有一次排查线上问题，发现 Jaeger 里总是缺最后几秒的 Span，就是这个原因。

OTel 的"坑"——升级前请看

OpenTelemetry Rust 的 API 一直在演进，每个 minor 版本都可能有 breaking changes。 如果你从旧版本升级，大概率会遇到编译错误。

常见的变更模式

好消息：processor 不再依赖异步运行时了。 以前必须传 runtime::Tokio，现在用自带的后台线程。这解决了一个长期痛点——不是所有项目都用 Tokio。

教训：升级 OTel 之前，一定看 migration guide。锁死版本，测试后再升。 这个库的演进速度很快，API 不稳定是常态，不是你的问题。

错误上下文传播：SpanTrace

光有日志和链路追踪还不够。当错误发生时，你想知道的不只是"哪里报错了"，还想知道"报错时程序在做什么上下文"。

tracing-error crate 的 SpanTrace 可以在错误被捕获时自动记录当前的 Span 链路。用法很简单：在你的错误类型里加一个 SpanTrace 字段，构造时调用 SpanTrace::capture() 就行。

错误信息输出效果：

database connection failed

Span trace:
HTTP request (method=POST uri=/users)
  └── create_user (user_id=42)
       └── db::query (query="INSERT INTO users ...")

一眼就能看到：这个错误是在处理 POST /users 请求时，创建用户 42 时，执行数据库插入时发生的。

教训：SpanTrace 比 anyhow::backtrace 有用得多。backtrace 给你的是函数调用栈，SpanTrace 给你的是业务上下文。 你不需要知道是哪个函数调了哪个函数，你需要知道"这个请求在做什么"。

可观测性架构全景

最后画一张图，把所有组件串起来：

┌─────────────────────────────────────────────────────┐
│                    你的 Rust 服务                     │
│                                                     │
│  ┌──────────┐  ┌──────────┐  ┌──────────────────┐   │
│  │ tracing  │  │ metrics  │  │ tracing-error    │   │
│  │(Events + │  │(Counter/ │  │ (SpanTrace)      │   │
│  │ Spans)   │  │Histogram)│  │                  │   │
│  └────┬─────┘  └────┬─────┘  └────────┬─────────┘   │
│       │              │                 │             │
│  ┌────┴──────────────┴─────────────────┴──────────┐  │
│  │         tracing-subscriber (Layers)            │  │
│  │  ┌─────────┐ ┌──────────┐ ┌─────────────────┐  │  │
│  │  │fmt Layer│ │OTel Layer│ │metrics-tracing  │  │  │
│  │  │ (JSON)  │ │          │ │  -context       │  │  │
│  │  └────┬────┘ └────┬─────┘ └───────┬─────────┘  │  │
│  └───────┼───────────┼───────────────┼────────────┘  │
│          │           │               │               │
└──────────┼───────────┼───────────────┼───────────────┘
           │           │               │
     ┌─────┴───┐  ┌────┴────┐   ┌─────┴──────┐
     │  stdout │  │ OTLP    │   │ Prometheus │
     │ (日志)  │  │Exporter │   │  /metrics  │
     └─────────┘  └────┬────┘   └────────────┘
                       │
              ┌────────┴────────┐
              │  OTel Collector  │
              │  (or 直连)       │
              └───┬────────┬────┘
                  │        │
           ┌──────┴──┐ ┌───┴──────────┐
           │  Jaeger │ │Grafana Tempo │
           │(链路追踪)│ │ (链路追踪)    │
           └─────────┘ └──────────────┘

数据流：

• 日志 → stdout → 你的日志系统（Loki/ELK/CloudWatch）
• 链路追踪 → OTLP → OTel Collector → Jaeger/Grafana Tempo
• 指标 → Prometheus scrape → Grafana

三条管线，一个 subscriber，零侵入。

总结

可观测性不是"锦上添花"，而是"雪中送炭"。你的服务出了问题，能不能在 5 分钟内定位到原因，就取决于你今天花了多少时间在这上面。

Rust 的 tracing 生态给了你一个编译时零成本的工具。不用白不用。