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

作为一个自学的人，我一度觉得"反正是个小工具，打打 println! 就够了"。直到有一次，一个用户抱怨"你的 CLI 怎么这么慢"，我盯着代码看了两个小时，加了二十几个 println!，才找到是某次重试逻辑在死循环。从那以后，我决定正经学一下可观测性。今天这篇文章，就是我从小白到用上 tracing + OpenTelemetry 的完整记录。

一、从 println! 之痛到结构化日志

刚入门的时候，我的调试手段只有一个：println! 大法。模型调用了就打印一行，返回了就再打印一行。

/// 最原始的调试方式 —— println! 打天下
/// 问题：日志混在一起，没有层级，没有上下文，排查困难
async fn call_llm(prompt: &str) -> Result<String, Box<dyn 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 日志再算。

tracing crate 就是为了解决这些问题设计的。它提供了带**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) -> Result<String, Box<dyn 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) -> Result<String, Box<dyn 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) -> Result<String, Box<dyn 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<(), Box<dyn 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<(), Box<dyn std::error::Error>> {
    // 必须在任何 tracing 调用前初始化
    init_telemetry()?;

    // 所有 tracing 调用现在都会同时：
    // 1. 在终端打印（fmt layer）
    // 2. 发送到 Jaeger（opentelemetry layer）
    let result = call_llm_traced("你好，请解释一下 Rust 的所有权").await?;
    println!("结果: {}", result);

    // 确保程序退出前 Span 被导出（否则会丢数据）
    opentelemetry::global::shutdown_tracer_provider();
    Ok(())
}

配好之后，每次运行 CLI，Jaeger 上就能看到一条完整的调用链。你能直观地看到：哪几次调用是最慢的、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) -> Result<LlmResponse, Box<dyn 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) -> Result<LlmResponse, Box<dyn 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 的请求，点一下就能看到对应的请求详情。

四、生产环境的几个经验教训

实践过程中我还踩了不少坑，挑几个最有价值的分享：

  1. 批量导出有延迟：install_batch 是异步批量发送，程序退出太快会丢数据。必须在 main 最后显式调用 shutdown_tracer_provider()，或者用 install_simple（同步发送，但慢一点）。

  2. 不要在高频循环里打 info：如果你在处理一个 for 循环，里面每秒打几百条 info!，IO 会成为瓶颈。高频操作用 debug!，生产环境只输出 info 以上级别。

  3. Span 层级别太深：追踪粒度过细会导致火焰图太宽、难以阅读。一般建议：入口 → 业务逻辑层 → IO 调用层，三层够用。

  4. 敏感信息不入 Span：prompt 内容、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，看一次对话背后到底发生了什么——虽然不是什么大厂的微服务体系，但这种"看清楚自己代码在干什么"的感觉，真的让人踏实很多。

如果这篇文章帮你打开了可观测性的大门，欢迎点赞关注，我们下篇见！

# rust # github # python
Logo
乐奇 Rokid 开放社区

更多推荐

Word Embedding ：从分布式假设到神经网络语言模型

Word Embedding（词嵌入）是一种将离散的词汇符号映射到连续的低维稠密向量空间的技术。在这个向量空间中，语义相似的词在几何距离上彼此接近，从而实现了从"符号匹配"到"语义计算"的跨越。核心定义词嵌入是将单词（或多词短语）表示为固定维度的实值向量，这些向量之间的距离（例如余弦相似度）反映了单词之间的相关性，这种相关性基于单词通常出现的上下文。分布式假设（1954）↓统计共现分析（LSA/S

avatar 乐奇 Rokid 开放社区

镜游小导：运行在 Rokid AR 眼镜上的景区实景讲解智能体

项目以 RokidAIUI 开放智能体形态交付：页面用.ink描述，运行在眼镜端智能体运行时，直接调用系统能力。AGENTS.md身份镜游小导v1.0.0，景区 AR 实景讲解智能体；权限（Capabilities）microphonenetworkaudiogyroscope；技能（Skills）。

avatar 乐奇 Rokid 开放社区
cover

AI 智能眼镜技术文档

avatar 乐奇 Rokid 开放社区