从一次答非所问的请求说起：AI应用的跨层追踪与成本归因

线上告警说 AI 问答接口 P95 突破 30 秒，但监控面板上每个服务都正常：网关自身耗时 200ms，检索服务无异常，模型侧没有报错。真正的问题藏在这条链路的成本记录中：一次请求跨了三层、调了两次模型、触发了四次工具，却没有任何地方能把它当成一条完整链路来查看。下面从这次排查的路径出发，讲清如何把模型调用、检索、工具调用串成可追踪链路，并把 token 与延迟成本归因到具体的层和租户。

一、这次排查缺的是三样东西，不是日志

复盘后的失败链条是这样：有人把 rerank 的 top_k 从 5 调到了 50，prompt 从 1.2k token 涨到 11k，路由策略把长上下文请求切到了另一个模型，单次调用耗时从 2.1s 涨到 14s；客户端 8s 超时后 SDK 自动重试 2 次，三次物理调用全部超时耗尽配额，触发限流；最终网关返回保底文案“服务繁忙，请稍后再试”。用户看到的是答非所问，运维看到的是全绿。

翻日志的过程很痛苦，因为缺的是三样东西：

• 贯穿标识：网关日志有 request_id，检索服务有 trace_id，模型调用日志只有 session，三者对不上，没法把一次请求的碎片拼起来。
• 分层耗时：只记录了总耗时，看不出是检索慢、排队慢、还是输出阶段慢。
• 按层的 token 与成本：token 数只出现在响应体里，没有保存到数据库中，重试产生的三次调用自然也没有被计账。

三样东西对应可观测性的三个支柱在 AI 场景下的具体形态：trace 负责串联链路，metric 负责全量成本，log 负责定位真正的原因。下面给出最小可落地方案。

二、把一次请求切成层：span 划分与上下文传播

不要一开始就追求完美的埋点，先把 span 的划分确定下来。一条 RAG 或 Agent 请求通常可以切成四类 span，覆盖 90% 的排查场景：

上下文传播是最容易断裂的一环，有四个必须处理的位置：

1. 入口生成：在网关或 API 层生成 trace_id，通过 traceparent 头向下传，不要依赖各服务自己生成。
2. HTTP 出口：调用检索服务、模型网关时注入标准头，用 OpenTelemetry 的自动注入即可，别手写。
3. 异步与队列：写消息时把 trace context 放进消息头，消费端恢复；线程池里 contextvars 会丢，用 contextvars.copy_context() 包一层。
4. 流式响应：SSE 长连接期间 span 一直开着，注意在 finally 里结束，否则异常路径会漏 span。

埋点本身不需要侵入业务代码，用一个统一出口封装就能覆盖大部分：

from opentelemetry import trace
from opentelemetry.trace import Status, StatusCode

tracer = trace.get_tracer("ai.gateway")

def handle(tenant: str, conv_id: str, question: str):
    with tracer.start_as_current_span("ai.request") as root:
        root.set_attribute("app.tenant", tenant)
        root.set_attribute("app.conv_id", conv_id)
        try:
            ctx = retrieve(question)                 # 内部开 retrieval.search
            answer = call_llm(question, ctx, tenant)  # 内部开 llm.chat
            return answer
        except Exception as e:
            root.record_exception(e)
            root.set_status(Status(StatusCode.ERROR))
            raise

关键判断：span 的粒度按“可独立归因的成本单元”划分，不按函数划分。一次 rerank 是独立成本单元，值得单独一个 span；JSON 序列化不是，不要埋点。

三、Token 归因：成本按物理调用算，成功率按逻辑请求算

这是最容易出错的地方。一个逻辑请求可能产生 N 次物理模型调用（重试、并行工具、Agent 多轮循环），成本必须按物理调用算，否则账目永远是低的；而业务成功率必须按逻辑请求算，否则重试一次就会把成功率虚高。

成本记在叶子 span 上，不要记在父 span 上重复累加：

PRICE = {  # 每百万 token 的价格，配置化并带版本号
    "model-a": {"in": 1.0, "cached_in": 0.25, "out": 3.0, "version": "2025-03"},
    "model-b": {"in": 3.0, "cached_in": 0.75, "out": 9.0, "version": "2025-03"},
}

def record_llm_span(span, model: str, usage, attempt: int):
    p = PRICE[model]
    span.set_attribute("gen_ai.request.model", model)
    span.set_attribute("llm.attempt", attempt)
    span.set_attribute("gen_ai.usage.input_tokens", usage.prompt_tokens)
    span.set_attribute("gen_ai.usage.cached_tokens", getattr(usage, "cached_tokens", 0))
    span.set_attribute("gen_ai.usage.output_tokens", usage.completion_tokens)

    cached = getattr(usage, "cached_tokens", 0)
    cost = (
        (usage.prompt_tokens - cached) / 1e6 * p["in"]
        + cached / 1e6 * p["cached_in"]
        + usage.completion_tokens / 1e6 * p["out"]
    )
    span.set_attribute("llm.cost_usd", round(cost, 6))

价格表必须配置化和版本化。模型价格会变，缓存命中和未命中的价差可能有 4 倍，写死在代码里三个月后就对不上账了。

存到 ClickHouse 里做聚合，表结构保持扁平，属性用 Map 兜底：

CREATE TABLE ai_span (
  ts             DateTime64(3),
  trace_id       String,
  span_id        String,
  parent_span_id String,
  name           LowCardinality(String),
  status         LowCardinality(String),
  dur_ms         UInt32,
  app            LowCardinality(String),
  tenant         LowCardinality(String),
  model          LowCardinality(String),
  input_tokens   UInt32,
  cached_tokens  UInt32,
  output_tokens  UInt32,
  cost_usd       Decimal(12, 6),
  attrs          Map(String, String)
) ENGINE = MergeTree
PARTITION BY toDate(ts)
ORDER BY (app, ts, trace_id);

有了这张表，之前那个问题一个查询就能回答：“哪个模型、哪个租户的 token 涨了”：

SELECT
    tenant,
    model,
    count()                          AS calls,
    sum(input_tokens)                AS in_tok,
    sum(cost_usd)                    AS cost_usd,
    sum(cost_usd) / count()          AS cost_per_call,
    quantile(0.95)(dur_ms)           AS p95_ms
FROM ai_span
WHERE name = 'llm.chat'
  AND ts >= now() - INTERVAL 1 DAY
GROUP BY tenant, model
ORDER BY cost_usd DESC
LIMIT 20;

注意 WHERE name = 'llm.chat' 这个条件不能省。如果先在叶子 span 上记了 token 又在父 span 上汇总，聚合时就会翻倍，这是实际发生过的问题。

四、延迟归因：把 p95 拆成可解释的四段

总耗时对排查没有用，要拆。一次请求的延迟大致分四段，每段归属不同的责任方：

两个经验判断：

• TTFT 与输入 token 数强相关，输出阶段与输出 token 数强相关。 分开记录，才能区分“prompt 膨胀”和“模型变慢”两种完全不同的故障。上面那次排查中，TTFT 从 0.6s 涨到 6s，就已经明确指出输入侧出了问题。
• 重试造成的延迟是相乘的。 客户端 8s 超时 + 2 次重试，用户侧就变成 24s 起步，而模型侧看到的每一次调用都“正常”。所以 llm.chat 上的 llm.attempt 属性和 ai.request 上的 retry.count 必须同时存在，把两边的延迟对应起来看。

工具调用和 Agent 循环另外处理：并行工具取 max 而不是 sum，串行循环取 sum，同时记录 agent.step 轮数。轮数异常（比如本该 1 轮却跑了 6 轮）往往比单次耗时更值得告警。

五、四个实际发生过、需要特别注意的问题

坑一：流式响应拿不到 usage。 很多模型服务的流式接口默认不返回 usage，需要显式打开（OpenAI 兼容接口是 stream_options={"include_usage": true}，最后一帧才带）。没打开的话只能按字符数估算，误差轻松超过 10%，成本账目就恒等于估算值。上线前一定要验证这一帧确实拿到了。

坑二：重试的 span 打到 trace 外面。 SDK 内部重试如果没继承 context，会另起一个 trace，排查时看到“只有一次调用但耗时 30s”。解决办法是把重试逻辑收进自己封装的出口层，每次尝试显式 start_as_current_span 作为子 span。

坑三：缓存命中被记成全价。 命中 prompt 缓存的那部分 token 价格可能只有 1/4，但 prompt_tokens 仍然包含它们。不拆分 cached_tokens 会把成本高估 2-3 倍，成本归因直接失真，进而导致错误的优化方向。

坑四：异步任务链路断裂。 后台总结、批量打标这类任务走队列，入口没有 HTTP 头，trace_id 必须从消息体里显式恢复。这里断了，异步任务的成本就永远归不到触发它的用户身上。

六、可观测性本身也要算成本

trace 全量采集的成本不低，一次 RAG 请求 6-8 个 span，高峰期很可观。务实的做法是分两套数据、一个口径：

• trace 用来排障：错误 100% 采样，正常请求 5%-10% 采样，或者用尾部采样（先缓冲整条 trace，看到 error 或 p99 超阈值再决定是否保留）。这样既省下存储成本，又不会丢失需要排查的请求。
• metric 用来做全量成本：token 计数和成本用 counter/histogram 打点，全量上报，不依赖采样。成本核算必须全量，否则按租户分摊对不上账。

两边口径要一致：相同的 model、tenant 维度名，相同的价格版本号。对不上就说明埋点分叉了，早发现比晚发现好。

另外一个容易被忽略的点：采样决策要在 trace 入口做，并且把 sampled 标记随上下文传下去。中途某个服务自己决定采样，会出现“父 span 有、子 span 没有”的残缺链路，排查时比没埋点更误导。

落地建议

1. 第一天就固定 span 命名规范和 trace 传播方式：ai.request / retrieval.search / llm.chat / tool.call 四个名字写进团队规范，traceparent 由网关统一注入，异步任务从消息头恢复。改名字的成本远高于一开始就商量好。
2. 所有模型调用收敛到一个出口封装：usage 解析、成本计算、span 埋点、重试逻辑只写一处。散落在业务代码里的埋点必然分叉，三个月后没人说得清哪个数是准的。
3. 价格表配置化并带版本号，含缓存命中价、输出价、按模型和时间生效。成本报表上标注价格版本，避免历史数据被新价格重算。
4. 采样策略分开设置：trace 错误全采、正常 5%-10% 或尾部采样；成本走 metric 全量打点。成本核算不允许采样。
5. 上线前用一次真实的失败请求做回放验证：人为制造一次超时重试，检查 trace 里能否看到 3 个 llm.chat 子 span、retry.count 是否正确、成本是否为 3 次物理调用之和。这一步能提前发现绝大部分埋点问题。