From 36caf8c2013fd8277f95488e174780444b2a3c99 Mon Sep 17 00:00:00 2001 From: hamr0 Date: Sun, 26 Jul 2026 02:04:31 +0200 Subject: [PATCH] =?UTF-8?q?fix:=20BA-18=20=E2=80=94=20a=20request/idle=20t?= =?UTF-8?q?imeout=20on=20the=20http(s)=20providers=20(a=20hung=20socket=20?= =?UTF-8?q?was=20a=20~2h=20hang,=20not=20an=20error)?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The four http(s) providers (Anthropic, OpenAI, Gemini, Ollama) built their request with only `req.on('error')` wired — no socket timeout, no AbortSignal — so a socket the server silently dropped, or a response that never starts, was bounded only by the OS TCP timeout (~2h on Linux). It presented to the caller as a HANG, not a failure (no event, no error, no progress), which made every retry/casualty policy above it inert. Same BA-4/5/6/13/17 under-modeled-boundary family: a hung socket has no slot in the neutral result shape, so it rounded toward "still working." Part 1 (real): new `timeoutMs` option on all four providers (default 600000ms / 10 min, per-call overridable, 0/Infinity disable). One shared src/provider-http.js (resolveTimeoutMs/applyRequestTimeout) so the four cannot drift. Bounds on socket INACTIVITY (req.setTimeout) — a slow-but-streaming response is not killed, only a silent socket trips; the 10-min default clears any single non-streaming completion (TTFB ≈ generation time). On trip: a retryable TimeoutError (code:'ETIMEDOUT'). CLIPipe already bounded its child; unchanged. Part 2 (name mismatch, no code): the ask cited "withRetry has zero call sites." There is no withRetry — the primitive is Retry.call, and it IS wired around provider.generate (Loop({retry}), plus run-plan's stepRetry), with DEFAULT_RETRY_ON already classifying ETIMEDOUT transient. Covered by tests + docs; the intended contract is caller-side wiring, and the provider-level timeoutMs protects a caller who uses the provider directly. Disable-edge semantics are fail-safe (code-review findings 2 & 3): a per-call null/undefined INHERITS the instance value (a per-call null never re-enables the default over an instance-level disable), and a NaN/negative/non-finite value (e.g. Number(process.env.X) on an unset var) falls back to the default rather than silently disabling the bound (which would round back toward the ~2h hang). Per-call timeoutMs is now documented in each generate() JSDoc (finding 4). Finding 1 (finite default regresses >10min non-streaming completions) is the signed-off design choice — aligned with Anthropic's own ~10-min non-streaming ceiling, with 0/Infinity as the documented escape hatch and the Ollama cold-load caveat noted. Validation: POC (poc/ba18-timeout.mjs, real loopback servers, 9/9); +21 tests (all 4 providers fire + no false trip, resolveTimeoutMs incl. the two disable-edge fixes, the Retry seam); 5 mutations proven RED incl. a guard-OFF negative control that reproduces the hang and one per review fix; live verify on the real https wire 4/4 (poc/ba18-verify-shipped.mjs). Also folded in (separate, pre-existing): a flaky mcp-bridge reaping test whose 300ms connect-timeout raced node's ~400-500ms cold-start on a slow host — the child was SIGKILLed before it wrote its pid witness (ENOENT), so the test failed on this machine (passed on the faster release host). Raised that test's connect timeout to 2000ms (still ≪ the 10000ms slow-init, so it still exercises fail-to-connect + reaping). No product change. Docs synced same commit: CHANGELOG (0.34.0), CLAUDE.md, bareagent.context.md (+header), docs/02-features/errors.md, PRD §22. Version bumped 0.33.1 → 0.34.0 (new public option = MINOR). Co-Authored-By: Claude Opus 4.8 Claude-Session: https://claude.ai/code/session_01EWGqnWr4Qn3gDnHrE3DaZi --- CHANGELOG.md | 40 +++++++ CLAUDE.md | 2 +- bareagent.context.md | 4 +- docs/01-product/prd.md | 34 ++++++ docs/02-features/errors.md | 3 + package-lock.json | 4 +- package.json | 2 +- poc/ba18-timeout.mjs | 132 +++++++++++++++++++++ poc/ba18-verify-shipped.mjs | 39 ++++++ src/provider-anthropic.js | 13 +- src/provider-gemini.js | 13 +- src/provider-http.js | 59 ++++++++++ src/provider-ollama.js | 13 +- src/provider-openai.js | 16 ++- test/mcp-bridge.test.js | 7 +- test/provider-timeout.test.js | 216 ++++++++++++++++++++++++++++++++++ 16 files changed, 579 insertions(+), 18 deletions(-) create mode 100644 poc/ba18-timeout.mjs create mode 100644 poc/ba18-verify-shipped.mjs create mode 100644 src/provider-http.js create mode 100644 test/provider-timeout.test.js diff --git a/CHANGELOG.md b/CHANGELOG.md index e053960..5034b6f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,46 @@ All notable changes to bare-agent are documented here. Format: [Keep a Changelog](https://keepachangelog.com/). Versioning: [SemVer](https://semver.org/). +## [0.34.0] - 2026-07-26 + +### Added + +- **BA-18 — a configurable request/idle timeout on the http(s) providers (Anthropic, OpenAI, + Gemini, Ollama).** Before this, each provider built its request with only `req.on('error')` + wired — no socket timeout, no `AbortSignal` — so a socket the server silently dropped, or a + response that never starts, was bounded only by the **OS TCP timeout (~2h on Linux)**. It + presented to the caller as a *hang*, not a failure (no event, no error, no progress), which made + every retry/casualty policy above it inert by construction. Observed by an adopter 3/3 times a job + idled the connection 40–56s between turns: a single `generate()` never returned for **38 min** + (twice) and **2h24m** (once). + - New `timeoutMs` option on all four providers (constructor default **600000ms / 10 min**; + overridable per call via `generate(..., { timeoutMs })`). It bounds on socket **inactivity** + (`req.setTimeout`), so a slow-but-streaming response is not killed — only a silent or + never-answering socket trips it. The 10-min default sits safely above any single non-streaming + completion (TTFB ≈ generation time, since these requests are non-streaming) and well below the + OS ceiling. `0` or `Infinity` disables it (byte-identical pre-BA-18 behaviour). Disable-edge + semantics are fail-safe: a per-call `null`/`undefined` **inherits** the instance value (so a + per-call `null` never re-enables the default over an instance-level disable), and a `NaN` / + negative / non-finite value (e.g. `Number(process.env.X)` on an unset var) falls back to the + default rather than silently disabling the bound. + - On trip, `generate()` rejects with a **retryable `TimeoutError`** (`code: 'ETIMEDOUT'`, + `retryable: true`) — the shape `DEFAULT_RETRY_ON` already classifies as transient. + - Implemented once in `src/provider-http.js` (`resolveTimeoutMs` / `applyRequestTimeout`) and + wired at each provider's `_request`, so the four cannot drift. CLIPipe already bounded its child + process and is unchanged. + +### Clarified (no code change) + +- **The Retry seam already reaches the transient table.** BA-18's second part asked to "wire + `withRetry` around `provider.generate`, or document the seam." There is no `withRetry` — the + primitive is `Retry.call()`, and it *is* wired around `provider.generate` at `loop.js` (via + `Loop({ retry })`) and consumed by `run-plan`'s `stepRetry`. `DEFAULT_RETRY_ON` (`retry.js`) + classifies `ETIMEDOUT`/`ECONNRESET`/`ENOTFOUND`/429/5xx as transient, so a wired `Retry` already + retries a timed-out request and rethrows under `retryOn: () => false`. Now covered by tests and + documented (`docs/02-features/errors.md`, `usage-guide.md`). The intended contract is caller-side + wiring; the provider-level `timeoutMs` above is what protects a caller who uses the provider + directly, without a Loop. + ## [0.33.1] - 2026-07-22 ### Fixed diff --git a/CLAUDE.md b/CLAUDE.md index fbe2a35..2054e35 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -31,7 +31,7 @@ Node.js >= 18, pure JS + JSDoc, `node:test` for testing. Flat `src/` layout with | Spawn | tools/spawn.js | Fork child bareagent (`bin/cli.js --config`). LLM-callable blocks; library `spawnChild` returns handle. One JSONL channel per child (stderr re-emitted as `child:stderr`). Threads BAREGUARD env vars; bareguard 0.2+ caps per-family via `spawn.ratePerMinute` + `limits.maxDepth`. `timeoutMs` = wall-clock ceiling; opt-in `idleTimeoutMs` = heartbeat watchdog (kills a child silent on both stdio for N ms; resets per line, so slow-but-working children survive — result carries `idleKilled`) | | Defer | tools/defer.js | Append `{id, action, when}` to JSONL queue for an external waker (cron + `examples/wake.sh`) to fire later. Two-phase gov: emit-time gate.check on `defer` action; fire-time gate.check on inner action. bareguard 0.2+ caps via `defer.ratePerMinute` | -Providers: OpenAI, Anthropic, Gemini, Ollama, CLIPipe, Fallback -- each in `src/provider-*.js`. All normalize `stopReason` (BA-6) to one neutral vocabulary via `src/provider-stop-reason.js` (`end_turn`/`max_tokens`/`tool_use`/`stop_sequence`/`refusal`/`pause_turn`/`context_exceeded`; unknown-or-absent ⇒ `null` ⇒ pre-BA-6 behavior, so an unmapped provider degrades to the status quo, never to a false truncation). All 5 verified live. `tool_use` is DERIVED where the API can't express it: Gemini/Ollama return `STOP`/`stop` on a complete tool call (no tool-call finish reason), so `normalizeStopReason(raw, provider, {hasToolCalls})` promotes `end_turn`→`tool_use` when the round carried a call — narrow by design (only `end_turn`; a truncated `max_tokens` round stays truncated, preserving BA-4's refusal; never touches refusal/pause/context/passthrough). All normalize `usage` to one neutral shape incl. prompt-cache tiers (`cacheReadTokens`/`cacheCreationTokens`; `inputTokens` = uncached remainder). Gemini is native `generateContent` (its OpenAI-compat endpoint drops the cache tier). Anthropic has opt-in `cacheSystem` (cache_control on the system prompt — weak on its own: the 1024–4096-tok model-dependent cache minimum means a short persona silently never caches) + **opt-in `cacheMessages` (BA-1)** = a rolling `cache_control` breakpoint on the LAST content block of the LAST message, so a tool loop stops re-buying its whole transcript at full price every round (measured: $0.0753→$0.0110/round, 6.8× steady-state; the 1.25× write is paid once). It MUST live in the provider — the transcript ends on a `tool_result` that `_toAnthropicMessage` rebuilds, so no caller seam (`assemble` included) can reach it. Copy-on-write (never mutate the caller's array — a stale mark accumulates; Anthropic allows ≤4). Caching pays for RE-SENDING, not GROWING; a destructive `trim` fold that rewrites the PREFIX invalidates it (fold the middle, keep the head). **Provider-native block passthrough (BA-7):** `Message.providerBlocks`/`GenerateResult.providerBlocks` = `{provider, model, blocks}` — the transcript field for content blocks the normalized `{text, toolCalls}` shape CANNOT express (Anthropic `thinking`/`redacted_thinking`), which the OpenAI-shaped `Message` had nowhere to put and so silently DROPPED (the API returns 200 either way — the loss never surfaced). Anthropic echoes thinking back unchanged (signature included) on a tool-use continuation; the provider now replays them at the FRONT of the assistant turn (thinking must lead). Three constraints: OPAQUE (keep bytes, never re-serialize from parsed fields — a `redacted_thinking` block can't survive it, and a `type==='thinking'` check would silently drop the next new block type = the same bug again); the provider+model TAG is enforced on replay (a signature is model-bound; mismatch ⇒ drop, degrade to the lossy-but-valid pre-BA-7 request, never a 400); and normalized `content`/`tool_calls` stay the SOURCE OF TRUTH (only unexpressible blocks ride along, so an `assemble`/`trim` seam that rewrites a message isn't silently undone by a stale cached copy of its text). Adaptive thinking is ALREADY DEFAULT on sonnet-5/Opus 4.7+ (measured: blocks on ~3/10 rounds with the param OMITTED; sending `thinking:{type:'adaptive'}` changed the rate not at all) — so the opt-in `thinking` option (forwarded to `body.thinking` VERBATIM/unvalidated, since `budget_tokens` already died and a reshaping library would need a release per API move) does NOT enable thinking; it pins the mode / reaches `display`/`effort`. **PROTOCOL fix, NOT a capability fix — the adopter's head-to-head found NO outcome difference; never re-sell it as one.** + `baseUrl`. Loop returns `result.metrics` (the meter: cumulative 4-tier tokens, byTool, costUsd null-not-zero, unpricedRounds, spawned, context.{compactions,summaries,tokensTrimmed}, memory.{stashed,episodes,recalls,stored,facts}) — `estimateCost` prices the 4 tiers separately. The §3.6 CE rollup: `context.tokensTrimmed` is an APPROXIMATE (~4 chars/token) estimate over the evicted span (no exact provider count); `memory.*` is reported via the loop-lent `ctx.recordMemoryOp` hook (channel A — the originating module announces, the loop counts + emits `loop:memory`), bounded PER RUN — `stashed`/`episodes` flow through the stash fold; the Memory wrapper is metered symmetrically opt-in via ctx: `recalls` (`Memory.search` reads) + `stored` (`Memory.store` writes; ctx in a trailing opts arg, never in persisted metadata). `memory.facts` is written by `remember` (the F5 consolidation pass) via the Store socket — disjoint from `stored`; litectx's own episode→fact promotion is a separate, litectx-internal op (§3.7) +Providers: OpenAI, Anthropic, Gemini, Ollama, CLIPipe, Fallback -- each in `src/provider-*.js`. All normalize `stopReason` (BA-6) to one neutral vocabulary via `src/provider-stop-reason.js` (`end_turn`/`max_tokens`/`tool_use`/`stop_sequence`/`refusal`/`pause_turn`/`context_exceeded`; unknown-or-absent ⇒ `null` ⇒ pre-BA-6 behavior, so an unmapped provider degrades to the status quo, never to a false truncation). All 5 verified live. `tool_use` is DERIVED where the API can't express it: Gemini/Ollama return `STOP`/`stop` on a complete tool call (no tool-call finish reason), so `normalizeStopReason(raw, provider, {hasToolCalls})` promotes `end_turn`→`tool_use` when the round carried a call — narrow by design (only `end_turn`; a truncated `max_tokens` round stays truncated, preserving BA-4's refusal; never touches refusal/pause/context/passthrough). All normalize `usage` to one neutral shape incl. prompt-cache tiers (`cacheReadTokens`/`cacheCreationTokens`; `inputTokens` = uncached remainder). Gemini is native `generateContent` (its OpenAI-compat endpoint drops the cache tier). Anthropic has opt-in `cacheSystem` (cache_control on the system prompt — weak on its own: the 1024–4096-tok model-dependent cache minimum means a short persona silently never caches) + **opt-in `cacheMessages` (BA-1)** = a rolling `cache_control` breakpoint on the LAST content block of the LAST message, so a tool loop stops re-buying its whole transcript at full price every round (measured: $0.0753→$0.0110/round, 6.8× steady-state; the 1.25× write is paid once). It MUST live in the provider — the transcript ends on a `tool_result` that `_toAnthropicMessage` rebuilds, so no caller seam (`assemble` included) can reach it. Copy-on-write (never mutate the caller's array — a stale mark accumulates; Anthropic allows ≤4). Caching pays for RE-SENDING, not GROWING; a destructive `trim` fold that rewrites the PREFIX invalidates it (fold the middle, keep the head). **Provider-native block passthrough (BA-7):** `Message.providerBlocks`/`GenerateResult.providerBlocks` = `{provider, model, blocks}` — the transcript field for content blocks the normalized `{text, toolCalls}` shape CANNOT express (Anthropic `thinking`/`redacted_thinking`), which the OpenAI-shaped `Message` had nowhere to put and so silently DROPPED (the API returns 200 either way — the loss never surfaced). Anthropic echoes thinking back unchanged (signature included) on a tool-use continuation; the provider now replays them at the FRONT of the assistant turn (thinking must lead). Three constraints: OPAQUE (keep bytes, never re-serialize from parsed fields — a `redacted_thinking` block can't survive it, and a `type==='thinking'` check would silently drop the next new block type = the same bug again); the provider+model TAG is enforced on replay (a signature is model-bound; mismatch ⇒ drop, degrade to the lossy-but-valid pre-BA-7 request, never a 400); and normalized `content`/`tool_calls` stay the SOURCE OF TRUTH (only unexpressible blocks ride along, so an `assemble`/`trim` seam that rewrites a message isn't silently undone by a stale cached copy of its text). Adaptive thinking is ALREADY DEFAULT on sonnet-5/Opus 4.7+ (measured: blocks on ~3/10 rounds with the param OMITTED; sending `thinking:{type:'adaptive'}` changed the rate not at all) — so the opt-in `thinking` option (forwarded to `body.thinking` VERBATIM/unvalidated, since `budget_tokens` already died and a reshaping library would need a release per API move) does NOT enable thinking; it pins the mode / reaches `display`/`effort`. **PROTOCOL fix, NOT a capability fix — the adopter's head-to-head found NO outcome difference; never re-sell it as one.** **Request/idle timeout (BA-18):** the four http(s) providers wired only `req.on('error')` — no socket timeout — so a silently-dropped or never-answering socket hung `generate()` until the OS TCP timeout (~2h), a HANG not an error (so every retry policy above it was inert; the BA-4/5/6/13 under-modeled-boundary family, rounding toward "still working"). One shared `src/provider-http.js` (`resolveTimeoutMs`/`applyRequestTimeout`) gives each provider a `timeoutMs` option (default 600000, per-call overridable, `0`/`Infinity` disable) that bounds on socket INACTIVITY (`req.setTimeout` — a slow-but-streaming response is not killed; the 10-min default clears any single non-streaming completion where TTFB≈generation time) and on trip rejects with a retryable `TimeoutError` (`code:'ETIMEDOUT'`). The RETRY seam is caller-side and already exists — `Loop({retry})` wraps `provider.generate` with `Retry.call`, `run-plan`'s `stepRetry` is a second consumer, and `DEFAULT_RETRY_ON` classifies ETIMEDOUT transient — so a wired Retry retries a timed-out request with ZERO new wiring (the ask's "`withRetry` has zero call sites" was a name mismatch: the primitive is `Retry.call`, not `withRetry`). CLIPipe already bounded its child, unchanged. + `baseUrl`. Loop returns `result.metrics` (the meter: cumulative 4-tier tokens, byTool, costUsd null-not-zero, unpricedRounds, spawned, context.{compactions,summaries,tokensTrimmed}, memory.{stashed,episodes,recalls,stored,facts}) — `estimateCost` prices the 4 tiers separately. The §3.6 CE rollup: `context.tokensTrimmed` is an APPROXIMATE (~4 chars/token) estimate over the evicted span (no exact provider count); `memory.*` is reported via the loop-lent `ctx.recordMemoryOp` hook (channel A — the originating module announces, the loop counts + emits `loop:memory`), bounded PER RUN — `stashed`/`episodes` flow through the stash fold; the Memory wrapper is metered symmetrically opt-in via ctx: `recalls` (`Memory.search` reads) + `stored` (`Memory.store` writes; ctx in a trailing opts arg, never in persisted metadata). `memory.facts` is written by `remember` (the F5 consolidation pass) via the Store socket — disjoint from `stored`; litectx's own episode→fact promotion is a separate, litectx-internal op (§3.7) CLIPipe tool mode has TWO shapes, and the choice between them is COST, not capability. **EMULATION (v0.32.0, `src/provider-clipipe-tools.js`, `toolProtocol:'claude'`):** the caller's tools are described in the system prompt, the CLI is constrained to a JSON envelope (`--json-schema`), the envelope is parsed back into `toolCalls`, and **the Loop keeps ownership of the cycle** (round accounting, spin guards, stop-reason classification apply per round). It re-sends the whole transcript every round — right for a CLI with NO MCP channel, WRONG for the claude CLI on cost. CLI reduced to a bare brain via `--tools '' --strict-mcp-config` + `--setting-sources ''` (MEASURED ~18× cut). Loud-failure by design: a weak model answering in prose is caught UPFRONT by a capability probe (behaviour-based, mirrors real-task shape, per BA-10) → model floor (sonnet-class+ for tools); a malformed envelope is a loud `ProviderError`; tools with no `toolProtocol` stay plain-text with a one-time warn. **NATIVE (BA-16, `src/provider-clipipe-mcp.js` + `src/mcp-bridge-stub.js`, `toolProtocol:'claude-mcp'` — the default for the claude CLI):** the CLI runs its OWN multi-turn session per `generate()` and executes the caller's tools natively over a unix-socket MCP bridge that calls back into the caller's in-process closures. The CLI owns the inner cycle — so the Loop's per-round machinery cannot run and the governance moves to the PROVIDER at the `tools/call` bridge (the one seam every call crosses): the SAME `policy` chokepoint (identical audit-row shape, zero gate changes), BA-11 deny-streak + BA-12 identical-error guards (same 3/3 narrowest triggers), and the turn bound (NAMED stop `error:'max_turns'` + `stopReason:'max_turns'`, work preserved per BA-5). **A TURN IS ONE ASSISTANT MESSAGE, NOT ONE STREAM EVENT (BA-17)** — the CLI emits a separate `assistant` event per content BLOCK, each repeating that message's `usage`, so counting events inflated a caller's turn axis 5–7× (guillotining a bounded worker at half its allowance) and its token axis 5.04×; a run of consecutive events sharing `message.id` is ONE turn (adjacent-run dedup, no-id ⇒ degrade to per-event). `maxTurns` is an LLM-TURN bound — the same unit as the Loop path, never a tool-call count — enforced BOTH by the CLI's `--max-turns` (which stops cleanly and emits the cost-bearing result event) and by a parent-side counter that kills only on an OVERRUN, because the flag is undocumented; the flag itself was measured to enforce correctly and in the right unit, so the ask that reported it broken was a mis-count, not a flag defect. `onTurn` STREAMS once per TURN with all four cache tiers (never sum-at-end; a mid-run death has already surfaced its spend) then one closing `session` event carrying the authoritative cost AND the token RESIDUAL — a turn's `usage` is an unrevised first-block snapshot, so the residual is what makes a gate's tiers add up to the CLI's own total; when wired the Loop skips its own forward (billed once, never starved). **Provider owns its cycle (`Provider.ownsCycle`):** the Loop THROWS at construction on any option it could never honor — `assemble`/`trim`/`cacheMessages` and a Loop-level `policy` (which would be a fence silently not there) — no silently-dead knobs. `GenerateResult.session` + `metrics.sessionTurns` report the REAL turn/tool count in MESSAGES (a 14-turn session never reads as one round, and a 2-turn session never reads as 14); an internal terminal (bound, guard, or a **broken bridge** — a dead bridge still ends `subtype:'success'`, so it is caught parent-side by attempted-vs-served tool calls) surfaces as the run's `error`, never a laundered clean finish. **Cost is the claim (measured $0.25–0.55/round emulation vs ~$0.006/turn native); output-quality parity is deliberately UNMINTED (n=2).** Claude-only for now; both shapes isolated so a second CLI slots in behind the same seams. Stores: SQLiteStore (peer dep: better-sqlite3), JsonFileStore (zero deps) -- each in `src/store-*.js` diff --git a/bareagent.context.md b/bareagent.context.md index 422430e..538e8ae 100644 --- a/bareagent.context.md +++ b/bareagent.context.md @@ -1,7 +1,7 @@ # bareagent — Integration Guide > For AI assistants and developers wiring bareagent into a project. -> v0.33.1 | Node.js >= 18 | zero required deps (`bareguard >=0.9.0 <0.13.0` optional peer for governance) | Apache 2.0 +> v0.34.0 | Node.js >= 18 | zero required deps (`bareguard >=0.9.0 <0.13.0` optional peer for governance) | Apache 2.0 > > Full human guide with composition examples, design philosophy, and recipes: [Usage Guide](docs/02-features/usage-guide.md) @@ -829,6 +829,8 @@ All return `{ text, toolCalls, usage: { inputTokens, outputTokens }, model?, cos **Error body (v0.11.0):** on an HTTP error the OpenAI/Anthropic/Ollama providers throw a `ProviderError` whose `message` carries the upstream error string. The full parsed response is **not** attached to `err.body` by default (so an unexpected field can't leak through logs that dump the error object). Pass `{ exposeErrorBody: true }` to attach it for debugging. +**Request/idle timeout (BA-18, v0.34.0):** the four http(s) providers (Anthropic, OpenAI, Gemini, Ollama) accept a `timeoutMs` option — constructor default **600000 (10 min)**, overridable per call via `generate(..., { timeoutMs })`, and `0`/`Infinity` disables it. Before this they wired only `req.on('error')`, so a socket the server silently dropped — or a response that never starts — hung `generate()` until the OS TCP timeout (~2h): a hang, not an error, so retry/casualty policy above it never fired. `timeoutMs` bounds on socket **inactivity** (`req.setTimeout`), so a slow-but-streaming response is not killed — only a silent/never-answering socket trips it; the 10-min default clears any single non-streaming completion (TTFB ≈ generation time). On trip, `generate()` rejects with a retryable `TimeoutError` (`code: 'ETIMEDOUT'`, `retryable: true`). **Retry is caller-side and already wired:** `new Loop({ provider, retry: new Retry() })` wraps `provider.generate`, and `DEFAULT_RETRY_ON` classifies `ETIMEDOUT` (and `ECONNRESET`/`ENOTFOUND`/429/5xx) as transient — so a wired `Retry` retries a timed-out request and rethrows under `retryOn: () => false`, with no extra wiring (`run-plan`'s `stepRetry` is a second consumer of the same seam). CLIPipe already bounded its child process (`timeout`, default 30000 for one-shot) and is unchanged. + **Plaintext-key warning (Unreleased):** the OpenAI provider's `baseUrl` accepts `http://` (for local/OpenAI-compatible endpoints), but a `Bearer` key sent over plaintext http to a **non-loopback** host is exposed on the wire. The provider now warns once when that happens. Loopback hosts (`localhost`/`127.0.0.0/8`/`::1` — local proxies, Ollama-style endpoints) stay silent, since that's the legitimate keyless-local case. The header is **not** stripped (some local proxies want a key), so use `https` for any remote endpoint, or drop `apiKey` when the local endpoint needs none. **Cost estimation:** Loop automatically estimates USD cost per run based on model and token usage. The `cost` field appears in every `loop.run()` result and in `loop:done` stream events. Pricing covers OpenAI and Anthropic models; unknown models use a default average. To adjust rates, edit `COST_PER_1K` at the top of `src/loop.js`. The model is resolved as `result.model || provider.model` (v0.16.1+) — providers now echo the model in their `generate()` result, so cost accounting holds even when `provider.model` is absent or varies per response, e.g. behind `FallbackProvider` or `CircuitBreaker.wrapProvider` (the wrapper also preserves `model`/`name` passthrough props). Wire `onLlmResult` (via `wireGate`) and a `budget.maxCostUsd` cap then halts on token-heavy workloads too. diff --git a/docs/01-product/prd.md b/docs/01-product/prd.md index ca6d09f..ae46915 100644 --- a/docs/01-product/prd.md +++ b/docs/01-product/prd.md @@ -809,6 +809,40 @@ re-litigated unless the user explicitly asks. > back into this main PRD; granular evidence tables for each live in the > CHANGELOG and git history. +### v0.34.0 / provider request-idle timeout (bareloop BA-18) (2026-07-26) + +> **Numbering note.** This is **bareloop's** BA-18 (`docs/UPSTREAM-ASKS.md`), not +> a bareagent-internal BA-number — cross-repo ask numbers can collide. + +- **The defect (part 1) was real; the diagnosis (part 2) was a name mismatch.** + The ask filed two parts: (1) `AnthropicProvider` sets no request/idle timeout, + and (2) "`withRetry` has zero call sites." Grounding both in source before + building (the standing BA-2/BA-17 discipline): (1) **confirmed** — `_request` + wired only `req.on('error')`, no `timeout`/`setTimeout`/`AbortSignal`, so a + hung socket was bounded only by the OS TCP timeout (~2h). (2) **misnamed** — + there is no `withRetry`; the primitive is `Retry.call`, and it IS wired around + `provider.generate` (`Loop({retry})`, plus `run-plan`'s `stepRetry`), with + `DEFAULT_RETRY_ON` already classifying `ETIMEDOUT` transient. So part 2 needs + no code — a test + docs prove the seam reaches the table. +- **Scope: all four http(s) providers, not just Anthropic** (user decision). The + same no-timeout `_request` shape existed in OpenAI/Gemini/Ollama; fixing only + Anthropic would leave three siblings with the identical hang (the + fix-one-sibling footgun). Implemented once in `src/provider-http.js` + (`resolveTimeoutMs`/`applyRequestTimeout`), wired at each `_request`. CLIPipe + already bounded its child, untouched. +- **Idle semantics, finite default 600000ms (user decision).** Bounds on socket + INACTIVITY (`req.setTimeout`), so a slow-but-streaming response is not killed — + only a silent/never-answering socket trips. Because these requests are + non-streaming (TTFB ≈ generation time), the default must clear the longest + legit completion; 10 min sits above that and well below the OS ceiling. `0`/ + `Infinity` disable (byte-identical pre-BA-18 behaviour). On trip: a retryable + `TimeoutError` (`code:'ETIMEDOUT'`) so a wired `Retry` picks it up. +- **Same BA-4/5/6/13/17 family** — an under-modeled boundary (a hung socket has + no slot in the neutral result shape) rounding optimistically toward + "still working." The loopback-server tests reproduce the transport-layer + failure faithfully (a socket that accepts but never responds) and were + mutation-proven, incl. a guard-OFF negative control that reproduces the hang. + ### v0.33.1 / CLIPipe native turn-unit fix (bareloop BA-17) (2026-07-22) > **Numbering note.** This is **bareloop's** BA-17 (`docs/UPSTREAM-ASKS.md`), diff --git a/docs/02-features/errors.md b/docs/02-features/errors.md index e2f0302..7635a47 100644 --- a/docs/02-features/errors.md +++ b/docs/02-features/errors.md @@ -117,9 +117,12 @@ The circuit breaker tracks failures per key. After `threshold` failures, calls a | Error | When | Fix | |-------|------|-----| | `[Retry] Timeout` (`TimeoutError`) | A single attempt exceeded the configured `timeout` (default 60s) | Increase `timeout` in constructor or per-call options. `instanceof TimeoutError`, `code: 'ETIMEDOUT'`, `retryable: true` | +| `[] request timed out after Nms of socket inactivity` (`TimeoutError`, BA-18) | An http(s) provider's socket went idle past its `timeoutMs` (default 600000; a silently-dropped or never-answering socket). Applies to Anthropic/OpenAI/Gemini/Ollama. | Expected on a dead/hung connection — it's now an error instead of a ~2h hang. `code: 'ETIMEDOUT'`, `retryable: true`. Tune per provider via `timeoutMs` (`0`/`Infinity` disables); wrap the Loop in `Retry` to auto-retry it. | **Note:** After exhausting `maxAttempts`, Retry rethrows the last error from the wrapped function — it does not add its own prefix. Errors with `err.retryable === true` are automatically retried; `err.retryable === false` bail immediately without consuming remaining attempts. +**Provider request timeout + Retry (BA-18).** The Loop wires `Retry` around `provider.generate` — `new Loop({ provider, retry: new Retry() })` — and the default retry predicate (`DEFAULT_RETRY_ON`) classifies `ETIMEDOUT`/`ECONNRESET`/`ENOTFOUND`/429/5xx as transient. So a provider request that times out (or drops its socket) is retried automatically under a wired `Retry`, and rethrows under `retryOn: () => false`. `run-plan`'s `stepRetry` is the same seam at the step level. Using a provider **without** a Loop? Its own `timeoutMs` still bounds the hang — you just handle the rejection yourself. + ## CLIPipeProvider | Error | When | Fix | diff --git a/package-lock.json b/package-lock.json index c22229a..d0a0a55 100644 --- a/package-lock.json +++ b/package-lock.json @@ -1,12 +1,12 @@ { "name": "bare-agent", - "version": "0.33.1", + "version": "0.34.0", "lockfileVersion": 3, "requires": true, "packages": { "": { "name": "bare-agent", - "version": "0.33.1", + "version": "0.34.0", "license": "Apache-2.0", "bin": { "bare-agent": "bin/cli.js" diff --git a/package.json b/package.json index 8ffbd54..a0a20f9 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "bare-agent", - "version": "0.33.1", + "version": "0.34.0", "files": [ "index.js", "index.d.ts", diff --git a/poc/ba18-timeout.mjs b/poc/ba18-timeout.mjs new file mode 100644 index 0000000..4597181 --- /dev/null +++ b/poc/ba18-timeout.mjs @@ -0,0 +1,132 @@ +// POC for BA-18: prove an idle-socket timeout on an Anthropic-shaped _request. +// Riskiest assumption: req.setTimeout(ms) + req.destroy(err) rejects with our +// error carrying code:'ETIMEDOUT' within the window, AND a fast response does +// NOT trip it. Proven against REAL local http servers (must be able to fail). +import http from 'node:http'; + +// A faithful copy of provider-anthropic.js:_request WITH the proposed timeout added. +function requestWithTimeout(baseUrl, body, timeoutMs) { + return new Promise((resolve, reject) => { + const payload = JSON.stringify(body); + const url = new URL(baseUrl + '/messages'); + const req = http.request(url, { + method: 'POST', + headers: { 'Content-Type': 'application/json', 'Content-Length': Buffer.byteLength(payload) }, + }, (res) => { + let chunks = ''; + res.on('data', d => chunks += d); + res.on('end', () => { + try { resolve(JSON.parse(chunks)); } + catch (e) { reject(new Error('bad json')); } + }); + }); + if (timeoutMs > 0) { + req.setTimeout(timeoutMs, () => { + const err = new Error(`request timed out after ${timeoutMs}ms`); + err.code = 'ETIMEDOUT'; + err.retryable = true; + req.destroy(err); + }); + } + req.on('error', reject); + req.write(payload); + req.end(); + }); +} + +function server(handler) { + return new Promise((resolve) => { + const s = http.createServer(handler); + s.listen(0, '127.0.0.1', () => resolve(s)); + }); +} +const baseOf = (s) => `http://127.0.0.1:${s.address().port}`; + +let pass = 0, fail = 0; +const ok = (c, m) => { if (c) { pass++; console.log(' PASS', m); } else { fail++; console.log(' FAIL', m); } }; + +// ---- Case A: server accepts but NEVER responds → must reject ~timeout with ETIMEDOUT +{ + const held = []; + const s = await server((req, res) => { held.push(res); /* never respond */ }); + const t0 = Date.now(); + let err; + try { await requestWithTimeout(baseOf(s), { model: 'x', messages: [] }, 100); } + catch (e) { err = e; } + const dt = Date.now() - t0; + console.log(`Case A (never responds): rejected after ${dt}ms, code=${err?.code}`); + ok(!!err, 'A: generate rejected (did not hang)'); + ok(err?.code === 'ETIMEDOUT', 'A: error carries code ETIMEDOUT'); + ok(err?.retryable === true, 'A: error is retryable (Retry picks it up)'); + ok(dt >= 90 && dt < 500, `A: rejected within ~100ms window (was ${dt}ms)`); + held.forEach(r => { try { r.destroy(); } catch {} }); + s.close(); +} + +// ---- Case B: server responds IMMEDIATELY (within window) → must NOT reject +{ + const s = await server((req, res) => { + res.writeHead(200, { 'Content-Type': 'application/json' }); + res.end(JSON.stringify({ content: [{ type: 'text', text: 'hi' }], stop_reason: 'end_turn' })); + }); + let result, err; + try { result = await requestWithTimeout(baseOf(s), { model: 'x', messages: [] }, 100); } + catch (e) { err = e; } + console.log(`Case B (fast response): err=${err?.code || 'none'}, text=${result?.content?.[0]?.text}`); + ok(!err, 'B: fast response did NOT trip the timeout'); + ok(result?.content?.[0]?.text === 'hi', 'B: got the real response body'); + s.close(); +} + +// ---- Case C: negative control — response arrives at ~250ms, timeout 100ms → rejects (correct) +// Proves the timer actually measures idleness, not a no-op that always resolves. +{ + const s = await server((req, res) => { + setTimeout(() => { + res.writeHead(200, { 'Content-Type': 'application/json' }); + res.end(JSON.stringify({ content: [{ type: 'text', text: 'late' }] })); + }, 250); + }); + let result, err; + try { result = await requestWithTimeout(baseOf(s), { model: 'x', messages: [] }, 100); } + catch (e) { err = e; } + console.log(`Case C (slow=250ms, timeout=100ms): err=${err?.code || 'none'}`); + ok(err?.code === 'ETIMEDOUT', 'C: a response outside the window is a timeout (timer is real)'); + s.close(); +} + +// ---- Case D: same slow server, but a GENEROUS timeout → succeeds (timer resets on activity / long enough) +{ + const s = await server((req, res) => { + setTimeout(() => { + res.writeHead(200, { 'Content-Type': 'application/json' }); + res.end(JSON.stringify({ content: [{ type: 'text', text: 'late-ok' }] })); + }, 250); + }); + let result, err; + try { result = await requestWithTimeout(baseOf(s), { model: 'x', messages: [] }, 2000); } + catch (e) { err = e; } + console.log(`Case D (slow=250ms, timeout=2000ms): err=${err?.code || 'none'}, text=${result?.content?.[0]?.text}`); + ok(!err && result?.content?.[0]?.text === 'late-ok', 'D: a generous timeout lets a slow-but-working response through'); + s.close(); +} + +// ---- Case E: timeout disabled (0) against never-responds, bounded by our own outer race → confirms 0 = no provider timeout +{ + const held = []; + const s = await server((req, res) => { held.push(res); }); + let timedOutByUs = false, err; + try { + await Promise.race([ + requestWithTimeout(baseOf(s), { model: 'x', messages: [] }, 0), + new Promise((_, rej) => setTimeout(() => { timedOutByUs = true; rej(new Error('outer')); }, 400)), + ]); + } catch (e) { err = e; } + console.log(`Case E (timeout=0): outer race fired=${timedOutByUs}`); + ok(timedOutByUs, 'E: timeoutMs:0 disables the provider timeout (hangs until an outer bound) — back-compat'); + held.forEach(r => { try { r.destroy(); } catch {} }); + s.close(); +} + +console.log(`\n${pass} passed, ${fail} failed`); +process.exit(fail ? 1 : 0); diff --git a/poc/ba18-verify-shipped.mjs b/poc/ba18-verify-shipped.mjs new file mode 100644 index 0000000..a523140 --- /dev/null +++ b/poc/ba18-verify-shipped.mjs @@ -0,0 +1,39 @@ +// BA-18 live verify-shipped — proves the request timeout on the REAL https wire (the unit tests +// use loopback http; https adds a TLS handshake worth confirming the idle timer survives). +// Run: ANTHROPIC_API_KEY=... node poc/ba18-verify-shipped.mjs +// (Do NOT hardcode a key. Ask the user to run with the key, or `!ANTHROPIC_API_KEY=$(pass ...) node ...`.) +import { AnthropicProvider } from '../src/provider-anthropic.js'; + +const key = process.env.ANTHROPIC_API_KEY; +if (!key) { console.error('set ANTHROPIC_API_KEY'); process.exit(2); } + +const MSGS = [{ role: 'user', content: 'Say the single word: ok' }]; +let pass = 0, fail = 0; +const ok = (c, m) => { if (c) { pass++; console.log(' PASS', m); } else { fail++; console.log(' FAIL', m); } }; + +// Case 1: default (10 min) timeout → a real completion returns normally (no false trip). +{ + const p = new AnthropicProvider({ apiKey: key, model: 'claude-haiku-4-5-20251001' }); + const t0 = Date.now(); + let r, err; + try { r = await p.generate(MSGS, [], { maxTokens: 16 }); } catch (e) { err = e; } + console.log(`Case 1 (default timeout): ${Date.now() - t0}ms, text=${JSON.stringify(r?.text)}, err=${err?.code || 'none'}`); + ok(!err && typeof r?.text === 'string' && r.text.length > 0, 'a real completion succeeds under the default timeout (no false trip)'); +} + +// Case 2: an aggressively short timeout → the real https request trips ETIMEDOUT before the model +// can answer (a real generation is always > 100ms). Proves the idle timer works over TLS. +{ + const p = new AnthropicProvider({ apiKey: key, model: 'claude-haiku-4-5-20251001', timeoutMs: 100 }); + const t0 = Date.now(); + let r, err; + try { r = await p.generate(MSGS, [], { maxTokens: 512 }); } catch (e) { err = e; } + const dt = Date.now() - t0; + console.log(`Case 2 (timeoutMs:100): ${dt}ms, err=${err?.code || 'none'}, retryable=${err?.retryable}`); + ok(err?.code === 'ETIMEDOUT', 'a 100ms bound trips ETIMEDOUT on the real https wire'); + ok(err?.retryable === true, 'the timeout error is retryable (a wired Retry would pick it up)'); + ok(dt < 5000, `rejected promptly on the bound, not an OS-timeout hang (was ${dt}ms)`); +} + +console.log(`\n${pass} passed, ${fail} failed`); +process.exit(fail ? 1 : 0); diff --git a/src/provider-anthropic.js b/src/provider-anthropic.js index fdfe97f..5338022 100644 --- a/src/provider-anthropic.js +++ b/src/provider-anthropic.js @@ -5,6 +5,7 @@ const http = require('http'); const { ProviderError } = require('./errors'); const { requestWithTemperatureFallback } = require('./provider-temperature'); const { normalizeStopReason } = require('./provider-stop-reason'); +const { resolveTimeoutMs, applyRequestTimeout } = require('./provider-http'); /** @param {string} hostname @returns {boolean} */ function isLoopbackHost(hostname) { @@ -27,6 +28,7 @@ function isLoopbackHost(hostname) { * * **MEASURED CAVEAT — this option does not "turn thinking on".** On `claude-sonnet-5` adaptive thinking is ALREADY the default: sending this changed the observed thinking rate not at all (2/10 rounds with it vs 3/10 without — `poc/ba7-adaptive-default.mjs`). Its real use is pinning the mode and reaching `display`/`effort`. The change that mattered is that thinking blocks are now PRESERVED and replayed (see `Message.providerBlocks`), which happens whether or not you ever set this. * @property {boolean} [exposeErrorBody=false] - Attach the full upstream response to `err.body` on HTTP errors (off by default to avoid leaking unexpected fields through error logs; `err.message` still carries the API error). + * @property {number} [timeoutMs=600000] - BA-18: request/idle timeout in ms. A silent or never-answering socket (dropped by the server, or a response that never starts) was otherwise bounded only by the OS TCP timeout (~2h) — a hang, not an error, so every retry policy above it was inert. Bounds on socket INACTIVITY (the timer resets on activity, so a slow-but-streaming response is not killed); on trip, `generate()` rejects with a retryable `TimeoutError` (`code: 'ETIMEDOUT'`) that a wired `Retry` (`Loop({ retry })`) retries. Default 10 min sits above any single non-streaming completion; `0` or `Infinity` disables it (pre-BA-18 behaviour). Overridable per call via `generate(..., { timeoutMs })`. */ class AnthropicProvider { @@ -52,13 +54,15 @@ class AnthropicProvider { this.thinking = options.thinking != null ? options.thinking : null; // See OpenAIProvider: attach full upstream body to err.body only on opt-in. this.exposeErrorBody = options.exposeErrorBody === true; + // BA-18: request/idle timeout (ms). Resolved at call time (default 600000; 0/Infinity disable). + this.timeoutMs = options.timeoutMs; } /** * Generate a response from the Anthropic API. * @param {Message[]} messages - Conversation messages (OpenAI format, auto-converted). * @param {ToolDef[]} [tools=[]] - Tool definitions. - * @param {Record} [options={}] - Options (temperature, maxTokens, system). + * @param {Record} [options={}] - Options (temperature, maxTokens, system, timeoutMs — a per-call override of the constructor's `timeoutMs`; see BA-18). * @returns {Promise} * @throws {Error} `[AnthropicProvider] ...` — on HTTP errors (4xx/5xx) or invalid JSON response. */ @@ -142,8 +146,9 @@ class AnthropicProvider { // BA-10: some models (e.g. claude-sonnet-5) reject a non-default `temperature` with a 400 — drop it // and retry once rather than let the whole call fail. `temperatureDropped` flows back so an upstream // receipt (recurse's refineLeaf) can report the effective temperature, not the one the model ignored. + const timeoutMs = resolveTimeoutMs(this.timeoutMs, options.timeoutMs); const { data, temperatureDropped } = await requestWithTemperatureFallback({ - request: () => this._request(body), + request: () => this._request(body, timeoutMs), hadTemperature: () => body.temperature != null, stripTemperature: () => { delete body.temperature; }, warnOnce: () => this._warnTemperatureDropped(), @@ -275,9 +280,10 @@ class AnthropicProvider { /** * @param {Record} body + * @param {number} [timeoutMs=0] - Idle-socket timeout (ms); 0 disables. See BA-18 / provider-http. * @returns {Promise} */ - _request(body) { + _request(body, timeoutMs = 0) { return new Promise((resolve, reject) => { const payload = JSON.stringify(body); const url = new URL(this.baseUrl + '/messages'); @@ -314,6 +320,7 @@ class AnthropicProvider { } }); }); + applyRequestTimeout(req, timeoutMs, 'AnthropicProvider'); req.on('error', reject); req.write(payload); req.end(); diff --git a/src/provider-gemini.js b/src/provider-gemini.js index 81c6d45..8648c54 100644 --- a/src/provider-gemini.js +++ b/src/provider-gemini.js @@ -5,6 +5,7 @@ const http = require('http'); const { ProviderError } = require('./errors'); const { requestWithTemperatureFallback } = require('./provider-temperature'); const { normalizeStopReason } = require('./provider-stop-reason'); +const { resolveTimeoutMs, applyRequestTimeout } = require('./provider-http'); /** @typedef {import('../types').Message} Message */ /** @typedef {import('../types').ToolDef} ToolDef */ @@ -23,6 +24,7 @@ function isLoopbackHost(hostname) { * @property {string} [model='gemini-2.5-flash'] - Model ID. * @property {string} [baseUrl='https://generativelanguage.googleapis.com/v1beta'] - API base (override for proxies; posts to `${baseUrl}/models/${model}:generateContent`). * @property {boolean} [exposeErrorBody=false] - Attach the full upstream response to `err.body` on HTTP errors (off by default; `err.message` still carries the API error). + * @property {number} [timeoutMs=600000] - BA-18: request/idle timeout in ms. Bounds a silent or never-answering socket on inactivity so `generate()` rejects with a retryable `TimeoutError` (`code: 'ETIMEDOUT'`) instead of hanging until the OS TCP timeout (~2h). `0`/`Infinity` disables it (pre-BA-18 behaviour). Overridable per call via `generate(..., { timeoutMs })`. */ /** @@ -39,13 +41,15 @@ class GeminiProvider { this.model = options.model || 'gemini-2.5-flash'; this.baseUrl = options.baseUrl || 'https://generativelanguage.googleapis.com/v1beta'; this.exposeErrorBody = options.exposeErrorBody === true; + // BA-18: request/idle timeout (ms). Resolved at call time (default 600000; 0/Infinity disable). + this.timeoutMs = options.timeoutMs; } /** * Generate a response from the Gemini API. * @param {Message[]} messages - Conversation messages (OpenAI format, auto-converted). * @param {ToolDef[]} [tools=[]] - Tool definitions. - * @param {Record} [options={}] - Options (temperature, maxTokens). + * @param {Record} [options={}] - Options (temperature, maxTokens, timeoutMs — a per-call override of the constructor's `timeoutMs`; see BA-18). * @returns {Promise} * @throws {Error} `[GeminiProvider] ...` — on HTTP errors (4xx/5xx) or invalid JSON response. */ @@ -107,8 +111,9 @@ class GeminiProvider { // BA-10: graceful degrade if a model rejects a non-default `temperature` (Gemini nests it under // generationConfig). Keyed off the API error text, so dormant on models that accept temperature. + const timeoutMs = resolveTimeoutMs(this.timeoutMs, options.timeoutMs); const { data, temperatureDropped } = await requestWithTemperatureFallback({ - request: () => this._request(`/models/${this.model}:generateContent`, body), + request: () => this._request(`/models/${this.model}:generateContent`, body, timeoutMs), hadTemperature: () => body.generationConfig?.temperature != null, stripTemperature: () => { if (body.generationConfig) delete body.generationConfig.temperature; }, warnOnce: () => this._warnTemperatureDropped(), @@ -174,9 +179,10 @@ class GeminiProvider { /** * @param {string} path * @param {Record} body + * @param {number} [timeoutMs=0] - Idle-socket timeout (ms); 0 disables. See BA-18 / provider-http. * @returns {Promise} */ - _request(path, body) { + _request(path, body, timeoutMs = 0) { return new Promise((resolve, reject) => { const url = new URL(this.baseUrl + path); const transport = url.protocol === 'https:' ? https : http; @@ -213,6 +219,7 @@ class GeminiProvider { } }); }); + applyRequestTimeout(req, timeoutMs, 'GeminiProvider'); req.on('error', reject); req.write(payload); req.end(); diff --git a/src/provider-http.js b/src/provider-http.js new file mode 100644 index 0000000..15dae75 --- /dev/null +++ b/src/provider-http.js @@ -0,0 +1,59 @@ +'use strict'; + +const { TimeoutError } = require('./errors'); + +/** + * BA-18 — shared request-timeout helper for the http(s)-based providers (Anthropic, OpenAI, + * Gemini, Ollama). They all build a `http.ClientRequest` with only `req.on('error')` wired, so a + * socket the server silently dropped — or a response that never starts — was bounded only by the + * OS TCP timeout (~2h on Linux). That presents to the caller as a hang, not a failure, so every + * retry/casualty policy above it is inert. This adds a finite, configurable idle bound in one + * place so the four providers cannot drift. + */ + +// 10 minutes: safely above any single non-streaming completion (a big reasoning response is a few +// minutes at most), well below the ~2h OS TCP default. These requests are non-streaming, so a legit +// slow completion can have no socket activity until the whole body arrives (TTFB ≈ generation time) +// — the default must clear that, not a typical round-trip. +const DEFAULT_TIMEOUT_MS = 600000; + +/** + * Resolve the effective timeout in ms. A per-call value overrides the instance default, but `null` + * and `undefined` BOTH mean "inherit" — so a per-call `null` never shadows an instance-level + * disable (finding-2). The explicit opt-out idiom is `0` or `Infinity` → returns 0 (no bound, the + * pre-BA-18 behaviour). A NaN / negative / otherwise non-finite value is treated as a caller + * MISTAKE and falls back to {@link DEFAULT_TIMEOUT_MS}: it must never silently disable the safety + * bound, which would round optimistically back toward the ~2h hang BA-18 exists to prevent + * (finding-3; the disable-edge bug class). + * @param {number|undefined|null} instanceTimeout + * @param {number|undefined|null} [callTimeout] + * @returns {number} a finite positive ms bound, or 0 to disable + */ +function resolveTimeoutMs(instanceTimeout, callTimeout) { + const raw = callTimeout != null ? callTimeout : instanceTimeout; // null/undefined per-call → inherit + if (raw == null) return DEFAULT_TIMEOUT_MS; // absent on both → finite default + const n = Number(raw); + if (n === 0 || n === Infinity) return 0; // the explicit opt-out idiom → no bound + if (!Number.isFinite(n) || n < 0) return DEFAULT_TIMEOUT_MS; // NaN / negative / garbage → SAFE default, never a silent disable + return n; // finite positive bound +} + +/** + * Bound an in-flight ClientRequest on socket INACTIVITY. On timeout, destroy the request with a + * retryable {@link TimeoutError} (`code: 'ETIMEDOUT'`) — `DEFAULT_RETRY_ON` classifies that as + * transient, and the provider's own `req.on('error', reject)` turns it into a rejected promise, so + * the caller regains control instead of hanging. Idle semantics (via `req.setTimeout`): the timer + * resets on any socket activity, so a slow-but-streaming response is NOT killed — only a silent or + * never-answering socket trips it. A `timeoutMs` of 0 is a no-op (bound disabled). + * @param {import('http').ClientRequest} req + * @param {number} timeoutMs - resolved bound; 0 disables + * @param {string} providerName - for the error message (e.g. 'AnthropicProvider') + */ +function applyRequestTimeout(req, timeoutMs, providerName) { + if (!(timeoutMs > 0)) return; + req.setTimeout(timeoutMs, () => { + req.destroy(new TimeoutError(`[${providerName}] request timed out after ${timeoutMs}ms of socket inactivity`)); + }); +} + +module.exports = { DEFAULT_TIMEOUT_MS, resolveTimeoutMs, applyRequestTimeout }; diff --git a/src/provider-ollama.js b/src/provider-ollama.js index 36c39c2..19a2049 100644 --- a/src/provider-ollama.js +++ b/src/provider-ollama.js @@ -4,6 +4,7 @@ const http = require('http'); const { ProviderError } = require('./errors'); const { requestWithTemperatureFallback } = require('./provider-temperature'); const { normalizeStopReason } = require('./provider-stop-reason'); +const { resolveTimeoutMs, applyRequestTimeout } = require('./provider-http'); /** @typedef {import('../types').Message} Message */ /** @typedef {import('../types').ToolDef} ToolDef */ @@ -14,6 +15,7 @@ const { normalizeStopReason } = require('./provider-stop-reason'); * @property {string} [model='llama3.2'] * @property {string} [url='http://localhost:11434'] * @property {boolean} [exposeErrorBody=false] + * @property {number} [timeoutMs=600000] - BA-18: request/idle timeout in ms. Bounds a silent or never-answering socket on inactivity so `generate()` rejects with a retryable `TimeoutError` (`code: 'ETIMEDOUT'`) instead of hanging until the OS TCP timeout. `0`/`Infinity` disables it. Overridable per call via `generate(..., { timeoutMs })`. (A local Ollama that is loading a large model cold can be slow to first byte — raise this or disable it for very large local models.) */ class OllamaProvider { @@ -25,13 +27,15 @@ class OllamaProvider { this.url = options.url || 'http://localhost:11434'; // See OpenAIProvider: attach full upstream body to err.body only on opt-in. this.exposeErrorBody = options.exposeErrorBody === true; + // BA-18: request/idle timeout (ms). Resolved at call time (default 600000; 0/Infinity disable). + this.timeoutMs = options.timeoutMs; } /** * Generate a response from a local Ollama instance. * @param {Message[]} messages - Conversation messages. * @param {ToolDef[]} [tools=[]] - Tool definitions. - * @param {Record} [options={}] - Options (`temperature`, `maxTokens`). + * @param {Record} [options={}] - Options (`temperature`, `maxTokens`, `timeoutMs` — a per-call override of the constructor's `timeoutMs`; see BA-18). * @returns {Promise} * @throws {Error} `[OllamaProvider] ...` — on HTTP errors or invalid JSON response. */ @@ -64,8 +68,9 @@ class OllamaProvider { // BA-10: graceful degrade if a model rejects a non-default `temperature` (Ollama nests it under // `options`). Keyed off the API error text, so dormant on models that accept temperature. + const timeoutMs = resolveTimeoutMs(this.timeoutMs, options.timeoutMs); const { data, temperatureDropped } = await requestWithTemperatureFallback({ - request: () => this._request('/api/chat', body), + request: () => this._request('/api/chat', body, timeoutMs), hadTemperature: () => body.options?.temperature != null, stripTemperature: () => { if (body.options) delete body.options.temperature; }, warnOnce: () => this._warnTemperatureDropped(), @@ -110,9 +115,10 @@ class OllamaProvider { /** * @param {string} path * @param {Record} body + * @param {number} [timeoutMs=0] - Idle-socket timeout (ms); 0 disables. See BA-18 / provider-http. * @returns {Promise} */ - _request(path, body) { + _request(path, body, timeoutMs = 0) { return new Promise((resolve, reject) => { const url = new URL(this.url + path); const payload = JSON.stringify(body); @@ -141,6 +147,7 @@ class OllamaProvider { } }); }); + applyRequestTimeout(req, timeoutMs, 'OllamaProvider'); req.on('error', reject); req.write(payload); req.end(); diff --git a/src/provider-openai.js b/src/provider-openai.js index 04fc587..7b802aa 100644 --- a/src/provider-openai.js +++ b/src/provider-openai.js @@ -5,6 +5,7 @@ const http = require('http'); const { ProviderError } = require('./errors'); const { requestWithTemperatureFallback } = require('./provider-temperature'); const { normalizeStopReason } = require('./provider-stop-reason'); +const { resolveTimeoutMs, applyRequestTimeout } = require('./provider-http'); /** @typedef {import('../types').Message} Message */ /** @typedef {import('../types').ToolDef} ToolDef */ @@ -27,6 +28,10 @@ function isLoopbackHost(hostname) { * field in an error payload can't leak through logs that dump the error * object; `err.message` still carries the API's error message. Turn on for * debugging only. + * @property {number} [timeoutMs=600000] - BA-18: request/idle timeout in ms. Bounds a silent or + * never-answering socket on inactivity so `generate()` rejects with a retryable `TimeoutError` + * (`code: 'ETIMEDOUT'`) instead of hanging until the OS TCP timeout (~2h). `0`/`Infinity` + * disables it (pre-BA-18 behaviour). Overridable per call via `generate(..., { timeoutMs })`. */ class OpenAIProvider { @@ -38,13 +43,15 @@ class OpenAIProvider { this.model = options.model || 'gpt-4o-mini'; this.baseUrl = options.baseUrl || 'https://api.openai.com/v1'; this.exposeErrorBody = options.exposeErrorBody === true; + // BA-18: request/idle timeout (ms). Resolved at call time (default 600000; 0/Infinity disable). + this.timeoutMs = options.timeoutMs; } /** * Generate a response from the OpenAI API. * @param {Message[]} messages - Conversation messages. * @param {ToolDef[]} [tools=[]] - Tool definitions. - * @param {Record} [options={}] - Options (temperature, maxTokens). + * @param {Record} [options={}] - Options (temperature, maxTokens, timeoutMs — a per-call override of the constructor's `timeoutMs`; see BA-18). * @returns {Promise} * @throws {Error} `[OpenAIProvider] ...` — on HTTP errors (4xx/5xx) or invalid JSON response. */ @@ -65,8 +72,9 @@ class OpenAIProvider { // BA-10: newer models (o1/gpt-5-class) reject a non-default `temperature` with a 400 — drop it and // retry once. `temperatureDropped` flows back so an upstream receipt can report the effective value. + const timeoutMs = resolveTimeoutMs(this.timeoutMs, options.timeoutMs); const { data, temperatureDropped } = await requestWithTemperatureFallback({ - request: () => this._request('/chat/completions', body), + request: () => this._request('/chat/completions', body, timeoutMs), hadTemperature: () => body.temperature != null, stripTemperature: () => { delete body.temperature; }, warnOnce: () => this._warnTemperatureDropped(), @@ -124,9 +132,10 @@ class OpenAIProvider { /** * @param {string} path * @param {Record} body + * @param {number} [timeoutMs=0] - Idle-socket timeout (ms); 0 disables. See BA-18 / provider-http. * @returns {Promise} */ - _request(path, body) { + _request(path, body, timeoutMs = 0) { return new Promise((resolve, reject) => { const url = new URL(this.baseUrl + path); const transport = url.protocol === 'https:' ? https : http; @@ -168,6 +177,7 @@ class OpenAIProvider { } }); }); + applyRequestTimeout(req, timeoutMs, 'OpenAIProvider'); req.on('error', reject); req.write(payload); req.end(); diff --git a/test/mcp-bridge.test.js b/test/mcp-bridge.test.js index 82d3e9b..c1089db 100644 --- a/test/mcp-bridge.test.js +++ b/test/mcp-bridge.test.js @@ -439,7 +439,12 @@ describe('createMCPBridge', () => { }); const leakBridge = join(TMP, '.leak-bridge.json'); try { - const bridge = await createMCPBridge({ configPaths: [slowConfig], bridgePath: leakBridge, timeout: 300 }); + // The connect timeout must clear node's cold-start (the child records its pid witness at + // module load, and on a slow host that spawn can take ~400-500ms) yet stay far below the + // child's 10000ms MOCK_SLOW_INIT, so the server still fails to connect. A tighter bound + // (e.g. 300ms) races the child's startup: it gets SIGKILLed before it writes its pid, and + // the assertion below reads a file that was never created (ENOENT) rather than testing reaping. + const bridge = await createMCPBridge({ configPaths: [slowConfig], bridgePath: leakBridge, timeout: 2000 }); assert.equal(bridge.servers.length, 0, 'slow server should fail to connect'); await bridge.close(); diff --git a/test/provider-timeout.test.js b/test/provider-timeout.test.js new file mode 100644 index 0000000..fe38c03 --- /dev/null +++ b/test/provider-timeout.test.js @@ -0,0 +1,216 @@ +'use strict'; + +// BA-18 — a request/idle timeout on the http(s) providers, and proof the Retry seam reaches the +// transient table. Before this, a socket the server silently dropped (or a response that never +// starts) hung generate() until the OS TCP timeout (~2h): a hang, not an error, so every retry +// policy above it was inert. These tests must be able to FAIL — they drive real loopback servers. + +const { describe, it, before, after } = require('node:test'); +const assert = require('node:assert/strict'); +const http = require('node:http'); + +const { AnthropicProvider } = require('../src/provider-anthropic'); +const { OpenAIProvider } = require('../src/provider-openai'); +const { GeminiProvider } = require('../src/provider-gemini'); +const { OllamaProvider } = require('../src/provider-ollama'); +const { resolveTimeoutMs, applyRequestTimeout, DEFAULT_TIMEOUT_MS } = require('../src/provider-http'); +const { Retry } = require('../src/retry'); +const { TimeoutError } = require('../src/errors'); + +// A server that accepts the connection and NEVER responds — the exact BA-18 failure shape. +function silentServer() { + /** @type {import('http').ServerResponse[]} */ + const held = []; + const server = http.createServer((req, res) => { held.push(res); /* never end */ }); + return new Promise((resolve) => + server.listen(0, '127.0.0.1', () => + resolve({ server, held, url: `http://127.0.0.1:${server.address().port}` }))); +} + +// A server that responds after `delayMs` with a canned 200 JSON body (per-provider shapes below). +function slowServer(delayMs, body) { + const server = http.createServer((req, res) => { + setTimeout(() => { + res.writeHead(200, { 'Content-Type': 'application/json' }); + res.end(JSON.stringify(body)); + }, delayMs); + }); + return new Promise((resolve) => + server.listen(0, '127.0.0.1', () => + resolve({ server, url: `http://127.0.0.1:${server.address().port}` }))); +} + +function closeSilent(s) { + s.held.forEach(r => { try { r.socket.destroy(); } catch { /* noop */ } }); + s.server.close(); +} + +// Minimal valid 200 bodies per provider so the happy path parses. +const ANTHROPIC_OK = { content: [{ type: 'text', text: 'hi' }], stop_reason: 'end_turn', usage: { input_tokens: 1, output_tokens: 1 } }; +const OPENAI_OK = { choices: [{ message: { content: 'hi', role: 'assistant' }, finish_reason: 'stop' }], usage: { prompt_tokens: 1, completion_tokens: 1 } }; +const GEMINI_OK = { candidates: [{ content: { parts: [{ text: 'hi' }] }, finishReason: 'STOP' }], usageMetadata: { promptTokenCount: 1, candidatesTokenCount: 1 } }; +const OLLAMA_OK = { message: { content: 'hi', role: 'assistant' }, done: true, done_reason: 'stop', prompt_eval_count: 1, eval_count: 1 }; + +const MSGS = [{ role: 'user', content: 'hi' }]; + +// Build each provider pointed at a loopback url, with a short timeout, in one place so the four +// stay symmetric (Ollama takes `url`, the rest take `baseUrl`). +function makeProvider(kind, url, timeoutMs) { + if (kind === 'Anthropic') return new AnthropicProvider({ apiKey: 'x', baseUrl: url, timeoutMs }); + if (kind === 'OpenAI') return new OpenAIProvider({ apiKey: 'x', baseUrl: url, timeoutMs }); + if (kind === 'Gemini') return new GeminiProvider({ apiKey: 'x', baseUrl: url, timeoutMs }); + if (kind === 'Ollama') return new OllamaProvider({ url, timeoutMs }); + throw new Error('unknown kind ' + kind); +} +const OK_BODY = { Anthropic: ANTHROPIC_OK, OpenAI: OPENAI_OK, Gemini: GEMINI_OK, Ollama: OLLAMA_OK }; + +describe('BA-18: a hung socket trips the provider timeout (all four http providers)', () => { + for (const kind of ['Anthropic', 'OpenAI', 'Gemini', 'Ollama']) { + it(`${kind}: a never-answering socket rejects with ETIMEDOUT, not a hang`, async () => { + const s = await silentServer(); + const p = makeProvider(kind, s.url, 120); + const t0 = Date.now(); + let err; + try { await p.generate(MSGS, []); } + catch (e) { err = e; } + const dt = Date.now() - t0; + closeSilent(s); + assert.ok(err, `${kind}: generate must reject, not hang`); + assert.equal(err.code, 'ETIMEDOUT', `${kind}: error carries code ETIMEDOUT`); + assert.equal(err.retryable, true, `${kind}: error is retryable so a wired Retry picks it up`); + // Rejected on the timeout, well inside the OS TCP window. Generous upper bound for CI noise. + assert.ok(dt >= 90 && dt < 2000, `${kind}: rejected on the timeout (was ${dt}ms)`); + }); + } +}); + +describe('BA-18: a response inside the window is NOT killed (no false trip)', () => { + for (const kind of ['Anthropic', 'OpenAI', 'Gemini', 'Ollama']) { + it(`${kind}: a fast response returns normally under the timeout`, async () => { + const s = await slowServer(0, OK_BODY[kind]); + // A generous bound on purpose: this asserts the timeout does NOT fire, so it must not race a + // loopback round-trip under CPU load. The "timeout fires" case above owns the tight bound. + const p = makeProvider(kind, s.url, 5000); + let result, err; + try { result = await p.generate(MSGS, []); } + catch (e) { err = e; } + s.server.close(); + assert.ok(!err, `${kind}: a fast response must not trip the timeout (got ${err && err.code})`); + assert.equal(result.text, 'hi', `${kind}: returns the real body`); + }); + } +}); + +describe('BA-18: the timeout is a real timer (negative control), and 0/Infinity disable it', () => { + it('a response OUTSIDE the window is a timeout — proves the timer measures idleness, not a no-op', async () => { + const s = await slowServer(300, ANTHROPIC_OK); + const p = new AnthropicProvider({ apiKey: 'x', baseUrl: s.url, timeoutMs: 100 }); + let err; + try { await p.generate(MSGS, []); } + catch (e) { err = e; } + s.server.close(); + assert.equal(err && err.code, 'ETIMEDOUT', 'a 300ms response under a 100ms bound must time out'); + }); + + it('a generous timeout lets a slow-but-working response through', async () => { + const s = await slowServer(300, ANTHROPIC_OK); + const p = new AnthropicProvider({ apiKey: 'x', baseUrl: s.url, timeoutMs: 5000 }); + const r = await p.generate(MSGS, []); + s.server.close(); + assert.equal(r.text, 'hi'); + }); + + it('timeoutMs:0 disables the provider bound (back-compat) — bounded only by an outer race here', async () => { + const s = await silentServer(); + const p = new AnthropicProvider({ apiKey: 'x', baseUrl: s.url, timeoutMs: 0 }); + let outerFired = false; + let err; + try { + await Promise.race([ + p.generate(MSGS, []), + new Promise((_, rej) => setTimeout(() => { outerFired = true; rej(new Error('outer')); }, 400)), + ]); + } catch (e) { err = e; } + closeSilent(s); + assert.ok(outerFired, 'with timeoutMs:0 the provider never times out (pre-BA-18 behaviour)'); + assert.equal(err.message, 'outer'); + }); + + it('a per-call timeoutMs overrides the instance default', async () => { + // Instance disabled, but the call bounds itself → it must time out on the call value. + const s = await silentServer(); + const p = new AnthropicProvider({ apiKey: 'x', baseUrl: s.url, timeoutMs: 0 }); + let err; + try { await p.generate(MSGS, [], { timeoutMs: 120 }); } + catch (e) { err = e; } + closeSilent(s); + assert.equal(err && err.code, 'ETIMEDOUT', 'a per-call timeoutMs must bound even when the instance disabled it'); + }); +}); + +describe('BA-18: resolveTimeoutMs — default / override / disable', () => { + it('absent instance and call → the finite default', () => { + assert.equal(resolveTimeoutMs(undefined, undefined), DEFAULT_TIMEOUT_MS); + assert.equal(DEFAULT_TIMEOUT_MS, 600000); + }); + it('a per-call value wins over the instance value', () => { + assert.equal(resolveTimeoutMs(1000, 5000), 5000); + assert.equal(resolveTimeoutMs(5000, undefined), 5000); + }); + it('0 and Infinity are the explicit opt-out (return 0)', () => { + assert.equal(resolveTimeoutMs(0, undefined), 0); + assert.equal(resolveTimeoutMs(Infinity, undefined), 0); + // A per-call 0 disables even when the instance had a finite bound. + assert.equal(resolveTimeoutMs(1000, 0), 0); + }); + it('NaN / negative / garbage fall back to the default — never a silent disable (finding-3)', () => { + // A `Number(process.env.X)` mistake must not revert to the ~2h hang BA-18 exists to prevent. + assert.equal(resolveTimeoutMs(NaN, undefined), DEFAULT_TIMEOUT_MS); + assert.equal(resolveTimeoutMs(-1, undefined), DEFAULT_TIMEOUT_MS); + assert.equal(resolveTimeoutMs(-Infinity, undefined), DEFAULT_TIMEOUT_MS); + assert.equal(resolveTimeoutMs('nope', undefined), DEFAULT_TIMEOUT_MS); + }); + it('null and undefined per-call both INHERIT the instance — null never shadows a disable (finding-2)', () => { + assert.equal(resolveTimeoutMs(1000, undefined), 1000); + assert.equal(resolveTimeoutMs(1000, null), 1000); + assert.equal(resolveTimeoutMs(0, null), 0, 'a per-call null must NOT re-enable an instance-level disable'); + assert.equal(resolveTimeoutMs(0, undefined), 0); + }); + it('applyRequestTimeout is a no-op when timeoutMs is 0 (never arms a timer)', () => { + let armed = false; + const fakeReq = { setTimeout: () => { armed = true; }, destroy: () => {} }; + applyRequestTimeout(/** @type {any} */ (fakeReq), 0, 'X'); + assert.equal(armed, false, 'a disabled bound must not arm the socket timer'); + }); +}); + +describe('BA-18 part 2: the Retry seam reaches the transient table (this is how Loop wires it)', () => { + it('a TimeoutError is classified transient by the default predicate', () => { + // DEFAULT_RETRY_ON keys on err.retryable / err.code — TimeoutError sets both. + const err = new TimeoutError('x'); + assert.equal(err.code, 'ETIMEDOUT'); + assert.equal(err.retryable, true); + }); + + it('a transport that throws ETIMEDOUT once then succeeds returns the success under a wired Retry', async () => { + // This mirrors loop.js: `this.retry ? await this.retry.call(generate) : await generate()`. + let calls = 0; + const generate = async () => { + calls++; + if (calls === 1) throw new TimeoutError('[AnthropicProvider] request timed out'); + return { text: 'recovered' }; + }; + const retry = new Retry({ maxAttempts: 3, backoff: 1 }); // 1ms backoff — fast test + const result = await retry.call(generate); + assert.equal(calls, 2, 'it retried exactly once after the timeout'); + assert.equal(result.text, 'recovered'); + }); + + it('the same failure rethrows under retryOn: () => false', async () => { + let calls = 0; + const generate = async () => { calls++; throw new TimeoutError('timed out'); }; + const retry = new Retry({ maxAttempts: 3, backoff: 1, retryOn: () => false }); + await assert.rejects(() => retry.call(generate), (e) => e instanceof TimeoutError); + assert.equal(calls, 1, 'retryOn:false means no retry — one attempt only'); + }); +});