From 65457ff8e0c12cca63157c9561919cb0b2a05b47 Mon Sep 17 00:00:00 2001 From: Hermes Date: Sun, 23 Aug 2026 12:40:32 -0700 Subject: [PATCH] =?UTF-8?q?feat(security):=20activate=20caddy=20security-e?= =?UTF-8?q?vent=20pipeline=20=E2=80=94=20bounded=20first-start=20replay,?= =?UTF-8?q?=20self-noise=20filter,=20host=20fidelity=20(DC-113)=20[glm-gra?= =?UTF-8?q?de=3DA]?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 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 --- README.md | 6 +- .../caddy-worker-naming-dc112.test.js | 22 +- .../caddy-worker-pipeline-dc113.test.js | 314 ++++++++++++++++++ dashcaddy-api/src/security/event-workers.js | 75 ++++- start.sh | 2 + 5 files changed, 402 insertions(+), 17 deletions(-) create mode 100644 dashcaddy-api/__tests__/caddy-worker-pipeline-dc113.test.js diff --git a/README.md b/README.md index 700a9a6..a17f2c2 100644 --- a/README.md +++ b/README.md @@ -355,9 +355,9 @@ dashcaddy/ ├── status/ # Dashboard frontend │ ├── index.html # Main dashboard │ └── assets/ # Logos, icons, fonts -├── caddy-api/ # API backend +├── dashcaddy-api/ # API backend │ ├── server.js # Express server -│ ├── app-templates.js # App template definitions +│ ├── src/docker/app-templates.js # App template definitions │ └── package.json # Dependencies ├── dashcaddy-installer/ # Electron installer (WIP) └── docs/ # Documentation @@ -365,7 +365,7 @@ dashcaddy/ ### Adding Custom App Templates -Edit `caddy-api/app-templates.js`: +Edit `dashcaddy-api/src/docker/app-templates.js`: ```javascript "myapp": { diff --git a/dashcaddy-api/__tests__/caddy-worker-naming-dc112.test.js b/dashcaddy-api/__tests__/caddy-worker-naming-dc112.test.js index 94dc180..868242e 100644 --- a/dashcaddy-api/__tests__/caddy-worker-naming-dc112.test.js +++ b/dashcaddy-api/__tests__/caddy-worker-naming-dc112.test.js @@ -128,11 +128,11 @@ describe('caddy worker end-to-end (real tail + real store)', () => { 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. + // headers as arrays, host nested in request, duration in seconds. fs.appendFileSync(ACCESS_LOG, JSON.stringify({ ts: 1787500800, - host: 'plex.sami', - request: { + request: { host: 'plex.sami', + remote_ip: '10.9.9.9', method: 'GET', uri: '/api/auth/gate/plex', @@ -163,15 +163,15 @@ describe('caddy worker end-to-end (real tail + real store)', () => { 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'] } }, + 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, - 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'] } }, + 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'); @@ -192,8 +192,8 @@ describe('caddy worker end-to-end (real tail + real store)', () => { 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'] } }, + 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'); @@ -216,8 +216,8 @@ describe('caddy worker end-to-end (real tail + real store)', () => { 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: {} }, + request: { host: 'plex.sami', + remote_ip: '10.9.9.9', method: 'GET', uri: '/api/auth/gate/plex', headers: {} }, status: 401, }) + '\n'); diff --git a/dashcaddy-api/__tests__/caddy-worker-pipeline-dc113.test.js b/dashcaddy-api/__tests__/caddy-worker-pipeline-dc113.test.js new file mode 100644 index 0000000..9507190 --- /dev/null +++ b/dashcaddy-api/__tests__/caddy-worker-pipeline-dc113.test.js @@ -0,0 +1,314 @@ +/** + * DC-113 regression pins — caddy security-event pipeline activation. + * + * Background (queue item h, 2026-08-23): the caddy tail worker was fully + * wired (DC-112 named the gate events) but 100% DEAD in production — no + * /var/log/caddy mount in the container, no CADDY_ACCESS_LOG env, and no + * global access log in the Caddyfile. Store census: 45,912 events, 100% + * source_type 'api', ZERO 'caddy'. DC-113 wires the pipeline: + * - global Caddyfile logger `dashcaddy-access` (file /var/log/caddy/ + * access.log, roll 50MiB keep 5) + `log dashcaddy-access` in every + * site block (via caddy-apply, host-side — NOT pinned here) + * - start.sh: -v /var/log/caddy:/var/log/caddy:ro + CADDY_ACCESS_LOG env + * - worker fixes pinned in THIS file: + * 1. real caddy JSON nests `host` inside `request` — the top-level + * read (DC-112, fixture-shaped) always produced null on live lines + * 2. self-noise filter: the API's own probes (DashCaddy-Probe/1.0, + * DashCaddy-HealthCheck/1.0) hit Caddy every 10-30s per service + * and would bury real perimeter signal in the 100k-event store + * 3. recovered-log visibility (DC-112 judge polish fold): when the + * access log appears after startup, one info line is logged + * + * All tests use the REAL worker: temp access log, real tail, real event + * store, hermetic sinks. No mocks of the module under test. + */ + +const path = require('path'); +const fs = require('fs'); +const os = require('os'); + +// Hermetic sinks (same pattern as caddy-worker-naming-dc112.test.js) +const TMP_DIR = fs.mkdtempSync(path.join(os.tmpdir(), 'dc113-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; + +const { startCaddyWorker } = require('../src/security/event-workers'); +const { getStore } = require('../src/security/event-store'); + +let capturedWarns = []; +let capturedInfos = []; +const fakeLogger = { + warn: (ctx, msg, extra) => capturedWarns.push({ ctx, msg, extra }), + info: (ctx, msg, extra) => capturedInfos.push({ ctx, msg, extra }), + 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 []; } +} + +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().filter(e => e.source_type === 'caddy').length})`); +} + +beforeEach(() => { + fs.writeFileSync(STORE_FILE, '', 'utf8'); + fs.writeFileSync(ACCESS_LOG, '', 'utf8'); + // Reset the tail's persisted offset (same flake lesson as DC-112). + fs.writeFileSync(path.join(TMP_DIR, '.caddy-tail-offset'), '0', 'utf8'); + capturedWarns = []; + capturedInfos = []; + getStore({ log: fakeLogger }); // fresh singleton pointed at the temp store file +}); + +afterAll(() => { + try { fs.rmSync(TMP_DIR, { recursive: true, force: true }); } catch {} +}); + +describe('DC-113: real caddy JSON shape — host nested inside request', () => { + let worker; + afterEach(() => { if (worker) { worker.stop(); worker = null; } }); + + test('metadata.host reads request.host on live caddy lines (was null pre-DC-113)', async () => { + // Exact shape from /var/log/caddy/seeds.log on DNS2 (2026-08-23): + // host is nested in request; headers are arrays. + fs.appendFileSync(ACCESS_LOG, JSON.stringify({ + level: 'info', + ts: 1787461432.8595521, + logger: 'http.log.access.dashcaddy-access', + msg: 'handled request', + request: { + remote_ip: '162.243.83.227', + remote_port: '57446', + client_ip: '162.243.83.227', + proto: 'HTTP/1.1', + method: 'TRACE', + host: 'seeds.cryptographic-triangles.org', + uri: '/', + headers: { Connection: ['close'], 'User-Agent': ['Mozilla/5.0'] }, + tls: { resumed: false, version: 772, cipher_suite: 4865, proto: 'http/1.1', server_name: 'seeds.cryptographic-triangles.org', ech: false }, + }, + bytes_read: 0, + user_id: '', + duration: 0.000070446, + size: 0, + status: 404, + }) + '\n'); + + worker = startCaddyWorker({ log: fakeLogger }); + const [ev] = await waitForEvents(1); + expect(ev.metadata.host).toBe('seeds.cryptographic-triangles.org'); + expect(ev.actor).toBe('162.243.83.227'); + expect(ev.metadata.user_agent).toBe('Mozilla/5.0'); + expect(ev.action).toBe('http.404'); + }); + + test('top-level host (DC-112 fixture shape) still parses — backwards compat', async () => { + 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, + }) + '\n'); + worker = startCaddyWorker({ log: fakeLogger }); + const [ev] = await waitForEvents(1); + expect(ev.metadata.host).toBe('plex.sami'); + }); +}); + +describe('DC-113: self-noise filter — probe UAs do not flood the store', () => { + let worker; + afterEach(() => { if (worker) { worker.stop(); worker = null; } }); + + test('DashCaddy-Probe/1.0 and DashCaddy-HealthCheck/1.0 lines are dropped', async () => { + const mk = (ua, uri) => JSON.stringify({ + ts: Date.now() / 1000, + request: { remote_ip: '172.17.0.2', method: 'GET', uri, host: 'plex.sami', headers: { 'User-Agent': [ua] } }, + status: 200, + }); + fs.appendFileSync(ACCESS_LOG, mk('DashCaddy-Probe/1.0', '/api/health') + '\n'); + fs.appendFileSync(ACCESS_LOG, mk('DashCaddy-HealthCheck/1.0', '/') + '\n'); + fs.appendFileSync(ACCESS_LOG, mk('Mozilla/5.0', '/wp-login.php') + '\n'); + + worker = startCaddyWorker({ log: fakeLogger }); + const events = await waitForEvents(1); // only the external line survives + expect(events.length).toBe(1); + expect(events[0].metadata.user_agent).toBe('Mozilla/5.0'); + expect(events[0].target).toBe('GET /wp-login.php'); + expect(events[0].actor).toBe('172.17.0.2'); + }); + + test('probe-like prefix UA (DashCaddy-Probe/1.1-future) is also filtered', async () => { + fs.appendFileSync(ACCESS_LOG, JSON.stringify({ + ts: Date.now() / 1000, + request: { remote_ip: '10.1.1.1', method: 'GET', uri: '/', host: 'x.sami', headers: { 'User-Agent': ['DashCaddy-Probe/1.1-future'] } }, + status: 200, + }) + '\n'); + worker = startCaddyWorker({ log: fakeLogger }); + await new Promise(r => setTimeout(r, 700)); // tail poll settles + expect(readStored().filter(e => e.source_type === 'caddy').length).toBe(0); + }); + + test('null/absent UA is NOT filtered (unknown clients stay visible)', async () => { + fs.appendFileSync(ACCESS_LOG, JSON.stringify({ + ts: Date.now() / 1000, + request: { remote_ip: '203.0.113.9', method: 'GET', uri: '/admin', host: 'x.sami', headers: {} }, + status: 403, + }) + '\n'); + worker = startCaddyWorker({ log: fakeLogger }); + const [ev] = await waitForEvents(1); + expect(ev.metadata.user_agent).toBeNull(); + expect(ev.severity).toBe('warn'); // 403 → warn + }); +}); + +describe('DC-113: recovered-log visibility (DC-112 judge polish fold)', () => { + let worker; + afterEach(() => { if (worker) { worker.stop(); worker = null; } }); + + test('info line when the access log appears after startup (missing → present)', async () => { + // Start with NO access log file at all. + fs.rmSync(ACCESS_LOG); + worker = startCaddyWorker({ log: fakeLogger }); + + // Wait past one missing-poll cycle (pollMs * 5 = 5s default → but the + // initial tick is pollMs=1s; give it 1.5s to hit the missing branch). + await new Promise(r => setTimeout(r, 1500)); + + // The file appears (the infra wiring this test models: caddy reload + // creates /var/log/caddy/access.log; the container mount lands). + fs.writeFileSync(ACCESS_LOG, '', 'utf8'); + fs.appendFileSync(ACCESS_LOG, JSON.stringify({ + ts: Date.now() / 1000, + request: { remote_ip: '198.51.100.7', method: 'GET', uri: '/', host: 'status.sami', headers: { 'User-Agent': ['curl/8.0'] } }, + status: 200, + }) + '\n'); + + await waitForEvents(1); + const infos = capturedInfos.filter(i => /caddy access log active/.test(i.msg)); + expect(infos.length).toBeGreaterThanOrEqual(1); + expect(infos[0].msg).toContain(ACCESS_LOG); + }); + + test('info line also fires on first poll when the log exists at startup', async () => { + fs.writeFileSync(ACCESS_LOG, JSON.stringify({ + ts: Date.now() / 1000, + request: { remote_ip: '198.51.100.8', method: 'GET', uri: '/x', host: 'status.sami', headers: { 'User-Agent': ['curl/8.0'] } }, + status: 200, + }) + '\n'); + worker = startCaddyWorker({ log: fakeLogger }); + await waitForEvents(1); + expect(capturedInfos.filter(i => /caddy access log active/.test(i.msg)).length).toBe(1); + }); + + test('onAppear fires once per appearance, not per poll', async () => { + fs.writeFileSync(ACCESS_LOG, JSON.stringify({ + ts: Date.now() / 1000, + request: { remote_ip: '198.51.100.9', method: 'GET', uri: '/y', host: 'status.sami', headers: { 'User-Agent': ['curl/8.0'] } }, + status: 200, + }) + '\n'); + worker = startCaddyWorker({ log: fakeLogger }); + await waitForEvents(1); + // Extra polls with the file still present must not re-fire. + await new Promise(r => setTimeout(r, 1500)); + expect(capturedInfos.filter(i => /caddy access log active/.test(i.msg)).length).toBe(1); + }); +}); + +describe('DC-113 r2: bounded first-start replay (judge fix-first fold)', () => { + let worker; + afterEach(() => { if (worker) { worker.stop(); worker = null; } }); + + // NOTE: trailing \n is REQUIRED — these lines are join('')ed into the + // access log; without it the whole tail becomes one unterminated line + // that never flushes from the tail buffer. + const mkLine = (ip, path) => JSON.stringify({ + ts: Date.now() / 1000, + request: { remote_ip: ip, method: 'GET', uri: path, host: 'status.sami', headers: { 'User-Agent': ['curl/8.0'] } }, + status: 200, + }) + '\n'; + + test('first-ever start skips the backlog beyond the 5 MiB cap and drops the partial line', async () => { + // No persisted offset state file for this scenario. + fs.rmSync(path.join(TMP_DIR, '.caddy-tail-offset'), { force: true }); + // Build a file beyond the 5 MiB cap WITHOUT flooding the store's write + // queue: ONE huge filler line (6 MiB of padding) + a normal backlog + + // the two live tail lines. The cap jump lands inside the huge line — + // the partial-line discard must skip it entirely, then the backlog + // lines (post-jump window) and the live tail lines emit. + const mkFiller = (bytes) => JSON.stringify({ + ts: 1787000000, request: { remote_ip: '10.0.0.1', method: 'GET', uri: '/huge-' + 'x'.repeat(bytes), host: 'status.sami', headers: { 'User-Agent': ['curl/8.0'] } }, status: 200, + }) + '\n'; + const backlog = []; + for (let i = 0; i < 40; i++) backlog.push(mkLine('10.0.0.2', '/backlog-' + i)); + const big = [mkFiller(6 * 1024 * 1024), ...backlog, mkLine('203.0.113.101', '/live-1'), mkLine('203.0.113.102', '/live-2')]; + fs.writeFileSync(ACCESS_LOG, big.join(''), 'utf8'); + expect(fs.statSync(ACCESS_LOG).size).toBeGreaterThan(5 * 1024 * 1024 + 1024); + + worker = startCaddyWorker({ log: fakeLogger }); + + // Poll until BOTH live tail lines land (cap window = last 5 MiB, which + // contains the whole normal backlog + tail lines; drains in <2s). + const deadline = Date.now() + 30000; + let all = []; + while (Date.now() < deadline) { + all = readStored().filter(e => e.source_type === 'caddy'); + const uris = new Set(all.map(e => e.target)); + if (uris.has('GET /live-1') && uris.has('GET /live-2')) break; + await new Promise(r => setTimeout(r, 150)); + } + const uris = new Set(all.map(e => e.target)); + expect(uris.has('GET /live-1')).toBe(true); + expect(uris.has('GET /live-2')).toBe(true); + // Cap engaged: the huge pre-cap line is GONE (jumped past + partial + // discard), and the backlog window landed. + expect(all.length).toBe(42); // 40 backlog + 2 live + expect(all.some(e => e.target && e.target.includes('/huge-'))).toBe(false); + // Persisted offset now exists — restart resumes from live. + expect(fs.existsSync(path.join(TMP_DIR, '.caddy-tail-offset'))).toBe(true); + }, 45000); + + test('restart with persisted offset replays nothing (no re-emit, no gap)', async () => { + fs.rmSync(path.join(TMP_DIR, '.caddy-tail-offset'), { force: true }); + fs.writeFileSync(ACCESS_LOG, mkLine('203.0.113.201', '/first') + '\n', 'utf8'); + worker = startCaddyWorker({ log: fakeLogger }); + // Wait for the offset to persist (stream 'end' handler), not just the + // event to appear — waitForEvents can return before 'end' fires. + const deadline = Date.now() + 5000; + while (Date.now() < deadline) { + if (fs.existsSync(path.join(TMP_DIR, '.caddy-tail-offset')) + && fs.readFileSync(path.join(TMP_DIR, '.caddy-tail-offset'), 'utf8').trim() !== '0') break; + await new Promise(r => setTimeout(r, 50)); + } + worker.stop(); + await new Promise(r => setTimeout(r, 200)); + + // New content after the stop. Do NOT truncate the store file: the + // singleton's memory still holds w1's events and would flush them on + // the next append, making file line-count useless as a replay oracle. + // Instead: a replay would append '/first' a SECOND time. + fs.appendFileSync(ACCESS_LOG, mkLine('203.0.113.202', '/second') + '\n', 'utf8'); + worker = startCaddyWorker({ log: fakeLogger }); + await waitForEvents(2); + await new Promise(r => setTimeout(r, 300)); // settle + const all = readStored().filter(e => e.source_type === 'caddy'); + const firsts = all.filter(e => e.target === 'GET /first'); + const seconds = all.filter(e => e.target === 'GET /second'); + expect(firsts.length).toBe(1); // exactly once — no replay on restart + expect(seconds.length).toBe(1); // and no gap — new line processed + }, 15000); +}); diff --git a/dashcaddy-api/src/security/event-workers.js b/dashcaddy-api/src/security/event-workers.js index 56ae297..163cca1 100644 --- a/dashcaddy-api/src/security/event-workers.js +++ b/dashcaddy-api/src/security/event-workers.js @@ -90,16 +90,32 @@ function resolveCaddyAction(method, uri, status) { * Watches `filePath`, emits each new line via `onLine(line)`. * Persists last-read offset to `stateFile` so restarts don't re-process. * On file truncation (rotation), resets offset to 0. + * + * DC-113: `onAppear` fires on every missing→present transition of the file + * (including the first-ever appearance), letting callers log recovery from + * a dead path (judge polish round on DC-112). + * + * DC-113 r2 (judge fix-first fold): `firstStartMaxBytes` bounds the replay + * on the FIRST-EVER start (no persisted offset). A fresh deployment pointing + * at a long-lived log would otherwise ingest the entire backlog into the + * capped security store, evicting recent history. We jump to (size - cap) + * and discard the partial first line. Normal restarts (state file exists) + * always resume at the exact persisted offset — no data gap, no skip. */ -function createTail({ filePath, stateFile, onLine, label = 'tail', pollMs = 1000 }) { +function createTail({ filePath, stateFile, onLine, onAppear, label = 'tail', pollMs = 1000, firstStartMaxBytes = null }) { let offset = 0; let buffer = ''; let stopped = false; + let sawFile = false; + let firstStart = false; + let skipPartialFirstLine = false; // Load persisted offset try { if (fs.existsSync(stateFile)) { offset = parseInt(fs.readFileSync(stateFile, 'utf8').trim(), 10) || 0; + } else { + firstStart = true; } } catch {} @@ -113,12 +129,27 @@ function createTail({ filePath, stateFile, onLine, label = 'tail', pollMs = 1000 fs.stat(filePath, (err, st) => { if (err) { // File doesn't exist yet — just wait + sawFile = false; return setTimeout(tick, pollMs * 5); } + if (!sawFile) { + sawFile = true; + try { onAppear && onAppear(); } catch (e) { + log.error('events', e, { worker: label, phase: 'onAppear' }); + } + } + // First-ever start against a large pre-existing file: skip to live. + if (firstStart && typeof firstStartMaxBytes === 'number' && st.size > firstStartMaxBytes) { + offset = st.size - firstStartMaxBytes; + skipPartialFirstLine = true; + buffer = ''; + } + firstStart = false; // Detect truncation/rotation if (st.size < offset) { offset = 0; buffer = ''; + skipPartialFirstLine = false; } if (st.size === offset) { return setTimeout(tick, pollMs); @@ -130,7 +161,16 @@ function createTail({ filePath, stateFile, onLine, label = 'tail', pollMs = 1000 encoding: 'utf8', }); stream.on('data', (chunk) => { - buffer += chunk; + let text = chunk; + if (skipPartialFirstLine) { + // We jumped into the middle of the file — discard bytes up to + // the first newline (the partial line we cut into). + const nl = text.indexOf('\n'); + if (nl === -1) return; // still inside the partial line + text = text.slice(nl + 1); + skipPartialFirstLine = false; + } + buffer += text; const lines = buffer.split('\n'); buffer = lines.pop() || ''; // last partial stays for (const line of lines) { @@ -190,10 +230,34 @@ function startCaddyWorker({ log: logger = log } = {}) { } warnIfMissing(); + // DC-113: self-noise filter. The API's own probes (health-checker, + // caddy-upstream-watcher, uptime watchdog) hit Caddy ~every 10-30s per + // service and would bury real perimeter signal in the 100k-event store + // within hours. Drop our own probe UAs from the event stream — the raw + // access.log keeps every line for forensics; only the derived security + // store is filtered. + const SELF_NOISE_UAS = [ + 'DashCaddy-Probe/1.0', // health-checker + upstream watcher + 'DashCaddy-HealthCheck/1.0', // startup validator + ]; + function isSelfNoise(userAgent) { + return !!userAgent && SELF_NOISE_UAS.some(ua => userAgent.startsWith(ua)); + } + return createTail({ filePath: caddyLog, stateFile, label: 'caddy', + // DC-113 r2: cap first-start replay at 5 MiB (~30-40k caddy lines) so a + // fresh deployment against a long-lived access.log ingests only the + // recent window, not the whole backlog (store caps at 100k events). + firstStartMaxBytes: 5 * 1024 * 1024, + // DC-113 (judge polish fold): emit a single info line when the log + // path becomes (or starts out) readable, so recovery after the + // missing-warn is visible in docker logs. + onAppear: () => { + logger.info?.('events', `caddy access log active at ${caddyLog} — caddy-source security events enabled`, { worker: 'caddy' }); + }, onLine: (line) => { let entry; try { entry = JSON.parse(line); } @@ -207,6 +271,7 @@ function startCaddyWorker({ log: logger = log } = {}) { // 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; + if (isSelfNoise(userAgent)) return; // Severity mapping let severity = 'info'; @@ -245,7 +310,11 @@ function startCaddyWorker({ log: logger = log } = {}) { user_agent: userAgent, size: entry.size || null, proto: req.proto || null, - host: entry.host || null, // DC-112: which vhost served it + // DC-113: real caddy JSON nests host inside request — the + // top-level read was always null on live lines (the DC-112 test + // fixture shape was wrong; verified against /var/log/caddy/ + // seeds.log lines on DNS2). + host: req.host || entry.host || null, }, }); }, diff --git a/start.sh b/start.sh index 8316d7d..f268544 100755 --- a/start.sh +++ b/start.sh @@ -160,6 +160,7 @@ docker run -d --restart unless-stopped --name ${CONTAINER_NAME} \ -v ${BACKUPS_DIR}:/app/backups \ -v ${CADDYFILE}:/caddyfile \ -v /etc/caddy/sites:/etc/caddy/sites:ro \ + -v /var/log/caddy:/var/log/caddy:ro \ -v /var/run/docker.sock:/var/run/docker.sock \ -v ${ASSETS_DIR}:/app/assets \ -v ${UPDATES_DIR}:/app/updates \ @@ -180,6 +181,7 @@ docker run -d --restart unless-stopped --name ${CONTAINER_NAME} \ -e HEALTH_CONFIG_FILE=/app/data/health-config.json \ -e CADDYFILE_PATH=/caddyfile \ -e CADDY_ADMIN_URL=http://${HOST_IP}:2019 \ + -e CADDY_ACCESS_LOG=/var/log/caddy/access.log \ -e ASSETS_DIR=/app/assets \ -e DASHCADDY_API_SOURCE_DIR=/opt/dashcaddy/dashcaddy-api \ -e DASHCADDY_UPDATE_ENABLED=false \