queue time、TTFT 与完成时间的口径差异#
前面的维护章节已经讲了 RequestStage、ReqTimeStats、request-level exporter、tracing 与 metrics,但如果没有一章把这些指标名字本身重新放回同一条时间线,读者在现场仍然很容易犯同一种错误:有指标,却读错了指标。
像下面这些名字,看起来都很熟:
queue_time- time to first token(TTFT)
e2e_latencyresponse_sent_to_client_tsrequest_finished_tsdecode_throughput
真正危险的地方在于,它们并不站在同一层。只要口径混读,你就很容易把“某个值变大了”直接归因到错误层级。优秀技术书在这里不该再发明新指标,而应该主动告诉读者:这些名字各自对应 runtime 时间线上的不同切片。
先把这些指标重新放回同一条时间线上#
下面这张图的作用,不是重复 RequestStage,而是把最常被平铺误读的字段重新放回同一条有先后顺序的时间线上:
flowchart LR
Create["created_time"] --> Dispatch["api_server_dispatch_finish_time"]
Dispatch --> Queue["queue_time"]
Queue --> First["first_token_time"]
First --> Resp["response_sent_to_client_time"]
Resp --> Finish["finished_time"]
Finish --> Metrics["e2e / decode / throughput"]图里最重要的一点是:这些指标不是平铺字段,而是同一条请求时间线上的不同窗口。只要这个先后关系先站稳,后面很多线上误判就会自然减少。
created_time 和 api_server_dispatch_finish_time 分别切开了哪两层#
APIServerReqTimeStats 里,set_created_time() 是服务端正式接住请求的起点。它不是客户端开始构造请求的时刻,也不是 scheduler 第一次看到请求的时刻,而是“请求已经进入 API server 时间线”的起点。
api_server_dispatch_finish_time 则更像第一道重要分界线。它代表的是:
- API server 侧对象整理已经完成
- 请求已经准备进入下一层
这意味着它很适合拿来切开两类成本:
- API server 前置整理成本
- 真正 runtime 内部的时间
也正因为这样,一些 span attrs 或近似推断才会把 api_server_dispatch_finish_time -> finished_time 看作更接近“模型推理时间”的窗口,而不是把整个 created -> finished 都混成一段。
queue_time 不是“请求总等待时间”,它是 scheduler 边界里的等待切片#
这类误读是现场最常见的。SchedulerReqTimeStats.convert_to_output_meta_info() 给出的 queue_time 本质上对应的是:
- 请求进入 scheduler 相关等待状态后
- 到真正进入 forward 之前
的那段切片。
因此如果你看到:
queue_time很高
更稳的第一反应应该是:
- admission / waiting / batch 成形问题
而不是:
- detokenizer 慢
- 客户端网络慢
- 输出序列化慢
换句话说,queue_time 值钱的地方,不是它“大”,而是它已经把问题先压到了 scheduler 边界内。
TTFT 真正覆盖了什么#
TokenizerManager 里 first_token_time 只会在第一批输出到达时写一次,因此 TTFT 更准确的理解是:
first_token_time - created_time
这意味着 TTFT 从来都不是“纯 prefill latency”的同义词。它实际上会一起吞掉:
- tokenize
- API dispatch
- queueing
- 第一次 forward
- 第一批输出回到 tokenizer manager
这也是为什么一看到 TTFT 上升,就直接说“模型前向慢了”是危险的。TTFT 其实更接近“用户第一次看到输出”这件事在服务端内部的总体切片,而不是某一个局部模块的纯成本。
response_sent_to_client_time 和 finished_time 之所以都需要,是因为系统内部完成和用户感知完成不是一回事#
这是另一组特别容易被混用的字段。
response_sent_to_client_time 更偏:
- 系统把结果真正准备好并送给客户端的时刻
而 finished_time / request_finished_ts 更偏:
- 请求在系统内部被标记为真正完成的时刻
这两个时间看起来很近,但语义完全不同。尤其在 streaming 场景里,客户端可能已经看到最后一批 chunk,而系统内部还在做 logger、exporter、cleanup 或状态回收。也就是说:
response_sent_to_client_time更像外部感知边界finished_time更像内部生命周期收口边界
如果两者差得比较大,问题更可能在收尾阶段,而不是在前向或 decode 本身。
e2e_latency 大,不代表模型就慢#
get_e2e_latency() 在 APIServerReqTimeStats 里的定义很直接:
finished_time - created_time
这意味着它天然是最宽口径的指标:只要请求在服务端里花了时间,无论是 dispatch、queueing、prefill、decode,还是 finish 之后的收尾,都可能被它覆盖进去。
因此一旦看到 e2e_latency 上升,更稳的问题不是“模型是不是慢了”,而是:
- 是 dispatch 变慢了
- queueing 变长了
- prefill / decode 变慢了
- 还是 finished 之后的收尾拖长了
如果没有这层口径意识,e2e_latency 反而会因为“太全”而最容易误导人。
decode_throughput 只有在某些请求人格下才有意义#
decode_throughput 的值钱之处,并不在于它能给出一个吞吐数字,而在于它默认隐含了两个前提:
decode_latency > 0completion_tokens > 0
这说明它天然更适用于真正有 completion token 的生成请求。换句话说:
- embedding / rerank 之类请求不适合直接套这套口径
- 极短 completion 也容易让这个值噪声很大
好技术书应该主动提醒读者这种适用边界,而不是让人把所有指标默认套到所有请求人格上。
为什么一条请求最后会同时带 tokenizer 视角和 scheduler 视角的时间#
这也是很多字段看起来“重复”的来源。TokenizerManager 在 finished 分支里,会把:
state.time_stats.convert_to_output_meta_info(...)scheduler_time_stats.convert_to_output_meta_info()
一起折进最终 meta_info。这说明一条请求最终输出里的时间字段,本来就是两个视角拼起来的:
- API server / tokenizer 视角
- scheduler 视角
因此你看到很多时间字段同时存在时,不应该先怀疑“是不是重复设计”,而应该先承认:这本来就是不同层的切片被一起折到了最终输出里。
最容易出现的四种误判#
第一,误把 TTFT 当成纯 prefill latency。
它还吞掉了 dispatch 和 queueing。
第二,误把 e2e_latency 当成模型执行时间。
它覆盖的是整个服务端请求生命周期。
第三,误把 response_sent_to_client_time 和 finished_time 当成同一个完成时刻。
它们分别对应外部发送边界和内部完成边界。
第四,看到 queue_time 就推断系统整体都慢。
它更具体地指向 admission / waiting / batch 成形阶段。
真正用这些指标排障时,更稳的顺序#
更稳的排障顺序通常是:
- 先看
queue_time:判断是不是 batch 成形或等待问题 - 再看 TTFT:判断第一次输出整体是不是变晚了
- 再看
decode_throughput:判断后续生成是不是变慢了 - 最后对照
response_sent_to_client_time和finished_time:判断收尾阶段是否额外拉长
这条顺序的最大价值,在于它沿着请求时间线逐层缩小问题空间,而不是一开始就拿最宽口径的指标去猜根因。
小结#
这一章真正要补齐的,不是另一组指标定义,而是一种读指标的方法:同一个请求上的这些字段,分别代表时间线上的不同切片,因此不能互相替代,也不能脱离请求人格和所处层级单独解释。
把这层读清之后,RequestStage 和 ReqTimeStats 这套时间语义才会从“源码存在的能力”变成“现场真正能用的工作工具”。
叶王 © 2013-2026 版权所有。如果本文档对你有所帮助,可以请作者喝饮料。