Rust AI CLI 的可观测性：tracing + opentelemetry 看清每一次模型调用

Rust AI CLI 的可观测性tracing opentelemetry 看清每一次模型调用作为一个自学的人我一度觉得反正是个小工具打打println!就够了。直到有一次一个用户抱怨你的 CLI 怎么这么慢我盯着代码看了两个小时加了二十几个println!才找到是某次重试逻辑在死循环。从那以后我决定正经学一下可观测性。今天这篇文章就是我从小白到用上 tracing OpenTelemetry 的完整记录。一、从 println! 之痛到结构化日志刚入门的时候我的调试手段只有一个println!大法。模型调用了就打印一行返回了就再打印一行。/// 最原始的调试方式 —— println! 打天下 /// 问题日志混在一起没有层级没有上下文排查困难 async fn call_llm(prompt: str) - ResultString, Boxdyn std::error::Error { // 散落的 println —— 不知道哪条是哪次的请求 println!( 开始调用 LLM ); println!(prompt 长度: {} 字符, prompt.len()); let start std::time::Instant::now(); let response do_api_call(prompt).await?; let elapsed start.elapsed(); // 更散落的 println —— 多线程同时打印会混在一起 println!(LLM 返回了耗时: {:?}, elapsed); println!(响应长度: {} 字符, response.len()); println!( LLM 调用结束 ); Ok(response) }这玩意儿最大的问题有三个第一日志没有层级关系——你没法知道某条日志是哪个请求的。第二多线程或者说 Tokio 多任务同时打印时日志会交错完全没法读。第三没有结构化数据——你想统计上周平均每次 LLM 调用的耗时只能手动 grep 日志再算。tracingcrate 就是为了解决这些问题设计的。它提供了带**Span跨度**的结构化日志每一个 Span 代表一个操作单元子 Span 可以嵌套在父 Span 里。use tracing::{info, warn, error, instrument, Span}; use std::time::Instant; /// 使用 tracing 改造的 LLM 调用 /// 每个 Span 会自动记录进入和退出的时间 #[instrument(name llm_call, skip(prompt), fields(prompt_len prompt.len()))] async fn call_llm_traced(prompt: str) - ResultString, Boxdyn std::error::Error { // instrument 宏自动创建了一个 Span // 进入函数 Span 开始离开函数 Span 结束 // 子 Span 会嵌套在这个 Span 下面 info!(准备调用 LLM API); // 在 Span 内记录额外字段 Span::current().record(model, gpt-4o); let response call_api_with_retry(prompt).await?; info!( response_len response.len(), LLM 调用成功 ); Ok(response) } /// 子函数用 #[instrument] 标注后会自动成为子 Span #[instrument(name api_retry, skip(prompt))] async fn call_api_with_retry(prompt: str) - ResultString, Boxdyn std::error::Error { let mut retries 0u32; loop { match do_http_call(prompt).await { Ok(resp) { info!(retries, API 调用成功); return Ok(resp); } Err(e) if retries 3 { // warn! 会记录警告级别比 info! 醒目 warn!(retries, error %e, API 调用失败准备重试); retries 1; tokio::time::sleep(std::time::Duration::from_millis(500)).await; } Err(e) { error!(retries, error %e, API 调用彻底失败); return Err(e); } } } } async fn do_http_call(_prompt: str) - ResultString, Boxdyn std::error::Error { // 模拟 HTTP 调用 Ok(模拟响应.to_string()) }这样改造之后你的日志输出是JSON 格式的每一条都有span_id和parent_span_id你可以清楚地看到api_retry 是 llm_call 的子操作。这就是可观测性的第一步让日志变成结构化数据而不仅是字符串。二、用 OpenTelemetry 把 Span 发到 Jaeger 上看火焰图日志结构化只是第一步。更强大的玩法是把 tracing 的 Span 数据通过 OpenTelemetry 协议导出到 Jaeger一个分布式追踪可视化工具然后在 Jaeger 上看到每次请求的火焰图——每个 Span 的开始时间、结束时间、耗时一目了然。sequenceDiagram participant CLI as Rust CLI participant Tracer as tracing-opentelemetry participant OTLP as OTLP Collector participant Jaeger as Jaeger UI CLI-CLI: #[instrument] 创建 Span (llm_call) CLI-CLI: 子 Span (api_retry) 开始 CLI-CLI: 子 Span (api_retry) 结束 CLI-CLI: llm_call Span 结束 CLI-Tracer: 批量导出 Span 数据 Tracer-OTLP: 通过 gRPC/HTTP 发送 Span OTLP-Jaeger: 写入 Jaeger 存储 Jaeger--CLI: 用户在 Jaeger UI 看到火焰图配置 OpenTelemetry 导出其实不复杂核心代码如下use opentelemetry::global; use opentelemetry_sdk::propagation::TraceContextPropagator; use opentelemetry_sdk::trace::TracerProvider; use opentelemetry_otlp::WithExportConfig; use tracing_subscriber::layer::SubscriberExt; use tracing_subscriber::Registry; /// 初始化 OpenTelemetry 导出 /// 把 tracing 的 Span 数据发到本地的 Jaeger默认端口 4317 fn init_telemetry() - Result(), Boxdyn std::error::Error { // 1. 全局设置传播器跨服务传递 trace_id 用的 global::set_text_map_propagator(TraceContextPropagator::new()); // 2. 创建 OTLP exporter通过 gRPC 发送到 Jaeger let tracer opentelemetry_otlp::new_pipeline() .tracing() .with_exporter( opentelemetry_otlp::new_exporter() .tonic() .with_endpoint(http://localhost:4317) // ← Jaeger OTLP 端口 ) .install_batch(opentelemetry_sdk::runtime::Tokio)?; // 3. 创建 OpenTelemetry layer桥接 tracing 和 opentelemetry let telemetry_layer tracing_opentelemetry::layer() .with_tracer(tracer); // 4. 注册 subscriber同时输出到终端 导出到 Jaeger Registry::default() .with( tracing_subscriber::fmt::layer() .pretty() // 终端输出用好看的格式 .with_target(false) ) .with(telemetry_layer) // ← 关键把 Span 导出 .init(); info!(OpenTelemetry 初始化完成); Ok(()) } #[tokio::main] async fn main() - Result(), Boxdyn std::error::Error { // 必须在任何 tracing 调用前初始化 init_telemetry()?; // 所有 tracing 调用现在都会同时 // 1. 在终端打印fmt layer // 2. 发送到 Jaegeropentelemetry layer let result call_llm_traced(你好请解释一下 Rust 的所有权).await?; println!(结果: {}, result); // 确保程序退出前 Span 被导出否则会丢数据 opentelemetry::global::shutdown_tracer_provider(); Ok(()) }配好之后每次运行 CLIJaeger 上就能看到一条完整的调用链。你能直观地看到哪几次调用是最慢的、token 消耗最高的请求在哪个时间段、重试发生在哪个步骤。三、记录 token 消耗和模型参数——把业务指标也塞进 Span可观测性不只是看快不快还要看贵不贵。对于 AI CLI 来说token 消耗是核心成本指标。每调一次 GPT-4o几千个 token 就烧没了不记录的话月底看账单直接懵了。use tracing::field; /// 把模型调用的业务指标作为 Span 的 attributes 记录 #[instrument( name llm_inference, skip(prompt), fields( model gpt-4o, prompt_len prompt.len(), // 响应相关字段在调用后记录这里先占位 ) )] async fn llm_inference(prompt: str) - ResultLlmResponse, Boxdyn std::error::Error { let response do_api_call(prompt).await?; // 调用完成后把 token 数据写进当前 Span let current_span Span::current(); current_span.record(prompt_tokens, response.prompt_tokens); current_span.record(completion_tokens, response.completion_tokens); current_span.record(total_tokens, response.total_tokens); current_span.record(cost_usd, format!({:.6}, response.cost_usd).as_str() ); // 同时在日志里打出来方便终端查看 info!( prompt_tokens response.prompt_tokens, completion_tokens response.completion_tokens, total_tokens response.total_tokens, cost format!(${:.6}, response.cost_usd), LLM 调用完成 ); Ok(response) } /// 模拟的 LLM 响应结构 struct LlmResponse { content: String, prompt_tokens: u64, completion_tokens: u64, total_tokens: u64, cost_usd: f64, } async fn do_api_call(_prompt: str) - ResultLlmResponse, Boxdyn std::error::Error { // 实际项目中替换成 openai / anthropic SDK 调用 Ok(LlmResponse { content: 这是 LLM 的回复.to_string(), prompt_tokens: 120, completion_tokens: 350, total_tokens: 470, cost_usd: 0.007, // GPT-4o 大约的单价 }) }有了这些数据在 Jaeger 里你要分析今天哪个请求最烧钱就是一键筛选的事。Span 的 attribute 支持按条件过滤比如total_tokens 1000的请求或者cost_usd 0.01的请求点一下就能看到对应的请求详情。四、生产环境的几个经验教训实践过程中我还踩了不少坑挑几个最有价值的分享批量导出有延迟install_batch是异步批量发送程序退出太快会丢数据。必须在main最后显式调用shutdown_tracer_provider()或者用install_simple同步发送但慢一点。不要在高频循环里打 info如果你在处理一个for循环里面每秒打几百条info!IO 会成为瓶颈。高频操作用debug!生产环境只输出info以上级别。Span 层级别太深追踪粒度过细会导致火焰图太宽、难以阅读。一般建议入口 → 业务逻辑层 → IO 调用层三层够用。敏感信息不入 Spanprompt 内容、API Key 这类信息不要写成 Span attribute因为 Jaeger 是对团队可见的。我只记录prompt_len而不是 prompt 本身。flowchart LR subgraph 你的CLI[你的 Rust CLI] A[tracing Span] -- B{日志输出} B -- C[fmt layer: 终端/文件] B -- D[opentelemetry layer] end subgraph 可观测后端[可观测性后端] D -- E[Jaeger: 分布式追踪] D -- F[Prometheus: 指标采集] C -- G[Loki: 日志聚合] end style 你的CLI fill:#e1f5fe style 可观测后端 fill:#fff3e0五、总结这篇文章记录了我从println!到 tracing OpenTelemetry 的全过程。可观测性不是一个等出了问题再加的东西——等你真的出了 bug没有追踪数据你两眼一摸黑只能靠猜。对于和我一样的自学选手我的建议是从tracing开始。它和println!的使用成本差不多但给你的是一条阶梯式的升级路径——从结构化日志到分布式追踪每一步都能平滑演进。不用一开始就上 Jaeger可以先在终端看折叠的结构化日志等 CLI 的功能定型了再接上 OpenTelemetry 也不迟。我现在的 AI CLI 工具每次运行完都可以打开 Jaeger看一次对话背后到底发生了什么——虽然不是什么大厂的微服务体系但这种看清楚自己代码在干什么的感觉真的让人踏实很多。如果这篇文章帮你打开了可观测性的大门欢迎点赞关注我们下篇见