From 619ee2cc90a73cd1f2ac94c9e2436d4c2a4eacd3 Mon Sep 17 00:00:00 2001 From: Brennan Benson <79079362+brennanb2025@users.noreply.github.com> Date: Mon, 17 Aug 2026 15:15:14 -0700 Subject: [PATCH] fix(agent-hooks): detect IDS-truncated hook POSTs instead of failing open silently (STA-2870) (#14625) --- .../server-transport-interference.test.ts | 156 ++++++++++++++++++ src/main/agent-hooks/server.ts | 35 +++- src/main/index.ts | 6 + src/relay/agent-hook-server.ts | 16 ++ src/shared/agent-hook-listener.ts | 13 +- .../agent-hook-transport-interference.test.ts | 101 ++++++++++++ .../agent-hook-transport-interference.ts | 105 ++++++++++++ src/shared/telemetry-events.ts | 6 + 8 files changed, 434 insertions(+), 4 deletions(-) create mode 100644 src/main/agent-hooks/server-transport-interference.test.ts create mode 100644 src/shared/agent-hook-transport-interference.test.ts create mode 100644 src/shared/agent-hook-transport-interference.ts diff --git a/src/main/agent-hooks/server-transport-interference.test.ts b/src/main/agent-hooks/server-transport-interference.test.ts new file mode 100644 index 00000000000..37c80087bdb --- /dev/null +++ b/src/main/agent-hooks/server-transport-interference.test.ts @@ -0,0 +1,156 @@ +// Reproduces #11217's mechanism without an IDS: an authenticated hook POST whose body is cut +// short of its own Content-Length. The listener fails open on every request error, so the only +// way this stays diagnosable is if the truncation is classified before it is swallowed. +import { connect } from 'node:net' +import { afterEach, describe, expect, it, vi } from 'vitest' +import type { HookTransportInterferenceReport } from '../../shared/agent-hook-transport-interference' +import { AgentHookServer } from './server' + +async function postTruncatedHook( + port: number, + token: string, + options: { pathname?: string; sentBytes?: string; announcedLength?: number } = {} +): Promise { + const { + pathname = '/hook/claude', + sentBytes = 'paneKey=tab', + announcedLength = 100_000 + } = options + await new Promise((resolve, reject) => { + const socket = connect({ port, host: '127.0.0.1' }, () => { + socket.write( + `POST ${pathname} HTTP/1.1\r\nHost: 127.0.0.1\r\nContent-Type: application/x-www-form-urlencoded\r\nX-Orca-Agent-Hook-Token: ${token}\r\nContent-Length: ${announcedLength}\r\n\r\n${sentBytes}` + ) + // Why: an RST mid-body is what an inspecting IDS does; a FIN would be an ordinary client hangup. + setTimeout(() => { + socket.resetAndDestroy() + resolve() + }, 20) + }) + socket.on('error', () => { + resolve() + }) + socket.setTimeout(2_000, () => { + socket.destroy() + reject(new Error('truncated post never connected')) + }) + }) + // Why: the server settles the request on 'close', which lands a tick after the client's reset. + await new Promise((resolve) => setTimeout(resolve, 50)) +} + +/** Opens a POST that announces a body and then never sends it, so Orca's own slowloris cap ends it. */ +async function postStalledHook(port: number, token: string): Promise { + const socket = connect({ port, host: '127.0.0.1' }) + await new Promise((resolve) => socket.on('connect', () => resolve())) + socket.write( + `POST /hook/claude HTTP/1.1\r\nHost: 127.0.0.1\r\nContent-Type: application/x-www-form-urlencoded\r\nX-Orca-Agent-Hook-Token: ${token}\r\nContent-Length: 100000\r\n\r\n` + ) + await new Promise((resolve) => { + socket.on('close', () => resolve()) + socket.on('error', () => resolve()) + }) + await new Promise((resolve) => setTimeout(resolve, 50)) +} + +async function postCompleteHook(port: number, token: string): Promise { + const body = 'paneKey=tab%3Aleaf&payload=%7B%7D' + const response = await fetch(`http://127.0.0.1:${port}/hook/claude`, { + method: 'POST', + headers: { + 'Content-Type': 'application/x-www-form-urlencoded', + 'X-Orca-Agent-Hook-Token': token + }, + body + }) + expect(response.status).toBe(204) +} + +describe('AgentHookServer transport interference', () => { + const servers: AgentHookServer[] = [] + const warn = vi.spyOn(console, 'warn').mockImplementation(() => {}) + + afterEach(() => { + for (const server of servers) { + server.stop() + } + servers.length = 0 + warn.mockClear() + }) + + async function startServer(): Promise<{ + server: AgentHookServer + port: number + token: string + reports: HookTransportInterferenceReport[] + }> { + const server = new AgentHookServer() + servers.push(server) + const reports: HookTransportInterferenceReport[] = [] + server.setTransportInterferenceListener((report) => { + reports.push(report) + }) + await server.start() + const env = server.buildPtyEnv() + return { + server, + port: Number(env.ORCA_AGENT_HOOK_PORT), + token: env.ORCA_AGENT_HOOK_TOKEN, + reports + } + } + + it('reports once after repeated truncated POSTs and names the route', async () => { + const { port, token, reports } = await startServer() + + await postTruncatedHook(port, token) + await postTruncatedHook(port, token) + expect(reports).toEqual([]) + + await postTruncatedHook(port, token, { pathname: '/hook/codex' }) + expect(reports).toEqual([ + { count: 3, source: 'codex', bytesRead: expect.any(Number), contentLength: 100_000 } + ]) + expect(warn.mock.calls.flat().join(' ')).toContain('security software') + + // Why: warn-once — a blocked fleet must not turn every hook event into a log line. + await postTruncatedHook(port, token) + expect(reports).toHaveLength(1) + }, 20_000) + + it('never reports for POSTs that deliver their whole body', async () => { + const { port, token, reports } = await startServer() + + for (let i = 0; i < 5; i++) { + await postCompleteHook(port, token) + } + + expect(reports).toEqual([]) + }, 20_000) + + it('excludes requests the slowloris cap destroyed, so the count stays honest', async () => { + const { port, token, reports } = await startServer() + + await postTruncatedHook(port, token) + await postTruncatedHook(port, token) + // Why: Orca destroys this one itself at HOOK_REQUEST_SLOWLORIS_MS; counting it would make + // every stalled agent look like an IDS block. + await postStalledHook(port, token) + expect(reports).toEqual([]) + + await postTruncatedHook(port, token) + expect(reports).toHaveLength(1) + expect(reports[0].count).toBe(3) + }, 30_000) + + it('never reports for unauthenticated probes', async () => { + const { port, reports } = await startServer() + + // Why: a port scanner is not interference; only a request that cleared the token check can be. + await postTruncatedHook(port, 'wrong-token') + await postTruncatedHook(port, 'wrong-token') + await postTruncatedHook(port, 'wrong-token') + + expect(reports).toEqual([]) + }, 20_000) +}) diff --git a/src/main/agent-hooks/server.ts b/src/main/agent-hooks/server.ts index 2f450d6a6b9..2743ace64df 100644 --- a/src/main/agent-hooks/server.ts +++ b/src/main/agent-hooks/server.ts @@ -40,6 +40,12 @@ import { type AgentHookEventPayload, type HookListenerState } from '../../shared/agent-hook-listener' +import { + createHookTransportInterferenceTracker, + describeHookTransportInterference, + isHookRequestTruncatedError, + type HookTransportInterferenceReport +} from '../../shared/agent-hook-transport-interference' import { claudeTeammateIdMatchesName, claudeRosterHasRestoredSnapshotSubagent, @@ -683,6 +689,11 @@ export class AgentHookServer { private endpointFileWritten = false // Why: per-instance (not module-level) so tests can spin up multiple servers without state cross-contamination. private state: HookListenerState = createHookListenerState() + private onTransportInterference: ((report: HookTransportInterferenceReport) => void) | null = null + private transportInterference = createHookTransportInterferenceTracker((report) => { + console.warn(describeHookTransportInterference(report)) + this.onTransportInterference?.(report) + }) // Why: hydrated rows give UI continuity but aren't evidence of live agent work in this runtime. private runtimeObservedStatusPaneKeys = new Set() private hydratedAuthorityCommitments: readonly AgentHookAuthorityEvidence[] = Object.freeze([]) @@ -707,6 +718,17 @@ export class AgentHookServer { // Why: skip disk writes when the JSON exactly matches the last write; guards against re-firing trailing timers when nothing changed. private lastWrittenJson: string | null = null + /** + * Notified once per process when repeated hook POSTs are cut off mid-body (#11217). + * Why: the listener fails open on every request error, so without this the only symptom is + * agent status quietly going stale — for every runtime at once, since they share this transport. + */ + setTransportInterferenceListener( + listener: ((report: HookTransportInterferenceReport) => void) | null + ): void { + this.onTransportInterference = listener + } + setListener(listener: ((payload: EnrichedAgentHookEventPayload) => void) | null): void { this.onAgentStatus = listener if (!listener) { @@ -2251,13 +2273,16 @@ export class AgentHookServer { } // Why: bound request time so a stalled client can't hold a socket open (slowloris). + // Why: track our own destroy so the slowloris cap can't be misread as outside interference. + let destroyedBySlowlorisCap = false req.setTimeout(HOOK_REQUEST_SLOWLORIS_MS, () => { + destroyedBySlowlorisCap = true req.destroy() }) + const pathname = new URL(req.url ?? '/', 'http://127.0.0.1').pathname try { const body = await readRequestBody(req) - const pathname = new URL(req.url ?? '/', 'http://127.0.0.1').pathname if (pathname === CLAUDE_STATUSLINE_PATHNAME) { const statusLineEvent = parseClaudeStatusLineBody(body) if (statusLineEvent) { @@ -2296,7 +2321,13 @@ export class AgentHookServer { res.writeHead(204) res.end() - } catch { + } catch (error) { + // Why (#11217): an authenticated POST whose body dies short of its own Content-Length was cut + // by something on the loopback path, not by a bad payload. Fail open as before, but count it — + // this is the one failure mode that silently stops status for every runtime at once. + if (isHookRequestTruncatedError(error) && !destroyedBySlowlorisCap) { + this.transportInterference.record({ source: resolveHookSource(pathname) ?? null, error }) + } // Why: fail open — return success on malformed payloads so a broken hook never blocks the agent. res.writeHead(204) res.end() diff --git a/src/main/index.ts b/src/main/index.ts index 751dcee4601..90aed9840ef 100644 --- a/src/main/index.ts +++ b/src/main/index.ts @@ -999,6 +999,12 @@ function startTerminalRuntimeStartupServices(): WindowsDesktopStartupServices { return } logStartupMilestone('startup-service-start', { service: 'agent-hook-server' }) + // Why (#11217): the hook listener fails open on every request error, so an IDS resetting + // loopback POSTs mid-body stops agent status for every runtime with no symptom but staleness. + // Log + telemetry (the daemon_start_failed pattern) so it is diagnosable without a packet capture. + agentHookServer.setTransportInterferenceListener((report) => { + track('agent_hook_transport_blocked', { count: report.count }) + }) await agentHookServer.start({ env: app.isPackaged ? 'production' : 'development', // Why: hooks source this endpoint file at invocation time so old PTY env reaches the current process after restart; dev namespaces it (worktrees share `orca-dev`). diff --git a/src/relay/agent-hook-server.ts b/src/relay/agent-hook-server.ts index 878403ddbde..7dc54d820d5 100644 --- a/src/relay/agent-hook-server.ts +++ b/src/relay/agent-hook-server.ts @@ -22,6 +22,11 @@ import { type AgentHookEventPayload, type HookListenerState } from '../shared/agent-hook-listener' +import { + createHookTransportInterferenceTracker, + describeHookTransportInterference, + isHookRequestTruncatedError +} from '../shared/agent-hook-transport-interference' import { REMOTE_AGENT_HOOK_ENV, type AgentHookRelayEnvelope, @@ -62,6 +67,9 @@ export class RelayAgentHookServer { private endpointFilePath: string private endpointFileWritten = false private state: HookListenerState = createHookListenerState() + private transportInterference = createHookTransportInterferenceTracker((report) => { + process.stderr.write(`${describeHookTransportInterference(report)}\n`) + }) // Why: retain envelope metadata so replays match live POSTs. // Invariant: keys mirror state.lastStatusByPaneKey, populated/cleared in lockstep. private lastEnvelopeMetaByPaneKey = new Map< @@ -225,7 +233,10 @@ export class RelayAgentHookServer { res.end() return } + // Why: track our own destroy so the slowloris cap can't be misread as outside interference. + let destroyedBySlowlorisCap = false req.setTimeout(HOOK_REQUEST_SLOWLORIS_MS, () => { + destroyedBySlowlorisCap = true req.destroy() }) try { @@ -252,6 +263,11 @@ export class RelayAgentHookServer { res.writeHead(204) res.end() } catch (err) { + // Why (#11217): a remote host can run the same IDS; count truncations here so a blocked SSH + // relay reports the cause instead of an anonymous "hook request failed". + if (isHookRequestTruncatedError(err) && !destroyedBySlowlorisCap) { + this.transportInterference.record({ source: null, error: err }) + } // Why: hooks fail open (204 on any error) so a buggy agent never blocks the run; still log so the 204 doesn't mask bugs. process.stderr.write( `[relay-hook-server] hook request failed: ${err instanceof Error ? err.message : String(err)}\n` diff --git a/src/shared/agent-hook-listener.ts b/src/shared/agent-hook-listener.ts index dc349fcdaed..e471c55d25e 100644 --- a/src/shared/agent-hook-listener.ts +++ b/src/shared/agent-hook-listener.ts @@ -76,6 +76,7 @@ import { resolveGrokSessionsDir } from './grok-session-paths' import { sweepStaleAgentHookEndpointTemps } from './agent-hook-endpoint-temp-cleanup' +import { classifyTruncatedHookRequest } from './agent-hook-transport-interference' import { assertJsonTextStructureWithinLimits } from './json-text-structure-limit' /** Maximum request body size accepted by the listener (1 MB). */ @@ -534,12 +535,20 @@ export function readRequestBody(req: IncomingMessage): Promise { settleReject(error) } } + // Why (#11217): a body cut short of its own Content-Length is the fingerprint of an IDS + // resetting the connection mid-inspection. Classify on every path that ends the request without + // 'end' — a peer RST surfaces as 'error' (ECONNRESET) and only a local destroy reaches 'close' first. + const settleUnfinished = (fallback: Error): void => { + settleReject( + classifyTruncatedHookRequest(req.headers['content-length'], byteLength) ?? fallback + ) + } const onError = (err: Error): void => { - settleReject(err) + settleUnfinished(err) } // Why: req.destroy() (slowloris timer) emits 'close' but not 'end'/'error'; without this the promise never settles and buffers leak. const onClose = (): void => { - settleReject(new Error('aborted')) + settleUnfinished(new Error('aborted')) } req.on('data', onData) req.on('end', onEnd) diff --git a/src/shared/agent-hook-transport-interference.test.ts b/src/shared/agent-hook-transport-interference.test.ts new file mode 100644 index 00000000000..95b4c97c055 --- /dev/null +++ b/src/shared/agent-hook-transport-interference.test.ts @@ -0,0 +1,101 @@ +import { describe, expect, it, vi } from 'vitest' +import { + classifyTruncatedHookRequest, + createHookTransportInterferenceTracker, + describeHookTransportInterference, + HookRequestTruncatedError, + isHookRequestTruncatedError +} from './agent-hook-transport-interference' + +describe('classifyTruncatedHookRequest', () => { + it('reports truncation when fewer bytes arrived than Content-Length promised', () => { + const error = classifyTruncatedHookRequest('4096', 512) + expect(isHookRequestTruncatedError(error)).toBe(true) + expect(error).toMatchObject({ bytesRead: 512, contentLength: 4096 }) + }) + + it('reports truncation when the connection died before any body byte', () => { + expect(classifyTruncatedHookRequest('4096', 0)).toBeInstanceOf(HookRequestTruncatedError) + }) + + it('stays silent for a complete body', () => { + expect(classifyTruncatedHookRequest('512', 512)).toBeNull() + }) + + it('stays silent without a usable Content-Length', () => { + // Why: chunked bodies and malformed headers prove nothing — reporting them would drown the signal. + expect(classifyTruncatedHookRequest(undefined, 10)).toBeNull() + expect(classifyTruncatedHookRequest('', 10)).toBeNull() + expect(classifyTruncatedHookRequest('not-a-number', 10)).toBeNull() + }) + + it('reads the first value when the header arrives duplicated', () => { + expect(classifyTruncatedHookRequest(['4096', '4096'], 12)).toBeInstanceOf( + HookRequestTruncatedError + ) + }) +}) + +describe('createHookTransportInterferenceTracker', () => { + const truncation = { source: 'claude', error: new HookRequestTruncatedError(10, 900) } + + it('stays quiet below the threshold so a single crashed writer is not an alarm', () => { + const onThreshold = vi.fn() + const tracker = createHookTransportInterferenceTracker(onThreshold, 3) + tracker.record(truncation) + tracker.record(truncation) + expect(onThreshold).not.toHaveBeenCalled() + expect(tracker.getCount()).toBe(2) + }) + + it('reports exactly once at the threshold and keeps counting after', () => { + const onThreshold = vi.fn() + const tracker = createHookTransportInterferenceTracker(onThreshold, 3) + for (let i = 0; i < 6; i++) { + tracker.record(truncation) + } + expect(onThreshold).toHaveBeenCalledTimes(1) + expect(onThreshold).toHaveBeenCalledWith({ + count: 3, + source: 'claude', + bytesRead: 10, + contentLength: 900 + }) + expect(tracker.getCount()).toBe(6) + }) + + it('re-arms after reset', () => { + const onThreshold = vi.fn() + const tracker = createHookTransportInterferenceTracker(onThreshold, 1) + tracker.record(truncation) + tracker.reset() + tracker.record(truncation) + expect(onThreshold).toHaveBeenCalledTimes(2) + }) +}) + +describe('describeHookTransportInterference', () => { + it('names the cause and the consequence so the log line is actionable', () => { + const message = describeHookTransportInterference({ + count: 3, + source: 'codex', + bytesRead: 10, + contentLength: 900 + }) + expect(message).toContain('/hook/codex') + expect(message).toContain('10/900 bytes') + expect(message).toContain('security software') + // Why: the client's own --max-time can truncate too; a single-cause message would misdiagnose a stall. + expect(message).toContain('stalled past the hook client timeout') + }) + + it('omits the route when the truncation happened before it resolved', () => { + const message = describeHookTransportInterference({ + count: 3, + source: null, + bytesRead: 0, + contentLength: 900 + }) + expect(message).not.toContain('/hook/') + }) +}) diff --git a/src/shared/agent-hook-transport-interference.ts b/src/shared/agent-hook-transport-interference.ts new file mode 100644 index 00000000000..820dc2e013b --- /dev/null +++ b/src/shared/agent-hook-transport-interference.ts @@ -0,0 +1,105 @@ +// Transport background and the allowlisting answer for security teams: docs/reference/agent-hook-transport.md +// +// Why (#11217): enterprise IDS/AV products inspect loopback HTTP bodies and reset the hook POST +// mid-flight when the agent's own tool I/O happens to match an LFI/command-injection signature. +// The listener fails open on every error, so a reset arrives as a swallowed exception and agent +// status stops with no diagnostic anywhere. Classifying the truncation is what makes it reportable. + +/** Thrown by the listener when a request closed before `end` with fewer bytes than `Content-Length` promised. */ +export class HookRequestTruncatedError extends Error { + readonly bytesRead: number + readonly contentLength: number + + constructor(bytesRead: number, contentLength: number) { + super(`hook request truncated after ${bytesRead} of ${contentLength} bytes`) + this.name = 'HookRequestTruncatedError' + this.bytesRead = bytesRead + this.contentLength = contentLength + } +} + +export function isHookRequestTruncatedError(error: unknown): error is HookRequestTruncatedError { + return error instanceof HookRequestTruncatedError +} + +/** + * Truncation is only interference when Orca did not cause it. `Content-Length` must be present and + * unmet: a chunked body or a completed one proves nothing, and reporting those would make the + * signal useless. + */ +export function classifyTruncatedHookRequest( + contentLengthHeader: string | string[] | undefined, + bytesRead: number +): HookRequestTruncatedError | null { + const raw = Array.isArray(contentLengthHeader) ? contentLengthHeader[0] : contentLengthHeader + if (!raw || !/^\d+$/.test(raw.trim())) { + return null + } + const contentLength = Number(raw.trim()) + return bytesRead < contentLength ? new HookRequestTruncatedError(bytesRead, contentLength) : null +} + +/** Why: one truncation can be a crashed agent mid-write; a repeat is a device on the loopback path. */ +export const HOOK_TRANSPORT_INTERFERENCE_THRESHOLD = 3 + +export type HookTransportInterferenceReport = { + /** Total authenticated-but-truncated hook POSTs observed since start. */ + count: number + /** The hook route of the most recent truncation, when the URL resolved to one. */ + source: string | null + bytesRead: number + contentLength: number +} + +export type HookTransportInterferenceTracker = { + record: (detail: { source: string | null; error: HookRequestTruncatedError }) => void + getCount: () => number + reset: () => void +} + +/** + * Counts truncated hook POSTs and reports exactly once, at `threshold`. Counting continues after + * the report so a diagnostics reader can still see the magnitude without re-notifying per event. + */ +export function createHookTransportInterferenceTracker( + onThresholdReached: (report: HookTransportInterferenceReport) => void, + threshold: number = HOOK_TRANSPORT_INTERFERENCE_THRESHOLD +): HookTransportInterferenceTracker { + let count = 0 + let reported = false + return { + record: ({ source, error }) => { + count += 1 + if (reported || count < threshold) { + return + } + reported = true + onThresholdReached({ + count, + source, + bytesRead: error.bytesRead, + contentLength: error.contentLength + }) + }, + getCount: () => count, + reset: () => { + count = 0 + reported = false + } + } +} + +/** + * Shared operator-facing text. Names the likely cause first but not exclusively: the hook client's + * own `--max-time` can also cut a body if this process stalls, and claiming certainty would send a + * user to their IT department over a main-thread hang. + */ +export function describeHookTransportInterference(report: HookTransportInterferenceReport): string { + return ( + `[agent-hooks] ${report.count} agent-status POSTs were cut off mid-body on loopback ` + + `(last: ${report.bytesRead}/${report.contentLength} bytes${report.source ? `, /hook/${report.source}` : ''}). ` + + 'Agent status will be missing for every runtime until this stops. Most likely local network ' + + 'security software is inspecting and blocking loopback HTTP; less likely, this process stalled ' + + 'past the hook client timeout. See docs/reference/agent-hook-transport.md.' + ) +} diff --git a/src/shared/telemetry-events.ts b/src/shared/telemetry-events.ts index f6bbea3c755..0466ca79430 100644 --- a/src/shared/telemetry-events.ts +++ b/src/shared/telemetry-events.ts @@ -781,6 +781,11 @@ const agentHookUnattributedSchema = z .object({ reason: z.enum(['empty_pane_key', 'unknown_tab_id']) }) .strict() +// Why (#11217): loopback hook POSTs reset mid-body by local security software kill agent status for +// every runtime at once. Count only — the truncated bodies carry user prompts and tool I/O, so +// nothing derived from them may reach the wire. +const agentHookTransportBlockedSchema = z.object({ count: z.number().int().nonnegative() }).strict() + // ── Onboarding ────────────────────────────────────────────────────────── // Closed enums only — no raw paths/repo names/URLs/error strings (measures activation, not repo debugging). // Why: event names still carry legacy seven-step payloads; keep validation backward-compatible for old rows. @@ -1444,6 +1449,7 @@ export const eventSchemas = { agent_error: agentErrorSchema, agent_hook_install_failed: agentHookInstallFailedSchema, agent_hook_unattributed: agentHookUnattributedSchema, + agent_hook_transport_blocked: agentHookTransportBlockedSchema, daemon_start_failed: daemonStartFailedSchema, main_thread_hang_detected: mainThreadHangDetectedSchema,