# 问答耗时观测（F097）

F171只减少本地JSON/分块计量/固定提示构造及编号绑定重复计算，原分析输入、调用数、F170调度和并发不变，不新增阶段或遥测字段。JSON构造属于模型调用包装之前的本地工作，编号回填也不等于模型生成；本地微秒/毫秒收益不能用来承诺`model_call.analysis`或6.653秒分析阶段明显下降，范围见[候选分析恢复](candidate-analysis-recovery.md)。

F170新增`analysis_prepare`及`analysis_scheduled_chunks`、`analysis_reordered_chunks`、`analysis_schedule_original_weight`/`analysis_schedule_selected_weight`数值；权重只用于分块调度估算，不是实测毫秒或token。只在预计尾部负载至少下降5%时调整开始顺序，原模型输入/分块、并发上限及完整性规则保持。见[原文分析调度](concurrency.md#原文分析调度f170)，本地合成效果不代替线上耗时验收。

F169增加请求内已写检查点的Redis核验复用：核对当前版本及正文后可省去大正文重复回传，最终get_state和pending writes完整读取保持。新增checkpoint_cache_prepare耗时及redis_checkpoint_cache_hit/cache_saved_bytes数值，详见[Redis读取诊断](redis-read-timing.md)。仅本地合成验证，真实Redis脚本执行/CPU开销与线上延迟未验收。

F168诊断提示：`synthesis`与`model_call.synthesis`的差额可粗估该阶段模型调用之外的本地工作，但含计时舍入和其他处理，不能直接叫作精确压缩CPU耗时。最终`session_result_load`应单看；若时间主要在`redis_checkpoint_read.session_result_load`而解码很短，应继续区分Redis执行、连接/网络及客户端读取，不能由日志将其全归因到Redis服务器。不要把并发的model_call或executor_wait累加量直接加到请求总时长。

F101新增Redis回读细分：metrics.spans增加客户端HGETALL、字段解析、检查点选择、JSON/Base64及反序列化时间；metrics.measurements记录返回/选中编码数据量及固定字段分类。以.session_result_load定位最终回读，详见[Redis读取诊断](redis-read-timing.md)。不改变原读取行为，需重启后采集。

每个已接纳的 chat 请求在后台工作线程退出时写一条 `event=request_performance` JSON日志。按用户要求包含原始 `thread_id`，并保留每轮独立的 `request_id`、脱敏 `session_ref` 和 `outcome`。问题、回答、公司资料、资料标题、引用、附件地址和模型输入均不进入统计。其他既有日志继续通过request_id关联。

无需前端改动，没有新增SSE事件，不改变result或Redis会话结构。需重启后端后采集新请求，旧请求无法补算。此次仅增加观测，没有调整模型、并发数、检索预算、重试或生成提示。

## 指标口径

`metrics.total_ms`：HTTP处理函数收到请求至后台工作线程退出前统计时的墙钟耗时，包含解析、接纳、排队、业务处理及收尾。直接调用Service时从Job创建计时。使用单调时钟，不受系统校时影响。

`metrics.milestones_ms`均为相对相同起点的时间，未发生为null，不用0冒充：

| 字段 | 含义 |
| --- | --- |
| worker_started | 工作线程开始处理；包含HTTP前置处理，纯工作线程排队见worker_queue |
| first_card | 第一张完整item成功进入服务端事件队列 |
| first_text | 首次非空answer_delta、answer或summary成功入队；包括程序前置说明、补问或降级答复 |
| first_model_text | 首次模型公开正文增量成功入队，区别于程序前置说明；非流式/同题QA路径可能为空 |
| result_ready | 完整result成功入队 |
| terminal_ready | done/error成功入队；断线等情况下可为空 |

这些是服务端指标，不是浏览器收到或渲染时间。被撤回的首段草稿仍计首次输出；不代表首段内容最终通过校验。前端显示延迟、网络和代理缓冲需要另行联调。`total_ms`是后台生命周期，可能晚于终止事件；超时/断线后的在途同步调用结束仍会记录。进程被强制终止则无法保证输出统计。

`metrics.spans`各项包含count、total_ms、max_ms、failed_count。total_ms是该类已完成区间之和；并发子调用和嵌套父阶段相互重叠，不能将全部项相加当作请求总耗时。failed_count仅指异常逃出计时区间，已被业务内部处理的失败需结合result_ready原有诊断；LangGraph正常补问中断不算失败。

| 项 | 范围 |
| --- | --- |
| session_load / session_result_load / history_save | 会话读取、最终状态读取、请求历史保存；图内部检查点写入未单列 |
| prepare / analyze / search / basic / honors / plan / retrieve / recommend等 | 实际图节点运行，包括节点内子阶段；中断恢复可能多次计数 |
| attachments | 附件下载、解析和图片识别 |
| rerank / analysis / highlights | 初筛、全文分析、卡片短文案阶段墙钟时间 |
| reduction / synthesis | 中间笔记每批整理、最终综合；按实际调用累加，重试计入 |
| model_wait.阶段 | 等待共享模型并发名额；count包含获取超时 |
| model_call.阶段 | 获取名额后到调用返回/抛错，count包含重试和失败；不等于模型服务端纯推理时间 |
| executor_wait.阶段 | 本请求候选/证据块/初筛等线程池排队时间，按任务累加 |
| retrieval_wait.retrieve / retrieval_call.retrieve | 等待共享检索名额、取得名额后的检索处理 |
| embedding_wait.retrieve / embedding_call.retrieve | 本地向量锁等待及向量计算（可能含初始化） |
| vector_search | 每条查询跨六库检索的耗时，多个查询可重叠 |
| content_read | 每库完整资料分段读取调用，空集合可能为0毫秒 |
| worker_queue / event_queue | Job接纳至工作线程启动；事件入队耗时（含慢消费造成的背压） |

在线请求的模型等待能反映后台会话分析、公司分类对共享名额的竞争；本日志不另行统计那些后台任务自身耗时。无模型调用的分支不制造model_call项。

## 采集与分析

筛选`event=request_performance`，用thread_id聚合同一会话的多轮请求，用request_id与阶段/错误日志关联。先按闲聊、知识咨询、具体需求、公司确认恢复、附件场景分组，再分别统计首卡、首字、总耗时的中位数和P95；null样本单独计数，失败/降级/中断单独分组。不能把人工等待补问的多轮间隔算入单次请求耗时。

优先比较analysis、reduction、synthesis墙钟时间及对应model_wait/model_call；executor_wait高表示本请求任务排队，model_wait高表示共享模型名额竞争，event_queue高表示消费背压。先收集重启后代表性真实样本，再决定下一项提速。本次合成验证仅证明计时、隔离和协议兼容，不代表线上性能基线或提速效果。