前几天晚上一条告警把我从床上拽起来AI 客服助手在晚高峰时段大量超时用户端直接提示“服务暂时走神”。我第一反应是打开日志平台结果越看越上火——调用日志一条没少每段都带了 TraceIDHTTP 状态码是 200模型返回内容也捞到了可我就是说不清楚这次故障到底发生在哪一环。翻了快一个小时才发现问题压根不在“有没有日志”而在“日志里记录的信息根本回答不了 AI 调用场景下的故障问题”。这篇文章想聊两件事第一为什么很多团队明明给 AI 调用上了日志、挂了 TraceID遇到故障还是两眼一抹黑第二我先后踩过几次坑之后沉淀出来的一套“AI 调用可观测性”做法。如果你正在做 LLM 应用、Agent 编排或者 RAG 服务这篇内容应该能帮你少走不少弯路。1. 传统排障三板斧为什么碰到 AI 调用就失灵1.1 你以为的“有日志”通常只覆盖了链路的两端传统后端排障有三板斧查异常栈看哪个方法抛了异常查状态码看 HTTP 层返回什么查耗时曲线看哪个节点明显变慢。这三招对付普通接口基本够用但放到 AI 调用上第一板斧就劈空。原因其实很朴素传统接口的处理逻辑是自己的代码异常栈对应的是自己的函数调用栈问题出在哪一目了然。AI 调用不一样真正的推理逻辑在模型服务内部对于我们来说它是一个黑盒。你只能看到“请求发出去了”然后“模型吐了个东西回来”中间那几秒到几十秒到底发生了什么日志平台里通常什么都没有。所以你在日志系统里翻到的往往是两端请求进来时打的一条日志、响应回来时打的一条日志。中间那个黑盒时间片靠传统手段根本看不见。更麻烦的是就算 HTTP 层一切正常业务代码也判定成功模型返回的内容质量不对传统日志也会干脆沉默。系统日志显示绿色用户实际体验已经崩了这种割裂是 AI 排障难的第一层原因。1.2 “查不清”的三个典型症状几乎人人都遇到过第一个症状是入口有日志、出口有日志中间是黑洞。日志只告诉我们“发生了什么”不告诉我们“为什么发生”。同一个接口昨天正常今天异常输入都一样输出却千差万别。传统日志解释不了这种不确定性因为它天生假设“输入相同输出就相同”。第二个症状是请求上下文压根没进日志。AI 调用的结果高度依赖 Prompt、temperature、max_tokens、历史会话、截断策略。这些参数任何一个变了输出都可能天翻地覆。但很多团队的日志里只有“调用模型 API”“返回成功”“耗时 X 秒”这三条关键现场全丢了故障发生后只能靠猜。第三个症状是语义失败不会产生任何错误日志。传统接口的失败会体现在错误码上AI 的失败往往藏在返回文本里——“抱歉我无法回答这个问题”被模型正常生成HTTP 状态码是 200日志记录一次成功的调用。但用户得到的是无效答案业务方视图是功能异常两边视图完全对不上。这就是典型的“日志全绿故障照旧”。2. 日志里具体缺了哪几环才让人怎么都查不清2.1 链路断裂异步、线程池、回调把 TraceID 弄丢了AI 应用很少是单次直连模型的真实业务里大多是串糖葫芦用户请求进来先去知识库检索一段内容再调工具 API 拿点数据然后把检索结果、历史会话和用户问题一起拼进 Prompt发给模型模型生成完再回调业务侧落库或推送结果。每个环节可能都会打日志但链路往往在这里开始断裂。最常见的情况是线程池。为了并发拿多路数据代码里用了异步任务子线程里日志系统会重新生成一个 TraceID导致原本一条完整链路被切成了好几段。排查时你拿着入口的 TraceID 去搜搜出来的只有入口那一条剩下的全部沉在日志海洋里。回调场景更惨模型结果回来后回调逻辑里打的日志根本关联不上原始请求你只知道有个任务提交了不知道它到底跑完没有。还有个隐蔽问题是重试。路由层发现模型服务超时后自动重试每次重试都生成新的 TraceID日志平台里看起来有好几条近似的调用记录但它们其实属于同一次用户请求。日志是齐的链路是碎的这时候你越看越乱排查自然卡住。2.2 上下文缺失现场都丢光了故障自然无法复现排障时最怕一句话——“日志全有但现场没了”。传统接口的现场是请求参数和数据库状态AI 调用的现场是完整输入上下文、模型参数和中间结果。这几样东西有一个没记录下来复现就是空谈。举个例子。同一句用户问题temperature0 和 temperature1 两次调用结果可能完全不同。模型版本升级后同样的 Prompt 输出风格突变。上下文超长后触发截断截断策略把中间一段关键信息丢掉了模型输出直接跑偏。再比如 max_tokens 设小了回答在生成到一半时被掐断日志里只有 finish_reason 等于 length不熟悉的人还以为这是正常结束。这些参数和现场数据恰恰是传统日志体系最少关注的。普通接口排查只需要 IP、入参、异常栈但 AI 排查依赖的是 Prompt 内容、参数快照、Token 用量。不在日志里记录这些出了问题你只能对着一个“成功”的调用记录发呆。2.3 语义断层模型不会自己生成“错误码”传统接口设计里失败一定会映射到错误码调用方根据错误码做分支处理。AI 调用打破了这种约定模型返回的内容不是结构化错误信息只是自然语言文本。模型说“我不能处理这个请求”从协议层看没有任何异常信号。语义断层是 AI 排障体系里最隐蔽的部分。它意味着你的日志系统即使完美记录了调用记录也无法回答“这一次调用到底算成功还是失败”。因为“成功”的定义从来不只是 HTTP 状态码还包括输出是否为空、是否被截断、是否格式非法、是否内容拒绝主题要求。要解决这个问题必须给输出内容增加一层“语义判定”把模型的自然语言输出翻译成结构化状态empty_response、truncated_output、json_parse_error、refusal_keyword_hit然后再写进日志字段。这一步不做日志系统再完善也只能当数据仓库用排不了障。2.4 流式响应与异步任务结束日志永远缺失用流式输出比如 SSE时排障难度又高一层。传统接口一次请求一次响应响应回来就算结束。流式接口不一样连接何时建立、首 Token 何时到达、中间段是否发生断连、客户端是否中途取消、生成是否正常收尾这些事件都分散在不同的时间片里任何一段出问题日志里都看不出全貌。我见过最典型的坑是用户在浏览器端等不及直接刷新页面客户端断开连接服务端还在继续生成内容生成结果却没人接。日志平台上只有“连接建立”一条记录没有“连接关闭”和“生成中断”看起来就像调用一直悬挂实际已经报废了。异步任务也好不到哪去。请求提交后日志打了一条“任务已入队”后续模型调用、结果回调散落在不同的时间点。如果回调逻辑没执行或者回调里报错日志平台上除了那条孤零零的“已提交”什么都没留下。没有结束标记就没有完成态你根本无法判断任务是慢、是挂、还是已经丢了。3. 五步把 AI 调用日志改造成排障工具3.1 第一步让 TraceID 贯穿所有环节包括异步和回调TraceID 透传是基础但很多团队的实践只做到了一半入口网关生成 TraceID业务代码里打日志能带上一到线程池就断了。正确做法是设计一层统一的“上下文透传”机制而不是靠每个开发者自觉传递。具体做法不复杂业务启动时把 TraceID 塞进线程上下文提交异步任务时显式把父 TraceID 注入子线程回调逻辑里从任务上下文取回原始 ID。如果用 Java 技术栈可以在线程池提交时用一个包装类统一处理把 MDC 里的值复制过去如果用 PHP 或 Python则需要手动做协程上下文的传递。关键的验证方式是做一次“全链路演练”故意在异步分支里打点日志然后用同一个 ID 搜索整个链路看接口数量是否完整。// Java 伪代码示意线程池提交时透传 TraceID ExecutorService executor new ThreadPoolExecutor(...); public void submitTask(Runnable task, String traceId) { executor.submit(() - { MDC.put(traceId, traceId); // 还原父链路 ID try { task.run(); } finally { MDC.remove(traceId); } }); }3.2 第二步补齐四类关键日志而不是只打“调用成功”第一步解决“链路能串起来”第二步解决“现场能对得上”。我把 AI 调用的日志分成四类每类都规划了固定字段调用前日志、调用后日志、异常日志、审计日志。调用前日志记录发起方的完整意图和参数包括脱敏后的 Prompt、模型名称、模型版本、temperature、max_tokens、上下文长度、是否触发截断、重试次数。调用后日志记录模型的真实返回状态包括 HTTP 状态码、业务状态码、首 Token 延迟、总耗时、Token 用量、finish_reason、截断标志、语义判定结果。异常日志负责记录超时、限流、连接错误、解析异常时的完整异常栈和上下文快照。审计日志则给成本和合规用谁在什么时候调了哪个模型花了多少 Token。// 调用前日志示例 { timestamp: 2025-06-17T20:31:05.123Z, trace_id: 0a3f7b9c8d1e2f3a4b5c6d7e8f9a0b1c, event: ai_call_start, model: some-llm-v2, prompt_meta: { chars: 342, truncated: true, history_keep: 6 }, params: { temperature: 0.2, max_tokens: 2048 }, input_preview: [已脱敏] }// 调用后日志示例 { timestamp: 2025-06-17T20:31:20.421Z, trace_id: 0a3f7b9c8d1e2f3a4b5c6d7e8f9a0b1c, event: ai_call_end, duration_ms: 15300, first_token_ms: 2130, total_tokens: 1560, output_tokens: 780, finish_reason: length, semantic_status: truncated_output, error: null }注意这两个示例里的字段不是摆设。finish_reason 等于 length 说明输出被 max_tokens 掐断了semantic_status 等于 truncated_output 说明内容本身不完整这两个字段同时出现基本可以直接判定这是一次低质量调用不需要再去日志里大海捞针地翻原始文本。3.3 第三步增加语义判定层让日志自己会“分类”这是我踩过几次坑之后觉得最重要的一步。以前排查 AI 调用问题得先把日志拉出来用肉眼扫模型返回的文本看是不是空、是不是拒绝、是不是截断。后来我写了一个轻量的语义判定模块在模型返回之后、写日志之前先对输出做一次程序化分类把判定结果直接落进 semantic_status 字段。判定的逻辑不需要太复杂几条规则就能覆盖绝大多数问题输出内容长度为零判 empty_responsefinish_reason 为 length 且输出长度接近 max_tokens 判 truncated_output要求 JSON 输出但解析失败判 json_parse_error输出文本命中拒绝类关键字比如“抱歉我不能”判 refusal 类如果调用方设定了输出模板而结果不匹配判 content_mismatch以上都没有才是 normal。有了这个字段之后排查效率是天壤之别。以前要全文检索“抱歉”“无法回答”这类词现在一条查询语句就能统计出“今天有多少空响应、多少截断、多少 JSON 解析失败”。这不是日志格式的小优化而是整个排障思路从“捞日志看内容”变成“按状态筛记录”的本质变化。3.4 第四步给流式和异步任务补上“结束标记”流式接口的日志规则很简单一个调用至少对应四个时间点——连接建立、首 Token、部分输出、连接关闭。其中连接关闭要区分正常结束、服务端中断、客户端取消这三种情况分别打不同的事件日志。客户端取消尤其容易被忽略用户刷新页面或断开网络时服务端感知不到如果不记录这个调用就会永远悬挂在日志平台里看起来还在跑实际已经终止了。异步任务的处理建议是维护一张“未完成跟踪表”。任务提交时写一条记录带原始请求的 TraceID 和任务状态回调成功或失败时更新状态。再加一个定时扫描发现超过 N 分钟仍然处于“已提交未回调”状态的任务就自动告警。这样既能解决回调日志不关联的问题也能防住任务静默丢失的隐患。3.5 第五步建一个“失败现场样本库”别把所有日志一锅炖最后一步可能很多人没意识到排障日志、成本日志、业务流水日志应该是分开的。Token 计数和成本统计这类高频写入的日志不需要跟排障日志混在一起真正排障时需要的是按 TraceID 聚合的一组高质量记录而不是海量的普通流水。我的做法是对异常请求和语义状态异常的请求额外保留一份完整的输入输出样本包括没有截断的 Prompt、模型原始返回、时序事件表。这样每次线上故障都不是孤立的现场而是一份可回放、可对比、可用来重新测试的数据集。这个样本库积累到一定规模后很多看似偶发的问题会自己浮现出规律。4. 一次空响应故障复盘从“日志全绿”到定位根因我拿最近一次实际处理过的故障举例演示一下这套日志体系怎么用起来。现象是某 Agent 服务在特定时段大概 15% 的调用返回空响应业务层的监控指标全部正常传统日志里没有任何异常堆栈HTTP 状态码清一色 200。第一步是拿 TraceID 把所有关联日志捞出来发现入口日志和出口日志都在模型确实返回了内容但 semantic_status 被判定成了 empty_response。这说明问题出在模型侧而不是网关或者业务代码。第二步看调用前日志里的 prompt_meta发现输入文本长度已经非常接近上下文窗口上限系统触发了截断。截断策略是最简单的前向截断也就是把历史会话中靠前的内容整段丢掉。问题在于一次多轮对话中用户的核心意图往往在最早几轮出现前向截断恰恰把最关键的信息丢了。第三步接着看模型参数max_tokens 设置偏小模型生成到一半就触发了 finish_reason 等于 length。双重因素叠加模型没有足够上下文输出质量本来就差又因为 token 上限内容还没生成完就被切断。模型没有报错也不会主动告诉你“我不理解你在问什么”它就静默返回了一段残缺内容。第四步定位根因改配置。把上下文截断策略从“前向截断”改成“保留关键轮次 摘要压缩”同时把 max_tokens 调大到合理范围。问题消失。这件事给我最深的感受是如果系统没有语义判定层这个故障按老办法排查至少得先把 15% 的请求日志全捞出来人工阅读逐个对比输入和输出运气好可能一两个小时运气差就是一下午。而现在一条 SQL 筛选出所有 empty_response再按 trace_id 聚合看 prompt_meta十来分钟就锁定了方向。5. 常见坑位与排查速查表5.1 排障速查表症状、根因和第一步动作我把平时遇到最多的几类 AI 排障问题整理成一张速查表。排查时先对号入座可以省掉不少弯绕。现象最可能的根因第一条排查动作日志全绿但业务结果错误语义失败没有纳入日志体系给输出加 semantic_status 判定筛选空响应、拒绝响应、截断响应只有入口日志没有出口日志流式连接中断或客户端取消连接补记 stream_end / client_close 事件检查连接状态TraceID 中断在异步调用处线程池、回调未透传父 TraceID统一包装线程提交逻辑在子线程里还原父上下文偶发故障难以复现请求上下文没有快照记录完整脱敏 Prompt 和参数异常时保留原始输入输出模型返回内容被截断却显示成功max_tokens 设置不当或上下文超限检查 finish_reason 字段和 prompt_meta 的截断标记回调逻辑报错但找不到原始请求异步任务回调未关联 TraceID建立未完成跟踪表任务 ID 与 TraceID 双向绑定5.2 三个容易被忽略的避坑细节第一个坑是敏感信息脱敏。Prompt 里经常携带用户隐私信息打日志时一定要做脱敏和截断。我在项目里踩过一次因为排障要求完整现场把一段含用户手机号的 Prompt 直接打进了日志合规同事第二天就找上门了。建议默认打印 Prompt 的前几十个字符完整的原始输入只在异常样本库里留存并且做访问控制。第二个坑是日志别全部塞进同一个索引。全量记录每一次 Token 消耗会产生海量数据检索性能会越来越差。建议把成本统计、性能统计、排障日志分开存储排障索引只保留语义状态异常和慢调用相关记录普通正常调用只保留可以按 TraceID 定位的索引条目不必存全量文本。第三个坑是采样策略。线上高峰期调用量巨大不可能每一条都保留完整输入输出否则磁盘再大也不够用。坚持“全量记录元数据、按需保留样本”的原则所有调用都记录 trace_id、耗时、token 数、语义状态这些轻量字段只有异常和慢调用才保留完整 Prompt 和返回体。这个策略既能控制成本又不会在关键时刻漏掉现场。最后分享一点个人体会我实践下来最大的感悟是AI 调用排障难不是因为没日志而是因为日志在设计时沿用了传统接口的哲学。传统接口出错时异常栈就是答案AI 调用出错时答案藏在上下文、参数、截断策略和语义状态里。所以真正的解法不是买更贵的日志平台而是把日志体系围绕上下文、语义判定和链路透传重新设计一遍。还有一个小技巧把模型调用当成行为多变的外部依赖来对待不要默认“模型返回成功就是一次成功调用”。只要输出内容对用户没有价值它就是故障就必须留下可排查的现场。抱着这个心态去审视自己的日志系统你会发现值得补的东西比想象中多得多。
