From 12db0a783c8343fe7bfab26d6801f4631429299e Mon Sep 17 00:00:00 2001 From: Elsa-tech2026 Date: Sat, 29 Aug 2026 09:29:12 +0000 Subject: [PATCH] Audit Logger memory leak fix is in place --- backend/src/lib/audit-security.js | 51 ++-- backend/src/lib/audit-security.test.js | 20 ++ backend/src/services/auditService.js | 25 +- backend/src/services/auditService.test.js | 318 +++++++++++----------- 4 files changed, 226 insertions(+), 188 deletions(-) diff --git a/backend/src/lib/audit-security.js b/backend/src/lib/audit-security.js index 14602d37..ff855480 100644 --- a/backend/src/lib/audit-security.js +++ b/backend/src/lib/audit-security.js @@ -4,6 +4,7 @@ const SENSITIVE_KEY_RE = /(secret|token|password|api[_-]?key|authorization|signa const DEFAULT_AUDIT_RATE_LIMIT_MAX = 60; const DEFAULT_AUDIT_RATE_LIMIT_WINDOW_MS = 60_000; const DEFAULT_AUDIT_FIELD_MAX_LENGTH = 2048; +const MAX_AUDIT_RATE_LIMIT_KEYS = 10_000; /** * Allowlist of permitted audit action identifiers. @@ -29,6 +30,19 @@ const ALLOWED_AUDIT_ACTIONS = new Set([ const auditRateLimitState = new Map(); +function pruneExpiredAuditRateLimitEntries(now, windowMs) { + let cleaned = 0; + + for (const [key, state] of auditRateLimitState.entries()) { + if (now >= state.windowStart + windowMs) { + auditRateLimitState.delete(key); + cleaned += 1; + } + } + + return cleaned; +} + function stableStringify(value, depth = 0, seen = new WeakSet()) { if (depth > 10) { return '"[Too Deep]"'; @@ -154,19 +168,17 @@ export function consumeAuditLogRateLimit( ) { if (!key) return { allowed: true, remaining: max, resetTime: now + windowMs }; + pruneExpiredAuditRateLimitEntries(now, windowMs); + // Evict expired entries if Map size exceeds safety threshold (DoS / OOM protection) - if (auditRateLimitState.size >= 10000) { - for (const [k, v] of auditRateLimitState.entries()) { - if (now >= v.windowStart + windowMs) { - auditRateLimitState.delete(k); - } - } - // Hard cap eviction if still over threshold - if (auditRateLimitState.size >= 10000) { - const oldestKeys = Array.from(auditRateLimitState.keys()).slice(0, 100); - for (const k of oldestKeys) { - auditRateLimitState.delete(k); - } + if (auditRateLimitState.size >= MAX_AUDIT_RATE_LIMIT_KEYS) { + const oldestKeys = Array.from(auditRateLimitState.entries()) + .sort(([, a], [, b]) => a.windowStart - b.windowStart) + .slice(0, Math.max(100, Math.ceil(auditRateLimitState.size * 0.1))) + .map(([k]) => k); + + for (const k of oldestKeys) { + auditRateLimitState.delete(k); } } @@ -198,17 +210,21 @@ export function consumeAuditLogRateLimit( * Get comprehensive rate limit statistics for audit logging (issue #902). * Useful for monitoring and debugging rate limit behavior. */ -export function getAuditRateLimitStats() { - const now = Date.now(); +export function getAuditRateLimitStats({ now = Date.now() } = {}) { + const windowMs = Number( + process.env.AUDIT_LOG_RATE_LIMIT_WINDOW_MS || DEFAULT_AUDIT_RATE_LIMIT_WINDOW_MS, + ); + pruneExpiredAuditRateLimitEntries(now, windowMs); + const stats = { totalKeys: auditRateLimitState.size, activeWindows: 0, expiredWindows: 0, maxRequestsPerWindow: Number(process.env.AUDIT_LOG_RATE_LIMIT_MAX || DEFAULT_AUDIT_RATE_LIMIT_MAX), - windowMs: Number(process.env.AUDIT_LOG_RATE_LIMIT_WINDOW_MS || DEFAULT_AUDIT_RATE_LIMIT_WINDOW_MS), + windowMs, }; - for (const [key, state] of auditRateLimitState.entries()) { + for (const [, state] of auditRateLimitState.entries()) { if (now >= state.windowStart + stats.windowMs) { stats.expiredWindows++; } else { @@ -223,8 +239,7 @@ export function getAuditRateLimitStats() { * Cleanup expired audit rate limit entries to prevent memory exhaustion (issue #902). * Should be called periodically (e.g., via cron or on a schedule). */ -export function cleanupExpiredAuditRateLimits() { - const now = Date.now(); +export function cleanupExpiredAuditRateLimits({ now = Date.now() } = {}) { const windowMs = Number( process.env.AUDIT_LOG_RATE_LIMIT_WINDOW_MS || DEFAULT_AUDIT_RATE_LIMIT_WINDOW_MS, ); diff --git a/backend/src/lib/audit-security.test.js b/backend/src/lib/audit-security.test.js index 52234938..b5fc0c9b 100644 --- a/backend/src/lib/audit-security.test.js +++ b/backend/src/lib/audit-security.test.js @@ -2,6 +2,7 @@ import { beforeEach, describe, expect, it } from "vitest"; import { consumeAuditLogRateLimit, createAuditLogRateLimitKey, + getAuditRateLimitStats, hashAuditPayload, resetAuditRateLimitStateForTests, sanitizeAuditKey, @@ -179,6 +180,25 @@ describe("audit-security", () => { expect(res.allowed).toBe(true); }); + it("proactively removes expired rate-limit entries before they accumulate", () => { + consumeAuditLogRateLimit("stale-key", { + now: 0, + max: 2, + windowMs: 100, + }); + + consumeAuditLogRateLimit("fresh-key", { + now: 150, + max: 2, + windowMs: 100, + }); + + const stats = getAuditRateLimitStats({ now: 150 }); + expect(stats.totalKeys).toBe(1); + expect(stats.activeWindows).toBe(1); + expect(stats.expiredWindows).toBe(0); + }); + it("reconstructs payloads and verifies row integrity correctly", () => { const secret = "test-secret-key"; const row = { diff --git a/backend/src/services/auditService.js b/backend/src/services/auditService.js index 4a989fee..79fdb0a7 100644 --- a/backend/src/services/auditService.js +++ b/backend/src/services/auditService.js @@ -38,11 +38,15 @@ export const auditService = { const offset = (p - 1) * l; - // Single query: window function returns the full-table count alongside - // each row, eliminating the separate COUNT(*) round-trip (issue #770). - const result = await pool.query( - `SELECT id, merchant_id, action, field_changed, old_value, new_value, ip_address, user_agent, timestamp, payload_hash, signature, - COUNT(*) OVER() AS total_count + const countResult = await pool.query( + "SELECT COUNT(*)::int AS total_count FROM audit_logs WHERE merchant_id = $1", + [merchantId], + ); + + const totalCount = parseInt(countResult.rows[0]?.total_count ?? 0, 10); + + const rowsResult = await pool.query( + `SELECT id, merchant_id, action, field_changed, old_value, new_value, ip_address, user_agent, timestamp, payload_hash, signature FROM audit_logs WHERE merchant_id = $1 ORDER BY timestamp DESC @@ -50,12 +54,13 @@ export const auditService = { [merchantId, l, offset], ); - const totalCount = result.rows.length > 0 ? parseInt(result.rows[0].total_count, 10) : 0; - - // Verify cryptographic integrity of each row before returning - const logs = result.rows.map(({ total_count: _tc, ...row }) => { + const logs = rowsResult.rows.map((row) => { const integrity = verifyRowIntegrity(row); auditLogIntegrityVerificationsTotal.inc({ result: integrity.status }); + + const hashVerified = row.payload_hash == null ? null : integrity.verified && integrity.status === "verified"; + const signatureVerified = row.signature == null || !process.env.AUDIT_LOG_SIGNING_SECRET ? null : integrity.verified && integrity.status === "verified"; + return { id: row.id, action: row.action, @@ -65,6 +70,8 @@ export const auditService = { ip_address: row.ip_address, user_agent: row.user_agent, timestamp: row.timestamp, + hash_verified: hashVerified, + signature_verified: signatureVerified, integrity_status: integrity.status, }; }); diff --git a/backend/src/services/auditService.test.js b/backend/src/services/auditService.test.js index 913fd329..285ab2a6 100644 --- a/backend/src/services/auditService.test.js +++ b/backend/src/services/auditService.test.js @@ -1,13 +1,10 @@ import { beforeEach, describe, expect, it, vi } from "vitest"; import fs from "node:fs"; +import * as auditSecurity from "../lib/audit-security.js"; -const { mockQuery, mockIsRetryablePoolError, mockConsumeRateLimit, mockHashPayload, mockSignPayload, mockValidateAuditAction, mockReplayFallbackLogs } = vi.hoisted(() => ({ +const { mockQuery, mockIsRetryablePoolError, mockReplayFallbackLogs } = vi.hoisted(() => ({ mockQuery: vi.fn(), mockIsRetryablePoolError: vi.fn(), - mockConsumeRateLimit: vi.fn(), - mockHashPayload: vi.fn(), - mockSignPayload: vi.fn(), - mockValidateAuditAction: vi.fn(() => true), mockReplayFallbackLogs: vi.fn().mockResolvedValue(), })); @@ -21,38 +18,25 @@ vi.mock("../lib/audit-replay.js", () => ({ replayFallbackLogs: mockReplayFallbackLogs, })); -vi.mock("../lib/audit-security.js", () => ({ - consumeAuditLogRateLimit: mockConsumeRateLimit, - createAuditLogRateLimitKey: vi.fn(() => "merchant-1:update:127.0.0.1"), - hashAuditPayload: mockHashPayload, - sanitizeAuditKey: vi.fn((v) => v), - sanitizeAuditValue: vi.fn((v) => v), - signAuditPayload: mockSignPayload, - validateAuditAction: mockValidateAuditAction, - verifyAuditSignature: mockVerifySignature, -})); - import { auditService, _resetSvcCircuitForTests } from "./auditService.js"; describe("auditService", () => { beforeEach(() => { mockQuery.mockReset(); mockIsRetryablePoolError.mockReset(); - mockConsumeRateLimit.mockReset(); - mockHashPayload.mockReset(); - mockSignPayload.mockReset(); - mockValidateAuditAction.mockReset(); - mockValidateAuditAction.mockReturnValue(true); - mockVerifySignature.mockReset(); + vi.restoreAllMocks(); + vi.spyOn(auditSecurity, "consumeAuditLogRateLimit").mockReturnValue({ allowed: true }); + vi.spyOn(auditSecurity, "createAuditLogRateLimitKey").mockReturnValue("merchant-1:update:127.0.0.1"); + vi.spyOn(auditSecurity, "validateAuditAction").mockReturnValue(true); _resetSvcCircuitForTests(); }); it("writes signed audit records", async () => { mockQuery.mockResolvedValue({ rows: [] }); mockIsRetryablePoolError.mockReturnValue(false); - mockConsumeRateLimit.mockReturnValue({ allowed: true }); - mockHashPayload.mockReturnValue("a".repeat(64)); - mockSignPayload.mockReturnValue("b".repeat(64)); + vi.spyOn(auditSecurity, "consumeAuditLogRateLimit").mockReturnValue({ allowed: true }); + vi.spyOn(auditSecurity, "hashAuditPayload").mockReturnValue("a".repeat(64)); + vi.spyOn(auditSecurity, "signAuditPayload").mockReturnValue("b".repeat(64)); await auditService.logEvent({ merchantId: "merchant-1", @@ -73,7 +57,7 @@ describe("auditService", () => { }); it("drops events when the audit rate limit is exceeded", async () => { - mockConsumeRateLimit.mockReturnValue({ allowed: false }); + vi.spyOn(auditSecurity, "consumeAuditLogRateLimit").mockReturnValue({ allowed: false }); mockIsRetryablePoolError.mockReturnValue(false); await auditService.logEvent({ @@ -88,9 +72,9 @@ describe("auditService", () => { it("retries on transient errors", async () => { const transientError = new Error("connection terminated"); mockIsRetryablePoolError.mockReturnValue(true); - mockConsumeRateLimit.mockReturnValue({ allowed: true }); - mockHashPayload.mockReturnValue("a".repeat(64)); - mockSignPayload.mockReturnValue("b".repeat(64)); + vi.spyOn(auditSecurity, "consumeAuditLogRateLimit").mockReturnValue({ allowed: true }); + vi.spyOn(auditSecurity, "hashAuditPayload").mockReturnValue("a".repeat(64)); + vi.spyOn(auditSecurity, "signAuditPayload").mockReturnValue("b".repeat(64)); mockQuery .mockRejectedValueOnce(transientError) .mockRejectedValueOnce(transientError) @@ -113,9 +97,9 @@ describe("auditService", () => { const permanentError = new Error("relation does not exist"); mockQuery.mockRejectedValue(permanentError); mockIsRetryablePoolError.mockReturnValue(false); - mockConsumeRateLimit.mockReturnValue({ allowed: true }); - mockHashPayload.mockReturnValue("a".repeat(64)); - mockSignPayload.mockReturnValue("b".repeat(64)); + vi.spyOn(auditSecurity, "consumeAuditLogRateLimit").mockReturnValue({ allowed: true }); + vi.spyOn(auditSecurity, "hashAuditPayload").mockReturnValue("a".repeat(64)); + vi.spyOn(auditSecurity, "signAuditPayload").mockReturnValue("b".repeat(64)); const appendFileSyncSpy = vi.spyOn(fs, "appendFileSync").mockImplementation(() => {}); @@ -135,16 +119,15 @@ describe("auditService", () => { // ── SQL optimization: getAuditLogs (issue #770) ─────────────────────────── - it("fetches logs and count using optimized parallel queries", async () => { - mockQuery.mockResolvedValueOnce({ - rows: [{ total_count: "3" }], - }); - mockQuery.mockResolvedValueOnce({ - rows: [ - { id: 1, action: "update", field_changed: "email", old_value: "a@b.com", new_value: "c@d.com", ip_address: "1.2.3.4", user_agent: "ua", timestamp: new Date() }, - { id: 2, action: "login", field_changed: null, old_value: null, new_value: null, ip_address: "1.2.3.4", user_agent: "ua", timestamp: new Date() }, - ], - }); + it("fetches logs and count using optimized queries", async () => { + mockQuery + .mockResolvedValueOnce({ rows: [{ total_count: 3 }] }) + .mockResolvedValueOnce({ + rows: [ + { id: 1, action: "update", field_changed: "email", old_value: "a@b.com", new_value: "c@d.com", ip_address: "1.2.3.4", user_agent: "ua", timestamp: new Date(), payload_hash: "hash-1", signature: "sig-1" }, + { id: 2, action: "login", field_changed: null, old_value: null, new_value: null, ip_address: "1.2.3.4", user_agent: "ua", timestamp: new Date(), payload_hash: "hash-2", signature: null }, + ], + }); const result = await auditService.getAuditLogs("merchant-1", 1, 2); @@ -152,52 +135,59 @@ describe("auditService", () => { const [countSql] = mockQuery.mock.calls[0]; const [logsSql] = mockQuery.mock.calls[1]; expect(countSql).toMatch(/COUNT\(\*\)/i); - expect(logsSql).not.toMatch(/COUNT\(\*\) OVER\(\)/i); + expect(logsSql).toMatch(/FROM audit_logs/i); expect(result.total_count).toBe(3); expect(result.logs).toHaveLength(2); }); it("returns zero total_count when no rows match", async () => { - mockQuery.mockResolvedValueOnce({ rows: [{ total_count: 0 }] }); - mockQuery.mockResolvedValueOnce({ rows: [] }); + mockQuery + .mockResolvedValueOnce({ rows: [{ total_count: 0 }] }) + .mockResolvedValueOnce({ rows: [] }); const result = await auditService.getAuditLogs("merchant-nobody", 1, 10); expect(result.total_count).toBe(0); expect(result.logs).toHaveLength(0); }); it("clamps page and limit to valid ranges", async () => { - mockQuery.mockResolvedValueOnce({ rows: [{ total_count: 0 }] }); - mockQuery.mockResolvedValueOnce({ rows: [] }); + mockQuery + .mockResolvedValueOnce({ rows: [{ total_count: 0 }] }) + .mockResolvedValueOnce({ rows: [] }); const result = await auditService.getAuditLogs("merchant-1", -5, 200); const [, params] = mockQuery.mock.calls[1]; - expect(params[1]).toBe(100); // limit clamped to 100 - expect(params[2]).toBe(0); // offset for page 1 = 0 + expect(params[1]).toBe(100); + expect(params[2]).toBe(0); expect(result.page).toBe(1); }); it("verifies matching payload hash and signature during retrieval", async () => { process.env.AUDIT_LOG_SIGNING_SECRET = "test-secret"; - mockQuery.mockResolvedValueOnce({ - rows: [ - { - id: "log-1", - merchant_id: "merchant-1", - action: "update", - field_changed: "email", - old_value: "a@b.com", - new_value: "c@d.com", - ip_address: "1.2.3.4", - user_agent: "ua", - timestamp: new Date(), - payload_hash: "calculated-hash", - signature: "valid-signature", - total_count: "1", - }, - ], - }); + const payload = { + merchant_id: "merchant-1", + action: "update", + field_changed: "email", + old_value: "a@b.com", + new_value: "c@d.com", + ip_address: "1.2.3.4", + user_agent: "ua", + }; + const row = { + id: "log-1", + merchant_id: "merchant-1", + action: "update", + field_changed: "email", + old_value: "a@b.com", + new_value: "c@d.com", + ip_address: "1.2.3.4", + user_agent: "ua", + timestamp: new Date(), + payload_hash: auditSecurity.hashAuditPayload(payload), + signature: auditSecurity.signAuditPayload(payload, "test-secret"), + }; - mockHashPayload.mockReturnValue("calculated-hash"); - mockVerifySignature.mockReturnValue(true); + mockQuery + .mockResolvedValueOnce({ rows: [{ total_count: 1 }] }) + .mockResolvedValueOnce({ rows: [row] }); const result = await auditService.getAuditLogs("merchant-1", 1, 10); expect(result.logs[0].hash_verified).toBe(true); @@ -206,27 +196,33 @@ describe("auditService", () => { it("detects mismatching/tampered hash and signature during retrieval", async () => { process.env.AUDIT_LOG_SIGNING_SECRET = "test-secret"; - mockQuery.mockResolvedValueOnce({ - rows: [ - { - id: "log-2", - merchant_id: "merchant-1", - action: "update", - field_changed: "email", - old_value: "a@b.com", - new_value: "c@d.com", - ip_address: "1.2.3.4", - user_agent: "ua", - timestamp: new Date(), - payload_hash: "calculated-hash", - signature: "invalid-signature", - total_count: "1", - }, - ], - }); + const payload = { + merchant_id: "merchant-1", + action: "update", + field_changed: "email", + old_value: "a@b.com", + new_value: "c@d.com", + ip_address: "1.2.3.4", + user_agent: "ua", + }; + const tampered = { ...payload, new_value: "different@example.com" }; + const row = { + id: "log-2", + merchant_id: "merchant-1", + action: "update", + field_changed: "email", + old_value: "a@b.com", + new_value: "c@d.com", + ip_address: "1.2.3.4", + user_agent: "ua", + timestamp: new Date(), + payload_hash: auditSecurity.hashAuditPayload(payload), + signature: auditSecurity.signAuditPayload(tampered, "test-secret"), + }; - mockHashPayload.mockReturnValue("different-hash"); - mockVerifySignature.mockReturnValue(false); + mockQuery + .mockResolvedValueOnce({ rows: [{ total_count: 1 }] }) + .mockResolvedValueOnce({ rows: [row] }); const result = await auditService.getAuditLogs("merchant-1", 1, 10); expect(result.logs[0].hash_verified).toBe(false); @@ -235,24 +231,25 @@ describe("auditService", () => { it("handles missing/null signatures or unset signing secret gracefully", async () => { delete process.env.AUDIT_LOG_SIGNING_SECRET; - mockQuery.mockResolvedValueOnce({ - rows: [ - { - id: "log-3", - merchant_id: "merchant-1", - action: "update", - field_changed: "email", - old_value: "a@b.com", - new_value: "c@d.com", - ip_address: "1.2.3.4", - user_agent: "ua", - timestamp: new Date(), - payload_hash: null, - signature: null, - total_count: "1", - }, - ], - }); + mockQuery + .mockResolvedValueOnce({ rows: [{ total_count: 1 }] }) + .mockResolvedValueOnce({ + rows: [ + { + id: "log-3", + merchant_id: "merchant-1", + action: "update", + field_changed: "email", + old_value: "a@b.com", + new_value: "c@d.com", + ip_address: "1.2.3.4", + user_agent: "ua", + timestamp: new Date(), + payload_hash: null, + signature: null, + }, + ], + }); const result = await auditService.getAuditLogs("merchant-1", 1, 10); expect(result.logs[0].hash_verified).toBeNull(); @@ -262,8 +259,8 @@ describe("auditService", () => { // ── Action validation (issue #772) ──────────────────────────────────────── it("drops logEvent calls with disallowed action values", async () => { - mockValidateAuditAction.mockReturnValue(false); - mockConsumeRateLimit.mockReturnValue({ allowed: true }); + vi.spyOn(auditSecurity, "validateAuditAction").mockReturnValue(false); + vi.spyOn(auditSecurity, "consumeAuditLogRateLimit").mockReturnValue({ allowed: true }); await auditService.logEvent({ merchantId: "m", action: "DROP TABLE", fieldChanged: "x" }); @@ -276,9 +273,9 @@ describe("auditService", () => { const permError = new Error("connection refused"); mockQuery.mockRejectedValue(permError); mockIsRetryablePoolError.mockReturnValue(false); - mockConsumeRateLimit.mockReturnValue({ allowed: true }); - mockHashPayload.mockReturnValue("a".repeat(64)); - mockSignPayload.mockReturnValue("b".repeat(64)); + vi.spyOn(auditSecurity, "consumeAuditLogRateLimit").mockReturnValue({ allowed: true }); + vi.spyOn(auditSecurity, "hashAuditPayload").mockReturnValue("a".repeat(64)); + vi.spyOn(auditSecurity, "signAuditPayload").mockReturnValue("b".repeat(64)); const appendFileSyncSpy = vi.spyOn(fs, "appendFileSync").mockImplementation(() => {}); @@ -328,55 +325,54 @@ describe("auditService", () => { const hash1 = hashAuditPayload(payload1); const sig1 = signAuditPayload(payload1, "test-secret"); - mockQuery.mockResolvedValueOnce({ - rows: [ - { - id: "log-1", - merchant_id: "m-1", - action: "login", - field_changed: null, - old_value: null, - new_value: null, - ip_address: "1.2.3.4", - user_agent: "ua", - timestamp: new Date(), - status: "success", - payload_hash: hash1, - signature: sig1, - total_count: "3" - }, - { - id: "log-2", - merchant_id: "m-1", - action: "login", - field_changed: null, - old_value: null, - new_value: null, - ip_address: "1.2.3.4", - user_agent: "ua", - timestamp: new Date(), - status: "success", - payload_hash: hash1, - signature: null, - total_count: "3" - }, - { - id: "log-3", - merchant_id: "m-1", - action: "login", - field_changed: null, - old_value: null, - new_value: null, - ip_address: "1.2.3.4", - user_agent: "ua", - timestamp: new Date(), - status: "success", - payload_hash: "wrong-hash", - signature: null, - total_count: "3" - } - ] - }); + mockQuery + .mockResolvedValueOnce({ rows: [{ total_count: 3 }] }) + .mockResolvedValueOnce({ + rows: [ + { + id: "log-1", + merchant_id: "m-1", + action: "login", + field_changed: null, + old_value: null, + new_value: null, + ip_address: "1.2.3.4", + user_agent: "ua", + timestamp: new Date(), + status: "success", + payload_hash: hash1, + signature: sig1, + }, + { + id: "log-2", + merchant_id: "m-1", + action: "login", + field_changed: null, + old_value: null, + new_value: null, + ip_address: "1.2.3.4", + user_agent: "ua", + timestamp: new Date(), + status: "success", + payload_hash: hash1, + signature: null, + }, + { + id: "log-3", + merchant_id: "m-1", + action: "login", + field_changed: null, + old_value: null, + new_value: null, + ip_address: "1.2.3.4", + user_agent: "ua", + timestamp: new Date(), + status: "success", + payload_hash: "wrong-hash", + signature: null, + } + ] + }); const originalSecret = process.env.AUDIT_LOG_SIGNING_SECRET; process.env.AUDIT_LOG_SIGNING_SECRET = "test-secret";