# PROGRESS:普通对话耗时两项快修 — 2026-10-05 基线:任务书写成时已部署的是 `1252de3e`。开工时 `origin/staging` 为 `853772bc`(相对已部署提交只有文档)。执行中又快进到 `4c64733f`(再加一份纳迪研究任务书,产品代码与 `853772bc` 相同)。分支 `codex/consult-latency-quickwins-20261005`,工作树 `.worktrees/consult-latency-quickwins-20261005`。测试基线工作树停在 `853772bc`,没有改它。 未推送,未部署。用量页没有登录打开。修复版本:待发布。 ## 做了什么 1. 咨询路径上,校正闸不再为官方快照干等。请求里已有「外部证据可以后做」这个标记时:先复用当天已经验证的官方快照;没有就查当天的失败记录;都没有就记 `deferred_in_consultation`,不起 4 秒子进程,也不标成已验证。直接做生时校正、请求里没有这个标记时,仍走原来的官方快照。顶层那一次前台核对仍做(BUG-301 不推翻)。BUG-1231。 2. 普通对话补上分段计时。分类耗时、第 0 步、第 1 步的耗时和供应商 token,以及第 1 步开始到第一个正文字的时间,写入运行日志和用量账本里已有的 JSON 字段。用量页多一列「分段」。不改表。BUG-1232。 3. 记录:BUG-1231、BUG-1232、CHANGELOG、本文件、状态板改为「已实现待验收」。 推理强度、精简说明、第 0 步关闭思考,按产品决定不在本单。 ## T0 环境缺口 本轮没有登录态,也没有测试账号。公开接口测到: | 检查 | 结果 | | --- | --- | | `GET https://staging.jyotisha.chat/api/health` | 200。`deployment.gitCommit` = `1252de3e6363f3097668efa1b1d5d47186c9c2d0` | | `POST https://staging.jyotisha.chat/api/consultation_workflow` | 404。公网边缘没有这条 Python 引擎路由 | | 本机 `vedastro` 模块 | 未安装 | 任务书里的 4.6 秒是沙箱网络下测的。当前测试环境跑的仍是改前版本。要确认生产机器是不是也在等这 4 秒,请在这次上线之前看现在的 `/admin/usage` 或容器日志:工具耗时是否接近「领域数 × 4 秒以上」。这次上线之后,同一处不应再出现这段等待;新的「分段」列用来看分类、第 0 步、第 1 步。 ## T1 耗时 本机没有 VedAstro SDK,产品路径的冷热耗时没有重测。下表「改前」用任务书里的沙箱数字,「改后」是本轮测试能证明的行为。 | 场景 | 改前 | 改后 | | --- | --- | --- | | 装了 SDK、按产品路径,每个领域 | 约 4.6 秒,第二轮仍约 4.6 秒 | 本机测不了秒数。测试证明:不起快照子进程,状态是 `deferred_in_consultation`,不是已验证 | | 同一天再问,上次是超时或失败 | 再等约 4.6 秒(失败不进缓存) | 负缓存同日命中,文件不重写,子进程不调用 | | 下一个 UTC 日 | 任务书未单列 | 当天的负缓存失效,重新记 `deferred_in_consultation` | | 当天已经有已验证的官方快照 | 顶层能用缓存,校正闸仍去等 | 校正闸复用同一份缓存。整数小时和进闸后变成的浮点小时,用原始请求对齐,避免对不上键 | | 生时校正自己的请求(没有咨询标记) | 走原来的官方快照 | 仍走原来的 gateway,返回字段与现场结果逐项相同 | | 顶层前台 VedAstro | 照旧(BUG-301) | 照旧。标记只作用在校正闸,不作用在顶层 gateway | 3 位公开名人 × 父母 / 年运、冷热各两轮:环境缺口,没有秒数。 ## T2 产品在哪里看 用量页 `/admin/usage` 的「分段」列,旧记录没有这些数时显示「—」。数字来自用量账本已有的 JSON 字段,没有新表、没有迁移。同一组数也在服务端日志 `[agent-observability]` 里。本轮没有登录,页面没有点开;列的文字由单元测试锁住。 | 你看到的 | 含义 | 没有数时 | | --- | --- | --- | | 分类 180 ms | 分类这一步的耗时 | 分类 — | | 第 0 步 … · 推理 · 出 · 入 · 缓存入 | 决定要不要排盘的那一步。耗时是毫秒;后面四个是供应商返回的 token | 该项为 — | | 第 1 步 … | 写答案的那一步,字段同上 | 同上 | | 写到正文 450 ms | 第 1 步开始,到第一个正文字出现。第 0 步的旁白不计 | 写到正文 — | | 各领域工具耗时 | 原有字段,本单没有改含义 | 原样 | 日志和用量记录里的对应名字:`classification.durationMs`、`modelSteps`(只保留第 0 步和第 1 步)、`answer.reasoning_ms`、工具调用上原有的 `durationMs`。供应商没返回的 token 是空值,不估算。这些字段里没有提示词、答案正文、出生资料、用户标识。 ## 开工预检 读了 `docs/research/pre_work_error_ledger.md`。本单不涉及碎片目录或镜像仓,没有再读两份碎片清扫。`scripts/pre_work_check.py --remote-timeout 8 --command-timeout 45` 的结果: | 项 | 结果 | | --- | --- | | Python 运行时 | 通过 | | 外部引擎适配器 | 通过 | | 远端可见 | 通过,远端是 `https://git.copse.top/root/Jyotisha.git` | | 碎片扫描 | 90 秒超时 | | 聚焦测试 | 45 秒超时 | | 检查当时的分支 | 比 `origin/staging` 落后 1 个提交;随后已快进到 `4c64733f` | 碎片扫描和聚焦测试超时是这次预检命令自己的时限,不是远端同步失败。没有新的镜像路径要记。 磁盘:开工时 G: 约 557 GB 空闲,D: 约 135 GB,C: 约 24 GB。 ## 已完成的检查 | 项 | 结果 | | --- | --- | | 新增 Python 测试 + 增长合同 | 11 项通过 | | 两个新 Python 文件的 ruff | 通过。`jyotish_api_server.py` 里原有的 ruff 问题没有顺手改 | | 前端计时测试 | 4 项通过,0 失败,0 cancelled | | `tsc --noEmit` | 0 错 | | `npm run lint` | 0 error,126 条既有 warning,没有为消 warning 改业务代码 | | v5 打分文件 | 工作区没有改动。没有重跑 77 例 | | 生时校正打分 | 没改 | 全量 `pytest tests`、英文对照、隐私测试、全量 `npm test`、快速门:见下面「套件对照」。对照完成前,不把本单说成套件已通过。 ## 套件对照 前端全量 `npm test`(本机,不设 CI)。基线工作树 `853772bc`,本分支在快进后的产品代码上。两边都是退出码 1,cancelled 0,skipped 0。 | | tests | pass | fail | cancelled | | --- | --- | --- | --- | --- | | 开工基线 | 4844 | 4700 | 144 | 0 | | 本分支 | 4848 | 4703 | 145 | 0 | 多出来的 4 个测试是本单的计时测试,全量里 4 个都通过。144 条旧失败名字与基线逐条相同。多出来的那 1 条是 `database roles have no cluster privileges`:全量并行时 Docker 里的 Postgres 正在关闭,`psql` 报 `the database system is shutting down`。这条测试不读本单改过的文件。单独重跑该文件:2 项通过,0 失败。不是这次改动引进的。 英文对照 `tests/test_report_english_dictionary.py` 与隐私 `tests/test_repo_privacy_markers.py`:一起跑,退出码 0。 `tsc --noEmit`:0 错。`npm run lint`:0 error,126 条既有 warning。 全量 `pytest tests`(`--tb=line`,退出码以失败名单为准;日志里的短摘要计数行没有落盘)。用量页没有用浏览器点开。 | | 失败条数 | 与对方相比多出来的名字 | | --- | --- | --- | | 开工基线 `853772bc` | 130 | — | | 本分支 | 131 | `tests/test_consultation_native_layers.py::test_the_new_layer_leaves_every_existing_output_unchanged` | 其余 130 条名字与基线相同。多出来的这一条是既有的盘缓存抖动:缓存命中读回的 VedAstro 请求清单键序和现场重算不一样。这条测试会先跑掉新层再比整份输出,并且会剥掉 `vedastro_gateway`。它用的请求没有咨询标记,不走本单的校正闸开关。全量里失败一次。单独再跑:第一次失败,紧接着再跑一次通过。快速门里又失败一次,失败后用同一比较再跑,差异条数是 0。不记成新 bug。 v5 打分文件没有改动,没有重跑 77 例。 快速门 `scripts/run_quality_gate.py --profile quick`:退出码 1。1056 通过,1 跳过,1 失败。唯一失败仍是上面那条盘缓存测试。失败后立刻用同一比较再跑一遍,两边剥掉易变字段后差异条数是 0。这条失败跟着缓存时序走,不跟着本单的校正闸开关走。门禁跑完后,5 份待处理的 oracle 模板只多了回车换行,已还原,不进提交。 `next build`:这个工作树的 `frontend/node_modules` 是指到主检出的联接,Turbopack 拒绝「联接指向项目根以外」。改用门禁同一条 webpack 构建(`next build --webpack`):编译 3.6 分钟通过,TypeScript 2.5 分钟通过。收集页面数据时停在 `/api/consult`,原因是 Windows 不允许为 Skill 运行别名建符号链接(`EPERM`,`SKILL.md` → 临时目录)。路由表没有打出来,所以没能在这台机器上确认 `/` 仍是 Static。首页源文件没改。没有为了构建去改符号链接,也没有在工作树里重装依赖。 ## Claude 验收(2026-10-05,Linux,Node 22) **结论:通过,快进合入 staging。** 环境是 Linux,Node v22.14,Python 3.13。基线工作树是 `4c64733f`,被验分支是 `137ed6f4`。 | 项 | 基线 `4c64733f` | 本分支 `137ed6f4` | 判定 | | --- | --- | --- | --- | | Python 全量 `pytest tests`(-n 4) | 62 失败 | 62 失败,名单逐条相同 | 通过 | | 新增 Python 测试 + 增长合同 | — | 11 passed | 通过 | | 快速门 Python 段 | — | `pytest` ✓;唯一红是 npm test 步,即下一行的同一批环境失败 | 通过 | | 前端 `npm test` | 4932 / 24 fail / 0 cancelled | 4936 / 24 fail / 0 cancelled,失败名单逐条相同,新增 4 条全过 | 通过 | | `tsc --noEmit` / `npm run lint` | — | 0 错 / 0 error、126 warning | 通过 | | `next build`(Turbopack,硬链 node_modules) | `/` ○ Static | `/` ○ Static | 通过 | | 首屏 gzip(index.html 引用 JS+CSS,gzip -9 求和) | 636,225 B | 636,225 B(0%) | 通过 | 24 条前端失败与 62 条 Python 失败,两边名单相同,属于本机无 Docker / 无模型凭据等环境项。执行方在 Windows 上看到的 Docker 关停与盘缓存抖动,这次在 Linux 上没有出现。 **T1 实测**(补上执行方的环境缺口):在隔离 venv 里装 VedAstro SDK,走产品路径(`defer_optional_external_evidence: true`)。3 位名人 × 父母 / 年运,跑两轮共 12 次,每次都用全新的缓存目录。 | | 每领域耗时中位 | 校正闸 `official_closure_reason` | | --- | --- | --- | | 改前 `4c64733f` | 4.47 s(首次 5.89 s) | `official_raw_response_missing` | | 改后 `137ed6f4` | 1.66 s(首次 2.02 s) | `deferred_in_consultation` | - 每个领域省下约 2.8 s,降幅约 63%。 - 任务书写的「≤1.0 s」**没有达到**。我用 cProfile 拆过剩下的 1.66 s: - 约 1.33 s 是顶层前台 VedAstro 的等待上限(`vedastro_foreground.finish → _join_foreground_vedastro`); - 引擎本体约 0.07 s(盘缓存是热的)。 - 顶层这次等待是决策记录第 3 条(BUG-301)明确要保留的。任务书的 1.0 s 目标,是照着「外网全屏蔽」时的 0.75 s 定的,定得不对。这是任务书的问题,不是实现的问题。 - 本沙箱里顶层 VedAstro 拿不到已验证的结果,所以「复用当日已验证快照」这条路径没有被线上式请求走到,只有单元测试 `test_same_day_verified_snapshot_is_reused_ahead_of_the_negative_cache` 覆盖。 **审查意见(不阻断,留给后续)**: 1. 咨询路径从来不启动快照子进程,所以负缓存里存的只会是固定的 `deferred_in_consultation` 包,起不到「记住失败」的作用。而且它每人每天在 `api_scratch` 里写一个文件,没有清理。以后可以简化成不写盘。 2. `modelSteps` 默认第 1 步就是写答案的那一步。如果模型连续调用两次工具,第 1 步其实是第二次工具调用,这时 `answer.reasoning_ms` 记为空值。读数据时要注意这一点。 3. 部署后由产品在 `/admin/usage` 的「分段」列看一轮真实数字。这一列本轮没有在浏览器里点开过。