Skip to content

Commit 9566b4d

Browse files
perf(sse): cap init log replay to 500 lines; cleanup truncates oversized audit logs
The SSE 'init' bootstrap frame replayed the entire logBuffer (up to LOG_BUFFER_MAX=5000 lines, ~400KB) on every tab connect, on top of the full per-node results array — making the frame hundreds of KB. Cap the init replay to the last INIT_LOG_REPLAY=500 lines on both the admin (server.js:2434) and public (2138) frames. /live is unaffected — it refetches the full filtered backlog from GET /api/public/logs separately. admin.html relies on the init replay, so its log pane now shows the most recent 500 lines on a fresh connect/refresh; live lines stream in normally afterward. cleanup.mjs gains section 8: report + (--fix) truncate audit-*.log files longer than LOG_BUFFER_MAX lines down to their last LOG_BUFFER_MAX — the only tail the logBuffer/SSE init ever reads (server.js:692 slices lines.slice(-LOG_BUFFER_MAX), the in-flight log included; resume slices identically). Full file backed up to <name>.bak-<ts> before the rewrite; gated on the same !abortAll server-stopped guard as the other mutations; logs being quarantined by --purge-orphan-logs are skipped. Truncation algorithm verified against a 12,431-line fixture.
1 parent 4ee2285 commit 9566b4d

2 files changed

Lines changed: 77 additions & 2 deletions

File tree

scripts/cleanup.mjs

Lines changed: 66 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -27,6 +27,10 @@
2727
* 16384-char tail (UTF-8 byte size varies;
2828
* idempotent backstop to migration v11)
2929
* – prune batch_results to DEFAULT_BATCH_RETENTION
30+
* · truncate oversized audit-*.log files to their
31+
* last LOG_BUFFER_MAX (5000) lines — the only
32+
* tail the logBuffer/SSE init ever replays — after
33+
* backing the full file up to <name>.bak-<ts>
3034
* --purge-orphan-logs (with --fix) quarantine orphan audit logs into
3135
* results/.cleanup-trash/<ts>/ (move, not delete;
3236
* never the active or a recently-written log).
@@ -66,6 +70,11 @@ const BACKFILL_TOLERANCE_MS = 60_000; // wider dedup window for backfill (save-t
6670
const RECENT_LOG_MS = 24 * 60 * 60 * 1000; // never purge a log written in the last day
6771
const RUNAWAY_NOTES = 'continuous-loop iteration%';
6872
const LOG_SNIPPET_CAP = 16384; // 16384 chars (UTF-8 byte size varies) — mirrors core/db.js insertErrorLog + migration v11
73+
const LOG_BUFFER_MAX = 5000; // lines — mirrors server.js logBuffer cap. On boot/resume the logBuffer
74+
// hydrates from an audit-*.log via lines.slice(-LOG_BUFFER_MAX) (server.js
75+
// ~692), and the SSE init frame replays at most INIT_LOG_REPLAY of those.
76+
// Anything beyond the last LOG_BUFFER_MAX lines is never read back, so an
77+
// audit log longer than this carries a permanently-unused head.
6978

7079
// Human-readable byte size for the slim-down report.
7180
const humanBytes = n => {
@@ -318,6 +327,36 @@ if (!existsSync(RAW_DIR)) {
318327
else { repairable(`${orphanRawDirs.length} orphan raw dir(s), ${humanBytes(orphanRawBytes)} total reclaimable`); if (!FIX) console.log(C.dim(' (pass --fix to rm -rf these orphan dirs)')); }
319328
}
320329

330+
// ─── 8. Oversized audit logs (truncate head, keep last LOG_BUFFER_MAX lines) ──
331+
// The logBuffer (and thus the SSE init frame) only ever reads the TAIL of an
332+
// audit-*.log — resume hydrates via lines.slice(-LOG_BUFFER_MAX) (server.js
333+
// ~692). A log longer than LOG_BUFFER_MAX lines therefore has a head that is
334+
// never replayed; capping it to the last LOG_BUFFER_MAX lines loses nothing the
335+
// app consumes (the active/in-flight log included — resume slices identically).
336+
// The full pre-truncation file is backed up to <name>.bak-<ts> before the
337+
// rewrite, so historical context is preserved for manual review/deletion.
338+
section('8. Oversized audit logs');
339+
let oversizedLogs = []; // { name, lines }
340+
if (existsSync(RESULTS_DIR)) {
341+
const logs = readdirSync(RESULTS_DIR).filter(f => /^(audit|retest)-.*\.log$/.test(f));
342+
for (const f of logs) {
343+
let lines = 0;
344+
try {
345+
// Count newlines without holding a split array: cheap and bounded-memory
346+
// enough for the occasional server-stopped cleanup run.
347+
const buf = readFileSync(path.join(RESULTS_DIR, f));
348+
for (let i = 0; i < buf.length; i++) if (buf[i] === 0x0a) lines++;
349+
if (buf.length && buf[buf.length - 1] !== 0x0a) lines++; // last line w/o trailing \n
350+
} catch (e) { hard(`could not read ${f} for line count: ${e.message}`); continue; }
351+
if (lines > LOG_BUFFER_MAX) oversizedLogs.push({ name: f, lines });
352+
}
353+
if (!oversizedLogs.length) ok(`no oversized audit logs (${logs.length} log file(s), all ≤ ${LOG_BUFFER_MAX.toLocaleString()} lines)`);
354+
else {
355+
for (const o of oversizedLogs) repairable(`${o.name}: ${o.lines.toLocaleString()} lines > ${LOG_BUFFER_MAX.toLocaleString()} cap (would keep last ${LOG_BUFFER_MAX.toLocaleString()}; head is never replayed)`);
356+
if (!FIX) console.log(C.dim(` (pass --fix to truncate to the last ${LOG_BUFFER_MAX.toLocaleString()} lines — full file backed up first)`));
357+
}
358+
}
359+
321360
// Close our OWN read-only handle before mutating: if it stays open, the WAL
322361
// checkpoint below can report `busy` and falsely abort the whole --fix on a
323362
// perfectly healthy, server-stopped box.
@@ -509,6 +548,33 @@ if (FIX) {
509548
} catch (e) { hard(`orphan raw-dir reclaim failed: ${e.message}`); }
510549
} else if (!dbWriteOk) console.log(` ${C.dim('↳ orphan raw-dir reclaim skipped (DB writes disabled)')}`);
511550

551+
// ── Truncate oversized audit logs to their last LOG_BUFFER_MAX lines ──────
552+
// Gated on !abortAll (a blocked WAL checkpoint means the server is running and
553+
// may be appending to the active log — never rewrite a log under it). Back the
554+
// full file up to <name>.bak-<ts> BEFORE the rewrite, so a crash mid-write or a
555+
// later "wanted that history" leaves the original recoverable. Logs already
556+
// being quarantined wholesale by --purge-orphan-logs are skipped (the move
557+
// takes the whole file; truncating it first would be wasted work).
558+
if (oversizedLogs.length && !abortAll) {
559+
const purgeSet = (PURGE_LOGS) ? new Set(orphanLogs) : new Set();
560+
for (const o of oversizedLogs) {
561+
if (purgeSet.has(o.name)) { console.log(` ${C.dim(`↳ ${o.name}: skipped truncate (being quarantined by --purge-orphan-logs)`)}`); continue; }
562+
const src = path.join(RESULTS_DIR, o.name);
563+
try {
564+
const lines = readFileSync(src, 'utf8').split('\n');
565+
// split('\n') on a trailing-newline file yields a final '' element; drop
566+
// it so the kept count is real lines, then re-add one trailing newline.
567+
if (lines.length && lines[lines.length - 1] === '') lines.pop();
568+
const kept = lines.slice(-LOG_BUFFER_MAX);
569+
copyFileSync(src, `${src}.bak-${ts}`);
570+
writeFileSync(src, kept.join('\n') + '\n', 'utf8');
571+
fixd(`truncated ${o.name} → last ${kept.length.toLocaleString()} lines (was ${o.lines.toLocaleString()}; full file → ${o.name}.bak-${ts})`);
572+
} catch (e) { hard(`could not truncate ${o.name}: ${e.message}`); }
573+
}
574+
} else if (oversizedLogs.length && abortAll) {
575+
console.log(` ${C.dim('↳ oversized-log truncate skipped (server appears to be running)')}`);
576+
}
577+
512578
if (PURGE_LOGS && orphanLogs.length && !abortAll) {
513579
const trash = path.join(RESULTS_DIR, '.cleanup-trash', String(ts));
514580
try {

server.js

Lines changed: 11 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -219,6 +219,15 @@ emitter.setMaxListeners(100);
219219
// live so a refresh / reconnect / resume sees the run's full prior history,
220220
// not just the last few lines.
221221
const LOG_BUFFER_MAX = 5000;
222+
// The full LOG_BUFFER_MAX backlog is kept server-side, but the SSE `init`
223+
// bootstrap frame replays only the most recent INIT_LOG_REPLAY lines. A fresh
224+
// tab needs recent context, not 5000 lines — replaying the whole buffer made
225+
// the init frame hundreds of KB. /live is unaffected: it separately refetches
226+
// the full backlog from GET /api/public/logs (live.html), which still returns
227+
// the whole (filtered) buffer. admin.html relies on the init replay, so the
228+
// admin log pane shows the most recent INIT_LOG_REPLAY lines on a fresh
229+
// connect/refresh; subsequent live lines stream in normally as events arrive.
230+
const INIT_LOG_REPLAY = 500;
222231
const logBuffer = [];
223232

224233
// ─── State Snapshot (persists volatile fields across restarts) ───────────────
@@ -2135,7 +2144,7 @@ app.get('/api/public/events', attachAdminFlag, rlPublicSse, (req, res) => {
21352144
// Persisted log backlog so /live shows full history on refresh, not a blank
21362145
// panel — but ONLY during an active run. logBuffer is hydrated from
21372146
// results/audit-*.log on boot, so an idle page would otherwise leak it.
2138-
logs: workOn ? publicLogBuffer() : [],
2147+
logs: workOn ? publicLogBuffer().slice(-INIT_LOG_REPLAY) : [],
21392148
state: initState,
21402149
results: initResults,
21412150
// Report effective-live so the admin's own /live page flips into live mode
@@ -2431,7 +2440,7 @@ app.get('/api/events', adminOnly, rlAdminSse, (req, res) => {
24312440
// Trim each result row's diag to the 4 fields the dashboard reads (drop the
24322441
// credential/config/stdout blob). New array of clones — getResults() returns
24332442
// the shared in-memory state rows; never mutate them.
2434-
send({ type: 'init', state: stateForSse, results: results.map(trimRowDiag), logs: logBuffer.slice() });
2443+
send({ type: 'init', state: stateForSse, results: results.map(trimRowDiag), logs: logBuffer.slice(-INIT_LOG_REPLAY) });
24352444
const ADMIN_BLOCK = /^(loop:|iteration:|batch:)/;
24362445
const handler = (data) => {
24372446
if (data && typeof data.type === 'string' && ADMIN_BLOCK.test(data.type)) return;

0 commit comments

Comments
 (0)