第 3 课:结构化日志与指标:把每一步变成数据
学习目标:
- 说清生产环境观测要回答的四个问题,并认出它们和评测指标本来就是同一组数、只是换了用途
- 给自己的 harness 设计结构化日志:每次模型请求、每次工具调用各落一条记录,字段覆盖时长、token、工具名与报错
- 按诊断式读法把指标模式对应到具体修法,并识破「报错数 0」这类被记录方式扭曲的信号
前置要求:读完第 1、2 课,手上有一个能跑起来的 harness 循环(本系列第 7 门课) | 上一课 第 2 课 << | 下一课 第 4 课 >>
一次运行你能翻,两百次你翻不动
第 2 课结尾你干了件很值的事:把一份原始记录从头读到尾,抓出三处 Agent 自己没说的毛病。方法对,证据也硬。问题在于,那是一次运行。
现在把同一个 Agent 放到线上:一天两百次运行,每次十几轮循环,加起来两三千次工具调用往返。周一早上有人说「上周五下午那批任务好像特别慢」,你打算怎么回应?翻两百份记录显然不现实;就算翻完了也答不上慢在哪——这个判断要的是一堆运行的分布,不是一份样本的读后感。人眼读记录能回答「这一次它为什么这样」,回答不了「这一批比上一批差在哪」。
所以这一课要做的事一句话就能说完:把「翻记录才能回答的问题」变成「一条查询就能回答的问题」。 前者是「这次它为什么反复搜同一个词」,后者是「过去七天哪个工具调得最多、报错是不是都落在同一个参数上」。第 2 课立的规矩没变——原始记录是第一手证据,Agent 的自述不算数;这一课只是把同一批证据换个存法,让它除了能被人读,还能被过滤、被聚合、被算分布。
生产环境要回答的四个问题
官方文档给生产环境的可观测性列了四个要看清的东西:调了哪些工具、每次模型请求花了多久、花了多少 token、失败发生在哪1。做设计决策时你会一次次回到这四问上:这个字段有没有帮我回答其中之一?没有的话它就是噪音。
读到这儿你可能觉得眼熟。本系列第 10 门课讲评测时用过同一组数:除了终态准确率,还建议收集单次工具调用与整任务的运行时长、工具调用总次数、token 总消耗,以及工具报错2。同一组指标,两次出场,用途不同:
区别不在数字,在你拿它跟什么比。评测时比「改动前 vs 改动后」,参照是固定用例集,所以数字要能重复;监控时比「今天 vs 前七天」「这个会话 vs 其他会话」,参照是运行自己的历史,所以数字要连续、带时间戳、能按维度切开。本课讲后者。
结构化日志:每一步落一条记录
这一节是工程实践口径。日志字段怎么起名、用什么格式落盘,一手材料没有给过指导——下面这套是能用的默认起点,不是权威规范。字段名尽量借用官方材料里真实出现过的说法(会话 id、提示 id、工具名、tool_input、tool_response、duration_ms、token 计数、error),这样你以后接官方那套遥测时不用改词汇表。
记录单位:模型请求一条,工具调用一条
Agent 循环里天然有两种「一步」:一次模型请求,一次工具执行。两者属性差得远——模型请求有 token 计数没有工具名,工具执行反过来——但共享同一批上下文字段(哪次会话、哪次提示、多久)。
所以:每次模型请求写一条,每次工具调用写一条,用一个 type 字段区分。别把一整轮循环压成一条,那样你永远算不出「模型耗时 vs 工具耗时」的拆分;也别只在任务结束时写一条汇总,那样任务一卡在中间,你连它卡在哪一步都不知道。
格式:JSON Lines,一行一条
JSON Lines(常写作 JSONL)就是字面意思:一个文件,每行是一个完整的 JSON 对象,行与行之间没有逗号也没有外层数组。
选它的理由都很土但都成立:追加写就完事,不用在文件末尾回填 ],所以进程被 kill 掉也不会留下语法坏掉的文件(最后一行可能只写了一半,但前面所有行照样能读——这也是后面练习要求「坏行报出来但不中断」的现实来源);文件涨到几百兆时能一行一行流式处理;每行自成一体,grep 能筛,jq 能过,肉眼也能读。
对照很多 harness 里现成的那种散文日志——[09:12:05] search_docs 返回了 3 条结果,用时 412ms。读起来挺顺,但它只能被人读。想回答「过去七天 search_docs 的平均耗时」,你得写正则去抠那个 412ms;哪天有人把「用时」改成「耗时」,正则会悄无声息地开始返回 0。散文日志把结构编码进了自然语言,而自然语言是给人解码的。结构化日志反过来:结构在字段里,机器读起来没有歧义。能过滤、能聚合、能算分布——这三件事正是你从一次运行走向两百次运行时真正需要的能力。
字段词汇表
每条都带的上下文:ts(ISO 8601 时间戳,带毫秒和时区)、type(model_call 或 tool_call)、session_id(一次会话的标识,跨多轮不变)、prompt_id(一次用户提示的标识,它触发的所有模型请求和工具调用共用这个值)、duration_ms。模型请求另加 model、stop_reason、input_tokens / output_tokens;工具调用另加 tool、tool_use_id(和响应配对用)、error(只在出错时有)。
prompt_id 是这里最不起眼、后面最有用的字段。你现在只是把它写进每条记录,第 4 课会用它把散落的记录先圈成「同一次提示的事件」,再靠父子关系串成一棵树。至于工具的入参和返回值本身(tool_input / tool_response)——默认别写全文,只记长度或字节数,理由在倒数第二节讲。
接进 harness
下面这段接在本系列第 7 门课那个 stop_reason 驱动的循环上。先是记录器:
logRecord() 只干一件事:把公共上下文和调用方给的字段拼成一行 JSON 追加进文件。它不判断、不格式化、不做任何「聪明」的事——记录器越笨越好,因为它出错的时候你正好没有日志可查。然后是循环里的两个插桩点:
两处细节值得单说。
计时器的起止位置决定了这个数是什么意思。 t1 起在 runTool 之前、止在它返回之后,所以 duration_ms 包含工具自己的重试、退避等待和网络往返,但不包含调用前的参数校验。这个边界你自己定,定完写下来——半年后看着一个 30 秒的 duration_ms,你会需要知道它有没有把重试算进去。
报错既进日志也进模型上下文。 catch 里把错误信息塞回了 tool_result,Agent 下一轮能看见。官方那条建议在这儿正好用得上:工具报错时的响应应该被当成提示词来打磨,讲清楚具体该怎么改,而不是甩一个晦涩的错误码或调用栈2。日志里可以记 ETIMEDOUT,但送回模型的最好是「请求超时(30 秒)。这个接口对大范围查询容易超时,试试把 date_range 缩到 7 天以内」。
指标的诊断式读法
指标的价值不在「今天调了 1,283 次工具」这种数字本身,在于某几种模式指向某几种修法。官方给的几条对应关系,都是值得先去验证的线索:
冗余调用多 → 可能提示该调分页或 token 上限参数。 大量重复的工具调用,可能提示分页大小或 token 上限这类参数需要重新调一调2。模型要在文档里找一段说明,你的 search_docs 每页只返回 5 条,它就得翻 28 页。这 28 次调用每次都合法、每次都成功,指标上看不出任何「错误」,但它们全是浪费。把每页条数调到 25,这个模式当场消失。
无效参数报错多 → 可能说明工具描述该写清楚、该补例子。 大量因参数不合法而报的错,可能说明工具描述不够清楚、或许该补些示例2。这条厉害的地方在于:报错集中在同一个参数上时,信号强得几乎不用推理。七条报错都是 invalid parameter: date_range,那就先去查你在描述里有没有说清这个参数要什么格式。查证方向是工具描述,不是模型。
追踪工具调用还能看出别的。 统计工具调用可以揭示 Agent 实际常走的工作流,也能暴露一些工具其实可以合并的机会2。比如 read_file 后面 90% 跟着 parse_config,也许该提供一个一步到位的 read_config。这类发现从任何单次运行里都看不出来,只能从聚合里浮上来。另有一组值得常看的读法:把工具结果事件拿来分析,能看出最常用的工具、各工具的成功率、平均执行时长,以及按工具类型分的报错模式3。
有些毛病本身就是数量级问题,不看聚合根本说不清「多」在哪里。Anthropic 记下的早期毛病里就有这种:为并不存在的来源无休止地翻网页4——单看其中任何一次搜索都挑不出错,要把几十次调用摆在一起才看得出「它在原地打转」。
补一条通用经验(没有一手来源):耗时的平均值几乎总是骗人的。99 次 80 毫秒加 1 次 30 秒,平均值 379 毫秒,看着有点慢但还行;实际是 99 次飞快加一次彻底卡住。看耗时至少要看中位数和高分位,或者直接去看最慢的那几条记录。
读数的坑:你的信号到底在数什么
指标最容易骗人的地方不是数错了,是它数的东西跟你以为的不是一回事。
看一个真实产品的设计。Claude Code 在 API 请求失败时会在内部重试,只有彻底放弃之后才发出一条 api_error 事件——这条事件是该请求的终点信号,中间的重试尝试不会各记一条3。这个设计很合理:如果每次重试都报一条错,报错曲线会被自动恢复的抖动淹没,反而看不出真正失败了多少请求。代价是你得记住这条语义——「今天 3 条 api_error」的意思是「有 3 个请求最终失败了」,不是「有 3 次网络抖动」,底下藏着多少次成功的重试,这个信号一个字都不会说。
同一页文档还给了个很实用的读法:想分辨一个会话是从报错里恢复了还是就此卡死,按会话 id 分组,看那条报错之后有没有后续的 API 请求事件3。有后续说明它接着干下去了,没有说明它停在那儿了。这个判断只要一次分组、加一次「找报错之后还有没有记录」的扫描,性价比极高——本课 Level 2 练习就是写它。(追加写的 JSONL 天然按时间有序,所以单文件里不用显式排序;日志来自多个进程时就得先按 ts 排一遍。)
从这个坑里能提炼出一条通用做法:每个指标都写一句「它数的是什么」,写在代码注释或字段文档里。「工具报错数 = 重试全部失败后计一次」和「= 每次抛异常计一次」是两个完全不同的指标,名字却可以一模一样,而半年后看仪表盘的人没法从数字上分辨。
成本与 token:最值得盯的那个数
如果只能盯一个数,盯 token。
先看量级。在 Anthropic 的数据里,Agent 大约要用掉聊天交互 4 倍的 token,多 Agent 系统大约是 15 倍4。这是他们自己系统上的观察,不是普适常数,但它给了你一个心理预期:把聊天功能改造成 Agent,账单不会「稍微涨一点」。他们还有一条统计观察:token 用量本身就解释了 80% 的方差,工具调用次数和模型选择是另外两个解释因子4——这句出自他们分析评测表现的段落,说的是「哪些量最能解释不同运行之间的差异」,token 排第一。两条合起来读:token 既是账单的大头,又是运行差异的头号解释量,几个候选指标里它最值得先盯。
两条实践口径。成本数字是近似值:官方文档说得很直白,成本指标是近似值,正式账单数据要看你的 API 服务方3。所以它的用法是「发现异常、比较趋势」,不是「跟财务对账」。归因要按维度切:用量指标可以用来追踪团队或个人的趋势、找出高用量的会话,也可以按技能名、插件名、子代理类型把开销归到具体的东西上3。对自建 harness 的启发很直接——在日志记录里就把这些维度写进去,别等算账时再从别处拼,事后拼维度基本等于重跑一遍。另外 token 计数直接从模型响应的 usage 字段抄,别用字符数除以 4 之类的方法估,那在中英混排、大量代码、含图片的场景下都会明显偏。
分寸:不发明阈值,不记正文
有指标了,很自然的下一步冲动是设告警:报错率超过 5% 就报警,高分位耗时超过 10 秒就报警。
打住。本课不给任何阈值数字,因为一手材料里没有。 官方文档点了告警这件事该由谁做,但没给过任何具体数值——错误预算、SLO 目标、告警阈值,一个数都没有。我要是在这儿写「建议 5%」,那就是我编的,而你会拿去用。阈值只能从你自己的基线里长出来:先记两周数据,看正常波动的范围,再定什么算异常。顺序反过来,你得到的只是一个每天误报三次、两周后被所有人静音的规则。
分工也值得照抄官方产品的做法:Claude Code 只发出原始事件流,异常检测、建立基线、跨会话关联和告警都是后端(SIEM——安全信息与事件管理系统——或可观测性平台)的职责3。这对自建 harness 的意义是:被观测的系统不要自己做判断。 别在 harness 里写「连续 3 次工具报错就发邮件」——那段逻辑会跟着 Agent 一起被部署、一起被重启、一起出故障,而且它没有历史数据可比。
最后一件事,也是最容易在上线三个月后变成事故的:内容默认不记。 Claude Code 默认不采集用户提示词的内容、只记长度,要连内容一起记得显式打开一个环境变量3;Agent SDK 的遥测同样结构化优先——时长、模型名、工具名每个 span 都记,token 计数在 API 返回用量数据时记,但 Agent 读到和写出的内容默认不记录1。
这两个默认值背后是同一个判断:结构信息(谁、什么时候、多久、哪个工具、多少 token)足够回答绝大多数运维问题,内容不是。内容一旦进了日志,就跟着日志走进备份、走进长期存储、走进任何一个有读权限的人的视野。所以你的 harness 默认应该记 input_bytes: 137 而不是 tool_input: {...},真要排查某次调用的具体参数时再针对那一次打开完整记录。这跟第 2 课「原始记录是第一手证据」不冲突:调试时你当然要看完整往返,那是在你控制的环境里、针对特定一次运行、看完就完事;生产日志默认长期留存、默认多人可见,是另一回事。
边界:这一课到哪儿为止
到这里你手上有一堆结构化记录和一组能读的指标。还有三件事本课不做:记录之间的父子关系(一次提示触发了哪些模型请求、哪个工具调用套在哪个子代理里)要靠关联 id 串成一棵树,那是第 4 课;不改 harness 代码、从生命周期关口挂探头是第 5 课的 hooks;把这一整层装到你本系列第 7 门课那个 harness 上并走一次完整调试演练,是第 6 课。
💻 练习
小结
- 生产环境的可观测性要回答四个问题:调了哪些工具、每次模型请求花了多久、花了多少 token、失败发生在哪1。这四问和本系列第 10 门课那组评测指标(单次与整任务运行时长、工具调用总次数、token 总消耗、工具报错)2是同一组数——评测时拿它判改动好坏,监控时拿它盯运行健康。
- 日志的字段设计、JSONL 选型没有一手规范,是你自己的工程决定。默认起点:每次模型请求一条、每次工具调用一条,一行一条 JSON,带上会话 id、提示 id、时长、token 计数、工具名和报错。散文日志只能被人读,结构化的才能被过滤、聚合、算分布。
- 指标的价值在于模式直接对应修法:冗余调用多说明分页或 token 上限参数该调整,大量无效参数报错说明工具描述该写清楚、该补例子2;追踪工具调用还能揭示 Agent 实际常走的工作流、暴露工具可以合并的机会2;工具报错时的响应本身应该写成具体可执行的改进建议,而不是晦涩的错误码2。
- 信号的语义由记录方式决定。Claude Code 内部重试失败的 API 请求,只在放弃之后发一条
api_error 事件作为终点信号,中间的重试不单独记3——所以一个「报错数」底下可能藏着大量隐形重试。要分辨一个会话是恢复了还是卡死了,按会话 id 分组、看报错之后还有没有后续的请求事件3。
- token 是最值得盯的单一指标:在 Anthropic 的数据里 Agent 大约用掉聊天 4 倍的 token、多 Agent 系统约 15 倍4;他们分析评测表现时还发现 token 用量本身就解释了 80% 的方差,工具调用次数和模型选择是另外两个解释因子4。成本指标是近似值,正式账单看你的 API 服务方3;开销可以按技能名、插件名、子代理类型归因到具体的东西上3。
- 分寸两条:被观测的系统只管发原始事件流,异常检测、建立基线和告警是后端的职责3;日志默认别记正文——官方产品默认不采集提示词内容、只记长度3,遥测默认只记结构信息、不记 Agent 读写的内容1。告警阈值和 SLO 一手材料里没有任何数字,别发明,先记两周基线再说。
>> 第 4 课:Trace:把一次运行串成一棵树