Files
dashcaddy/dashcaddy-api/__tests__/caddy-worker-naming-dc112.test.js
Hermes 65457ff8e0
CI / Test & Lint (push) Canceled after 0s
CI / Security audit (push) Canceled after 0s
feat(security): activate caddy security-event pipeline — bounded first-start replay, self-noise filter, host fidelity (DC-113) [glm-grade=A]
The caddy tail worker (DC-112) was 100% dead in prod: no /var/log/caddy
mount, no CADDY_ACCESS_LOG env, no global access log in the Caddyfile.
Store census 45,912 events, 100% source_type 'api', ZERO 'caddy'.

- createTail: firstStartMaxBytes (5 MiB) bounds first-ever-start replay
  against a long-lived access.log; multi-chunk partial-line discard on
  the jump; normal restarts resume at exact persisted offset (judge r1
  fix-first fold)
- worker: self-noise filter drops our own probe UAs
  (DashCaddy-Probe/1.0, DashCaddy-HealthCheck/1.0) from the derived
  store — raw log keeps everything; ~50-100 events/min of probe noise
  would otherwise bury perimeter signal in the 100k-cap store
- worker: metadata.host reads request.host (real caddy JSON nests it;
  verified against live /var/log/caddy/seeds.log — the DC-112 read was
  always null on live lines); top-level fallback kept
- worker: onAppear recovery log (DC-112 judge polish fold)
- start.sh: -v /var/log/caddy:/var/log/caddy:ro + CADDY_ACCESS_LOG env
- README: dead caddy-api/ dir refs -> dashcaddy-api/ (queue item e)
- tests: +12 DC-113 pins (hermetic, real worker + store); DC-112
  fixtures corrected to the real nested request.host shape

126 suites / 2841 tests green. Judge: GLM-5.3 round-1 B, round-2 A
(SHIP). Verdict urn:ump:mccln523fptotuvrmddlqpf4zpkrxf273tg4kyytuyy3776rj3pq
2026-08-23 12:40:32 -07:00

249 lines
11 KiB
JavaScript

/**
* 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 nested in request, duration in seconds.
fs.appendFileSync(ACCESS_LOG, JSON.stringify({
ts: 1787500800,
request: { host: 'plex.sami',
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,
request: { host: 'status.sami',
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,
request: { host: 'status.sami',
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,
request: { host: 'status.sami',
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,
request: { host: 'plex.sami',
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);
});
});