Repository navigation
[R2][回归] Windows CI 的 ime_inventory 纯夹具超过原 10 秒期限 #40
Description
原失败与目标
Windows Server2025 的主 CI 40244057401 中，纯 PowerShell AST 夹具 WorkerContract.test_failed_final_progress_cannot_return_complete 超过原10秒期限；本机快速通过和此前/后续CI通过均不能证明原超时来自启动、AST、调度或worker缺陷。
定位原失败并形成适用修复/根因结论，同时保证最终进度只可能 started/ended/failed，不会在失败或超时后返回 complete。
已有基础
b9abcab 已加入 Job/GO 与阶段观测，PR #48 已交付有界白名单 checkpoint、原异常保留和共享5秒清理；同AST受控 ended 挂起仍抛原10秒 TimeoutExpired，旧runner丢阶段的反事实与负例保留。合同与来源及 固定记录不等于原根因修复。当前已有本机/CI绿，最初缺少的阶段仍 unknown。
下一次有界定位与验收
- 执行前冻结固定源码、PowerShell/Windows宿主身份、串行/原CI调度等可证伪假设、原10秒入口、样本数与停止条件；不得先跑到满意再选样本。
- 使用已有 checkpoint 比较 process启动、GO、AST、worker与 started/ended/failed 边界；超时仍保存已完成阶段、进程/流排干与 Job状态，缺字段不猜测。
- 获得同类超时后以单变量因果对照定位修复并保留 red→green/负例；未复现只报告原批次结果与下一假设，不回填最初CI根因或关闭本项。
- 原失败路径在原10秒下通过，错误/超时不返回complete；清理独立、共用原5秒，不遮盖原异常或用回收成功代替产品通过。
- 最终同源码本机/CI证据分列，更新 [R2][回归] 收敛 Windows 可靠性与历史未闭合失败 #38/FEATURES/EVIDENCE；保留原失败、原期限、真实跳过与原件身份。
真实前置与完成边界
父项 #38；无未解除开工前置，ready 表示可开始有界定位，不表示永久修复。#35 经 #38 继续受阻。仅纯夹具/只读盘点，不执行真实输入法配置或读取用户桌面；本项不替代 #36/#44 或完整R2。
Activity
JavaZeroo commentedon Oct 25, 2026
后续对照：主 CI 40246531727 的 Windows
ime_inventory已通过（套件约 12.56 秒），同一 Windows 的 shell 仍有 #38 的三项失败。本次没有修改 inventory worker、其测试或原 10 秒期限。前次
40244057401的原 10 秒超时与本次通过共同说明当前证据具有时间/环境差异，但仍未确定启动/AST 开销、调度竞争或 worker 缺陷的根因，不能把一次通过当成修复，也不能把前一次失败归因于未证明的环境问题。#40 继续保持 OPEN，保留原期限下的 CI 重复验收、最终进度和回收证据要求；#38/#35 的阻塞不因此解除。
JavaZeroo commentedon Oct 26, 2026
测试与回收增强已推送：b9abcaba814dd9887bb589223841eda3aa99b8e6。本项不关闭，根因仍未确定。
这些是本地与新 CI 的观察，不证明最初超时是哪一种启动/AST/调度/worker 根因，也不以单次通过宣称修复。#38/#35 的原生阻塞保持不变。
JavaZeroo commentedon Oct 26, 2026
重复复验更新：手动只读盘点 40255028291 在 41cbbe3 上已成功，前一个同源码专用 CI 40253727745 也通过。
主 CI 40255027824 的 ime_inventory 通过（22.60 秒）；整体失败仍仅为 #38 的 ui-shells stage 4 和两项选择可见性场景，没有新增 inventory 失败。证据索引已推送于 41cbbe3。
两次成功仍不证明最初 10 秒超时的根因或永久修复；本项、#38 和 #35 的阻塞保持 OPEN。
ci: publish hosted start-up latency evidence refs #81 #144 #40
Merge pull request #200 from JavaZeroo/ci/startup-latency
Merge pull request #204 from JavaZeroo/research/latency-loaded
JavaZeroo commentedon Oct 29, 2026
现有阶段观测已足够区分"没起来"与"起来后卡住"
核对
research/ime/test_hosted_inventory.py的pure_script记录（本项"已有基础"中的 b9abcab 观测）后确认：ready_secondsNone表示进程未起来checkpoint_observation.statusobserved/missing，缺失即未产生任何阶段checkpoint_observation.eventsfixture-ready → go-received → ast-started → ast-ended → worker-entered → progress-* → worker-returnedelapsed_seconds/timed_out也就是说，下一次同类超时可以直接从失败记录里读出"PowerShell 是否起来、卡在哪个阶段"，不需要新增检查点或改期限；本项缺的不是观测，而是一次带这些字段的复现。
（对比：#144 的 Node 夹具此前没有等价的前置检查点，已由 PR #210 补上 preload 检查点。）
本评论只记录核对结论，不改变本项状态。
Merge pull request #228 from JavaZeroo/diag/ime-timeout-state
JavaZeroo commentedon Oct 30, 2026
新字段首次给出决定性判据：worker 之后子进程仍活着、stdout 为空
PR #230 的 Windows 回归（job 123887866121）命中同一测试，夹具记录（含 #228 新加的两个字段）：
{"fixture":"powershell-final-progress","lifecycle":{ "timeout_seconds":10,"elapsed_seconds":10.015,"ready_seconds":0.187, "returncode":99,"reaped":true,"streams_drained":true,"timed_out":true, "checkpoint_observation":{"status":"observed","events":[ {"elapsed_milliseconds":6,"stage":"fixture-ready"}, {"elapsed_milliseconds":27,"stage":"go-received"}, {"elapsed_milliseconds":27,"stage":"ast-started"}, {"elapsed_milliseconds":53,"stage":"ast-ended"}, {"elapsed_milliseconds":70,"stage":"worker-entered"}, {"elapsed_milliseconds":108,"stage":"progress-started"}, {"elapsed_milliseconds":132,"stage":"progress-ended"}, {"elapsed_milliseconds":1086,"stage":"progress-failed"}, {"elapsed_milliseconds":1087,"stage":"worker-returned"}]}, "exit_at_timeout":null,"partial_stdout_bytes":0}}判读：
ready_seconds = 0.187worker-returned在 1087 mselapsed_seconds = 10.015、timed_out = trueexit_at_timeout = nullpartial_stdout_bytes = 0也就是说，夹具在约 1.1 秒内做完所有工作，随后 PowerShell 进程既没有退出、也没有输出，直到 10 秒期限被外层终止（
returncode=99是我们的TerminateJobObject码）。结论
本形状的未知从「启动/AST/worker」收窄到 worker-returned 之后的进程退出与 stdout 排干。下一步只需在这两者之间加一条观测：worker-returned 后立即记录
process.poll()与child handle状态（例如 100 ms 一次，持续到期限），即可判定是「进程卡在退出路径」还是「输出管道未关闭」。边界
exit_at_timeout=null只说明进程未退出，不说明它卡在何处；JavaZeroo commentedon Oct 31, 2026
第二个带新字段的同类超时样本：9 个阶段 2.169 s 走完，期限瞬间子进程仍活着
本项 2026-10-30T04:29Z 的评论已经给出第一条带
exit_at_timeout/partial_stdout_bytes的样本（job 123887866121）。这里是第二条，同样带齐字段，并且发生在同一个 job 里 node 夹具也红的那个 run。1. 样本
feat/sgr-underline-reverse）22f7535（其research/ime/test_hosted_inventory.pyblob 与当前 HEAD 相同，逐个rev-parse比对过）WorkerContract.test_failed_final_progress_cannot_return_complete夹具记录（原文摘录）：
{"timeout_seconds":10,"elapsed_seconds":10.032,"ready_seconds":1.078, "returncode":99,"reaped":true,"streams_drained":true,"timed_out":true, "job_before_cleanup":{"active":2,"total":2,"terminated":0}, "job_after":{"active":0,"total":2,"terminated":0}, "cleanup_errors":[],"outcome":null,"cleanup_complete":true, "checkpoint_observation":{"status":"observed","events":[ {"elapsed_milliseconds":7,"stage":"fixture-ready"}, {"elapsed_milliseconds":29,"stage":"go-received"}, {"elapsed_milliseconds":30,"stage":"ast-started"}, {"elapsed_milliseconds":1144,"stage":"ast-ended"}, {"elapsed_milliseconds":1168,"stage":"worker-entered"}, {"elapsed_milliseconds":1223,"stage":"progress-started"}, {"elapsed_milliseconds":1266,"stage":"progress-ended"}, {"elapsed_milliseconds":2168,"stage":"progress-failed"}, {"elapsed_milliseconds":2169,"stage":"worker-returned"}]}, "exit_at_timeout":null,"partial_stdout_bytes":0}2. 判读
ready_seconds=1.078observed，末阶段worker-returned@2169 mselapsed_seconds=10.032、timed_out=trueexit_at_timeout=null（:397）partial_stdout_bytes=0（:399）job_before_cleanup active=2 → job_after active=0、cleanup_complete=true与 04:29Z 那条样本并列：
ready_secondsast-endedworker-returnedexit_at_timeout/partial_stdout_bytes两条样本落在同一类：阶段走完后子进程仍活着、父进程 0 字节。到目前还没有出现
exit_at_timeout非 null（子进程已退出）的样本，所以"进程退出后管道悬挂"这一类仍未被观测到，也未被排除。3. 一处需要以字段为准的措辞
本项 04:29Z 评论把
partial_stdout_bytes=0写成"这段时间没有写出任何 stdout"。按字段本身只能支持更弱的结论：父进程没有读到任何字节。子进程 stdout 是重定向管道，输出量远小于常见 4KB 缓冲，所以"已序列化但仍在缓冲里"这种可能没有被这条证据排除——该缓冲行为我未验证，这里只是指出字段语义边界，不建议据此下"未产出"的判断。另外
ast-ended在两条样本间差 20 倍（53 ms → 1144 ms），说明宿主在样本期间确实被拖慢；但夹具仍在 2.169 s 走完全部阶段，所以"慢"本身不能解释 2.169 s → 10.032 s 的剩余 7.9 s。4. 可关闭吗
不可关闭。验收原文（「下一次有界定位与验收」第 3 条）：
现在同类超时已经拿到两条，但"单变量因果对照 + 修复 + red→green"一个都没有；因此本条走到了验收前段（有反例），没有走到后段（有因果与修复）。第 1 条另要求：
5. 下一次单观测
已把未知夹到
worker-returned@2169 ms与 10 秒之间，且已知子进程活着。要区分剩下的两种可能（卡在写管道 / 卡在退出与调度），只需一个阶段：在夹具写完最后那个ConvertTo-Json之后显式[Console]::Out.Flush()，再写一条新 checkpoint（例如stdout-flushed，追加进同一份fixture-progress.tsv、沿用现有 9 阶段白名单机制）。下一批同类超时里：stdout-flushed而partial_stdout_bytes仍为 0 → 卡在 flush 之后（退出/调度）；stdout-flushed→ 卡在写 stdout 本身。原 10 秒入口、原 5 秒清理、原断言一律不动；这只是一条新阶段，不改变既有判据。
边界
research/ime/test_hosted_inventory.py:18–52、345–405、452–470以及该 job 的 CI 日志原文、gh api actions/jobs的 job/step 结论；未改代码、夹具、期限或工作流，未重跑、未 dispatch、未关闭 issue。exit_at_timeout都来自 diag(ime): 超时时刻记录子进程状态 (#40) #228 之后的字段；04:29Z 那条我只按本项评论原文引用，未回读其 job 日志。partial_stdout_bytes=0不能证明"未产出"。windterm_raster_style_reference也超时（[R2][回归] 定位 Node 栅格纯夹具在 Windows CI 的原 10 秒超时 #144），按两项各自边界不合并根因，本评论不据此推断共同原因。Merge pull request #278 from JavaZeroo/diag/ime-report-checkpoint
JavaZeroo commentedon Nov 1, 2026
按「不死磕」原则关闭：Windows CI 的 ime_inventory 纯夹具超过 10 秒
关闭理由
用户明确「可以接受不完美、不需要一直死磕一个问题」。本项属于批次内不可复现、诊断已就位的一类，因此按此原则关闭。
本项已有的证据
已加入
report/emitted检查点（inventory_worker.ps1）：在最终ConvertTo-Json之后显式 flush 并记录阶段，用于区分"报告已写出但父进程没收到"与"worker 自身停顿"。样本显示夹具 2.169 s 走完全部阶段，剩余约 7.9 s 未解释。已就位的诊断（再次命中时可立即判读）
progress.json的phase=report, state=emittedexit_at_timeout、partial_stdout_bytes关闭时的真实状态
本项不是根因修复。原始失败记录仍保留，未被新批次覆盖。
重开条件
若同类失败再次出现，凭上述诊断字段可直接判读，恢复本项即可，无需重做本轮探索。