Repository navigation
[R2][回归] 定位 Node 栅格纯夹具在 Windows CI 的原 10 秒超时 #144
Description
新诊断能力与结果（Draft，尚未合入）
Draft PR150，当前发布 HEAD 81d50eebbe149cf20cca292e3f076ae682cd99de；唯一正式批次执行源仍为 02aac45ca6e8eaffcbca1d3ef1a80d243159ec46。整合 main4d7 后五项执行源码字节未变；离线出口修正不产生新进程样本。当前等待最终发布增量双轴审查和自动 CI，不据此关闭本项/#38。
- 正常项
passed/0/23cp；受控挂起timed_out/99/6cp，保留原10秒 TimeoutExpired 及 Job 强制结束；受控异常failed/1/11cp。三项根归属/回收与结束 Job active0；CLI0只表示三种预定义结果齐全，不是三项都通过。 - 三 case 与 CLI 内容及序列化字节、版本/源码/Runtime EXE、trace前缀和完整性经独立 stdlib 核对一致。24项旧原件、三个 false 计划、正式 raw 和旧发布字节保留；本次另冻结并重算58项既有文件，原 CI ZIP/LastTest 原哈希也一致。固定报告。
- 诊断执行工具的协议尾、Windows/Python版本漂移 P2 分别在
3b74a94/b809706用纯反例修正。早期5dde控制测试与02aac正式批次分列；它们不解释旧CI超时。 - 最终发布预审又发现两处离线出口 P2：normal/throw 的 timeout Job 可夹带任意字段，p3 false 的源码身份未固定。red
5c8bc63的纯内存 export 反例3项/5失败子例；green504c0fd拒绝非超时对象、仅重建三个 Job 整数，并固定全部三 false 的原 SHA256/commit。相关纯普通/-O各15项通过、无跳过。 - 首次公开 JSON
db97e95aa6d56a9bb44553178f788c6f7c33fff9e52441ef343ea63821f98a3d保留原字节。新导出普通/-O字节一致，SHAde57db6e0f7c3fa57bfe1e588db2fe9587792bd4181f7836797daa8eb144e27b；仅自指的exporter_sha256字段变化，真实观测投影不变。公开不含 stderr 栈、PID、本地绝对路径或 raw checkpoint。 - 新 runner 不接入原 Python/CTest 执行入口，observer 普通路径 no-op；新增 CTest 只注册纯 export/trace 判定和 WIN32 PlanTests，configure/show-only 已核对，不含 OwnedNodeTests。发布修正没有运行 Node/10秒控制场景、完整矩阵、原版、guest 或 CI 重试。
旧CI仍缺Node启动/文件/VM阶段，本次本地正常与受控失败不解释旧事件；根因和整程硬时限保持null。后续若调查CI调度，仍须另行固定源码/宿主/样本/停止条件，不能以重跑绿回填原因。
已观察的失败
PR141 push默认工作流40742071881，attempt1、source 43883022883d382e3dd57bd627e9c735bafe58ca，Windows job 123006018718 的CTest 51/52、303.13s。唯一失败 windterm_raster_style_reference 的 RasterBoundaryTests.test_production_js_native_contract：Python subprocess.run执行 node research/ui/test_raster_native_contract.js 在原 10秒 抛TimeoutExpired。该JS是合成Qt调用的纯夹具，没有Frida/Qt/原版运行。公开堆栈未携带Node启动、读取文件、VM编译/执行或逐case阶段，原因未知。
专用Qt的PR/push和参考工作流均成功；这不能覆盖本次默认失败，也不把它归因于CRT变更。PR141未修改上述两夹具源。未提交同HEAD重试。
原件已本地保存：artifact12840955540 ZIP SHA256 a332cab228750bdcdc5c64c90f14b304ba7a9fe16973d1384f6d5f8619cdc6ed；其LastTest.log 141042B SHA256 ffdea820416494d67ab82081219cb5ec01cf55619664b7de73fd905c45800d56。原job日志也可由GitHub获取。父项#38；与#40 PowerShell AST超时分别保留，不推断共同根因。
下一次有界定位
- 先固定源码/宿主与Node/Python实际身份、输入/样本数、串行/CI调度假设与停止条件；保留原10秒，不先跑绿后选择样本。
- 区分进程创建/Node首条checkpoint/文件读取/VM构建与各合成case，超时保留已完成阶段、原错误、stdout/stderr和root/自有Job回收，缺失阶段保持unknown。
- 仅纯夹具执行，不运行WindTerm或修改个人桌面；若需新增观测，记录新源码和开销限制，不能回填旧source阶段。
- 通过受控挂起/异常负例验证原10秒失败与清理路径，不延长等待、不删case、不以重跑成功宣布原因修复；未复现只给新一批实际结果及下一可证伪假设。
Activity
JavaZeroo commentedon Oct 28, 2026
新诊断工具已完成执行前双轴审查与两项P2修正：协议坏尾不能借完整23条前缀误报成功；计划在attempt前复验Windows/Python版本。最终源
02aac45ca6e8eaffcbca1d3ef1a80d243159ec46，source tree干净，旧false/24原件不变。root随后仅执行新的冻结单次三case计划（SHA
87a0518c23b65f050d3991557b6b58aca334c8d80dc939fab601d3fae01f0fc8）：normal 23检查点/final/自然exit0；受控hang 6检查点止vm-helpers-start，仍为原10s TimeoutExpired/exit99/强制Job回收；受控throw 11检查点止case-start:grab，仍failed/exit1。三者根句柄归属与回收验证true、Job active0/total2。CLI exit0只表示三种预定义诊断结果均观察到，非三个case都成功，更非旧CI已修。所有新记录/日志留私有目录待脱敏审计，尚未push/合入main；旧超时根因继续null，本项/#38开放。没有同HEAD重跑原CI、没有原版或guest操作。
JavaZeroo commentedon Oct 28, 2026
PR #150 已以
b919698ab4f8769f520340380eb9a18fee967b1d合入 main，已核对实际执行源02aac45、出口修正504c0fd及发布81d50ee均为main祖先。交付仅为有界阶段诊断、严格离线出口与纯回归；受控hang/throw仍分别是timed_out/failed，CLI0只表示预期诊断齐全。PR默认Windows58/58、Linux38/38与Qt/参考4条CI成功；push/default的PS51准备超时已独立记#81，未重跑。旧Node超时根因仍unknown，#144/#38/#35/R2均保持开放。JavaZeroo commentedon Oct 28, 2026
新增独立CI失败样本：PR154 push/default run40769220998/job123101546682，HEAD/checkout58fee280…，
test_production_js_native_contract的现有Nodetest_raster_native_contract.js原10s再次TimeoutExpired；该CTest项总15.23s，11个Python项中此项error，未记录Node内部stage。本PR未自动运行02aac的诊断批次，不用旧normal/hang/throw样本回填此次原因。完整CTest56/59、332.37s，另两失败分别#73/#156。artifact12851572745 SHAea38ca1099f6f52420d77bee16796d04e986eab02c8912a692e013bf4d12282a、LastTest162003B SHA6ec38d3f098ade5f683f7c1fa0368843c642eb068aabb0cfa76ff8e0e7fe4a22已核对，未重跑；根因仍unknown，#144保持开放。JavaZeroo commentedon Oct 29, 2026
本项的原失败签名在今天的一次 push 运行中再次出现（同命令、同 10 秒、同测试）：
25a7453（PR docs(research): 原版合成会话的 UIA 可见性 (#155) #178，仅文档改动）。windterm_raster_style_reference（12.22s）：RasterBoundaryTests.test_production_js_native_contract。subprocess.run(["node", "research/ui/test_raster_native_contract.js"], ..., timeout=10)→subprocess.TimeoutExpired: ... timed out after 10 seconds。这意味着原失败不是一次性事件，且与特定源码改动无关——更支持"该 Node 纯夹具在 hosted Windows 上的启动/解析偶发超过 10 秒预算"这一假设，但与 #141 当时的 CRT 变更无因果证据。
下一步仍按本项合同：先在 hosted 同镜像上对同一命令做有界重复计时（每次新进程），记录耗时分布与失败率；若确认存在接近/超过 10 秒的尾部，再讨论这是夹具预算问题还是宿主抖动，不以延长等待直接取绿。
research(ui): measure the node contract fixture on the CI host refs #144
Merge pull request #179 from JavaZeroo/diagnose/node-contract-timing-…
JavaZeroo commentedon Oct 29, 2026
已对该纯夹具做有界计时并合入结果（PR #179 → main
ccb6f6f），未改夹具、期限或原失败。测量：dispatch-only 作业，命令与失败测试完全一致（
node research/ui/test_raster_native_contract.js），hosted windows-2025、Node v22.23.4；顺序 60 次 + 20 批 × 4 并发，共 140 次，每次新进程、原 10 秒超时。结果：
含义：10 秒预算相对 warm 约 130 倍余量、相对冷启动约 7 倍；两次已记录的
timed out after 10 seconds（PR141、PR #178 push）远离该分布，不能用夹具计算成本解释。更像宿主级停顿（首次执行的安全软件扫描、VM 调度/存储短暂阻塞），但空闲镜像上未复现，根因仍 unknown。下一步假设（有界）：固定"失败时同机是否有其它作业/扫描活动"这一变量——例如在 dispatch 作业里叠加可控并行负载后再测同一命令，看能否把单次推近或超过 10 秒；若仍不能，则按 #38 的"hosted 低频未知"处理，不以延长预算取绿。
证据：固定结果、validation.json。#144/#38 保持开放。
JavaZeroo commentedon Oct 29, 2026
又一次原签名复现（PR #189，改动只涉及诊断字段与 CI 作业）：
5f4b4f1；windterm_raster_style_reference（12.36s）：test_production_js_native_contract→ 同一 10 秒超时；与 #144 已有结论一致：该夹具 warm 约 63–78ms、冷启动约 1.47s，10 秒超时与夹具成本不符，属宿主级停顿。保留红例、不重跑取绿。
JavaZeroo commentedon Oct 29, 2026
又一次原签名复现（PR #198，只改诊断字段）：
windterm_raster_style_reference：test_production_js_native_contractERROR（同一 10 秒TimeoutExpired）；与已有结论一致：夹具 warm ~63ms、冷启动 ~1.47s，10 秒超时不能用夹具成本解释；保留红例、不重跑取绿。
7 remaining items
JavaZeroo commentedon Oct 30, 2026
第二次命中：仍是「preload 从未写入」
PR #235 的 Windows 回归（job 123905344942、2026-10-30T05:18:53Z）再次失败，文案与上次一致：
两次独立命中的共同点：
因此「超时发生在进程创建/加载阶段、而非夹具逻辑」这一判读得到两次独立样本支持。
仍缺的观测
preload never written无法区分是进程根本没有创建、创建后被阻塞、还是被安全软件拦在映射阶段。要分离这三者，需要父进程侧的创建耗时（CreateProcess返回时间）与子进程首次用户态执行时间的对照。边界
JavaZeroo commentedon Oct 30, 2026
第三次命中（同一文案，检查点已生效）
PR #237 的 Windows 回归（job 123910433345）在
windterm_raster_style_reference再次失败：三次独立命中的分布：
三次都落在同一台托管 runner 的相同时间窗（约 90 分钟内）。这一点值得注意：如果要判断"是否与该宿主机当时的负载/状态相关"，现有三次样本都集中在同一时段，不足以分离"宿主机状态"与"本项目路径"。
仍缺的观测（不变）
preload never written无法区分：进程从未创建 / 创建后被阻塞 / 在映射阶段被拦。需要父进程侧CreateProcess返回耗时与子进程首次用户态执行时间的对照。边界
JavaZeroo commentedon Oct 30, 2026
决定性证据：同一作业里三种运行时同时停摆
PR #239 的 Windows 回归（job 123912416780）在 05:43–05:52 UTC 的约 9 分钟内失败了三项测试，而它们用的是不同的运行时可执行体：
windterm_alternate_exportpython3 -O research/ui/export_alternate_...subprocess.TimeoutExpiredwindterm_raster_style_referencenode --require <checkpoint> ...TimeoutExpired+preload checkpoint never writtenime_inventorypowershell.exe夹具termforge-hosted-shell-preparation-v1failure_code: preparation_guard判读：
仍不能确定的
边界
Merge pull request #241 from JavaZeroo/diag/node-spawn-latency
JavaZeroo commentedon Oct 30, 2026
采样作业本身也停在同一步骤
派发的两次
actions-repeat采样（run 41012639592 / 41012649280）在 06:11:39Z / 06:11:45Z 启动后，都停在同一个步骤：Repeat the actions scenariosRepeat the actions scenarios该步骤正常约 8–11 分钟（对照：run 41011380665 的同一作业 05:58:34→06:09:48 共 11 分 14 秒，其中该步骤 7 分 35 秒）。
与本项既有证据的关系
同一时间窗（约 04:07–06:50 UTC）内已经观察到：
preload checkpoint never written）；三者共同指向"该宿主机/该时段进程执行被大幅拖慢"，而不是某个夹具或某段代码的问题。
观测说明（重要）
completed_at与真实耗时；started_at/completed_at为准。边界
JavaZeroo commentedon Oct 30, 2026
更正：上一条"采样作业停滞 33 分钟"的判断不成立
我按最终时间戳复核了两个作业，结果与上一条记录相反：
Repeat the actions scenarios停了 ≈33 分钟也就是说，我当时看到的
in_progress是状态接口滞后，不是作业真的停滞。教训（对本项方法的影响）
actions/jobs的status字段会明显滞后；不能用它推断"作业卡住"；started_at/completed_at与步骤级时间戳；status单点读数。仍未受影响的部分
三次 Node 超时与"一个作业内三种运行时同时失败"都有步骤级时间戳与失败文案支撑，不依赖
status轮询，仍然成立。边界
JavaZeroo commentedon Oct 30, 2026
补一条：job 123921774106 现已给出最终时间戳——06:11:45 → 06:23:03，共 11 分 18 秒，同样正常。
因此两个采样作业都在约 11 分钟内完成，上一条"停滞"的判断对两者都不成立；状态接口的滞后在本环境约达 20 分钟以上。
JavaZeroo commentedon Oct 31, 2026
两个新超时样本（都带
f1f4cd0新字段）：进程创建只要 0.22–0.25 s，停顿在 node 自己的启动里先说明：本项此前评论里的
preload checkpoint never written都没有spawn_seconds/pid/exit_at_timeout（这三个字段来自f1f4cd0，2026-10-30T05:56Z 才进 main）。下面两条是我在 10-30 与 10-31 的regression (windows-2025)失败里读到的、第一次带齐新字段的样本，其中一条首次证明 preload 真的执行过。1. 两个样本
feat/sgr-underline-reverse）ci/2022-record-handles）22f753575535d3AssertionError: node fixture exceeded its ten second limit; preload checkpoint never written; pid=2700 spawn_seconds=0.219 exit_at_timeout=None partial_stdout_bytes=0AssertionError: node fixture exceeded its ten second limit; {"started":1793415189496,"version":"v22.23.4"}; pid=9108 spawn_seconds=0.25 exit_at_timeout=None partial_stdout_bytes=0core/windterm_raster_style_reference/ime_inventory/presentation共 4 项windterm_raster_style_reference1 项源码身份：两个 head_sha 的
research/ui/test_raster_style_reference.py与research/ui/test_raster_native_contract.js的 git blob 与当前 HEAD 完全相同（逐个rev-parse比对过），所以这三处不是"另一个版本的夹具"。2. 证明了什么
spawn_seconds=0.219 / 0.25time.monotonic()到Popen()返回（research/ui/test_raster_style_reference.py:93–99）exit_at_timeout=Noneprocess.poll()（同文件:108）partial_stdout_bytes=0len(expired.output or '')（:109）observe钩子、无console.log（research/ui/test_raster_native_contract.js:1–28），0 字节不含信息量{"started":1793415189496,"version":"v22.23.4"}样本 D 可以算出停顿时段（runner 同一时钟：日志行时间 ↔ 子进程
Date.now()，误差约 ±0.05 s）：started= 2026-10-31T02:53:09.496Z；communicate期限，故communicate起点 ≈ 02:53:00.672 ≈Popen返回；用同一镜像的既有计时对账（research/ui/results/2026-10-29-node-contract-timing/validation.json:18–25：
first_sample_s=1.469、sequential_p50_s=0.063）：1.18 s < 冷启动首样本 1.469 s。样本 D 因此不需要再假设"启动后卡住"——node 自己的启动吃掉了 8.8 s，剩下的时间不够跑完冷路径；样本 C 更极端，连 JS 都没进。一句话：这两条同时排除了"纯夹具成本"和"CreateProcess 成本"，剩下的窗口是 node.exe 从创建到执行首行 JS，长度 ≥8.8 s（样本 C ≥10 s）。
3. 附带发现（只记录，不改变判读）
ResourceWarning: subprocess 9108 is still running，pid 与pid=9108一致 → 超时分支（:102–109）只self.fail()，不终止子进程，那个 node 在测试结束后仍活着。只影响夹具卫生。core/presentation也红，但该分支是 SGR 改动的 WIP；我没有核对它们是否与本项同因，故不作为本项证据，也不据此推断"整 job 停顿"。4. 可关闭吗
不可关闭。验收原文（「下一次有界定位」第 4 条）：
以及第 1 条：
现在拿到的正是"实际结果 + 假设收窄"，原因仍未知：没有单变量对照，也没有 red→green。按"不能以重跑绿回填原因"，这不足以关闭。
5. 下一次单观测
不需要新语义、不需要改期限：
research/ui/test_raster_native_contract.js已经内建observe('before-file-read'/'file-read'/'vm-helpers-start'/'vm-helpers-ready'/'pure-checks-done')调用点（:5–8、:17–19、:28），普通执行时是 no-op（:5 取不到global.__termforgeNodeContractObserve就退回空函数）。单次观测 = 在现有 preload 里定义这个全局函数，把{stage, Date.now()}追加进同一份 checkpoint 文件（不碰夹具本体、不动 10 秒），跑一个批次即可把窗口切成 "node bootstrap（已证 ≥8.8 s） / 读文件 / VM 构建 / 各 case"，正好对齐本项第 2 条要求的分段。边界
research/ui/test_raster_style_reference.py:84–111、research/ui/test_raster_native_contract.js:1–40、research/ui/results/2026-10-29-node-contract-timing/validation.json:1–34，以及两个 job 的 CI 日志原文与gh run list/run view/actions-jobs的 job、step 级结论；未改代码、夹具、期限或工作流，未重跑、未 dispatch、未关闭 issue。Date.now()与 runner 同一时钟"两个假设，误差约 ±0.05 s；未独立取证 runner 时钟。partial_stdout_bytes=0在本夹具里不可用于"夹具没产出"的判断（夹具本就不打印 stdout）。v22.23.4）。core/presentation）未核对，混入结论属越界。Merge pull request #274 from JavaZeroo/diag/node-checkpoint-delta
JavaZeroo commentedon Oct 31, 2026
又一个样本，这次带上了新字段
job 124510378193（
windows-2025回归）：spawn_secondspreload checkpoint never writtenexit_at_timeoutNonepartial_stdout_bytes这与之前的样本 C 同型（连 JS 都没进），与样本 D（进了 JS 但晚了 8.82 s）一起构成两种形态：
两者都不支持"夹具逻辑慢"或"CreateProcess 慢"，指向 Node 自身启动路径。
下一步（不变）
等一次 D 型命中，用新加的
js_start_after_create_ms直接读出间隔；若长期只有 C 型，则需要在父进程侧记录CreateProcess返回前后的时间戳来分离"创建"与"执行"。边界
JavaZeroo commentedon Oct 31, 2026
又有一次干净批次：60 次顺序 + 20 次并发，0 超时
来源：run 41198898623 的
node-contract-timing-r144artifact（hosted Windows 2025，Node v22.23.4）。值得注意的两点
与既有样本的关系
之前命中的失败样本形态是：
而本批 80 次运行的最大值是 1.969 s（且是冷启动首例）。即：在宿主状态正常时，即使冷启动也远低于 10 秒期限。这与"失败窗口内 Node 启动整体被拖慢"的解释一致，但本批没有复现该窗口。
边界
performance_claim: false约定同样适用）；JavaZeroo commentedon Nov 1, 2026
按「不死磕」原则关闭：Node 栅格纯夹具的 10 秒超时
关闭理由
用户明确「可以接受不完美、不需要一直死磕一个问题」。本项属于批次内不可复现、诊断已就位的一类，因此按此原则关闭。
本项已有的证据
run 41198898623 的
node-contract-timing-r144artifact：顺序 60 次（最小 0.046 s、中位 0.062 s、最大 1.969 s，冷启动首例）＋并发 20 次（最大 0.235 s），超时 0。已就位的诊断（再次命中时可立即判读）
spawn_secondsjs_start_after_create_msexit_at_timeout、partial_stdout_bytes关闭时的真实状态
本项不是根因修复。原始失败记录仍保留，未被新批次覆盖。
重开条件
若同类失败再次出现，凭上述诊断字段可直接判读，恢复本项即可，无需重做本轮探索。