Tokio 源码深度解析

第17章 Runtime 可观测性:Metrics、tracing 与 tokio-console

作者 杨艺韬 · 10,518 字 · 发布于 · 更新于

本章要点

  • 三层可观测性:RuntimeMetrics(数字——聚合态、定期采样)+ tracing(事件——细粒度、每次 span 进出)+ tokio-console(状态——实时面板、live task 快照)
  • RuntimeMetrics 近 30 项指标(1.40.0 里 RuntimeMetrics 一共 29 个公开方法):worker 级(park / poll / steal / overflow / local_queue_depth)+ blocking pool(num_blocking_threads / idle / queue_depth)+ IO driver(ready_count / fd_registered)——每项对应一个真实优化场景
  • #[instrument] 的魔法:宏展开后把函数体包进一个 instrumented future、在每次 poll 前 span.enter()、poll 后 span.exit()——让 await 不破坏 span 栈
  • 两条不同的"看现场"路径:tokio-console 走 console-subscriber 消费 runtime 发出的 tracing span(需 tokio_unstable + tracing);taskdump(Handle::dump())才是"抓 backtrace"那条路——它在 poll 中途用 trace_leaf 捕获真实调用栈、然后 defer waker 让任务重新排队
  • 生产黄金三元组:Prometheus 抓 Metrics + Jaeger 收 tracing + tokio-console 做 live debug——三者齐备,排查时才不缺数据

17.0 为什么可观测性是运行时的一等公民

对异步 runtime 而言、可观测性和正确性一样重要——这个观点在很多团队里仍然没有被充分接受。原因是:正确性问题大多在测试阶段能发现、但性能问题、慢长尾、资源泄漏只有在生产看到真实流量时才暴露——没有可观测性、这些问题像黑盒里的鬼、根本没办法定位。Tokio 作为生产级 runtime 这些年逐步把可观测性补成一等公民——metrics、tracing、tokio-console 三件套,再配上 panic 处理,让用户有完整的生产调试能力。

上一章结尾埋了一个伏笔:"看得见才能调得动"。本章就把这句话兑现。

想象你接手一个生产服务、QPS 掉到了平时的 1/3——延迟没涨、错误率没涨,就是吞吐不见了。如果你只能看日志,几乎没有办法诊断:日志只告诉你请求进了出了、不告诉你 task 在哪一步被 schedule 失败、worker 有没有被堵、blocking pool 有没有排队。

async runtime 的最大诊断难点是"状态极度弥散":几千个 task 分布在几个 worker、几十个 blocking thread、几百个 fd 上,每个都有自己的微观状态机——没有工具把这些状态收集起来,你就是盲人摸象。

Tokio 一直在补这一课,CHANGELOG 里能看到清晰的时间线:1.16.0 对 runtime metrics API 做了 breaking 的 overhaul(PR #4373);1.18.0 加了 I/O driver 指标(#4507);1.22.0 导出 blocking 线程池指标(#5161);1.29.0 加入 task backtrace dump(#5608 等);到 1.38.0 才开始正式稳定化——那一版稳定了 RuntimeMetrics::worker_count(#6556;注意 CHANGELOG 用的是旧称呼,1.40.0 里这个方法实际叫 num_workers),1.39.0 稳定了 num_alive_tasks(#6619)。也就是说,到本专栏基准的 1.40.0 为止,绝大多数 runtime 指标仍然在 tokio_unstable 之下。本章带你走一遍。

17.1 RuntimeMetrics:近 30 个数字描绘的运行时肖像

tokio::runtime::RuntimeMetrics 是 Tokio 提供的对外指标 API——通过它你可以实时读取 runtime 的内部状态:有多少 worker、每个 worker park 了多久、本地队列深度、有多少 blocking 线程、有多少 overflow 到全局队列……近三十个数字构成一幅完整的 runtime 肖像。读懂这些指标就能回答 "我的 runtime 健康吗?哪里是瓶颈?应该调什么参数?"等核心运维问题。

先上源码。tokio/src/runtime/metrics/runtime.rs:

pub struct RuntimeMetrics {
    handle: Handle,
}

就一个 Handle 包装——所有数据现场去读。这样的设计决策意味深远:

  • 读取开销极低:不持有快照、直接读 runtime 里的 atomic 计数器——一次读基本就是一次 Relaxed 的 atomic load;
  • 不存快照:RuntimeMetrics 自己不缓存任何数据;但 worker 级计数先累积在各 worker 自己的 MetricsBatch 里,要到 park、maintenance 或关闭前才 submit 写回共享的 atomic(tokio/src/runtime/metrics/batch.rs:80、tokio/src/runtime/scheduler/multi_thread/worker.rs:716),所以读到的 worker 级数值会有一点滞后;
  • 代价:要保证 runtime 里每个被观测的状态都是 atomic——源码里你会看到大量 AtomicU64、AtomicUsize。

核心指标地图

三十来个指标可以按"关心的运维问题"分成几类:任务调度类(worker_total_busy_duration / worker_steal_count / worker_local_schedule_count / worker_poll_count)、队列健康类(worker_local_queue_depth / injection_queue_depth)、blocking 健康类(num_blocking_threads / blocking_queue_depth / num_idle_blocking_threads)、IO Driver 类(io_driver_ready_count / io_driver_fd_registered_count)。注意 1.40.0 里没有 worker_busy_ratio 这种现成的比值指标——"利用率"要你自己拿 worker_total_busy_duration 除以墙钟时间算。这种分类让你从 "看到一堆数字"变成"每个数字对应一个问题域"——遇到事故时能快速定位是哪类问题。

全局级(stable,不需要 tokio_unstable——1.40.0 里就这两个,见 tokio/src/runtime/metrics/runtime.rs:47 和 :69):

  • num_workers(): worker 线程数(= Builder 里设的 worker_threads;current_thread runtime 恒为 1);
  • num_alive_tasks(): 当前存活的 task 数。

下面这些全部包在 cfg_unstable_metrics! 里(tokio/src/runtime/metrics/runtime.rs:73;宏定义在 tokio/src/macros/cfg.rs:218,展开就是一个 #[cfg(tokio_unstable)]),必须 RUSTFLAGS="--cfg tokio_unstable";其中返回 u64 / Duration 的那批还额外包了一层 cfg_64bit_metrics!(tokio/src/macros/cfg.rs:229,判据是 target_has_atomic = "64")——32 位平台上根本没有(它们靠 AtomicU64 实现)。

全局级(unstable):

  • num_blocking_threads(): blocking pool 现有线程数;
  • num_idle_blocking_threads(): 其中 idle 的数量;
  • spawned_tasks_count(): runtime 启动以来累计 spawn 数;
  • remote_schedule_count(): 从 runtime 之外(普通线程、blocking pool 线程等)spawn 或唤醒 task、只能经注入队列排队的次数;
  • budget_forced_yield_count(): coop budget 用完强制 yield 的次数;
  • injection_queue_depth(): 全局注入队列当前长度;
  • blocking_queue_depth(): blocking pool 队列当前长度。

每个 worker 级:

  • worker_park_count(i): worker i park(睡眠)的次数;
  • worker_poll_count(i): poll 的次数;
  • worker_steal_count(i): 从别人那里 steal 来的 task 数;
  • worker_overflow_count(i): 本地 queue 满、溢出到全局 inject 的次数;
  • worker_local_queue_depth(i): 当前本地 queue 长度;
  • worker_mean_poll_time(i): 每次 poll 耗时的指数加权移动平均(目前只有 multi-thread runtime 提供);
  • worker_total_busy_duration(i): worker 累计"非 park" 时间。

I/O driver 级:

  • io_driver_fd_registered_count(): 注册过的 fd 总数;
  • io_driver_fd_deregistered_count(): 注销过的;
  • io_driver_ready_count(): readiness 事件总数。

指标如何映射到真实问题

"指标"本身只是数字——关键是知道每个指标对应什么真实问题。本节把常见问题和指标做映射:CPU 饱和→worker_total_busy_duration 增量占墙钟时间的比例接近 1;Task 分布不均→worker_steal_count 远大于 worker_local_schedule_count;Blocking 挤压→blocking_queue_depth 持续 > 0;IO 空转→io_driver_ready_count 远高于实际请求量。掌握这种映射、你看 Grafana 图表时就不是盯着曲线发呆、而是直接对应到具体根因。

单个数字没用、配对比较才能诊断。下面这张表把常见的指标组合和它对应的怀疑方向列出来——注意这是排查方向的提示,不是结论,每一条都要再用 tracing / tokio-console 去证实:

观察 可能诊断
worker_poll_count 高、worker_mean_poll_time 低 每个 poll 很快、但 poll 次数多——task 被 wake 过频、可能存在"虚假唤醒"(比如某个 channel 每次收都 wake 但实际没数据)
worker_mean_poll_time 明显高于同服务的历史基线 某些 task 每次 poll 都重(CPU 计算)——应该 spawn_blocking 或改算法。具体阈值没有普适值,要和自己的基线比
worker_steal_count 总和接近 spawned_tasks_count 负载严重不均——几乎所有任务都需要 steal 才能跑、初始分配分布差
worker_local_schedule_count 远小于 worker_poll_count 任务多半是从别处调度进来的——本地 spawn 的局部性优化没吃到
worker_overflow_count > 0 且持续增加 本地 queue 被打满(LOCAL_QUEUE_CAPACITY = 256)——spawn 洪峰,考虑限速或加 worker
injection_queue_depth > num_workers 全局 inject 堆积——worker 消化不过来、增加 worker 或分流
blocking_queue_depth > 0 且增加 blocking pool 积压——上一章讲的场景,CPU 密集错用 spawn_blocking
io_driver_ready_count 大幅高于 QPS epoll 被频繁唤醒但没真实 IO——可能是某个 socket 在 spurious wakeup
budget_forced_yield_count 持续增加 有 hot task 在 CPU 上霸占——scheduler coop 机制在介入、但说明 task 本身不礼让

出了性能问题先看这几个数——但记住:这些指标只能缩小范围,定位到具体代码行还得靠后面两节的工具。

17.2 把 Metrics 连到 Prometheus

光有 RuntimeMetrics 不够——真实生产里你需要把指标推到监控系统、配置告警规则、做历史趋势分析。Prometheus 是目前 Rust 生态里最常用的指标系统——本节教你用 prometheus crate 把 Tokio RuntimeMetrics 导出成 Prometheus 格式、配合 Grafana 画图。这是每个生产级 Rust 服务的标配——不是可选的。

实际生产里你不会 println! 这些数字、你会按固定频率把它们导出到 Prometheus。基本 pattern:

// blocking_queue_depth / worker_poll_count 需要 RUSTFLAGS="--cfg tokio_unstable"
use std::time::Duration;

let metrics = tokio::runtime::Handle::current().metrics();
let workers = metrics.num_workers();

// 每 10 秒采样一次,挂到 prometheus gauge
tokio::spawn(async move {
    let mut ticker = tokio::time::interval(Duration::from_secs(10));
    loop {
        ticker.tick().await;
        TOKIO_ALIVE_TASKS.set(metrics.num_alive_tasks() as i64);
        TOKIO_BLOCKING_QUEUE.set(metrics.blocking_queue_depth() as i64);
        for w in 0..workers {
            TOKIO_WORKER_POLL
                .with_label_values(&[&w.to_string()])
                .set(metrics.worker_poll_count(w) as i64);
        }
    }
});

关键是——这个采样 task 本身跑在同一个 runtime 里、不能 block 太久。10 秒一次、每次只是几十个 atomic load,完全可以忽略。不要做高频全量采样(每秒上百次 × 每个 worker 十来个指标)——那时候观测本身就成了负载。

17.3 tracing:span 和 event 的双层模型

tracing 是 Tokio 生态的结构化日志库——它比 log crate 多了"span"概念(表示一段时间内的作用域)、支持跨异步边界的上下文传递、支持多种 subscriber(logger / jaeger / tokio-console)。对写 Rust 服务的人来说、tracing 不是可选项、是必修课——任何稍有复杂度的服务都应该从一开始就用 tracing 而不是 log / println。span + event 的双层模型让你能回答"这次请求花了多久"(span)和"请求过程中发生了什么"(events)两类问题。

tracing 相对 log 的根本优势:log 是"一条条消息"、tracing 是"带层级的事件流"。log 里每行互相独立、你得靠 request_id 这种字段自己串;tracing 里 span 自动带父子关系、跨 async await 点自动传递上下文——你在一个 handler 的深层函数里打 tracing event、它自动带上 handler 入口 span 的所有字段。这种"隐式上下文"让分布式追踪变得几乎无感——你只需要加 #[instrument] 标签、其他都是自动的。

RuntimeMetrics 给你数字、tracing 给你叙事——"某个请求经历了什么、在哪一步慢了多久"。

tracing 的核心抽象两个:

  • Span:有开始和结束的时间段——"我在处理请求 X";
  • Event:一个瞬间——"我刚收到了某个值"。
use tracing::{info, instrument};

#[instrument(skip(req), fields(user_id = %req.user_id))]
async fn handle(req: Request) -> Result<Response, Error> {
    info!("start processing");
    let user = fetch_user(req.user_id).await?;
    info!(?user, "user loaded");
    let resp = do_work(user).await?;
    info!("done");
    Ok(resp)
}

#[instrument] 干什么?宏展开后:

  1. 在函数进入时创建一个 span(名字默认是函数名、带上 fields 里声明的字段);
  2. 把函数体包进一个 wrapper future(有点像 Future combinator);
  3. 每次 poll wrapper 时——先 span.enter()(把 span 设为当前 thread 的 active)、poll 内部 future、再 span.exit();
  4. 函数返回时 drop span。

为什么 #[instrument] 这么重要

#[instrument] 是 tracing crate 的最高频使用宏——给一个 async fn 加上它、这个函数的每次调用就会自动生成一个 span、记录入参出参耗时 panic 等。这种"自动化结构化跟踪"让你几乎不用写手动 span 代码——加一个 attribute 就能让整个函数被完整观测。在一个中型服务里、几乎每个 async fn 都应该加 #[instrument]——这是可观测性基础架构的一部分。

手动 span.enter() + await 会出 bug——因为 await 是一个让出点、_guard 保持的"当前 span"会被带到 await 之后的另一个 poll 里去、但此时可能是另一个 task 在跑!这正是官方文档警告的那句话:"Span::enter may produce incorrect traces if the returned drop guard is held across an await point."

#[instrument] 通过每次 poll 都重新 enter / exit避开了这个坑——span 和 future 的生命周期绑定、而不是和线程的"某一段时间"绑定。这是 async 语境下 tracing 的核心正确姿态。

Subscriber:数据收到哪里去

tracing 的数据出口由 Subscriber 决定——这是一个插拔式设计、让你可以同时接多个 Subscriber:fmt 打到 stdout、opentelemetry-otlp 发到 Jaeger/Datadog、tokio-console 的 ConsoleSubscriber、自定义 Subscriber 发到内部日志系统。这种"一处采集、多处消费"的架构让 tracing 成为真正的单一真相源——业务代码里只加 span + event、监控 / 日志 / 分布式追踪三种需求统一从 tracing 层分发。

tracing 本身不决定日志打到哪、去不去 Jaeger——那是 Subscriber 的职责。常见组合:

  • tracing-subscriber::fmt:格式化打到 stdout——开发用;
  • tracing-subscriber::EnvFilter:按 RUST_LOG 过滤级别;
  • tracing-opentelemetry:把 span 导出到 OpenTelemetry collector(Jaeger / Tempo / SigNoz)——生产分布式追踪首选;
  • tracing-bunyan-formatter:JSON 结构化日志——ELK stack 配套。

一套典型生产配置:

use tracing_subscriber::{layer::SubscriberExt, Registry};
let registry = Registry::default()
    .with(tracing_subscriber::EnvFilter::from_default_env())
    .with(tracing_opentelemetry::layer().with_tracer(otel_tracer))
    .with(tracing_subscriber::fmt::layer().json());
tracing::subscriber::set_global_default(registry)?;

一行代码 + 一个全局默认 → 所有 info! / error! / span 都会被这几个 layer 处理。这种"分层订阅"的设计让 tracing 生态极其灵活——换一个输出目的地只改配置、不改业务代码。

17.4 tokio-console:live task 的 X 光

tokio-console 是 Tokio 生态里最具杀伤力的调试工具——它能让你实时看到运行中 Tokio 程序的每一个 task:task 的名字、spawn 位置、已运行时间、busy / idle 状态、甚至每次 poll 的耗时分布。这种"活体 X 光"能力在其他主流异步运行时里并不多见。

使用 tokio-console 的第一印象通常是震撼——第一次连上运行中的程序、看到几百个 task 实时刷新、每个 task 的具体位置和状态一览无余、你会有一种"之前完全看不见的黑箱现在变透明了"的感觉。这种感觉正是 Tokio 团队想传递的——异步系统的不可见状态是调试的最大障碍、工具让它可见,问题就解决了一大半。

Metrics 给你聚合数字、tracing 给你历史轨迹、但"此刻有哪些 task 活着、各自忙了多久、多久没被 poll"谁告诉你?tokio-console。

启动方式简单:

// Cargo.toml: console-subscriber = "0.4"
// tokio 需要开 "tracing" feature,并且编译时带上:
//   RUSTFLAGS="--cfg tokio_unstable"
console_subscriber::init();

在终端里跑 tokio-console、就能看到一个动态面板:所有 live task 的状态、多久没被 poll、在哪儿 spawn 的、带着哪些字段。像 top 命令但对象是 task。

先分清两件事:tokio-console 和 taskdump 不是一回事

这里必须纠正一个很常见的误解:tokio-console 并不依赖 taskdump。它靠的是 console-subscriber 这个 tracing Layer——runtime 在 tokio_unstable + tracing feature 下会为每个 task 发出 runtime.spawn 之类的 span(spawn_blocking 那条路径上你能直接看到 tracing::trace_span!(target: "tokio::task::blocking", "runtime.spawn", ...),tokio/src/runtime/blocking/pool.rs:371),console-subscriber 订阅这些 span 并通过 gRPC 转给 tokio-console 客户端。所以它看到的是"每个 task 被 poll 了多少次、busy/idle 各多久、在哪儿 spawn 的",而不是 backtrace。

taskdump 是另一条独立的路径——Handle::dump(),源码在 tokio/src/runtime/task/trace/mod.rs,1.29.0 才加入(PR #5608 等)。它的门槛高得多:cfg_taskdump!(tokio/src/macros/cfg.rs:418)要求 tokio_unstable + tokio_taskdump 两个 cfg 同时打开,且只支持 Linux 上的 x86 / x86_64 / aarch64,还要求二进制里带着 debuginfo(split-debuginfo = "off")。官方文档(tokio/src/runtime/handle.rs:531)另外警告:如果有别的 worker 阻塞超过 250ms,dump() 产生的 future 可能永远不 Ready——所以生产里用它一定要套 timeout。

关键技术:在 poll 中途就地抓栈。当你调 dump(),Tokio 会:

  1. 把 runtime 里 alive 的 task 全部 collect 到一张 list;
  2. 用 Trace::capture 装上一个 collector,并把每个 task 的 future 包在 Trace::root 里;
  3. 强行 poll 这些 task;
  4. task 一路 poll 到某个叶子(JoinHandle::poll、各种 driver 的 poll 里都埋了 ready!(crate::trace::trace_leaf(cx)),例如 tokio/src/runtime/task/join.rs:328)——触发 trace_leaf(),用 backtrace::trace 把 Trace::root 和 trace_leaf 之间那段栈帧抓下来;
  5. trace_leaf 随后 s.defer.defer(cx.waker()) 并返回 Poll::Pending(tokio/src/runtime/task/trace/mod.rs:191,下面这段是删减后的示意、非逐字)——task 没真正推进业务逻辑,只是"路过让 Tokio 抓一把 backtrace",然后按 yield_now 的同一套逻辑重新排队。
if did_trace {
    context::with_scheduler(|scheduler| {
        // ... 记录 trace ...
        s.defer.defer(cx.waker());
    });
    Poll::Pending
}

这个机制的精妙之处:不需要停 runtime、不需要 ptrace、不需要修改 task 结构——利用 Future 本身的 poll 可重入语义,就把所有 live task 的栈抓下来了(代价是每个 task 都要被额外 poll 一轮,所以它是"按需触发"而非常驻)。这是 Tokio 把"把 async 结构变成第一公民"思想贯彻到底的结果:既然 Future 的 poll 是可重入的、那就用这个重入捕获状态。

你能在 tokio-console 里看到什么

列表可以很长——但最高价值的几个视图是:按 busy_time 排序的 task 列表(立刻看出哪些 task 在吃 CPU)、resource 列表(看有哪些被插桩的资源活着)、某个 task 的详情(每次 poll 的耗时分布)、某个 mutex / rwlock 的详情(哪些 task 正在等它,看锁争用)。这四个视图覆盖了大部分诊断场景——学会看它们你就能用 tokio-console 解决大部分 async 性能问题。

  • 每个 task 的 ID + 名字 + 当前 state(running / idle / scheduled / done);
  • Task 上一次 poll 的时长、总 poll 次数、总被 wake 次数;
  • Task 的 spawn 位置(#[track_caller] + std::panic::Location::caller() 记下来的 file:line,见 tokio/src/util/trace.rs:12);
  • Resource 的等待者列表——1.40.0 里只有 Sleep、Interval、Mutex、RwLock、Semaphore、Barrier、oneshot 带了插桩,mpsc 等其他 channel 和 I/O 资源都看不到;
  • console 自带的告警(Warn 列)——比如 task 自唤醒比例过高、丢失 waker、长时间不 yield,由 tokio-console 自己检查得出,应用不能自定义。

这个工具对诊断"task 泄漏"、"某个 task 被某个锁挂死"、"某个 task 长期不 yield"的价值无可替代。要看"卡在哪一行的调用栈",那是上面说的 taskdump 的活,不是 tokio-console 的。第 15 章(§15.11)那个"JoinSet 变成无界队列"的场景,用 tokio-console 会非常直观——面板上同一 spawn 位置的 task 数量一路往上涨、且大部分处于 idle,一眼就知道是哪段 spawn 没人回收。

17.5 三层一体:一次真实 bug 诊断的流水账

本节用一个具体的 bug 诊断案例把前三个工具串起来用——这是本章最实战的部分。场景:某服务间歇性变慢、尾延迟被拉高一个数量级。靠单一工具很难定位——但三个工具组合起来能快速锁定根因:Metrics 看到某个 worker 的 park 占比骤降、tracing 看到特定 endpoint 的 span 有长尾、tokio-console 看到那个 endpoint 的 task busy 时间异常累积。三个数据点一交叉、问题就定位了。这种"多工具协同诊断"是可观测性的真正威力。

把这个案例的诊断链条 verbalize 出来:Metrics 是"雷达"——发现某个 worker 异常、但没告诉你具体是什么 task;tracing 是"时间轴"——显示哪些请求慢、但没告诉你慢的 task 内部在等什么;tokio-console 是"显微镜"——直接显示哪个 task 单次 poll 占了多久、在哪儿 spawn 的。三者各自看一部分、组合起来才能看全貌——就像医学诊断需要病史 + 影像 + 化验三管齐下、少一个就可能漏诊。这种"多层协同"思维是高阶运维的核心能力。

下面这条推演不是某次具体事故的复盘,而是把三个工具串起来的标准动作——设想一个服务"偶尔"整整几秒无响应:

Step 1(Metrics 发现异常):Grafana 上看到 worker_poll_count 每 5 分钟会有一个 5 秒长的水平段——这段时间 runtime 几乎不 poll。注意它的真实签名是 pub fn worker_poll_count(&self, worker: usize) -> u64(tokio-1.40.0/tokio/src/runtime/metrics/runtime.rs:512),按 worker 下标取,不是一条全局计数——上报时要么按 worker 打 label,要么自己求和。

Step 2(关联其他 Metrics):那 5 秒里 num_alive_tasks()(tokio-1.40.0/tokio/src/runtime/metrics/runtime.rs:69,返回 usize)曲线还在涨——task 进来了但不被处理(blocking_queue_depth() 则不必指望:blocking 队列只和 spawn_blocking 的提交量、blocking 线程上限有关,worker 被 CPU 卡住并不会让它上涨)。worker_park_count(worker)(tokio-1.40.0/tokio/src/runtime/metrics/runtime.rs:281)没跳——worker 没睡,在干活。干什么活?

一个容易踩的前提:这里用到的三个指标里只有 num_alive_tasks 是稳定 API。worker_poll_count / worker_park_count 都在 tokio-1.40.0/tokio/src/runtime/metrics/runtime.rs:73 起的 cfg_unstable_metrics! 块里,必须带 RUSTFLAGS="--cfg tokio_unstable" 才编得出来。

Step 3(tracing 找范围):grep Jaeger 里那几秒的 span——发现某个 process_batch span 的 duration 恰好 5 秒。而这个函数正常时间是 50 毫秒。猜测:某个 batch 里有超大数据、同步处理卡 CPU。

Step 4(tokio-console live 抓):下次重现时开 tokio-console——看到一个 task 的单次 poll 时长达到 4.8 秒、spawn 位置正指向 process_batch 所在的 handler。回到代码里,这段路径上唯一的重活是同步的 serde_json::to_vec(&huge_struct)。

真相大白:有个边界 case 下 huge_struct 变得巨大(几 MB)、to_vec 在 worker 上同步跑了 5 秒、把整个 worker 卡死——期间其他 task 要么堵在这个 worker、要么要 steal 到别的 worker(短暂缓解,但最终还是波及)。

修复:把 to_vec 包进 spawn_blocking(或者从源头限制 huge_struct 的大小)。修完之后 Grafana 上那段水平段就应该消失——这一步的验证同样靠 Metrics。

这个案例的教训:Metrics 发现"什么时候慢"、tracing 发现"哪个函数慢"、tokio-console 发现"慢在哪个 task"——三者各司其职、缺一不可。

17.6 一些 Metrics 使用的实战微技巧

本节汇总一些真实项目中发现的 RuntimeMetrics 使用技巧——这些都是血泪经验、在官方文档里找不到。技巧 1:worker_total_busy_duration 的增量要和同一段墙钟时间对照——两者接近,说明 worker 几乎一直在忙、很少 park(CPU bound);技巧 2:worker_steal_count 暴涨是饥饿 worker 的信号——说明某些 worker 饿了要去偷其他 worker 的 task;技巧 3:blocking_queue_depth 稳定不为 0 说明 blocking pool 在堆积——要么增加 max_blocking_threads、要么减少 spawn_blocking 调用率。

把这些集中讲出来、都是踩过坑的:

微技巧 1:用 diff 而不是 raw 值做告警

很多指标是单调递增的(计数器)——比如 steal_count、poll_count。这种指标做告警不能用 raw 值("steal_count > 1M 告警"没意义)、要用时间窗内的增量("过去 1 分钟 steal_count 增量 > 10K 告警")。这个看起来基础的分清 counter 和 gauge 的习惯、在真实告警规则配置里反复被做错——Prometheus 的 rate() / irate() 函数就是为这个问题而生。

spawned_tasks_count 是累计值——告警配"瞬时值 > 10000"毫无意义(上线一周所有正常进程都会超)。应该每分钟记一次差值、告警"每分钟新增 > 50000"——才是真正的"突发 spawn 洪峰"信号。Prometheus 的 rate() 函数就是为这个设计的。

微技巧 2:per-worker 曲线分别画

Tokio 的很多指标是 per-worker 的(每个 worker 有自己的 busy_duration 等)——最大错误是把所有 worker 的数据加起来画一条曲线。这掩盖了 per-worker 的不均衡问题——比如 4 个 worker 里 1 个满载、3 个闲着、加起来平均值看着还不错、实际是 work-stealing 失效。Grafana 画图时要让每个 worker 一条线、用颜色区分——一眼就能看出不均衡。

不要把所有 worker 的 worker_poll_count 加总成一条曲线。分开画——你会看到"负载是否均衡"的真相。理想情况下 8 条曲线应该几乎重合、如果某条明显比其他高(或低)——scheduler 负载分布有问题、可能是某个 task 有线程亲和性、或是 work-stealing 没起作用。

微技巧 3:histogram 的 bucket 配置

histogram 的 bucket 边界影响极大——bucket 区间不合适,分位数就完全不准。Tokio 自带的 poll 时间直方图默认是 HistogramScale::Linear、resolution 100µs、10 个 bucket(tokio/src/runtime/metrics/histogram.rs:136 的 HistogramBuilder::new() 里写死的三行:scale: HistogramScale::Linear、resolution: 100_000(纳秒)、num_buckets: 10),也就是说默认只能分辨到"0–100µs / 100–200µs / … / >900µs"——poll 耗时通常是重尾分布,这套线性划分会把绝大多数样本挤进第一个 bucket,长尾完全看不见。想看长尾就要换 log scale 并加 bucket 数。

poll_count_histogram_* API 允许你看 "poll 耗时的分布直方图"——但你得先在 Builder 里 enable 它、默认关(因为有额外 overhead):

use std::time::Duration;
use tokio::runtime::{Builder, HistogramScale};

Builder::new_multi_thread()
    .enable_metrics_poll_count_histogram()                       // 默认关,因为有额外开销
    .metrics_poll_count_histogram_scale(HistogramScale::Log)     // 默认 Linear
    .metrics_poll_count_histogram_resolution(Duration::from_micros(10)) // 默认 100µs(第一个桶的宽度)
    .metrics_poll_count_histogram_buckets(20)                    // 默认 10
    .build()?;

读回来用 poll_count_histogram_num_buckets() / poll_count_histogram_bucket_range(i) / poll_count_histogram_bucket_count(worker, i) 这三个方法——同样都在 tokio_unstable 下。

log scale 比 linear 好——log 模式下每个 bucket 覆盖的区间是前一个的两倍,能同时容纳"绝大多数极短的 poll"和"少数极长的 poll";linear bucket 则会把绝大多数样本挤到第一个 bucket 里、看不出分布。

微技巧 4:worker_total_busy_duration 是"CPU 利用率"的分子

想监控"Tokio 的 CPU 利用率"?公式是 worker_total_busy_duration / elapsed_time——这个比值告诉你 worker 真正在工作的时间占比。这个比值越接近 1,worker 就越饱和;长期很低则说明 worker 开多了、或者瓶颈根本不在 runtime 上。注意它是"累计忙碌时长",要先算增量再除以同一段墙钟时间,具体的健康区间要和自己服务的基线比,没有普适阈值。这是运维 Tokio 服务的最核心指标之一。

busy_duration(w) / wall_time 就是 worker w 的 CPU 利用率——不是整机 CPU 利用率、是 runtime 的利用率。低利用率 + 高延迟 = 瓶颈在 IO 或下游(worker 都在 park 等 IO);高利用率 + 高延迟 = 瓶颈在 CPU(worker 忙不过来)。两者的优化方向完全相反。

微技巧 5:injection_queue_depth 的"持续 > 0" 才是问题

worker 本地队列满时 task 会 overflow 到全局 injection queue——这本身不是问题(Tokio 设计预期就有这种情况)。只有 injection_queue_depth 持续 > 0 才是问题——说明 overflow 速度持续超过 drain 速度、task 在堆积。配告警时"1 分钟内最小值 > 0"比"任意时刻 > 0"合理得多——避免 false positive。

偶发 spike 到 1-2 个是正常(spawn 间隙本来就会短暂排队)。持续偏高、且 worker 都忙——说明 worker 消化速度 < 外部注入速度、典型的"producer 快 consumer 慢"。这时候增加 worker 可能没用(CPU 本来就不够)、该考虑的是限速或分流。

17.7 和其他专栏的呼应

可观测性是所有 runtime 级系统的共同话题——Linux 内核有 perf、eBPF、ftrace;JVM 有 JMX、Flight Recorder、async-profiler;Python 有 asyncio debug mode、py-spy。Tokio 的可观测性工具链在 Rust 生态里是最完整的——但和其他生态比各有千秋。理解这些跨生态的工具能让你写出有"可观测素养"的 Rust 代码——不光为你当前这个 runtime 负责、也为未来任何迁移负责。

关于可观测性和本章 Tokio 其他章节的关联:前面每一章讲 Tokio 某个子系统时都提到过对应的观测方法——比如第 4 章讲 Runtime 时提到调默认值前先用 tokio-console / perf 拿证据、第 5 章讲 Scheduler 时用 worker_total_busy_duration 和 tokio-console 排查调度问题、第 16 章讲 blocking 时提到监控 blocking pool 深度。本章是把这些零散的观测方法集中系统化——读完本章再回去看前面章节里每次"可以用 X 观测"的提示、你会有更完整的理解。这种"具体章节讲机制、专章讲观测"的结构让你学到的不是"碎片化"知识、而是"可操作"知识——知道怎么监测每个子系统就意味着你能运维它。

一个有意思的跨生态对比:Java 有 Java Flight Recorder(JFR)——只要加一个 JVM 参数就能记录详细运行时事件、事后用 Mission Control 分析。Tokio 目前没有完全等价的工具——但 tokio-console + tracing 的组合已经非常接近这种体验。随着 Tokio 生态成熟、"一键开启深度运行时录制"的能力会越来越好——现在还需要你主动配置和取舍。

《Vue 3 设计与实现》第 18 章讲过 Vue 的 DevTools Performance 面板,以及 app.config.performance = true 打开后 runtime-core 在组件 render / patch 前后往浏览器 Performance 时间线里写标记——runtime 自己埋点、外部工具消费,和 tokio-console 的设计哲学一模一样。区别只是 Vue 走浏览器的 Performance API 与 devtools 消息通道、tokio-console 走 tracing + gRPC。"observability 是运行时的 contract、不是外挂功能"——这是两个生态的共同共识。

《Rust 编译器与运行时揭秘》第 7 章提到过 用 rustc 的 -Zself-profile 把编译器各阶段耗时写成 measureme 的 .mm_profdata——#[instrument] 宏和那套机制异曲同工:编译期插入观测代码、运行期收集聚合。学会在两种"运行时"(rustc 和 tokio)里都用这种技术,是系统工程师的基本功。

《vLLM 推理内核深度解析》第 2 章里的 IterationStats 按每轮迭代累积 prompt/generation token 数、TTFT、TPOT 等延迟——和 RuntimeMetrics 里 worker 级指标是同一个思路:调度器自己暴露足够多的内部状态、让调用方能看清自己"做了多少功"。这是所有严肃调度器共享的基础设施品质。

17.8 可观测性的心智模型:永远留足"下次调试"的空间

好的可观测性不是"出事后加日志"、而是"先建好观测、再写业务"。这个顺序对很多团队来说反直觉——他们先上业务、等出了问题再加监控。但那时候紧急 + 不全——日志加了一半事故就过去了、下次类似问题还要从头来。正确姿势是:把可观测性当成和业务代码同等重要的构件、一起设计、一起上线。这一节把这个心智模型讲清——读完你对"为什么每次新服务都要先搭可观测性"有具体认识。

一个实用的初始模板:每个新 Tokio 服务启动时做五件事:(1)接 RuntimeMetrics 到 Prometheus、暴露 /metrics 端点;(2)配置 tracing_subscriber、stdout 加 JSON 格式的 Layer;(3)在 main 函数里起一个 console_subscriber(dev mode 专用);(4)设 std::panic::set_hook 捕获 panic 到 tracing::error;(5)给 runtime 起个有意义的名字(config)。这五件事代码量不大、第一天就做、不要等出事。

最后一条原则、实践里最值钱——今天加的每个 metric、每个 tracing span,都是在给"下次出事"的自己留路。

什么时候加观测?不是出 bug 才加——那时候场景已经消失了。而是"你觉得这段代码未来有可能成为瓶颈时"——比如新加的一段 spawn_blocking、一个 channel 的 buffer size、一个 select! 的多路分支——就地加一个 debug! 或 gauge,平时几乎不花钱,出事时救命。

观测的反模式:

  • 把所有 debug! 写到 info! 级别——日志量爆炸、找不到重点;
  • 只加 metrics 不加 tracing——知道"什么时候"不知道"为什么";
  • 只加 tracing 不加 metrics——每个请求都清楚、但看不到聚合趋势;
  • 上线后才 attach tokio-console——生产环境不开 tokio_unstable 就用不了。

正反结合:开发就上全套(fmt logs + jaeger dev env + console)、生产上 metrics + sampled tracing + console 预开但按需连。

一个补充:tracing 的"成本焦虑"通常被高估

很多团队不敢全面用 tracing、担心"日志开销"——但被关掉的那些 span/event,代价基本就是一次级别比较。大部分"tracing 太慢"的传闻来自错误配置——比如用了 fmt::Layer 但 target level 设太低(DEBUG / TRACE)、同步地往 stdout 格式化巨量输出。正确配置下(INFO level + 结构化输出 + non-blocking writer)、tracing 对绝大多数服务都是净正收益。真要下结论,请在自己的服务上量一次开/关的差异。

很多人不敢在热路径写 info!——怕性能。实际上 tracing 的 runtime 成本分两层:

  1. level 被全局关掉时:info! 展开后先和 tracing 维护的全局 max level 比一下,不通过就直接跳过——这一步不做格式化、不做分配。
  2. level 打开时:要求值字段、走 subscriber 的 event 回调、可能还要格式化输出——这才是真正花钱的地方。所以热路径上通常不开 info。

最佳实践:热路径用 debug! 或 trace!(默认关)、请求入口用 info! 、异常情况 warn!/error!。配合 EnvFilter 在问题重现时按需打开 debug——不用改代码(想不重启就切换,还要再套一层 tracing_subscriber::reload)。这才是 tracing 的真正威力:按需扩展观测精度。

tracing 这套设计和 linux 的 dmesg/ftrace/perf 是同一个哲学——近乎零开销的"关着的"诊断点、按需"打开"。学会这套思维、你的每个生产服务都会比对照组更容易排障。

17.9 把可观测性当"文化"而不是"工具"

"工具"是术——"文化"是道。可观测性做得好的团队有几个共同特征:每次事故后有 post-mortem、会识别"我们当时缺了什么观测";所有服务上线前要过"可观测性 review"——有没有关键 metric?有没有 span?有没有合理告警?;对"加日志有成本"的认知——不是越多越好、要有取舍。这些行为模式合起来叫"可观测性文化"——工具再好、没有这个文化也发挥不出价值。

同样的工具栈,有"可观测性文化"的团队和没有的团队,事故定位速度可以差出一个量级——差别不在工具,在"大家平时是否投入"。文化是隐性的、但效果是非常显性的——这也是"文化 > 工具"的原因。在你能影响的团队里推动可观测性文化、比拿再好的工具更有长期价值。

一个反复出现的团队级差异:同样的 Tokio、同样的 tracing、同样的 Grafana——A 团队很快就能定位,B 团队反复卡在"查不到"。差别不在工具、在文化。

A 团队的特征:

  • 每个 PR 的代码 review 会问"这段代码的观测点在哪"——和"这段代码有测试吗"一样重要;
  • 线上事故后一定有"下次怎么更快发现"的复盘项——直接落成新 metric / 新 dashboard;
  • on-call 手册里每个告警都链接到 runbook——不是"重启试试"、而是"先看 X 指标、再看 Y 面板";
  • 定期看 Grafana 不是出事才看——周会上过一遍关键曲线、长期趋势里藏着未来的坑。

B 团队的特征常常是反过来的:metrics 是"加了就好"、dashboard 没人看、告警大多数被静默、tracing 只在 dev 环境看过。出事了翻日志、翻代码、翻 git blame——花的时间全是工具本该替他们省的。

可观测性的终极价值不是帮你解决 bug、而是帮你用更少的 bug 运营系统——每条新加的 metric、每个新加的 span,都在训练整个团队对系统的直觉。而直觉,才是资深工程师的护城河。所以把这一章的工具用起来——工具是死的、文化是活的;只有把工具注入日常、可观测性才真正发挥作用。

最后一个建议:给每个 runtime 起个名字

如果你的服务有多个 runtime(第 18 章详讲)——一定要给每个 runtime 起个有意义的名字。这样 metric 里能区分("rt_main" vs "rt_background")、tracing span 里能打标——没有名字的时候这些都是一坨。为可读性投入一点点初始代价、换来生产调试时的数倍收益——这是 Tokio 配置里最值得养成的习惯。

默认的 worker 线程叫 tokio-runtime-worker——如果你进程里有多个 runtime(下一章话题),panic 时你看不出是哪个。永远用 Builder 的 .thread_name("my-service") 起显式名字:

Builder::new_multi_thread()
    .thread_name("api-server-worker")
    .build()?;

这一行改动,能在凌晨三点你看堆栈时省下一段翻查时间——乘以一辈子的 on-call 次数,是非常可观的。运行时的可观测性、从一行名字开始。

17.10 另一个常被遗忘的观测维度:panic 追踪

panic 是一类特别难追踪的事件——它发生时程序状态已经部分损坏、栈展开和 Drop 都在跑、日志可能输不出去、metric 可能来不及上报。所以需要特别的"panic observability"方案:用 std::panic::set_hook 捕获每个 panic、记录到独立 panic log、用 sentry/bugsnag 等服务收集和去重 panic、关键服务里甚至要把 panic count 作为告警 metric。如果你没有做 panic 追踪、就是在"祈祷生产不会 panic"——生产一定会 panic、问题是你能不能发现。

Tokio 特有的 panic 陷阱:Task panic 不会 panic 主进程——它只会让对应 JoinHandle 返回一个 is_panic() 为 true 的 Err(JoinError)。如果你不 await 那个 JoinHandle、panic 就默默被吞掉了。这种"silent panic"在生产里极其危险——服务看起来还在跑、但某些任务已经悄悄死了。对策是用 JoinSet 统一管理所有 spawn 的 task 并正确处理 panic 情况——或者全局用 panic hook 做告警。

async 里最容易被忽视的观测漏洞是 panic 追踪。当一个 spawn 出去的 task panic 了、默认情况下留下的只有标准库默认 panic hook 往 stderr 打的那几行——如果你的生产日志不收 stderr、或者 stderr 被 systemd journal 吞了但 log agent 没配——这次 panic 就无声无息丢了。JoinHandle await 时会得到 is_panic() 为 true 的 JoinError,但要主动检查。

正确的做法是在 spawn 边界包一层:

tokio::spawn(async move {
    let result = std::panic::AssertUnwindSafe(run()).catch_unwind().await;
    if let Err(payload) = result {
        tracing::error!(?payload, "task panicked");
        PANIC_COUNTER.inc();
    }
});

这样每次 panic 都会触发 error! 级日志、PANIC_COUNTER 上报 Prometheus、告警触发。(注意 catch_unwind 来自 futures::FutureExt,需要引入 futures crate;而且它对 panic = "abort" 的构建无效。)"跑了很久才发现一直在丢 panic"是相当常见的经历——这个黑洞,只有把 panic 当作"一等观测对象"才能堵住。

Tokio 还提供了 Builder::unhandled_panic(UnhandledPanic::ShutdownRuntime) 选项、可以在 panic 发生时整个 runtime 退出——这在对"任何 panic 都意味着状态不一致"的系统(比如交易、数据库)里非常有用:与其让 runtime 带着一个 corrupted task 继续跑几小时、不如立刻 crash 让 supervisor 重启。但 1.40.0 里它有两条硬限制:它整体包在 cfg_unstable! 里(tokio/src/runtime/builder.rs:911,要 --cfg tokio_unstable),而且文档(tokio/src/runtime/builder.rs:930)明确写着"This method panics if called with UnhandledPanic::ShutdownRuntime on a runtime other than the current thread runtime"——multi_thread runtime 上直接用会 panic。默认值是 UnhandledPanic::Ignore(tokio/src/runtime/builder.rs:322)。选择哪种策略取决于你的系统能不能容忍"部分失败"——对无状态服务可忍、对有状态服务多半不可忍。这也是"可观测性不止是看、也包含对异常的处置策略"的一个注脚。

17.11 本章小结

可观测性是 Tokio 生产级使用的"第二项基本功"——第一项是本章之前讲的运行时机制、第二项就是本章的可观测性工具链。两者缺一不可:不懂运行时、你看 metric 看不出名堂;没有 metric、你再懂运行时也没法在生产发现问题。

带走四件事:

  1. 三层可观测性要组合用——Metrics 给聚合数、tracing 给叙事、tokio-console 给 live 状态。三者分别对应"多慢、为什么慢、现在卡在哪"——单一工具有盲区,交叉分析才能看到完整图景。RuntimeMetrics 接到 Prometheus 是生产服务的最低门槛,tracing 从第一天就用、别用 log / println
  2. #[instrument] 宏的核心是每次 poll re-enter span——这才能正确跨越 await 边界。手动 span.enter() + await 在 async 里几乎必错
  3. taskdump 利用 Future poll 可重入、在叶子处抓 backtrace 再 defer waker——不停服就能拿到 live task 的调用栈,但门槛不低(tokio_unstable + tokio_taskdump、仅 Linux 的 x86/x86_64/aarch64、需要 debuginfo)。而 tokio-console 走的是另一条路:tracing span + gRPC
  4. 可观测性要先行——写业务前先建监控、不要等出事再补

下一章进入跨 runtime 通信与多 runtime 架构——你会看到为什么"一个进程只有一个 Tokio runtime" 不再是唯一答案、什么时候该分 runtime、分 runtime 之间如何通信而不死锁。


延伸阅读