/** * Structured logging with ring buffer, SSE, and on-disk JSONL persistence. * * Patches the primitive `log` object from config.js so every log call also: * 1. lands in an in-memory ring buffer (dashboard "recent logs") * 2. fans out to live SSE subscribers * 3. appends a structured JSONL line to logs/app-.jsonl * 4. errors/warns also go to logs/error-.jsonl * Optional LOG_* disk limits add retention, size rotation and oldest-first eviction. * * Structured context: the last argument to log.*() may be a plain object. * It is stripped from the message and attached as `ctx`, so callers can do: * log.info('Chat request', { requestId, model, account: acct.email }); * and the dashboard can filter/group by ctx fields. */ import { mkdirSync, createWriteStream } from 'fs'; import { join } from 'path'; import { randomUUID } from 'crypto'; import { config, log } from '../config.js'; import { safeLogValue } from '../log-safety.js'; import { createLogFileWriter, readLogPolicy } from './log-files.js'; const MAX_BUFFER = 1000; const _buffer = []; const _subscribers = new Set(); const LOG_DIR = join(config.dataDir, 'logs'); try { mkdirSync(LOG_DIR, { recursive: true }); } catch {} const logPolicy = readLogPolicy(); const _fileWriter = Object.values(logPolicy).some(limit => limit > 0) ? createLogFileWriter({ dir: LOG_DIR, ...logPolicy, onError: () => console.warn('[logger] Disk log write/cleanup failed; check directory permissions and LOG_* limits.') }) : null; // Rotate by UTC date. One stream per day, lazily recreated at midnight. let _appStream = null; let _errStream = null; let _streamDate = ''; function today() { const d = new Date(); return `${d.getUTCFullYear()}-${String(d.getUTCMonth() + 1).padStart(2, '0')}-${String(d.getUTCDate()).padStart(2, '0')}`; } function createLogStream(file) { const stream = createWriteStream(file, { flags: 'a' }); stream._windsurfLogFailed = false; stream.on('error', () => { stream._windsurfLogFailed = true; try { stream.destroy(); } catch {} }); return stream; } function writeLogLine(stream, line) { if (!stream || stream.destroyed || stream._windsurfLogFailed) return; try { stream.write(line); } catch {} } function needsNewStream(stream) { return !stream || stream.destroyed || stream._windsurfLogFailed; } function getStreams() { const date = today(); if (date !== _streamDate || needsNewStream(_appStream) || needsNewStream(_errStream)) { try { _appStream?.end(); } catch {} try { _errStream?.end(); } catch {} _appStream = createLogStream(join(LOG_DIR, `app-${date}.jsonl`)); _errStream = createLogStream(join(LOG_DIR, `error-${date}.jsonl`)); _streamDate = date; } return { app: _appStream, err: _errStream }; } function formatArg(a) { if (typeof a === 'string') return a; if (a instanceof Error) return a.stack || a.message; try { return JSON.stringify(a); } catch { return String(a); } } // Detect "context object": plain object, not array, not Error, reasonable size. function isCtx(x) { return x && typeof x === 'object' && !Array.isArray(x) && !(x instanceof Error) && Object.getPrototypeOf(x) === Object.prototype; } // ── Injection boundary ────────────────────────────────────────────────────── // Callers interpolate request data (model names, tool names, upstream error // text) into log.*() arguments. Before this scrub, a `\n` inside such a value // forged a second record and an ANSI ESC sequence reached the operator's // terminal (pm2 console print) or a downloaded log attachment (format=txt). // // The scrub lives HERE — the single funnel every log.*() call passes through — // rather than at the ~30 call sites that interpolate caller data, because the // per-callsite version cannot stay complete: each new or missed interpolation // reopens the hole silently, while the funnel covers present and future // callers for free. Cleaning the ENTRY (not just the console echo) is what // makes the ring buffer, SSE subscribers, both JSONL legs and the txt export // safe without touching their own code: they all read the same scrubbed // object. JSONL needed the least of this — JSON.stringify already escaped the // characters inside the string — but the entry now carries '·' so a line that // LOOKED multiline stays visibly single-line wherever it is rendered. // // Trade-off, deliberate: an Error's multi-line stack collapses to '·'-joined // text in the entry and console echo. Readability is preserved, integrity wins. const MAX_LOG_MSG = 4000; // stacks stay intact; a flood cannot bloat one entry const MAX_CTX_STRING = 240; // ctx fields are short labels/ids/error text const MAX_CTX_KEY = 64; const MAX_CTX_DEPTH = 3; // past this a container is replaced, not traversed const CTX_TRUNCATED = '[truncated:ctx-depth]'; function scrubCtxValue(value, depth) { if (typeof value === 'string') return safeLogValue(value, MAX_CTX_STRING); if (value && typeof value === 'object' && (Array.isArray(value) || Object.getPrototypeOf(value) === Object.prototype)) { // A container this deep is never traversed, so its strings cannot be // scrubbed — swap the whole thing for a marker (same contract as // trace.js's DEPTH_TRUNCATION). if (depth >= MAX_CTX_DEPTH) return CTX_TRUNCATED; if (Array.isArray(value)) return value.map((v) => scrubCtxValue(v, depth + 1)); const out = {}; for (const [k, v] of Object.entries(value)) { out[safeLogValue(k, MAX_CTX_KEY)] = scrubCtxValue(v, depth + 1); } return out; } // Numbers, booleans, null and non-plain objects (Error, Date) cannot carry // control characters into a string context; leave them untouched. return value; } function scrubCtx(ctx) { const out = {}; for (const [k, v] of Object.entries(ctx)) { out[safeLogValue(k, MAX_CTX_KEY)] = scrubCtxValue(v, 0); } return out; } // Save originals before patching const _orig = { debug: log.debug, info: log.info, warn: log.warn, error: log.error, }; for (const level of ['debug', 'info', 'warn', 'error']) { log[level] = (...args) => { // Pull trailing context object out of args. let ctx = null; if (args.length > 1 && isCtx(args[args.length - 1])) { ctx = args[args.length - 1]; args = args.slice(0, -1); } // Scrub at the write point: msg + ctx feed the buffer, the JSONL line and // the console echo below from this one cleaned pair (see the boundary note // at scrubCtxValue for why this is the funnel and not a call-site fix). const msg = safeLogValue(args.map(formatArg).join(' '), MAX_LOG_MSG); if (ctx) ctx = scrubCtx(ctx); const entry = { ts: Date.now(), level, msg }; if (ctx) entry.ctx = ctx; _buffer.push(entry); if (_buffer.length > MAX_BUFFER) _buffer.shift(); for (const fn of _subscribers) { try { fn(entry); } catch {} } // Persist to disk try { const line = JSON.stringify(entry) + '\n'; if (_fileWriter) _fileWriter.write(level, line); else { const { app, err } = getStreams(); writeLogLine(app, line); if (level === 'error' || level === 'warn') writeLogLine(err, line); } } catch {} // Also print to console so pm2 logs still work. The echo reuses the // SCRUBBED msg/ctx — echoing raw `args` would bypass the boundary for the // one sink that renders directly into an operator's terminal. if (ctx) { const ctxStr = Object.entries(ctx) .map(([k, v]) => `${k}=${typeof v === 'string' ? v : JSON.stringify(v)}`) .join(' '); _orig[level](ctxStr ? `${msg} {${ctxStr}}` : msg); } else { _orig[level](msg); } }; } /** * Return a logger bound to a fixed context (e.g. { requestId }). * Later args to .info/.warn/.error can still add more context fields. */ export function withCtx(baseCtx) { const bind = (level) => (...args) => { let extra = null; if (args.length > 1 && isCtx(args[args.length - 1])) { extra = args[args.length - 1]; args = args.slice(0, -1); } log[level](...args, { ...baseCtx, ...(extra || {}) }); }; return { debug: bind('debug'), info: bind('info'), warn: bind('warn'), error: bind('error'), requestId: baseCtx.requestId, }; } /** Generate a short request id for tracing a single chat call end-to-end. */ export function newRequestId() { return 'r_' + randomUUID().replace(/-/g, '').slice(0, 10); } /** Get recent logs, optionally filtered by since/level/ctx. */ export function getLogs(since = 0, level = null, ctxFilter = null) { let result = _buffer; if (since > 0) result = result.filter(e => e.ts > since); if (level) result = result.filter(e => e.level === level); if (ctxFilter && typeof ctxFilter === 'object') { result = result.filter(e => { if (!e.ctx) return false; for (const [k, v] of Object.entries(ctxFilter)) { if (e.ctx[k] !== v) return false; } return true; }); } return result; } export function subscribeToLogs(callback) { _subscribers.add(callback); } export function unsubscribeFromLogs(callback) { _subscribers.delete(callback); } /** Get current log directory (for dashboard to display). */ export function getLogDir() { return LOG_DIR; }