:用结构化日志与全链路追踪搭建可复制排查骨架)
1. 为什么 RAG 上线后“答错”比“报错”更难查RAG 系统上线后最让人头疼的不是服务挂了而是它安安静静地给出一个错误答案。普通 API 出错会抛 500、延迟飙升、内存溢出这些都有明确的信号。但 RAG 的失败方式非常隐蔽——它不报错、不崩溃只是“答得不够好”。用户问“上季度的利润增长”它答了一个增长率知识库里明明有那份文档它却说“找不到相关信息”上下文里白纸黑字写着“增长 15%”模型却编了一个“增长 12%”。这些问题的根源分散在整条流水线上查询改写可能把语义改偏了向量检索可能没召回到相关文档重排序可能把最相关的 chunk 从第 3 名挤到了第 15 名上下文组装可能因为 token 截断丢掉了关键段落LLM 生成阶段可能“选择性失明”无视了正确信息。六个环节每一个都可能独立出错也可能组合出错。没有全链路追踪你只能看到“最终回答不好”中间发生了什么完全是盲区。更麻烦的是RAG 的问题往往是渐进式退化而非突发式崩溃。文档库从 1000 篇涨到 10000 篇检索精度慢慢下降新入库的文档质量参差不齐拉低了整体效果模型 API 版本更新后行为悄悄漂移。这些都不是“今天突然坏了”而是“不知不觉变差了”。没有基线对比和趋势监控你甚至意识不到问题在发生。这篇文章要解决的就是给 RAG 系统装上一套可复制的排查骨架结构化日志记录每个环节的详细数据全链路追踪串起从用户输入到最终输出的完整路径监控指标实时盯住延迟、成本和质量的变化。三者配合任何一个 bad case 都能在十分钟内定位到具体环节。2. 前置准备用 TaoToken 统一接入模型与观测链路在搭建可观测性之前需要先确保模型调用层是稳定且可追踪的。我试过在多个模型供应商之间来回切换做对比测试每次都要改 base_url、换 API Key、重新适配返回格式调试成本很高。后来统一走 TaoToken 的 API 网关模型对话、coding plan、console 管理都在一个入口排查问题时不用再怀疑“是不是某个供应商的接口又变了”。TaoToken 的接入方式兼容 OpenAI 风格的接口对于 RAG 管道里的 LLM 生成环节只需要把 base_url 指向https://taotoken.net/apiAPI Key 在 console 里生成即可。这样做的另一个好处是所有模型调用的延迟、token 消耗、返回状态都经过同一个网关结构化日志里记录的 llm_latency_ms 和 token_usage 字段来源一致不会因为供应商不同导致统计口径混乱。如果你还在选模型阶段可以先用模型对话功能快速对比不同模型在相同上下文下的生成质量确认哪个模型在你的 RAG 场景下“听话”程度最高。对于需要长期跑编码任务或 Agent 流程的团队Coding Plan 提供了更稳定的配额和调用策略避免因为限流导致 trace 数据断档。接入文档里有完整的参数说明和示例代码API Keys 管理页面可以按环境开发/测试/生产生成不同的 Key方便在日志里区分请求来源。这些准备工作做完后面的追踪埋点和日志规范才有统一的落点。3. 可复制配置结构化日志字段规范与追踪埋点3.1 全链路六个节点的记录标准全链路追踪的核心思想很简单给每个请求分配一个唯一的trace_id从用户输入到最终输出经过的每一个环节都记录在这个 trace 上。出了问题拿着trace_id一查全链路每一步的状态一目了然。RAG 管道需要记录的六个节点① 用户输入raw_query→ ② 查询改写结果rewritten_query→ ③ 检索结果retrieved_chunks→ ④ 重排序结果reranked_chunks→ ⑤ 最终上下文final_context→ ⑥ LLM 输出completion为什么检索和重排序要分开记这是归因的关键分界。正确的 chunk 在检索结果里、但被重排序挤出了 top-k问题在 rerank检索结果里根本没有问题在召回。两个阶段各记 chunk_id 列表和分数一比就知道错在哪一跳。为什么记“最终上下文”而不是只记检索结果检索到不等于进了 prompt。截断策略、去重、token 预算都可能把正确答案在组装阶段丢掉。第⑤环节记录的是模型真实看到的东西这是审 case 时的 ground truth。每个节点必须记录输入是什么、输出是什么、耗时多少、是否成功。3.2 Trace 数据结构的代码实现import uuid import time from dataclasses import dataclass, field dataclass class RAGTrace: trace_id: str field(default_factorylambda: str(uuid.uuid4())) timestamp: float field(default_factorytime.time) # 六个节点的完整记录 raw_query: str rewritten_query: str retrieved_chunks: list field(default_factorylist) # [{text, score, doc_id, chunk_id}] reranked_chunks: list field(default_factorylist) final_context: str completion: str # 每步耗时毫秒 rewrite_latency_ms: float 0 retrieval_latency_ms: float 0 rerank_latency_ms: float 0 llm_latency_ms: float 0 total_latency_ms: float 0 # 成本 input_tokens: int 0 output_tokens: int 0 estimated_cost: float 0.0 # 用户反馈 user_feedback: str None # up / down / None def to_dict(self) - dict: return { trace_id: self.trace_id, timestamp: self.timestamp, raw_query: self.raw_query, rewritten_query: self.rewritten_query, retrieved_chunks: [ {doc_id: c[doc_id], score: c[score], text_preview: c[text][:100]} for c in self.retrieved_chunks ], reranked_chunks: [ {doc_id: c[doc_id], score: c[score]} for c in self.reranked_chunks ], final_context_tokens: len(self.final_context) // 4, completion: self.completion[:200], latency: { rewrite: self.rewrite_latency_ms, retrieval: self.retrieval_latency_ms, rerank: self.rerank_latency_ms, llm: self.llm_latency_ms, total: self.total_latency_ms, }, tokens: {input: self.input_tokens, output: self.output_tokens}, cost: self.estimated_cost, user_feedback: self.user_feedback, }关键设计点retrieved_chunks和reranked_chunks都要记录完整的 score 和 doc_id。排查问题时你首先看的就是“相关文档有没有被召回”和“召回后排序对不对”——如果只存了最终 Prompt这些中间信息就丢了。3.3 在 RAG 管道中埋点def rag_pipeline(query: str) - str: trace RAGTrace(raw_queryquery) # Step 1: 查询改写 t0 time.time() trace.rewritten_query rewrite_query(query) trace.rewrite_latency_ms (time.time() - t0) * 1000 # Step 2: 检索 t0 time.time() trace.retrieved_chunks vector_search(trace.rewritten_query, top_k20) trace.retrieval_latency_ms (time.time() - t0) * 1000 # Step 3: 重排序 t0 time.time() trace.reranked_chunks rerank(trace.retrieved_chunks, query, top_k5) trace.rerank_latency_ms (time.time() - t0) * 1000 # Step 4: 组装上下文 trace.final_context build_prompt(query, trace.reranked_chunks) # Step 5: LLM 生成 t0 time.time() response llm.invoke(trace.final_context) trace.llm_latency_ms (time.time() - t0) * 1000 trace.completion response.text trace.input_tokens response.usage.input_tokens trace.output_tokens response.usage.output_tokens # 记录完整 Trace log_trace(trace.to_dict()) return response.text3.4 结构化日志的写入与分级日志必须结构化JSON不能是纯文本——因为你要按字段查询、聚合、统计。import json import logging logger logging.getLogger(rag) def log_trace(trace_data: dict): # 写入结构化日志支持后续 ELK / Loki 检索 logger.info(json.dumps(trace_data, ensure_asciiFalse)) # 同时写入 trace 存储如 ClickHouse / Postgres trace_store.insert(trace_data)查询示例找出所有用户点踩的请求。SELECT trace_id, raw_query, completion, user_feedback FROM rag_traces WHERE user_feedback down ORDER BY timestamp DESC LIMIT 50;日志存储有个坑retrieved_chunks和prompt字段可能很大每个 chunk 几百字20 个 chunk 加 Prompt 轻松超过 10KB。如果用 Elasticsearch 存全量成本会很高。建议 chunk 内容只存前 100 字 preview完整内容存对象存储日志里只存 URL 指针。日志分级策略级别记录频率记录内容存储位置全量 Trace每个请求九字段完整记录ClickHouse / Postgres保留 30 天异常 Trace出错时全量 堆栈 环境信息Elasticsearch / Loki长期保留采样 Trace1% 正常请求全量含完整 Prompt 和 Completion对象存储用于离线分析聚合指标每分钟QPS、平均延迟、成功率Prometheus / Grafana4. 验证请求用 trace_id 还原一次答错的全过程配置完成后需要验证整条链路是否真的能定位问题。构造一个典型的“答错”场景知识库里有文档明确写着“2024 年 Q3 利润增长 15%”但系统回答“利润增长 12%”。第一步从用户反馈入口拿到trace_id拉出完整 trace 数据。trace trace_store.get(trace_idabc-123-def) # 检查检索阶段相关文档有没有被召回 for chunk in trace[retrieved_chunks]: if 利润 in chunk[text_preview]: print(f召回: doc_id{chunk[doc_id]}, score{chunk[score]}) # 检查重排序阶段排序有没有变化 for i, chunk in enumerate(trace[retrieved_chunks][:10]): rerank_pos next( (j for j, rc in enumerate(trace[reranked_chunks]) if rc[doc_id] chunk[doc_id]), None ) if rerank_pos is not None and rerank_pos i: print(fdoc {chunk[doc_id]} 从第{i1}名被排到第{rerank_pos1}名) # 检查最终上下文正确信息在不在里面 correct_info 增长15% position trace[final_context].find(correct_info) total_len len(trace[final_context]) if position -1: print(正确信息不在最终上下文中 → 检索/截断问题) elif position total_len * 0.3: print(在开头模型应该能注意到) elif position total_len * 0.7: print(在末尾可能被忽略) else: print(在中间Lost in the Middle 风险)假设验证结果是检索阶段召回了正确文档score 0.82重排序后仍然在前 3 名最终上下文里也包含了“增长 15%”且位置在开头。但 completion 输出的是“增长 12%”。这说明问题出在生成阶段——模型无视了上下文中的正确信息。进一步检查 System Prompt 是否明确要求“基于上下文回答”以及 Temperature 是否过高。如果 Prompt 里写的是“请根据以下信息回答”但模型仍然编造可能需要换成指令遵循能力更强的模型或者在 Prompt 里加硬约束“如果上下文中没有明确答案请回答‘根据现有信息无法确定’”。这个验证流程走通一次后面所有 bad case 都可以按同样的路径排查。5. 本篇常见错排查5.1 trace_id 没有贯穿全链路最常见的问题是trace_id只在入口生成但调用检索服务、重排序服务、LLM 网关时没有透传。结果就是日志里每个环节各记各的无法关联。解决方式是在所有跨服务调用的 header 或参数里带上trace_id确保每个环节的日志都包含这个字段。5.2 检索结果只存了 text没存 score 和 doc_id排查“排序对不对”时必须对比 rerank 前后的 doc_id 顺序和分数变化。如果只存了 text 片段没有 doc_id根本无法判断同一个 chunk 在重排序前后的位置变化。score 也要存因为分数分布能反映 Embedding 的区分度。5.3 日志量爆炸导致存储成本失控全量记录每个请求的完整 Prompt 和 Completion一天下来可能几十 GB。解决方案是分级存储全量 trace 只保留 30 天chunk 内容只存 preview完整内容放对象存储。同时设置采样策略正常请求按 1-5% 采样但用户点踩、拒答、低置信度的请求 100% 留全量 trace。5.4 监控指标只看平均值不看分位数延迟必须看 P50 / P95 / P99。RAG 系统的延迟长尾很重——90% 的请求 2 秒返回10% 因为检索了更多文档或触发了重试要 15 秒。平均值看起来 3.5 秒还行但那 10% 的用户体验已经崩了。分段延迟监控能直接定位瓶颈在哪个环节。latency_breakdown { rewrite: {p50: 480, p99: 1200}, retrieval: {p50: 85, p99: 320}, rerank: {p50: 210, p99: 580}, llm_first_token: {p50: 850, p99: 3200}, llm_total: {p50: 1800, p99: 6500}, end_to_end: {p50: 2625, p99: 8600}, }从上面可以看出瓶颈在 LLM 生成阶段尤其是 P99。重排 P99 580ms 也有优化空间可以考虑换更快的 Reranker。5.5 拒答率突升被误判为“系统变诚实了”如果拒答率突然从 8% 涨到 25%通常不是系统变诚实了而是检索出了问题——文档没召回导致系统频繁说“找不到相关信息”。先查检索层再查 Prompt 层。检索命中率RecallK需要一个标注数据集作为基线人工标注 100-500 个 Query 对应的正确文档定期跑一遍看正确文档是否出现在 Top-K 内。6. 从排查到进化让每次答错都变成系统资产可观测性的价值不只是“定位这一次为什么答错”而是让每一次答错都转化为系统改进的输入。用户点踩的请求自动关联 trace 落入 bad case 池定期人工归因后沉淀为回归评测集。这样线上问题会持续转化为测试资产每次调整分块策略、换 embedding 模型、改 prompt 时跑一遍防止“修好一个坏三个”。工具链方面追踪层可以用 OpenTelemetry 的 span 模型或者 LangSmith / Langfuse / Phoenix 这类 LLM 观测平台不必自研全部。日志层用 ELK 或 Grafana Loki 存储结构化日志支持按trace_id、user_feedback、latency等字段检索和聚合。指标层用 Prometheus Grafana 实时监控延迟分布、Token 成本、检索命中率设置告警阈值。评估层用 Ragas / TruLens 定期在标注数据集上跑 Faithfulness、Answer Relevancy、Context Precision 等指标。上线检查清单可以对照这几条每个请求都有唯一trace_id贯穿全链路六个节点的输入输出都被记录检索结果保存完整 score 和 doc_id延迟按环节分段记录至少有 P50 和 P99Token 用量和成本每次请求都记录有用户反馈通道且反馈绑定到 trace有标注数据集做定期基线评估关键指标有告警阈值日志有保留策略点踩的 case 自动进入待分析队列。回到最核心的一点RAG 可观测性的核心不是“装一堆监控工具”而是建立一条从用户反馈到问题根因的完整链路。用户说“答错了”拿trace_id拉全链路数据看是检索没召回、排序不对、上下文截断、还是模型幻觉针对性修复。没有这条链路你永远在猜问题出在哪有了这条链路十分钟定位根因。如果你还在搭建模型调用层可以先用 TaoToken 的模型对话快速对比不同模型在相同上下文下的生成质量确认哪个模型在你的 RAG 场景下“听话”程度最高。接入文档里有完整的参数说明和示例代码API Keys 管理页面可以按环境生成不同的 Key方便在日志里区分请求来源。对于需要长期跑编码任务或 Agent 流程的团队Coding Plan 提供了更稳定的配额和调用策略避免因为限流导致 trace 数据断档。