From 5cf4323511eb7e1bf3640f5ceac557cb64395e5d Mon Sep 17 00:00:00 2001 From: Anso Date: Tue, 28 Apr 2026 00:59:04 -0400 Subject: [PATCH] perf(backend): batch audit_log inserts into a buffered transaction (#817) Every mutating /api/* request runs an individual INSERT into audit_log which serializes against other writers under burst load (SQLite's single-writer model). Buffer the writes in DatabaseService and flush them in a single transaction either every second or once the buffer reaches 100 entries, whichever comes first. Read paths (getAuditLogs, getAuditLogsInRange, cleanupOldAuditLogs) drain the buffer first so callers always see a consistent view, which keeps the existing test pattern of insert-then-read working. Graceful shutdown flushes before db.close() so no entries are lost on clean exit. The 1s flush timer is unref'd so the buffer cannot keep the process alive on its own. The CLI resetMfa script flushes explicitly before returning since it exits before the timer fires. --- backend/src/bootstrap/shutdown.ts | 3 + backend/src/cli/resetMfa.ts | 3 + backend/src/services/DatabaseService.ts | 81 ++++++++++++++++++++++++- 3 files changed, 84 insertions(+), 3 deletions(-) diff --git a/backend/src/bootstrap/shutdown.ts b/backend/src/bootstrap/shutdown.ts index ff71b5ae..06d70278 100644 --- a/backend/src/bootstrap/shutdown.ts +++ b/backend/src/bootstrap/shutdown.ts @@ -39,6 +39,9 @@ export function installShutdownHandlers(server: Server): void { try { MfaService.getInstance().stop(); } catch (e) { console.warn('[Shutdown] MfaService cleanup failed:', (e as Error).message); } + try { DatabaseService.getInstance().flushAuditLogBuffer(); } catch (e) { + console.warn('[Shutdown] Audit log flush failed:', (e as Error).message); + } try { DatabaseService.getInstance().getDb().close(); } catch (e) { console.warn('[Shutdown] Database close failed:', (e as Error).message); } diff --git a/backend/src/cli/resetMfa.ts b/backend/src/cli/resetMfa.ts index 4373e5d0..f18f3ba5 100644 --- a/backend/src/cli/resetMfa.ts +++ b/backend/src/cli/resetMfa.ts @@ -47,6 +47,9 @@ export function resetMfaForUser(username: string): ResetMfaResult { // Audit failure should not block the reset itself. console.warn('[reset-mfa] audit log write failed:', (err as Error).message); } + // The audit log buffer flushes on a 1s timer that the CLI process exits + // before reaching, so flush explicitly to make sure the entry persists. + db.flushAuditLogBuffer(); return { ok: true, message: `Two-factor authentication cleared for ${username}` }; } diff --git a/backend/src/services/DatabaseService.ts b/backend/src/services/DatabaseService.ts index ed10aa99..71d05f23 100644 --- a/backend/src/services/DatabaseService.ts +++ b/backend/src/services/DatabaseService.ts @@ -467,6 +467,16 @@ export interface ScanSummary { scan_id: number; } +// Audit log buffering: writes are batched into a transaction either after +// AUDIT_LOG_FLUSH_INTERVAL_MS or once the buffer hits AUDIT_LOG_FLUSH_THRESHOLD, +// whichever comes first. Without this, every mutating /api/* request runs an +// individual INSERT and serializes against other writers under burst load +// (SQLite's single-writer model). All read paths (getAuditLogs, +// getAuditLogsInRange, cleanupOldAuditLogs) drain the buffer first so callers +// always observe a consistent view. +const AUDIT_LOG_FLUSH_INTERVAL_MS = 1_000; +const AUDIT_LOG_FLUSH_THRESHOLD = 100; + export class DatabaseService { private static instance: DatabaseService; private db: Database.Database; @@ -477,6 +487,9 @@ export class DatabaseService { // process is the sole writer to global_settings; sidecar tools that // edit the row directly will not invalidate the cache. private cachedGlobalSettings: Readonly> | null = null; + private auditLogBuffer: Array> = []; + private auditLogFlushTimer: ReturnType | null = null; + private auditLogInsertStmt: Database.Statement | null = null; private constructor() { const dataDir = process.env.DATA_DIR || path.join(process.cwd(), 'data'); @@ -2203,9 +2216,68 @@ export class DatabaseService { // --- Audit Log --- public insertAuditLog(entry: Omit): void { - this.db.prepare( - 'INSERT INTO audit_log (timestamp, username, method, path, status_code, node_id, ip_address, summary) VALUES (?, ?, ?, ?, ?, ?, ?, ?)' - ).run(entry.timestamp, entry.username, entry.method, entry.path, entry.status_code, entry.node_id, entry.ip_address, entry.summary); + this.auditLogBuffer.push(entry); + if (this.auditLogBuffer.length >= AUDIT_LOG_FLUSH_THRESHOLD) { + this.flushAuditLogBuffer(); + return; + } + if (!this.auditLogFlushTimer) { + // unref(): the buffer flush should not by itself keep the process + // alive. The HTTP server keeps the event loop running during + // normal operation; on shutdown, the explicit flush in + // bootstrap/shutdown.ts drains the buffer before db.close(). + this.auditLogFlushTimer = setTimeout( + () => this.flushAuditLogBuffer(), + AUDIT_LOG_FLUSH_INTERVAL_MS, + ); + this.auditLogFlushTimer.unref(); + } + } + + /** + * Drain the audit-log buffer to disk in a single transaction. Safe to + * call from any path: read methods flush before querying so callers + * observe buffered writes, and the shutdown handler flushes before the + * DB connection closes. + */ + public flushAuditLogBuffer(): void { + if (this.auditLogFlushTimer) { + clearTimeout(this.auditLogFlushTimer); + this.auditLogFlushTimer = null; + } + if (this.auditLogBuffer.length === 0) return; + // Swap the buffer reference before running the transaction. Any + // re-entrant insertAuditLog call (e.g. from a future hook that audits + // its own writes) lands on the new empty buffer and survives to the + // next flush, instead of being captured into the in-flight batch and + // potentially dropped on transaction failure. + const batch = this.auditLogBuffer; + this.auditLogBuffer = []; + if (!this.auditLogInsertStmt) { + this.auditLogInsertStmt = this.db.prepare( + 'INSERT INTO audit_log (timestamp, username, method, path, status_code, node_id, ip_address, summary) VALUES (?, ?, ?, ?, ?, ?, ?, ?)', + ); + } + const stmt = this.auditLogInsertStmt; + const insertMany = this.db.transaction((entries: typeof batch) => { + for (const entry of entries) { + stmt.run( + entry.timestamp, + entry.username, + entry.method, + entry.path, + entry.status_code, + entry.node_id, + entry.ip_address, + entry.summary, + ); + } + }); + try { + insertMany(batch); + } catch (err) { + console.error('[Audit] Failed to flush audit log buffer:', err); + } } public getAuditLogs(filters: { @@ -2217,6 +2289,7 @@ export class DatabaseService { to?: number; search?: string; } = {}): { entries: AuditLogEntry[]; total: number } { + this.flushAuditLogBuffer(); const page = filters.page ?? 1; const limit = filters.limit ?? 50; const offset = (page - 1) * limit; @@ -2257,11 +2330,13 @@ export class DatabaseService { } public cleanupOldAuditLogs(daysToKeep = 90): void { + this.flushAuditLogBuffer(); const cutoff = Date.now() - (daysToKeep * 24 * 60 * 60 * 1000); this.db.prepare('DELETE FROM audit_log WHERE timestamp < ?').run(cutoff); } public getAuditLogsInRange(from: number, to: number): AuditLogEntry[] { + this.flushAuditLogBuffer(); return this.db.prepare( 'SELECT * FROM audit_log WHERE timestamp >= ? AND timestamp < ? ORDER BY timestamp ASC' ).all(from, to) as AuditLogEntry[];