test(review): stamp the ledger entries when the test runs, not when it loads

[yiliang114]

What this PR does

This PR moves one Date.now() in run-ledger.test.ts out of the describe body and into the helper that uses it, so the ledger entries are stamped when the test runs rather than when the file is collected.

Why it's needed

ledgerResumeCount reads entries through a fence:

epoch  = statSync(planPath).mtimeMs - RUN_EPOCH_SLACK_MS   // 2000 ms
kept   = entries.filter(e => e.atMs >= epoch && e.atMs <= ceiling)

The block stamped its three entries from a Date.now() evaluated in the describe body — at collection — while beforeEach writes the plan file at execution. The entries are therefore older than the file they are fenced against by however long collection took, and once that exceeds the 2-second slack the fence drops them as a previous run's.

Collection is normally a few hundred milliseconds, so the gap stayed inside the slack and the bug stayed latent. Release run 33713579913 collected for 2260 seconds on a contended host, and the block read 1, then 0, then 0 across its three --retry=2 attempts against an expected 2 — three different wrong answers, because the gap kept growing between attempts.

Reproduced against the real module, bundled standalone so it runs without the workspace build:

gap between stamp and execution	ledgerResumeCount	expected
0 ms	2	2 ✅
1.5 s	2	2 ✅
3 s	1	2 ❌
60 s	0	2 ❌
2260 s (this release run)	0	2 ❌

The boundary sits exactly at RUN_EPOCH_SLACK_MS, and the 2 → 1 → 0 progression is the one CI reported.

The fence itself is correct — an entry older than the plan file it claims to have seen is from a previous run. The test was asserting against a stamp it took too early.

Reviewer Test Plan

How to verify

1. cd packages/cli && npx vitest run src/commands/review/lib/run-ledger.test.ts — the ledgerResumeCount — entries past the original block passes, as it did before on a fast machine.
2. Confirm the failure mode is gone by construction: the stamp and the plan file's mtime are now both taken inside the same it(), so their gap is milliseconds regardless of how long collection took.
3. The other two const now = Date.now() in this file (lines 108 and 818) are already inside it() bodies and are left alone — only the describe-level one was evaluated at collection.

Evidence (Before & After)

Before: expected 1 to be 2, then expected +0 to be 2, then expected +0 to be 1 at run-ledger.test.ts:149, in Workspace Tests (3/3) of release run 33713579913, alongside 10,611 passing tests.

After: the stamp is taken at call time; the table above shows the count holds at 2 for any gap when the stamp is current.

Tested on

OS	Status
🍏 macOS	N/A
🪟 Windows	N/A
🐧 Linux	⚠️

Environment (optional)

The suite itself was not run here — this worktree has no built workspace dist/, and building it is what this machine cannot do. The mechanism was verified instead by bundling run-ledger.ts standalone with esbuild (its only cross-package import stubbed) and driving appendRunSession / ledgerResumeCount directly at the gaps in the table. The file parses under esbuild and Prettier.

Risk & Scope

• Main risk or tradeoff: none identified. The change is one statement's position; the entries' relative offsets (now, now + 1000, now + 2000) and every assertion are unchanged.
• Not validated / out of scope: this fixes the test, not the two infrastructure failures in the same release run — a [vitest-worker]: Timeout calling "onTaskUpdate" unhandled error, which --retry does not cover, and shard 2/3 exhausting the job's 45-minute cap. Both are being handled separately.
• Breaking changes / migration notes: none.

Linked Issues

Split out of #10870, which covers the wall-clock budget assertions. This one is a defect rather than a tradeoff, so it stands alone.

中文说明

本 PR 做了什么

把 run-ledger.test.ts 中的一处 Date.now() 从 describe 体移入使用它的辅助函数，使 ledger 条目在测试执行时打时间戳，而不是在文件被收集时。

为什么需要

ledgerResumeCount 通过一道围栏读取条目：

epoch  = statSync(planPath).mtimeMs - RUN_EPOCH_SLACK_MS   // 2000 毫秒
kept   = entries.filter(e => e.atMs >= epoch && e.atMs <= ceiling)

该代码块用一个在 describe 体中求值的 Date.now() 给三个条目打戳 —— 也就是在收集阶段 —— 而 beforeEach 是在执行阶段写 plan 文件。因此条目比它们所对照的那个文件旧了「收集耗时」那么多，一旦超过 2 秒的容差，围栏就会把它们当作上一次 run 的数据丢弃。

收集通常只有几百毫秒，差距落在容差内，所以这个缺陷一直潜伏。release run 33713579913 在一台被争抢的宿主上收集了 2260 秒，该代码块在 --retry=2 的三次尝试中分别读到 1、0、0，而期望值是 2 —— 三个不同的错误答案，因为尝试之间差距还在扩大。

针对真实模块复现（单独打包，无需 workspace 构建）：

打戳与执行的间隔	ledgerResumeCount	期望
0 毫秒	2	2 ✅
1.5 秒	2	2 ✅
3 秒	1	2 ❌
60 秒	0	2 ❌
2260 秒（本次 release）	0	2 ❌

拐点正好落在 RUN_EPOCH_SLACK_MS 上，而 2 → 1 → 0 的递减正是 CI 报告的那一组。

围栏本身是正确的 —— 一个比它声称见过的 plan 文件还旧的条目，确实来自上一次 run。是测试拿了一个取得过早的时间戳去断言。

Reviewer Test Plan

如何验证

1. cd packages/cli && npx vitest run src/commands/review/lib/run-ledger.test.ts —— ledgerResumeCount — entries past the original 代码块通过，与它此前在快机器上的表现一致。
2. 从构造上确认失败模式已消失：时间戳与 plan 文件的 mtime 现在都在同一个 it() 内取得，无论收集耗时多久，两者差距都是毫秒级。
3. 该文件另外两处 const now = Date.now()（第 108、818 行）本就在 it() 体内，未做改动 —— 只有 describe 级那一处是在收集阶段求值的。

Evidence（修复前后）

修复前：release run 33713579913 的 Workspace Tests (3/3) 中，run-ledger.test.ts:149 报 expected 1 to be 2、expected +0 to be 2、expected +0 to be 1，同时另有 10611 个测试通过。

修复后：时间戳在调用时取得；上表显示只要戳是当前的，计数恒为 2。

测试环境

OS	Status
🍏 macOS	N/A
🪟 Windows	N/A
🐧 Linux	⚠️

Environment（可选）

本地没有跑该测试套件 —— 这个 worktree 没有构建产物 dist/，而构建正是这台机器做不到的事。改为用 esbuild 将 run-ledger.ts 单独打包（其唯一的跨包导入用 stub 替代），直接驱动 appendRunSession / ledgerResumeCount 在上表各个间隔下验证机制。该文件通过 esbuild 解析与 Prettier 检查。

风险与范围

• 主要风险或取舍：未发现。改动只是一条语句的位置；条目之间的相对偏移（now、now + 1000、now + 2000）与所有断言均未改变。
• 未验证 / 不在范围内：本 PR 修的是测试，不涉及同一次 release 中的两个基础设施故障 —— 一个 [vitest-worker]: Timeout calling "onTaskUpdate" 的 unhandled error（--retry 覆盖不到），以及 shard 2/3 耗尽 job 的 45 分钟上限。两者另行处理。
• 破坏性变更 / 迁移说明：无。

关联 Issue

从 #10870 拆分而出，那个 PR 处理的是挂钟预算断言。本 PR 是一个缺陷而非取舍，因此单独成 PR。

https://claude.ai/code/session_01MCE9CXnMVrX4fUxHpQoUr8

[qwen-code-ci-bot]

✅ Qwen Triage finished — view run. See the stage comments in this thread for the result.

✅ Qwen Triage 已完成 —— 查看运行。结果见本线程中的各阶段评论。

[qwen-code-ci-bot]

Thanks for the PR!

Template looks good ✓

Problem: observed, not theoretical. Release run 33713579913 collected for ~2260s on a contended host, and the ledgerResumeCount — entries past the original block read 1, then 0, then 0 across its --retry=2 attempts against an expected 2. I verified the mechanism against the code: runEpochMs is statSync(planPath).mtimeMs - RUN_EPOCH_SLACK_MS (2000 ms) and beforeEach writes the plan file at execution time — so a stamp taken at collection is stale by the collection duration, and once that exceeds the 2s slack the fence drops the entries. The author's standalone reproduction (3s gap → 1, 60s → 0) matches the fence as implemented.

Direction: aligned — a latent flake in the review-command ledger tests that a slow CI host turned into a real failure; fixing the stamp keeps the suite trustworthy. No product surface involved.

Size: not applicable — one test file, +9/−3, no core production paths.

Approach: the scope is exactly right. One statement moves into the helper that consumes it, the single other consumer inlines its own stamp, offsets and assertions are unchanged. I checked the sibling PR #10870 — it touches the latency-budget files, not this one, so the split is clean.

Risk: no elevated risk signals (test-only change, no high-risk paths matched).

Moving on to code review. 🔍

中文说明

感谢贡献！

模板完整 ✓

问题： 已观测到，不是理论问题。Release run 33713579913 在一台被争抢的宿主上收集了约 2260 秒，ledgerResumeCount — entries past the original 代码块在 --retry=2 的三次尝试中分别读到 1、0、0，而期望值是 2。机制已对照代码核实：runEpochMs 是 statSync(planPath).mtimeMs - RUN_EPOCH_SLACK_MS（2000 毫秒），且 beforeEach 在执行阶段写 plan 文件——因此在收集阶段取的时间戳会陈旧「收集耗时」那么多，一旦超过 2 秒容差，围栏就会丢弃这些条目。作者的独立复现（3 秒间隔 → 1，60 秒 → 0）与围栏实现一致。

方向： 对齐——这是 review 命令 ledger 测试中一个潜伏的 flake，被慢速 CI 宿主变成了真实失败；修正打戳时机可保持套件可信。不涉及产品面。

规模： 不适用——单个测试文件，+9/−3，不涉及核心生产路径。

方案： 范围恰好。一条语句移入使用它的辅助函数，另一个使用处内联取戳，偏移与断言均未改变。已核对姊妹 PR #10870——它改的是 latency-budget 相关文件，与本文件无交集，拆分干净。

风险： 无升级风险信号（纯测试改动，未命中高风险路径）。

进入代码审查 🔍

— Qwen Code · qwen3.8-max

_{Reviewed at 1b9af1739940a778b72ada0ffa4acc3febf7e8ae · re-run with @qwen-code /triage}

[qwen-code-ci-bot]

Code review

Before reading the diff, my independent proposal from the description alone: the stamp must move from collection scope into execution scope — either a let now assigned in beforeEach, or taken inside the helper that uses it. The PR takes the second, more minimal form.

What I verified against the code at the reviewed commit:

• Diagnosis holds. The fence is exactly as described: the epoch is the plan file's mtime minus 2000 ms of slack (runEpochMs in prompt-record.ts), reads keep only entries inside [epoch, Date.now() + 2000] whose recorded planMtimeMs matches the plan's current mtime, and beforeEach writes the plan file at execution time. A stamp taken at collection is therefore stale by the full collection duration, and past 2s the epoch fence drops the entries as a previous run's.
• The diff covers every consumer. The old describe-scoped now had four uses — three in threeSessions(), one in is zero on a fresh ledger — and all four are handled (the helper now stamps at call time; the fresh-ledger test inlines Date.now()). The other two const now = Date.now() in this file (lines 108 and 818) are already inside it() bodies and are untouched, as the PR claims.
• No new sharp edges. threeSessions() is called once per test, beforeEach recreates the plan every time, and the now + 2000 entry stays below the read-time ceiling (Date.now() + 2000, evaluated after the stamp) — nothing regresses by construction.

No blockers; nothing to change.

Test evidence — this run's CI, read via the API

I did not build or run the PR's code — this lane never does. Below is the PR's own CI on the reviewed commit, fetched once (not polled); the table updates in place once CI settles.

The fix is substantiated by construction rather than by a rerun: the stamp is now taken inside the test body, after beforeEach writes the plan, so the window no longer depends on collection time at all. No ordinary CI run can reproduce the original trigger (collection longer than 2s), which is also why the sandboxed lanes add no evidence here — a /verify A/B passes both arms on a normal runner, and /tmux has no TUI surface to drive. The author's standalone reproduction table (0ms→2, 3s→1, 60s→0) matches the fence implementation I read in run-ledger.ts; the construction argument stands without it.

CI at fetch time — unit suite, lint, and integration still running; nothing failing:

Check	Conclusion
Test (ubuntu-latest, Node 22.x)	⏳ in progress
Lint & Static (ubuntu-latest, Node 22.x)	⏳ in progress
Integration Tests (no-AK, No Sandbox)	⏳ in progress
TUI parity snapshots (ink vs opentui)	✅ success
Security Checks (secret scan / dependency CVE audit)	✅ success
Desktop Shell (ubuntu-22.04)	✅ success
Desktop Shell (windows-2022)	✅ success
OpenTUI no-flicker gate	✅ success
Classify PR / assign / label / authorize / delay-automatic-review	✅ success
Test (windows-latest / macos-latest)	⏭️ skipped (normal for this repo)
verify / tmux-testing / precheck-pr / Integration Tests (CLI, No Sandbox) / publish gates	⏭️ skipped (not triggered)
triage / review-pr (bot jobs)	⏳ in progress

Not verified: the suite under artificially slow collection — that trigger cannot arise after this change by construction, so there is nothing to rerun.

中文说明

代码审查

读 diff 之前，我仅凭描述给出的独立方案：时间戳必须从收集作用域移入执行作用域——要么在 beforeEach 里给 let now 赋值，要么在使用它的辅助函数内取戳。PR 采用了第二种、更小的形式。

在受审提交上对照代码核实：

• 诊断成立。 围栏与描述完全一致：epoch 是 plan 文件 mtime 减 2000 毫秒容差（prompt-record.ts 的 runEpochMs），读取只保留落在 [epoch, Date.now() + 2000] 内、且所记录的 planMtimeMs 与 plan 当前 mtime 匹配的条目，而 beforeEach 在执行阶段写 plan 文件。因此在收集阶段取的戳会陈旧整整一个收集时长，超过 2 秒后 epoch 围栏就把这些条目当作上一次 run 的丢弃。
• diff 覆盖了所有使用点。 原 describe 级 now 有四处使用——threeSessions() 内三处、is zero on a fresh ledger 一处——全部处理（辅助函数改为调用时取戳；fresh-ledger 测试内联 Date.now()）。文件里另外两处 const now = Date.now()（第 108、818 行）本就在 it() 体内，未改动，与 PR 声明一致。
• 没有新的坑。 threeSessions() 每个测试只调用一次，beforeEach 每次重建 plan，now + 2000 的条目低于读取时的上限（Date.now() + 2000，在取戳之后求值）——构造上不会回归。

无阻塞问题；无需修改。

测试证据——本次运行 CI，经 API 读取

本流程不构建、不运行 PR 代码。以上是 PR 自身 CI 在受审提交上的状态，一次性读取（不轮询）；CI 结束后表格会就地更新。

该修复由构造支撑，而非靠重跑：时间戳现在在测试体内、beforeEach 写完 plan 之后取得，窗口不再依赖收集耗时。任何普通 CI 运行都无法复现原触发条件（收集超过 2 秒），这也是沙箱流程在此无法补充证据的原因——/verify 的 A/B 在正常 runner 上两臂都会通过，/tmux 没有 TUI 面可驱动。作者的独立复现表（0ms→2、3s→1、60s→0）与我在 run-ledger.ts 读到的围栏实现一致；构造论证不依赖它也能成立。

未验证：人为放慢收集下的套件——该触发条件在本次改动后按构造不可能再出现，无需重跑。

— Qwen Code · qwen3.8-max

_{Reviewed at 1b9af1739940a778b72ada0ffa4acc3febf7e8ae · re-run with @qwen-code /triage}

[qwen-code-ci-bot]

Confidence: 5/5 — an observed flake whose mechanism matches the fence code exactly, fixed by moving one statement; verified by construction.

Stepping back: the diagnosis is the strong part of this PR. The 2 → 1 → 0 progression across retries is exactly what a stamp going stale against a 2s epoch slack produces, and I confirmed each load-bearing piece in prompt-record.ts and run-ledger.ts rather than taking the description on faith. The fix is the smallest possible one — the stamp moves into the helper that consumes it, the one other consumer inlines its own, and nothing else in the block changes. My independent proposal was the same move, so there is no simpler path to point at. Test-only, no product surface, and split cleanly from #10870 (which owns the latency-budget files).

Approval is deferred only because the unit suite, lint, and integration jobs are still running on this commit — approval lands automatically once every check on 1b9af1739940a778b72ada0ffa4acc3febf7e8ae settles green (the CI table in the review comment updates in place).

中文说明

置信度：5/5 —— 已观测到的 flake，机制与围栏代码完全吻合，仅移动一条语句即修复；构造层面已验证。

回头看：诊断是这个 PR 的亮点。重试间 2 → 1 → 0 的递减正是时间戳相对 2 秒 epoch 容差变陈旧的结果；我逐一在 prompt-record.ts 与 run-ledger.ts 中核实了每个关键论断，而不是轻信描述。修复是最小的——戳移入使用它的辅助函数，另一个使用处内联取戳，块内其余不变。我独立想到的方案与此相同，没有更简路径可指。纯测试改动，无产品面，与 #10870 拆分干净（后者负责 latency-budget 文件）。

暂缓批准仅因该提交上的单元套件、lint 与集成任务仍在运行——待 1b9af1739940a778b72ada0ffa4acc3febf7e8ae 上的检查全绿后自动批准（审查评论中的 CI 表格会就地更新）。

— Qwen Code · qwen3.8-max

_{Reviewed at 1b9af1739940a778b72ada0ffa4acc3febf7e8ae · re-run with @qwen-code /triage}

[chiga0]

Scope: test file only — packages/cli/src/commands/review/lib/run-ledger.test.ts (9 additions / 3 deletions). Cross-file context read: run-ledger.ts (production source — appendRunSession, parseSessions, epoch fence) and prompt-record.ts (RUN_EPOCH_SLACK_MS = 2000). No execution rung run; no environmental-behavior change in production code.

---

No blocking findings.
Approval blockers: none.

What was checked:

Contract / epoch-fence correctness. The fencing condition in parseSessions keeps entries where atMs >= runEpochMs(planPath) and runEpochMs = planMtimeMs − RUN_EPOCH_SLACK_MS (i.e. plan-file mtime − 2 s). beforeEach writes the plan file at test execution time. A Date.now() stamp taken at Vitest collection time — before any beforeEach has run — can therefore be arbitrarily earlier than the plan file's mtime. On the release run cited in the comment (run 33713579913, 2260 s collection latency), the stamp was 2258 s before the epoch, so every entry was fenced out and the three affected tests read 1 / 0 / 0 against an expected 2. Moving the stamp inside threeSessions() means it is evaluated at call time, after beforeEach has written the plan, putting the stamp within the slack window. Verified: appendRunSession takes nowMs as its third parameter and stores it as atMs; the fix feeds a fresh Date.now() through threeSessions() — correct.

The lone standalone test. it('is zero on a fresh ledger, whatever excludes') previously used the outer now variable; after the fix now is no longer in scope there. The replacement Date.now() is called inline at execution time (after beforeEach), so the same epoch-fence concern does not apply. The test's assertion (one entry, ledgerResumeCount = 0) does not depend on relationships between multiple session timestamps, so a fresh inline stamp is correct here.

No production-code change. The diff is test-only; the epoch fence, appendRunSession, and ledgerResumeCount implementations are unchanged.

Existing reviews / cross-check. No prior non-bot reviews on this PR; no conflicting findings to reconcile.

Not reviewed: no terminal-dependent or environment-dependent production change, so execution rungs not run.

Reviewed with AI assistance.

[qwen-code-dev-bot]

Reviewed at head 1b9af173.

• The mechanism checks out against the module at this head: runEpochMs = statSync(plan).mtimeMs - RUN_EPOCH_SLACK_MS (2000), beforeEach rewrites the plan at execution, so a stamp taken at collection ages past the fence exactly as described — and the observed 2→1→0 retry gradient is the oldest-entry-first drop (now, now+1000, now+2000) the table predicts. Stamping inside threeSessions() makes the stamp↔mtime gap milliseconds by construction. The atMs <= runCeilingMs() side stays safe: S2 at stamp+2000 is read within the same it(), so ceiling (read-time + 2000) still admits it.
• No dangling references to the removed describe-scoped now (the only bare uses are now function-local or Date.now()); the other two const now declarations are indeed already inside it() bodies.
• Ran locally against the PR-head files (run-ledger.ts and prompt-record.ts are byte-identical to current main): run-ledger.test.ts 72/72 passed.
• No prior reviews or threads to re-verify; no CI failures on this head (Test/Lint lanes still running — per the channel convention the call is on the review itself). No new Criticals found in the one-file test change.

[qqqys]

Reviewed at head 1b9af173. First round on this PR (no prior reviews or threads), and my Critical-only pass finds no blocking defects.

The change, verified at this head: the ledger entries in the ledgerResumeCount block are now stamped at call time instead of collection time — const now = Date.now() moves inside threeSessions(), and the fresh-ledger case takes its own Date.now(). This is the right fix for the observed flake: readSessions fences entry timestamps against the plan file's mtime with only RUN_EPOCH_SLACK_MS (2 s) of slack, and the describe's beforeEach rewrites that file, so any stamp older than collection time plus 2 s is dropped as a previous run's — exactly the shape in release run 33713579913, where a 2260 s collection on a contended host made the block read 1/0/0 against an expected 2.

Semantic preservation checked: every test in the block calls threeSessions() exactly once (or stamps its own fresh timestamp), so the per-call stamp changes no assertion — the expected resume counts (2/2/1/0/0) are untouched; no other reference to the moved binding remains in the block, and the similarly named local in the sessionEntryCount describe is a separate declaration. Test-only change; no production code, no runtime surface.

CI at this head: no failing or cancelled checks at review time; Test (ubuntu-latest, Node 22.x), Lint & Static, the no-AK integration lane, review-pr and triage are still pending, which does not gate this review per policy.

[qwen-code-ci-bot]

Released in v0.23.0.