mirror of
https://github.com/stablyai/orca.git
synced 2026-10-17 00:03:08 +00:00
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 <help@stably.ai>
This commit is contained in:
@@ -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 </dev/null &`
|
||||
// Why: pass --log-file so the relay rotates relay.log in-process (size cap +
|
||||
// one archived generation). The shell redirect stays so pre-JS boot/crash
|
||||
// output is still captured; once JS starts, the in-process rotator owns all
|
||||
// subsequent logging (it wraps process.stderr/stdout), so the current log
|
||||
// stays at relay.log for the `tail relay.log` diagnostics workflow.
|
||||
const launchCmd = `cd ${escapedDir} && nohup ${escapedNode} relay.js --detached --grace-time ${graceTime} --sock-path ${shellEscape(sockFile)} --log-file ${shellEscape(logFile)} > ${shellEscape(logFile)} 2>&1 </dev/null &`
|
||||
const launchChannel = await conn.exec(launchCmd)
|
||||
launchChannel.on('data', () => {})
|
||||
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(' ')
|
||||
|
||||
+15
-2
@@ -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<string | undefined> {
|
||||
// ── Normal mode ──────────────────────────────────────────────────────
|
||||
|
||||
async function main(): Promise<void> {
|
||||
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<void> {
|
||||
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 => {
|
||||
|
||||
@@ -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)
|
||||
})
|
||||
})
|
||||
@@ -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()
|
||||
}
|
||||
}
|
||||
}
|
||||
Reference in New Issue
Block a user