fix(db): install busy_timeout before the connection's first statement (#12394)

getDbInstance() ran PRAGMA journal_mode = WAL as the connection's first statement, before PRAGMA busy_timeout, and openSqliteDatabase() passes no driver-level timeout. A process opening the database while another closed its WAL connection — checkpoint plus WAL delete hold an EXCLUSIVE lock for a few hundred microseconds — therefore died with `database is locked` instead of waiting. That is the flake behind exclusive-connection-leases.test.ts on release/v3.8.51 runs 33525300898 and 33493797519 and on unrelated PR runs.

The second half is worse than the flake: isTransientProbeError matched /SQLITE_BUSY/ against error.message, but both drivers report the plain text `database is locked` and put the code in .code / .errcode. A transient lock during the corruption probe therefore took the corrupt-database path and renamed the file to storage.sqlite.probe-failed-… with "Manual recovery required". The probe now recognises the drivers' real BUSY/PROTOCOL/IOERR signals.

Validated in a combined worktree with all 25 PRs of this batch boarded together: typecheck:core clean, 443/443 node-runner tests plus 14/14 vitest across every test file the batch touches, and check-changelog-integrity, check:cycles (418 files), check:provider-consistency (272 REGISTRY entries, 355 canonical providers), check:docs-counts, check:docs-sync (42 locales) and check-file-size all green.

Thanks @pacocartones.
This commit is contained in:
Paco Cartones
2026-09-02 08:13:41 +02:00
committed by GitHub
parent bb5c6d148e
commit c8e2cb3ffc
4 changed files with 138 additions and 2 deletions

View File

@@ -0,0 +1 @@
- **fix(db):** install `busy_timeout` before the SQLite connection's first statement so a process opening the database while another one closes its WAL connection waits out the transient EXCLUSIVE lock instead of dying with `database is locked`, and recognise the drivers' real BUSY/PROTOCOL/IOERR errors as transient in the corruption probe so the same lock no longer renames the database away as corrupt; deflakes `cross-process contenders never both acquire the same connection` (#12394 — thanks @pacocartones)

View File

@@ -1277,13 +1277,18 @@ export function getDbInstance(): SqliteDatabase {
// selected on the server's primary DB path too, not only the backup-import
// route.
console.log(`[DB] Driver: ${db.driver} | file: ${sqliteFile}`);
db.pragma("journal_mode = WAL");
// better-sqlite3 is synchronous, so a contended write parks the Node event loop for up to
// busy_timeout ms (a 0-CPU freeze that stacks under load → /health stops responding). The
// hot-path writers here (usage_history, call_logs) are best-effort and the WinUI host opens
// the same DB, so cap the block at 2s instead of 5s: normal writes complete in <1ms, and a
// contended op can no longer freeze the loop past the host watchdog's 6s liveness probe.
//
// Install the busy handler before the connection's first statement. `journal_mode = WAL`
// needs a SHARED lock, and another process closing its WAL connection briefly holds the
// file EXCLUSIVE (checkpoint + WAL delete); node:sqlite opens with busy timeout 0, so with
// the pragmas in the other order that window surfaced as `database is locked` at startup.
db.pragma("busy_timeout = 2000");
db.pragma("journal_mode = WAL");
db.pragma("synchronous = NORMAL");
db.pragma(`cache_size = -${DEFAULT_DATABASE_SETTINGS.optimization.cacheSize}`);
db.pragma("temp_store = MEMORY");

View File

@@ -22,7 +22,19 @@ import path from "node:path";
*/
export function isTransientProbeError(error: unknown): boolean {
const message = error instanceof Error ? error.message : String(error);
return /SQLITE_BUSY|SQLITE_PROTOCOL|SQLITE_IOERR|ENOENT/i.test(message);
if (/SQLITE_BUSY|SQLITE_PROTOCOL|SQLITE_IOERR|ENOENT|database is locked/i.test(message)) {
return true;
}
// The real drivers do not put the result-code name in the message: both
// report plain "database is locked" for SQLITE_BUSY. better-sqlite3 carries
// the name in `code`, node:sqlite the numeric primary code in `errcode`
// (5 BUSY, 10 IOERR, 15 PROTOCOL; extended codes live in the high bits).
// Without this, a transient lock during the probe was classified as
// corruption and the database was renamed away.
if (typeof error !== "object" || error === null) return false;
const { code, errcode } = error as { code?: unknown; errcode?: unknown };
if (typeof code === "string" && /^SQLITE_(BUSY|PROTOCOL|IOERR)/.test(code)) return true;
return typeof errcode === "number" && [5, 10, 15].includes(errcode & 0xff);
}
/**

View File

@@ -0,0 +1,118 @@
import assert from "node:assert/strict";
import { spawn } from "node:child_process";
import fs from "node:fs";
import os from "node:os";
import path from "node:path";
import { DatabaseSync } from "node:sqlite";
import test from "node:test";
// Regression for the "cross-process contenders never both acquire the same
// connection" flake (tests/unit/exclusive-connection-leases.test.ts): the
// faster contender exited while the slower one was still opening, and a
// closing WAL connection briefly takes an EXCLUSIVE lock on the database file
// (checkpoint + WAL delete). getDbInstance() issued `PRAGMA journal_mode = WAL`
// — the connection's first statement, which needs a SHARED lock — *before*
// installing the busy handler, so on node:sqlite (busy timeout 0 by default)
// the slower process died with `database is locked` instead of waiting the few
// milliseconds the lock is held. The corruption probe that runs first had the
// same gap: it only recognised BUSY when the driver put "SQLITE_BUSY" in the
// message, which neither node:sqlite nor better-sqlite3 does, so a transient
// lock there renamed the database away as corrupt.
//
// The holder below reproduces the lock deterministically (WAL + EXCLUSIVE
// locking mode keeps the file lock from the first read until close) and
// releases it only after the child has reached getDbInstance(), so the open
// path meets the lock on every run and must wait it out via busy_timeout.
const CORE_URL = new URL("../../src/lib/db/core.ts", import.meta.url).href;
// Longer than the probe's first transient-retry delay (500ms), so the main
// open still meets the lock after the probe has retried; well inside the
// 2000ms busy_timeout getDbInstance() configures, so the fixed open waits it
// out instead of timing out.
const HOLD_MS = 1200;
type ChildResult = { code: number | null; stdout: string; stderr: string };
function runChild(script: string, env: Record<string, string>): Promise<ChildResult> {
return new Promise((resolve, reject) => {
const child = spawn(
process.execPath,
["--import", "tsx/esm", "--input-type=module", "-e", script],
{
cwd: process.cwd(),
env: { ...process.env, ...env },
stdio: ["ignore", "pipe", "pipe"],
}
);
let stdout = "";
let stderr = "";
child.stdout.setEncoding("utf8").on("data", (chunk) => (stdout += chunk));
child.stderr.setEncoding("utf8").on("data", (chunk) => (stderr += chunk));
child.once("error", reject);
child.once("exit", (code) => resolve({ code, stdout, stderr }));
});
}
async function waitForFile(file: string, timeoutMs: number): Promise<void> {
const deadline = Date.now() + timeoutMs;
while (!fs.existsSync(file)) {
if (Date.now() > deadline) throw new Error(`timed out waiting for ${file}`);
await new Promise((resolve) => setTimeout(resolve, 5));
}
}
test("getDbInstance() waits out a transient exclusive file lock instead of failing on its first statement", async () => {
const dataDir = fs.mkdtempSync(path.join(os.tmpdir(), "omniroute-open-busy-"));
const sqliteFile = path.join(dataDir, "storage.sqlite");
const ready = path.join(dataDir, "ready");
const env = { DATA_DIR: dataDir, OPEN_READY_FILE: ready };
let holder: DatabaseSync | null = null;
try {
// Seed a real database (schema + migrations) so the corruption probe in
// getDbInstance() sees a healthy file rather than a skeleton.
const seed = await runChild(
`const core = await import(${JSON.stringify(CORE_URL)}); core.getDbInstance(); core.closeDbInstance();`,
env
);
assert.equal(seed.code, 0, seed.stderr);
// Hold the database file's EXCLUSIVE lock from another connection, exactly
// what a closing WAL connection holds while it checkpoints and deletes the WAL.
holder = new DatabaseSync(sqliteFile);
holder.exec("PRAGMA locking_mode = EXCLUSIVE");
holder.prepare("SELECT count(*) AS n FROM sqlite_master").get();
const opener = runChild(
[
`import fs from "node:fs";`,
`const core = await import(${JSON.stringify(CORE_URL)});`,
`fs.writeFileSync(process.env.OPEN_READY_FILE, "ready");`,
`const busyTimeout = core.getDbInstance().pragma("busy_timeout", { simple: true });`,
`core.closeDbInstance();`,
`process.stdout.write(JSON.stringify({ busyTimeout }) + "\\n");`,
].join("\n"),
env
);
await waitForFile(ready, 30_000);
await new Promise((resolve) => setTimeout(resolve, HOLD_MS));
holder.close();
holder = null;
const result = await opener;
assert.equal(result.code, 0, `open failed under a transient lock: ${result.stderr}`);
// The probe may log that it met the lock; what must not happen is the
// corruption path (rename + manual-recovery abort) or a failed main open.
assert.doesNotMatch(result.stderr, /Renamed corrupt DB|probe-failed|Manual recovery/);
assert.deepEqual(
fs.readdirSync(dataDir).filter((name) => name.includes("probe-failed")),
[],
"a transient lock must not rename the database away as corrupt"
);
const summary = result.stdout.match(/^\{"busyTimeout":(\d+)\}$/m);
assert.ok(summary, `child did not report its busy timeout: ${result.stdout}`);
assert.equal(Number(summary[1]), 2000);
} finally {
holder?.close();
fs.rmSync(dataDir, { recursive: true, force: true, maxRetries: 5, retryDelay: 100 });
}
});