fix(tests): measure what the code controls in three tests that failed on busy hosts by devswha · Pull Request #2150 · devswha/ovis

devswha · 2026-10-28T03:13:34Z

Closes #2110, closes #2142, closes #2143.

Change

Three tests failed PR CI and local check fast on busy hosts with nothing wrong in the code. Each now measures what the code controls, and each still fails the regression it guards. Test-only: no app code changes.

`scripts/ci-browser.test.ts` (#2110)

Cause: the stubbed browser lane forks a few processes per browser script. On a loaded host the whole stubbed run approached its 5 s spawn limit, and Bun killed it (exit 143).
Second problem, found while proving the guard: the spawn timeout ended only the lane's bash. The script's pipeline kept the output open, so a lane that really hung failed only at the test's own timeout and left processes running. The old 5 s version had the same leak.
Fix: a 60 s hang guard, and each lane test gets 70 s to report. The test reads the lane's output as it comes. At 60 s the guard ends the lane and every process under it (from one process-table snapshot, and only while the lane's bash still runs; taskkill /T on Windows). It then stops reading and fails with what the lane printed. It never waits for the output to close, which a process the lane left behind can hold open. The lane stays in the test file's own process group, so scripts/ci-tests.ts still ends any such process when the file finishes or a run is interrupted.

`server/codex.test.ts` (#2142)

Cause: three bounded-time cases timed parseCodexTranscript and matchShortCodexAnswers with performance.now() against 1,000 ms. CI failed at 1,013 to 1,062 ms because a busy runner stretches the clock while the work waits for a core.
A second gap: at the old fixture size, the 1,000 ms bound did not catch the regression the code comment names. With cutAtLinkTargets changed back to a regex split, the unclosed-link case took 167 ms of CPU and passed.
Fix: each case times a small and a five-times-larger input in this thread's CPU time (clock_gettime(CLOCK_THREAD_CPUTIME_ID), as src/lib/markdown.test.ts does since Flaky test: markdown.test.ts 'looks once for the end of a formula that never closes' exceeds its timing ratio on a loaded runner #2084). It takes the least of three runs per size and bounds how much the time grows. A ratio does not depend on the runner's processor, which an absolute CPU budget still would.

case	as written	bound	regression	with it
citation parsing	12x	40	each unmatched delimiter scans the rest of the text	132x
unclosed links	3x	8	`cutAtLinkTargets` as a regex split	15.8x
large answer	5x	10	work per link grows with the links before it	24.6x

`server/opencode.contract.test.ts` (#2143)

Cause: the first-key gap was measured from the last request the fake service had received. A /review send (the prompt path) types its first key about 4 ms after the submit, before asking the service anything. Its reference was therefore the previous send's last request, and the "gap" was however long that send's tail took. CI saw 1,063 and 1,388 ms, always on prompt/slow.
Fix: each send is measured from the latest of three things before its first byte: its own submit, the queued send's idle report, and the bridge's requests. The byte's time is the stand-in's own read time, not when its report arrives.

Known limit (unchanged by this PR): a request that lands after a stream wait and before the first key still becomes the reference. This change narrows the blind spot: requests after the first byte no longer count, and an earlier send's requests no longer do either.

Proof

test(ci-browser): the CHECK_DIR evidence case fails at its 5 s spawn timeout on a loaded host #2110 reproduced, old vs new: 8 copies of each test pinned to 2 cores.
- Old: 8 of 8 runs failed (Received: 143).
- New: 8 of 8 passed, the slowest lane test at 5.4 s.
A hung lane still fails: with a stub that sleeps 600 s, the test fails at 60.2 s with "the stubbed lane did not finish within 60 s; its output so far: …". No lane process is left afterwards, and none is left when the test's process group is interrupted at 5 s either. A lane that exits while a background process it started holds its output open also fails at 60.1 s (before, it reached the 70 s test timeout). That straggler is then ended by the test file's group kill, as scripts/ci-tests.ts does.
Codex mutations: each regression in the table fails its own case and only that case. Three runs of the unchanged code pass 3 of 3.
OpenCode mutation: a temporary bridge that waits up to 1.5 s for the event stream before typing fails the test (slow-mode gaps 1,512 to 1,617 ms). With the fix, the prompt path measures 4 to 9 ms.
Under load: six rounds of the codex and opencode tests, alongside bun run check fast through dori heavy, all passed. The largest OpenCode gap was 207 ms.
bun run check fast: ok on fca3d9c (rebased on 124e9b9), 7,878 pass, 0 fail.

Reviews

omo-native-code-reviewer: PASS on the first commit. Its MEDIUM was the unclosed-link case's thin headroom under the absolute bound, which the ratio replaces.
Codex Sol 6.1 Fast xhigh, four rounds:
- Round 1 (first commit): no CRITICAL or HIGH. Its MEDIUM about hardware-dependent CPU budgets is fixed by the CPU-growth commit. Its other MEDIUM is the known OpenCode limit above, and its LOW (retries hiding a cold-only regression) went away with the ratio.
- Round 2: two MEDIUMs on the hang guard. Windows has no negative-pid group kill, and a detached lane escaped ci-tests.ts's interruption cleanup. Fixed by ending the lane's process tree inside the test's own group.
- Round 3: one MEDIUM and one LOW. A process orphaned before the snapshot could still hold the output open, and a stale pid could be signalled. Fixed by reading the output as it comes, ending the tree only while the lane runs, and failing at the guard without waiting for the output to close.
- Round 4: no findings.

… on busy hosts - scripts/ci-browser.test.ts (#2110): the stubbed browser lane's 5 s spawn limit was a hang guard that load reached; it is now 60 s, with each lane test given room beyond it. - server/codex.test.ts (#2142): the three bounded-time cases count this thread's CPU time (least of up to three runs) instead of wall-clock milliseconds. Their bounds now fail the regression each names: the citation scan 100 ms (tail rescan per delimiter 461 ms), the unclosed-link fixture grows to 4000 repeats (regex split 1684 ms), the large answer keeps 1000 ms (per-link unshift 6041 ms). - server/opencode.contract.test.ts (#2143): each send's first-key gap is measured from its own submit, idle report or request, with the byte's read time from the stand-in; a /command send was measured from the previous send's requests.

… lane's whole group Review follow-ups to the previous commit. - server/codex.test.ts (#2142): an absolute CPU budget still depends on the runner's processor. Each case now times a small and a five-times-larger input and bounds the growth: citation 12x as written (bound 40, a tail rescan per delimiter 132x), unclosed links 3x (bound 8, the regex split 15.8x), large answer 5x (bound 10, a per-link unshift 24.6x). - scripts/ci-browser.test.ts (#2110): the spawn timeout ended only the lane's bash, and its pipeline kept the output open, so a hung lane failed only at the test timeout and outlived it. The lane runs in its own process group, which the 60 s guard kills, and the error shows what the lane printed.

… own group Codex review of the previous commit: a detached lane left the test file's process group, so scripts/ci-tests.ts could not end it when a run was interrupted, and Windows has no negative-pid group kill. The lane now stays in the test's group, and the 60 s guard ends the lane and every process under it, read from the process table (taskkill /T on Windows).

… its output to close Codex review of the previous commit: a process the lane orphaned before the guard's process-table snapshot, or forked after it, could hold the output open, so the test still reached its own timeout; and once the lane's bash had exited, its pid could name another process. The test now reads the lane's output as it comes. At 60 s the guard ends the lane's process tree only while its bash still runs, then stops reading and fails with what the lane printed. A process left behind stays in the test file's group, which scripts/ci-tests.ts ends after it.

coderabbitai · 2026-10-28T03:13:43Z

Warning

Review limit reached

You've used all free OSS reviews for now. Wait for the free limit to reset to keep reviewing this public repository.

Next included review available in 5 minutes.

Check out review usage here.

View limit details

Limit details: You’ve used all 4 included reviews currently available.

Learn how review limits work.

Review configuration:

Run configuration

Source mode: Auto
Repository: devswha/ovis
Branch: fix/timing-flakes-under-load
File: .coderabbit.yaml
Commit: fca3d9c
Layers: Repository YAML
Review profile: CHILL
Plan: Advanced
Run ID: 3ca0f5c9-0e4d-4e79-a228-51994d4f4900

Commits

Reviewing files that changed from the base of the PR and between 124e9b9 and fca3d9c.

Files selected for processing: 4

changelog.d/timing-flakes-under-load.md
scripts/ci-browser.test.ts
server/codex.test.ts
server/opencode.contract.test.ts

Autofix · Keep fixing CodeRabbit findings and required CI, and resolving merge conflicts

Thanks for using CodeRabbit! It's free for OSS, and your support helps us grow. If you like it, consider giving us a shout-out.

❤️ Share

_{Comment @coderabbitai help to get the list of available commands.}

devswha · 2026-10-28T03:14:04Z

CodeRabbit is rate-limited ("Review limit reached") and did not review this head (fca3d9c). Test-only PR: it was reviewed by omo-native-code-reviewer (PASS) and by Codex Sol 6.1 Fast xhigh in four rounds, with every MEDIUM/LOW fixed and the last round finding nothing. Details in the PR body.

devswha · 2026-10-28T03:33:39Z

Merging fca3d9c: omo-native-code-reviewer and Codex both pass this head. The change is test-only, adds no new fixed sleeps, and a mutation still fails each case. The required checks are green, and CodeRabbit did not review this head. omo's MEDIUM (direct runs without --timeout can hit Bun's 5 s default on a busy host; CI is unaffected) and the LOW notes go to a follow-up issue.

… same size (#2169) Follow-up to #2150. Addresses item 1 of #2155; the other #2155 items are left as they are. ## Change Test-only: `server/codex.test.ts`, plus the wording of #2150's unreleased changelog fragment. #2150's bounded-time cases compared the thread CPU time of a small input with that of an input five times larger. That growth still moved on busy hosts: - The unclosed-links case (3x as written, bound 8) read 10.8 on a GitHub runner and failed Fast checks on #2158, which does not touch this file ([run](https://github.com/devswha/ovis/actions/runs/40627909864)). - Under local load (`dori heavy`, six copies at a time alongside `bun run check fast`), the other two cases crossed their bounds as well: large answer 10.33 vs 10, citation 45.5 vs 40. Each case now compares its input with one **of the same size** that the code reads in one pass. The work both share (parsing, the screen) stays out of the ratio, while the regression's cost grows with the size: | case | subject | reference (same length) | as written | bound | regression | with it | |---|---|---|---|---|---|---| | unclosed links | 5 answers of 8,000 chars, all unclosed `](` | one closed link | 1.2-1.8 | 10 | `cutAtLinkTargets` as a regex split | 403-506 | | large answer | 40,000 links | one link | 1.4-9.4 | 20 | `cutAtLinkTargets` with `unshift` (work per link grows) | 145-247 | | citation | 1,000 unmatched backtick runs | `'` instead of backticks | 0.6-5.7 | 20 | each unmatched delimiter searches the rest of the line | 670 | The "as written" ranges cover every loaded run below. The helper (`cpuGrowth`, now `cpuRatio`) also takes a fix for a problem Codex reproduced, which predates this PR. Without a thread clock (Windows), `process.cpuUsage` counts in steps of about 16 ms, and only the first reference run was checked against the 20 ms floor. A later, warmer run could read 0, which made the ratio NaN or Infinity. The least reference of each set of three is now checked, and the set is timed again over twice the runs while it is too short. On that clock the floor is 100 ms. **#2155 item 1:** the three cases get a 30 s timeout, so direct runs without `--timeout` do not hit Bun's 5 s default on a busy host. The large-answer case also reads 8 candidates instead of 32: the ratio does not depend on the count, and with 32, six runs sharing two cores took up to 11.6 s. **Known limit:** a reference of the same size bounds the cost tied to what the regression reacts to (unclosed links, links, backtick runs). It does not catch a cost that grows with the text's length alone, which both inputs share. The doc comment says so. ## Proof SHAs below are from before the rebase onto bcd75e0, with no conflicts: f49d460e = ec224ec, 7f3515df = 057d4ed, 83412911 = a6780c6, ff480649 = baf772e. `bun run check fast` passed on the rebased head as well. All runs use this host's thread clock unless noted. Logs are in the lane's `.omo/run`. - **Load, final test code (83412911):** 30 rounds through `dori heavy`, alongside `bun run check fast`. Each round ran the real file without `--timeout` plus five ratio-logging copies at once. - 0 failures; 150 samples per case, the highest as follows. Unclosed links: max 1.78 (median 1.56). Large answer: max 9.42 (median 3.09). Citation: max 5.74 (median 1.45). - The direct runs passed 30 of 30 (75 tests each). The slowest matcher case took 963 ms. - The citation bound then went from 10 to 20 (ff480649). Only the bound changed, so these runs still hold. - **Two cores, six copies at a time** (`taskset`): 30 rounds and 0 failures (unclosed max 1.68, large max 8.03, citation max 3.46). - **Mutants:** each fails only its own case. - Regex split: 10 of 10 runs, at 403 to 506 against a bound of 10. - `unshift`: 145 to 247 against 20. - Citation tail search: 670 against 20. The other citation tests still pass with it. - **Coarse clock, modeled on Linux:** the thread clock is forced off and `process.cpuUsage` is floored to 15.625 ms per user/system counter, which is Codex's model. - On #2150's code, Codex measured 5 failures in 30 runs (NaN/Infinity). - With the fix: 30 runs, six at a time on two cores, 0 failures. Ratios: unclosed 1.25-1.82, citation 1.09-2.50, large 2.90-10.29. - The regex-split mutant still fails at 194. - **`bun run check fast`:** ok on ff480649 (7,904 pass, 0 fail). ## Reviews - **omo-native-code-reviewer (f49d460e):** PASS, LOW findings only. Changes made from them: the changelog no longer overclaims, and the known limit is in the doc comment. Left as follow-ups: LOW-1 (the large reference's GC share) has headroom under its bound; LOW-5 (neither link case reaches `matchShortCodexAnswers`'s second loop) was already true before this PR. - **Codex Sol 6.1 Fast xhigh:** - Round 1 (f49d460e): BLOCK on one MEDIUM, the coarse-clock zero reference above, which also reproduces on #2150. It is fixed in 7f3515df. Its LOW (changelog wording) is fixed too. - Round 2 (7f3515df): PASS, no open findings, and both earlier findings resolved. - It checked the helper under a controlled clock: a third reference that turns to 0 after calibration is discarded, then retimed over twice the runs. - It repeated the coarse-clock model: 36 of 36 cases passed, and no accepted reference was below 109.375 ms. - Not reviewed by Codex: the two commits after round 2 change only parameters, both measured above. - 83412911 doubles the unclosed answers to 8,000 characters. With 4,000, the regex split read as low as 85 under load. - ff480649 raises the citation bound from 10 to 20. - CodeRabbit is not needed: test-only change.

…when the icon font arrives (#2158) ## What it fixes The last two items of #2064 that #2074 left open. #2074 fixed every MEDIUM and most LOWs; its body lists these two as left as they are. - **Powerline separators redrew every row when the icon font arrived.** Separators U+E0B0-E0B7 are painted as boxes (`terminalBoxGlyphs.ts`), not taken from a font. Every drawn character still asked for its late faces, though, so a prompt whose only private-use characters are separators followed `Symbols Nerd Font Mono`'s face. When it arrived, the terminal measured again and drew every row again for nothing. - **The Hangul face's range test missed a broken range.** It checked only that the range held no Latin and covered the syllables, so dropping the compatibility jamo or adding `U+E000-F8FF` still passed. ## The change - `src/lib/terminalGlyphs.ts`: faces are asked for after the span is rebuilt. Characters painted as boxes (`isBoxGlyph`) in a span drawn as boxes ask *quietly* (`followLateFaces(...).ask(families, text, true)`): their faces are still followed, but an arrival that only they waited for measures and draws nothing again. xterm measured those characters with the stand-in too, though, so the first time one is drawn from the font instead (under the cursor, or with a joiner), the terminal measures again in the next frame. A single box under the cursor also gets its cell's spacing from the face at once, so even that first frame is not drawn at the stand-in's width. A character the font draws keeps asking as before: the cursor cell, a span with a joiner, Powerline's other shapes U+E0B8-E0D7 (drawn from the icon font), and the box-drawing diagonals U+2571-2573, which `BOX_GLYPHS` matches but `boxDrawing` leaves to the font. - `src/lib/fontFamily.test.ts`: asserts the exact `U+3131-318E, U+AC00-D7A3` for both weights. It also reads each woff2's cmap (a small brotli + format 4 reader in the test) and checks that it maps exactly those code points. Both files map 11,266 code points: 3131-318E and AC00-D7A3. ## Before and after Chrome (headless, the lockfile's build path) on an isolated test herdr session and a port-0 server. The pane prints `\ue0b0 main \ue0b1 abc \ue0b2\ue0b3`, the icon font's response is held until the first drawing, and the script counts how often xterm draws that row again after the face arrives. The script was QA-only and is not committed. | | separator row drawn again after the icon face arrived | icon font fetched | |---|---|---| | before #2062 (7eeb7d4) | 2 | yes | | main 38f0989 | 2 | yes | | this branch | 0 | yes | The icon font is still fetched: the page's own layout of the row text reaches it (it did before #2062 too), and this module starts no load since #2074. Skipping that fetch would mean taking the separators out of the text the browser lays out, which this PR does not do. ## #2064 items With #2074 this closes the issue: - Powerline separators fetching the icon font and redrawing every row: the redraw is fixed. The fetch comes from layout and predates #2062 (see above). - The exact-range assertion and the cmap check: done. ## Design reference No UI change. The rule follows #2062/#2074 (Zed and Warp size a cell from the font that draws it): a character that no font draws needs no late face. ## Checks - `bun test src/lib/terminalGlyphs.test.ts`: the new case "follows no face for Powerline's separators" **fails on main** (1 refresh instead of 0) and passes here. New cases also check: - an icon beside a separator and a box-drawing diagonal still follow their faces (the diagonal case fails if the skip uses `BOX_GLYPHS` instead of `isBoxGlyph`); - a box painted while its face loads, then drawn under the cursor or with a joiner after the face arrived, measures again once, and under the cursor takes its one cell at once. This is the merge pass's MEDIUM at d92c3a6. Its own reproduction with xterm's real `WidthCache` (13 cases) passes here. - `followLateFaces`: a quiet arrival measures nothing until a character it covers is drawn from it, then once; a face asked for by painted and font-drawn text measures again when it arrives. Each was checked against a mutation of the code it covers: dropping the rebuilt guard, the quiet re-measure, the quiet ask, the quiet-to-followed upgrade, or the cursor spacing each fails at least one case. - `src/lib/fontFamily.test.ts` fails under each mutation of the CSS: dropping `U+3131-318E`, or adding `U+E000-F8FF`. The cmap reader's output matches an independent scratch parser for both files. It also fails on Codex's malformed copies of both fonts, where U+3131's glyph-array entry plus `idDelta` is glyph 0; a reader that ignored the delta passed them. - `bun run check fast`: 7396ca78 passed in full (7912 unit tests, 0 fail). On a384522 (the same code minus one removed test, on newer main) and on 92e8cc3a the only local failure on 92e8cc3a was `server/codex.test.ts` "reads short answers in bounded time however many unclosed links" (11.8 against < 8), the ratio flake after #2150 that another lane is fixing; this PR does not touch that file. It also failed this PR's first CI run. - On the merge pass's fix: the Chrome QA above still draws the separator row 0 times after the icon arrives, and `scripts/terminal-late-faces-regression.ts` passes. ## Reviews - omo-native-code-reviewer: **PASS** (two LOW). LOW 1, diagonals skipped through `BOX_GLYPHS`, is fixed. LOW 2 was the cmap reader's glyph-0 reading: Codex found the concrete case, and it is fixed. - Merge pass at d92c3a6: one MEDIUM (a box painted while its face loaded kept xterm's stand-in width once drawn from the font under the cursor). Fixed as described above. - CodeRabbit: one comment on the changelog wording, applied. - Codex Sol on 92e8cc3a (the merge pass's fix): BLOCK on one MEDIUM. The quiet flag was read through a closure, which kept a stopped terminal alive through a face that never loads. Fixed: the arrival handler takes a plain entry. Codex's probes show the leak on 92e8cc3a and not on the fix. A WeakRef/`Bun.gc` unit test for it failed every run against the closure, but also failed 2 to 3 runs in 1000 on the fix (conservative stack scanning), so it was left out; the comment on `whenLoaded` states the rule. - Codex Sol re-review of that fix: the MEDIUM is fixed, no production finding; its only other finding was that flaky test, now removed. - Codex Sol 6.1 Fast xhigh, on fd6094f1: BLOCK on one MEDIUM (font-drawn diagonals lost late-face tracking) and one LOW (cmap `idDelta` on glyph-array entries). Both are fixed in this head. Its re-review of only the fix delta: **PASS**, no new findings. Closes #2064

devswha added 4 commits October 28, 2026 12:12

devswha merged commit 99547b0 into main Oct 28, 2026
19 checks passed

devswha deleted the fix/timing-flakes-under-load branch October 28, 2026 03:33

This was referenced Oct 28, 2026

fix(tests): follow-ups from the Codex bounded-time tests review (#2169) #2174

Closed

fix(chat): keep the focus on a todo update its run folds in, and show each update's own input and output (#1601) #2161

Merged

Navigation Menu

Repository navigation

fix(tests): measure what the code controls in three tests that failed on busy hosts - #2150

fix(tests): measure what the code controls in three tests that failed on busy hosts#2150
devswha merged 4 commits into
mainfrom
fix/timing-flakes-under-load

devswha commented Oct 28, 2026

Uh oh!

coderabbitai Bot commented Oct 28, 2026

Review limit reached

Uh oh!

devswha commented Oct 28, 2026

Uh oh!

devswha commented Oct 28, 2026

Uh oh!

Uh oh!

Reviewers

Uh oh!

Assignees

Labels

Projects

Milestone

Development

Uh oh!

1 participant

Conversation

devswha commented Oct 28, 2026

Change

scripts/ci-browser.test.ts (#2110)

server/codex.test.ts (#2142)

server/opencode.contract.test.ts (#2143)

Proof

Reviews

Uh oh!

coderabbitai Bot commented Oct 28, 2026

Review limit reached

Uh oh!

devswha commented Oct 28, 2026

Uh oh!

devswha commented Oct 28, 2026

Uh oh!

Uh oh!

Reviewers

Uh oh!

Assignees

Labels

Projects

Milestone

Development

Uh oh!

1 participant

`scripts/ci-browser.test.ts` (#2110)

`server/codex.test.ts` (#2142)

`server/opencode.contract.test.ts` (#2143)