1. 大模型推理可观测性到底在解决什么问题大模型应用上线之后最让人头疼的往往不是模型本身答得好不好而是“它到底花了多少钱、慢在哪里、什么时候会崩”。我见过不少团队模型部署起来了接口也能通但一问到“昨天那批请求平均消耗了多少 Token”“哪个环节延迟最高”“为什么这个用户的响应突然变慢了三倍”大家就开始翻日志、猜原因。这就是典型的可观测性缺失。所谓大模型日志与可观测性说白了就是给每一次推理过程装上“行车记录仪”。每一次请求进来从排队、预处理、Token 化、模型前向计算、采样、后处理到返回整条链路上发生了什么、花了多少时间、消耗了多少 Token、有没有异常全部记录下来并且能被查询、聚合、告警。它解决的核心问题是三个成本归因、性能定位、异常追溯。适合谁来参考这篇内容如果你正在做 AI 应用后端、推理服务运维、模型 API 网关或者你是一个独立开发者自己部署了模型想搞清楚账单和延迟那这篇东西就是写给你的。我不打算讲空泛的理论而是从实际落地角度把怎么设计日志字段、怎么埋点、怎么算 Token、怎么分析延迟、怎么排查常见问题一层层拆开讲。2. 整体设计思路与方案选型拆解2.1 为什么不能只用普通应用日志普通 Web 服务的日志通常记录请求路径、状态码、耗时这对 CRUD 应用够用但放到大模型推理场景就完全不够。原因在于大模型的“消耗”和“延迟”有很强的特殊性。第一Token 消耗不是简单的一次性计数。一次对话请求可能包含系统提示词、历史对话、当前用户输入输出又分生成内容和结束标记。输入 Token 和输出 Token 的计费单价往往不同有的模型还区分缓存命中 Token 和未命中 Token。如果你只记一个“总 Token”后面做成本分析时根本拆不开。第二延迟的构成非常复杂。用户感知的端到端延迟至少包含网络传输、网关排队、Token 化、首 Token 生成时间TTFT、每 Token 生成间隔TPOT、后处理与流式返回。其中首 Token 延迟和后续生成延迟对体验的影响完全不同。一个模型如果首 Token 要等 3 秒用户会觉得“卡”如果首 Token 很快但后面每个字都慢用户会觉得“吐字慢”。这两种问题的优化方向截然不同。第三大模型推理有很强的资源竞争特征。同一张 GPU 上并发多个请求时显存占用、批处理大小、KV Cache 都会互相影响。没有细粒度日志你根本无法判断延迟抖动是模型本身的问题还是被其他请求挤占了资源。所以我的设计原则是日志字段要能支撑成本核算、性能分析和容量规划三类查询。不是记越多越好而是每个字段都要有明确的消费场景。2.2 可观测性三大支柱在推理场景的落地业界常说的可观测性三大支柱是日志Logging、指标Metrics、追踪Tracing。放到大模型推理场景我的落地方式是这样的。日志负责记录单次请求的详细上下文比如请求 ID、模型名称、输入输出 Token 数、各阶段耗时、采样参数、是否命中缓存、错误信息。它是最细粒度的原始数据用于事后排查和审计。指标负责聚合统计比如每分钟请求数、P95 首 Token 延迟、平均每请求 Token 消耗、GPU 显存使用率、队列等待长度。指标用于监控大盘和告警特点是开销小、可长期存储。追踪负责串联一次请求经过的多个服务节点。比如请求先到网关再到预处理服务再到推理引擎最后到后处理服务每个节点都打一个 Span最终形成完整调用链。这样当延迟变高时你能一眼看出是哪个环节拖慢了整体。三者不是替代关系而是互补。我的经验是日志字段设计得好指标和追踪都能从日志里派生出来。所以第一步一定是把日志的字段结构定清楚。2.3 字段设计的核心考量设计日志字段时我习惯先问三个问题这个字段用来回答什么问题它的取值基数大不大它会不会包含敏感信息举几个关键字段说明。request_id是贯穿全链路的唯一标识基数极高但必须记录否则无法串联。model_name基数中等用于按模型聚合成本。input_tokens和output_tokens是数值型直接用于计费。ttft_ms和tpot_ms是性能核心指标。status用于区分成功、超时、限流、模型错误。需要特别注意的是不要把完整的用户输入和模型输出明文写进日志。一方面体积巨大另一方面涉及隐私合规。我的做法是只记录 Token 数量和内容的哈希值需要排查时再通过采样或脱敏回放来定位。还有一个容易忽略的点是时间戳的精度和时区。推理延迟经常在毫秒级时间戳必须用毫秒甚至微秒精度并且统一用 UTC 存储展示时再转本地时区。我踩过一次坑日志用了本地时间但没标时区跨机房分析时差了 8 小时排查了半天才发现是时区问题。3. 核心细节解析与实操要点3.1 Token 消耗到底怎么算才准确Token 计数是可观测性的基础但很多人算不准。原因主要有三个不同模型的 Tokenizer 不一样、流式返回时结束标记容易漏算、多轮对话的历史 Token 重复计算。先说 Tokenizer 差异。同一个中文句子在不同模型家族里切出来的 Token 数可能差 20% 到 40%。所以你不能用一个通用的字符数除以某个系数来估算必须用对应模型自己的 Tokenizer。如果推理引擎本身提供了 usage 字段优先用引擎返回的因为那是最权威的。如果引擎不返回就要在网关层用对应的 Tokenizer 库自己算。再说流式返回。流式场景下模型是一个 Token 一个 Token 吐出来的。如果你只在请求结束时统计很容易漏掉最后一个结束标记。我的做法是在流式回调里累加计数每收到一个 Token 就加一请求结束时再和引擎返回的 usage 做一次对账不一致就告警。多轮对话的历史 Token 是成本大头。很多应用会把完整历史拼进 prompt导致输入 Token 随轮次线性增长。日志里必须区分“本次新增输入 Token”和“历史上下文 Token”否则你根本不知道成本是被谁推高的。我通常会在日志里加一个context_tokens字段专门记录历史部分。下面是一个 Token 统计的伪代码示例展示在流式回调中如何累加class TokenCounter: def __init__(self): self.input_tokens 0 self.output_tokens 0 self.context_tokens 0 def count_input(self, prompt, tokenizer): self.input_tokens len(tokenizer.encode(prompt)) def count_context(self, history, tokenizer): self.context_tokens sum( len(tokenizer.encode(msg)) for msg in history ) def on_token(self, token): self.output_tokens 1 def finalize(self, engine_usageNone): if engine_usage: if engine_usage.output_tokens ! self.output_tokens: log_warning(token_mismatch, localself.output_tokens, engineengine_usage.output_tokens) return { input_tokens: self.input_tokens, output_tokens: self.output_tokens, context_tokens: self.context_tokens, total_tokens: self.input_tokens self.output_tokens }注意Token 对账不要只在出错时做建议按 1% 采样率常态化对账这样能及早发现 Tokenizer 版本不一致的问题。3.2 延迟拆解首 Token 与每 Token 间隔延迟分析是另一个核心。我习惯把一次推理的延迟拆成以下几段每段单独打点。阶段含义典型优化方向排队延迟请求进入队列到开始处理扩容、限流、优先级调度预处理延迟Token 化、模板拼接缓存 Tokenizer、减少拼接首 Token 延迟开始计算到第一个 Token 输出优化 KV Cache、减少 prompt 长度生成延迟后续每个 Token 的平均间隔批处理调优、量化、投机采样后处理延迟输出过滤、格式化、返回异步处理、减少同步阻塞首 Token 延迟TTFT和每 Token 间隔TPOT是两个最关键的体验指标。TTFT 决定了用户“等多久才看到第一个字”TPOT 决定了“吐字速度”。我实测下来TTFT 超过 2 秒用户就会明显感到卡顿TPOT 超过 100 毫秒用户会觉得慢。计算 TPOT 的公式是TPOT (总生成时间 - TTFT) / (输出 Token 数 - 1)。注意分母减一因为第一个 Token 的时间已经算在 TTFT 里了。这个细节很多人会算错导致 TPOT 偏大。还有一个容易被忽略的指标是“延迟抖动”。平均值好看不代表体验好如果 P99 延迟是平均值的五倍说明系统存在长尾问题。所以日志里要保留原始延迟数据指标层要计算 P50、P95、P99 分位数。3.3 埋点位置的选择与开销控制埋点位置决定了数据的准确性。我的原则是在离真实计算最近的地方打点在离业务最近的地方聚合。具体来说TTFT 的打点应该在推理引擎输出第一个 Token 的回调里而不是在网关收到第一个字节时。因为网关到引擎之间还有网络和序列化开销如果打点在网关你测到的是“用户感知延迟”但排查时无法区分是引擎慢还是网络慢。两个都打对比着看才能定位问题。埋点开销必须控制。我见过有人在每个 Token 回调里都写一次日志结果日志量爆炸反而拖慢了推理。正确做法是Token 级别的数据在内存里累加只在请求结束时写一条完整日志。如果确实需要 Token 级追踪用采样比如每 100 个请求采一个。另外日志写入要用异步方式不能阻塞推理主流程。我通常用内存队列加后台线程批量刷盘队列满了就丢弃低优先级日志并告警保证推理服务本身不受影响。4. 实操过程与核心环节实现4.1 从零搭建一套推理日志管道假设你现在有一个基于常见推理引擎的部署想加上完整的可观测性。我按实际搭建顺序讲一遍。第一步定义日志 Schema。这是最重要的一步Schema 定错了后面全要返工。我建议用 JSON 格式字段扁平化避免嵌套过深。核心字段包括timestamp、request_id、trace_id、model_name、input_tokens、output_tokens、context_tokens、ttft_ms、tpot_ms、total_latency_ms、queue_ms、status、error_code、sampling_params、cache_hit。第二步在推理服务里埋点。以常见的 Python 推理服务为例在请求入口生成request_id在预处理阶段记录输入 Token在引擎回调里记录 TTFT 和 Token 累加在请求结束时组装完整日志并投递到异步队列。第三步搭建日志收集。轻量方案是服务直接写本地文件用采集代理转发到集中存储。重一点的方案是直接写消息队列下游消费者写入时序数据库或日志检索系统。我倾向后者因为解耦了写入和存储推理服务不关心下游。第四步建立指标聚合。从日志流里实时计算每分钟的请求数、Token 总量、延迟分位数、错误率。这些指标推到监控系统做大盘和告警。第五步配置告警规则。比如 P95 TTFT 超过 3 秒告警、错误率超过 1% 告警、单请求 Token 超过阈值告警、Token 对账不一致告警。4.2 关键配置参数与计算过程延迟阈值怎么定不能拍脑袋。我的方法是先跑一周基线收集正常情况下的 P50、P95、P99然后按 P99 的 1.5 倍设告警线。比如基线 P99 TTFT 是 1.8 秒告警线设 2.7 秒。Token 预算怎么算假设你的模型输入单价是每百万 Token 若干元输出单价是输入的几倍。你要先估算日均请求量和平均 Token 消耗算出日成本再设一个日预算告警。我通常会给每个应用或每个用户设配额日志里带上app_id和user_id这样能按维度归因。采样率怎么定全量记录日志的成本很高。我的经验是错误请求 100% 记录慢请求超过 P95100% 记录正常请求按 10% 到 20% 采样。这样既控制了存储成本又保证了问题排查时有足够样本。下面是一个延迟分位数计算的示例用滑动窗口实现import collections import time class LatencyWindow: def __init__(self, window_seconds60): self.window window_seconds self.samples collections.deque() def add(self, latency_ms): now time.time() self.samples.append((now, latency_ms)) self._evict(now) def _evict(self, now): while self.samples and now - self.samples[0][0] self.window: self.samples.popleft() def percentile(self, p): if not self.samples: return None values sorted(v for _, v in self.samples) idx int(len(values) * p / 100) idx min(idx, len(values) - 1) return values[idx]提示滑动窗口的大小要和告警灵敏度匹配。窗口太小指标抖动大容易误报窗口太大问题发现不及时。我一般用 1 分钟窗口做告警5 分钟窗口做趋势。4.3 一次完整的排查现场记录说一个我实际遇到的案例。某天下午监控告警显示 P95 TTFT 从 1.2 秒涨到了 3.5 秒但错误率正常吞吐量也没变。我先看指标大盘发现所有模型的 TTFT 都涨了不只是某一个。这排除了单个模型的问题。接着看 GPU 显存和利用率发现显存占用比平时高了 30%但利用率没变。这提示可能是 KV Cache 占用变多了。然后我按context_tokens字段聚合日志发现平均上下文长度从 800 涨到了 2200。进一步按app_id拆分发现是某个应用改了 prompt 模板把历史对话轮数从 3 轮加到了 10 轮。上下文变长导致 KV Cache 占用增加进而拖慢了首 Token 生成。定位到原因后解决方案有两个一是让那个应用限制历史轮数二是给推理引擎开启分页 KV Cache 或前缀缓存。我们两个都做了TTFT 回落到 1.3 秒。这个案例说明可观测性字段的设计直接决定了排查效率。如果当初没记context_tokens和app_id我可能要在几百个应用里逐个排查耗时会长得多。5. 常见问题与排查技巧实录5.1 Token 计数不一致的排查思路Token 计数不一致是最常见的问题。表现是网关统计的 Token 数和引擎返回的 usage 对不上。排查顺序我一般是这样先确认 Tokenizer 版本。网关用的 Tokenizer 库版本和引擎内置的版本可能不同尤其是模型更新后。检查两边的版本号不一致就统一。再确认特殊 Token 的处理。有些模型会在输入前后自动加 BOS、EOS 或系统标记这些是否计入 Token 数两边定义可能不同。看引擎文档确认。然后确认流式结束标记。流式返回时最后一个结束 Token 是否被计数。有的引擎在 usage 里包含有的不包含。最后确认并发场景。高并发下如果计数变量是共享的可能出现串号。确保每个请求有独立的计数器实例。现象可能原因排查方法网关比引擎多重复计算了特殊标记对比 Tokenizer 输出网关比引擎少漏算结束标记检查流式回调随机不一致并发计数串号检查计数器作用域整体偏移固定值版本差异统一 Tokenizer 版本5.2 延迟抖动大但平均值正常的处理延迟抖动大说明系统存在长尾。平均值正常只是掩盖了问题。我的排查思路是先看抖动是否与并发量相关。如果并发高时抖动大说明资源竞争是主因要考虑限流或扩容。再看抖动是否与特定模型相关。如果只有某个模型抖动可能是该模型的批处理策略或显存管理有问题。还要看抖动是否与时间段相关。如果每天固定时间抖动可能是定时任务或备份在抢资源。我遇到过一次抖动问题最后发现是日志写入本身导致的。当时日志是同步写磁盘磁盘 IO 偶尔打满阻塞了推理线程。改成异步批量写入后抖动消失了。这个坑很隐蔽因为日志系统本身成了性能瓶颈。5.3 缓存命中率低导致的成本异常很多推理服务会做 prompt 缓存或 KV Cache 复用命中时能大幅降低成本。但如果日志里不记录cache_hit你根本不知道缓存有没有生效。我建议在日志里记录缓存命中的 Token 数并单独计算“缓存节省成本”。如果发现命中率突然下降排查方向包括缓存键是否包含了随机因素、缓存过期时间是否太短、请求的 prompt 前缀是否变化太频繁。有一次我们发现缓存命中率从 60% 掉到 10%最后查出来是某个应用在 prompt 开头加了当前时间戳导致每次请求前缀都不同缓存完全失效。加上cache_hit字段后这类问题几分钟就能定位。5.4 高频踩坑速查表问题根因解决日志量爆炸每 Token 写一条内存累加请求结束写一条时间戳错乱时区不统一统一 UTC 存储隐私泄露明文记录输入输出只记哈希和 Token 数告警误报阈值拍脑袋基于基线 P99 设阈值排查无门缺 request_id全链路透传唯一 ID成本失控无 Token 预算按应用设配额告警注意日志 Schema 一旦上线修改成本很高。建议先在测试环境跑两周确认字段够用再上生产。6. 从可观测性到成本优化的闭环可观测性本身不产生价值基于数据做优化才产生价值。我习惯把日志数据用成一个闭环观测、分析、优化、验证。观测阶段日志和指标告诉你现状。分析阶段你按模型、应用、用户维度拆解成本和延迟找出异常点。优化阶段针对异常点采取措施比如限制上下文长度、开启缓存、调整批处理参数。验证阶段再看指标是否改善形成闭环。举个实际例子。我们通过日志发现某个免费额度应用的 Token 消耗占了总量的 40%但请求数只占 5%。分析后发现该应用每次请求都带超长系统提示词。优化措施是给免费额度应用设更严格的上下文上限并在网关层做 prompt 压缩。一周后总 Token 消耗下降了 25%而用户体验没有明显变化。这个闭环能跑起来的前提就是日志字段足够细、指标聚合足够快、告警足够准。所以回到最开始那句话可观测性不是记流水账而是为决策提供依据。我个人在实际操作中的体会是先把 Token 和延迟这两个核心指标做扎实再逐步扩展其他维度。不要一上来就追求大而全字段太多反而没人看。从最痛的点入手让数据真正被用起来这套体系才有生命力。 
长河君 · 2026/10/4 23:42:55 · 阅读 1.2k 大模型推理可观测性实战：Token计费、延迟拆解与日志埋点设计
1. 大模型推理可观测性到底在解决什么问题大模型应用上线之后最让人头疼的往往不是模型本身答得好不好而是“它到底花了多少钱、慢在哪里、什么时候会崩”。我见过不少团队模型部署起来了接口也能通但一问到“昨天那批请求平均消耗了多少 Token”“哪个环节延迟最高”“为什么这个用户的响应突然变慢了三倍”大家就开始翻日志、猜原因。这就是典型的可观测性缺失。所谓大模型日志与可观测性说白了就是给每一次推理过程装上“行车记录仪”。每一次请求进来从排队、预处理、Token 化、模型前向计算、采样、后处理到返回整条链路上发生了什么、花了多少时间、消耗了多少 Token、有没有异常全部记录下来并且能被查询、聚合、告警。它解决的核心问题是三个成本归因、性能定位、异常追溯。适合谁来参考这篇内容如果你正在做 AI 应用后端、推理服务运维、模型 API 网关或者你是一个独立开发者自己部署了模型想搞清楚账单和延迟那这篇东西就是写给你的。我不打算讲空泛的理论而是从实际落地角度把怎么设计日志字段、怎么埋点、怎么算 Token、怎么分析延迟、怎么排查常见问题一层层拆开讲。2. 整体设计思路与方案选型拆解2.1 为什么不能只用普通应用日志普通 Web 服务的日志通常记录请求路径、状态码、耗时这对 CRUD 应用够用但放到大模型推理场景就完全不够。原因在于大模型的“消耗”和“延迟”有很强的特殊性。第一Token 消耗不是简单的一次性计数。一次对话请求可能包含系统提示词、历史对话、当前用户输入输出又分生成内容和结束标记。输入 Token 和输出 Token 的计费单价往往不同有的模型还区分缓存命中 Token 和未命中 Token。如果你只记一个“总 Token”后面做成本分析时根本拆不开。第二延迟的构成非常复杂。用户感知的端到端延迟至少包含网络传输、网关排队、Token 化、首 Token 生成时间TTFT、每 Token 生成间隔TPOT、后处理与流式返回。其中首 Token 延迟和后续生成延迟对体验的影响完全不同。一个模型如果首 Token 要等 3 秒用户会觉得“卡”如果首 Token 很快但后面每个字都慢用户会觉得“吐字慢”。这两种问题的优化方向截然不同。第三大模型推理有很强的资源竞争特征。同一张 GPU 上并发多个请求时显存占用、批处理大小、KV Cache 都会互相影响。没有细粒度日志你根本无法判断延迟抖动是模型本身的问题还是被其他请求挤占了资源。所以我的设计原则是日志字段要能支撑成本核算、性能分析和容量规划三类查询。不是记越多越好而是每个字段都要有明确的消费场景。2.2 可观测性三大支柱在推理场景的落地业界常说的可观测性三大支柱是日志Logging、指标Metrics、追踪Tracing。放到大模型推理场景我的落地方式是这样的。日志负责记录单次请求的详细上下文比如请求 ID、模型名称、输入输出 Token 数、各阶段耗时、采样参数、是否命中缓存、错误信息。它是最细粒度的原始数据用于事后排查和审计。指标负责聚合统计比如每分钟请求数、P95 首 Token 延迟、平均每请求 Token 消耗、GPU 显存使用率、队列等待长度。指标用于监控大盘和告警特点是开销小、可长期存储。追踪负责串联一次请求经过的多个服务节点。比如请求先到网关再到预处理服务再到推理引擎最后到后处理服务每个节点都打一个 Span最终形成完整调用链。这样当延迟变高时你能一眼看出是哪个环节拖慢了整体。三者不是替代关系而是互补。我的经验是日志字段设计得好指标和追踪都能从日志里派生出来。所以第一步一定是把日志的字段结构定清楚。2.3 字段设计的核心考量设计日志字段时我习惯先问三个问题这个字段用来回答什么问题它的取值基数大不大它会不会包含敏感信息举几个关键字段说明。request_id是贯穿全链路的唯一标识基数极高但必须记录否则无法串联。model_name基数中等用于按模型聚合成本。input_tokens和output_tokens是数值型直接用于计费。ttft_ms和tpot_ms是性能核心指标。status用于区分成功、超时、限流、模型错误。需要特别注意的是不要把完整的用户输入和模型输出明文写进日志。一方面体积巨大另一方面涉及隐私合规。我的做法是只记录 Token 数量和内容的哈希值需要排查时再通过采样或脱敏回放来定位。还有一个容易忽略的点是时间戳的精度和时区。推理延迟经常在毫秒级时间戳必须用毫秒甚至微秒精度并且统一用 UTC 存储展示时再转本地时区。我踩过一次坑日志用了本地时间但没标时区跨机房分析时差了 8 小时排查了半天才发现是时区问题。3. 核心细节解析与实操要点3.1 Token 消耗到底怎么算才准确Token 计数是可观测性的基础但很多人算不准。原因主要有三个不同模型的 Tokenizer 不一样、流式返回时结束标记容易漏算、多轮对话的历史 Token 重复计算。先说 Tokenizer 差异。同一个中文句子在不同模型家族里切出来的 Token 数可能差 20% 到 40%。所以你不能用一个通用的字符数除以某个系数来估算必须用对应模型自己的 Tokenizer。如果推理引擎本身提供了 usage 字段优先用引擎返回的因为那是最权威的。如果引擎不返回就要在网关层用对应的 Tokenizer 库自己算。再说流式返回。流式场景下模型是一个 Token 一个 Token 吐出来的。如果你只在请求结束时统计很容易漏掉最后一个结束标记。我的做法是在流式回调里累加计数每收到一个 Token 就加一请求结束时再和引擎返回的 usage 做一次对账不一致就告警。多轮对话的历史 Token 是成本大头。很多应用会把完整历史拼进 prompt导致输入 Token 随轮次线性增长。日志里必须区分“本次新增输入 Token”和“历史上下文 Token”否则你根本不知道成本是被谁推高的。我通常会在日志里加一个context_tokens字段专门记录历史部分。下面是一个 Token 统计的伪代码示例展示在流式回调中如何累加class TokenCounter: def __init__(self): self.input_tokens 0 self.output_tokens 0 self.context_tokens 0 def count_input(self, prompt, tokenizer): self.input_tokens len(tokenizer.encode(prompt)) def count_context(self, history, tokenizer): self.context_tokens sum( len(tokenizer.encode(msg)) for msg in history ) def on_token(self, token): self.output_tokens 1 def finalize(self, engine_usageNone): if engine_usage: if engine_usage.output_tokens ! self.output_tokens: log_warning(token_mismatch, localself.output_tokens, engineengine_usage.output_tokens) return { input_tokens: self.input_tokens, output_tokens: self.output_tokens, context_tokens: self.context_tokens, total_tokens: self.input_tokens self.output_tokens }注意Token 对账不要只在出错时做建议按 1% 采样率常态化对账这样能及早发现 Tokenizer 版本不一致的问题。3.2 延迟拆解首 Token 与每 Token 间隔延迟分析是另一个核心。我习惯把一次推理的延迟拆成以下几段每段单独打点。阶段含义典型优化方向排队延迟请求进入队列到开始处理扩容、限流、优先级调度预处理延迟Token 化、模板拼接缓存 Tokenizer、减少拼接首 Token 延迟开始计算到第一个 Token 输出优化 KV Cache、减少 prompt 长度生成延迟后续每个 Token 的平均间隔批处理调优、量化、投机采样后处理延迟输出过滤、格式化、返回异步处理、减少同步阻塞首 Token 延迟TTFT和每 Token 间隔TPOT是两个最关键的体验指标。TTFT 决定了用户“等多久才看到第一个字”TPOT 决定了“吐字速度”。我实测下来TTFT 超过 2 秒用户就会明显感到卡顿TPOT 超过 100 毫秒用户会觉得慢。计算 TPOT 的公式是TPOT (总生成时间 - TTFT) / (输出 Token 数 - 1)。注意分母减一因为第一个 Token 的时间已经算在 TTFT 里了。这个细节很多人会算错导致 TPOT 偏大。还有一个容易被忽略的指标是“延迟抖动”。平均值好看不代表体验好如果 P99 延迟是平均值的五倍说明系统存在长尾问题。所以日志里要保留原始延迟数据指标层要计算 P50、P95、P99 分位数。3.3 埋点位置的选择与开销控制埋点位置决定了数据的准确性。我的原则是在离真实计算最近的地方打点在离业务最近的地方聚合。具体来说TTFT 的打点应该在推理引擎输出第一个 Token 的回调里而不是在网关收到第一个字节时。因为网关到引擎之间还有网络和序列化开销如果打点在网关你测到的是“用户感知延迟”但排查时无法区分是引擎慢还是网络慢。两个都打对比着看才能定位问题。埋点开销必须控制。我见过有人在每个 Token 回调里都写一次日志结果日志量爆炸反而拖慢了推理。正确做法是Token 级别的数据在内存里累加只在请求结束时写一条完整日志。如果确实需要 Token 级追踪用采样比如每 100 个请求采一个。另外日志写入要用异步方式不能阻塞推理主流程。我通常用内存队列加后台线程批量刷盘队列满了就丢弃低优先级日志并告警保证推理服务本身不受影响。4. 实操过程与核心环节实现4.1 从零搭建一套推理日志管道假设你现在有一个基于常见推理引擎的部署想加上完整的可观测性。我按实际搭建顺序讲一遍。第一步定义日志 Schema。这是最重要的一步Schema 定错了后面全要返工。我建议用 JSON 格式字段扁平化避免嵌套过深。核心字段包括timestamp、request_id、trace_id、model_name、input_tokens、output_tokens、context_tokens、ttft_ms、tpot_ms、total_latency_ms、queue_ms、status、error_code、sampling_params、cache_hit。第二步在推理服务里埋点。以常见的 Python 推理服务为例在请求入口生成request_id在预处理阶段记录输入 Token在引擎回调里记录 TTFT 和 Token 累加在请求结束时组装完整日志并投递到异步队列。第三步搭建日志收集。轻量方案是服务直接写本地文件用采集代理转发到集中存储。重一点的方案是直接写消息队列下游消费者写入时序数据库或日志检索系统。我倾向后者因为解耦了写入和存储推理服务不关心下游。第四步建立指标聚合。从日志流里实时计算每分钟的请求数、Token 总量、延迟分位数、错误率。这些指标推到监控系统做大盘和告警。第五步配置告警规则。比如 P95 TTFT 超过 3 秒告警、错误率超过 1% 告警、单请求 Token 超过阈值告警、Token 对账不一致告警。4.2 关键配置参数与计算过程延迟阈值怎么定不能拍脑袋。我的方法是先跑一周基线收集正常情况下的 P50、P95、P99然后按 P99 的 1.5 倍设告警线。比如基线 P99 TTFT 是 1.8 秒告警线设 2.7 秒。Token 预算怎么算假设你的模型输入单价是每百万 Token 若干元输出单价是输入的几倍。你要先估算日均请求量和平均 Token 消耗算出日成本再设一个日预算告警。我通常会给每个应用或每个用户设配额日志里带上app_id和user_id这样能按维度归因。采样率怎么定全量记录日志的成本很高。我的经验是错误请求 100% 记录慢请求超过 P95100% 记录正常请求按 10% 到 20% 采样。这样既控制了存储成本又保证了问题排查时有足够样本。下面是一个延迟分位数计算的示例用滑动窗口实现import collections import time class LatencyWindow: def __init__(self, window_seconds60): self.window window_seconds self.samples collections.deque() def add(self, latency_ms): now time.time() self.samples.append((now, latency_ms)) self._evict(now) def _evict(self, now): while self.samples and now - self.samples[0][0] self.window: self.samples.popleft() def percentile(self, p): if not self.samples: return None values sorted(v for _, v in self.samples) idx int(len(values) * p / 100) idx min(idx, len(values) - 1) return values[idx]提示滑动窗口的大小要和告警灵敏度匹配。窗口太小指标抖动大容易误报窗口太大问题发现不及时。我一般用 1 分钟窗口做告警5 分钟窗口做趋势。4.3 一次完整的排查现场记录说一个我实际遇到的案例。某天下午监控告警显示 P95 TTFT 从 1.2 秒涨到了 3.5 秒但错误率正常吞吐量也没变。我先看指标大盘发现所有模型的 TTFT 都涨了不只是某一个。这排除了单个模型的问题。接着看 GPU 显存和利用率发现显存占用比平时高了 30%但利用率没变。这提示可能是 KV Cache 占用变多了。然后我按context_tokens字段聚合日志发现平均上下文长度从 800 涨到了 2200。进一步按app_id拆分发现是某个应用改了 prompt 模板把历史对话轮数从 3 轮加到了 10 轮。上下文变长导致 KV Cache 占用增加进而拖慢了首 Token 生成。定位到原因后解决方案有两个一是让那个应用限制历史轮数二是给推理引擎开启分页 KV Cache 或前缀缓存。我们两个都做了TTFT 回落到 1.3 秒。这个案例说明可观测性字段的设计直接决定了排查效率。如果当初没记context_tokens和app_id我可能要在几百个应用里逐个排查耗时会长得多。5. 常见问题与排查技巧实录5.1 Token 计数不一致的排查思路Token 计数不一致是最常见的问题。表现是网关统计的 Token 数和引擎返回的 usage 对不上。排查顺序我一般是这样先确认 Tokenizer 版本。网关用的 Tokenizer 库版本和引擎内置的版本可能不同尤其是模型更新后。检查两边的版本号不一致就统一。再确认特殊 Token 的处理。有些模型会在输入前后自动加 BOS、EOS 或系统标记这些是否计入 Token 数两边定义可能不同。看引擎文档确认。然后确认流式结束标记。流式返回时最后一个结束 Token 是否被计数。有的引擎在 usage 里包含有的不包含。最后确认并发场景。高并发下如果计数变量是共享的可能出现串号。确保每个请求有独立的计数器实例。现象可能原因排查方法网关比引擎多重复计算了特殊标记对比 Tokenizer 输出网关比引擎少漏算结束标记检查流式回调随机不一致并发计数串号检查计数器作用域整体偏移固定值版本差异统一 Tokenizer 版本5.2 延迟抖动大但平均值正常的处理延迟抖动大说明系统存在长尾。平均值正常只是掩盖了问题。我的排查思路是先看抖动是否与并发量相关。如果并发高时抖动大说明资源竞争是主因要考虑限流或扩容。再看抖动是否与特定模型相关。如果只有某个模型抖动可能是该模型的批处理策略或显存管理有问题。还要看抖动是否与时间段相关。如果每天固定时间抖动可能是定时任务或备份在抢资源。我遇到过一次抖动问题最后发现是日志写入本身导致的。当时日志是同步写磁盘磁盘 IO 偶尔打满阻塞了推理线程。改成异步批量写入后抖动消失了。这个坑很隐蔽因为日志系统本身成了性能瓶颈。5.3 缓存命中率低导致的成本异常很多推理服务会做 prompt 缓存或 KV Cache 复用命中时能大幅降低成本。但如果日志里不记录cache_hit你根本不知道缓存有没有生效。我建议在日志里记录缓存命中的 Token 数并单独计算“缓存节省成本”。如果发现命中率突然下降排查方向包括缓存键是否包含了随机因素、缓存过期时间是否太短、请求的 prompt 前缀是否变化太频繁。有一次我们发现缓存命中率从 60% 掉到 10%最后查出来是某个应用在 prompt 开头加了当前时间戳导致每次请求前缀都不同缓存完全失效。加上cache_hit字段后这类问题几分钟就能定位。5.4 高频踩坑速查表问题根因解决日志量爆炸每 Token 写一条内存累加请求结束写一条时间戳错乱时区不统一统一 UTC 存储隐私泄露明文记录输入输出只记哈希和 Token 数告警误报阈值拍脑袋基于基线 P99 设阈值排查无门缺 request_id全链路透传唯一 ID成本失控无 Token 预算按应用设配额告警注意日志 Schema 一旦上线修改成本很高。建议先在测试环境跑两周确认字段够用再上生产。6. 从可观测性到成本优化的闭环可观测性本身不产生价值基于数据做优化才产生价值。我习惯把日志数据用成一个闭环观测、分析、优化、验证。观测阶段日志和指标告诉你现状。分析阶段你按模型、应用、用户维度拆解成本和延迟找出异常点。优化阶段针对异常点采取措施比如限制上下文长度、开启缓存、调整批处理参数。验证阶段再看指标是否改善形成闭环。举个实际例子。我们通过日志发现某个免费额度应用的 Token 消耗占了总量的 40%但请求数只占 5%。分析后发现该应用每次请求都带超长系统提示词。优化措施是给免费额度应用设更严格的上下文上限并在网关层做 prompt 压缩。一周后总 Token 消耗下降了 25%而用户体验没有明显变化。这个闭环能跑起来的前提就是日志字段足够细、指标聚合足够快、告警足够准。所以回到最开始那句话可观测性不是记流水账而是为决策提供依据。我个人在实际操作中的体会是先把 Token 和延迟这两个核心指标做扎实再逐步扩展其他维度。不要一上来就追求大而全字段太多反而没人看。从最痛的点入手让数据真正被用起来这套体系才有生命力。