fix(audit): make the audit-log flush transaction actually atomic on SQLite - #3777

Community Contribution License Agreement

By creating this pull request, I grant the project maintainers an unlimited,
perpetual license to use, modify, and redistribute these contributions under any terms they
choose, including both the AGPLv3 and the Fossorial Commercial license terms. I
represent that I have the right to grant this license for all contributed content.

AI Disclosure

Claude Code (Anthropic) was used to trace this through drizzle-orm and better-sqlite3's source, write the fix and tests, and build/run the benchmarks below. I directed the investigation and verified every claim myself against a real database — including reproducing the broken rollback, confirming the mechanism via sqlite.inTransaction, and re-running the benchmarks to check variance before quoting any number.

Description

Summary

flushAuditLogs() in server/routers/badger/logRequestAudit.ts wraps its batched inserts in a transaction:

// Use a transaction to ensure all inserts succeed or fail together
// This prevents index corruption from partial writes
await logsDb.transaction(async (tx) => {
    const BATCH_DB_SIZE = 25;
    for (let i = 0; i < logsToWrite.length; i += BATCH_DB_SIZE) {
        await tx.insert(requestAuditLog).values(logsToWrite.slice(i, i + BATCH_DB_SIZE));
    }
});

On SQLite, that guarantee does not hold — the transaction is effectively a no-op.

Root cause

better-sqlite3's transaction() is synchronous. It runs BEGIN, invokes the callback, then COMMIT (lib/methods/transaction.js):

before.run();                               // BEGIN
try {
    const result = apply.call(fn, this, arguments);
    after.run();                            // COMMIT

drizzle passes the user callback straight through to it (drizzle-orm/better-sqlite3/session.cjs:61):

const nativeTx = this.client.transaction(transaction);

An async callback returns a promise at its first await, so apply.call(...) returns immediately and COMMIT fires on an empty transaction before a single insert has run. The inserts then execute afterwards in autocommit mode — one implicit transaction per 25-row batch — and the synchronous try/catch can't observe their rejections either.

Consequences

1. Partial writes persist. Against a real SQLite database, a flush that fails on the 3rd batch leaves 50 rows committed instead of 0. Confirmed mechanically: sqlite.inTransaction is true on entering the callback and false immediately after the first await — COMMIT has already run.

2. Duplicate audit-log rows. The catch block re-queues the entire slice on the assumption nothing was written:

auditLogBuffer.unshift(...logsToWrite);

Since the earlier batches were already committed, the retry inserts them a second time.

3. It's also a performance bug. Losing the wrapping transaction turns one commit into ceil(n/25) commits — 400 separate fsync'd transactions for a MAX_BUFFER_SIZE (10,000) flush instead of 1. And because better-sqlite3 is synchronous, that time is the event loop being blocked, stalling every proxied request the process is serving.

What changed

Extracted the batched insert into insertAuditLogsAtomically(), which drives the inserts synchronously on SQLite so the transaction is real. Postgres (node-postgres) is genuinely async and keeps the awaited form, selected via the existing driver export — the same branching already used in server/routers/auditLogs/.

Behaviour is unchanged on Postgres, and unchanged on SQLite's happy path; only the failure path and commit count differ.

Impact & measurements

All numbers from a real file-backed SQLite database on this machine, flushing MAX_BUFFER_SIZE = 10,000 rows with a schema mirroring requestAuditLog.

Correctness (the actual bug)

Event-loop blocking (what matters for a proxy)

Measured with a 1 ms interval probe; because better-sqlite3 is synchronous, this is time the process cannot serve any request.

Both shapes block the loop for their full duration (await on better-sqlite3 resolves as a microtask and doesn't yield to I/O), so this is a straight reduction with no latency trade-off — ~1.3 s less continuous blocking per full flush on the default configuration.

Flush time across buffer sizes

Honest caveats on these numbers:

• Absolute times vary noticeably run-to-run (disk/fsync noise). I ran the suite twice; the 10,000-row "before" figure came out as 3803 ms and 1736 ms on the two runs. The speedup ratio is the stable quantity — consistently ~3–4× across both runs.
• WAL mode sees little benefit (~1.0–1.3×, occasionally within noise), because WAL commits are far cheaper so commit count matters much less. The large win applies to the default DELETE/synchronous=FULL configuration, which is what ships unless ENABLE_SQLITE_WAL_MODE=true is set.
• The correctness fix applies regardless of journal mode.

Tests

Adds server/routers/badger/auditLogTransaction.test.ts, which pins all three behaviours against a real SQLite database:

1. a synchronous callback rolls every batch back on failure (0 rows),
2. it still commits all batches on success (60 rows),
3. an async callback leaves the earlier batches committed and shows inTransaction === false after the first await — documenting the exact regression this guards against.

How to test?

1. npx tsx server/routers/badger/auditLogTransaction.test.ts — all assertions pass.
2. npx tsc --noEmit — clean. I verified this under both npm run set:sqlite and npm run set:pg, since the driver branch has to compile against either driver's types.
3. npx eslint server/routers/badger/logRequestAudit.ts — clean.

🤖 Generated with Claude Code