Skip to content
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
28 changes: 24 additions & 4 deletions src/lib/db/core.ts
Original file line number Diff line number Diff line change
Expand Up @@ -529,10 +529,20 @@ declare global {
var __omnirouteDbOomFailureCount: number | undefined;
}

function checkpointDb(db: SqliteDatabase, mode: CheckpointMode = "TRUNCATE"): boolean {
// `wal_checkpoint(mode)` always returns exactly one row of {busy, log, checkpointed}
// (see https://www.sqlite.org/pragma.html#pragma_wal_checkpoint). busy != 0 means
// SQLite could not get the lock this mode needs (for TRUNCATE: full exclusivity --
// any other open connection, reader or not, blocks it) and the WAL was NOT shrunk,
// no matter how many frames "checkpointed" reports. This used to be ignored, so
// callers always reported "completed" even when TRUNCATE silently no-oped -- on a
// server that is rarely fully idle, that hid a WAL that grew unboundedly (observed
// live: an 11.7 GB WAL file, nearly as large as the 11 GB main database it shadows).
export function checkpointDb(db: SqliteDatabase, mode: CheckpointMode = "TRUNCATE"): boolean {
if (isCloud || isBuildPhase || !SQLITE_FILE) return false;
db.pragma(`wal_checkpoint(${mode})`);
return true;
const [result] = db.pragma(`wal_checkpoint(${mode})`) as [
{ busy: number; log: number; checkpointed: number },
];
return result?.busy === 0;
}

function summarizePreservedTables(tables: PreservedTableSnapshot[]): string {
Expand Down Expand Up @@ -995,9 +1005,15 @@ function startWalTruncateScheduler(db: SqliteDatabase) {
try {
if (!db.open) return;
// TRUNCATE waits for readers; under concurrent write load it can no-op without
// shrinking the file. That is expected — it retries on the next tick.
// shrinking the file. That is expected — it retries on the next tick. Log the
// no-op case too (previously silent) so a WAL that never finds an idle moment
// is visible in the logs instead of looking identical to a healthy server.
if (checkpointDb(db, "TRUNCATE")) {
console.log("[DB] Periodic SQLite WAL checkpoint completed (TRUNCATE).");
} else {
console.log(
"[DB] Periodic SQLite WAL checkpoint deferred (TRUNCATE busy -- a concurrent connection held the lock it needs); will retry next tick."
);
}
} catch (error: unknown) {
const message = error instanceof Error ? error.message : String(error);
Expand Down Expand Up @@ -1429,6 +1445,10 @@ export function closeDbInstance(options?: { checkpointMode?: CheckpointMode | nu
try {
if (checkpointDb(db, checkpointMode)) {
console.log(`[DB] SQLite WAL checkpoint completed (${checkpointMode}).`);
} else {
console.warn(
`[DB] SQLite WAL checkpoint did not fully complete during close (${checkpointMode}) -- another connection held the lock it needs; the WAL file may remain large.`
);
}
} catch (error: unknown) {
const message = error instanceof Error ? error.message : String(error);
Expand Down
88 changes: 88 additions & 0 deletions tests/unit/db-wal-checkpoint-busy-detection.test.ts
Original file line number Diff line number Diff line change
@@ -0,0 +1,88 @@
// checkpointDb() used to call `wal_checkpoint(mode)` and unconditionally return true,
// ignoring the {busy, log, checkpointed} row the pragma always returns. On a server
// that is rarely fully idle, wal_checkpoint(TRUNCATE) regularly comes back busy=1 --
// it got SOME lock to copy frames back into the main file, but not the exclusive one
// TRUNCATE needs to shrink the file -- yet callers logged "completed" every time
// anyway. Observed live: an 11.7 GB WAL file, nearly as large as the 11 GB main
// database it shadows, with the periodic scheduler's own logs claiming success the
// entire time.
//
// checkpointDb() itself isn't gated by isAutomatedTestProcess() (only the scheduler
// wrapper around it is -- see db-wal-truncate-scheduler.test.ts, which pins that
// wiring via source inspection since the scheduler can't run in this harness). This
// exercises the real function against a real WAL-mode SQLite file and a genuinely
// busy second connection, the same way SQLite itself reports busy=1 in production.

import test from "node:test";
import assert from "node:assert/strict";
import fs from "node:fs";
import os from "node:os";
import path from "node:path";
import Database from "better-sqlite3";

const TEST_DATA_DIR = fs.mkdtempSync(path.join(os.tmpdir(), "omniroute-wal-checkpoint-"));
process.env.DATA_DIR = TEST_DATA_DIR;

const core = await import("../../src/lib/db/core.ts");

function makeWalDb(): { file: string; db: InstanceType<typeof Database> } {
const dir = fs.mkdtempSync(path.join(os.tmpdir(), "omniroute-wal-checkpoint-db-"));
const file = path.join(dir, "test.sqlite");
const db = new Database(file);
db.pragma("journal_mode = WAL");
// better-sqlite3 defaults busy_timeout to 5000ms, which would make the busy-path
// assertions below block for 5s each retrying a lock they're deliberately testing
// will not become available -- 0 makes SQLITE_BUSY come back immediately.
db.pragma("busy_timeout = 0");
db.exec("CREATE TABLE t (id INTEGER PRIMARY KEY, v TEXT)");
db.exec("INSERT INTO t (v) VALUES ('hello')");
return { file, db };
}

test("checkpointDb reports failure (not success) when TRUNCATE cannot get the lock it needs", () => {
const { file, db } = makeWalDb();

// A second connection with an open read transaction reproduces the real
// "server never fully idle" condition that let this bug hide in production --
// reads happen continuously, so TRUNCATE's exclusivity requirement is rarely met.
const reader = new Database(file);
reader.exec("BEGIN");
reader.prepare("SELECT * FROM t").get();

assert.equal(
core.checkpointDb(db, "TRUNCATE"),
false,
"must report failure while a concurrent reader holds the file open"
);
assert.notEqual(
fs.statSync(`${file}-wal`).size,
0,
"the WAL file must NOT have been truncated while busy"
);

reader.exec("COMMIT");
reader.close();
db.close();
});

test("checkpointDb reports success once TRUNCATE actually gets exclusivity", () => {
const { file, db } = makeWalDb();

const reader = new Database(file);
reader.exec("BEGIN");
reader.prepare("SELECT * FROM t").get();
assert.equal(core.checkpointDb(db, "TRUNCATE"), false);

// Committing (even without closing the connection) releases the lock TRUNCATE needs.
reader.exec("COMMIT");

assert.equal(
core.checkpointDb(db, "TRUNCATE"),
true,
"must report success once no connection holds a blocking lock"
);
assert.equal(fs.statSync(`${file}-wal`).size, 0, "the WAL file must be truncated to zero");

reader.close();
db.close();
});
Loading