From b7cff031d7f907a7bc990002b1de01ab22059cf7 Mon Sep 17 00:00:00 2001 From: Jinwoo-H Date: Fri, 10 Jul 2026 05:48:26 -0400 Subject: [PATCH] fix(relay): rotate relay.log in-process with a size cap relay.log grows unbounded on long-lived relays: the detached launch redirects > relay.log 2>&1, which truncates only at relaunch, so per-stream stderr lines and reconnect flaps accumulate forever and can fill small remote hosts. Add an in-process RotatingLogWriter (the relay owns its own stderr; a shell redirect can't cap size). installRelayLogRotation wraps process.stdout/stderr so all logging (42 call sites) flows through a writer that appends to relay.log, tracks size, and at 10MB renames relay.log -> relay.log.1 (one archived generation) and reopens a fresh relay.log. Wired only for the detached daemon; deploy passes --log-file on the POSIX and Windows launch paths. Constraints: portable node:fs sync calls (works with pipe/redirect on Linux/macOS/Windows); the current log is always relay.log so the tail-diagnostics workflow keeps working; writes and rotation are guarded so a filesystem error degrades to uncapped logging rather than crashing, and rename (not delete) means no window without a log file. Tests cover rotation at the cap, tail-ability, boot-output preservation, ~2x cap footprint bound, and stderr wrapping/restore. Co-authored-by: Orca --- src/main/ssh/ssh-relay-deploy.ts | 11 +- src/relay/relay.ts | 17 ++- src/relay/rotating-log-writer.test.ts | 102 ++++++++++++++++ src/relay/rotating-log-writer.ts | 161 ++++++++++++++++++++++++++ 4 files changed, 288 insertions(+), 3 deletions(-) create mode 100644 src/relay/rotating-log-writer.test.ts create mode 100644 src/relay/rotating-log-writer.ts diff --git a/src/main/ssh/ssh-relay-deploy.ts b/src/main/ssh/ssh-relay-deploy.ts index 78e7dec4443..26501a8371b 100644 --- a/src/main/ssh/ssh-relay-deploy.ts +++ b/src/main/ssh/ssh-relay-deploy.ts @@ -756,7 +756,12 @@ async function launchRelay( // Fire-and-forget via conn.exec: we don't need the output — the socket // poll below detects readiness. const logFile = `${remoteDir}/relay.log` - const launchCmd = `cd ${escapedDir} && nohup ${escapedNode} relay.js --detached --grace-time ${graceTime} --sock-path ${shellEscape(sockFile)} > ${shellEscape(logFile)} 2>&1 ${shellEscape(logFile)} 2>&1 {}) launchChannel.on('error', () => {}) @@ -1052,6 +1057,10 @@ function windowsRelayLaunchCommand( quoted(sockPath), '--endpoint-dir', quoted(endpointDir), + // Why: in-process rotation owns relay.log (the tail-diagnostics target); + // the shell redirects remain for pre-JS boot/crash output. + '--log-file', + quoted(logFile), `1>${quoted(logFile)}`, `2>${quoted(errFile)}` ].join(' ') diff --git a/src/relay/relay.ts b/src/relay/relay.ts index 65f90e88628..96f0e4179d8 100644 --- a/src/relay/relay.ts +++ b/src/relay/relay.ts @@ -37,6 +37,7 @@ import { RelayDispatcher } from './dispatcher' import { RelayContext } from './context' import { PtyHandler } from './pty-handler' import { FsHandler } from './fs-handler' +import { installRelayLogRotation } from './rotating-log-writer' import { GitHandler } from './git-handler' import { PreflightHandler } from './preflight-handler' import { ExternalAutomationsHandler } from './external-automations-handler' @@ -114,6 +115,7 @@ function parseArgs(argv: string[]): { cliMode: boolean sockPath: string endpointDir?: string + logFile?: string } { let graceTimeMs = DEFAULT_GRACE_MS let connectMode = false @@ -121,6 +123,7 @@ function parseArgs(argv: string[]): { let cliMode = false let sockPath = '' let endpointDir: string | undefined + let logFile: string | undefined for (let i = 2; i < argv.length; i++) { if (argv[i] === '--grace-time' && argv[i + 1]) { const parsed = Number.parseInt(argv[i + 1], 10) @@ -143,12 +146,15 @@ function parseArgs(argv: string[]): { } else if (argv[i] === '--endpoint-dir' && argv[i + 1]) { endpointDir = argv[i + 1] i++ + } else if (argv[i] === '--log-file' && argv[i + 1]) { + logFile = argv[i + 1] + i++ } } if (!sockPath) { sockPath = join(process.cwd(), SOCK_NAME) } - return { graceTimeMs, connectMode, detached, cliMode, sockPath, endpointDir } + return { graceTimeMs, connectMode, detached, cliMode, sockPath, endpointDir, logFile } } // ── Connect mode ───────────────────────────────────────────────────── @@ -318,7 +324,7 @@ async function readOrcaCliStdin(): Promise { // ── Normal mode ────────────────────────────────────────────────────── async function main(): Promise { - const { graceTimeMs, connectMode, detached, cliMode, sockPath, endpointDir } = parseArgs( + const { graceTimeMs, connectMode, detached, cliMode, sockPath, endpointDir, logFile } = parseArgs( process.argv ) @@ -332,6 +338,13 @@ async function main(): Promise { return } + // Why: only the long-lived detached daemon accumulates relay.log; --connect + // bridges and --orca-cli are short-lived and already returned above. Route all + // relay logging through a size-capped rotator so relay.log can't grow forever. + if (detached && logFile) { + installRelayLogRotation(logFile) + } + let ownsSocketPath = false let ownedSocketIdentity: SocketIdentity | null = null const ownsCurrentSocketPath = (): boolean => { diff --git a/src/relay/rotating-log-writer.test.ts b/src/relay/rotating-log-writer.test.ts new file mode 100644 index 00000000000..5d410184b53 --- /dev/null +++ b/src/relay/rotating-log-writer.test.ts @@ -0,0 +1,102 @@ +/** + * Regression: relay.log grows unbounded on long-lived relays. + * + * The relay is launched detached with `> relay.log 2>&1`, which truncates only + * at relaunch; a relay that stays up for days accumulates per-stream stderr + * lines forever. These tests assert the in-process rotator caps size, keeps one + * archived generation, and always leaves the CURRENT log at relay.log so the + * `tail -100 relay.log` diagnostics workflow keeps working. + */ +import { describe, expect, it, beforeEach, afterEach } from 'vitest' +import { mkdtempSync, readFileSync, existsSync, statSync, writeFileSync } from 'node:fs' +import { rm } from 'node:fs/promises' +import * as path from 'node:path' +import { tmpdir } from 'node:os' + +import { RotatingLogWriter, installRelayLogRotation } from './rotating-log-writer' + +describe('RotatingLogWriter', () => { + let dir: string + let logPath: string + + beforeEach(() => { + dir = mkdtempSync(path.join(tmpdir(), 'relay-log-rot-')) + logPath = path.join(dir, 'relay.log') + }) + + afterEach(async () => { + await rm(dir, { recursive: true, force: true }) + }) + + it('rotates relay.log -> relay.log.1 at the cap and keeps the current log tail-able', () => { + const cap = 4 * 1024 + const writer = new RotatingLogWriter(logPath, cap) + try { + const line = `${'a'.repeat(200)}\n` + // Write well past the cap so at least one rotation happens. + for (let i = 0; i < 60; i += 1) { + writer.write(line) + } + + // Current log exists at relay.log (tail target) and is under the cap. + expect(existsSync(logPath)).toBe(true) + expect(statSync(logPath).size).toBeLessThanOrEqual(cap) + // Exactly one archived generation. + expect(existsSync(`${logPath}.1`)).toBe(true) + expect(existsSync(`${logPath}.2`)).toBe(false) + + // The most recent lines are in the current log (tail-ability). + writer.write('MARKER-LAST\n') + expect(readFileSync(logPath, 'utf-8')).toContain('MARKER-LAST') + } finally { + writer.dispose() + } + }) + + it('preserves pre-existing boot output already in relay.log (append, not truncate)', () => { + writeFileSync(logPath, 'BOOT-LINE-FROM-SHELL-REDIRECT\n') + const writer = new RotatingLogWriter(logPath, 1024 * 1024) + try { + writer.write('runtime line\n') + const contents = readFileSync(logPath, 'utf-8') + expect(contents).toContain('BOOT-LINE-FROM-SHELL-REDIRECT') + expect(contents).toContain('runtime line') + } finally { + writer.dispose() + } + }) + + it('caps total footprint to ~2x maxBytes (current + one archive)', () => { + const cap = 8 * 1024 + const writer = new RotatingLogWriter(logPath, cap) + try { + const line = `${'z'.repeat(256)}\n` + for (let i = 0; i < 500; i += 1) { + writer.write(line) + } + const currentSize = statSync(logPath).size + const archiveSize = existsSync(`${logPath}.1`) ? statSync(`${logPath}.1`).size : 0 + // Never more than the current file + a single archived generation. + expect(currentSize).toBeLessThanOrEqual(cap) + expect(archiveSize).toBeLessThanOrEqual(cap * 2) + expect(existsSync(`${logPath}.2`)).toBe(false) + } finally { + writer.dispose() + } + }) + + it('installRelayLogRotation routes process.stderr through the rotator and restores', () => { + const cap = 2 * 1024 + const { restore } = installRelayLogRotation(logPath, cap) + try { + process.stderr.write('via-stderr-line\n') + expect(readFileSync(logPath, 'utf-8')).toContain('via-stderr-line') + } finally { + restore() + } + // After restore, process.stderr no longer targets the rotator file. + const sizeAfterRestore = statSync(logPath).size + process.stderr.write('should-not-be-in-relay-log\n') + expect(statSync(logPath).size).toBe(sizeAfterRestore) + }) +}) diff --git a/src/relay/rotating-log-writer.ts b/src/relay/rotating-log-writer.ts new file mode 100644 index 00000000000..86c1a6f743b --- /dev/null +++ b/src/relay/rotating-log-writer.ts @@ -0,0 +1,161 @@ +// Size-capped, crash-safe rotation for the relay's diagnostic log. +// +// Why: the relay is launched detached with `> relay.log 2>&1`, which only +// truncates at relaunch — a long-lived relay's relay.log grows unbounded +// (per-stream stderr lines, reconnect flaps, etc.). Rotation must live in the +// relay process because it owns its own stderr; the shell redirect cannot cap +// size. Constraints honored: +// - keeps working when the launch fd is a pipe/redirect on Linux/macOS/Windows +// (append-only, no fd tricks; a rotation failure falls back to the prior fd); +// - the diagnostics tail (`tail -100 ~/.orca-remote/relay-*/relay.log`) keeps +// working because the CURRENT log is always at relay.log; +// - crash-safe: writes and rotation are guarded so logging never throws, and +// rotation renames (never deletes the live file) so no window loses logging. +import { closeSync, openSync, renameSync, statSync, writeSync } from 'node:fs' + +/** Default size cap before rotating relay.log → relay.log.1. 10 MB balances + * keeping enough history for diagnosis against bounding disk use on small + * remote hosts (e.g. a Raspberry Pi); one archived generation is kept. */ +export const DEFAULT_RELAY_LOG_MAX_BYTES = 10 * 1024 * 1024 + +type StreamWrite = typeof process.stderr.write + +export class RotatingLogWriter { + private readonly logPath: string + private readonly rotatedPath: string + private readonly maxBytes: number + private fd: number | null = null + private currentBytes = 0 + private failed = false + + constructor(logPath: string, maxBytes: number = DEFAULT_RELAY_LOG_MAX_BYTES) { + this.logPath = logPath + this.rotatedPath = `${logPath}.1` + this.maxBytes = maxBytes + this.open() + } + + private open(): void { + try { + // Append so pre-JS boot output already in relay.log is preserved and + // concurrent appends stay atomic per write. + this.fd = openSync(this.logPath, 'a') + try { + this.currentBytes = statSync(this.logPath).size + } catch { + this.currentBytes = 0 + } + } catch { + // Cannot open the log file (permission/full disk): disable rotation and + // let callers fall back to the original stream. + this.failed = true + this.fd = null + } + } + + /** True when the writer is usable; false means fall back to raw stderr. */ + get active(): boolean { + return !this.failed && this.fd !== null + } + + write(chunk: string | Uint8Array): void { + if (!this.active || this.fd === null) { + return + } + const buf = typeof chunk === 'string' ? Buffer.from(chunk, 'utf-8') : Buffer.from(chunk) + try { + // Rotate BEFORE writing when the incoming write would cross the cap, so a + // single large line still lands wholly in the fresh file. + if (this.currentBytes > 0 && this.currentBytes + buf.length > this.maxBytes) { + this.rotate() + } + writeSync(this.fd, buf) + this.currentBytes += buf.length + } catch { + // A write failure must never crash the relay; disable and fall back. + this.failed = true + this.closeQuietly() + } + } + + private rotate(): void { + try { + if (this.fd !== null) { + closeSync(this.fd) + this.fd = null + } + // rename() replaces any existing relay.log.1 atomically on POSIX and is + // supported on Windows; the live file is renamed (never deleted) so no + // log window is lost. + renameSync(this.logPath, this.rotatedPath) + } catch { + // Rotation failed (e.g. cross-device, locked file): reopen the same file + // and keep appending rather than losing the ability to log. + } + this.currentBytes = 0 + this.open() + } + + private closeQuietly(): void { + if (this.fd !== null) { + try { + closeSync(this.fd) + } catch { + // best-effort + } + this.fd = null + } + } + + dispose(): void { + this.closeQuietly() + } +} + +/** + * Route process.stdout/stderr writes through a RotatingLogWriter that owns + * `logPath`. Returns a restore function. If the writer cannot open the file, + * the original streams are left untouched (logging still works, just uncapped). + */ +export function installRelayLogRotation( + logPath: string, + maxBytes: number = DEFAULT_RELAY_LOG_MAX_BYTES +): { writer: RotatingLogWriter; restore: () => void } { + const writer = new RotatingLogWriter(logPath, maxBytes) + const originalStdout = process.stdout.write.bind(process.stdout) + const originalStderr = process.stderr.write.bind(process.stderr) + + if (!writer.active) { + return { writer, restore: () => {} } + } + + const wrap = + (original: StreamWrite): StreamWrite => + (chunk: string | Uint8Array, encodingOrCb?: unknown, cb?: unknown): boolean => { + writer.write(chunk) + // Why: preserve the Writable.write callback contract so callers awaiting + // the write (rare, but e.g. flush-before-exit) are not left hanging. + const callback = typeof encodingOrCb === 'function' ? encodingOrCb : cb + if (typeof callback === 'function') { + ;(callback as (err?: Error | null) => void)(null) + } + // If the writer went inactive mid-run (write failure), fall back so logs + // are not silently dropped for the rest of the session. + if (!writer.active) { + return (original as (c: string | Uint8Array) => boolean)(chunk) + } + return true + } + + process.stdout.write = wrap(originalStdout as StreamWrite) as typeof process.stdout.write + process.stderr.write = wrap(originalStderr as StreamWrite) as typeof process.stderr.write + + return { + writer, + restore: () => { + process.stdout.write = originalStdout as typeof process.stdout.write + process.stderr.write = originalStderr as typeof process.stderr.write + writer.dispose() + } + } +}