fix(security): name caddy-worker SSO gate events + dead-path visibility (DC-112) [glm-grade=A]
Queue item (g) — same defect class as DC-111 defect 1, different writer: the caddy access-log tail named every event http.<status>, so forward_auth gate hits were unanswerable in the unified security event store. - resolveCaddyAction() mirrors audit-logger ACTION_MAP vocabulary for BOTH URI shapes (legacy /api/auth/gate/<id> from Caddyfile line 87, canonical /api/v1/... from dashboard JS): auth.credential-injection, auth.app-token-issue, auth.sso-exchange (exact-path match, boundary-tested) - severity escalation now covers the legacy /api/auth/ prefix too - metadata fidelity: caddy logs headers as ARRAYS — old single-value read always produced user_agent:null; added metadata.host (vhost) and duration_seconds (caddy logs seconds; duration_ms kept, no consumers) - dead-path visibility: once-per-process warn when the access log is missing. Live discovery: prod store has 45,912 events, 100% source_type 'api', ZERO 'caddy' — the container has no /var/log/caddy mount, so the worker silently no-ops. Infra wiring queued separately. - new __tests__/caddy-worker-naming-dc112.test.js: 22 pins (real tail + real store, hermetic sinks, both URI shapes, boundary rows, offset persistence, once-warn). Full suite 125/2831 green. Judge: GLM-5.3 cold read round-1 A (deleg_65498358, 3 polish items folded) + round-2 A (deleg_eed9dcbf, judge re-ran suite itself). URN urn:ump:mjbwfcw6z7budx45s2rutovw5fatpp4jyzzspo7tq6nzajayulmq
This commit is contained in:
@@ -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.<status>`, 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/<id>), 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.<status>)', () => {
|
||||
// /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.<status> 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);
|
||||
});
|
||||
});
|
||||
@@ -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/<id> — 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.<status>` 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,
|
||||
};
|
||||
Reference in New Issue
Block a user