10 可观测与线上运维

第一部分 速记页

第二部分 易混对照

第三部分 面试口述稿

3.1 “你的 Agent 上线后怎么知道它运行得好不好？”

我会从三个层面记录。第一是每次运行一条记录：任务、开始结束时间、最终状态、步数、总 token。状态我分得比较细，成功、模型自己停下但验收没过、步数用完、卡住重复调用、程序崩溃，这几种要分开，不然”失败率上升”不知道从哪查。

第二是每一步的记录：模型调用的 token、耗时、停止原因；工具调用的名字、参数、是否成功、结果和耗时。结构上用链路追踪的方式，整次运行是一个 trace，每次模型调用和工具调用是它下面的 span，这样能看出时间花在哪、哪一步出的错。

第三是汇总指标和告警：完成率、平均步数、工具失败率、P95 耗时、每次运行成本。

我项目里做了前两层的简化版，用 SQLite 两张表存每次运行和每次工具调用，网页上可以点开任意一次运行看每一步。评测里发现的验收 bug、安全漏洞，都是翻这些记录找到的。

3.2 “Agent 的链路追踪和普通服务有什么不一样？”

结构是一样的，都是 trace 套 span。不一样的主要有三点。

一是要记的内容不同。除了耗时和错误，还要记 token、缓存命中、模型停止原因、工具参数和结果，因为 Agent 的问题很多不是报错，而是”做了不该做的事”，只看状态码看不出来。

二是同一个请求每次路径不一样，步数不固定，所以 span 树的形状每次都不同，看板要能按运行展开看，而不只是看平均值。

三是内容敏感。提示词和工具结果里可能有用户数据、密钥，OpenTelemetry 的 GenAI 约定里，记录输入输出消息的字段默认是不开启的，要显式打开。打开的话要先脱敏，并控制谁能看。

3.3 “延迟太高怎么排查？”

先拆开看时间花在哪。Agent 一次运行的时间大致是：步数乘以每步的模型时间，加上所有工具执行时间。模型时间里再分首 token 延迟和生成时间。

然后分别处理。步数多，看轨迹是不是在绕路，是提示词或工具设计的问题；模型慢，看输入是不是太长、能不能用缓存、能不能换小模型处理简单步骤；工具慢，看是不是有可以并行或缓存的调用。

看的时候用 P50 和 P95，不看平均。我项目算过，run_command 的中位数只有 26 毫秒，P95 却接近 15 秒，因为大部分是 ls 这类秒回的命令，少数是真正的编译。平均值会把这两种情况混在一起，得出一个哪边都不像的数。

3.4 “怎么控制 Agent 的成本？”

先要算得出来。每次模型调用记下输入 token、缓存命中 token 和输出 token，乘以对应单价，按运行、用户、功能汇总。

Agent 的成本结构有个特点：输入远大于输出，因为每一步都要重发之前的全部历史。我项目 288 次运行，输入是输出的 41.6 倍。所以省钱的重点在输入：稳定的前缀放前面让缓存命中；工具结果截断、历史压缩；限制步数上限，因为失败的运行往往跑满步数，是最贵的。

然后是兜底：单次运行设 token 或金额上限，超了就停；每天设总预算，接近时告警。我项目有一次就是余额耗尽，DeepSeek 返回 402，评测脚本没有停，又连着崩了四个项目，要是有连续崩溃告警就能早点发现。

3.5 “日志里要记用户的输入吗？隐私怎么处理？”

要看场景，但默认应该谨慎。不记内容的话，出了问题很难复现；全记的话，有泄露风险，还可能不合规。

我的做法是分层：指标和结构信息全量记，比如 token、耗时、工具名、成功与否，这些不含内容。内容部分写入前先脱敏，把密钥、手机号、身份证号这类用规则替换掉；原文只对少数有权限的人可见，设保留期限，到期删除。出错的运行完整保留，正常的可以抽样。

还有一点容易漏：工具的结果里也可能有敏感内容，比如读到了配置文件，脱敏不能只做用户输入。

3.6 “Langfuse、LangSmith 这类工具你用过吗？”

我项目里没有接，是自己用 SQLite 记的，因为是单机项目，两张表够用，也方便直接写 SQL 分析评测数据。

这类工具解决的问题是一样的：把每次模型调用、检索、工具调用按 trace 记下来，自动算 token 和成本，提供看板、打分和数据集功能。Langfuse 是开源的，可以自己部署，数据不出公司；LangSmith 是 LangChain 团队的，和 LangChain、LangGraph 集成最顺，但不用 LangChain 也能手动接。

如果要上线，我会优先按 OpenTelemetry 的约定去埋点，这样后端换成哪个平台都不用改业务代码。

第四部分 逐个详解

4.1 为什么 Agent 特别需要可观测

先说”可观测”这个词是怎么来的。 它最早不是软件里的词，而是控制理论的概念：1960 年匈牙利裔美国工程师 Rudolf E. Kálmán 提出，一个系统如果能靠它的输出反推出内部状态，就叫”可观测”（Observability）。软件行业原来说的是”监控”：事先想好要看哪些数，CPU、内存、错误率，超过阈值就报警。单体程序时代这够用，出了事登上那台机器翻日志就行。后来一个请求要穿过几十个服务，问题常常是事先没想到的组合，“事先想好要看什么”就不够了。2013 年 9 月 Twitter 工程博客发了一篇 Observability at Twitter，介绍他们专门的 Observability 团队怎么收集、存储、查询指标，是这个词在互联网公司里比较早的公开用法。

可观测性（observability）：能通过系统对外输出的数据，推断出它内部处于什么状态、为什么会这样。和”监控”的区别在于：监控回答事先想好的问题（CPU 高不高、错误率多少），可观测要能回答事先没想到的问题（为什么这个用户的请求花了 40 步）。

Agent 比普通服务更需要它，原因有四个：

一个真实的例子能说明”没有告警”的代价。我项目 runs.db 里，run 208 跑到第 28 步时 DeepSeek 返回 402（余额不足），接下来 209 到 212 四个项目每个都是第 1 步就崩溃：

208 re2           crash:APIStatusError  28 步
209 libuv         crash:APIStatusError   1 步
210 curl          crash:APIStatusError   1 步
211 libjpeg-turbo crash:APIStatusError   1 步
212 freetype      crash:APIStatusError   1 步

评测脚本对每个项目单独捕获异常、继续跑下一个，这对”一个项目出错不影响其他项目”是合理的，但对”余额没了”这种全局问题，继续跑没有意义。如果有一条”连续 3 次崩溃就告警”的规则，在 210 的时候就能发现。4.7 节的实验会用真实数据把这条规则跑出来。

4.2 三种数据：日志、指标、链路追踪

三者要能互相跳转：指标告警说”工具失败率上升了”，点进去看是哪些 trace，再看这些 trace 里失败 span 的日志。能跳转的前提是它们共用同一个 ID，比如日志里带上 trace_id。

先说链路追踪和 OpenTelemetry 是怎么来的。 日志和指标很早就有，链路追踪是分布式系统多了以后才被逼出来的。按 Dapper 论文里举的例子，Google 的一次搜索可能要用到上千台机器、很多个不同的服务，慢了不知道慢在哪一环。Google 的 Benjamin Sigelman 等人 2010 年 4 月发表了技术报告 Dapper，描述了他们内部的做法：给每个请求一个全局编号，经过的每一环记一段带父子关系的耗时记录，也就是后来的 trace 和 span。2012 年 Twitter 照着论文做了开源的 Zipkin（介绍文章），之后各家又做了一堆追踪系统。

问题跟着来了：每家后端的埋点代码都不一样，换一个后端就要把代码里的埋点全改一遍。为了统一埋点接口，社区先后出了两个标准，OpenTracing 和 Google 发起的 OpenCensus，两者功能大量重叠，开发者反而不知道该用哪个。2019 年 5 月两边宣布合并成 OpenTelemetry，Google 的公告里原话大意是”这两个项目最大的问题就是有两个”（公告）。它随即成为 CNCF 的项目，2026 年 5 月 21 日正式毕业（CNCF 公告），毕业是 CNCF 对项目成熟度的最高一档认定。

flowchart LR
    D["Dapper 论文<br/>Google 2010"] --> Z["Zipkin<br/>Twitter 2012 开源"]
    Z --> M["各家追踪系统<br/>埋点代码互不兼容"]
    M --> OT["OpenTracing<br/>统一追踪接口"]
    M --> OC["OpenCensus<br/>Google 发起"]
    OT --> OTel["OpenTelemetry<br/>2019 合并"]
    OC --> OTel
    OTel --> G["CNCF 毕业<br/>2026-05"]

OpenTelemetry（简称 OTel）：一个开源的可观测标准和工具集，由 CNCF（云原生计算基金会）托管。它定义了日志、指标、链路追踪的数据格式和各种语言的 SDK，采集一次数据，可以发给不同的后端（Jaeger、Grafana、Datadog、Langfuse 等）。

链路追踪里的几个概念：

• trace：一次完整请求，有一个全局唯一的 trace_id
• span：请求中的一个环节，有自己的 span_id、开始时间、耗时、名字和一组属性（attributes），也就是键值对
• 父 span：一个 span 可以包含子 span。子 span 记下父 span 的 ID，所有 span 就能拼回一棵树
• 状态和错误：span 可以标记为出错，并记录错误类型

用在 Agent 上，一次运行大致长这样：

flowchart TD
    A["invoke_agent crossbuild<br/>整次运行 72s"] --> M1["chat deepseek-flash<br/>第 1 步 2.1s<br/>in=3200 out=80"]
    A --> T1["execute_tool list_files<br/>第 1 步 1ms"]
    A --> M2["chat deepseek-flash<br/>第 2 步 1.8s"]
    A --> T2["execute_tool run_command<br/>第 2 步 14.9s<br/>cmake --build"]
    A --> M3["……"]
    A --> V["verify<br/>独立验收"]

图里的数字是示意，不是某次真实运行。

4.3 一个 Agent 每一步该记什么

按三个层级列。“我项目”一列标出做到了哪些，数据来自 agent/trace.py 的两张表。

整次运行

每次模型调用

每次工具调用

一个经验：字段宁可多记一点，事后补不回来。我项目的”缓存命中”和”模型耗时”没记，写这一篇时想分析就没有数据了，只能用”总耗时减去工具耗时”粗略估计（见 4.8 节）。

4.4 OpenTelemetry 的 GenAI 语义约定

语义约定（semantic conventions）：OTel 规定”某类操作的 span 叫什么名字、带哪些属性、属性叫什么”。有了统一名字，不同语言、不同框架埋的点，后端都能用同一套看板。

大模型相关的约定叫 GenAI semantic conventions。要注意两件事：

1. 还在开发中。文档里的状态标记是 Development，不是 Stable，字段名以后可能改
2. 已经搬家。原来在 OTel 主仓库的文档页，现在显示”已迁移、不再维护”，新位置是单独的 semantic-conventions-genai 仓库。网上很多文章引用的还是旧页面，比如旧版里提供方字段叫 gen_ai.system，新版叫 gen_ai.provider.name

下面是从新仓库 docs/gen-ai/ 下几份文档里核对到的内容（2026-09 查阅）。

span 名字和操作类型

操作类型的已知值里还有 plan（规划或任务拆解）、create_memory、search_memory 等和记忆相关的操作。

模型调用 span 的常用属性

Opt-In 是”需要主动开启才记录”的意思。提示词、回答、系统指令、工具定义这些内容类字段默认都不记，因为它们可能包含用户隐私和公司机密。

gen_ai.usage.input_tokens 要包含缓存命中的部分，这一点和有些厂商返回的字段不同，换算时要小心。约定里举的例子：100 个文本 token（其中 40 个命中缓存）加 200 个图片 token，input_tokens 记 300，cache_read.input_tokens 记 40。

工具调用 span：名字 execute_tool {gen_ai.tool.name}，类型是 INTERNAL（进程内部操作）；必填 gen_ai.tool.name，推荐 gen_ai.tool.call.id（模型给这次调用分配的 ID，用来和模型调用对上）。

指标：约定了几个直方图指标，包括 gen_ai.client.token.usage（token 用量）、gen_ai.client.operation.duration（操作耗时，单位秒）、gen_ai.client.operation.time_to_first_chunk（流式返回时收到第一块的时间）。

直方图（histogram）：一种指标类型，不只记平均值，而是记录数值落在各个区间里的个数，这样才能算出 P50、P95。

4.5 动手实验 1：一个最小的 span 记录器

不装 OTel SDK，用标准库写一个最简单的链路追踪，把 trace、span、父子关系、属性、错误记录、脱敏、成本都串一遍。保存为 mini_span.py。

import re
import time
import uuid
from contextlib import contextmanager

SPANS = []
STACK = []
SECRET = re.compile(r"(sk-[A-Za-z0-9]{6,}|(?i:password|token)=\S+)")


def redact(text):
    return SECRET.sub("[已脱敏]", text)


@contextmanager
def span(name, **attrs):
    parent = STACK[-1] if STACK else None
    record = {
        "trace_id": parent["trace_id"] if parent else uuid.uuid4().hex[:8],
        "span_id": uuid.uuid4().hex[:8],
        "parent_id": parent["span_id"] if parent else None,
        "name": name,
        "attrs": attrs,
        "start": time.perf_counter(),
    }
    STACK.append(record)
    try:
        yield record
    except Exception as e:
        record["attrs"]["error.type"] = type(e).__name__
        raise
    finally:
        record["ms"] = (time.perf_counter() - record["start"]) * 1000
        STACK.pop()
        SPANS.append(record)


def fake_model(step):
    time.sleep(0.03)
    if step == 1:
        return {"tool": "run_command", "args": "cmake -B build", "in": 1800, "cached": 0, "out": 40}
    return {"tool": None, "in": 2600, "cached": 1700, "out": 25}


def fake_tool(args):
    time.sleep(0.05)
    if "build" in args:
        raise RuntimeError("configure failed, token=abc123")


with span("invoke_agent crossbuild", **{"gen_ai.conversation.id": "run-42"}):
    for step in (1, 2):
        with span("chat deepseek-flash") as s:
            r = fake_model(step)
            s["attrs"].update({"gen_ai.usage.input_tokens": r["in"],
                               "gen_ai.usage.cache_read.input_tokens": r["cached"],
                               "gen_ai.usage.output_tokens": r["out"]})
        if r["tool"]:
            try:
                with span(f"execute_tool {r['tool']}", **{"gen_ai.tool.name": r["tool"]}) as t:
                    fake_tool(r["args"])
            except RuntimeError as e:
                t["attrs"]["result"] = redact(str(e))


def cost(a):
    miss = a["gen_ai.usage.input_tokens"] - a["gen_ai.usage.cache_read.input_tokens"]
    return (miss * 0.15 + a["gen_ai.usage.cache_read.input_tokens"] * 0.003
            + a["gen_ai.usage.output_tokens"] * 0.6) / 1e6


def show(parent_id, depth):
    for s in sorted((x for x in SPANS if x["parent_id"] == parent_id), key=lambda x: x["start"]):
        extra = ""
        if "gen_ai.usage.input_tokens" in s["attrs"]:
            extra = f"  in={s['attrs']['gen_ai.usage.input_tokens']} cached={s['attrs']['gen_ai.usage.cache_read.input_tokens']} ${cost(s['attrs']):.6f}"
        if "error.type" in s["attrs"]:
            extra = f"  error={s['attrs']['error.type']} result={s['attrs']['result']}"
        print(f"{'  ' * depth}{s['name']:<28}{s['ms']:>6.0f}ms{extra}")
        show(s["span_id"], depth + 1)


print("trace", SPANS[-1]["trace_id"])
show(None, 0)

实际输出（Python 3.14，只用标准库；trace ID 是随机的，毫秒数每次略有不同）：

trace c71fe2cf
invoke_agent crossbuild        122ms
  chat deepseek-flash             35ms  in=1800 cached=0 $0.000294
  execute_tool run_command        52ms  error=RuntimeError result=configure failed, [已脱敏]
  chat deepseek-flash             35ms  in=2600 cached=1700 $0.000155

逐段讲。

开头的全局变量。

• SPANS = []：所有结束了的 span 都放进这个列表
• STACK = []：当前”正在进行中”的 span，像一摞盘子，最上面那个是当前所在的环节。新开一个 span 时，它的父亲就是栈顶那个
• re.compile(...)：re 是正则表达式模块，compile 把规则预先编译好，反复用时更快
• 正则 sk-[A-Za-z0-9]{6,} 匹配 sk- 开头、后面至少 6 个字母数字的字符串，很多 API 密钥长这样；(?i:password|token)=\S+ 匹配 password= 或 token= 后面跟着的非空白字符，(?i:...) 表示括号里这一段不区分大小写，\S+ 是一个或多个非空白字符
• SECRET.sub("[已脱敏]", text)：把所有匹配到的部分替换成 [已脱敏]

span 函数。 这是整个实验的核心。

• @contextmanager：装饰器（decorator），写在函数定义上一行，给函数加上额外能力。contextmanager 来自标准库 contextlib，它把一个带 yield 的函数变成上下文管理器（context manager），就能用 with span(...) as s: 的写法
• with 语句的执行顺序：先执行 yield 之前的代码 → yield record 把 record 交给 as s 里的 s → 执行 with 块里的代码 → 回来执行 yield 之后的代码。它保证”开始”和”结束”一定成对，哪怕中间出了异常
• **attrs：关键字可变参数，调用时写的 name=value 形式的参数全部收进一个字典 attrs。因为 OTel 属性名里带点号（gen_ai.tool.name），不能直接写成 gen_ai.tool.name="x"，所以调用时用 **{"gen_ai.tool.name": ...} 把字典展开传进去
• parent = STACK[-1] if STACK else None：STACK[-1] 取列表最后一个元素；栈为空时（最外层）没有父亲
• trace_id：有父亲就沿用父亲的，没有就新生成一个。一棵树上所有 span 共用一个 trace_id
• uuid.uuid4().hex[:8]：生成随机唯一 ID，.hex 转成 32 位十六进制字符串，取前 8 位让输出短一点。真实系统要用完整长度
• time.perf_counter()：高精度计时器，只适合算时间差，不代表当前几点
• try / except / finally：except Exception as e 捕获异常，把异常类名记进属性后，用 raise 原样重新抛出，记录错误但不吞掉错误；finally 里的代码无论成功还是出错都会执行，所以耗时一定会被记下来，栈也一定会弹出

假模型和假工具。

• fake_model 第 1 步要求调用工具，第 2 步结束。第 2 步 2600 个输入 token 里有 1700 个命中缓存，模拟”前缀和上一步相同”的情况
• fake_tool 故意抛出一个异常，报错信息里带着 token=abc123，用来演示脱敏

主流程。

• 最外层 invoke_agent 是整次运行；循环里每步开一个 chat span，有工具调用再开一个 execute_tool span。因为它们在 with 块里面，自动成为最外层的子 span
• s["attrs"].update({...})：字典的 update 方法，把另一个字典的键值合并进来。token 数要等模型返回后才知道，所以在 span 进行中补上
• 工具 span 外面包了 try / except RuntimeError：span 内部记录了 error.type 并把异常抛出来，外层捕获后把脱敏后的报错写进属性。真实 Agent 里这一步就是”把报错作为工具结果回给模型”

成本和打印。

• cost：未命中的输入按每百万 0.15 美元，命中的按 0.003 美元，输出按 0.6 美元。这是写这篇时核对的 DeepSeek 价格页上 deepseek-flash 非高峰价格，价格会变，只作演示
• show 是递归函数，自己调用自己：先找出父 ID 等于给定值的所有 span，打印后再以它为父亲找下一层
• (x for x in SPANS if ...)：生成器表达式，和列表推导式写法一样但用圆括号，不会一次性生成整个列表
• key=lambda x: x["start"]：lambda 是一行写完的匿名函数，这里告诉 sorted 按开始时间排序。因为 span 是结束时才加进 SPANS 的，子 span 比父 span 先结束，不排序的话顺序是乱的
• SPANS[-1] 是最后结束的 span，也就是最外层那个

看输出。

1. 树形结构直接显示了父子关系，一眼能看出第 1 步工具失败了
2. 算一下耗时：35 + 52 + 35 = 122 毫秒，和最外层的耗时对得上，说明时间全部花在这三个环节上。如果外层明显大于子 span 之和，就说明有没被记录的环节
3. 第 2 步输入 token 更多（2600 对 1800），成本却更低（0.000155 对 0.000294），因为 1700 个命中了缓存。不记缓存命中，成本就算不准
4. 报错里的 token=abc123 被替换掉了

自己改一改：

1. 把 fake_tool 里的报错改成 "key is sk-abcdef123456"，看能不能被脱敏
2. 给 fake_model 加一个第 3 步，再调一次工具，看树形输出的变化
3. 在 span 函数里加一个 step 属性，打印时显示”第几步”
4. 故意在最外层 with 块最后加一句 time.sleep(0.1)，看外层耗时和子 span 之和的差距

4.6 我项目的记录是怎么做的

数据流：

flowchart LR
    LOOP["build_events<br/>Agent 循环"] -->|start / tool_call<br/>add_usage / finish| TR["Trace<br/>agent/trace.py"]
    TR --> DB[("runs.db<br/>runs + tool_calls")]
    LOOP -->|yield 事件| SSE["/api/build<br/>SSE 实时推送"]
    DB --> API["/api/runs<br/>/api/runs/{id}"]
    API --> WEB["RunHistory.vue<br/>运行列表 + 每步详情"]
    DB --> SQL["直接写 SQL<br/>评测分析"]

两条路：实时的事件通过 SSE 推给正在看的网页（14 篇细讲）；持久化的记录写进 SQLite，事后通过接口查，或者直接写 SQL 分析。

表结构（agent/trace.py）：

CREATE TABLE IF NOT EXISTS runs (
    id INTEGER PRIMARY KEY AUTOINCREMENT,
    task TEXT NOT NULL,
    workdir TEXT NOT NULL,
    model TEXT,
    started_at REAL NOT NULL,
    finished_at REAL,
    status TEXT,
    steps INTEGER DEFAULT 0,
    prompt_tokens INTEGER DEFAULT 0,
    completion_tokens INTEGER DEFAULT 0,
    result TEXT
);
CREATE TABLE IF NOT EXISTS tool_calls (
    id INTEGER PRIMARY KEY AUTOINCREMENT,
    run_id INTEGER NOT NULL REFERENCES runs(id),
    step INTEGER NOT NULL,
    tool TEXT NOT NULL,
    args TEXT,
    ok INTEGER NOT NULL,
    result TEXT,
    duration_ms REAL NOT NULL,
    created_at REAL NOT NULL
);
CREATE INDEX IF NOT EXISTS idx_tool_calls_run ON tool_calls(run_id);

• runs 是一次运行一行，tool_calls 是一次工具调用一行，用 run_id 关联。这相当于一个只有两层的 span 树：运行是根，工具调用是叶子，模型调用这一层没有单独的行
• started_at REAL：时间存成 Unix 时间戳（从 1970 年起的秒数），REAL 是浮点数类型
• idx_tool_calls_run：按 run_id 建索引，查”某次运行的所有工具调用”时不用扫全表

Trace 类的四个方法对应运行的生命周期：

几个值得讲的细节：

1. 每次写入都立刻 commit。运行中途进程崩了，已经执行的步骤也都在库里。代价是每次写都要落盘，对一次几十步的运行来说可以忽略
2. 崩溃也会记。build_events 用 try / except 包住整个循环，出异常时先 tracer.finish(f"crash:{type(e).__name__}", ...) 再重新抛出。402 余额不足那几次就是这样记下来的
3. add_usage 只累加到运行上，没有按步记，也没有取缓存命中字段，所以事后算不出每一步的上下文增长，也算不出真实成本
4. check_same_thread=False：Python 的 sqlite3 默认不允许在创建连接的线程之外使用这个连接。LangGraph 版本在线程池里跑节点，第一次运行（run 162）直接崩了，状态记为 crash:ProgrammingError，加上这个参数才解决

网页查看（server/app.py + web/src/components/RunHistory.vue）：/api/runs 返回最近 50 次运行的摘要，/api/runs/{id} 返回某次运行的全部工具调用。前端表格列出每次运行的状态、步数、token、耗时，点开一行显示每一步的工具名、参数、成功与否、耗时，再点可以展开结果。

这就是一个最简单的”轨迹查看器”。09 篇里提到的那些发现，大部分是这样一次次点开看出来的。

4.7 动手实验 2：从真实运行记录里算指标

用我项目真实的 runs.db（288 次运行、5625 次工具调用），算每个工具的失败率和耗时分位数，跑一遍”连续崩溃告警”规则，再粗估成本。保存为 trace_stats.py，放在项目根目录运行。

import sqlite3
import sys
from collections import defaultdict
from pathlib import Path

db = Path(sys.argv[1] if len(sys.argv) > 1 else "runs.db").resolve()
conn = sqlite3.connect(f"file:{db}?mode=ro", uri=True)


def p95(values):
    values = sorted(values)
    return values[max(0, int(len(values) * 0.95 + 0.5) - 1)]


durations = defaultdict(list)
fails = defaultdict(int)
for tool, ok, ms in conn.execute("SELECT tool, ok, duration_ms FROM tool_calls"):
    durations[tool].append(ms)
    fails[tool] += 0 if ok else 1

print(f"{'工具':<18}{'调用':>6}{'失败率':>8}{'P50毫秒':>10}{'P95毫秒':>10}{'最长毫秒':>10}")
for tool, ms in sorted(durations.items(), key=lambda kv: -len(kv[1])):
    n = len(ms)
    print(f"{tool:<18}{n:>6}{fails[tool] / n:>8.1%}{sorted(ms)[n // 2]:>10.0f}{p95(ms):>10.0f}{max(ms):>10.0f}")

print()
rows = conn.execute("SELECT id, status, steps FROM runs ORDER BY id").fetchall()
streak = []
for run_id, status, steps in rows:
    if status and status.startswith("crash"):
        streak.append((run_id, steps))
        if len(streak) == 3:
            print(f"告警：从 run {streak[0][0]} 起连续 3 次崩溃")
    else:
        if len(streak) >= 3:
            print(f"  这一串共 {len(streak)} 次：{[r for r, _ in streak]}，步数 {[s for _, s in streak]}")
        streak = []
if len(streak) >= 3:
    print(f"  这一串共 {len(streak)} 次：{[r for r, _ in streak]}，步数 {[s for _, s in streak]}")

tin, tout = conn.execute("SELECT SUM(prompt_tokens), SUM(completion_tokens) FROM runs").fetchone()
print()
print(f"输入 {tin:,} token，输出 {tout:,} token，输入/输出 = {tin / tout:.1f}")
cost = tin / 1e6 * 0.15 + tout / 1e6 * 0.6
print(f"全按缓存未命中、非高峰价粗估：${cost:.2f}")

实际输出（Python 3.14 自带的 sqlite3，SQLite 3.53.4）：

工具                    调用     失败率     P50毫秒     P95毫秒      最长毫秒
run_command         2724   17.5%        26     14936    120005
read_file           2151    0.8%         1         1        92
list_files           626    1.0%         0         1        11
write_file            74    0.0%         1         2         4
search_knowledge      50    0.0%         0       773      1464

告警：从 run 208 起连续 3 次崩溃
  这一串共 5 次：[208, 209, 210, 211, 212]，步数 [28, 1, 1, 1, 1]

输入 48,704,845 token，输出 1,169,783 token，输入/输出 = 41.6
全按缓存未命中、非高峰价粗估：$8.01

中文字符在终端里占两格宽，表头会有点错位，不影响数字。

逐段讲。

打开数据库。

• sys.argv：命令行参数列表，sys.argv[0] 是脚本名，sys.argv[1] 是第一个参数。没传就默认用 runs.db
• Path(...).resolve()：转成绝对路径
• f"file:{db}?mode=ro" 加 uri=True：用 URI 形式打开数据库，mode=ro 是只读模式。分析线上数据时养成只读打开的习惯，脚本写错了也不会改坏数据

分位数。

• 分位数（percentile）：把所有数从小到大排好，P95 就是排在 95% 位置上的那个数，意思是”95% 的调用不比它慢”
• p95 用的是最近排名法：位置 = 数量 × 0.95，四舍五入后取那个位置的数。int(x + 0.5) 是四舍五入的一种简单写法；列表下标从 0 开始，所以要减 1；max(0, ...) 防止只有一个数时下标变成负数
• P50（中位数）直接用 sorted(ms)[n // 2]，// 是整除
• 分位数的算法有好几种（线性插值、最近排名等），数据少时结果会有差别。看板上的 P95 和自己算的对不上时，先查是不是算法不同

按工具汇总。

• defaultdict(list)：来自 collections 的字典，访问不存在的键时自动创建一个空列表，不用先判断键在不在。defaultdict(int) 则自动创建 0
• for tool, ok, ms in conn.execute(...)：查询结果可以直接遍历，每行是一个元组（tuple），拆成三个变量
• fails[tool] += 0 if ok else 1：数据库里 ok 存的是 1 或 0
• sorted(durations.items(), key=lambda kv: -len(kv[1]))：按调用次数从多到少排序，取负号就是倒序
• {fails[tool] / n:>8.1%}：格式说明 .1% 把小数乘 100 显示成百分比，保留 1 位小数

连续崩溃告警。

• 按运行 ID 顺序遍历，streak 列表记录当前连续崩溃的运行
• 状态以 crash 开头就追加进去；刚好攒够 3 次时打印告警（只在第 3 次打印一次，不会每次都打）；遇到非崩溃的运行就清空
• 循环结束后还要再检查一次，因为连续崩溃可能一直持续到最后一条记录

成本。

• fetchone()：只取查询结果的第一行
• {tin:,}：格式说明里的逗号表示千分位分隔

看结果，能读出几件事。

1. run_command 的 P50 只有 26 毫秒，P95 却接近 15 秒。大部分命令是 ls、cmake -E 这种秒回的，少数是真正的编译。这种两极分化的分布，平均值哪边都不代表，所以要看分位数
2. 最长 120005 毫秒是一次命令超时被终止（cmake -P _findabsl.cmake，120 秒上限）。超时这类极端值要单独统计
3. run_command 失败率 17.5%，远高于其他工具。这很正常：编译报错是 Agent 获取信息的主要途径，失败不等于有问题。失败率要结合工具的性质看，读文件工具失败率 0.8% 就值得看一下是什么情况
4. 告警规则在 run 210 时就会触发，而实际上这一串崩溃一直持续到 212。每个崩溃的项目都只跑了 1 步，说明第一次调模型就失败了，是全局问题而不是项目问题
5. 成本粗估约 8 美元。这是按写这篇时的价格页、全部按缓存未命中、非高峰价算的。实际上缓存会命中一部分（Agent 每一步的前缀和上一步大量重复），高峰时段价格翻倍，而且跑评测时的价格也未必和现在相同。因为没记缓存命中，我算不出真实成本，只能给一个粗略的数量级

自己改一改：

1. 把连续崩溃的阈值改成 2，看会不会多出告警
2. 加一段：按 status 分组，统计每种状态的平均步数和平均输入 token，看失败的运行是不是更贵
3. 只统计 tool_calls 里 result 包含”超时”的调用，看有多少次

没有 runs.db 的话，可以用 4.5 节的思路自己造一个小库练习。

4.8 延迟怎么拆开看

一次模型调用的时间：

sequenceDiagram
    participant C as 客户端
    participant M as 模型服务
    C->>M: 发请求（带完整上下文）
    Note over M: 排队<br/>处理输入（输入越长越慢）
    M-->>C: 第一个 token
    Note over C,M: 首 token 延迟 TTFT
    M-->>C: 后续 token……
    M-->>C: 最后一个 token
    Note over C,M: 总耗时 = TTFT + 输出 token 数 × 每 token 时间

• 首 token 延迟（TTFT，time to first token）：发出请求到收到第一个 token 的时间，主要受输入长度、排队、缓存影响
• 每 token 生成时间：流式输出时相邻两块之间的间隔。OTel 约定里有对应的指标 gen_ai.client.operation.time_per_output_chunk

一次 Agent 运行的时间：

总耗时 ≈ Σ(每步模型时间) + Σ(每个工具耗时) + 其他（准备、验收）

我项目的真实拆分：268 次成功运行，总耗时 14,676 秒，其中工具耗时 7,632 秒，占 52%。剩下的部分平均每步 1.9 秒。

要说清楚这个数的局限：项目没有单独记模型调用耗时，“剩下的部分”是用总耗时减去工具耗时得来的，里面除了模型调用，还包括启动时的项目探测和结束时的独立验收（验收要重新跑一遍构建）。所以 1.9 秒是每步模型耗时的上限，不是精确值。

排查思路：

flowchart TD
    S[运行太慢] --> Q1{步数多吗}
    Q1 -->|多| A1[读轨迹看绕路<br/>改提示词 / 工具设计 / 加知识]
    Q1 -->|不多| Q2{模型时间占比高吗}
    Q2 -->|高| A2[输入太长？压缩历史、截断工具结果<br/>缓存命中了吗？稳定前缀放前面<br/>简单步骤换小模型]
    Q2 -->|不高| Q3{哪个工具慢}
    Q3 --> A3[能并行吗？能缓存吗？<br/>超时设置合理吗？]

步数永远是第一个要看的，因为它是乘数：每多一步，就多一次模型调用，而且每次的输入都比上一次更长。

4.9 成本看板

算法：

单次调用成本 = (输入 token − 缓存命中 token) × 未命中单价
             + 缓存命中 token × 命中单价
             + 输出 token × 输出单价

有的厂商写缓存还要额外收费（比如 Anthropic 写入 5 分钟缓存按 1.25 倍价格计费，见 06 篇），要按厂商的规则加上。

看板上放什么：

控制手段：

1. 单次运行上限：步数上限、token 上限或金额上限，超了就停。我项目的步数上限 40 就是这个作用。09 篇里说过，步数上限本质上是”愿意为一次失败付多少钱”
2. 每日预算：接近时告警，超了降级（换便宜模型或暂停非核心功能）
3. 余额监控：我项目就是没有这一条，余额耗尽后才从 402 报错里知道

4.10 线上指标和告警

先看通用的四个黄金信号。 Google SRE 书 Monitoring Distributed Systems 一章提出，监控面向用户的系统，至少要看四个信号：延迟、流量、错误、饱和度。其中”错误”包括显式的（比如 HTTP 500）、隐式的，以及按策略认定的。Agent 的大部分问题都是隐式错误：状态码正常，结果不对。

Agent 要加上的指标：

告警怎么设。 同一章里有几条原则很适合 Agent：

• 每条告警都要能处理。收到后只需要机械操作的，就不该发告警，应该自动化
• 优先盯症状，不盯原因。用户看得到的问题（完成率下降、延迟变高）优先；原因类的告警只设那些非常确定、马上要出事的
• 看尾部延迟，不看平均。和 4.7 节看到的一样

具体到 Agent，几条常见规则：

不要对单次失败告警。 Agent 本来就有随机性，单次失败很正常，告警太多大家就不看了，这叫告警疲劳。

4.11 隐私、脱敏和保留

Agent 的记录里敏感内容比普通服务多得多：用户的原始提问、检索到的内部文档、工具读到的文件、模型的回答。

flowchart LR
    RAW[原始事件] --> SPLIT{是内容吗}
    SPLIT -->|结构和数字<br/>token 耗时 工具名 状态| ALL[(全量保存<br/>长期)]
    SPLIT -->|提示词 回答 工具结果| RED[脱敏]
    RED --> KEEP{出错了吗}
    KEEP -->|是| FULL[(完整保留<br/>限制访问 设期限)]
    KEEP -->|否| SAMPLE[(抽样保存<br/>限制访问 设期限)]

要点：

1. 结构信息和内容分开。token、耗时、工具名、状态这些不含内容，全量存；内容单独处理。这和 OTel 约定里”内容字段默认不记”是一个思路
2. 写入前脱敏。用规则替换密钥、手机号、身份证号、邮箱，4.5 节实验演示了最简单的做法。规则总会漏，所以脱敏之外还要有第 3、4 条
3. 访问控制。能看原文的人要少，看的操作要有记录
4. 保留期限。到期删除；用户要求删除自己的数据时，记录也要能删
5. 工具结果也要脱敏。只盯着用户输入是不够的，Agent 读到的配置文件、环境变量、数据库查询结果都可能有敏感内容
6. 采样。正常的运行抽一部分存内容，出错的全部保留

我项目在这方面的情况：tool_calls.result 存的是工具结果原文（截断到 2000 字符），没有脱敏。工具层对凭据文件做了拦截（read_file 拒绝读 .env 等文件名，11 篇细讲），这减少了敏感内容进入记录的机会，但不是脱敏。单机自用可以接受，要给别人用就得补上。

4.12 工具怎么选

选型时想清楚几件事：

1. 数据能不能出公司。用户对话、内部文档是不是允许发给第三方 SaaS
2. 会不会被绑定。按 OTel 约定埋点，后端可以换；直接用某个平台的 SDK，换平台要改代码
3. 性能影响。记录要异步发送、批量上报，不能拖慢主流程。Langfuse 文档里提到它的 SDK 是本地排队、批量发送的
4. 和评测打通。线上发现的坏例子能不能一键加进评测数据集，这是 09 篇里”失败回流”的落地方式

关于我项目为什么没接：单机项目，一次评测几十次运行，SQLite 两张表足够，而且评测分析大量依赖直接写 SQL（统计 search_knowledge 调用次数、查某类报错出现在哪些运行里）。如果要上线给多人用，我会先补缓存命中和模型耗时这两个缺的字段，再按 OTel 约定改造成三层 span，这样后端选哪个都行。

第五部分 对照项目

对照开源实现：pi

pi（05 篇第五部分介绍过）的可观测分两部分，成熟程度差别很大。源码以 commit 7b4cfd6 为准。

现在的命令行产品：没有链路追踪，靠会话文件和界面底栏。

• 每条模型回复都带完整用量：输入、输出、缓存读、缓存写、推理 token，以及按模型价格表算好的每项金额，跟着会话 JSONL 一起存下来（07 篇），事后可以重新汇总
• 界面底栏实时显示本次会话累计的输入、输出、缓存读写 token，最近一次的缓存命中率，花费，上下文用了多少；累计值包括工具内部调模型的用量和压缩时生成摘要的用量
• 不往任何监控后端发数据

正在做的新运行时：先把 span 结构定义好。 遥测接口单独成包 packages/telemetry，不绑定任何后端，要接 OpenTelemetry、Sentry，由使用者写一个适配器。Agent 这边在 agent/src/harness/telemetry.ts 里用代码定义了每种 span 的名字、允许的父级和属性。设计文档自己注明了，大部分运行时 span 还在设计或实现中，所以这里只看它的设计：

pi.harness.run              一次运行
├─ pi.harness.turn          一轮：一次模型回复加上它发起的一批工具
│  ├─ pi.harness.step       一次尝试，重试时每次一个
│  ├─ pi.harness.tool       一次工具执行
│  └─ pi.harness.sleep      一次重试前的等待
└─ pi.harness.checkpoint    一次检查点

可以挂在任何一层下面的：
pi.ai.request               一次模型请求
pi.harness.hook             一次钩子调用
pi.session.write            一次会话写入

模型请求这个 span 记的属性（L45-L117），基本就是本篇 4.3 节”每次模型调用记什么”那张表：服务商、请求的模型名和实际响应的模型名、结束原因、HTTP 状态码、输入 / 输出 / 缓存读 / 缓存写 / 推理 token、费用、流式收到的块数、收到第一块的耗时、错误类型。工具 span 记工具名、调用编号、是否出错，还记了这个工具声明的”能不能安全重做”和”这次是不是恢复执行”（07 篇讲过这两个概念）。

和本篇、和我的项目对比：

值得讲的点：

1. 默认不记内容，和 OTel 约定是同一个思路。 本篇 4.4 节说 OTel 约定里提示词、回答这些内容字段是 Opt-In。pi 的遥测包说得更具体，连”原始报错文字”都默认不放，因为报错里经常带路径、参数甚至密钥。span 里只放结构化的数字和短标签，内容要看就去会话文件里查。本篇 4.11 节的”结构信息和内容分开”，这就是一个现成例子。

2. 记录失败不能影响业务。 遥测包对适配器的要求里写着：记录方法不能抛异常，后端出错要吞掉，业务逻辑必须照常执行且只执行一次。对应本篇 4.12 节”记录不能拖慢主流程”，而且更进一步：连出错都不能影响主流程。我项目是同步写 SQLite，写入失败会直接抛异常中断运行。

3. 先定结构，后接后端。 pi 没有先选 Langfuse 还是 LangSmith，而是先把”记哪些 span、每个 span 有哪些字段”定义成代码，后端通过适配器接。这和本篇 4.12 节”按 OTel 约定埋点，后端可以换”是一个方向，只不过字段名是自己定的。

第六部分 追问清单

第七部分 闭卷自测

1. 日志、指标、链路追踪各擅长什么？用 Agent 的例子各举一个。

2. trace、span、父 span 分别是什么？一次 Agent 运行的 span 树大致长什么样？

3. 为什么说 Agent 会”安静地错”？举项目里的例子。

4. OTel GenAI 约定里，模型调用的 span 名字怎么起？输入 token 是否包含缓存命中的部分？

5. gen_ai.input.messages 为什么是 Opt-In？开启后要注意什么？

6. 实验 1 里，第 2 步输入 token 更多，为什么成本反而更低？

7. 实验 1 里，span 函数为什么用 try / finally？except 里为什么要 raise？

8. 实验 2 里 run_command P50 是 26 毫秒、P95 约 15 秒，说明什么？这时看平均耗时有什么问题？

9. 我项目 402 余额耗尽那一串崩溃，从数据上怎么看出是全局问题而不是项目问题？该用什么规则告警？

10. 我项目 268 次成功运行里工具耗时占 52%，剩下的平均每步 1.9 秒。这个 1.9 秒能直接当作模型调用耗时吗？

11. Agent 运行太慢，排查顺序是什么？为什么先看步数？

12. 设计告警时，为什么不对单次失败告警？SRE 书里对告警有哪几条原则？

13. 我项目的记录要改成符合 OTel 约定，至少要补哪些东西？

14. pi 的遥测规定 span 属性默认不放提示词、回答、工具输出，连原始报错文字也不放。为什么报错文字也要排除？那出了问题去哪看内容？

延伸阅读

1. OpenTelemetry GenAI 语义约定仓库 — docs/gen-ai/ 下有模型调用 span、Agent span、指标、MCP 等文档；目前是开发中状态
2. Google SRE 书：Monitoring Distributed Systems — 四个黄金信号、告警原则
3. Langfuse 可观测概览 — 开源 LLM 观测平台的功能范围
4. LangSmith 可观测概念 — run、trace、thread、project 的定义
5. Anthropic：Demystifying evals for AI agents（2026-01）— 本篇和 09 篇共用的背景：为什么要读轨迹、评测怎么持续迭代
6. pi：telemetry 包 和 Agent 遥测定义（commit 7b4cfd6）— 不绑定后端的遥测接口、适配器必须遵守的规则、Agent 的 span 结构和字段

下一篇：11 安全——记录能让你看到 Agent 做了什么，安全要保证它做不了不该做的事。