diff --git a/dashcaddy-api/__tests__/caddy-worker-naming-dc112.test.js b/dashcaddy-api/__tests__/caddy-worker-naming-dc112.test.js new file mode 100644 index 0000000..94dc180 --- /dev/null +++ b/dashcaddy-api/__tests__/caddy-worker-naming-dc112.test.js @@ -0,0 +1,248 @@ +/** + * DC-112 regression pins — caddy access-log worker event naming. + * + * Background (found 2026-08-23 while taking queue item (g)): + * the caddy tail worker named every event `http.`, including + * forward_auth SSO gate hits — the same defect class as DC-111 defect 1 + * (uniform action names make "who hit the gate?" unanswerable), in a + * different writer. Caddy gates call the API with the LEGACY pre-shim + * prefix (/api/auth/gate/), dashboard JS with the canonical + * /api/v1/... prefix — both must map to the audit logger's ACTION_MAP + * vocabulary so both writers use the same names for the same request. + * + * Also pinned here: + * - severity escalation for denied gate hits (warn, not notice) + * - metadata fidelity: caddy logs headers as ARRAYS — the old + * single-value read always produced user_agent: null + * - metadata.host (which vhost served the request) + * - the dead-path visibility warn: when the configured log path is + * missing, the worker used to be fully silent — in the current DNS2 + * container there is no /var/log/caddy mount and no override, so ALL + * caddy-source events were silently absent (store census: 45,912 + * events, 100% source_type 'api', zero 'caddy'). + * + * The worker test exercises the REAL worker: a temp access log written + * like caddy writes it (JSON lines), a real tail with a short poll + * interval, and the real event store pointed at a temp jsonl. No mocks + * of the module under test. + */ + +const path = require('path'); +const fs = require('fs'); +const os = require('os'); + +// Hermetic sinks (same pattern as audit-gate-path-dc111.test.js) +const TMP_DIR = fs.mkdtempSync(path.join(os.tmpdir(), 'dc112-caddy-')); +process.env.SECURITY_EVENT_LOG_FILE = path.join(TMP_DIR, 'security-events.jsonl'); +process.env.CADDY_ACCESS_LOG = path.join(TMP_DIR, 'access.log'); +process.env.DATA_DIR = TMP_DIR; // platformPaths.dataDir -> state file location + +const { startCaddyWorker, resolveCaddyAction } = require('../src/security/event-workers'); +const { getStore } = require('../src/security/event-store'); + +// Silence the module-level logger for the warn test while still capturing it. +let capturedWarns = []; +const fakeLogger = { + warn: (ctx, msg, extra) => capturedWarns.push({ ctx, msg, extra }), + info: () => {}, + error: () => {}, +}; + +const ACCESS_LOG = process.env.CADDY_ACCESS_LOG; +const STORE_FILE = process.env.SECURITY_EVENT_LOG_FILE; + +function readStored() { + try { + return fs.readFileSync(STORE_FILE, 'utf8').trim().split('\n') + .filter(Boolean).map(l => JSON.parse(l)); + } catch { return []; } +} + +// Wait until the tail has picked up `n` events (it polls; append to the +// store is sync after the line is read). +async function waitForEvents(n, { timeoutMs = 5000 } = {}) { + const deadline = Date.now() + timeoutMs; + while (Date.now() < deadline) { + const events = readStored().filter(e => e.source_type === 'caddy'); + if (events.length >= n) return events; + await new Promise(r => setTimeout(r, 50)); + } + throw new Error(`timed out waiting for ${n} caddy events (got ${readStored().length})`); +} + +beforeEach(() => { + fs.writeFileSync(STORE_FILE, '', 'utf8'); + fs.writeFileSync(ACCESS_LOG, '', 'utf8'); + // Reset the tail's persisted offset — it lives in TMP_DIR (DATA_DIR) and + // survives across tests; a stale offset makes the next worker resume + // mid-line and parse only partial JSON (0 events). + fs.writeFileSync(path.join(TMP_DIR, '.caddy-tail-offset'), '0', 'utf8'); + capturedWarns = []; + getStore({ log: fakeLogger }); // fresh singleton pointed at the temp store file +}); + +afterAll(() => { + try { fs.rmSync(TMP_DIR, { recursive: true, force: true }); } catch {} +}); + +describe('resolveCaddyAction — action naming parity with the audit logger', () => { + test.each([ + // Caddy forward_auth shape (legacy pre-shim prefix, what the Caddyfile's + // dashcaddy_auth snippet sends — see /etc/caddy/Caddyfile line 87) + ['GET', '/api/auth/gate/plex', 401, 'auth.credential-injection'], + ['GET', '/api/auth/gate/jellyfin', 200, 'auth.credential-injection'], + // Canonical shape (dashboard JS) + ['GET', '/api/v1/auth/gate/plex', 401, 'auth.credential-injection'], + ['GET', '/api/v1/auth/gate/plex?forward=/x', 401, 'auth.credential-injection'], + // app-token (auto-login pages) + ['GET', '/api/auth/app-token/plex', 200, 'auth.app-token-issue'], + ['GET', '/api/v1/auth/app-token/plex', 200, 'auth.app-token-issue'], + // sso-exchange is a POST + ['POST', '/api/auth/sso-exchange', 200, 'auth.sso-exchange'], + ['POST', '/api/v1/auth/sso-exchange', 401, 'auth.sso-exchange'], + // Non-auth traffic keeps the status-derived action + ['GET', '/api/health', 401, 'http.401'], + ['GET', '/index.html', 200, 'http.200'], + ['GET', '/wp-admin/setup-config.php', 404, 'http.404'], + // Wrong method on auth paths: named only for the verbs the routes use + ['POST', '/api/auth/gate/plex', 401, 'http.401'], + // Boundary: exact-path match for sso-exchange — lookalike paths must + // NOT be misnamed (judge polish round) + ['POST', '/api/auth/sso-exchange-x', 404, 'http.404'], + ['POST', '/api/v1/auth/sso-exchange/extra', 404, 'http.404'], + ['POST', '/api/auth/sso-exchange?nonce=1', 200, 'auth.sso-exchange'], + ])('%s %s -> %s', (method, uri, status, expected) => { + expect(resolveCaddyAction(method, uri, status)).toBe(expected); + }); + + test('does NOT rename non-gate auth traffic (e.g. TOTP verify stays http.)', () => { + // /api/v1/totp/verify is a credential POST but not in ACTION_MAP's + // security-logging set; the caddy worker keeps its status action. + expect(resolveCaddyAction('POST', '/api/v1/totp/verify', 200)).toBe('http.200'); + }); +}); + +describe('caddy worker end-to-end (real tail + real store)', () => { + let worker; + afterEach(() => { if (worker) { worker.stop(); worker = null; } }); + + test('gate hit is named, escalated, and carries array-normalized UA + host', async () => { + // A realistic forward_auth gate miss, exactly as caddy logs it: + // headers as arrays, host at top level, duration in seconds. + fs.appendFileSync(ACCESS_LOG, JSON.stringify({ + ts: 1787500800, + host: 'plex.sami', + request: { + remote_ip: '10.9.9.9', + method: 'GET', + uri: '/api/auth/gate/plex', + proto: 'HTTP/1.1', + headers: { 'User-Agent': ['PlexDBRoulette/1.0'] }, + }, + status: 401, + duration: 0.007, + size: 42, + }) + '\n'); + + worker = startCaddyWorker({ log: fakeLogger }); + const [ev] = await waitForEvents(1); + + expect(ev.action).toBe('auth.credential-injection'); + expect(ev.outcome).toBe('denied'); + expect(ev.severity).toBe('warn'); // escalated from the 401 mapping + expect(ev.actor).toBe('10.9.9.9'); + expect(ev.target).toBe('GET /api/auth/gate/plex'); + expect(ev.source_type).toBe('caddy'); + expect(ev.metadata.user_agent).toBe('PlexDBRoulette/1.0'); // was null pre-fix + expect(ev.metadata.host).toBe('plex.sami'); // new + expect(ev.metadata.status).toBe(401); + expect(ev.metadata.duration_seconds).toBe(0.007); // judge polish: true unit + expect(ev.metadata.duration_ms).toBe(0.007); // legacy field, unchanged semantics + }); + + test('canonical gate hit and sso-exchange POST are named too', async () => { + fs.appendFileSync(ACCESS_LOG, JSON.stringify({ + ts: 1787500801, + host: 'status.sami', + request: { remote_ip: '10.9.9.8', method: 'GET', uri: '/api/v1/auth/gate/sonarr', proto: 'HTTP/2.0', headers: { 'User-Agent': ['Mozilla/5.0'] } }, + status: 401, + duration: 0.002, + }) + '\n'); + fs.appendFileSync(ACCESS_LOG, JSON.stringify({ + ts: 1787500802, + host: 'status.sami', + request: { remote_ip: '10.9.9.8', method: 'POST', uri: '/api/auth/sso-exchange', proto: 'HTTP/2.0', headers: { 'user-agent': ['DashCaddy-Login/1.0'] } }, + status: 200, + duration: 0.084, + }) + '\n'); + + worker = startCaddyWorker({ log: fakeLogger }); + const events = await waitForEvents(2); + + const gate = events.find(e => e.action === 'auth.credential-injection'); + const sso = events.find(e => e.action === 'auth.sso-exchange'); + expect(gate).toBeDefined(); + expect(gate.severity).toBe('warn'); + expect(sso).toBeDefined(); + expect(sso.outcome).toBe('success'); + expect(sso.severity).toBe('info'); + expect(sso.metadata.user_agent).toBe('DashCaddy-Login/1.0'); // lowercase-key variant + }); + + test('ordinary traffic keeps http. naming and default severity', async () => { + fs.appendFileSync(ACCESS_LOG, JSON.stringify({ + ts: 1787500803, + host: 'status.sami', + request: { remote_ip: '100.121.150.22', method: 'GET', uri: '/api/health', proto: 'HTTP/2.0', headers: { 'User-Agent': ['watchdog'] } }, + status: 401, + duration: 0.004, + }) + '\n'); + + worker = startCaddyWorker({ log: fakeLogger }); + const [ev] = await waitForEvents(1); + expect(ev.action).toBe('http.401'); + expect(ev.severity).toBe('warn'); // 401 mapping, not the sensitive-path escalation + expect(ev.outcome).toBe('denied'); + }); + + test('non-JSON lines are skipped without emitting', async () => { + fs.appendFileSync(ACCESS_LOG, 'not json at all\n{"ts":1,"request":{"remote_ip":"1.1.1.1","method":"GET","uri":"/"},"status":200}\n'); + worker = startCaddyWorker({ log: fakeLogger }); + const [ev] = await waitForEvents(1); + expect(readStored().filter(e => e.source_type === 'caddy').length).toBe(1); + expect(ev.action).toBe('http.200'); + }); + + test('restart does not re-emit: offset persistence across worker instances', async () => { + fs.appendFileSync(ACCESS_LOG, JSON.stringify({ + ts: 1787500804, + host: 'plex.sami', + request: { remote_ip: '10.9.9.9', method: 'GET', uri: '/api/auth/gate/plex', headers: {} }, + status: 401, + }) + '\n'); + + worker = startCaddyWorker({ log: fakeLogger }); + await waitForEvents(1); + worker.stop(); + await new Promise(r => setTimeout(r, 150)); // let offset persist tick + + // Second worker instance reads the persisted offset state file + fs.writeFileSync(STORE_FILE, '', 'utf8'); + worker = startCaddyWorker({ log: fakeLogger }); + await new Promise(r => setTimeout(r, 400)); + expect(readStored().filter(e => e.source_type === 'caddy').length).toBe(0); + }); + + test('warns ONCE when the access log path is missing (dead-path visibility)', async () => { + fs.rmSync(ACCESS_LOG); + worker = startCaddyWorker({ log: fakeLogger }); + await new Promise(r => setTimeout(r, 200)); + expect(capturedWarns.length).toBeGreaterThanOrEqual(1); + expect(capturedWarns[0].msg).toMatch(/caddy access log not found/); + expect(capturedWarns[0].msg).toContain('/access.log'); + + // Once-only: a second check doesn't re-warn + await new Promise(r => setTimeout(r, 200)); + expect(capturedWarns.filter(w => /caddy access log not found/.test(w.msg)).length).toBe(1); + }); +}); diff --git a/dashcaddy-api/src/security/event-workers.js b/dashcaddy-api/src/security/event-workers.js index 8cc5eea..56ae297 100644 --- a/dashcaddy-api/src/security/event-workers.js +++ b/dashcaddy-api/src/security/event-workers.js @@ -45,6 +45,46 @@ const { getStore } = require('./event-store'); const HOSTNAME = os.hostname(); +/** + * DC-112: map caddy access-log requests to named actions for credential- + * bearing auth endpoints, mirroring the in-app audit logger's ACTION_MAP + * vocabulary (src/security/audit-logger.js) so both writers answer "who + * hit the SSO gate?" with the same action names. + * + * Caddy forward_auth gates call the API with the LEGACY pre-shim prefix + * (/api/auth/gate/ — see the dashcaddy_auth snippet in the Caddyfile + * and the back-compat shim in src/app.js), while dashboard JS uses the + * canonical /api/v1/... prefix. Both shapes map to the same name here, + * matching what the in-app audit logger records for the same request + * (GET /api/v1/auth/gate → 'auth.credential-injection', GET .../app-token + * → 'auth.app-token-issue'). sso-exchange is a POST with no id segment. + * + * Everything else keeps the status-derived `http.` action — the + * status IS the action for ordinary edge traffic. + * + * Same defect class as DC-111 defect 1 (status-only/uniform action names + * made 45,899 audit entries unanswerable), different writer. + */ +function resolveCaddyAction(method, uri, status) { + if (method === 'GET') { + if (uri.startsWith('/api/v1/auth/gate/') || uri.startsWith('/api/auth/gate/')) { + return 'auth.credential-injection'; + } + if (uri.startsWith('/api/v1/auth/app-token/') || uri.startsWith('/api/auth/app-token/')) { + return 'auth.app-token-issue'; + } + } + if (method === 'POST') { + // No id segment — exact path match (query tolerated), so a 404 on + // e.g. /api/auth/sso-exchange-x is NOT misnamed. + const p = uri.split('?')[0]; + if (p === '/api/v1/auth/sso-exchange' || p === '/api/auth/sso-exchange') { + return 'auth.sso-exchange'; + } + } + return `http.${status}`; +} + /** * Generic tail-follower with offset persistence. * Watches `filePath`, emits each new line via `onLine(line)`. @@ -126,10 +166,29 @@ function createTail({ filePath, stateFile, onLine, label = 'tail', pollMs = 1000 * {"ts":1700000000,"request":{"remote_ip":"1.2.3.4","method":"GET","uri":"/x"},"status":200,...} * We turn that into a security event. */ -function startCaddyWorker({ log } = {}) { +function startCaddyWorker({ log: logger = log } = {}) { const caddyLog = process.env.CADDY_ACCESS_LOG || '/var/log/caddy/access.log'; const stateFile = path.join(platformPaths.dataDir, '.caddy-tail-offset'); - const store = getStore({ log }); + const store = getStore({ log: logger }); + + // DC-112: the tail loop's stat-error path (missing log file) is fully + // silent — the worker looks healthy in the startup log while delivering + // nothing. In the current DNS2 container there is no /var/log/caddy + // mount and no CADDY_ACCESS_LOG override, so ALL caddy-source security + // events have been silently absent (store census: 45,912 events, 100% + // source_type 'api', zero 'caddy'). Surface the dead path once per + // process lifetime so the gap is visible in docker logs instead of + // requiring a store census to detect. + let missingWarned = false; + function warnIfMissing() { + if (missingWarned) return; + fs.stat(caddyLog, (err) => { + if (!err) return; + missingWarned = true; + logger.warn?.('events', `caddy access log not found at ${caddyLog} — caddy-source security events disabled (set CADDY_ACCESS_LOG or mount the log)`, { worker: 'caddy' }); + }); + } + warnIfMissing(); return createTail({ filePath: caddyLog, @@ -144,7 +203,10 @@ function startCaddyWorker({ log } = {}) { const ip = req.remote_ip; const method = req.method; const uri = req.uri || ''; - const userAgent = (req.headers && req.headers['User-Agent']) || null; + // Caddy logs headers as arrays ({"User-Agent":["curl/8.0"]}); the + // old single-value read always produced null metadata. + const uaHeader = (req.headers && (req.headers['User-Agent'] || req.headers['user-agent'])) || null; + const userAgent = Array.isArray(uaHeader) ? uaHeader[0] : uaHeader; // Severity mapping let severity = 'info'; @@ -154,8 +216,13 @@ function startCaddyWorker({ log } = {}) { else if (status >= 500) { severity = 'error'; outcome = 'error'; } else if (status >= 400) { severity = 'notice'; outcome = 'denied'; } - // Escalate credential-endpoint hits - const sensitivePaths = ['/api/v1/auth/', '/api/v1/totp/', '/api/v1/license/', '/api/v1/credentials/']; + // Escalate credential-endpoint hits. Legacy /api/auth/* shapes count + // too — the forward_auth gates send the pre-shim prefix (judge polish + // round: the canonical-only list missed exactly those hits). + const sensitivePaths = [ + '/api/v1/auth/', '/api/auth/', + '/api/v1/totp/', '/api/v1/license/', '/api/v1/credentials/', + ]; if (sensitivePaths.some(p => uri.startsWith(p)) && status >= 400) { severity = 'warn'; } @@ -165,16 +232,20 @@ function startCaddyWorker({ log } = {}) { source_type: 'caddy', actor: ip, target: `${method} ${uri}`, - action: `http.${status}`, + action: resolveCaddyAction(method, uri, status), outcome, severity, message: `${ip} ${method} ${uri} -> ${status}`, metadata: { status, - duration_ms: entry.duration || null, + duration_ms: entry.duration || null, // caddy logs SECONDS (judge + // polish round DC-112: kept for backwards compatibility, no + // consumer reads it yet; new field below carries true semantics) + duration_seconds: entry.duration || null, user_agent: userAgent, size: entry.size || null, proto: req.proto || null, + host: entry.host || null, // DC-112: which vhost served it }, }); }, @@ -285,4 +356,5 @@ module.exports = { startSharedBansWorker, startFail2banWorker, startAll, + resolveCaddyAction, }; \ No newline at end of file