From 6e83562dff3cbe3dfd70224cb2218fcd37abd2a6 Mon Sep 17 00:00:00 2001 From: Hako Date: Thu, 13 Aug 2026 22:54:28 +0900 Subject: [PATCH] fix(watcher): degrade to slow probes after repeated native watcher failures The native session watcher supervisor retried every 30 seconds forever when the child could not stay up. Under inotify watch exhaustion (ENOSPC) that produced 1752 consecutive silent failures over 14.5 hours, with discovery updates degraded the whole time and nothing actionable in the log (#42). - After 20 consecutive failures the restart schedule degrades from the fast exponential backoff to a 10-minute probe cadence: recovery stays automatic when the host condition clears, without a permanent 30s crash loop. - Crossing the cap logs one loud line naming the run length, and when the child's stderr contained the ENOSPC token, the exact remedy (fs.inotify.max_user_watches). Only that fixed token is retained; stderr content itself is still never forwarded, preserving the invariant that watcher diagnostics never expose transcript paths. - The chokidar per-provider watchers append the same remedy hint to their existing error line when the error names ENOSPC. - getGjcWatcherHealth() exposes ok/consecutiveFailures/degraded/enospc for status surfaces, and the restart schedule is a pure exported function under regression tests. Closes #42 --- .../services/gjc-session-watcher.service.ts | 14 +++- .../services/sessions-watcher.service.ts | 68 +++++++++++++++++-- .../tests/gjc-session-watcher.test.ts | 20 ++++++ .../tests/sessions-watcher-degrade.test.ts | 44 ++++++++++++ 4 files changed, 141 insertions(+), 5 deletions(-) create mode 100644 server/modules/providers/tests/sessions-watcher-degrade.test.ts diff --git a/server/modules/providers/services/gjc-session-watcher.service.ts b/server/modules/providers/services/gjc-session-watcher.service.ts index fe27c6f..13d029a 100644 --- a/server/modules/providers/services/gjc-session-watcher.service.ts +++ b/server/modules/providers/services/gjc-session-watcher.service.ts @@ -113,6 +113,7 @@ export class GjcSessionWatcher { private ready = false; private closed = false; private failed = false; + private enospcSeen = false; private exitedOnce = false; private input = Buffer.alloc(0); private readonly pending = new Map(); @@ -158,7 +159,13 @@ export class GjcSessionWatcher { }); this.child = child; child.stdout.on('data', (chunk) => this.onStdout(chunk)); - child.stderr?.on('data', () => this.diagnose(STDERR_MESSAGE)); + // stderr content is never forwarded (it may name transcript paths), but + // the fixed ENOSPC token is safe and is the one diagnosis an operator + // can act on: inotify watch exhaustion needs a sysctl, not a restart. + child.stderr?.on('data', (chunk) => { + if (!this.enospcSeen && String(chunk).includes('ENOSPC')) this.enospcSeen = true; + this.diagnose(STDERR_MESSAGE); + }); child.stdin.on?.('error', () => this.fail('stdin-error')); child.on('error', () => this.fail('child-error')); child.on('exit', (code, signal) => this.onExit(code, signal)); @@ -265,6 +272,11 @@ export class GjcSessionWatcher { safeCall(() => this.options.diagnostic(message)); } + /** True when the child's stderr named inotify watch exhaustion (ENOSPC). */ + get enospcObserved(): boolean { + return this.enospcSeen; + } + private fail(reason: GjcSessionWatcherFailureReason, detail?: string): void { if (this.failed || this.closed) return; this.failed = true; diff --git a/server/modules/providers/services/sessions-watcher.service.ts b/server/modules/providers/services/sessions-watcher.service.ts index ece753a..1bac4af 100644 --- a/server/modules/providers/services/sessions-watcher.service.ts +++ b/server/modules/providers/services/sessions-watcher.service.ts @@ -76,9 +76,48 @@ let gjcWatcherRestartDelayMs = 1_000; // otherwise logs one indistinguishable line every 30s forever. The run length makes // a stuck loop visible in the log without needing to count timestamps by hand. let gjcWatcherConsecutiveFailures = 0; +let gjcWatcherEnospcObserved = false; let gjcWatcherGeneration = 0; let sessionWatchersClosing = false; const GJC_WATCH_RESTART_MAX_MS = 30_000; +// #42: a watcher failing at the 30s cap because of a host condition (measured: +// inotify ENOSPC for 14.5h / 1752 attempts) cannot succeed by retrying faster. +// After this many consecutive failures the supervisor degrades to a slow probe +// cadence — recovery stays automatic, without a permanent 30s crash loop. +export const GJC_WATCH_MAX_FAST_FAILURES = 20; +export const GJC_WATCH_DEGRADED_RETRY_MS = 10 * 60_000; + +/** Pure restart schedule, exported for tests: fast backoff, then slow probes. */ +export function nextGjcWatcherRestartDelayMs( + consecutiveFailures: number, + currentDelayMs: number, +): { delayMs: number; nextDelayMs: number; degraded: boolean } { + if (consecutiveFailures >= GJC_WATCH_MAX_FAST_FAILURES) { + return { delayMs: GJC_WATCH_DEGRADED_RETRY_MS, nextDelayMs: currentDelayMs, degraded: true }; + } + return { + delayMs: currentDelayMs, + nextDelayMs: Math.min(currentDelayMs * 2, GJC_WATCH_RESTART_MAX_MS), + degraded: false, + }; +} + +export type GjcWatcherHealth = { + ok: boolean; + consecutiveFailures: number; + degraded: boolean; + enospcObserved: boolean; +}; + +/** Current native-watcher health for diagnostics and status surfaces. */ +export function getGjcWatcherHealth(): GjcWatcherHealth { + return { + ok: gjcWatcherConsecutiveFailures === 0, + consecutiveFailures: gjcWatcherConsecutiveFailures, + degraded: gjcWatcherConsecutiveFailures >= GJC_WATCH_MAX_FAST_FAILURES, + enospcObserved: gjcWatcherEnospcObserved, + }; +} type PendingWatcherUpdate = { providers: Set; @@ -415,12 +454,27 @@ function clearGjcWatcherRestartTimer(): void { function scheduleGjcWatcherRestart(): void { if (sessionWatchersClosing || gjcWatcherRestartTimer) return; - const delay = gjcWatcherRestartDelayMs; - gjcWatcherRestartDelayMs = Math.min(gjcWatcherRestartDelayMs * 2, GJC_WATCH_RESTART_MAX_MS); + const schedule = nextGjcWatcherRestartDelayMs( + gjcWatcherConsecutiveFailures, + gjcWatcherRestartDelayMs, + ); + gjcWatcherRestartDelayMs = schedule.nextDelayMs; + if (schedule.degraded && gjcWatcherConsecutiveFailures === GJC_WATCH_MAX_FAST_FAILURES) { + const remedy = gjcWatcherEnospcObserved + ? ' The watcher child reported ENOSPC: raise the inotify limit' + + ' (sudo sysctl -w fs.inotify.max_user_watches=524288, persist in /etc/sysctl.d/)' + + ' — other processes on this host are consuming the watches.' + : ''; + console.error( + `GJC native session watcher degraded after ${gjcWatcherConsecutiveFailures} consecutive failures; ` + + `retrying every ${Math.round(GJC_WATCH_DEGRADED_RETRY_MS / 60_000)} minutes. ` + + `Session discovery updates may lag until it recovers.${remedy}`, + ); + } gjcWatcherRestartTimer = setTimeout(() => { gjcWatcherRestartTimer = null; void startGjcSessionWatcher(true); - }, delay); + }, schedule.delayMs); gjcWatcherRestartTimer.unref?.(); } @@ -447,6 +501,7 @@ async function runGjcSessionWatcherStart( if (failureReported || generation !== gjcWatcherGeneration || sessionWatchersClosing) return; failureReported = true; gjcWatcherConsecutiveFailures += 1; + if (watcher.enospcObserved) gjcWatcherEnospcObserved = true; controller.abort(); if (gjcWatcher === watcher) gjcWatcher = null; const reason = typeof error?.cause === 'string' ? error.cause : 'unreported'; @@ -511,6 +566,7 @@ async function runGjcSessionWatcherStart( } gjcWatcherRestartDelayMs = 1_000; gjcWatcherConsecutiveFailures = 0; + gjcWatcherEnospcObserved = false; } catch (error) { reportFailure(error instanceof Error ? error : undefined); await watcher.close(); @@ -622,7 +678,10 @@ export async function initializeSessionsWatcher(): Promise { }) .on('error', (error: unknown) => { const message = error instanceof Error ? error.message : String(error); - console.error(`Session watcher error for provider "${provider}"`, { error: message }); + const remedy = message.includes('ENOSPC') + ? ' (inotify watch exhaustion — raise fs.inotify.max_user_watches; transcript updates fall back to the 60s reconcile pass)' + : ''; + console.error(`Session watcher error for provider "${provider}"${remedy}`, { error: message }); }); watchers.push(watcher); @@ -694,6 +753,7 @@ export async function closeSessionsWatcher(): Promise { watchers.length = 0; gjcWatcherRestartDelayMs = 1_000; gjcWatcherConsecutiveFailures = 0; + gjcWatcherEnospcObserved = false; pendingWatcherUpdate = null; pendingWatcherUpdateStartedAt = null; watcherRefreshInFlight = false; diff --git a/server/modules/providers/tests/gjc-session-watcher.test.ts b/server/modules/providers/tests/gjc-session-watcher.test.ts index e8a379e..faa8b5d 100644 --- a/server/modules/providers/tests/gjc-session-watcher.test.ts +++ b/server/modules/providers/tests/gjc-session-watcher.test.ts @@ -242,6 +242,26 @@ test('ready timeout and child exit stay distinguishable, exit status included', assert.equal(signalled.failures[0].cause, 'child-exit code=none signal=SIGKILL'); }); +// #42: ENOSPC (inotify watch exhaustion) is a host condition no restart can fix. +// The child names it on stderr; only that fixed token is retained — the stderr +// content itself (which may carry transcript paths) is never forwarded. +test('detects the ENOSPC token on stderr without leaking stderr content', async () => { + const diagnostics: string[] = []; + const { watcher, child } = setup({ diagnostic: (message) => diagnostics.push(message) }); + await ready(watcher, child); + + assert.equal(watcher.enospcObserved, false); + child.stderr.emit('data', Buffer.from('Error: ENOSPC: System limit for number of file watchers reached, watch \'/home/user/.gjc/agent/sessions/secret.jsonl\'')); + assert.equal(watcher.enospcObserved, true); + assert.deepEqual(diagnostics, ['GJC session watcher emitted diagnostics.']); + assert.doesNotMatch(diagnostics.join(' '), /secret/u); + + const clean = setup(); + await ready(clean.watcher, clean.child); + clean.child.stderr.emit('data', Buffer.from('ordinary startup notice')); + assert.equal(clean.watcher.enospcObserved, false); +}); + test('failure diagnostics name the reason so a restart loop is diagnosable from logs alone', async () => { const diagnostics: string[] = []; const { watcher, child } = setup({ diagnostic: (message) => diagnostics.push(message) }); diff --git a/server/modules/providers/tests/sessions-watcher-degrade.test.ts b/server/modules/providers/tests/sessions-watcher-degrade.test.ts new file mode 100644 index 0000000..2f53d69 --- /dev/null +++ b/server/modules/providers/tests/sessions-watcher-degrade.test.ts @@ -0,0 +1,44 @@ +import assert from 'node:assert/strict'; +import test from 'node:test'; + +import { + GJC_WATCH_DEGRADED_RETRY_MS, + GJC_WATCH_MAX_FAST_FAILURES, + getGjcWatcherHealth, + nextGjcWatcherRestartDelayMs, +} from '@/modules/providers/services/sessions-watcher.service.js'; + +// #42 regression lock: the native watcher supervisor used to retry every 30s +// forever (measured: 1752 consecutive failures over 14.5h under inotify +// ENOSPC). Below the cap the fast exponential backoff is unchanged; at the cap +// the schedule degrades to slow probes so recovery stays automatic without a +// permanent crash loop. +test('restart schedule keeps the fast backoff below the failure cap', () => { + let delayMs = 1_000; + const delays: number[] = []; + for (let failures = 1; failures < GJC_WATCH_MAX_FAST_FAILURES; failures += 1) { + const schedule = nextGjcWatcherRestartDelayMs(failures, delayMs); + assert.equal(schedule.degraded, false, `failure ${failures} must stay in the fast lane`); + delays.push(schedule.delayMs); + delayMs = schedule.nextDelayMs; + } + assert.deepEqual(delays.slice(0, 6), [1_000, 2_000, 4_000, 8_000, 16_000, 30_000]); + assert.ok(delays.every((delay) => delay <= 30_000)); +}); + +test('at the cap the schedule degrades to slow probes and stays there', () => { + for (const failures of [GJC_WATCH_MAX_FAST_FAILURES, GJC_WATCH_MAX_FAST_FAILURES + 1, 1_752]) { + const schedule = nextGjcWatcherRestartDelayMs(failures, 30_000); + assert.equal(schedule.degraded, true, String(failures)); + assert.equal(schedule.delayMs, GJC_WATCH_DEGRADED_RETRY_MS); + } +}); + +test('watcher health starts clean and its shape is stable for status surfaces', () => { + assert.deepEqual(getGjcWatcherHealth(), { + ok: true, + consecutiveFailures: 0, + degraded: false, + enospcObserved: false, + }); +});