Skip to content

test(cli): deflake snapshot freeze repro on fast runners - #14897

Merged
kirillk merged 3 commits into
mainfrom
fluffy-island
Oct 7, 2026
Merged

kirillk merged 3 commits into
mainfrom
fluffy-island

Conversation

@kirillk

@kirillk kirillk commented Oct 7, 2026

Copy link
Copy Markdown
Contributor

Issue

No existing issue — this is a CI flake caught on main while investigating run 37610968313.

What Problem This Solves

test/kilocode/snapshot-freeze-repro.test.ts was failing intermittently on main, blocking the unit (linux, 2/2) shard and therefore the test and unit gate jobs:

expect(received).toBeGreaterThan(expected)
Expected: > 0
Received: 0

Three separate main pushes on 2026-10-07 failed on this exact assertion (runs 37610968313, 37615363396, 37621039042) with successful runs interleaved, so anyone pushing to main had a decent chance of a red build unrelated to their change.

The test forks Snapshot.diffFull and runs a setInterval(..., 25) alongside it, then asserted expect(ticks.count).toBeGreaterThan(0) as proof the event loop stayed unblocked. That assertion only holds if the workload takes at least 25ms — but keeping diffFull fast is the entire purpose of the caps + worker offload this test guards. On a fast Linux runner the diff-and-abort window finished inside a single interval period, the timer never fired, and ticks.count was 0.

The test failed precisely because the code performed well. The junit duration for the failing case was 0.33s, versus ~8s on a local macOS machine, which matches that reading.

Why This Change Was Made

Tick count is the wrong signal, because its healthy value depends on how slow the code is. The invariant the test actually cares about is that the event loop was never parked long enough to swallow an ESC keypress, so assert the maximum gap between ticks instead.

Max gap is meaningful at any workload duration:

  • Zero ticks (fast box) collapses the gap to total elapsed, which is a few milliseconds — passes.
  • The original freeze pushed the gap into minutes — still fails loudly.

Changes:

  • Track the maximum interval between timer ticks rather than the tick count, and assert it stays under 2s, matching the tolerance already used by the neighbouring abort-latency assertion.
  • Fold the stretch between the final tick and the end of the work into the gap, so a stall cannot hide in the tail after the last tick.
  • Add an explicit 30s test timeout. Setup alone — git init, committing a 3000-line file, and taking two snapshots — exceeded bun's 5s default on a loaded machine, which is a second, independent flake axis. 30s matches the convention in sibling tests such as snapshot-prepare.test.ts.

No production code is touched. The defect was entirely in the test's responsiveness assertion; the freeze fix itself is unchanged and still covered.

User Impact

No user-visible change. Contributors stop seeing spurious red unit (linux) failures on main and on PRs that rebase onto it, so a failing unit shard is once again a real signal. The regression coverage for the original TUI freeze (ESC not being delivered during a large diffFull) is preserved and is now strictly more precise about what it measures.

Screenshots / Video

N/A - no visual changes.

Evidence

All checks below were executed by the agent in this worktree.

  • Root cause confirmed by reproduction, not inference: temporarily stretching the interval to 60s so the timer can never fire reproduces the CI failure byte-for-byte — Expected: > 0 / Received: 0 after 7 expect() calls, and assertion Add discord link and binary name to readme #7 is exactly the ticks.count check. The same scenario passes with this change applied.
  • bun test ./test/kilocode/snapshot-freeze-repro.test.ts (from packages/opencode/): passes, 13 expect calls. Run repeatedly, landing at both 12.3s and 4.0s, so both the slow and the fast path are covered.
  • bun run typecheck (from packages/opencode/): passes, clean tsgo --noEmit.
  • bun run lint (root): 0 errors. The 11022 warnings are pre-existing repo-wide and none originate from the touched file.
  • bun run script/check-opencode-annotations.ts --worktree (root): no shared upstream source files changed, nothing to check. test/kilocode/ is an exempt path, so no kilocode_change markers are required.

Reviewer test steps

  1. From packages/opencode/, run bun test ./test/kilocode/snapshot-freeze-repro.test.ts and confirm it passes.
  2. To see the original failure mode, change the setInterval period from 25 to 60000 on the branch point before this commit and re-run — the pre-change assertion fails with Expected: > 0 / Received: 0, while the post-change assertion passes.

Blocked checks and substitute verification

None. No checks were blocked.

Changeset: not required. This is a test-only change with no user-facing behavior.

Dependency

None.

Checklist

  • Issue linked above, or exception explained
  • Tests/verification described
  • Screenshots/video included for visual changes, or marked N/A
  • Changeset considered for user-facing changes
  • I personally reviewed the diff and can explain the changes, including any AI-assisted work.

The snapshot freeze regression test asserted that a concurrent
setInterval(25ms) ticked at least once while a forked diffFull ran,
as proof the event loop stayed unblocked. That requires the workload
to take at least 25ms — but keeping diffFull fast is precisely what
the test guards. On fast Linux CI runners the diff and abort window
completed inside a single interval period, the timer never fired, and
ticks.count was 0, so the test failed exactly when the code performed
best. This hit main repeatedly (runs 37610968313, 37615363396,
37621039042) with passing runs interleaved.

Assert the maximum gap between ticks instead of the tick count. Max
gap is a meaningful event-loop-stall signal at any workload duration:
with zero ticks it collapses to total elapsed (tiny on a fast box),
while the original freeze would push it into minutes. The stretch
after the final tick is folded in so a stall cannot hide in the tail.

Also add an explicit 30s timeout. Setup alone — git init, committing
a 3000-line file, and two snapshots — exceeded bun's 5s default on a
loaded machine.
@kilo-code-bot

kilo-code-bot Bot commented Oct 7, 2026 •

Copy link
Copy Markdown
Contributor

Code Review Summary

Status: No Issues Found | Recommendation: Merge

The incremental change addresses the prior watchdog feedback: all six timing sites now use the monotonic performance.now() instead of Date.now(), and the stall watchdog is armed before the diffFull fork so a stall at fork time is observed. Moving the fork inside the try also means the interval is cleared even if forking throws. Test-only deflake; no new issues.

Files Reviewed (1 file)
  • packages/opencode/test/kilocode/snapshot-freeze-repro.test.ts
Previous Review Summary (commit 9cdc84a)

Current summary above is authoritative. Previous snapshots are kept for context only.

Previous review (commit 9cdc84a)

Status: No Issues Found | Recommendation: Merge

The change is a single test file. Switching the responsiveness check from tick count to max inter-tick gap is sound: the tick counter's healthy value depended on how slow diffFull ran, so a fast box legitimately produced zero ticks. Measuring the maximum gap (with the post-last-tick tail folded in) is a meaningful stall signal at any workload duration, the interval is still cleared in finally, and the added 30s timeout addresses the independent setup-time flake.

Files Reviewed (1 file)
  • packages/opencode/test/kilocode/snapshot-freeze-repro.test.ts

Reviewed by deepseek-v4.1-flash · Input: 38.7K · Output: 4.7K · Cached: 213.2K

Review guidance: REVIEW.md from base branch main

@brunoagatao brunoagatao left a comment

Copy link
Copy Markdown
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No High findings. Low: set clock and start before the fork so a stall at fork start is not hidden (snapshot-freeze-repro.test.ts:88-96).

@kirillk

kirillk commented Oct 7, 2026

Copy link
Copy Markdown
Contributor Author

Addressing the two review items. Both are now implemented and pushed.

@brunoagatao — "set clock and start before the fork so a stall at fork start is not hidden" (snapshot-freeze-repro.test.ts:88-96)

Fixed, and this turned out to be a real hole rather than a theoretical one. The watchdog is now armed before snapshot.diffFull(...).pipe(Effect.forkChild({ startImmediately: true })), and the fork moved inside the existing try so clearInterval in finally still covers it if the fork throws.

I verified the blind spot empirically by injecting a synthetic 2500ms synchronous block immediately after the fork:

Clock armed Result with a 2500ms stall at fork time
After the fork (previous code) passes — 13 expect calls, stall entirely invisible
Before the fork (this change) fails — expect(clock.gap).toBeLessThan(2000) received 2547.99

Because startImmediately: true runs the fiber at the fork, the old ordering left exactly the window where the original synchronous freeze would have begun unobserved. Good catch.

@WebReflection — performance.now() over Date.now()

Done, replied in-thread. All six timing call sites switched to the monotonic clock.

Verification for both: bun test ./test/kilocode/snapshot-freeze-repro.test.ts passes (13 expect calls, repeated runs), bun run typecheck clean, bun run lint 0 errors, check-opencode-annotations.ts --worktree reports nothing to check. All run by the agent.

Arm the stall watchdog before forking the diff. `startImmediately: true`
runs the fiber at the fork, so arming the clock afterwards left the
fork-time window unobserved — exactly where the original synchronous
freeze would have begun. Confirmed as a real blind spot and not a
theoretical one: a synthetic 2500ms block injected immediately after
the fork passed under the previous ordering, and now fails with a
measured gap of 2547ms. The fork moves inside the existing try so the
clearInterval in finally still covers it if the fork throws.

Switch every timing call site to the monotonic performance.now(). Wall
time is the wrong clock for measuring event-loop parking: an NTP step
mid-test could fabricate a multi-second stall and fail a healthy run,
or step backwards and mask a real one. That matters more than usual in
a test whose purpose is to be deflaked.

Addresses review feedback from @WebReflection and @brunoagatao.
# Conflicts:
#	packages/opencode/test/kilocode/snapshot-freeze-repro.test.ts
@kirillk
kirillk merged commit 518148b into main Oct 7, 2026
30 checks passed
@kirillk
kirillk deleted the fluffy-island branch October 7, 2026 16:15
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants