What happens
Check (plugin) intermittently fails with tests that report this test timed out after 5000ms and nothing else. No assertion failure, no error message, no stack — just a wall-clock kill. The set of tests that fail changes between runs, and they pass on a re-run and in isolation.
Recent example on a PR branch: 3929 pass / 7 fail, all 7 timeouts, spread across four unrelated files (system-prompt-hash, inject-compartments, compaction-off-transition, storage-embedding-measurements). All four pass locally.
I originally read this as a slow runner, and want to show why that's wrong, because it's the reason the real cause is easy to miss:
| test |
local |
CI |
keeps project docs, user profile, and key files out… |
52 ms |
>5000 ms |
does NOT update systemPromptHash… |
47 ms |
>5000 ms |
injects the MINIMAL block for a subagent… |
45 ms |
>5000 ms |
invalidates cached marker reads after background writes… |
242 ms |
>5000 ms |
bounds a session's corpus rows… |
133 ms |
>5000 ms |
The CI runner is about 6.5× slower on this suite overall (668s vs 102s wall for the same 3926 tests). 6.5× on a 52 ms test is ~340 ms. These are 20–100× blowups. Nothing is slow; something is waiting.
Cause
Three things upstream combine, and each is individually reasonable:
-
packages/plugin/test-preload.ts:30 points every test at one database. It sets MAGIC_CONTEXT_TEST_DATA_DIR to a single temp dir, and resolveDatabasePath() (storage-db.ts:162-172) resolves a bare openDatabase() inside it. So every openDatabase() with no explicit path opens the same context.db. There are 491 such call sites across 54 test files.
-
storage-db.ts:711 sets PRAGMA busy_timeout=5000. Correct for production — the comment explains it guards a cold-open race between OpenCode/Pi startup and the subprocess lease tests.
-
bun test's default per-test timeout is also 5000ms, and packages/plugin/package.json's test script is a bare bun test with no --timeout.
All test files execute in one process (verified: two files report the same process.pid), so these connections are genuinely concurrent against one file.
When one connection holds a write lock and another wants it, SQLite blocks the second for the full busy_timeout. That's 5000ms — expiring at the same moment bun kills the test. The lock wait is never observed: bun's timeout fires first and reports a bare timeout instead of SQLITE_BUSY: database is locked.
The two 5000s are unrelated constants that happen to be equal, which is what makes the failure unattributable.
Reproduction (clean upstream/master, no fork code)
packages/plugin/src/zz-repro.test.ts:
import { test, expect } from "bun:test";
import { Database } from "bun:sqlite";
import { openDatabase, resolveDatabasePath } from "./features/magic-context/storage-db";
test("shared-DB lock contention surfaces as an undiagnosable test timeout", () => {
const seed = openDatabase(); // creates the shared context.db the preload points at
seed?.close();
const { dbPath } = resolveDatabasePath();
console.log(`REPRO shared_db=${dbPath}`);
const a = new Database(dbPath);
a.exec("PRAGMA busy_timeout=5000");
a.exec("PRAGMA journal_mode=WAL");
a.exec("CREATE TABLE IF NOT EXISTS zz(x)");
a.exec("BEGIN EXCLUSIVE"); // hold the write lock
const b = new Database(dbPath);
b.exec("PRAGMA busy_timeout=5000"); // what initializeDatabase sets
const t0 = Date.now();
try { b.exec("INSERT INTO zz VALUES (1)"); }
catch (e) { console.log(`REPRO blocked_ms=${Date.now() - t0} err=${(e as Error).message}`); }
expect(1).toBe(1);
});
REPRO shared_db=/tmp/mc-plugin-test-xdg-fcEEXR/cortexkit/magic-context/context.db
REPRO blocked_ms=5004 err=database is locked
(fail) shared-DB lock contention surfaces as an undiagnosable test timeout [5050.17ms]
^ this test timed out after 5000ms.
Both lines print: the lock wait and the timeout, at the same 5004/5050ms. In a real run only the second is visible.
Why CI and not local
Contention is a race. A faster machine narrows the window where two tests want the write lock simultaneously; a slower, more contended runner widens it. That explains the CI-only, non-deterministic, moves-around-between-runs signature — without requiring any test to actually be slow.
Suggested fixes
Not mutually exclusive; (1) alone converts every future instance from unattributable to self-explaining.
-
Decouple the two constants. Run the plugin suite with --timeout set to something clearly above busy_timeout (the E2E job already does this — ci.yml:317 uses --timeout 600000). A lock wait then surfaces as SQLITE_BUSY: database is locked with a real stack, instead of a bare wall-clock kill. Cheapest change, biggest diagnostic win.
-
Give each test file its own database. A per-file temp dir (or :memory: where the test doesn't need a real path) removes the contention rather than making it legible. Bigger change — 491 call sites — but it's the actual fix, and inject-compartments.test.ts already uses :memory: in one place as precedent.
-
Lower busy_timeout under test only, so a lock wait fails fast and loudly well inside the test budget. Least invasive to production semantics, but only helps if paired with (1) for the message to be readable.
Happy to send a PR for (1) — one line in packages/plugin/package.json — if you want to start there. (2) is worth its own change with a decision on the isolation mechanism first.
Environment
What happens
Check (plugin)intermittently fails with tests that reportthis test timed out after 5000msand nothing else. No assertion failure, no error message, no stack — just a wall-clock kill. The set of tests that fail changes between runs, and they pass on a re-run and in isolation.Recent example on a PR branch: 3929 pass / 7 fail, all 7 timeouts, spread across four unrelated files (
system-prompt-hash,inject-compartments,compaction-off-transition,storage-embedding-measurements). All four pass locally.I originally read this as a slow runner, and want to show why that's wrong, because it's the reason the real cause is easy to miss:
keeps project docs, user profile, and key files out…does NOT update systemPromptHash…injects the MINIMAL block for a subagent…invalidates cached marker reads after background writes…bounds a session's corpus rows…The CI runner is about 6.5× slower on this suite overall (668s vs 102s wall for the same 3926 tests). 6.5× on a 52 ms test is ~340 ms. These are 20–100× blowups. Nothing is slow; something is waiting.
Cause
Three things upstream combine, and each is individually reasonable:
packages/plugin/test-preload.ts:30points every test at one database. It setsMAGIC_CONTEXT_TEST_DATA_DIRto a single temp dir, andresolveDatabasePath()(storage-db.ts:162-172) resolves a bareopenDatabase()inside it. So everyopenDatabase()with no explicit path opens the samecontext.db. There are 491 such call sites across 54 test files.storage-db.ts:711setsPRAGMA busy_timeout=5000. Correct for production — the comment explains it guards a cold-open race between OpenCode/Pi startup and the subprocess lease tests.bun test's default per-test timeout is also 5000ms, andpackages/plugin/package.json's test script is a barebun testwith no--timeout.All test files execute in one process (verified: two files report the same
process.pid), so these connections are genuinely concurrent against one file.When one connection holds a write lock and another wants it, SQLite blocks the second for the full
busy_timeout. That's 5000ms — expiring at the same moment bun kills the test. The lock wait is never observed: bun's timeout fires first and reports a bare timeout instead ofSQLITE_BUSY: database is locked.The two 5000s are unrelated constants that happen to be equal, which is what makes the failure unattributable.
Reproduction (clean
upstream/master, no fork code)packages/plugin/src/zz-repro.test.ts:Both lines print: the lock wait and the timeout, at the same 5004/5050ms. In a real run only the second is visible.
Why CI and not local
Contention is a race. A faster machine narrows the window where two tests want the write lock simultaneously; a slower, more contended runner widens it. That explains the CI-only, non-deterministic, moves-around-between-runs signature — without requiring any test to actually be slow.
Suggested fixes
Not mutually exclusive; (1) alone converts every future instance from unattributable to self-explaining.
Decouple the two constants. Run the plugin suite with
--timeoutset to something clearly abovebusy_timeout(the E2E job already does this —ci.yml:317uses--timeout 600000). A lock wait then surfaces asSQLITE_BUSY: database is lockedwith a real stack, instead of a bare wall-clock kill. Cheapest change, biggest diagnostic win.Give each test file its own database. A per-file temp dir (or
:memory:where the test doesn't need a real path) removes the contention rather than making it legible. Bigger change — 491 call sites — but it's the actual fix, andinject-compartments.test.tsalready uses:memory:in one place as precedent.Lower
busy_timeoutunder test only, so a lock wait fails fast and loudly well inside the test budget. Least invasive to production semantics, but only helps if paired with (1) for the message to be readable.Happy to send a PR for (1) — one line in
packages/plugin/package.json— if you want to start there. (2) is worth its own change with a decision on the isolation mechanism first.Environment
upstream/master; all three ingredients are upstream code (test-preload.ts:30,storage-db.ts:711, pluginpackage.jsontest script)mock.modulebleed in Process-global mock.module in promotion.test.ts can hang unrelated tests under worker sharding #279 — the four files still usingmock.moduleare upstream-identical, and none of the timing-out suites import from them