fix(indexing): HDD-class storage — false parse timeouts, dropped files, and WAL checkpoint write-back (#1231) (#1242)
Parse timeouts are now judged by the worker's own clock: the base timer only marks a job late (after a long synchronous store stall, Node runs the timers phase before the poll phase, so the timer fired before an already-delivered result was processed — killing workers over parses that took milliseconds, even on 0-byte files); a result arriving before a 3× hard-kill backstop is accepted, timed-out files are retried, and CODEGRAPH_PARSE_TIMEOUT_MS overrides the budget. Grammar WASM bytes are pre-read once on the main thread and handed to every worker, so spawns/respawns load grammars from memory instead of re-reading a saturated disk. Bulk indexing defers WAL auto-checkpointing for the whole run: the default 1000-page interval re-writes hot B-tree/FTS pages into the main DB file over and over — ~95% of all disk I/O under throttled measurement. A WalCheckpointValve bounds WAL growth with off-thread PASSIVE backfill passes (never blocking the writer or the #850 watchdog heartbeat), pauses the writer for a full backfill if the disk truly can't keep up, and folds the WAL at the parse→resolution boundary so post-parse reads never page a bulk-write-sized WAL. Opt out with CODEGRAPH_NO_WAL_DEFER=1; tune with CODEGRAPH_WAL_VALVE_MB. Measured at 150 IOPS (HDD class): commons-lang 1526s → 59s with 0 dropped files (was 8); guava-scale completes in 7.6 min with a full graph where v1.3.1 needed 25 min for a repo 5× smaller. Unthrottled: no change. Co-authored-by: Claude Fable 5 <noreply@anthropic.com>
This commit is contained in:
Colby Mchenry
co-authored by
Claude Fable 5
Claude Fable 5
parent
e76a355df5
commit
a11a439002
+113
-7
@@ -189,6 +189,98 @@ export class DatabaseConnection {
|
||||
return stats.size;
|
||||
}
|
||||
|
||||
/**
|
||||
* Size of the `-wal` sidecar file in bytes. 0 when it doesn't exist (non-WAL
|
||||
* journal mode, in-memory DB, or no write since the last checkpoint+reset).
|
||||
*/
|
||||
getWalSizeBytes(): number {
|
||||
if (!this.dbPath || this.dbPath === ':memory:') return 0;
|
||||
try {
|
||||
return fs.statSync(`${this.dbPath}-wal`).size;
|
||||
} catch {
|
||||
return 0;
|
||||
}
|
||||
}
|
||||
|
||||
/** Current `wal_autocheckpoint` interval in pages (0 = disabled). */
|
||||
getWalAutocheckpoint(): number {
|
||||
const v = this.db.pragma('wal_autocheckpoint', { simple: true });
|
||||
const n = Number(v);
|
||||
return Number.isFinite(n) ? n : 0;
|
||||
}
|
||||
|
||||
/**
|
||||
* Set the connection's `wal_autocheckpoint` interval (pages; 0 disables).
|
||||
* Bulk indexing defers checkpoints entirely (#1231): the default 1000-page
|
||||
* auto-checkpoint re-writes hot B-tree/FTS pages into the main DB file over
|
||||
* and over — measured at ~95% of ALL disk I/O during a bulk index, and the
|
||||
* difference between 45s and 19+ minutes on HDD-class storage. During
|
||||
* deferral a {@link WalCheckpointValve} bounds WAL growth off-thread.
|
||||
*/
|
||||
setWalAutocheckpoint(pages: number): void {
|
||||
this.db.pragma(`wal_autocheckpoint = ${Math.max(0, Math.floor(pages))}`);
|
||||
}
|
||||
|
||||
/**
|
||||
* `PRAGMA wal_checkpoint(PASSIVE)` on a worker thread with its own
|
||||
* connection. PASSIVE never blocks the writer, and running it off-thread
|
||||
* means the main thread — and the #850 watchdog heartbeat — keep turning
|
||||
* even when the backfill is minutes of I/O on slow storage (a synchronous
|
||||
* checkpoint that exceeds the watchdog's 60s window gets a healthy index
|
||||
* SIGKILLed — observed in the #1231 repro).
|
||||
*
|
||||
* Returns SQLite's checkpoint result row — `log === checkpointed` with
|
||||
* `busy === 0` means the ENTIRE WAL was backfilled, so the writer's next
|
||||
* commit restarts the WAL from the top and the file stops growing. The
|
||||
* WAL valve needs that signal because a WAL file's SIZE never shrinks:
|
||||
* after the first wrap, raw file size says nothing about the un-backfilled
|
||||
* backlog. Best-effort: returns null on any failure (including worker
|
||||
* threads being unavailable — a potentially minutes-long checkpoint must
|
||||
* never run inline on the main thread).
|
||||
*/
|
||||
async checkpointWalPassive(): Promise<{ busy: number; log: number; checkpointed: number } | null> {
|
||||
if (!this.dbPath || this.dbPath === ':memory:') {
|
||||
try {
|
||||
const row = this.db.prepare('PRAGMA wal_checkpoint(PASSIVE)').get() as Record<string, number> | undefined;
|
||||
return row ? { busy: Number(row.busy), log: Number(row.log), checkpointed: Number(row.checkpointed) } : null;
|
||||
} catch {
|
||||
return null;
|
||||
}
|
||||
}
|
||||
try {
|
||||
const { Worker } = await import('node:worker_threads');
|
||||
const workerSource = `
|
||||
const { workerData, parentPort } = require('node:worker_threads');
|
||||
let row = null;
|
||||
try {
|
||||
const { DatabaseSync } = require('node:sqlite');
|
||||
const db = new DatabaseSync(workerData.dbPath);
|
||||
try { row = db.prepare('PRAGMA wal_checkpoint(PASSIVE)').get(); } catch {}
|
||||
try { db.close(); } catch {}
|
||||
} catch {}
|
||||
parentPort.postMessage({ row });
|
||||
`;
|
||||
return await new Promise((resolve) => {
|
||||
let settled = false;
|
||||
const finish = (row?: Record<string, number> | null): void => {
|
||||
if (settled) return;
|
||||
settled = true;
|
||||
resolve(row ? { busy: Number(row.busy), log: Number(row.log), checkpointed: Number(row.checkpointed) } : null);
|
||||
};
|
||||
try {
|
||||
const worker = new Worker(workerSource, { eval: true, workerData: { dbPath: this.dbPath } });
|
||||
worker.once('message', (m: { row?: Record<string, number> | null }) => { void worker.terminate(); finish(m?.row ?? null); });
|
||||
worker.once('error', () => { void worker.terminate(); finish(null); });
|
||||
worker.once('exit', () => finish(null));
|
||||
} catch {
|
||||
finish(null);
|
||||
}
|
||||
});
|
||||
} catch {
|
||||
return null;
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Optimize database (vacuum and analyze)
|
||||
*/
|
||||
@@ -233,6 +325,22 @@ export class DatabaseConnection {
|
||||
try { this.db.exec('PRAGMA wal_checkpoint(PASSIVE)'); } catch { /* ignore */ }
|
||||
return;
|
||||
}
|
||||
await this.runPragmasOffThread(
|
||||
['PRAGMA analysis_limit=1000', 'PRAGMA optimize', 'PRAGMA wal_checkpoint(PASSIVE)'],
|
||||
// Worker threads unavailable — bounded in-line fallback, no checkpoint.
|
||||
['PRAGMA analysis_limit=1000', 'PRAGMA optimize']
|
||||
);
|
||||
}
|
||||
|
||||
/**
|
||||
* Run pragmas on a worker thread against its own connection to this DB
|
||||
* (shared machinery for {@link runMaintenance} and
|
||||
* {@link checkpointWalPassive}). Each pragma is individually best-effort;
|
||||
* the whole call is best-effort. `inlineFallback` (if any) runs on THIS
|
||||
* connection only when worker threads are unavailable — keep it to pragmas
|
||||
* that are safe to run synchronously on the main thread.
|
||||
*/
|
||||
private async runPragmasOffThread(pragmas: string[], inlineFallback: string[] = []): Promise<void> {
|
||||
try {
|
||||
const { Worker } = await import('node:worker_threads');
|
||||
const workerSource = `
|
||||
@@ -240,9 +348,7 @@ export class DatabaseConnection {
|
||||
try {
|
||||
const { DatabaseSync } = require('node:sqlite');
|
||||
const db = new DatabaseSync(workerData.dbPath);
|
||||
try { db.exec('PRAGMA analysis_limit=1000'); } catch {}
|
||||
try { db.exec('PRAGMA optimize'); } catch {}
|
||||
try { db.exec('PRAGMA wal_checkpoint(PASSIVE)'); } catch {}
|
||||
for (const p of workerData.pragmas) { try { db.exec(p); } catch {} }
|
||||
try { db.close(); } catch {}
|
||||
} catch {}
|
||||
parentPort.postMessage('done');
|
||||
@@ -253,7 +359,7 @@ export class DatabaseConnection {
|
||||
if (!settled) { settled = true; resolve(); }
|
||||
};
|
||||
try {
|
||||
const worker = new Worker(workerSource, { eval: true, workerData: { dbPath: this.dbPath } });
|
||||
const worker = new Worker(workerSource, { eval: true, workerData: { dbPath: this.dbPath, pragmas } });
|
||||
worker.once('message', () => { void worker.terminate(); finish(); });
|
||||
worker.once('error', () => { void worker.terminate(); finish(); });
|
||||
worker.once('exit', finish);
|
||||
@@ -262,9 +368,9 @@ export class DatabaseConnection {
|
||||
}
|
||||
});
|
||||
} catch {
|
||||
// Worker threads unavailable — bounded in-line fallback, no checkpoint.
|
||||
try { this.db.exec('PRAGMA analysis_limit=1000'); } catch { /* ignore */ }
|
||||
try { this.db.exec('PRAGMA optimize'); } catch { /* ignore */ }
|
||||
for (const p of inlineFallback) {
|
||||
try { this.db.exec(p); } catch { /* ignore */ }
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
|
||||
@@ -0,0 +1,206 @@
|
||||
/**
|
||||
* WAL checkpoint valve — bounds WAL growth while auto-checkpointing is
|
||||
* deferred during a bulk index (#1231).
|
||||
*
|
||||
* Why deferral: SQLite's default `wal_autocheckpoint` (1000 pages) re-writes
|
||||
* hot B-tree/FTS pages into the main DB file over and over during a bulk
|
||||
* index — measured at ~95% of ALL disk I/O, and the difference between 45s
|
||||
* and 19+ minutes on HDD-class storage (150 random IOPS). Deferring
|
||||
* checkpoints turns the store into pure sequential WAL appends; each backfill
|
||||
* pass writes distinct pages once, in page order (≈ sequential).
|
||||
*
|
||||
* Why a valve: unbounded deferral is its own failure mode, both measured in
|
||||
* the #1231 repro. The WAL duplicates hot pages per COMMIT, so it grows far
|
||||
* faster than the DB (5.9GB WAL for a ~340MB DB on a 3.3k-file index) —
|
||||
* filling the disk, and poisoning every subsequent read that must page
|
||||
* through it (the first resolution-phase read blocked the main thread >60s
|
||||
* and the #850 liveness watchdog killed the healthy index). The valve
|
||||
* watches WAL growth on a timer and, past a soft threshold, backfills with
|
||||
* `PRAGMA wal_checkpoint(PASSIVE)` on a worker-thread connection — PASSIVE
|
||||
* never blocks the writer, and off-thread means the main thread (and the
|
||||
* watchdog heartbeat) keep turning regardless of how long a backfill takes.
|
||||
*
|
||||
* The load-bearing subtlety: a WAL file's SIZE never shrinks. After a full
|
||||
* backfill, the writer's next commit RESTARTS the WAL from the top and the
|
||||
* frames recycle inside the same file — so raw size says nothing about the
|
||||
* un-backfilled backlog, and a size-triggered valve degenerates into firing
|
||||
* (and pausing the writer) forever once the file passes its threshold
|
||||
* (measured: guava crawled at ~9min per 160 files). Instead the valve
|
||||
* tracks `sizeAtLastFullBackfill` — refreshed whenever a checkpoint reports
|
||||
* `log === checkpointed` (everything backfilled) — and triggers on GROWTH
|
||||
* beyond that baseline, which only happens when genuinely un-backfilled
|
||||
* frames push past the file's high-water mark.
|
||||
*
|
||||
* Backpressure: if the writer outruns the checkpointer past a hard cap of
|
||||
* growth (2× soft), {@link backpressure} pauses the writer (at a safe,
|
||||
* between-transactions boundary) until a FULL backfill lands. One in-flight
|
||||
* pass is not enough: on a disk saturated by the writer, every concurrent
|
||||
* PASSIVE pass is already stale by the time it finishes (the writer appended
|
||||
* past its snapshot), so neither SQLite's WAL wrap nor the baseline ever
|
||||
* trigger and the WAL grows without bound (measured: 5.9GB on guava at 150
|
||||
* IOPS, then a >60s read stall and a watchdog kill). With the writer parked,
|
||||
* the next pass covers everything, the WAL wraps on the following commit,
|
||||
* and the pause is the disk's honest catch-up cost — the correct terminal
|
||||
* mode when hardware genuinely can't keep up with the append rate.
|
||||
*/
|
||||
|
||||
import type { DatabaseConnection } from './index';
|
||||
|
||||
/** Soft WAL-growth threshold (MB) that triggers an off-thread passive checkpoint. */
|
||||
const DEFAULT_WAL_VALVE_MB = 256;
|
||||
/** Hard cap = this × soft threshold; past it the writer pauses for a full backfill. */
|
||||
const HARD_CAP_MULTIPLIER = 2;
|
||||
/** Passes attempted per writer pause before giving up (a pinned reader could stall forever). */
|
||||
const MAX_PAUSED_BACKFILL_PASSES = 20;
|
||||
/** How often the timer looks at the WAL file size. */
|
||||
const CHECK_INTERVAL_MS = 2000;
|
||||
|
||||
/**
|
||||
* Resolve the valve's soft threshold from the `CODEGRAPH_WAL_VALVE_MB`
|
||||
* override; non-numeric / non-positive values fall back to the default.
|
||||
*/
|
||||
export function resolveWalValveMb(envVal: string | undefined): number {
|
||||
if (envVal !== undefined && envVal !== '') {
|
||||
const n = Number(envVal);
|
||||
if (Number.isFinite(n) && n > 0) return Math.floor(n);
|
||||
}
|
||||
return DEFAULT_WAL_VALVE_MB;
|
||||
}
|
||||
|
||||
export class WalCheckpointValve {
|
||||
private timer: ReturnType<typeof setInterval> | null = null;
|
||||
private inflight: Promise<void> | null = null;
|
||||
/** Writer pause in progress (hard cap breached): passes loop until a full backfill. */
|
||||
private pause: Promise<void> | null = null;
|
||||
/**
|
||||
* WAL file size observed when a checkpoint last reported the ENTIRE WAL
|
||||
* backfilled. Growth is measured against this baseline — see the header
|
||||
* comment for why absolute size cannot be used.
|
||||
*/
|
||||
private sizeAtLastFullBackfill = 0;
|
||||
private readonly softBytes: number;
|
||||
private readonly hardBytes: number;
|
||||
|
||||
constructor(
|
||||
private readonly db: DatabaseConnection,
|
||||
softMb: number = resolveWalValveMb(process.env.CODEGRAPH_WAL_VALVE_MB),
|
||||
private readonly intervalMs: number = CHECK_INTERVAL_MS,
|
||||
private readonly log: (msg: string) => void = () => {}
|
||||
) {
|
||||
this.softBytes = softMb * 1024 * 1024;
|
||||
this.hardBytes = this.softBytes * HARD_CAP_MULTIPLIER;
|
||||
}
|
||||
|
||||
private mb(n: number): string {
|
||||
return `${Math.round(n / 1024 / 1024)}MB`;
|
||||
}
|
||||
|
||||
/** Un-backfilled growth estimate: bytes the WAL has grown past the last full backfill. */
|
||||
private growthBytes(): number {
|
||||
return this.db.getWalSizeBytes() - this.sizeAtLastFullBackfill;
|
||||
}
|
||||
|
||||
/** Begin watching the WAL. Idempotent; the timer never holds the loop open. */
|
||||
start(): void {
|
||||
if (this.timer) return;
|
||||
this.timer = setInterval(() => this.check(), this.intervalMs);
|
||||
this.timer.unref?.();
|
||||
}
|
||||
|
||||
/** Stop watching. Any in-flight checkpoint keeps running — await drain(). */
|
||||
stop(): void {
|
||||
if (this.timer) {
|
||||
clearInterval(this.timer);
|
||||
this.timer = null;
|
||||
}
|
||||
}
|
||||
|
||||
/** One poll: fire an off-thread passive checkpoint when growth passes the soft threshold. */
|
||||
check(): void {
|
||||
if (!this.pause && !this.inflight && this.growthBytes() > this.softBytes) this.fire();
|
||||
}
|
||||
|
||||
/**
|
||||
* Writer-side backstop, called at a between-transactions boundary. Returns
|
||||
* null (no wait) while growth is under the hard cap; past it, returns a
|
||||
* promise that resolves only once a FULL backfill has landed — see the
|
||||
* header comment for why a single pass is not enough on a saturated disk.
|
||||
*/
|
||||
backpressure(): Promise<void> | null {
|
||||
if (this.pause) return this.pause;
|
||||
if (this.growthBytes() <= this.hardBytes) return null;
|
||||
this.log(`backpressure: wal=${this.mb(this.db.getWalSizeBytes())} baseline=${this.mb(this.sizeAtLastFullBackfill)} — pausing writer for full backfill`);
|
||||
const t0 = Date.now();
|
||||
this.pause = this.backfillFully().finally(() => {
|
||||
this.pause = null;
|
||||
this.log(`backpressure released after ${Date.now() - t0}ms: wal=${this.mb(this.db.getWalSizeBytes())} baseline=${this.mb(this.sizeAtLastFullBackfill)}`);
|
||||
});
|
||||
return this.pause;
|
||||
}
|
||||
|
||||
/** Await any in-flight checkpoint and writer pause. */
|
||||
async drain(): Promise<void> {
|
||||
while (this.pause || this.inflight) {
|
||||
if (this.pause) await this.pause;
|
||||
if (this.inflight) await this.inflight;
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Phase-boundary fold: backfill the ENTIRE WAL now (off-thread, awaited).
|
||||
* Called between bulk phases — e.g. after parsing, before resolution's
|
||||
* first reads — so the next phase never pages a bulk-write-sized WAL on
|
||||
* the main thread (the post-parse read against a multi-GB WAL is what
|
||||
* blew the #850 watchdog's 60s window in the #1231 repro). The await
|
||||
* keeps the event loop (and the watchdog heartbeat) turning.
|
||||
*/
|
||||
async foldNow(): Promise<void> {
|
||||
await this.drain();
|
||||
if (this.growthBytes() <= 0) return;
|
||||
this.log(`foldNow: wal=${this.mb(this.db.getWalSizeBytes())} baseline=${this.mb(this.sizeAtLastFullBackfill)}`);
|
||||
this.pause = this.backfillFully().finally(() => { this.pause = null; });
|
||||
await this.pause;
|
||||
}
|
||||
|
||||
/**
|
||||
* With the writer parked on the returned promise, loop passive passes until
|
||||
* one reports the entire WAL backfilled (typically the second: the first
|
||||
* drains the pass that was already running against a stale snapshot). Gives
|
||||
* up after a bounded number of passes — e.g. a reader pinning the WAL —
|
||||
* because unbounded WAL growth degrades; a wedged writer never recovers.
|
||||
*/
|
||||
private async backfillFully(): Promise<void> {
|
||||
for (let i = 0; i < MAX_PAUSED_BACKFILL_PASSES; i++) {
|
||||
if (this.inflight) await this.inflight; // fold in the stale in-flight pass first
|
||||
const res = await this.db.checkpointWalPassive();
|
||||
if (!res) return; // checkpoint machinery unavailable — don't spin
|
||||
this.log(`backfill pass ${i + 1}: busy=${res.busy} log=${res.log} checkpointed=${res.checkpointed} wal=${this.mb(this.db.getWalSizeBytes())}`);
|
||||
if (res.busy === 0 && res.log === res.checkpointed) {
|
||||
this.sizeAtLastFullBackfill = this.db.getWalSizeBytes();
|
||||
return;
|
||||
}
|
||||
}
|
||||
this.log(`backfill gave up after ${MAX_PAUSED_BACKFILL_PASSES} passes — WAL stays unbounded this cycle`);
|
||||
}
|
||||
|
||||
private fire(): void {
|
||||
const p = this.db
|
||||
.checkpointWalPassive()
|
||||
.then((res) => {
|
||||
// Full backfill (busy 0, every log frame checkpointed) ⇒ the writer's
|
||||
// next commit wraps the WAL; the file's current size becomes the new
|
||||
// growth baseline. A partial pass (writer appended during it, or a
|
||||
// read transaction pinned frames) leaves the baseline alone, so the
|
||||
// next tick fires again and copies the remainder. In non-WAL mode
|
||||
// SQLite reports log = checkpointed = -1, which is harmless here.
|
||||
if (res && res.busy === 0 && res.log === res.checkpointed) {
|
||||
this.sizeAtLastFullBackfill = this.db.getWalSizeBytes();
|
||||
}
|
||||
})
|
||||
.catch(() => { /* best-effort */ })
|
||||
.finally(() => {
|
||||
if (this.inflight === p) this.inflight = null;
|
||||
});
|
||||
this.inflight = p;
|
||||
}
|
||||
}
|
||||
Reference in New Issue
Block a user