diff --git a/changelog.d/fixes/12853-wal-maintenance-extraction.md b/changelog.d/fixes/12853-wal-maintenance-extraction.md new file mode 100644 index 0000000000..eabeb66866 --- /dev/null +++ b/changelog.d/fixes/12853-wal-maintenance-extraction.md @@ -0,0 +1 @@ +- **fix(db):** WAL maintenance lives in its own module: a `TRUNCATE` checkpoint that hits a busy database now warns with its streak and retries once via `PASSIVE` instead of logging success, and closing-time checkpoints no longer report success on builds without a database file, with the busy totals visible in the authenticated monitoring health payload ([#12853](https://github.com/diegosouzapw/OmniRoute/pull/12853)) diff --git a/docs/reference/ENVIRONMENT.md b/docs/reference/ENVIRONMENT.md index da053f1db3..f357f73584 100644 --- a/docs/reference/ENVIRONMENT.md +++ b/docs/reference/ENVIRONMENT.md @@ -101,7 +101,7 @@ OmniRoute uses **SQLite** (via `better-sqlite3`) for all persistence. These vari | `OMNIROUTE_CRYPT_KEY` | _(unset)_ | `src/lib/db/encryption.ts` | **Legacy alias** for `STORAGE_ENCRYPTION_KEY`. Accepted as a fallback when the primary variable is absent. | | `OMNIROUTE_API_KEY_BASE64` | _(unset)_ | `src/lib/db/encryption.ts` | **Legacy alias** (Base64-encoded form) accepted as a fallback. Decoded automatically before use. | | `OMNIROUTE_DB_HEALTHCHECK_INTERVAL_MS` | _(unset)_ | `src/lib/db/core.ts` | Override the periodic SQLite healthcheck interval (ms). When unset, defaults are derived from `NODE_ENV`. | -| `OMNIROUTE_WAL_TRUNCATE_INTERVAL_MS` | `21600000` (6h) | `src/lib/db/core.ts` | Override the periodic `wal_checkpoint(TRUNCATE)` interval (ms). Auto-checkpoint never shrinks the WAL file itself, and a long-running server never closes its DB. `0` disables. | +| `OMNIROUTE_WAL_TRUNCATE_INTERVAL_MS` | `21600000` (6h) | `src/lib/db/walMaintenance.ts` | Override the periodic `wal_checkpoint(TRUNCATE)` interval (ms). Auto-checkpoint never shrinks the WAL file itself, and a long-running server never closes its DB. `0` disables. | | `OMNIROUTE_SKIP_DB_HEALTHCHECK` | `0` | `src/lib/db/core.ts`, `src/lib/db/healthCheck.ts` | Set to `1` to skip the DB healthcheck entirely on startup. Useful for short-lived tasks and integration tests. | | `OMNIROUTE_FORCE_DB_HEALTHCHECK` | `0` | `src/lib/db/core.ts` | Set to `1` to force the DB healthcheck loop on, even when it would normally be skipped (e.g., short-lived tasks). | | `OMNIROUTE_SKIP_POSTINSTALL` | `0` | `scripts/postinstall.mjs` | Set to `1` to skip the native-runtime warm-up during `npm install`. Useful in CI/headless installs where sqlite is already built. | diff --git a/src/app/api/monitoring/health/route.ts b/src/app/api/monitoring/health/route.ts index c859ad7bdd..08f3cf04bd 100644 --- a/src/app/api/monitoring/health/route.ts +++ b/src/app/api/monitoring/health/route.ts @@ -1,6 +1,7 @@ import { NextResponse } from "next/server"; import { getProviderConnections } from "@/lib/db/providers"; import { getCachedSettings } from "@/lib/db/readCache"; +import { getWalMaintenanceState } from "@/lib/db/walMaintenance"; import { buildHealthPayload } from "@/lib/monitoring/observability"; import { readRunningBuildSha } from "@/lib/monitoring/buildSha"; import { APP_CONFIG } from "@/shared/constants/config"; @@ -241,6 +242,10 @@ async function rebuildHealthPayload(): Promise { null ) : null; + // #12853: WAL maintenance state (ticks/busy streak + totals) next to the + // admission gates. getWalMaintenanceState never throws and never touches + // the DB — a monitoring read stays cheap. Additive key, nothing moves. + const walMaintenance = readHealthValue("wal maintenance", () => getWalMaintenanceState(), null); const payload = buildHealthPayload({ appVersion: APP_CONFIG.version, @@ -266,6 +271,7 @@ async function rebuildHealthPayload(): Promise { credentialHealth, adaptiveAdmission, chatAdmission, + walMaintenance, }); if (generation === healthPayloadCacheGeneration) { diff --git a/src/lib/db/core.ts b/src/lib/db/core.ts index c8ba9b1f18..3c3769c066 100644 --- a/src/lib/db/core.ts +++ b/src/lib/db/core.ts @@ -41,6 +41,14 @@ import { rowToCamel } from "./caseMapping"; import { isAutomatedTestProcess } from "@/shared/utils/testProcess"; import { parseModelAccessMode } from "./apiKeys/modelAccessMode"; import { getExistingDbInstance as getDb, setDbInstance as setDb } from "./singleton"; +import type { WalCheckpointMode } from "./walMaintenance"; +import { + startWalMaintenance, + stopWalMaintenance, + runCheckpointNow, + getWalMaintenanceState, + logCheckpointOutcome, +} from "./walMaintenance"; // Re-exported so existing call sites that pull these helpers off the core module keep working. export { toSnakeCase, toCamelCase, objToSnake, rowToCamel, cleanNulls } from "./caseMapping"; import { @@ -55,7 +63,6 @@ import { type SqliteDatabase = SqliteAdapter; type JsonRecord = Record; -type CheckpointMode = "PASSIVE" | "FULL" | "RESTART" | "TRUNCATE"; type DatabaseOptimizationSettings = DatabaseSettings["optimization"]; type PreservedTableSnapshot = { table: string; @@ -529,12 +536,6 @@ declare global { var __omnirouteDbOomFailureCount: number | undefined; } -function checkpointDb(db: SqliteDatabase, mode: CheckpointMode = "TRUNCATE"): boolean { - if (isCloud || isBuildPhase || !SQLITE_FILE) return false; - db.pragma(`wal_checkpoint(${mode})`); - return true; -} - function summarizePreservedTables(tables: PreservedTableSnapshot[]): string { if (tables.length === 0) return "none"; return tables.map((table) => `${table.table}(${table.rowCount})`).join(", "); @@ -962,50 +963,9 @@ function startDbHealthCheckScheduler(db: SqliteDatabase) { dbHealthCheckTimer.unref?.(); } -let walTruncateTimer: NodeJS.Timeout | null = null; - -function getWalTruncateIntervalMs(): number { - const rawValue = process.env.OMNIROUTE_WAL_TRUNCATE_INTERVAL_MS; - if (typeof rawValue === "string" && rawValue.trim().length > 0) { - const parsed = Number(rawValue); - if (Number.isFinite(parsed) && parsed >= 0) { - return parsed; - } - } - return 6 * 60 * 60 * 1000; -} - -function clearWalTruncateScheduler() { - if (walTruncateTimer) { - clearInterval(walTruncateTimer); - walTruncateTimer = null; - } -} - // Auto-checkpoint moves WAL pages back into the main DB file but never shrinks the WAL // file itself; only wal_checkpoint(TRUNCATE) does, and a long-running server never closes its DB. -function startWalTruncateScheduler(db: SqliteDatabase) { - clearWalTruncateScheduler(); - if (isCloud || isBuildPhase || isAutomatedTestProcess()) return; - - const intervalMs = getWalTruncateIntervalMs(); - if (intervalMs <= 0) return; - - walTruncateTimer = setInterval(() => { - 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. - if (checkpointDb(db, "TRUNCATE")) { - console.log("[DB] Periodic SQLite WAL checkpoint completed (TRUNCATE)."); - } - } catch (error: unknown) { - const message = error instanceof Error ? error.message : String(error); - console.warn("[DB] Periodic WAL truncate failed:", message); - } - }, intervalMs); - walTruncateTimer.unref?.(); -} +// The scheduler lives in ./walMaintenance (periodic TRUNCATE + busy warn + PASSIVE retry). export function runManagedDbHealthCheck(options?: { autoRepair?: boolean }) { const db = getDbInstance(); @@ -1390,7 +1350,7 @@ export function getDbInstance(): SqliteDatabase { } startDbHealthCheckScheduler(db); - startWalTruncateScheduler(db); + startWalMaintenance(db, SQLITE_FILE); // Log the resolved absolute DATA_DIR + SQLITE_FILE once at init so a // multi-replica / Docker volume-topology mismatch (each replica opening a // different on-disk DB → "phantom"/missing combos & connections) is @@ -1416,9 +1376,10 @@ export function pingDb(): boolean { } } -export function closeDbInstance(options?: { checkpointMode?: CheckpointMode | null }): boolean { +export function closeDbInstance(options?: { checkpointMode?: WalCheckpointMode | null }): boolean { clearDbHealthCheckScheduler(); - clearWalTruncateScheduler(); + const streakBefore = getWalMaintenanceState().busyStreak; + stopWalMaintenance(); const db = getDb(); if (!db) return false; @@ -1427,9 +1388,12 @@ export function closeDbInstance(options?: { checkpointMode?: CheckpointMode | nu try { if (checkpointMode) { try { - if (checkpointDb(db, checkpointMode)) { - console.log(`[DB] SQLite WAL checkpoint completed (${checkpointMode}).`); - } + const outcome = runCheckpointNow(db, checkpointMode, { + sqliteFile: SQLITE_FILE, + isCloud, + isBuildPhase, + }); + logCheckpointOutcome(outcome, checkpointMode, streakBefore); } catch (error: unknown) { const message = error instanceof Error ? error.message : String(error); console.warn(`[DB] WAL checkpoint failed during close (${checkpointMode}):`, message); diff --git a/src/lib/db/walMaintenance.ts b/src/lib/db/walMaintenance.ts new file mode 100644 index 0000000000..8dfad87bad --- /dev/null +++ b/src/lib/db/walMaintenance.ts @@ -0,0 +1,236 @@ +import { isAutomatedTestProcess } from "@/shared/utils/testProcess"; +import { isNextBuildPhase } from "../buildPhase"; +import type { SqliteAdapter } from "./adapters/types"; +import { registerDbStateResetter } from "./stateReset"; + +/** + * WAL maintenance owns the periodic `wal_checkpoint(TRUNCATE)` lifecycle that + * used to live inside `core.ts`: interval parsing, the scheduler, and reading + * the pragma result so a busy checkpoint warns instead of logging success. + */ +export type WalCheckpointMode = "PASSIVE" | "FULL" | "RESTART" | "TRUNCATE"; + +export interface WalCheckpointOutcome { + ok: boolean; + busy: boolean; + skipped: boolean; + logFrames: number | null; + checkpointedFrames: number | null; + error: string | null; +} + +export interface WalCheckpointContext { + sqliteFile?: string | null; + isCloud?: boolean; + isBuildPhase?: boolean; +} + +export interface WalMaintenanceState { + ticks: number; + busyStreak: number; + busyTotal: number; + lastBusyAt: string | null; + lastOkAt: string | null; +} + +const isCloud = typeof globalThis.caches === "object" && globalThis.caches !== null; + +const DEFAULT_WAL_TRUNCATE_INTERVAL_MS = 6 * 60 * 60 * 1000; +const RETRY_DELAY_MS = 60_000; + +let walTimer: NodeJS.Timeout | null = null; +let retryTimer: NodeJS.Timeout | null = null; +let ticks = 0; +let busyStreak = 0; +let busyTotal = 0; +let lastBusyAt: string | null = null; +let lastOkAt: string | null = null; + +function recordBusy(): void { + busyStreak++; + busyTotal++; + lastBusyAt = new Date().toISOString(); +} + +function recordOk(): void { + busyStreak = 0; + lastOkAt = new Date().toISOString(); +} + +function toFiniteNumber(value: unknown): number | null { + const num = Number(value); + return Number.isFinite(num) ? num : null; +} + +function failOpen(): WalCheckpointOutcome { + return { + ok: true, + busy: false, + skipped: false, + logFrames: null, + checkpointedFrames: null, + error: null, + }; +} + +function parseCheckpointRow(result: unknown): WalCheckpointOutcome { + const row = Array.isArray(result) ? result[0] : result; + if (row === undefined || row === null) return failOpen(); + if (typeof row !== "object") return failOpen(); + const record = row as Record; + const busy = toFiniteNumber(record.busy); + const logFrames = toFiniteNumber(record.log); + const checkpointedFrames = toFiniteNumber(record.checkpointed); + if (busy === null || logFrames === null || checkpointedFrames === null) return failOpen(); + return { + ok: busy !== 1, + busy: busy === 1, + skipped: false, + logFrames, + checkpointedFrames, + error: null, + }; +} + +export function runCheckpointNow( + db: SqliteAdapter, + mode: WalCheckpointMode = "TRUNCATE", + ctx: WalCheckpointContext = {} +): WalCheckpointOutcome { + if (ctx.sqliteFile === null || ctx.isCloud === true || ctx.isBuildPhase === true) { + return { + ok: false, + busy: false, + skipped: true, + logFrames: null, + checkpointedFrames: null, + error: null, + }; + } + try { + return parseCheckpointRow(db.pragma(`wal_checkpoint(${mode})`)); + } catch (error: unknown) { + const message = error instanceof Error ? error.message : String(error); + return { + ok: false, + busy: false, + skipped: false, + logFrames: null, + checkpointedFrames: null, + error: message, + }; + } +} + +export function getWalMaintenanceIntervalMs(env: NodeJS.ProcessEnv = process.env): number { + const rawValue = env.OMNIROUTE_WAL_TRUNCATE_INTERVAL_MS; + if (typeof rawValue === "string" && rawValue.trim().length > 0) { + const parsed = Number(rawValue); + if (Number.isFinite(parsed) && parsed >= 0) { + return parsed; + } + } + return DEFAULT_WAL_TRUNCATE_INTERVAL_MS; +} + +export function logCheckpointOutcome( + outcome: WalCheckpointOutcome, + mode: WalCheckpointMode, + streak: number +): void { + if (outcome.skipped) return; + if (outcome.busy) { + console.warn( + `[DB] SQLite WAL checkpoint busy — ${outcome.logFrames} frames pending (streak ${streak})` + ); + return; + } + if (!outcome.ok) { + console.warn( + `[DB] SQLite WAL checkpoint failed (${mode}): ${outcome.error ?? "unknown error"}` + ); + return; + } + console.log(`[DB] SQLite WAL checkpoint completed (${mode})`); +} + +function schedulePassiveRetry(db: SqliteAdapter): void { + if (retryTimer) return; + retryTimer = setTimeout(() => { + retryTimer = null; + try { + if (isCloud || isNextBuildPhase() || isAutomatedTestProcess()) return; + if (!db.open) return; + const outcome = runCheckpointNow(db, "PASSIVE"); + if (outcome.skipped) return; + if (outcome.busy) { + recordBusy(); + logCheckpointOutcome(outcome, "PASSIVE", busyStreak); + } else if (outcome.ok) { + recordOk(); + } else { + logCheckpointOutcome(outcome, "PASSIVE", busyStreak); + } + } catch { + // A periodic retry must never throw into the event loop. + } + }, RETRY_DELAY_MS); + retryTimer.unref?.(); +} + +export function startWalMaintenance( + db: SqliteAdapter, + sqliteFile: string | null, + env: NodeJS.ProcessEnv = process.env +): void { + stopWalMaintenance(); + if (sqliteFile === null || isCloud || isNextBuildPhase() || isAutomatedTestProcess()) return; + const intervalMs = getWalMaintenanceIntervalMs(env); + if (intervalMs <= 0) return; + walTimer = setInterval(() => { + try { + if (!db.open) return; + const outcome = runCheckpointNow(db, "TRUNCATE"); + if (outcome.skipped) return; + ticks++; + if (outcome.busy) { + recordBusy(); + logCheckpointOutcome(outcome, "TRUNCATE", busyStreak); + schedulePassiveRetry(db); + } else if (outcome.ok) { + recordOk(); + } else { + logCheckpointOutcome(outcome, "TRUNCATE", busyStreak); + } + } catch { + // A periodic scheduler must never throw into the event loop. + } + }, intervalMs); + walTimer.unref?.(); +} + +export function stopWalMaintenance(): void { + if (walTimer) { + clearInterval(walTimer); + walTimer = null; + } + if (retryTimer) { + clearTimeout(retryTimer); + retryTimer = null; + } + ticks = 0; + busyStreak = 0; + busyTotal = 0; + lastBusyAt = null; + lastOkAt = null; +} + +export function getWalMaintenanceState(): WalMaintenanceState { + return { ticks, busyStreak, busyTotal, lastBusyAt, lastOkAt }; +} + +export function __resetForTests(): void { + stopWalMaintenance(); +} + +registerDbStateResetter(stopWalMaintenance); diff --git a/src/lib/monitoring/observability.ts b/src/lib/monitoring/observability.ts index 747afa0b91..91854bde4a 100644 --- a/src/lib/monitoring/observability.ts +++ b/src/lib/monitoring/observability.ts @@ -4,6 +4,7 @@ import { } from "@omniroute/open-sse/services/codexAccount/index.ts"; import type { AdaptiveAdmissionPublicSnapshot } from "@omniroute/open-sse/services/admission/runtime.ts"; import type { PerConnectionAdmissionController } from "@/shared/middleware/chatBodyAdmission"; +import type { WalMaintenanceState } from "@/lib/db/walMaintenance"; type JsonRecord = Record; @@ -37,6 +38,32 @@ export type ChatAdmissionHealthSummary = { countCapEnabled: boolean; }; +/** + * WAL maintenance health summary (#12853) — the periodic TRUNCATE lifecycle + * from walMaintenance.ts. Fixed low-cardinality shape, never raw-spread. + */ +export type WalMaintenanceSnapshot = Pick< + WalMaintenanceState, + "ticks" | "busyStreak" | "busyTotal" | "lastBusyAt" | "lastOkAt" +>; + +/** + * Explicit allowlisted projection of the WAL maintenance state. + * Copies only the documented scalar fields — no timers, no internals. + */ +export function projectWalMaintenanceSummary( + state: WalMaintenanceState | null | undefined +): WalMaintenanceSnapshot | null { + if (!state || typeof state !== "object") return null; + return { + ticks: state.ticks, + busyStreak: state.busyStreak, + busyTotal: state.busyTotal, + lastBusyAt: state.lastBusyAt, + lastOkAt: state.lastOkAt, + }; +} + /** * Explicit allowlisted projection of the structural admission snapshot. * Never spreads the snapshot — only the documented low-cardinality fields pass. @@ -217,6 +244,8 @@ interface BuildHealthPayloadOptions { adaptiveAdmission?: AdaptiveAdmissionPublicSnapshot | null; /** #11244: optional structural chat-admission snapshot; projected, never raw-spread. */ chatAdmission?: ChatAdmissionSnapshot | null; + /** #12853: optional WAL maintenance snapshot; projected, never raw-spread. */ + walMaintenance?: WalMaintenanceSnapshot | null; } function limitMonitors(monitors: QuotaMonitorSnapshot[], maxItems = 8): QuotaMonitorSnapshot[] { @@ -405,6 +434,7 @@ export function buildHealthPayload({ credentialHealth, adaptiveAdmission = null, chatAdmission = null, + walMaintenance = null, buildSha = null, }: BuildHealthPayloadOptions) { const timestamp = new Date().toISOString(); @@ -510,6 +540,9 @@ export function buildHealthPayload({ // #11244: the STRUCTURAL gate (chatBodyAdmission.ts) next to the adaptive one — // distinct key so clients reading `adaptiveAdmission` are untouched. chatAdmission: projectChatAdmissionSummary(chatAdmission), + // #12853: WAL maintenance next to the admission gates — additive key, + // nothing existing moves. + walMaintenance: projectWalMaintenanceSummary(walMaintenance), dedup: { inflightRequests, }, diff --git a/tests/unit/db-wal-truncate-scheduler.test.ts b/tests/unit/db-wal-truncate-scheduler.test.ts index cbd93cde7e..5d2d310b01 100644 --- a/tests/unit/db-wal-truncate-scheduler.test.ts +++ b/tests/unit/db-wal-truncate-scheduler.test.ts @@ -17,24 +17,22 @@ function readSource(relativePath: string): string { } const CORE_PATH = "src/lib/db/core.ts"; +const MAINTENANCE_PATH = "src/lib/db/walMaintenance.ts"; test("a periodic WAL truncate scheduler is started when the DB instance boots", () => { const source = readSource(CORE_PATH); assert.match( source, - /startWalTruncateScheduler\(db\)/, - "getDbInstance() must start the WAL truncate scheduler alongside the DB health-check scheduler" + /startWalMaintenance\(db/, + "getDbInstance() must start the WAL maintenance scheduler alongside the DB health-check scheduler" ); }); test("the WAL truncate scheduler runs wal_checkpoint(TRUNCATE), not a lighter mode", () => { - const source = readSource(CORE_PATH); - const fnStart = source.indexOf("function startWalTruncateScheduler"); - assert.notEqual(fnStart, -1, "startWalTruncateScheduler must exist"); - const fnBody = source.slice(fnStart, fnStart + 1200); + const source = readSource(MAINTENANCE_PATH); assert.match( - fnBody, - /checkpointDb\(db, "TRUNCATE"\)/, + source, + /wal_checkpoint\(TRUNCATE\)/, "the scheduled checkpoint must request TRUNCATE mode — a lighter mode would not shrink the WAL file" ); }); @@ -47,13 +45,13 @@ test("the WAL truncate scheduler is cleared on close, like the health-check sche assert.match(fnBody, /clearDbHealthCheckScheduler\(\)/); assert.match( fnBody, - /clearWalTruncateScheduler\(\)/, - "closeDbInstance() must clear the WAL truncate timer so it does not outlive the DB handle" + /stopWalMaintenance\(\)/, + "closeDbInstance() must stop the WAL maintenance timer so it does not outlive the DB handle" ); }); test("the truncate interval is overridable via OMNIROUTE_WAL_TRUNCATE_INTERVAL_MS", () => { - const source = readSource(CORE_PATH); + const source = readSource(MAINTENANCE_PATH); assert.match( source, /OMNIROUTE_WAL_TRUNCATE_INTERVAL_MS/, @@ -62,14 +60,10 @@ test("the truncate interval is overridable via OMNIROUTE_WAL_TRUNCATE_INTERVAL_M }); test("the scheduler self-gates the same way the DB health-check scheduler does", () => { - const source = readSource(CORE_PATH); - const fnStart = source.indexOf("function startWalTruncateScheduler"); - const fnBody = source.slice(fnStart, fnStart + 300); - assert.match( - fnBody, - /isCloud \|\| isBuildPhase \|\| isAutomatedTestProcess\(\)/, - "must not run during cloud/build/test contexts, same as startDbHealthCheckScheduler" - ); + const source = readSource(MAINTENANCE_PATH); + assert.match(source, /isCloud/); + assert.match(source, /isNextBuildPhase\(\)/); + assert.match(source, /isAutomatedTestProcess\(\)/); }); test("the new env var is documented", () => { @@ -80,3 +74,47 @@ test("the new env var is documented", () => { "docs/reference/ENVIRONMENT.md must document the new env var (check:env-doc-sync)" ); }); + +test("close carries the busy streak into the checkpoint log", () => { + const source = readSource(CORE_PATH); + const fnStart = source.indexOf("export function closeDbInstance"); + assert.notEqual(fnStart, -1, "closeDbInstance must exist"); + const fnBody = source.slice(fnStart, fnStart + 1200); + assert.match(fnBody, /getWalMaintenanceState\(\)\.busyStreak/); + assert.match(fnBody, /runCheckpointNow\(db, checkpointMode, \{/); + assert.match(fnBody, /logCheckpointOutcome\(outcome, checkpointMode, streakBefore\)/); +}); + +test("periodic schedulers log the error path (ok:false, busy:false)", () => { + const source = readSource(MAINTENANCE_PATH); + const periodic = source.slice(source.indexOf("function schedulePassiveRetry")); + const truncateLogs = ( + periodic.match(/logCheckpointOutcome\(outcome, "TRUNCATE", busyStreak\)/g) ?? [] + ).length; + const passiveLogs = ( + periodic.match(/logCheckpointOutcome\(outcome, "PASSIVE", busyStreak\)/g) ?? [] + ).length; + assert.ok( + truncateLogs >= 2, + `periodic TRUNCATE scheduler must log busy AND error outcomes (found ${truncateLogs} log calls)` + ); + assert.ok( + passiveLogs >= 2, + `PASSIVE retry scheduler must log busy AND error outcomes (found ${passiveLogs} log calls)` + ); +}); + +test("close reads the busy streak BEFORE stopping maintenance (streak otherwise always 0)", () => { + const source = readSource(CORE_PATH); + const fnStart = source.indexOf("export function closeDbInstance"); + assert.notEqual(fnStart, -1, "closeDbInstance must exist"); + const fnBody = source.slice(fnStart, fnStart + 1200); + const streakIdx = fnBody.indexOf("getWalMaintenanceState().busyStreak"); + const stopIdx = fnBody.indexOf("stopWalMaintenance()"); + assert.notEqual(streakIdx, -1, "closeDbInstance must read busyStreak"); + assert.notEqual(stopIdx, -1, "closeDbInstance must stop maintenance"); + assert.ok( + streakIdx < stopIdx, + "streakBefore must be captured before stopWalMaintenance() resets busyStreak to 0" + ); +}); diff --git a/tests/unit/observability-payloads.test.ts b/tests/unit/observability-payloads.test.ts index 05bc8f6b76..210308f12d 100644 --- a/tests/unit/observability-payloads.test.ts +++ b/tests/unit/observability-payloads.test.ts @@ -7,6 +7,7 @@ import { buildTelemetryPayload, projectAdaptiveAdmissionSummary, projectChatAdmissionSummary, + projectWalMaintenanceSummary, } from "../../src/lib/monitoring/observability.ts"; test("buildSessionsSummary returns sticky counts and ordered top sessions", () => { @@ -416,3 +417,55 @@ test("buildHealthPayload projects allowlisted structural chatAdmission fields on assert.equal(projectChatAdmissionSummary(null), null); assert.equal(projectChatAdmissionSummary(undefined), null); }); + +test("buildHealthPayload projects allowlisted walMaintenance fields only", () => { + const state = { + ticks: 4, + busyStreak: 1, + busyTotal: 2, + lastBusyAt: "2026-09-06T10:00:00.000Z", + lastOkAt: "2026-09-06T11:00:00.000Z", + // Internal keys that must never leak into the public payload. + walTimer: { _idleTimeout: 1 }, + retryTimer: null, + } as unknown as import("../../src/lib/monitoring/observability.ts").WalMaintenanceSnapshot; + + const payload = buildHealthPayload({ + appVersion: "9.9.9", + settings: { setupComplete: false }, + connections: [], + circuitBreakers: [], + rateLimitStatus: {}, + learnedLimits: {}, + lockouts: {}, + localProviders: {}, + inflightRequests: 0, + quotaMonitorSummary: { + active: 0, + alerting: 0, + exhausted: 0, + errors: 0, + statusCounts: { starting: 0, idle: 0, healthy: 0, warning: 0, exhausted: 0, error: 0 }, + byProvider: {}, + }, + quotaMonitorMonitors: [], + activeSessions: [], + walMaintenance: state, + }); + + assert.deepEqual(payload.walMaintenance, { + ticks: 4, + busyStreak: 1, + busyTotal: 2, + lastBusyAt: "2026-09-06T10:00:00.000Z", + lastOkAt: "2026-09-06T11:00:00.000Z", + }); + + const json = JSON.stringify(payload); + assert.equal(json.includes("walTimer"), false); + assert.equal(json.includes("retryTimer"), false); + + // Absent / null state projects to null (degraded path parity). + assert.equal(projectWalMaintenanceSummary(null), null); + assert.equal(projectWalMaintenanceSummary(undefined), null); +}); diff --git a/tests/unit/wal-maintenance.test.ts b/tests/unit/wal-maintenance.test.ts new file mode 100644 index 0000000000..8447de2829 --- /dev/null +++ b/tests/unit/wal-maintenance.test.ts @@ -0,0 +1,166 @@ +import test from "node:test"; +import assert from "node:assert/strict"; +import { runCheckpointNow, logCheckpointOutcome } from "../../src/lib/db/walMaintenance.ts"; + +function fakeDb(result: unknown, throws?: string) { + return { + pragma: (_s: string) => { + if (throws) throw new Error(throws); + return result; + }, + }; +} + +test("busy row reports busy, not ok", () => { + const out = runCheckpointNow(fakeDb([{ busy: 1, log: 5, checkpointed: 5 }]) as never); + assert.equal(out.ok, false); + assert.equal(out.busy, true); +}); + +test("clean row reports ok", () => { + const out = runCheckpointNow(fakeDb([{ busy: 0, log: 0, checkpointed: 12 }]) as never); + assert.equal(out.ok, true); + assert.equal(out.busy, false); + assert.equal(out.logFrames, 0); + assert.equal(out.checkpointedFrames, 12); +}); + +test("sentinel -1 row is success, not busy", () => { + const out = runCheckpointNow(fakeDb([{ busy: 0, log: -1, checkpointed: -1 }]) as never); + assert.equal(out.ok, true); + assert.equal(out.busy, false); +}); + +test("bare object tolerated", () => { + const out = runCheckpointNow(fakeDb({ busy: 0, log: 0, checkpointed: 3 }) as never); + assert.equal(out.ok, true); +}); + +test("undefined, null, [] fail open", () => { + for (const shape of [undefined, null, []]) { + const out = runCheckpointNow(fakeDb(shape) as never); + assert.equal(out.ok, true); + assert.equal(out.busy, false); + } +}); + +test("bun:sqlite checkpoint shape parses (array of one row)", async (t) => { + if (!process.versions.bun) { + t.skip("bun:sqlite is only available under Bun"); + return; + } + const { Database } = await import("bun:sqlite"); + const { createBunSqliteAdapter } = await import("../../src/lib/db/adapters/bunSqliteAdapter.ts"); + const adapter = createBunSqliteAdapter(new Database(":memory:"), ":memory:"); + t.after(() => adapter.close()); + const out = runCheckpointNow(adapter, "TRUNCATE"); + assert.equal(out.ok, true); + assert.equal(out.busy, false); +}); + +test("pragma throw never propagates", () => { + const out = runCheckpointNow(fakeDb(undefined, "database is locked") as never); + assert.equal(out.ok, false); + assert.match(out.error ?? "", /database is locked/); +}); + +test("error outcome (ok:false, busy:false) is logged as a failure, not swallowed", () => { + const warnings: string[] = []; + const origWarn = console.warn; + console.warn = (...args: unknown[]) => { + warnings.push(args.map(String).join(" ")); + }; + try { + logCheckpointOutcome( + { + ok: false, + busy: false, + skipped: false, + logFrames: null, + checkpointedFrames: null, + error: "boom", + }, + "TRUNCATE", + 0 + ); + assert.ok( + warnings.some((line) => line.includes("WAL checkpoint failed")), + `expected a "WAL checkpoint failed" warn, got: ${JSON.stringify(warnings)}` + ); + } finally { + console.warn = origWarn; + } +}); + +test("guarded ctx skips without calling pragma", () => { + let called = 0; + const db = { + pragma: (_s: string) => { + called++; + return [{ busy: 0, log: 0, checkpointed: 0 }]; + }, + }; + const out = runCheckpointNow(db as never, "TRUNCATE", { sqliteFile: null }); + assert.equal(out.skipped, true); + assert.equal(called, 0); +}); + +test("interval defaults to 6h, rejects garbage, honors 0", async () => { + const { getWalMaintenanceIntervalMs } = await import("../../src/lib/db/walMaintenance.ts"); + assert.equal(getWalMaintenanceIntervalMs({} as NodeJS.ProcessEnv), 6 * 60 * 60 * 1000); + assert.equal( + getWalMaintenanceIntervalMs({ + OMNIROUTE_WAL_TRUNCATE_INTERVAL_MS: "nope", + } as NodeJS.ProcessEnv), + 6 * 60 * 60 * 1000 + ); + assert.equal( + getWalMaintenanceIntervalMs({ + OMNIROUTE_WAL_TRUNCATE_INTERVAL_MS: "60000", + } as NodeJS.ProcessEnv), + 60000 + ); + assert.equal( + getWalMaintenanceIntervalMs({ OMNIROUTE_WAL_TRUNCATE_INTERVAL_MS: "0" } as NodeJS.ProcessEnv), + 0 + ); +}); + +test("__resetForTests zeroes state", async () => { + const mod = await import("../../src/lib/db/walMaintenance.ts"); + mod.__resetForTests(); + assert.deepEqual(mod.getWalMaintenanceState(), { + ticks: 0, + busyStreak: 0, + busyTotal: 0, + lastBusyAt: null, + lastOkAt: null, + }); +}); + +test("start is silent and stateless under the test-process gate", async () => { + const mod = await import("../../src/lib/db/walMaintenance.ts"); + mod.__resetForTests(); + const db = { open: true, pragma: (_s: string) => [{ busy: 0, log: 0, checkpointed: 0 }] }; + mod.startWalMaintenance(db as never, "/tmp/fake.sqlite"); + assert.deepEqual(mod.getWalMaintenanceState(), { + ticks: 0, + busyStreak: 0, + busyTotal: 0, + lastBusyAt: null, + lastOkAt: null, + }); + mod.__resetForTests(); + mod.__resetForTests(); + assert.deepEqual(mod.getWalMaintenanceState(), { + ticks: 0, + busyStreak: 0, + busyTotal: 0, + lastBusyAt: null, + lastOkAt: null, + }); +}); + +test.beforeEach(async () => { + (await import("../../src/lib/db/walMaintenance.ts")).__resetForTests(); +});