可观测性与调试:看清 Agent 的每一步 · 第 4 / 6 节

第 4 课:Trace:把一次运行串成一棵树

学习目标:

  • 用关联 ID 把散落的记录收拢成「一次提示触发的全部事件」,并说清它和会话 ID 的分工
  • 读懂 span 与 trace 的层级:根 span、模型请求、工具调用、工具的等权限与执行两段,以及子代理如何嵌进父 Agent 的工具 span
  • 在仪表盘没数据时先怀疑管道而不是怀疑 Agent:知道导出为什么会静默失败、批量导出会在什么情况下丢东西、怎么验证探测器本身

前置要求:读完第 1–3 课(非确定性怎么让复现失灵、原始记录是第一手证据、给 harness 装上结构化日志与指标) | 上一课 第 3 课 << | 下一课 第 5 课 >>

400 条记录,哪 12 条是那一次?

上一课结束时,你的 harness 已经在往 runs.jsonl 里写结构化记录了:每次模型请求一条,每次工具调用一条,带时长、带 token、带报错。日志从「一大坨文本」变成了「一行一个 JSON 对象」,你很满意。

然后用户来报问题:「昨天下午我让它改一下登录页的文案,结果它把测试文件也动了,我没让它动那个。」

你打开日志,按日期一 grep,400 条记录躺在屏幕上。两百多次工具调用、一百多次模型请求,还有几十条来自子代理的记录混在中间。用户说的那次提示,大概对应其中十来条。哪十来条?

你能用的线索只有两个,都不够用:

  • 会话 ID。上一课你确实给每条记录都写了 session_id,可用户昨天下午在同一个会话里聊了七八个来回。按会话过滤,400 条变成 210 条。范围小了一半,性质没变。
  • 时间戳。你可以估个时间窗切一刀,但子代理是并发跑的,它的记录和主循环的记录在时间轴上交错咬合;而且用户说的「下午」到底是两点还是四点,他自己也记不清。

问题不在于记录不够详细,而在于记录之间没有关系。第 3 课把每一步都变成了数据,但那些数据是一堆平行的行,行与行之间谁引发了谁、谁是谁的孩子,一个字都没写。几百条整整齐齐的 JSON,还是一盘散沙——只是这次的沙子比较方正。

这一课补上的就是那层关系。

关联 ID:一条提示的名字

最小的一步:给「一次触发」发一个身份证号,凡是这次触发引出的事件,都把这个号抄一遍。这就是关联 ID(correlation ID)。它不需要任何基础设施,就是一个字段。

Claude Code 的第一方设计正是这么做的。用户提交一条提示后,Claude Code 可能会发起多次 API 调用、跑好几个工具;prompt.id 这个属性让你把所有这些事件全部系回触发它们的那一条提示1。文档给的调试起手式也很直白:要追一条提示触发的全部活动,就按某个具体的 prompt.id 值过滤你的事件1

这和会话 ID 是两个粒度的东西,各干各的活:

关联 ID覆盖范围回答什么问题
session id一整场对话这次会话总共花了多少钱?中途有没有换权限模式?
prompt id会话里的一次提示用户抱怨的那一句,到底引出了哪些模型请求和工具调用?

回到开头那 400 条记录:如果每条都带上 prompt_id,你只要从会话转录里找到「改一下登录页的文案」那一句对应的 id,一次过滤就从 400 条落到 12 条。散沙第一次有了边界。

但边界不等于结构。12 条记录仍然是并排的 12 行,你还是不知道那次误改测试文件的写入,是主循环直接干的,还是它派出去的子代理干的;也不知道那次跑了 40 秒的工具,40 秒里有多少花在等你点「同意」。

span 与 trace:把事件排成一棵树

先把几个词说成人话,后面都要用:

  • span:一段「有始有终的活儿」的记录。它有名字(比如 llm_request)、开始时间、结束时间,还挂着若干属性(模型名、工具名、token 数)。一个 span 可以指认自己的父 span。
  • trace:由父子关系串起来的一整棵 span 树。一次完整的请求从头到尾发生的所有事,读成一棵树。
  • 导出器(exporter):进程里负责把 span 打包发出去的那段代码。
  • collector:接收这些 span 的中转站或后端服务。导出器把数据发给它,你在它的界面上看树。

Claude Code 的分布式追踪导出的 span,把每条用户提示与它触发的 API 请求、工具执行连起来,于是整个请求在你的追踪后端里读成一条 trace1。具体的层级是这样的:每条用户提示开启一个 claude_code.interaction 根 span;API 调用、工具调用、hook 执行记为它的孩子;工具 span 自己还有两个子 span——一个记等待权限决定花掉的时间,一个记真正执行花掉的时间1

工具那两个子 span 值得停一下。第 3 课你记的是 duration_ms:一个工具跑了 40 秒。可「40 秒里 38 秒在等人点同意」和「40 秒里 38 秒在跑命令」是两个完全不同的问题,前者要改权限配置或换个交互方式,后者要改工具实现。同一个 40 秒,拆成两段就变成了两条不同的修法。这就是树状结构比平铺字段多给你的东西。

Agent SDK 那边把话说得更直接:trace 是你能拿到的、关于一次 Agent 运行最细的视图;把 CLAUDE_CODE_ENHANCED_TELEMETRY_BETA=1 设上之后,Agent 循环的每一步都成为一个你可以在追踪后端里检视的 span2。CLI 本身内建了 OpenTelemetry 插桩:围绕每次模型请求和每次工具执行记 span,为 token 与成本计数器发指标,为提示词和工具结果发结构化日志事件2

对照你自己在本系列第 7 门课写的那个 harness:你的循环里本来就有「发请求 / 收 tool_use / 跑工具 / 回 tool_result」这几个明确的点位,每个点位天然对应一个 span。你缺的不是位置,是父子关系。

跨边界传播:子代理、你的应用、Bash 子进程

树好看,但真实的一次运行会跨好几个进程边界。跨过去以后树还连得上吗?连得上,靠的是把「我是谁的孩子」这条信息一路传下去。

往下一层:子代理。 当 Agent 通过 Agent 工具派出一个子代理时,子代理的 llm_requesttool span 会嵌在父 Agent 的 claude_code.tool span 之下,于是整条委托链呈现为一条 trace2。这顺手解决了一个没有树就答不了的问题——子代理烧的 token 算谁的?它长在那次工具调用底下,那次工具调用又长在那条提示底下,所以算那条提示的。你不需要额外拼接。

往上一层:你的应用。 SDK 会自动把 W3C trace context 传播进 CLI 子进程。W3C trace context 说白了就是一个标准格式的字符串,里面装着 trace id 和当前 span 的 id,谁拿到它谁就知道自己该挂在哪儿。你在应用里有一个 OpenTelemetry span 处于活跃状态时调用 query(),SDK 会把 TRACEPARENTTRACESTATE 注入子进程的环境变量,CLI 读到它们,于是它的 claude_code.interaction span 成为你那个 span 的孩子——这次 Agent 运行出现在你应用的 trace 里,而不是一个跟谁都不挨着的孤儿根2

这个差别在排查线上问题时非常实际:用户投诉的是「我点了那个按钮,页面转了 20 秒」,你从 HTTP 请求的 trace 点进去,能一路点到 Agent 里那次卡了 14 秒的工具调用,中间不用换系统、不用靠时间戳对齐。

再往下:Agent 自己跑的命令。 追踪激活时,Bash 和 PowerShell 子进程会自动继承一个 TRACEPARENT 环境变量,里面装着当前那次工具执行 span 的 W3C trace context1。如果通过 Bash 工具启动的命令自己也发 OpenTelemetry span,这些 span 会嵌在包着该命令的 claude_code.tool.execution span 之下2

三段接起来,一棵树可以从你的 Web 请求开始,穿过 CLI、穿过子代理、一直长到 Agent 跑的那条 npm run build 内部的编译阶段。

只看结构,不看内容

到这儿你可能会犯嘀咕:把 Agent 每一步都发到外部后端,那用户跟它说的话、它读写的文件内容,是不是也一起出去了?

Anthropic 在多 Agent 研究系统的复盘里给了两条并排的结论。一条是收益:上线全链路 tracing 之后,他们才能诊断 Agent 为什么失败,并系统性地修问题3。另一条是边界:他们监控的是 Agent 的决策模式与交互结构,全程不监控单次对话的内容,为的是保住用户隐私;就这样一层高层面的观测,就帮他们诊断出了根因、发现了意外行为、修掉了常见失败3

第一方工具的默认口径正好对得上这条原则。遥测默认是结构性的:时长、模型名、工具名记在每个 span 上;token 计数在底层 API 请求返回用量数据时记录,所以失败或中止的请求对应的 span 可能没有 token 数;至于 Agent 读到和写出的内容,默认不记录2。用户提示词的内容默认也不采集,只记提示词长度;要把内容一起带上,得显式设 OTEL_LOG_USER_PROMPTS=11。Agent SDK 那页在它自己那组内容采集开关旁边写着同一类提醒:除非你的观测管道被批准存储 Agent 处理的这类数据,否则就别设2

对很多团队来说这是好消息:你不需要先打赢一场「能不能把用户内容送到第三方后端」的合规仗,才能开始看清 Agent 在干什么。很多问题在结构层面就能看出来。

设计自己 harness 的 trace 时,把这条当默认值:span 上记名字、时长、工具名、token 数、错误类型;参数和返回内容留在本地的原始记录里(第 2 课那份),需要时再按 id 回去捞。

观测管道自己也会骗你

前面讲的都是「树建好之后你能看到什么」。这一节讲一件更早发生、也更容易吃亏的事:你以为你在看数据,其实你在看一个空面板

第一件要记住的事:导出失败默认是静默的。如果端点不可达,或者后端拒收数据,Agent 照常运行,CLI 把遥测丢掉,并且不在你的应用里冒出任何错误2。这个设计本身是对的——观测管道不该把主流程拖垮——但它的代价是:管道断了和一切正常,在你这边长得一模一样。

第二件:批量导出会在特定情况下丢东西。CLI 把遥测攒成批、按间隔导出。进程干净退出时它会尝试冲刷还没发出去的数据,但这个冲刷有一个很短的超时上限,所以只要 collector 响应慢,span 照样会被丢掉;而如果进程在 CLI 关停之前就被杀掉,还留在批缓冲区里的东西全部丢失2。默认情况下,指标每 60 秒导出一次,trace 和日志每 5 秒导出一次2。把这几句放在一起看:一个在 CI 里跑三五秒就结束的短命 Agent 运行,尾巴上的遥测要靠「冲刷在超时之内完成、进程没被提前杀掉」两个条件同时成立才保得住,导出间隔又放大了留在缓冲区里的量——这种场景要把导出间隔调到明显小于运行时长,并保证进程走干净退出。

第三件,也是排障时该做的第一件事:先验证探测器本身(探测器就是你安的那些探头,一个东西两个叫法)。要验证一套导出指标的配置有没有生效,去你的后端查 claude_code.session.count 这个指标——会话一启动 Claude Code 就会发它1;如果什么都没到,跑 claude --debug,在调试日志里找 OTel 导出报错1。这两步的价值在于它们把「Agent 有没有问题」和「管道通不通」拆成了两个可以分别回答的问题。

还有两条容易踩的配置坑:

  • CLI 默认把 service.name 报成 claude-code。如果你同时跑好几个 Agent,或者 SDK 和别的服务导出到同一个 collector,就覆盖服务名并加上资源属性,这样你才能在后端里按 Agent 过滤2。否则三个 Agent 的 span 混在同一个服务名下,你看到的是一锅粥。
  • 通过 SDK 运行时,不要把 console 设成导出器的值2。文档没说原因;按 SDK 与 CLI 的通信方式推测,SDK 靠 stdout 跟 CLI 通消息,往那儿打印 span 会把这条通道搅乱。

三个信号,可以只开需要的

不用一上来就全家桶。CLI 导出三个各自独立的 OpenTelemetry 信号——指标、日志事件、trace——每个信号有自己的启用开关和自己的导出器,所以你可以只打开你需要的那些2

这给了一条很自然的采用顺序:

  1. 先开指标。成本和 token 用量最先有人问,指标最便宜,60 秒一次的默认导出间隔对长跑服务也够用。
  2. 再开日志事件。工具结果、权限决定这些结构化事件,是第 3 课那套诊断读法的原料。
  3. 出了说不清的问题再开 trace。它最贵也最细,是你真正要「看清一次运行的形状」时才需要的那一层。

导出目标是任何接受 OpenTelemetry 协议(OTLP)的后端,文档顺带点了几个名字:Honeycomb、Datadog、Grafana、Langfuse,或者你自己托管的 collector2。选哪个不在这门课的范围里,这里只说一句:三个信号各自独立这件事意味着你可以先拿最小的那块试水,不用等基础设施全备齐。

顺带一句:同一批事件也是审计轨迹

结构化事件还有一个跟调试无关的用途,知道有这回事就行。

给事件带上终端用户身份属性之后,tool_decisiontool_resultmcp_server_connectionpermission_mode_changed 这几类事件(它们以 claude_code. 前缀的名字导出为日志记录)就构成一份按用户组织的审计轨迹,可以转发给 SIEM 平台2。每个事件都携带身份属性,把工具调用、MCP 活动和权限决定系回触发它们的那个人1

同一批数据,换个读法就是另一件事的原料:调试时你按 prompt.id 横切,审计时按用户竖切。安全话题不在这门课里展开。

这门课不给你的答案

有几件事得说清楚边界,免得你去别处找现成配方:

  • 采样率和保留窗口:trace 全量存起来会很贵,采多少、留多久确实是真问题,但一手材料里没有任何指导,这门课不编数字。等你的数据量真的成为问题时,那是你和后端账单之间的事。
  • 告警阈值:同上,不给数字。
  • hooks:怎么在循环的生命周期关口安探头、PreToolUsePostToolUse 各自能拿到什么,是第 5 课。这里先埋一个接口:hook 的输入里带着当前正在处理的那条用户提示的 UUID,它和遥测事件上的 prompt.id 属性是同一个值,所以 hook 的输出和同一条提示的遥测能对上号4。这一课建立的关联 ID,下一课直接就能用。
  • 你自己的 harness 不必上 OTel 全套。这一课用第一方设计当教具,是因为它把该有的结构都摆明了。但你要的其实只是那棵树:第 6 课会给每次运行发一个 trace_id,给每条记录加上 span_id 和一个指向父记录的字段,然后写十几行代码按缩进打印出来——你会得到用同一套父子机制建起来的一棵树(第 6 课会说明它给工具挑了个不同的父亲),不需要 collector,不需要后端,不需要任何依赖。等你哪天真要接 OTLP,字段是现成的。

💻 练习

小结

  • 结构化日志解决了「记录够不够细」,没解决「记录之间什么关系」。关联 ID 是补上关系的第一步:一条提示可能引出多次 API 调用和好几个工具,prompt.id 把这些事件全部系回触发它们的那一条提示,调试的起手式就是按这个值过滤1
  • span 是一段有始有终的活儿,trace 是由父子关系串起来的那棵树。分布式追踪把每条用户提示与它触发的 API 请求、工具执行连成 span,整个请求在追踪后端里读成一条 trace1
  • 层级是固定的:每条提示开一个 claude_code.interaction 根 span,API 调用、工具调用、hook 执行是它的孩子;工具 span 还有两个子 span,等权限的时间和真正执行的时间分开记1。开启增强遥测后,Agent 循环的每一步都成为可检视的 span,trace 是一次运行最细的视图2
  • 树能跨进程边界连起来:子代理的 span 嵌进父 Agent 的工具 span,整条委托链读成一棵 trace;SDK 把 TRACEPARENTTRACESTATE 注入 CLI 子进程,Agent 运行出现在你应用的 trace 里而不是一个断开的根2;再往下,Bash 子进程继承 TRACEPARENT1,命令自己发的 span 嵌进那次工具执行的 span2
  • 上线全链路 tracing 之后才能系统性地诊断失败3;而且只监控决策模式与交互结构、不看对话内容,也足以诊断根因、发现意外行为3。机制上正好对得上:遥测默认结构性——时长、模型名、工具名记在每个 span 上,内容默认不记录2;提示词默认只记长度,要带内容得显式开开关1
  • 指标、日志事件、trace 是三个独立信号,各有启用开关和导出器,可以只开需要的2——增量采用,不用一把梭。
  • 观测管道自己也会骗你:导出失败默认静默,Agent 照常跑而遥测被丢且不报错2;批量导出在干净退出时会尝试冲刷但受短超时约束,进程被杀则缓冲区里的全丢2;默认指标 60 秒、trace 与日志 5 秒导出一次2,短命运行要缩短间隔。所以排障第一件事是验证探测器本身:查后端有没有那个会话计数指标1,没有就开 --debug 看导出报错1
  • 两个配置坑:多个 Agent 共用一个后端要覆盖 service.name 并加资源属性才分得开2;通过 SDK 运行时别把 console 设成导出器2
  • 同一批结构化事件换个读法就是审计材料:带上身份属性后,工具决定、工具结果、MCP 连接、权限模式变更这些事件成为可转发 SIEM 的按用户审计轨迹2,每个事件的身份属性把工具调用系回触发它的人1
  • 采样率与保留窗口没有一手指导,这门课不给数字。你自己的 harness 也不必上 OTel 全套——第 6 课用一个 trace_id 加父指针字段再加缩进打印,就能用同一套父子机制得到一棵树。

>> 第 5 课:在关口安探头:hooks 与定位流程

Footnotes

  1. Monitoring — Claude Code 官方文档 — https://code.claude.com/docs/en/monitoring-usage 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17

  2. Observability with OpenTelemetry — Claude Agent SDK 官方文档 — https://code.claude.com/docs/en/agent-sdk/observability 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26

  3. How we built our multi-agent research system — Anthropic Engineering — https://www.anthropic.com/engineering/multi-agent-research-system 2 3 4

  4. Hooks reference — Claude Code 官方文档 — https://code.claude.com/docs/en/hooks

练习

01

下面是某次 Agent 运行导出的 14 条 span 记录,一行一个 JSON 对象。它们是按结束时间写进文件的(span 结束时才知道自己跑了多久),所以孩子往往排在父亲前面。

Level 1:把 14 条扁平记录画成一棵树

为了让这题短一点,我把每个工具的「等权限」子记录折进了工具记录上的 wait_ms 字段,只保留了执行子记录;end_ms 是相对这次运行开始的毫秒数。

不写代码,用纸笔或文本编辑器完成:

  1. 把这 14 条记录重建成一棵缩进的 trace 树。同一层的兄弟按开始时间从上到下排(开始时间 = end_ms - dur_ms)。每行标出名字、耗时,工具记上工具名。
  2. 回答:这次运行里子代理消耗的 token,算进哪一条提示?为什么?把这条提示的 token 总数算出来。
  3. 回答:哪一条记录能证明那次 build.compile第二次工具调用触发的?指出是记录里的哪个字段、哪一段值。
完成标准 · 本地勾选
02

不写代码。下面三个情景都长着「仪表盘不对劲」的外表,但底下是三种不同的机制。对每一个,写出:最可能的原因、你要按什么顺序验证、以及验证通过后怎么处置。每条判断都要能指回本课讲过的某个机制,不要一律归结成「配置写错了」。

Level 2:三块空仪表盘,逐个给排查路径
  • 情景 A:接上遥测导出、上线一周,仪表盘上一条数据都没有。没有 span,没有指标,也没有事件。这一周 Agent 一直在正常服务用户,没人抱怨。
  • 情景 B:指标面板一切正常——token 计数在涨、成本曲线在动、会话数对得上。但你打开追踪后端,按今天的时间范围搜,一条 trace 都没有。
  • 情景 C:一个在 CI 里跑的短脚本,每次跑完 trace 都「缺尾巴」:根 span 在,前面几步也在,最后两三个工具 span 没了。同样的配置在本地开发机上长跑时一切正常。
完成标准 · 本地勾选

我的笔记

记下想法、痛点、没懂的地方。只写进这门课的附录,正课文件不动。