把 trace 画出来:单文件 trace 查看器

一个 trace 查看器做五件事:把各种来源的 JSON 读成同一种 span 列表,建成树,画成瀑布图,按错误和慢步骤过滤,把 token 和成本加对;再加一件:把两次运行对齐,找到第一个分叉的步骤。

这个页面本身就是查看器。它不调任何服务,全部用合成的 BugHunt trace;也能读你自己的文件、OTLP/JSON 导出和 Codex app-server 的通知序列。

1为什么还要再写一个查看器

第 2 周「Agent 做错了,你怎么知道它错在哪一步?」里已经有一个瀑布图演示,但那是写死四条 trace 的教具:数据在代码里,按下标比较分叉点。真要用起来,查看器面对的是别人产出的文件:字段可能缺、父 span 可能不在、时间戳是 19 位整数、内容里混着被测网页的原文,一条 trace 可能有几万个 span。这一讲把它做成一个能读任意输入的单文件工具,下一讲给它接上后端存储和查询,再下一讲部署。

查看器要做的事本讲的做法对应的工程问题
读数据三种输入先转成同一种 span 列表格式适配、宽进严出、纳秒精度
建树、画瀑布图Map 建索引,迭代 DFS孤儿、环、多个根;大 trace 不爆栈
过滤错误、慢步骤(按自身耗时)、文本搜索,命中项连同祖先一起显示"慢"该怎么定义
汇总 token 和成本按模型汇总,只算"最深层"的 usage重复计算、缓存口径
对比两条 trace按步骤签名加权对齐,标出第一个分叉插入一步后整体错位
显示内容只用 textContenttrace 内容是不可信输入(XSS)

2数据模型:一个 span 有哪些字段

本周三讲共用一份 JSON 约定(week09_全栈/code/trace_schema.md):一条 trace 有 trace_id、name 和 spans,字段名照搬 OTLP 的 protobuf 字段名(snake_case),值做了简化:

本周约定OTLP/JSON(opentelemetry-proto v1.11.1)说明
trace_id / span_id / parent_span_idtraceId / spanId / parentSpanId,十六进制字符串16 字节 / 8 字节,全 0 无效;根 span 的 parent 为空
kind:"CLIENT" 等字符串kind:整数(3 = CLIENT)OTLP/JSON 规定枚举必须编码成整数
start_time_unix_nano:JSON 整数startTimeUnixNano:十进制字符串64 位整数在 OTLP/JSON 里写成字符串,读的时候数字、字符串都要接受
status.code:UNSET / OK / ERRORstatus.code:0 / 1 / 2message 只在 ERROR 时有意义
attributes:扁平对象,值只能是标量attributes:[{key, value: {stringValue | intValue | ...}}]结构化内容在本约定里存成 JSON 字符串

属性名用 OpenTelemetry GenAI 语义约定:gen_ai.operation.name(chat、execute_tool、invoke_agent)、gen_ai.request.model、gen_ai.tool.name、gen_ai.tool.call.arguments / result、gen_ai.usage.input_tokens / output_tokens / cache_read.input_tokens / cache_write.input_tokens;错误用 error.type,HTTP 子 span 用 http.request.method、http.response.status_code、url.full。

版本:GenAI 约定已经搬到单独的仓库 open-telemetry/semantic-conventions-genai,整体状态是 Development,这个仓库还没有发过版本,本文按 2026-09-30 的提交 b31e9e8 核对;error.type、http.*、url.full 在通用语义约定 v1.44.0 里是 Stable。属性名以后可能改,读数据时要容忍不认识的属性。

另一种数据模型:Codex app-server 的 thread / turn / item

第 3 周「一个生产级 Agent 长什么样?Codex 的仓库地图」讲过 app-server 对外的三层模型。它本身就是一棵树:thread 是根,turn 是一次用户请求,item 是 turn 里的一条消息、一次命令执行、一次 MCP 调用。查看器把通知序列转成 span(这个映射是笔者自己定的,不是 Codex 的约定):

Codex(commit 7993248)转成要注意的地方
Turn.startedAt / completedAtturn span 的起止(只在 turn 里没有 item 时兜底)源码注释写的是 Unix 秒,精度不够画瀑布图
item/started 的 startedAtMs、item/completed 的 completedAtMsitem span 的起止毫秒;时间在通知上,不在 ThreadItem 里
thread/tokenUsage/updated 的 tokenUsage.last,只在 total 变化时按 turnId 相加turn span 上的 gen_ai.usage.*last 是最近一次响应的用量,但限流更新、流出错重试、压缩、线程恢复时,app-server 会把同一个 last 再推一次,所以不能逐条相加。Codex 自己按 total 在 turn 首尾的差值算单个 turn 的用量(tasks/mod.rs:720-735);查看器只在 total 比这个线程上一条通知变化时才累加 last;录制里混进的其他线程的通知跳过,并计入警告
commandExecution 的 status: failed / declinedERROR + error.typeTurnStatus 只有 completed / interrupted / failed / inProgress

所以 turn 有 item 时,起止只用 item 的毫秒时间;秒级的 startedAt 只作兜底,否则秒的取整会凭空多出一段"自身耗时"。Codex 的 inputTokens 含缓存读的部分(non_cached_input() 是 input_tokens − cached_input),这一点和 GenAI 约定一致;缓存写的口径本文没有核实。

3数据加载:宽进严出,纳秒不能丢

适配层:三种输入(本周约定、OTLP/JSON、Codex 通知数组)各写一个适配函数,输出同一种内部结构,后面的建树、过滤、汇总、对比只认这一种。新增一种来源,只加一个适配函数。

宽进:下一讲的后端校验不过就返回 400;查看器反过来,尽量显示,把问题列成警告。原因是查看器还要读直接导出的 OTLP 文件和还在运行的 trace:父 span 可能还没写进来(孤儿),结束时间可能还没有。演示里粘贴一段有问题的 trace,会看到这些警告:

情况查看器的处理
父 span 不在这条 trace 里(孤儿)挂到一个虚拟根下
多个根 / 没有根加一个虚拟根
父子关系成环从根和孤儿出发走一遍,走不到的不是在环上就是环的后代;每个环只断开一条边,断开处的节点挂到虚拟根,其余节点和后代仍挂在原父节点下;环和孤儿分开计数
span_id 重复保留第一个
end < start / 缺结束时间按 0 时长画 / 画到 trace 的最后时刻,标"未结束"

纳秒精度:1759300000000000123 用 JSON.parse 读成 Number,变成 1759300000000000000。这个量级在 \(2^{60}\) 和 \(2^{61}\) 之间,double 的间隔是 \(2^{60-52} = 256\) 纳秒。查看器给 JSON.parse 传一个 reviver,用第三个参数 context.source 拿到原文,键名以 _unix_nano / UnixNano 结尾的值按 BigInt 读;相减求相对时间之后才转成毫秒。导出时 BigInt 原样写回,测试里确认了导出再读回逐位一致。context.source 在 Chrome 114+、Firefox 135+、Safari 18.4+、Node 21+ 可用,不支持时退回 Number 并在页面上提示。

4建树和瀑布图:自身耗时才是"慢在哪"

建树用一个 Map(span_id → 节点),一遍扫完挂好父子关系,\(O(n)\);对每个 span 用数组 find 找父亲是 \(O(n^2)\),几万个 span 时就能感觉到。遍历一律用显式栈,不用递归,深度很大的 trace 也不会爆栈。

瀑布图的横条长度是总耗时 \(e - s\)。但"哪一步慢"要看自身耗时:总耗时减去子 span 覆盖的时间。子 span 可能重叠(并行调用),也可能超出父 span(时钟偏差、异步收尾),所以先裁剪、再求并集:

$$t_{\text{self}} = (e - s) - \Bigl|\,\bigcup_i \bigl[\max(s_i, s),\ \min(e_i, e)\bigr]\Bigr|$$

按总耗时排序,根 span 永远排第一,这个信息没用。run-07 里阈值设 1 秒:按总耗时命中 6 个 span(根 + 5 次模型调用),按自身耗时命中 5 个,根的自身耗时只有 590 ms。run-08 里按自身耗时,最慢的是那次超时的 HTTP 请求(4.9 s),而它的父 span execute_tool browser_navigate 总耗时 5 s、自身只有 100 ms。

5过滤:错误、慢步骤,以及"过滤不出来"的失败

过滤命中的 span 要连同它的祖先一起显示(祖先变淡),否则一个孤零零的 GET 看不出是哪一步的。run-08 勾上"只看错误",剩 3 行:根(上下文)、超时的导航、它下面的 HTTP 请求。

错误还要再分一层。OTel《Recording errors》说操作没出错时状态码 MUST 保持 unset;被重试兜住、最后正常完成的错误,SHOULD NOT 记在描述这个操作的 span 上。但每一次尝试自己是一个 span,超时的那次尝试照样是 ERROR。查看器的做法(笔者的规则):一个 ERROR span 后面如果有一个签名相同、没出错的兄弟 span,就标成"已补上"。run-08 的超时导航就是这样。

run-09 是一次漏报:登录态丢了,Agent 打开购物车被重定向到登录页,截了一张图,又调了一次模型,就结束了,没提交报告。整条 trace 一个 ERROR span 都没有,"只看错误"什么也过滤不出来。这类失败要靠和成功运行对比(第 7 节)。

6token 与成本:别把同一批 token 加两遍

GenAI 约定里 client / internal 两种 invoke_agent span 的属性表都有 gen_ai.usage.input_tokens / output_tokens(Recommended);BugHunt 是进程内的 Agent,对应 internal span。如果插桩在根上记了汇总值、每次模型调用的 span 也记了自己的值,把所有 span 的 usage 相加,就把同一批 token 算了两遍。run-10 是一份 OTLP 导出,根 span 带了汇总:直接相加得到输入 38,800,去重后是 19,400,正好两倍。

查看器的规则:一个 span 的 usage 只有在它的所有后代都没有 usage 时才计入("最深层")。这样不依赖 gen_ai.operation.name 写没写对,Codex 那种 usage 记在 turn 上的数据也能用。下一讲的后端用的是另一种规则:只累加 gen_ai.operation.name 是推理操作(chat 等)的 span。对本课的样例,两种规则结果相同。

成本按模型分开算。gen_ai.usage.input_tokens 按约定含缓存读写,所以未缓存输入要减掉:

$$\text{成本} = \frac{(\text{input} - \text{cache\_read} - \text{cache\_write})\,p_{\text{in}} + \text{cache\_read}\,p_{\text{read}} + \text{cache\_write}\,p_{\text{write}} + \text{output}\,p_{\text{out}}}{10^6}$$

run-07:6 次模型调用,输入 19,400(缓存读 9,000、缓存写 1,800)、输出 910。按示例价格(合成)mock-large 输入 4、缓存读 0.4、缓存写 5、输出 20(美元 / 百万 token),成本 $0.0652。价格不是任何厂商的真实价格,页面上可以改。

7对比两条 trace:先对齐,再找第一个分叉

按下标比较,一次重试就会让后面全部错位。run-08 比 run-07 多了两步(超时的导航,以及模型看到超时后又想了一次),按下标比较 13 个位置里有 7 个"不一致",看起来像两次运行大不相同。

查看器先给每一步算一个签名(操作类型 + 工具名 + 目标,例如 tool browser_navigate http://shop.bughunt.test/cart;模型调用是 chat + 模型名),再算一个结果(状态、error.type、子 span 的 HTTP 状态码、退出码)。对齐用动态规划:签名相同且结果相同得 2 分,签名相同结果不同得 1 分,签名不同不能配对,求总分最大的配法(打分规则是笔者定的)。和最长公共子序列是一类问题;git diff 默认用的 Myers 算法也是在求这类对齐。

对比按下标加权对齐第一个分叉
run-07 vs run-0813 个位置 7 个不一致相同 11,只有 B 有 2第 2 步:B 多了一次超时的导航(后面被补上)
run-07 vs run-0911 个位置 8 个不一致相同 4,结果不同 1,只有 A 有 6第 2 步:同样打开 /cart,A 是 200,B 是 302 → 200(被重定向到登录页)
和第 6 周「测试 Agent 为什么漏掉 Bug?从读 trace 到失败分类」接上:开放编码时只记 trace 里第一个失败,因为上游的错会引出下游的错。和一条成功运行对齐后的第一个分叉,就是这个"第一个上游失败"的候选。run-09 的分叉落在导航的 HTTP 302 上,对应那一章分类表里的"登录态丢失";后面"没点优惠券、没提交报告"都是下游症状,不该各记一笔。分叉点只是候选,归不归这一类还要人读。

8大 trace:只建看得见的那几十行

一行 span 大约 8 个 DOM 节点。2 万个 span 全部建出来,查看器里有 160,141 个节点;滚动、过滤、折叠都要重建。虚拟滚动:外层容器的高度按"行数 × 24 px"撑开,滚动时只建可见范围加上下各 8 行缓冲。5 万个 span 时也只建 26 行、218 个节点,滚到第 25,000 行附近还是只有几十行。

其他几处:对齐表是 \(n \times m\) 的 Int32Array,超过 400 万格就拒绝对齐并提示;文件超过 50 MB 直接拒绝;5 万个 span 的 JSON 约 16 MB,主线程解析要零点几秒(本机实测,随机器变化),再大就该把解析挪到 Web Worker(本讲没做)。

9trace 内容是不可信输入:只用 textContent

BugHunt 的测试 Agent 每天读别人写的网页,页面文字会原样进到工具结果、模型输出、Bug 报告标题里,最后进 trace。第 8 周「被测页面里藏了一句「指令」,测试 Agent 会照做吗?」讲的是这些内容骗模型;查看器面对的是同一批内容,换了一个受害者:打开 trace 的人。如果查看器用 innerHTML 显示工具结果,页面评论里的一段 <img src=x onerror=...> 就会在查看器里执行,这就是存储型 XSS。对应第 35 讲「找 Bug 的测试 Agent,会踩到 OWASP LLM Top 10 的哪几条?」里的 LLM10:2026 Improper Output Handling(2025 版是 LLM05):模型和工具的输出要当成不可信用户输入。

// 错:MDN 的 innerHTML 页面就有这个例子,插入的 <script> 不执行,但 onerror 会执行
td.innerHTML = result;
// 错:只转义了尖括号,放进属性里,一个双引号就能闭合属性
row.innerHTML = `<td title="${escLtGt(result)}">...`;
// 对:纯文本
td.textContent = result;
  1. 写入一律 textContent / createElement。OWASP 的 XSS 防护清单把 textContent 列为安全的写入点(Safe Sink),并建议把 innerHTML 重构掉。这个页面的脚本里没有一处 innerHTML、insertAdjacentHTML、document.write,测试脚本会检查这一点。
  2. 属性也小心。setAttribute 只用于 title 这类无害属性;不把 trace 里的字符串放进 href、src、style、on*。比如 url.full 只显示、不做成链接。
  3. 拼 URL 前先校验。从后端列表拿到的 trace_id 先检查是 32 位十六进制,再拼进请求路径。
  4. 纵深防御:部署时再加内容安全策略(CSP),以及 MDN 提到的 Trusted Types(require-trusted-types-for)。它们是第二道防线,不能代替第一条。

演示里的 run-11 带了三段合成的 XSS 探针,触发后只会设置一个全局标志 window.__laqPwned。点开每一行,标志都不会被设置。

▶互动演示:trace 查看器

全部是合成数据:BugHunt 测试 Agent 检查"两张互斥优惠券能不能同时用"(注入的 Bug #12)。点左边的名字看属性,点 ▸ 折叠子 span。瀑布图里蓝色是模型调用,绿色是工具调用,灰色是其他,红色是出错,红白斜纹是"出错但后面被同样的调用补上了",橙色描边是超过慢步骤阈值的。

样例
加载自己的 trace(文件 / 粘贴 / 后端)
文件
后端
span 数
总耗时(根 span)
ERROR span
最深层级
token(去重后,输入 / 输出)
成本(示例价格(合成))
过滤
模型调用工具调用其他 ERRORERROR,后面被补上 慢步骤
span 树

▶token 与成本:按模型汇总

单价全部是示例价格(合成),单位:美元 / 百万 token,可以改。未缓存输入 = input_tokens − 缓存读 − 缓存写。一个 span 的 usage 只有在它的后代都没有 usage 时才计入("最深层"规则),避免根 span 上的汇总值再被加一遍。

▶对比两条 trace:找第一个分叉

把两条 trace 的"步骤"(根下面的第一层 span;Codex 的 turn 会展开成里面的 item)排成两列。签名相同(同一种操作、同一个工具、同一个目标)才能配对;配上了再看结果(状态、error.type、HTTP 状态码、退出码)一不一样。

AB
对齐方式

▶大 trace:虚拟滚动

生成一条合成大 trace(每轮一次模型调用、一次工具调用、一个 HTTP 子 span),按本周 JSON 约定序列化成文本,再走一遍和上面完全相同的解析、建树、渲染。关掉虚拟滚动,每个 span 都会建一行 DOM。耗时是你这台机器上实测的,每次会有波动;行数和节点数是确定的。

span 数
JSON 大小
—
解析(JSON.parse + BigInt)
—
建树(含自身耗时)
—
渲染(含一次强制布局)
—
实际建出的行
—
查看器里的 DOM 节点
—
关掉虚拟滚动时最多建 20,000 行,再多页面会明显卡顿。

▶不可信内容:同一个字符串,两种写法

下面列出当前 trace 里所有"长得像 HTML"的字符串(span 名、属性键、属性值)。查看器只用 textContent 写入,所以它们显示成原文。右边一列是如果改用 innerHTML,浏览器会把它解析成哪些元素:这一列是用 DOMParser 在一个不渲染、不执行脚本的独立文档里解析出来的,不会插进页面。选"run-11 恶意页面"看效果。

✎练习

题 1(自身耗时):一个 span 从 0 ms 到 1000 ms,有三个子 span:[100, 400]、[300, 700]、[900, 1200](最后一个超出了父 span 的结束时间)。这个 span 的自身耗时是多少毫秒?
ms
先把子 span 裁到父 span 的范围里:[100, 400]、[300, 700]、[900, 1000]。前两个重叠,并起来是 [100, 700],600 ms;第三个 100 ms。子 span 覆盖了 700 ms,自身耗时 = 1000 − 700 = 300 ms。直接用 1000 − (300 + 400 + 300) 会得到 0,重叠和越界都算错了。
题 2(token 去重):根 span invoke_agent 记了 gen_ai.usage.input_tokens = 12000,它下面三个 chat span 分别记了 3000、4000、5000,其他 span 没有 usage。这次运行的输入 token 应该算多少?
GenAI 约定的 invoke_agent span 属性表里就有 gen_ai.usage.input_tokens(Recommended),所以 C 不对。根上的 12,000 和三个 chat span 的和是同一批 token,A 把它算了两遍。查看器按"最深层"规则只算叶子上的 usage;如果根和叶子的和对不上,说明插桩有问题,应该报警告而不是挑一个。
题 3(XSS):查看器要把工具结果显示在详情面板里,工具结果来自被测网页。哪种写法是安全的?
A:innerHTML 确实不执行插入的 <script>,但 <img src=x onerror=...> 这类事件属性照样会跑(MDN 的 innerHTML 页面就是这个例子)。B:在属性值里,只转义尖括号挡不住一个双引号把属性闭合、再接一个 onmouseover。C 把字符串当纯文本,OWASP 的 XSS 防护清单把 textContent 列为安全的写入点(Safe Sink)。
题 4(对齐):A 的步骤是 [打开 /cart, 点优惠券 A, 点优惠券 B, 截图, 提交报告];B 的步骤是 [打开 /cart(超时), 打开 /cart, 点优惠券 A, 点优惠券 B, 截图, 提交报告]。两条 trace 按下标一一比较(缺的位置也算不一致;同一个操作但一个超时、一个成功也算不一致),有几个位置不一致?
个
B 多了开头那次超时,后面整体错开一位:第 1 位"成功 vs 超时"不一致,第 2~5 位两边的操作都不同,第 6 位 A 没有。6 个位置全部不一致,看起来像"整条运行都不一样"。加权对齐会把 B 的第二个"打开 /cart"和 A 的配上,结论是:B 多了一次超时的尝试,其余 5 步完全相同。
题 5(时间戳精度):纳秒时间戳 1,759,300,000,000,000,000 被 JSON.parse 读成 JS 的 Number(double)。在这个量级上,相邻两个能表示的 double 相差多少纳秒?
ns
260 ≈ 1.15×1018 ≤ 1.76×1018 < 261,double 有 52 位尾数,间隔是 260−52 = 256 ns。显示毫秒没问题,但如果拿两个 Number 相减求一个很短的 span 的时长,误差可以到几百纳秒;把 Number 再传回服务端,存进去的就不是原值了。查看器用 reviver 的 context.source 按 BigInt 读,相减之后再转成毫秒。

10面试要点

一句话讲清楚

trace 查看器先把各种来源(自己的 JSON、OTLP、Codex 通知)适配成同一种 span 列表,宽进严出,纳秒时间戳按 BigInt 读;用 Map 一次建树,瀑布图看总耗时,找慢步骤看自身耗时;token 只算最深层的 usage,避免根上的汇总被加两遍;对比两次运行时按步骤签名加权对齐,第一个分叉就是错误分析里"第一个上游失败"的候选;大 trace 用虚拟滚动;trace 内容是不可信输入,只用 textContent。

追问准备

  1. 为什么后端严格、前端宽松?后端是写入的关口,脏数据进了库就到处扩散;查看器要读运行中的 trace 和外部导出的文件,拒绝整条不如显示出来、把问题列成警告。
  2. 按自身耗时还是总耗时找慢步骤?总耗时会把根和所有容器 span 排在前面;自身耗时才是"时间花在这一层自己身上"。子 span 并行、越界时要先裁剪再求并集。
  3. 两次运行步数不一样,怎么比?按下标比,一次重试就让后面全部错位。按签名做序列对齐,配对后再比结果;第一个不相同的位置是分叉点。
  4. 漏报的 trace 里没有任何错误,怎么发现?错误过滤找不到它。要么和成功运行对比找分叉,要么看结局属性(比如没有 submit_report),再人工读。
  5. 查看器有什么安全风险?trace 里有被测网页和模型输出的原文,用 innerHTML 显示就是存储型 XSS,受害者是看 trace 的工程师。只用 textContent,属性和 URL 也不拼不可信字符串,部署时加 CSP。

常见错误说法

❌ "innerHTML 插进去的 script 不会执行,所以用 innerHTML 显示也安全":<img onerror> 这类事件属性照样执行。
❌ "把所有 span 的 gen_ai.usage.* 加起来就是总 token":根 span 也可能带汇总值,会算两遍。
❌ "瀑布图里最长的条就是最慢的步骤":最长的永远是根,要看自身耗时。
❌ "只看错误过滤一遍就能找到所有失败":漏报那条 trace 一个 ERROR 都没有。
❌ "两次运行按步骤下标对比就行":插入一次重试,后面全部错位。
❌ "纳秒时间戳用 JSON.parse 读就行":1.76×1018 附近 double 的间隔是 256 ns,原值回不去。

代码和样例

这个页面就是查看器,所有逻辑都在页面底部的一个 <script> 里。week09_全栈/code/trace_viewer/test_viewer.mjs 用 Playwright 打开本页,调用页面里真实的解析、建树、汇总、对齐函数,点界面、做练习;设了 TRACE_BASE 时还会把样例 POST 到下一讲的 Go 后端,再 GET 回来比对。samples/ 里是本页用到的合成 trace:run07 / 08 / 09 / 11 四个文件是本周约定格式,可以直接 POST 到后端;run10_otlp.json、codex_notifications.json 是其他格式,只给查看器读。

下一讲:Go 后端,接收 trace、存进 SQLite、提供查询 API。

公式显示依赖 KaTeX(CDN),断网时公式会显示成原始 LaTeX 源码,交互部分不受影响。