做AI Agent工程这两年我有个越来越强烈的体会Agent跑成功的时候你根本不需要看日志但Agent一旦跑失败你大概率什么都查不到。上周我就经历了一次典型事故——一个数据聚合Agent跑了40分钟调用了十几个外部工具最终只吐出一句“任务失败”没有堆栈、没有中间状态、没有上下文快照。更麻烦的是同样的任务重新跑一遍它可能又成功了。这种不确定性让“复现Bug”变成了一厢情愿也让传统的log堆栈排障方式彻底失效。我们团队最后是靠一套Agent Trace机制救回来的把一次完整执行的所有环节——模型思考、工具调用、工具返回、状态变更、异常重试——全部以结构化的方式记录下来然后像翻监控录像一样把失败的那次执行一帧一帧还原出来。这篇文章我会用一次真实的失败执行作为案例完整拆解Trace的数据模型、还原过程、根因定位方法以及我们在落地过程中踩过的那些坑。适合正在做AI Agent开发、调试和测试的同学参考尤其是那些已经开始被“随机性失败”折磨的团队。1. Agent的失败为什么是“悬案”传统日志在非确定性系统面前失效了1.1 三次本质差异决定了排障思路必须变传统后端服务是一个确定性系统相同的入参一定会走相同的代码路径只要日志打够、堆栈捞全问题基本都能复现。但Agent不是这样。一个Agent执行任务的路径是由LLM在运行时动态决定的它可能这次先调用工具A再调用工具B下次觉得没必要调用A直接跳过去。这种路径的不确定性让传统“复现Bug—打日志—定位”的闭环直接断裂。我概括过传统系统和Agent系统的三个本质差异这也是为什么必须引入Trace而不是继续依赖日志失败层级的多样性Agent的失败可能发生在LLM推理层规划错了、工具调用层参数传错、状态流转层上下文丢了、外部系统层下游接口超时。传统日志通常只记录了“哪一层报错”但Agent需要知道的是“这一层为什么这么决策”。非确定性执行路径同一任务两次执行LLM采样结果不会完全一致。没有执行轨迹记录你无法回答“上一次它到底做了什么”这个基本问题。副作用无法回滚Agent执行过程中可能已经写入了数据库、发送了邮件、创建了订单。出了问题不能像单测一样重放一遍必须靠执行轨迹确认“它动过哪些外部资源”。1.2 传统日志为什么帮不上忙我做排障时最常见的场景是Agent返回了一个错误日志里只有一行Tool execution failed: get_weekly_orders。这个信息相当于告诉你“车坏了”但没告诉你是发动机、轮胎还是油路的问题。更麻烦的是Agent的很多错误是“复合型”的。比如最终失败原因是“生成报告失败”但往前追溯可能是第二步工具返回了一个格式异常的数据LLM基于这段异常数据做了错误决策然后一路错到底。传统日志以“发生了什么结论”为中心而Agent排障必须以“决策过程”为中心——这正是Trace的定位。提示判断一个系统是否需要上Trace最简单的标准就是——出了故障之后你是否能准确说出“上一次执行中模型在第三步到底看到了什么”。如果答不上来现有的日志体系撑不起Agent排障。2. Trace的底层模型一次执行、一串Span、无数Event2.1 最核心的三个概念我做Trace设计时的第一原则是不要凭空发明一套新概念沿用业界已经验证的OpenTelemetry链路模型把Agent的一次执行映射成标准的Trace-Span-Event三级结构。TraceRun ID一次完整的Agent执行从开始到结束生成一个全局唯一的trace_id。这是所有排障的入口主键。Span一次执行内部的一个有明确边界的环节。一次Agent执行通常可以拆成规划、模型生成、工具调用、工具返回、状态更新等若干个Span。EventSpan内部的细粒度事件记录比如模型生成了哪些中间token、工具调用的入参是什么、抛出了什么异常、触发了几次重试。用一个生活化的类比Trace是整个航班的飞行记录仪Span是航段起飞、巡航、降落Event是每一秒的仪表读数。排查事故时先看哪个航段出了问题再放大到对应的仪表读数。2.2 为什么必须用三级模型不能只有一层我在第一版Agent Trace设计时曾经偷懒过——只记录“每步做了什么”结果排障时依然抓瞎。原因很简单面向的问题粒度完全不同。Trace回答的是“这次执行整体是否成功、耗时多久、调了多少次工具”Span回答的是“哪一个环节出了问题、这个环节的上下游是谁”Event回答的是“这个环节内部到底发生了什么、为什么失败”。三层各有用途缺一层都会让排障效率大打折扣。举个例子只看Trace层你能发现“调用工具阶段耗时过长”但只有进入Span层才能看到是“第二个工具重试了三次”再进到Event层才能看到第三次重试是因为“返回结果里的金额字段变成了字符串类型导致LLM解析失败”。2.3 构建执行树parent_span_id 是关键Span之间不能是平铺的列表必须通过parent_span_id构建成树状结构。因为Agent执行天然是分层的——一个规划Span下面挂了多个工具调用Span每个工具调用Span下面又挂了事件明细。这里分享一个实践中的小细节时间片时序在Agent Trace中比传统链路中更重要。传统链路每个Span的耗时相对固定而Agent的模型生成Span可能耗时20秒工具调用Span可能只有200毫秒。两个Span之间的时间间隔往往暴露问题——比如模型生成结束后到下一次工具调用之间隔了十几秒通常意味着它在悄悄重试或者卡在了哪里。3. 解剖一次失败执行从Trace完整还原崩溃现场3.1 一个真实的失败案例背景我拿我们上周的那个排障案例展开。任务本身不复杂Agent需要从订单系统查询本周订单数据聚合出每日趋势并生成一段业务分析文字。整个执行过程调用了工具OrderTool.get_weekly_orders然后基于返回结果做汇总。最终Agent返回了一个让人摸不着头脑的错误“报告生成失败订单数据不可用”。如果只看最终错误信息你会以为数据源出了问题。但当我用Trace ID拉出完整执行轨迹后真相完全不一样。下面是一段简化后的Trace数据JSON Lines格式为了阅读清晰做了缩进{ trace_id: trc_9f31a2b8e7, session_id: sess_02c4d1, user_input: 查询本周订单数据生成每日趋势和业务分析, status: failed, start_time: 2025-03-04T10:00:01.128Z, end_time: 2025-03-04T10:11:47.392Z, spans: [ { span_id: span_001, parent_span_id: null, name: plan, span_type: llm_plan, start_time: 2025-03-04T10:00:01.200Z, end_time: 2025-03-04T10:00:09.804Z, events: [ {type: llm_input, data: {messages: [system: 你是一个数据分析助手..., user: 查询本周订单...]}}, {type: llm_output, data: {plan: [调用OrderTool查询订单, 按日聚合订单金额, 生成趋势分析]}} ] }, { span_id: span_002, parent_span_id: span_001, name: call_tool:OrderTool.get_weekly_orders, span_type: tool_call, start_time: 2025-03-04T10:00:10.010Z, end_time: 2025-03-04T10:00:10.892Z, events: [ {type: tool_input, data: {date_format: MM/DD/YYYY, value: 02/05/2025}}, {type: tool_error, data: {message: date format error, expected YYYY-MM-DD}}, {type: retry_count, value: 1} ] }, { span_id: span_003, parent_span_id: span_001, name: call_tool:OrderTool.get_weekly_orders(retry), span_type: tool_call, start_time: 2025-03-04T10:00:12.310Z, end_time: 2025-03-04T10:00:13.055Z, events: [ {type: tool_input, data: {date_format: YYYY-MM-DD, value: 02/05/2025T00:00:00}}, {type: tool_error, data: {message: date format error, expected YYYY-MM-DD}}, {type: failure_reason, data: agent stopped retrying} ] }, { span_id: span_004, parent_span_id: span_001, name: generate_report, span_type: llm_generate, start_time: 2025-03-04T10:00:13.800Z, end_time: 2025-03-04T10:11:40.221Z, events: [ {type: llm_error, data: {message: required data missing: order list is empty, raw: 报告生成失败订单数据不可用}} ] } ] }3.2 逐帧还原执行过程把这段Trace按时间线展开后整个执行过程其实非常清晰时间Span事件说明10:00:01planLLM规划模型输出了三步计划看起来正常10:00:10call_tool第一次调用传入了date_formatMM/DD/YYYY被工具拒绝10:00:12call_tool重试调用转换了date_format字段但value仍然是02/05/2025T00:00:00依然被拒10:00:13generate_report模型生成因拿不到订单数据最终输出一个误导性错误从Trace里能明显看出三个关键信息第一真正的失败点发生在10:00:10的工具调用而非最后那句“报告生成失败”。最终错误信息是LLM在数据缺失情况下编造出来的“合理解释”具有很强欺骗性。第二Agent进行了一次重试但重试时只修正了格式字段没有修正value字段。这说明模型并没有真正理解错误信息里的“expected YYYY-MM-DD”意味着什么只是机械地调整了它认为可疑的参数。第三两个工具调用Span之间的间隔只有2秒左右不存在超时或卡顿问题排除了下游系统故障的可能。3.3 外层错误的“欺骗性”是Agent排障最大的陷阱这个案例完美地展示了一个我之前反复踩的坑Agent的最终错误输出往往是它基于不完整信息做的“合理化解释”而不是真实的失败原因。在传统系统里最外层的报错信息通常是最靠近根因的但在Agent系统里恰恰相反最外层错误信息往往经过了LLM的重构和想象距离真实原因最远。这也是为什么我一直强调排障时必须从Trace中最深的工具错误Event开始看而不是从Agent最终的message开始看。4. 顺着Trace找根因我常用的五步定位法4.1 从最深处的Error Event反查拿到一个失败执行的Trace后我的习惯是先过滤出所有type为tool_error或llm_error的Event然后选择时间戳最早的那一个作为根因候选。这个方法看起来简单但非常有效。因为Agent执行有很强的“链式放大”特征早期一个小错误经过后续几步LLM的推理、编造、扩展到最后可能完全面目全非。后端排障是“由顶向下逐层下钻”Agent排障一定要“由底向上逆向回溯”。4.2 还原Agent当时看到的完整上下文定位到最早的Error Event后下一步不是急着改代码而是要完整还原Agent在那一刻的上下文。我最常查的三样东西系统Prompt里有关于日期格式的明确说明吗还是说只是工具描述里的一句话带过工具返回的错误信息原文是什么它是否给出了正确的格式示例模型在这个错误发生之前已经看到了哪些中间结果有没有可能上下文被截断导致它遗漏了关键信息在刚才那个案例里还原完上下文后我们发现工具返回的错误信息虽然写了expected YYYY-MM-DD但整个错误文本很短没有给出正确的调用示例。模型第一次传错后第二次只是盲目调整了参数名并没有真正理解value字段也需要同步转换格式。这说明问题并不单纯是“模型笨”工具层的错误信息设计也有优化空间。4.3 区分“模型不懂”和“代码没接好”这是Agent根因分析里最需要经验的一步。我一般用下面这个标准来判断责任归属现象可能原因责任方Prompt/工具描述里明确给了示例模型依然传错模型对指令遵循能力不足模型/提示词层工具描述里没有格式说明模型凭感觉传参工具定义不完整工程层工具返回了结构化错误LLM错误解析错误信息设计不佳工程层工具本身逻辑对部分输入抛异常工具健壮性不足工程层上下文过长被截断模型看不到关键约束Prompt设计/上下文管理工程层在落地Trace后我发现一个很反直觉的规律大部分Agent“看起来像模型问题”的失败最后查下来都是工程层的问题。工具描述写得不清楚、错误信息不友好、重试逻辑不带上下文修正、上下文截断策略太粗暴——这些才是高频根因。4.4 用Diff Trace对比成功执行有一种特殊场景失败Trace本身看不出明显异常参数没传错工具也正常返回但Agent最终结果就是不对。这种情况我建议把同一任务的成功Trace拉出来和失败Trace做逐Span对比。具体做法是把两个Trace按Span名对齐逐个对比输入、输出、耗时、token数。我之前遇到过一个问题最后一次排查出失败Trace里某个工具返回的结果被截断成了之前的70%导致LLM汇总时缺了一部分数据。单纯看失败Trace根本发现不了一对比就真相大白了。4.5 留意重试机制掩盖真实原因的情况当Span列表里出现多次retry_count就要特别小心。重试在Agent里是把双刃剑——它能提高任务完成率但也经常把根因藏起来。我在实践中的一个原则是重试时必须记录每一次重试的完整输入和输出并标记触发重试的原因。如果只是静默地重新调用一次工具Trace看起来就多了一个慢Span里面没有诊断价值。只有记录了“上一次因为什么失败、这次调整了什么参数”重试链路才能真正辅助排障。5. 把Trace体系真正落地埋点、存储、检索与可视化5.1 埋点在Agent主循环的六个关键位置打点Agent的工程实现千差万别但核心执行循环基本一致。我建议在下面六个位置打Trace埋点覆盖绝大多数排障需求LLM生成开始/结束记录完整messages输入和生成的response这是还原“Agent看到什么”的关键工具调用开始记录函数名和完整入参工具返回结束记录返回结果并对大体积结果做截断状态更新记录Agent内部状态比如任务清单、已完成步骤的变更异常捕获记录所有exception信息及其上下文重试触发记录重试原因、重试次数、重试前的修正决策下面是我在用的一种极简埋点实现核心概念清晰接入成本也低import uuid import json from datetime import datetime, timezone class TraceEmitter: def __init__(self, trace_id: str): self.trace_id trace_id self.spans [] self.current_span_stack [] def start_span(self, name: str, span_type: str) - str: span_id uuid.uuid4().hex[:12] parent_id self.current_span_stack[-1] if self.current_span_stack else None self.current_span_stack.append(span_id) self.spans.append({ trace_id: self.trace_id, span_id: span_id, parent_span_id: parent_id, name: name, span_type: span_type, start_time: datetime.now(timezone.utc).isoformat(), end_time: None, events: [] }) return span_id def end_span(self, span_id: str): span next(s for s in self.spans if s[span_id] span_id) span[end_time] datetime.now(timezone.utc).isoformat() if self.current_span_stack: self.current_span_stack.pop() def emit_event(self, span_id: str, event_type: str, data: dict): span next(s for s in self.spans if s[span_id] span_id) span[events].append({ type: event_type, data: data, time: datetime.now(timezone.utc).isoformat() }) def save(self, writer): writer.write(json.dumps({ trace_id: self.trace_id, status: failed if any(e[type].endswith(_error) for s in self.spans for e in s[events]) else success, spans: self.spans }, ensure_asciiFalse) \n)在Agent主循环里的使用方式也很简单以工具调用为例trace TraceEmitter(trace_idtrc_9f31a2b8e7) span_id trace.start_span(call_tool:OrderTool.get_weekly_orders, tool_call) try: trace.emit_event(span_id, tool_input, {date_format: MM/DD/YYYY, value: 02/05/2025}) result order_tool.invoke(date_formatMM/DD/YYYY, value02/05/2025) trace.emit_event(span_id, tool_result, {summary: result.summary()}) except Exception as e: trace.emit_event(span_id, tool_error, {message: str(e)}) finally: trace.end_span(span_id)5.2 存储从JSONL起步别一开始就上重型系统在存储方案上我见过不少团队一上来就搭ClickHouse结果数据量没起来运维成本先压垮了团队。我建议分阶段演进阶段一验证期直接往本地JSONL文件追加Trace记录。排查时用jq按trace_id过滤就行零运维成本。阶段二小规模生产接一个轻量的PostgreSQL或者SQLite按trace_id建索引查询维度做到session_id和error_type即可。阶段三规模化当每日Trace量达到数十万条时再迁移到ClickHouse或者兼容OpenTelemetry的链路系统同时考虑采样策略。存储时有一个建议Trace原始数据尽量以JSON全文保存不要为了省空间只存结构化字段。Agent排障的灵异问题常常需要回看原始输入输出字段拆分越细还原能力越弱。5.3 检索与可视化最小可用闭环长什么样可视化这块我踩过“过度设计”的坑。第一版我花了两周做了一个花哨的甘特图界面结果团队用起来发现最缺的其实就是个检索框。收敛之后我们的最小可视化闭环就三个能力按trace_id或者session_id拉出一条完整的时间线清晰展示各Span的先后顺序、父子关系、耗时错误Span用高亮标红。点击某个Span能展开它的全部Events尤其是tool_input和tool_error的原始内容。支持按error_type、模型名称、工具名称做聚合统计能快速看出哪类失败占比最高。提示如果你的Agent系统已经接入了OpenTelemetry规范的链路追踪可以考虑直接把Agent的Span映射为标准Span复用已有的Jaeger或者Grafana Tempo。好处是不用重复造可视化轮子坏处是Agent的Event语义和标准RPC调用不太一样需要做一些字段映射。6. 实践半年的踩坑清单给Trace系统补上的七块短板6.1 只记结论不记快照等于没记这是我犯过的最严重的错误。早期我为了节省存储把每个Span只记录“发生了什么”的摘要比如tool_result: ok。等到排障时才发现我需要的是“工具完整返回了什么数据”“模型那一刻看到了什么文本”而不是一个布尔值。现在的原则是凡是模型可见的内容必须尽可能完整快照。LLM和工具的输入输出是排障的“现场物证”不能只留摘要。6.2 大体积工具结果要截断但不能只截断工具返回几MB的JSON很常见全量存储不现实。我的做法是双轨存储在线的截断结果前面N个字符长度统计同时把完整结果写入对象存储或者本地磁盘Trace里带上文件路径。这样既控制了体积又保留了全量还原的能力。6.3 敏感信息脱敏必须在写入前完成Agent的工具调用参数里经常夹带密钥、Token、用户手机号之类的敏感字段。如果Trace系统不处理脱敏它就成了一个泄密数据库。我建议在埋点层就配置敏感字段正则对疑似敏感内容做掩码处理而不是在存储层后补。否则一旦数据进了日志系统想要彻底清理就非常被动。6.4 异步任务必须穿透trace_id很多Agent系统会异步执行子任务或者多Agent协作。这个时候如果子任务的Trace不从父任务透传trace_id你会在排障时看到一堆孤立的Trace片段根本无法还原全貌。我的做法是在Agent的上下文对象里挂一个TraceContext所有的子任务、回调、异步分支都从里面取trace_id并且把父Span ID带下去。6.5 保留策略成功短留失败长留Agent执行的成功率通常不是100%失败Trace的诊断价值远高于成功Trace。我目前的保留策略是成功Trace保留7天失败Trace保留30天带工具级错误的Trace保留90天。这个策略在存储成本和排障能力之间平衡得还不错。6.6 从第一天就做别等出事故再补这是我的真心话。Trace体系如果等项目跑飞了再补最大的困难不是技术而是“没有历史的Trace数据可供回溯”。事故发生后再想还原现场只能靠用户描述和残缺日志那种无力感非常难受。哪怕是最简单的JSONL方案也应该在Agent系统的第一个Demo阶段就接入。6.7 用Trace数据反向驱动Agent质量改进Trace不只是用来排障的它还是Agent质量分析的一手数据源。我每周会做一次Trace数据汇总统计哪类工具报错最多、哪个环节平均耗时最长、哪种任务的LLM重试率最高。这些指标能直接指导Prompt优化和工具设计。在我看来Trace的价值一半在事故排障另一半在日常迭代——甚至后者的长期价值更大。回到开头那个案例。我们通过Trace定位到根因后只做了两个改动工具的错误信息里增加了正确的日期格式示例同时在工具层放开了解析逻辑接受常见日期格式。从那以后这类失败基本消失了。整个过程没有AI的“玄学修复”就是靠Trace把模糊的失败变成明确的工程问题。这也是我坚持写完这篇实践记录的原因——Agent的不可解释性恰恰需要通过工程手段来消解。