fix(audit): restore named audit actions for SSO gate traffic — 3 live defects (DC-111) [glm-grade=A]
1. audit-logger middleware computed action/resource from req.path INSIDE the res.json override — after the /api/v1 router rebased req.url to the router-relative path. resolveAction fell through ACTION_MAP for every HTTP request, producing 45,899 'unknown.get' entries since 2026-07-14. Fix: snapshot req.path/req.method at app-level (post-shim, pre-router). 2. DC-044 shim double-prefixed ALREADY-canonical /api/v1/auth/gate|x into /api/v1/v1/... → 401 for canonical-URI clients. Fix: rewrite only legacy /api/auth/* shapes; canonical pass through untouched. 3. event-store VALID_OUTCOMES lacked 'failure' → every failed API action's security event was rejected+dropped from security-events.jsonl. Fix: add 'failure' to the vocabulary set. 8 regression pins over a faithful shim→audit→router mount mirror. Suite: 124 suites / 2809 tests green. Judge: GLM-5.3 cold read round-1 A/ship, URN urn:ump:ywv6rpmx55tlxbgc7ciyxqfcmx2v6q756cjbmif2d66k4bwwn6ya
This commit is contained in:
@@ -0,0 +1,226 @@
|
||||
/**
|
||||
* DC-111 regression pins — audit trail correctness for the SSO gate path.
|
||||
*
|
||||
* THREE live defects found 2026-08-23 by probing the production container
|
||||
* (45,899 'unknown.get' entries in audit-log.json / security-events.jsonl
|
||||
* spanning 2026-07-14 → 2026-08-23, plus failed actions dropped from the
|
||||
* unified security event store):
|
||||
*
|
||||
* 1. audit-logger.middleware() computed action/resource from req.path
|
||||
* INSIDE the res.json override — i.e. AFTER the /api/v1 router had
|
||||
* rebased req.url to the router-relative path (/auth/gate/plex).
|
||||
* resolveAction fell through ACTION_MAP → 'unknown.get' for every
|
||||
* gate hit over HTTP. DC-028's unit tests passed because they call
|
||||
* resolveAction() directly with canonical paths and never exercise
|
||||
* the middleware over HTTP.
|
||||
*
|
||||
* 2. The DC-044 back-compat shim rewrote the ALREADY-canonical
|
||||
* /api/v1/auth/gate/<id> (and app-token) through '/api/v1' +
|
||||
* slice(4), producing /api/v1/v1/auth/gate/<id> → 401/404 for every
|
||||
* canonical-URI client — the exact drift case DC-044 meant to tolerate.
|
||||
*
|
||||
* 3. event-store VALID_OUTCOMES lacked 'failure' (the audit middleware's
|
||||
* vocabulary for data.success === false), so every failed API action's
|
||||
* security event was REJECTED and dropped from security-events.jsonl
|
||||
* ([AuditLogger] Security event emit failed: Invalid event: bad
|
||||
* outcome: failure — seen live in docker logs).
|
||||
*
|
||||
* These tests exercise a REAL Express app (not the module in isolation):
|
||||
* the app-level DC-044 shim + audit middleware + a /api/v1 router that
|
||||
* mounts the gate route the same way src/app.js does, so the router-rebase
|
||||
* behavior that caused defect 1 is reproduced faithfully.
|
||||
*/
|
||||
|
||||
const path = require('path');
|
||||
const fs = require('fs');
|
||||
const os = require('os');
|
||||
const express = require('express');
|
||||
const request = require('supertest');
|
||||
|
||||
// Hermetic sinks (same pattern as audit-logger-pii-masking-dc110.test.js)
|
||||
const TMP_DIR = fs.mkdtempSync(path.join(os.tmpdir(), 'dc111-audit-'));
|
||||
process.env.AUDIT_LOG_FILE = path.join(TMP_DIR, 'audit-log.json');
|
||||
process.env.SECURITY_EVENT_LOG_FILE = path.join(TMP_DIR, 'security-events.jsonl');
|
||||
|
||||
const auditLogger = require('../src/security/audit-logger');
|
||||
const { getStore } = require('../src/security/event-store');
|
||||
|
||||
// Reset singleton state between tests so audit-log.json assertions see a
|
||||
// clean file (the singleton StateManager caches nothing across writes, but
|
||||
// the event store keeps an in-memory index — point it at a fresh file by
|
||||
// writing directly and asserting file contents only).
|
||||
beforeEach(() => {
|
||||
fs.writeFileSync(process.env.AUDIT_LOG_FILE, '[]', 'utf8');
|
||||
fs.writeFileSync(process.env.SECURITY_EVENT_LOG_FILE, '', 'utf8');
|
||||
});
|
||||
|
||||
// Faithful mirror of the src/app.js mount chain relevant to this bug:
|
||||
// app-level legacy-path shim → audit middleware → /api/v1 router
|
||||
// with the gate route mounted at /auth/gate/:serviceId (as routes/auth
|
||||
// does), answering via res.json so the audit override fires.
|
||||
function buildApp() {
|
||||
const app = express();
|
||||
|
||||
// DC-044 shim — EXACT copy of the fixed src/app.js logic
|
||||
app.use((req, res, next) => {
|
||||
if (req.url.startsWith('/api/auth/gate/')
|
||||
|| req.url.startsWith('/api/auth/app-token/')
|
||||
|| req.url.startsWith('/api/auth/sso-exchange')) {
|
||||
req.url = '/api/v1' + req.url.slice(4);
|
||||
} else if (req.url.startsWith('/api/auth/totp/check-session')) {
|
||||
req.url = '/api/v1' + req.url.slice(9);
|
||||
} else if (req.url.startsWith('/api/v1/auth/totp/check-session')) {
|
||||
req.url = '/api/v1' + req.url.slice(12);
|
||||
}
|
||||
next();
|
||||
});
|
||||
|
||||
app.use(auditLogger.middleware());
|
||||
|
||||
const apiRouter = express.Router();
|
||||
apiRouter.get('/auth/gate/:serviceId', (req, res) => {
|
||||
// Simulate both outcomes: ?fail=1 makes the handler answer
|
||||
// success:false so the audit middleware records outcome 'failure'.
|
||||
if (req.query.fail === '1') {
|
||||
return res.status(401).json({ success: false, error: 'Session expired or invalid' });
|
||||
}
|
||||
res.json({ success: true, authenticated: true, credentialsInjected: false });
|
||||
});
|
||||
app.use('/api/v1', apiRouter);
|
||||
return app;
|
||||
}
|
||||
|
||||
async function waitForAuditEntry(predicate, { timeoutMs = 3000, what } = {}) {
|
||||
const start = Date.now();
|
||||
for (;;) {
|
||||
// StateManager's write is truncate-then-write (non-atomic, DC-110
|
||||
// lesson): a poll can catch the file between truncate and rewrite.
|
||||
// Treat unparsable reads as "not yet" instead of crashing.
|
||||
let entries;
|
||||
try {
|
||||
entries = JSON.parse(fs.readFileSync(process.env.AUDIT_LOG_FILE, 'utf8'));
|
||||
} catch (_) {
|
||||
entries = [];
|
||||
}
|
||||
const hit = entries.find(predicate);
|
||||
if (hit) return hit;
|
||||
if (Date.now() - start > timeoutMs) throw new Error(`timeout waiting for ${what || 'audit entry'}`);
|
||||
await new Promise(r => setTimeout(r, 50));
|
||||
}
|
||||
}
|
||||
|
||||
function readMirrorLines() {
|
||||
const raw = fs.readFileSync(process.env.SECURITY_EVENT_LOG_FILE, 'utf8');
|
||||
return raw.split('\n').filter(Boolean).map(l => JSON.parse(l));
|
||||
}
|
||||
|
||||
describe('DC-111 defect 1: audit action/resource computed from pre-router path', () => {
|
||||
test('canonical /api/v1/auth/gate/<id> logs as auth.credential-injection, not unknown.get', async () => {
|
||||
const app = buildApp();
|
||||
const res = await request(app).get('/api/v1/auth/gate/plex');
|
||||
expect(res.status).toBe(200);
|
||||
|
||||
const entry = await waitForAuditEntry(
|
||||
e => e.action === 'auth.credential-injection' && e.resource === 'gate/plex',
|
||||
{ what: 'auth.credential-injection entry' }
|
||||
);
|
||||
expect(entry.outcome).toBe('success');
|
||||
});
|
||||
|
||||
test('legacy /api/auth/gate/<id> (what Caddy forward_auth sends) also resolves the named action', async () => {
|
||||
const app = buildApp();
|
||||
const res = await request(app).get('/api/auth/gate/jellyfin');
|
||||
expect(res.status).toBe(200);
|
||||
|
||||
const entry = await waitForAuditEntry(
|
||||
e => e.action === 'auth.credential-injection' && e.resource === 'gate/jellyfin',
|
||||
{ what: 'legacy-shape credential-injection entry' }
|
||||
);
|
||||
expect(entry.outcome).toBe('success');
|
||||
});
|
||||
});
|
||||
|
||||
describe('DC-111 defect 2: DC-044 shim must not double-prefix canonical paths', () => {
|
||||
test('canonical /api/v1/auth/gate/<id> still reaches the route (no /api/v1/v1 rewrite)', async () => {
|
||||
const app = buildApp();
|
||||
const res = await request(app).get('/api/v1/auth/gate/plex');
|
||||
expect(res.status).toBe(200);
|
||||
expect(res.body.success).toBe(true);
|
||||
});
|
||||
|
||||
test('legacy /api/auth/gate/<id> still reaches the route (shim keeps working)', async () => {
|
||||
const app = buildApp();
|
||||
const res = await request(app).get('/api/auth/gate/plex');
|
||||
expect(res.status).toBe(200);
|
||||
expect(res.body.success).toBe(true);
|
||||
});
|
||||
|
||||
test('legacy totp check-session rewrite unchanged', async () => {
|
||||
const app = buildApp();
|
||||
// Route not mounted in this harness — assert the rewrite by querying the
|
||||
// shim behavior indirectly: /api/auth/totp/check-session must NOT 404 as
|
||||
// /v1/totp/... it becomes /api/v1/totp/check-session (unmounted → 404
|
||||
// from the api router, which proves it was NOT left under /auth).
|
||||
const res = await request(app).get('/api/auth/totp/check-session');
|
||||
expect(res.status).toBe(404);
|
||||
});
|
||||
});
|
||||
|
||||
describe('DC-111 defect 3: failed actions must land in the unified security event store', () => {
|
||||
test("outcome 'failure' is accepted by the event store", async () => {
|
||||
const app = buildApp();
|
||||
const res = await request(app).get('/api/v1/auth/gate/plex?fail=1');
|
||||
expect(res.status).toBe(401);
|
||||
|
||||
const entry = await waitForAuditEntry(
|
||||
e => e.outcome === 'failure' && e.resource === 'gate/plex',
|
||||
{ what: 'failure audit entry' }
|
||||
);
|
||||
expect(entry.action).toBe('auth.credential-injection');
|
||||
|
||||
// Mirror write is async after the audit entry — poll the jsonl
|
||||
const start = Date.now();
|
||||
for (;;) {
|
||||
const lines = readMirrorLines();
|
||||
const ev = lines.find(l => (l.metadata || {}).audit_id === entry.id);
|
||||
if (ev) {
|
||||
expect(ev.outcome).toBe('failure');
|
||||
expect(ev.action).toBe('auth.credential-injection');
|
||||
expect(ev.severity).toBe('warn'); // auth.* + failure escalates per resolveSeverity
|
||||
return;
|
||||
}
|
||||
if (Date.now() - start > 3000) throw new Error('mirror event never written for failed action');
|
||||
await new Promise(r => setTimeout(r, 50));
|
||||
}
|
||||
});
|
||||
|
||||
test('VALID_OUTCOMES includes failure (unit pin on the set itself)', () => {
|
||||
// Direct pin so a future revert of the event-store change fails loudly.
|
||||
const store = getStore();
|
||||
const bad = store._validate({ source_type: 'api', severity: 'info', outcome: 'failure' });
|
||||
expect(bad).toBeNull();
|
||||
});
|
||||
});
|
||||
|
||||
describe('DC-111: historical-corpus shape must never regress', () => {
|
||||
test('no unknown.get entries are produced for gate traffic (canonical or legacy)', async () => {
|
||||
const app = buildApp();
|
||||
await request(app).get('/api/v1/auth/gate/plex');
|
||||
await request(app).get('/api/auth/gate/plex');
|
||||
await request(app).get('/api/v1/auth/gate/sonarr?fail=1');
|
||||
|
||||
await waitForAuditEntry(e => e.resource === 'gate/sonarr' && e.outcome === 'failure', {
|
||||
timeoutMs: 6000,
|
||||
what: 'third entry',
|
||||
});
|
||||
// give the async log() a beat to finish all three
|
||||
await new Promise(r => setTimeout(r, 300));
|
||||
|
||||
const entries = JSON.parse(fs.readFileSync(process.env.AUDIT_LOG_FILE, 'utf8'));
|
||||
const unknownGate = entries.filter(e => e.action.startsWith('unknown.'));
|
||||
expect(unknownGate).toEqual([]);
|
||||
// Each fired request must be present; supertest may issue an extra
|
||||
// redirect-following request on some code paths, so assert >= not ==.
|
||||
expect(entries.filter(e => e.action === 'auth.credential-injection').length).toBeGreaterThanOrEqual(3);
|
||||
});
|
||||
});
|
||||
@@ -235,9 +235,9 @@ async function createApp() {
|
||||
//
|
||||
// Path mapping (any -> canonical):
|
||||
// /api/auth/gate/<id> -> /api/v1/auth/gate/<id> (mounted at /auth/gate/:serviceId)
|
||||
// /api/v1/auth/gate/<id> -> /api/v1/auth/gate/<id> (drift, gate pre-1.5.0 sometimes used this)
|
||||
// /api/v1/auth/gate/<id> -> (unchanged — already canonical, DC-111)
|
||||
// /api/auth/app-token/<id> -> /api/v1/auth/app-token/<id> (mounted at /auth/app-token/:serviceId)
|
||||
// /api/v1/auth/app-token/<id> -> /api/v1/auth/app-token/<id> (drift)
|
||||
// /api/v1/auth/app-token/<id> -> (unchanged — already canonical, DC-111)
|
||||
// /api/auth/totp/check-session -> /api/v1/totp/check-session (mounted at /totp/check-session — no /auth prefix)
|
||||
// /api/v1/auth/totp/check-session->/api/v1/totp/check-session (drift)
|
||||
// /api/auth/sso-exchange -> /api/v1/auth/sso-exchange (mounted at /auth/sso-exchange, same shape as gate/app-token)
|
||||
@@ -254,8 +254,14 @@ async function createApp() {
|
||||
// — needs the same rewrite as gate/app-token, not the check-session one
|
||||
// (this route's canonical mount already includes /auth/).
|
||||
app.use((req, res, next) => {
|
||||
if (req.url.startsWith('/api/auth/gate/') || req.url.startsWith('/api/v1/auth/gate/')
|
||||
|| req.url.startsWith('/api/auth/app-token/') || req.url.startsWith('/api/v1/auth/app-token/')
|
||||
// DC-111: the '/api/v1/...' drift variants are ALREADY canonical — the
|
||||
// gate and app-token routes mount at /auth/* INSIDE the /api/v1 router.
|
||||
// DC-044 added them to the '/api' + slice(4) rewrite, which turned
|
||||
// /api/v1/auth/gate/plex into /api/v1/v1/auth/gate/plex → 401/404 for
|
||||
// every canonical-URI client (the exact drift case DC-044 meant to
|
||||
// tolerate). Only the legacy '/api/auth/...' shapes need rewriting.
|
||||
if (req.url.startsWith('/api/auth/gate/')
|
||||
|| req.url.startsWith('/api/auth/app-token/')
|
||||
|| req.url.startsWith('/api/auth/sso-exchange')) {
|
||||
req.url = '/api/v1' + req.url.slice(4); // '/api'.length === 4
|
||||
} else if (req.url.startsWith('/api/auth/totp/check-session')) {
|
||||
@@ -264,6 +270,7 @@ async function createApp() {
|
||||
req.url = '/api/v1' + req.url.slice(9); // '/api/auth'.length === 9
|
||||
} else if (req.url.startsWith('/api/v1/auth/totp/check-session')) {
|
||||
// Drift: /api/v1/auth/totp/check-session -> /api/v1/totp/check-session
|
||||
// (canonical route is /totp/check-session — genuinely different mount)
|
||||
// Drop the '/api/v1/auth' prefix (12 chars), keep the leading '/'.
|
||||
req.url = '/api/v1' + req.url.slice(12); // '/api/v1/auth'.length === 12
|
||||
}
|
||||
|
||||
@@ -228,12 +228,29 @@ class AuditLogger {
|
||||
return (req, res, next) => {
|
||||
if (this.shouldSkip(req.method, req.path)) return next();
|
||||
|
||||
// DC-111: snapshot the request path NOW, at app-level (pre-router).
|
||||
// The res.json override below fires AFTER the /api/v1 router has
|
||||
// dispatched the request, and Express rebases req.url to the
|
||||
// router-relative path at that point (/api/v1/auth/gate/plex becomes
|
||||
// /auth/gate/plex). resolveAction/extractResource on the rebased path
|
||||
// fall through ACTION_MAP and derive 'unknown.*' — which is exactly
|
||||
// how 45,899 'unknown.get' entries landed in the audit trail between
|
||||
// 2026-07-14 and 2026-08-23. Snapshot req.path in the middleware body
|
||||
// (string copy — req.path is a live getter over req.url): this runs
|
||||
// after the DC-044 legacy-prefix shim has canonicalized /api/auth/*
|
||||
// to /api/v1/* but before the router rebase, so ACTION_MAP sees the
|
||||
// canonical path for both legacy and canonical clients. Do NOT use
|
||||
// req.originalUrl — it freezes the PRE-shim legacy path, which
|
||||
// ACTION_MAP does not cover.
|
||||
const requestPath = req.path;
|
||||
const requestMethod = req.method;
|
||||
|
||||
const originalJson = res.json.bind(res);
|
||||
res.json = (data) => {
|
||||
// Log asynchronously — don't block the response
|
||||
const ip = req.ip || req.socket?.remoteAddress || '';
|
||||
const action = this.resolveAction(req.method, req.path);
|
||||
const resource = this.extractResource(req.path);
|
||||
const action = this.resolveAction(requestMethod, requestPath);
|
||||
const resource = this.extractResource(requestPath);
|
||||
const outcome = data && data.success === false ? 'failure' : 'success';
|
||||
|
||||
// Sanitize details — don't log passwords or tokens
|
||||
|
||||
@@ -36,7 +36,7 @@ const MAX_EVENTS_ON_DISK = parseInt(process.env.SECURITY_EVENT_MAX_DISK || '
|
||||
|
||||
const VALID_SOURCE_TYPES = new Set(['api', 'caddy', 'fail2ban', 'shared-bans', 'syslog', 'agent']);
|
||||
const VALID_SEVERITIES = new Set(['info', 'notice', 'warn', 'error', 'critical']);
|
||||
const VALID_OUTCOMES = new Set(['success', 'denied', 'blocked', 'rate-limited', 'error', 'unknown']);
|
||||
const VALID_OUTCOMES = new Set(['success', 'failure', 'denied', 'blocked', 'rate-limited', 'error', 'unknown']);
|
||||
|
||||
class SecurityEventStore extends EventEmitter {
|
||||
constructor(opts = {}) {
|
||||
|
||||
Reference in New Issue
Block a user