Skip to content

fix(runtime): retry the sqlite WAL switch under the busy timeout; await MCP session admission in tests - #567

Merged
ScriptedAlchemy merged 4 commits into
mainfrom
fix/ci-flakes-sqlite-session
Sep 5, 2026
Merged

fix(runtime): retry the sqlite WAL switch under the busy timeout; await MCP session admission in tests#567
ScriptedAlchemy merged 4 commits into
mainfrom
fix/ci-flakes-sqlite-session

Conversation

@ScriptedAlchemy

@ScriptedAlchemy ScriptedAlchemy commented Sep 5, 2026

Copy link
Copy Markdown
Owner

Eliminates two intermittent Verify (Node 24) failures at their root cause. Each was observed in the last 40 CI runs and previously "fixed" by a blind re-run (~10–13 min per occurrence).

Flake A — packages/rsc-runtime/tests/state-sqlite-cross-process.test.ts

Symptom (run 33926598550, attempt 1): a writer child exits 1 with
AgentStateError: State 'state-cross-process/tasks' storage stayed locked beyond the busy timeout (configure storage), cause database is locked (SQLITE_BUSY), thrown from dist/state/sqlite.js:627:20 — which is exactly db.exec('PRAGMA journal_mode = WAL').

Root causepackages/rsc-runtime/src/state/sqlite.ts (SqliteStore#initialize, formerly lines 929–936). The driver already set PRAGMA busy_timeout before switching to WAL, so hypotheses (1)/(2) as literally stated were not it. The actual rule is SQLite's own (pager.c, sqlite3PagerSetBusyhandler): the busy handler is invoked only for the NO_LOCK → SHARED and RESERVED → EXCLUSIVE lock transitions, never for SHARED → RESERVED (deadlock avoidance). PRAGMA journal_mode = WAL on a rollback-mode file runs sqlite3BtreeSetVersion, which opens a read transaction (SHARED) and then upgrades it to a write (RESERVED) to rewrite header bytes 18–19. When a second process is mid-switch and holds RESERVED, that upgrade returns SQLITE_BUSY immediately, regardless of busy_timeout. The window is the duration of one fsync-bounded write transaction, which is why it shows on loaded CI runners with slow disks and almost never locally.

Proof, in-process (a second connection holding BEGIN IMMEDIATE on the fresh file, busy_timeout = 300):

WAL switch failed after 0 ms   (busy_timeout=300): errcode=5 database is locked
BEGIN IMMEDIATE failed after 302 ms (busy_timeout=300): errcode=5 database is locked   ← control: honoured

Fix (production code, sqlite.ts): split the three PRAGMAs and wrap only the WAL switch in Effect.retrywalSwitchRetries(busyTimeoutMs): Schedule.spaced(min(5 ms, busyTimeoutMs)) recurring only while the next attempt still starts inside busyTimeoutMs (Schedule.while(({ duration, elapsed }) => elapsed + duration <= busyTimeoutMs)), retrying only while the mapped error's cause is SQLITE_BUSY. Once the header says WAL, the statement is a plain read and never contends again, so the retry is confined to the first-ever open of a file (or a legacy rollback-mode file). Same knob, same budget, same unavailable error when it runs out. Extended result codes (SQLITE_BUSY_*, SQLITE_CORRUPT_*) are now compared by primary code (errcode & 0xff), so the retry predicate and mapSqliteError agree on what "busy" means.

Regression tests (packages/rsc-runtime/tests/state-sqlite.test.ts): waits for another process mid-WAL-switch instead of failing the first open (fails on the unfixed driver with expected 'failed' to be 'pending' — the CI failure in miniature) and fails the first open as unavailable once the WAL switch outlives busyTimeoutMs (pins the budget bound for budgets of 100 ms and 1 ms — the latter below the retry pause).

Reproduction counts (two/three node children opening + configuring the same fresh file behind a wall-clock start barrier, 50 iterations each):

harness before after
raw node:sqlite, driver's statement order, 2 writers 19–20/50 failed, all at journal_mode 0/50 (17 writers needed ≥1 retry)
raw node:sqlite, 3 writers 21/50 0/50 (32 writers needed ≥1 retry)
raw node:sqlite, file pre-switched to WAL (control) 0/50
built driver (dist), 2 writers 6/50 — exact CI message 0/50
built driver (dist), 3 writers 0/50
the test file itself, 30 runs (unbarriered children; this box has 96 cores + NVMe) 0/30 (also 0/20 pinned to 2 cores with 3 CPU burners) 0/30

The test file never reproduced locally without the barrier; the barrier harnesses are the reliable trigger and the built-driver row shows the identical AgentStateError CI printed.

Flake B — packages/agent-bundle/tests/mcp-session-service.test.ts

Symptom (run 33915324117): expected [] to have a length of 1 but got +0 at line 1138.

Root cause — test-only. Lines 1137 and 1150 slept 10 ms as a stand-in for "the first callTool has been admitted and its abort signal registered"; line 272 slept 25 ms as a stand-in for "the hang request is admitted so cancel() returns true". McpSession#callTool runs #assertEpochCurrentEffect() (an async epoch-store probe) before #admitRequest, all inside an Effect runtime, so under CI load 10 ms is not enough.

Fix: the stub client's callTool now resolves an admission promise (nextAdmission()) on entry, after pushing the signal and the release; the test awaits that instead of sleeping. For the real fixture server, toolCallSent(session, 'hang') subscribes to the session trace and resolves when the client-direction tools/call frame for that tool is put on the wire (the request slot is admitted before the SDK sends, so cancel() finds it). mcp-session-routes.test.ts (the only sibling; there is no mcp-session.test.ts) contains no such sleeps. Test-only, so agent-bundle is not named in the changeset.

Counts: 30 runs before (0/30 locally, concurrent with the sqlite loop) → 30 runs after (0/30, concurrent with pnpm typecheck and the sqlite loop). Not reproducible on this machine; the change removes the timing assumption rather than widening it.

Gate

pnpm build && pnpm typecheck && pnpm lint && pnpm test:unit — 3578 passed, 0 failed, 6 skipped. Both target files also run individually 30× post-fix (above). No website/docs change: no hand-written page documents busyTimeoutMs or the open phase, the error text is unchanged, and @agent-bundle/runtime is outside the TypeDoc surface.

Self-review

Reviewer: change-risk-reviewer subagent, model gpt-5.6-sol-medium, asked for concrete merge risks only against the diff vs origin/main.

# Finding Disposition
1 sqlite.ts retry schedule: Schedule.upTo({ duration }) compares elapsed before sleeping the next interval, so an attempt could start up to one 5 ms pause past busyTimeoutMs, and a budget below 5 ms still waited 5 ms. Fixed in a025ba1: walSwitchRetries(busyTimeoutMs) clamps the pause to min(5 ms, busyTimeoutMs) and recurs only while elapsed + nextDelay <= busyTimeoutMs; the budget regression test now also covers busyTimeoutMs: 1.

Categories the reviewer checked and found clean: other SHARED→RESERVED upgrades or busy_timeout bypasses in the open path (none — BEGIN IMMEDIATE and BEGIN DEFERRED acquire from NO_LOCK, which the busy handler covers), extended-result-code mapping, public ./state/sqlite surface and error semantics, the mcp-session trace-subscription synchronization (toolCallSent cannot resolve early, match a stale frame, or leak — afterSequence is the current cursor and finally unsubscribes), the 50 ms Promise.race in the new pending-open test (neither outcome is reachable while the lock is held: the switch cannot succeed and the 5 s default budget cannot expire), changeset, and docs parity.

Second pass after the fix (same reviewer, same model): no concrete merge risks remain.

…it MCP session admission in tests

Two CI flakes in `Verify (Node 24)`, each fixed at its root cause.

state-sqlite-cross-process: `PRAGMA journal_mode = WAL` on a rollback-mode
database upgrades a read transaction to a write (SHARED -> RESERVED), the
one lock transition SQLite never routes through the busy handler, so two
processes racing the first open of a state file failed SQLITE_BUSY at once
regardless of `busy_timeout`. The driver now retries that single statement
for up to `busyTimeoutMs`; once the header says WAL the statement is a plain
read and never contends again. Extended result codes map by primary code.

mcp-session-service: the 10 ms / 25 ms sleeps standing in for "the call has
been admitted" are replaced by an admission promise resolved from inside the
stub client, and by a trace subscription that resolves when the `tools/call`
frame is put on the wire.
@changeset-bot

changeset-bot Bot commented Sep 5, 2026

Copy link
Copy Markdown

🦋 Changeset detected

Latest commit: d36cb68

The changes in this PR will be included in the next version bump.

This PR includes changesets to release 1 package
Name Type
@agent-bundle/runtime Patch

Not sure what this means? Click here to learn what changesets are.

Click here if you're a maintainer who wants to add another changeset to this PR

@chatgpt-codex-connector

Copy link
Copy Markdown

You have reached your Codex usage limits for code reviews. You can see your limits in the Codex usage dashboard.
To continue using code reviews, add credits to your account and enable them for code reviews in your settings.

@pkg-pr-new

pkg-pr-new Bot commented Sep 5, 2026

Copy link
Copy Markdown
npm i https://pkg.pr.new/ScriptedAlchemy/agent-bundle@567
npm i https://pkg.pr.new/ScriptedAlchemy/agent-bundle/create-agent-bundle@567
npm i https://pkg.pr.new/ScriptedAlchemy/agent-bundle/rsc-markdown-stream@567
npm i https://pkg.pr.new/ScriptedAlchemy/agent-bundle/@agent-bundle/runtime@567

commit: d36cb68

ScriptedAlchemy and others added 2 commits September 5, 2026 00:12
Schedule.upTo compared elapsed time before sleeping the next interval, so
an attempt could start up to one pause past the budget (and a budget below
5 ms still waited 5 ms). Clamp the pause to the budget and recur only while
the next attempt starts inside it. Self-review finding on #567.
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.

1 participant