From bbeba7ddb9d72060497561e5a82e618629a7dcdc Mon Sep 17 00:00:00 2001 From: hamr0 Date: Thu, 23 Jul 2026 10:06:35 +0200 Subject: [PATCH] =?UTF-8?q?fix:=20BA-17=20=E2=80=94=20a=20native=20(claude?= =?UTF-8?q?-mcp)=20turn=20is=20one=20assistant=20message,=20not=20one=20st?= =?UTF-8?q?ream=20event?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit The claude CLI emits a separate `assistant` stream event per content BLOCK, each repeating that message's `usage`. `createSessionStream` fired one `onTurn` per event, which corrupted both metering axes: - Turn axis: a caller whose attempt bound is an LLM-turn count saw 14 "turns" for 2 real ones (7x; 4.4x on the adopter's failing job — 35 events for 8 turns). Its net guillotined the session at ~half the advertised allowance, and on native that routed to humanChannel -> terminate, discarding the worker's output. - Token axis: the same message's usage was summed once per block — 5.04x inflated vs the CLI's own session total, so a budget cap fired on tokens never spent. A run of consecutive events sharing message.id is now ONE turn (adjacent-run dedup — not a Set, so a recurring id still counts; no id degrades to per-event, never collapses the session into one turn). `--max-turns` itself was never the defect. The ask filed it as "does not enforce, counts tool-calling turns" — both measured false on the wire: it enforces (12-step task under --max-turns 4 stopped at 4, named error_max_turns) and counts assistant turns (12 tool calls across 2 turns inside --max-turns 3). Also in this fix: - The turn bound is now bare-agent's guarantee. --max-turns still maps through (it stops cleanly and emits the cost-bearing result event); a parent-side counter kills the session only on an OVERRUN (> not >=), because --max-turns is undocumented in `claude --help` and a rename would silently unbound it. - BA-5 on native: a bounded session returns the last turn's text (the CLI reports result:null on a bound), and the imposed terminal reports stopReason:'max_turns' via an own-property lookup (proto-key guard), not null. - The closing kind:'session' event reconciles the TOKEN axis: a turn's usage is an unrevised first-block snapshot, so the streamed sum is short of the total. The closing event carries the per-tier residual (floored at 0), so a wired gate's tokens sum to exactly the CLI's own total. Verified live (streamed + residual = 821 = the CLI's output total). - GenerateResult.model on native is read from result.modelUsage via mapClaudeMeta (the result event has no `model` key), so model/costUsd stop being null. No new public surface (patch). Adopters bounding by LLM turns get fewer onTurn events and smaller, correct token numbers than 0.33.0 reported. Evidence: poc/ba17-turn-unit.mjs, poc/ba17-unit-parallel.mjs (the flag's real unit), poc/ba17-verify-shipped.mjs (shipped code on a live session, both cases green incl. token reconciliation). +34 tests; every new guard mutation-proved in both directions (19 mutations, all red). Co-Authored-By: Claude Opus 4.8 (1M context) Claude-Session: https://claude.ai/code/session_01QxUb57y7xtJcaviVP9avJ6 --- CHANGELOG.md | 62 ++++++ CLAUDE.md | 2 +- bareagent.context.md | 8 +- docs/01-product/prd.md | 47 ++++ package-lock.json | 4 +- package.json | 2 +- poc/ba17-turn-unit.mjs | 167 +++++++++++++++ poc/ba17-unit-parallel.mjs | 91 ++++++++ poc/ba17-verify-shipped.mjs | 145 +++++++++++++ src/provider-clipipe-mcp.js | 146 ++++++++++--- src/provider-clipipe.js | 99 +++++++-- test/provider-clipipe-mcp.test.js | 342 ++++++++++++++++++++++++++++++ 12 files changed, 1059 insertions(+), 56 deletions(-) create mode 100644 poc/ba17-turn-unit.mjs create mode 100644 poc/ba17-unit-parallel.mjs create mode 100644 poc/ba17-verify-shipped.mjs diff --git a/CHANGELOG.md b/CHANGELOG.md index ceb0d8d..e053960 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -2,6 +2,68 @@ All notable changes to bare-agent are documented here. Format: [Keep a Changelog](https://keepachangelog.com/). Versioning: [SemVer](https://semver.org/). +## [0.33.1] - 2026-07-22 + +### Fixed + +- **BA-17 — a native (`claude-mcp`) turn is one assistant MESSAGE, not one stream event.** Measured + on the real wire: the claude CLI emits a **separate `assistant` event per content block**, and each + one repeats that message's `usage` verbatim (one 13-block message arrived as 13 identical-usage + events). `createSessionStream` fired one `onTurn` per event, which corrupted both axes a caller + meters: + - **Turn axis** — a caller whose attempt bound is an LLM-turn count saw **14 "turns" for 2 real + ones** (7×; 4.4× on the adopter's failing job: 35 events for 8 turns). Its net then guillotined + the session at roughly *half* the allowance it advertised, and on the native path that routed to + `humanChannel → terminate`, discarding the worker's output entirely. + - **Token axis** — the same message's usage was added once per block: **5.04× inflated** against + the CLI's own session total, so a budget cap fired on tokens that were never spent. + + A run of consecutive events sharing `message.id` is now ONE turn: usage recorded once, one `onTurn`. + Adjacent-run dedup (not a Set) so a recurring id still counts as a new turn — dropping a real turn + is the failure that matters. An event with **no** id degrades to one-turn-per-event, the pre-BA-17 + behaviour, never a collapse of the session into a single turn. + + **`--max-turns` itself was never the defect.** It was filed as "does not enforce, and counts + tool-calling turns"; both were measured false. It enforces (a 12-step task under `--max-turns 4` + stopped at 4 with the named `error_max_turns`) and it counts assistant turns (12 tool calls served + across 2 turns, inside `--max-turns 3`). The symptom was the mis-count above. + +- **BA-17 — the turn bound is now bare-agent's guarantee, not an undocumented flag's.** `maxTurns` + still maps to `--max-turns` (which stops the session cleanly and emits the result event carrying + its real cost), and a parent-side counter now kills the session if a turn **beyond** N is ever + observed. Deliberately `>` and not `>=`: killing at exactly N on every bounded run would throw away + the only report of what the session cost. The backstop exists because `--max-turns` is undocumented + in `claude --help` — a rename would otherwise silently unbound every session. + +- **BA-17 — a bounded native session returns its work (BA-5 on the native path).** The CLI reports + `result: null` when it stops on its own bound, so the provider returned `text: ''` — destroying the + only channel from one bounded attempt to the next. The last assistant turn's own text is now + carried forward, on the bound, on a guard terminal, and on a session we killed. The stop also + reports `stopReason: 'max_turns'` rather than `null` (a terminal we impose has no subtype to read + one from), via an own-property lookup — same proto-key guard as `SUBTYPE_MAP`. + +- **BA-17 — the closing `kind:'session'` event now reconciles the token axis, not just money.** A + turn's `message.usage` is a snapshot taken when its first block was emitted and never revised + (measured: a turn that emitted ~816 output tokens reported 2, identically on all 13 of its events), + so the streamed per-turn sum is real but **short** of the session total. The closing event carries + the **residual** per tier (floored at 0 — a negative would be a credit that silently widens a cap), + so a wired gate's tokens now add up to exactly what the CLI itself reports. Verified on the live + wire: streamed + residual = 821 = the CLI's own output total. + +- `GenerateResult.model` on the native path is read from the result event's `modelUsage` key via the + existing `mapClaudeMeta` helper. The result event has no `model` key, so this field — and the + closing session event's `model` — were always `null`. + +### Notes + +- No new public surface; `maxTurns`, `onTurn`, `session.turns` and `usage` keep their names and + change only to report honestly. Adopters bounding by LLM turns should expect **fewer** `onTurn` + events and **smaller, correct** token numbers than 0.33.0 reported. +- Evidence: `poc/ba17-turn-unit.mjs` (event-vs-turn + flag enforcement), `poc/ba17-unit-parallel.mjs` + (the flag's unit), `poc/ba17-verify-shipped.mjs` (the shipped code on a live session, both cases + green including the token reconciliation). +34 tests, every new guard mutation-proved in both + directions (19 mutations, all red). + ## [0.33.0] - 2026-07-21 ### Added diff --git a/CLAUDE.md b/CLAUDE.md index fd4a44a..fbe2a35 100644 --- a/CLAUDE.md +++ b/CLAUDE.md @@ -32,7 +32,7 @@ Node.js >= 18, pure JS + JSDoc, `node:test` for testing. Flat `src/` layout with | 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) -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 via `--max-turns` (NAMED stop `error:'max_turns'`). `onTurn` STREAMS per-turn usage with all four cache tiers (never sum-at-end; a mid-run death has already surfaced its spend) then one closing `session` event with the authoritative cost — and 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 (a 14-turn session never reads as one round); 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. +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` Tools: BrowsingTools (tools/browse.js, optional dep: barebrowse) — library tools for inline snapshots, CLI session (`npx barebrowse`) for token-efficient disk-based browsing diff --git a/bareagent.context.md b/bareagent.context.md index f702a2a..422430e 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.0 | Node.js >= 18 | zero required deps (`bareguard >=0.9.0 <0.13.0` optional peer for governance) | Apache 2.0 +> v0.33.1 | 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) @@ -817,11 +817,11 @@ new CLIPipe({ command: 'claude', args: ['-p', '--model', 'sonnet'], toolProtocol **CLIPipe NATIVE tool mode (BA-16, `toolProtocol:'claude-mcp'`).** The claude CLI has a real tool channel; native mode uses it instead of emulating one. The CLI runs its OWN multi-turn session per `generate()` call and executes your `tools` natively over an MCP bridge that calls back into your in-process `execute` closures. Because the CLI owns the inner cycle, the Loop's per-round machinery cannot run — so the governance you'd wire on `Loop` moves to the **provider**, at the one seam every tool call crosses: - `policy` — the SAME `(tool, args, ctx) => true|string` chokepoint as `Loop({policy})`, so a wired `wireGate(gate).policy` writes **audit rows of identical shape, zero gate changes**. A deny is a tool result (advisory); the handler never runs. **Required here** — a `Loop({policy})` in native mode would be a fence that is silently not there, so the Loop throws. - `maxConsecutiveDenials` (3) / `maxIdenticalToolErrors` (3) — BA-11/BA-12 guards at the bridge, same narrowest triggers; end the session `denied:` / `stuck:`. -- `maxTurns` — maps to the CLI's `--max-turns`; the bound stop is `error:'max_turns'`, never a silent success. -- `onTurn` — streams each completed turn's usage (four cache tiers, `costUsd:null` — the CLI prices the session) as it arrives, then one closing `kind:'session'` event with the authoritative total. Shape mirrors `onLlmResult`, so `wireGate(gate).onLlmResult` drops in; when wired the Loop skips its own forward (billed once, never starved). +- `maxTurns` — a bound on **assistant/LLM turns**, the SAME unit as the Loop path, so one number means one thing on both surfaces (BA-17). NOT a tool-call count: one turn can fire a dozen parallel tool calls and still be one turn (measured: 12 calls across 2 turns, inside `--max-turns 3`). Enforced twice — the CLI's own `--max-turns` stops cleanly at N (and emits the result event that carries the session's real cost), plus a parent-side counter that kills the session if a turn beyond N is ever seen, since that flag is undocumented in `claude --help`. The stop is `error:'max_turns'` + `stopReason:'max_turns'` and **carries the last turn's text forward** — the CLI reports `result:null` on a bounded session, so an unfixed build returned `text:''`. +- `onTurn` — fires once per **assistant turn** (BA-17: the CLI emits a separate stream event per content *block*, all repeating that message's usage — firing per event inflated a caller's turn axis ~5–7× and its token axis 5.04×), carrying four cache tiers and `costUsd:null` since the CLI prices the session, not the turn. Then one closing `kind:'session'` event carrying the authoritative cost **and the token residual** — a turn's `message.usage` is a snapshot taken at its first block and never revised (a turn that emitted ~816 output tokens reported 2), so the closing event makes the streamed tiers add up to exactly the CLI's own session total. Shape mirrors `onLlmResult`, so `wireGate(gate).onLlmResult` drops in; when wired the Loop skips its own forward (billed once, never starved). - `sessionTimeout` (600s) / `bridgeTimeoutMs` (120s) — whole-session and per-handler ceilings. -`GenerateResult.session` (`{turns, toolCalls, error, usageReported}`) carries what really happened; `metrics.sessionTurns` reports the real turn count so a 14-turn session never reads as one round. A terminal the CLI detects inside the session (bound, guard, or a **broken tool 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. `assemble`/`trim`/`cacheMessages` and a Loop-level `policy` all THROW at construction in native mode (no silently-dead knobs — the CLI owns the transcript). The bridge is a unix socket (0600 in a 0700 dir), never a listening port. Claude-only for now; the CLI-specific parts live in `src/provider-clipipe-mcp.js` + `src/mcp-bridge-stub.js` behind the same seam as emulation. +`GenerateResult.session` (`{turns, toolCalls, error, usageReported}`) carries what really happened; `metrics.sessionTurns` reports the real turn count — assistant *messages*, not stream events — so a 14-turn session never reads as one round, and a 2-turn session never reads as 14. A terminal the CLI detects inside the session (bound, guard, or a **broken tool 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. `assemble`/`trim`/`cacheMessages` and a Loop-level `policy` all THROW at construction in native mode (no silently-dead knobs — the CLI owns the transcript). The bridge is a unix socket (0600 in a 0700 dir), never a listening port. Claude-only for now; the CLI-specific parts live in `src/provider-clipipe-mcp.js` + `src/mcp-bridge-stub.js` behind the same seam as emulation. All return `{ text, toolCalls, usage: { inputTokens, outputTokens }, model?, costUsd? }`. The optional `model` (v0.16.1+) is the id the response was produced by — Loop prefers it over `provider.model` for cost accounting. By default CLIPipe returns `toolCalls: []` and zero usage (CLI tools don't report tokens) and omits `model`. **Structured output (v0.26.0+):** set `parse: 'claude-json'` (a preset for `claude -p --output-format json`) — or a `(stdout) => Partial` function for any other CLI — and CLIPipe maps the CLI's JSON envelope onto real `usage`, `model`, and `costUsd`, throwing `ProviderError` on a malformed/error envelope (never a silent raw-text fall-back). `costUsd` (optional `GenerateResult` field) is an **authoritative** per-call price the provider reports itself; when finite the Loop prefers it over the internal rate-table `estimateCost`, so a CLI-piped run enforces a bareguard USD cap with no local pricing table (a `0` counts as priced, distinct from null/unpriced). `toolCalls` stays `[]` regardless (CLIPipe is tool-free). diff --git a/docs/01-product/prd.md b/docs/01-product/prd.md index 5a3fe97..ca6d09f 100644 --- a/docs/01-product/prd.md +++ b/docs/01-product/prd.md @@ -809,6 +809,53 @@ 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.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`), +> the criterion-4 follow-up to BA-16 below. Not a bareagent-internal BA-number. + +Decisions locked, not to be re-litigated: + +- **A native turn is one assistant MESSAGE, not one stream event.** Measured on + the real wire: the claude CLI emits a separate `assistant` event per content + BLOCK, each repeating that message's `usage`. Counting events as turns inflated + a caller's LLM-turn net 5–7× (guillotining a bounded worker at ~half its + allowance) and the token axis 5.04×. Fix: a run of consecutive events sharing + `message.id` is ONE turn (adjacent-run dedup — NOT a Set, so a recurring id + still counts; no id ⇒ degrade to per-event, never collapse the session into + one turn). This is the same BA-4/5/6/13 optimistic-rounding class the native + mode was built to avoid — the boundary "one message ≠ one event" was + under-modeled and rounded toward "fewer turns / more tokens." +- **The filed ask was measured WRONG about the cause, and that correction is the + decision.** BA-17 filed `--max-turns` as "does not enforce, and counts + tool-calling turns." Both false on the wire: it enforces (12-step task under + `--max-turns 4` stopped at 4, named `error_max_turns`) and counts assistant + turns (12 tool calls across 2 turns inside `--max-turns 3`). The symptom was + the event-vs-message mis-count above. **A cross-repo ask is a symptom report, + not a root-cause diagnosis — verify the mechanism on the real wire before + building to the ask's stated cause.** +- **`maxTurns` is an LLM-turn bound, enforced TWICE.** The CLI's own + `--max-turns` stops the session cleanly at N (and emits the result event that + carries the session's real cost); a parent-side counter kills the session only + on an OVERRUN (`>` not `>=`, so the clean-exit cost report is never thrown + away). The backstop exists because `--max-turns` is **undocumented in + `claude --help`** — a guarantee cannot rest on a flag that could be renamed + silently. Same unit as the Loop path, so a caller's `maxTurns` means one thing + on both surfaces. +- **A bounded native session returns its work (BA-5 on native).** The CLI reports + `result: null` when it stops on its own bound, so the last assistant turn's own + text is carried forward; the imposed terminal reports `stopReason:'max_turns'` + (own-property lookup — the proto-key guard) rather than `null`. +- **The closing session event reconciles the TOKEN axis, not just money.** A + turn's `message.usage` is an unrevised first-block snapshot (a turn emitting + ~816 output tokens reported 2), so the streamed per-turn sum is short of the + session total; the closing `kind:'session'` event carries the per-tier + **residual** (floored at 0 — a negative would be a credit that widens a cap), + so a wired gate's tokens sum to exactly the CLI's own total. Verified live. +- **No new public surface — a patch.** `maxTurns`/`onTurn`/`session.turns`/`usage` + keep their names; they only report honestly. Adopters bounding by LLM turns get + FEWER `onTurn` events and SMALLER, correct token numbers than 0.33.0 reported. + ### v0.33.0 / CLIPipe native MCP tool mode (bareloop BA-16) (2026-07-21) > **Numbering note.** This is **bareloop's** BA-16 (`docs/UPSTREAM-ASKS.md`), an diff --git a/package-lock.json b/package-lock.json index 9ca8934..c22229a 100644 --- a/package-lock.json +++ b/package-lock.json @@ -1,12 +1,12 @@ { "name": "bare-agent", - "version": "0.33.0", + "version": "0.33.1", "lockfileVersion": 3, "requires": true, "packages": { "": { "name": "bare-agent", - "version": "0.33.0", + "version": "0.33.1", "license": "Apache-2.0", "bin": { "bare-agent": "bin/cli.js" diff --git a/package.json b/package.json index e3f688b..8ffbd54 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "bare-agent", - "version": "0.33.0", + "version": "0.33.1", "files": [ "index.js", "index.d.ts", diff --git a/poc/ba17-turn-unit.mjs b/poc/ba17-turn-unit.mjs new file mode 100644 index 0000000..4325749 --- /dev/null +++ b/poc/ba17-turn-unit.mjs @@ -0,0 +1,167 @@ +// BA-17 — what IS a "turn" on a native claude-mcp session, and does `--max-turns N` bind at N? +// +// The filed ask says: `--max-turns 8` did not stop an 8-turn scout in ANY unit (16 "LLM turns", +// 26 tool calls observed). But the adopter's gate audit for that very run shows 35 llm records +// whose token totals repeat in CONSECUTIVE RUNS — 4190×3, 14484×4, 17264×3, 21842×16, … — eight +// distinct groups. That is the signature of ONE assistant message being emitted as SEVERAL +// stream-json `assistant` events (one per content block), each carrying the SAME message.usage. +// +// If that is what the CLI does, then bare-agent's `createSessionStream` — which fires one `onTurn` +// per assistant EVENT and sums usage per event — has two defects the ask did not name: +// (a) the caller's turn-unit net counts BLOCKS, not turns (35 vs 8: a ~4x early guillotine); +// (b) the session's summed `usage` counts the same message's tokens once per block (inflated). +// …and defect 1 of the ask ("the flag does not enforce") may be an ARTIFACT of (a), not real. +// +// This spike must be able to return the NEGATIVE: if the CLI emits one event per real turn and the +// repeats are something else, H1 is dead and the ask's framing stands. +// +// Design: a CHAINED tool (each result carries the token needed for the next call) forces STRICTLY +// SEQUENTIAL turns — no parallel-call batching to muddy the count — and asks for more steps than +// `--max-turns` allows, so an enforcing flag MUST cut it short. +// +// Cross-check that cannot be argued with: the CLI's own `result` event reports `num_turns` and the +// session `usage` total. Our per-event count and per-event sum are measured against THOSE. +// +// Requires the `claude` CLI, logged in. ~$0.05 notional. Run: node poc/ba17-turn-unit.mjs + +import net from 'node:net'; +import fs from 'node:fs'; +import os from 'node:os'; +import path from 'node:path'; +import { spawn } from 'node:child_process'; +import { fileURLToPath } from 'node:url'; + +const STUB = path.join(path.dirname(fileURLToPath(import.meta.url)), '..', 'src', 'mcp-bridge-stub.js'); + +const MAX_TURNS = 4; // the advertised bound +const CHAIN_LEN = 12; // steps the task needs — 3x the bound, so enforcement is unmissable + +const dir = fs.mkdtempSync(path.join(os.tmpdir(), 'ba17-')); +const sock = path.join(dir, 'b.sock'); +let served = 0; + +const server = net.createServer((conn) => { + let buf = ''; + conn.on('data', (d) => { + buf += d; const nl = buf.indexOf('\n'); if (nl === -1) return; + let req; try { req = JSON.parse(buf.slice(0, nl)); } catch { return conn.end(); } buf = ''; + if (req.op === 'list') { + return conn.write(JSON.stringify({ tools: [{ + name: 'chain_step', + description: 'Advance the chain. Pass the token you were last given (or "start"). Returns the next token.', + inputSchema: { type: 'object', properties: { token: { type: 'string' } }, required: ['token'] }, + }] }) + '\n'); + } + if (req.op === 'call') { + served++; + // Step n is derivable only from the previous token -> the model CANNOT batch ahead. + const prev = String(req.args?.token ?? ''); + const n = prev === 'start' ? 1 : (Number(prev.split('-')[1]) || 0) + 1; + const body = n >= CHAIN_LEN + ? { next: `FINAL-${n}`, done: true } + : { next: `tok-${n}`, done: false }; + conn.write(JSON.stringify({ text: JSON.stringify(body) }) + '\n'); + } + }); + conn.on('error', () => {}); +}); +await new Promise((r) => server.listen(sock, r)); + +const cfg = JSON.stringify({ mcpServers: { bareagent: { command: process.execPath, args: [STUB], env: { BAREAGENT_BRIDGE_SOCK: sock } } } }); +const child = spawn('claude', [ + '--model', 'sonnet', '-p', '--mcp-config', cfg, '--tools', '', '--strict-mcp-config', + '--setting-sources', '', '--allowedTools', 'mcp__bareagent__*', + '--system-prompt', + 'You advance a chain using the chain_step tool. Call it with token "start", then keep calling it ' + + 'with the token from the previous result, ONE CALL AT A TIME, until a result has done:true. ' + + 'Then reply with the final token only.', + '--output-format', 'stream-json', '--verbose', + '--max-turns', String(MAX_TURNS), +], { stdio: ['pipe', 'pipe', 'pipe'] }); + +let out = '', err = ''; +child.stdout.on('data', (d) => { out += d; }); +child.stderr.on('data', (d) => { err += d; }); +child.stdin.end(`Advance the chain to completion (it needs about ${CHAIN_LEN} steps) and report the final token.`); +await new Promise((r) => child.on('close', r)); +server.close(); + +const raw = path.join(dir, 'stream.jsonl'); +fs.writeFileSync(raw, out); + +// ── Measure exactly what the shipped code measures, plus what it does NOT ────────────────────── +const events = []; +for (const line of out.split('\n')) { + if (!line.trim()) continue; + try { events.push(JSON.parse(line)); } catch { /* not our frame */ } +} + +const assistants = events.filter((e) => e.type === 'assistant' && e.message); +const withUsage = assistants.filter((e) => e.message.usage); +const ids = assistants.map((e) => e.message.id); +const distinctIds = [...new Set(ids)]; +const toolUse = assistants.flatMap((e) => (e.message.content || []).filter((b) => b?.type === 'tool_use')); + +// Per-event sum: what the shipped provider reports as the session's usage today. +const perEvent = withUsage.reduce((a, e) => { + const u = e.message.usage; + return a + (Number(u.input_tokens) || 0) + (Number(u.output_tokens) || 0) + + (Number(u.cache_read_input_tokens) || 0) + (Number(u.cache_creation_input_tokens) || 0); +}, 0); +// Per-message sum: the same arithmetic deduped by message.id. +const seen = new Map(); +for (const e of withUsage) if (!seen.has(e.message.id)) seen.set(e.message.id, e.message.usage); +const perMessage = [...seen.values()].reduce((a, u) => a + + (Number(u.input_tokens) || 0) + (Number(u.output_tokens) || 0) + + (Number(u.cache_read_input_tokens) || 0) + (Number(u.cache_creation_input_tokens) || 0), 0); + +const result = events.find((e) => e.type === 'result') || {}; +const cliUsage = result.usage || {}; +const cliTotal = (Number(cliUsage.input_tokens) || 0) + (Number(cliUsage.output_tokens) || 0) + + (Number(cliUsage.cache_read_input_tokens) || 0) + (Number(cliUsage.cache_creation_input_tokens) || 0); + +// Block-type breakdown per message — shows WHY the event count differs from the turn count. +const perId = new Map(); +for (const e of assistants) { + const cur = perId.get(e.message.id) || { events: 0, blocks: [] }; + cur.events++; + for (const b of (e.message.content || [])) cur.blocks.push(b?.type); + perId.set(e.message.id, cur); +} + +console.log('── raw capture:', raw); +console.log('\n── EVENT vs TURN ────────────────────────────────────────'); +console.log('assistant events :', assistants.length); +console.log(' …carrying usage :', withUsage.length, ' <- one onTurn each TODAY'); +console.log('distinct message.id :', distinctIds.length, ' <- real assistant turns'); +console.log('tool_use blocks :', toolUse.length); +console.log('bridge calls served :', served); +console.log('CLI result.num_turns :', result.num_turns); +console.log('\nper message.id (events -> block types):'); +for (const [id, v] of perId) console.log(` ${id.slice(0, 24)} events=${v.events} blocks=[${v.blocks.join(',')}]`); + +console.log('\n── USAGE ARITHMETIC ─────────────────────────────────────'); +console.log('summed per EVENT (shipped):', perEvent); +console.log('summed per MESSAGE (dedup):', perMessage); +console.log('CLI result.usage total :', cliTotal); + +console.log('\n── BOUND ────────────────────────────────────────────────'); +console.log('--max-turns advertised :', MAX_TURNS); +console.log('result.subtype :', result.subtype); +console.log('is_error :', result.is_error); +console.log('final text :', JSON.stringify(String(result.result || '').slice(0, 120))); +if (err.trim()) console.log('stderr :', err.trim().slice(0, 200)); + +// ── Verdicts. Each is falsifiable; none is assumed. ─────────────────────────────────────────── +const H1 = withUsage.length > distinctIds.length; +const boundHeld = distinctIds.length <= MAX_TURNS; +const namedStop = result.subtype === 'error_max_turns'; + +console.log('\n── VERDICT ──────────────────────────────────────────────'); +console.log(`H1 one message emitted as SEVERAL usage-bearing events : ${H1 ? 'CONFIRMED' : 'REFUTED'}`); +console.log(` (events ${withUsage.length} vs turns ${distinctIds.length})`); +console.log(`H2 --max-turns ${MAX_TURNS} bound the session at <= ${MAX_TURNS} turns : ${boundHeld ? 'HELD' : 'FAILED'}`); +console.log(`H3 the bound surfaced as the named error_max_turns : ${namedStop ? 'YES' : 'NO'}`); +console.log(`H4 shipped usage sum matches the CLI's own total : ${perEvent === cliTotal ? 'MATCHES' : 'INFLATED by ' + (perEvent - cliTotal)}`); +console.log(`H5 deduped usage sum matches the CLI's own total : ${perMessage === cliTotal ? 'MATCHES' : 'off by ' + (perMessage - cliTotal)}`); +console.log(`\nchain completed? served=${served} of ${CHAIN_LEN} steps needed`); diff --git a/poc/ba17-unit-parallel.mjs b/poc/ba17-unit-parallel.mjs new file mode 100644 index 0000000..2e453f2 --- /dev/null +++ b/poc/ba17-unit-parallel.mjs @@ -0,0 +1,91 @@ +// BA-17 probe 2 — does `--max-turns N` count ASSISTANT TURNS or TOOL CALLS? +// +// Probe 1 chained one tool call per turn, so turns == calls and the two hypotheses were +// indistinguishable. This probe breaks the tie: the tool is designed to be called MANY TIMES PER +// TURN (independent lookups, no chaining), and the model is told to batch them. With `--max-turns 3` +// and 12 items to look up: +// - if the flag counts TOOL CALLS -> the session stops after ~3 calls, well short of 12 +// - if the flag counts TURNS -> the session runs ~3 assistant messages and serves MANY MORE +// than 3 calls +// Either outcome is a real answer; the probe cannot confirm one by construction. +// +// Requires the `claude` CLI, logged in. ~$0.04 notional. Run: node poc/ba17-unit-parallel.mjs + +import net from 'node:net'; +import fs from 'node:fs'; +import os from 'node:os'; +import path from 'node:path'; +import { spawn } from 'node:child_process'; +import { fileURLToPath } from 'node:url'; + +const STUB = path.join(path.dirname(fileURLToPath(import.meta.url)), '..', 'src', 'mcp-bridge-stub.js'); +const MAX_TURNS = 3; +const ITEMS = ['alpha', 'bravo', 'charlie', 'delta', 'echo', 'foxtrot', 'golf', 'hotel', 'india', 'juliet', 'kilo', 'lima']; + +const dir = fs.mkdtempSync(path.join(os.tmpdir(), 'ba17p2-')); +const sock = path.join(dir, 'b.sock'); +let served = 0; + +const server = net.createServer((conn) => { + let buf = ''; + conn.on('data', (d) => { + buf += d; const nl = buf.indexOf('\n'); if (nl === -1) return; + let req; try { req = JSON.parse(buf.slice(0, nl)); } catch { return conn.end(); } buf = ''; + if (req.op === 'list') { + return conn.write(JSON.stringify({ tools: [{ + name: 'lookup', + description: 'Look up the numeric code for ONE item. Independent of every other lookup.', + inputSchema: { type: 'object', properties: { item: { type: 'string' } }, required: ['item'] }, + }] }) + '\n'); + } + if (req.op === 'call') { + served++; + const item = String(req.args?.item ?? ''); + conn.write(JSON.stringify({ text: `${item} = ${item.length * 7}` }) + '\n'); + } + }); + conn.on('error', () => {}); +}); +await new Promise((r) => server.listen(sock, r)); + +const cfg = JSON.stringify({ mcpServers: { bareagent: { command: process.execPath, args: [STUB], env: { BAREAGENT_BRIDGE_SOCK: sock } } } }); +const child = spawn('claude', [ + '--model', 'sonnet', '-p', '--mcp-config', cfg, '--tools', '', '--strict-mcp-config', + '--setting-sources', '', '--allowedTools', 'mcp__bareagent__*', + '--system-prompt', + 'You look up codes with the lookup tool. The lookups are INDEPENDENT — issue as many lookup ' + + 'calls as you can IN PARALLEL in a single turn rather than one at a time. Then report the codes.', + '--output-format', 'stream-json', '--verbose', + '--max-turns', String(MAX_TURNS), +], { stdio: ['pipe', 'pipe', 'pipe'] }); + +let out = ''; +child.stdout.on('data', (d) => { out += d; }); +child.stdin.end(`Look up the code for every one of these ${ITEMS.length} items and report them all: ${ITEMS.join(', ')}.`); +await new Promise((r) => child.on('close', r)); +server.close(); + +fs.writeFileSync(path.join(dir, 'stream.jsonl'), out); +const events = out.split('\n').filter((l) => l.trim()).map((l) => { try { return JSON.parse(l); } catch { return null; } }).filter(Boolean); +const assistants = events.filter((e) => e.type === 'assistant' && e.message); +const ids = [...new Set(assistants.map((e) => e.message.id))]; +const toolUse = assistants.flatMap((e) => (e.message.content || []).filter((b) => b?.type === 'tool_use')); +const result = events.find((e) => e.type === 'result') || {}; + +console.log('── raw capture:', path.join(dir, 'stream.jsonl')); +console.log('--max-turns :', MAX_TURNS); +console.log('assistant events :', assistants.length); +console.log('distinct message.id :', ids.length, ' <- real assistant turns'); +console.log('tool_use blocks :', toolUse.length); +console.log('bridge calls served :', served); +console.log('CLI result.num_turns :', result.num_turns); +console.log('result.subtype :', result.subtype); +console.log('result.stop_reason :', result.stop_reason); +console.log('per-turn call counts :', assistants.map((e) => (e.message.content || []).filter((b) => b?.type === 'tool_use').length).join(',')); + +const countsCalls = served <= MAX_TURNS + 1; +const countsTurns = ids.length <= MAX_TURNS && served > MAX_TURNS + 1; +console.log('\n── VERDICT ─────────────────────────────────────────────'); +if (countsTurns) console.log(`UNIT = ASSISTANT TURNS (${ids.length} turns <= ${MAX_TURNS}, while ${served} tool calls were served)`); +else if (countsCalls) console.log(`UNIT = TOOL CALLS (${served} calls served, ${ids.length} turns)`); +else console.log(`INDETERMINATE — turns=${ids.length} calls=${served} cap=${MAX_TURNS}; the model may not have batched. Re-run or reshape.`); diff --git a/poc/ba17-verify-shipped.mjs b/poc/ba17-verify-shipped.mjs new file mode 100644 index 0000000..86e2ce1 --- /dev/null +++ b/poc/ba17-verify-shipped.mjs @@ -0,0 +1,145 @@ +// BA-17 verify-shipped — the SHIPPED turn-unit fix on a real claude CLI session, driven through a +// real `Loop`. Not the build spikes (poc/ba17-turn-unit.mjs, poc/ba17-unit-parallel.mjs): this +// imports src/, so it goes red if the shipped code drifts from what was measured. +// +// What went wrong in 0.33.0, on the adopter's real job: the CLI emits one `assistant` stream event +// per content BLOCK, all repeating that message's usage. The provider fired one `onTurn` per event, +// so a caller whose attempt bound is an LLM-turn count saw 35 "turns" for 8 real ones and its net +// guillotined the session at real turn ~4 of an advertised 8 — while the token axis was inflated +// 5.04x by the same repetition. `--max-turns` itself was never the problem: measured, it enforces, +// and it counts assistant turns. +// +// Case 1 (the inflation): a task the model answers with MANY tool calls inside FEW turns. Pre-fix +// this reported one turn per block; the assertions below are false unless a turn is a message. +// Case 2 (the bound): a task that cannot finish inside the bound. The stop must be NAMED and must +// still carry the work — the CLI reports `result: null` on a bounded session (measured), so an +// unfixed build returns text:''. +// +// Requires: the `claude` CLI, logged in. Costs ~$0.10 notional. Run: node poc/ba17-verify-shipped.mjs + +import { createRequire } from 'node:module'; + +const require = createRequire(import.meta.url); +const { Loop } = require('../src/loop'); +const { CLIPipeProvider } = require('../src/provider-clipipe'); + +let failures = 0; +const check = (label, cond, detail = '') => { + if (!cond) failures++; + console.log(` [${cond ? 'PASS' : 'FAIL'}] ${label}${detail ? ` — ${detail}` : ''}`); +}; + +const ITEMS = ['alpha', 'bravo', 'charlie', 'delta', 'echo', 'foxtrot', 'golf', 'hotel', 'india', 'juliet', 'kilo', 'lima']; + +// ── Case 1 — many tool calls, few turns ────────────────────────────────────────────────────────── +console.log('\nCASE 1 — a turn is a message, not a stream event'); +{ + let served = 0; + const turnEvents = []; + const allUsage = []; + let sessionEvents = 0; + + const provider = new CLIPipeProvider({ + command: 'claude', + args: ['--model', 'sonnet'], + toolProtocol: 'claude-mcp', + maxTurns: 6, + onTurn: async (e) => { + allUsage.push(e.usage); + if (e.kind === 'session') { sessionEvents++; return; } + turnEvents.push(e.usage); + }, + }); + + const out = await new Loop({ + provider, + system: 'You look up codes with the lookup tool. The lookups are INDEPENDENT — issue as many ' + + 'lookup calls as you can IN PARALLEL in a single turn rather than one at a time.', + }).run( + [{ role: 'user', content: `Look up the code for each of these ${ITEMS.length} items and report them: ${ITEMS.join(', ')}.` }], + [{ + name: 'lookup', + description: 'Look up the numeric code for ONE item. Independent of every other lookup.', + parameters: { type: 'object', properties: { item: { type: 'string' } }, required: ['item'] }, + execute: async ({ item }) => { served++; return `${item} = ${String(item).length * 7}`; }, + }], + ); + + const turns = out.metrics.sessionTurns; + console.log(` observed: ${turns} turns, ${served} tool calls served, ${turnEvents.length} per-turn events, ${sessionEvents} session event`); + + check('the session ran and was not error-tagged', out.error === null, `error=${out.error}`); + check('tool calls GREATLY outnumber turns (the shape that broke the count)', served > turns + 2, + `${served} calls across ${turns} turns`); + check('one per-turn event per TURN — not one per content block', turnEvents.length === turns, + `${turnEvents.length} events vs ${turns} turns`); + check('exactly one closing session event', sessionEvents === 1); + + // The direct fingerprint of the bug: repeated blocks of one message all carried the SAME usage, + // so pre-fix the stream produced consecutive byte-identical usage records. + const dupes = turnEvents.filter((u, i) => i > 0 && JSON.stringify(u) === JSON.stringify(turnEvents[i - 1])).length; + check('no two consecutive turns report byte-identical usage', dupes === 0, `${dupes} duplicate pair(s)`); + + // The token axis: every turn of a session has a strictly growing cached prefix, so a per-block + // repeat would show up as a flat input side. Report it rather than assert a model-dependent shape. + console.log(` per-turn output tokens: [${turnEvents.map((u) => u.outputTokens).join(', ')}]`); + + // The token axis a wired gate actually sums: every per-turn event plus the closing residual. A + // turn's own `message.usage` is an early snapshot the CLI never revises, so the per-turn sum alone + // is SHORT — the closing event must make up exactly the difference, on the real wire. + const tot = (k) => allUsage.reduce((a, u) => a + (Number(u[k]) || 0), 0); + const m = out.metrics.tokens ?? {}; + console.log(` gate would sum: in=${tot('inputTokens')} out=${tot('outputTokens')} cread=${tot('cacheReadTokens')} ccreate=${tot('cacheCreationTokens')}`); + console.log(` CLI session total: ${JSON.stringify(m)}`); + const turnsOnly = turnEvents.reduce((a, u) => a + (Number(u.outputTokens) || 0), 0); + check('the per-turn snapshots really ARE short of the total (else this proves nothing)', + turnsOnly < m.output, `per-turn ${turnsOnly} vs session ${m.output}`); + check('per-turn events + the closing residual add up to the CLI\'s own session total', + tot('inputTokens') === m.input && tot('outputTokens') === m.output + && tot('cacheReadTokens') === m.cacheRead && tot('cacheCreationTokens') === m.cacheCreation, + `${tot('outputTokens')} vs ${m.output} output`); +} + +// ── Case 2 — the bound is named, and the work survives it ──────────────────────────────────────── +console.log('\nCASE 2 — a bounded session stops NAMED and keeps its work'); +{ + let served = 0; + const provider = new CLIPipeProvider({ + command: 'claude', + args: ['--model', 'sonnet'], + toolProtocol: 'claude-mcp', + maxTurns: 3, + }); + + const out = await new Loop({ + provider, + system: 'You advance a chain with the chain_step tool. Call it with token "start", then keep ' + + 'calling it with the token from the previous result, ONE CALL AT A TIME, until a result has ' + + 'done:true. Before each call, write one short sentence saying which step you are on.', + }).run( + [{ role: 'user', content: 'Advance the chain to completion (it needs about 12 steps) and report the final token.' }], + [{ + name: 'chain_step', + description: 'Advance the chain. Pass the token you were last given (or "start"). Returns the next token.', + parameters: { type: 'object', properties: { token: { type: 'string' } }, required: ['token'] }, + execute: async ({ token }) => { + served++; + const n = token === 'start' ? 1 : (Number(String(token).split('-')[1]) || 0) + 1; + return JSON.stringify(n >= 12 ? { next: `FINAL-${n}`, done: true } : { next: `tok-${n}`, done: false }); + }, + }], + ); + + console.log(` observed: error=${out.error} stopReason=${out.stopReason} turns=${out.metrics.sessionTurns} calls=${served}`); + console.log(` text kept: ${JSON.stringify(String(out.text).slice(0, 140))}`); + + check('the task really could not finish inside the bound', served < 12, `${served} of 12 steps`); + check("the stop is the NAMED bound, never a silent clean success", out.error === 'max_turns', `error=${out.error}`); + check("stopReason is 'max_turns'", out.stopReason === 'max_turns', `stopReason=${out.stopReason}`); + check('the bound did not exceed what was advertised', out.metrics.sessionTurns <= 3, `${out.metrics.sessionTurns} turns vs maxTurns 3`); + check('BA-5: the work survives the bound (the CLI reports result:null here)', + typeof out.text === 'string' && out.text.length > 0, `${String(out.text).length} chars`); +} + +console.log(`\n${failures === 0 ? 'ALL GREEN' : `${failures} FAILURE(S)`}`); +process.exit(failures === 0 ? 0 : 1); diff --git a/src/provider-clipipe-mcp.js b/src/provider-clipipe-mcp.js index f0c4b02..fd82b1b 100644 --- a/src/provider-clipipe-mcp.js +++ b/src/provider-clipipe-mcp.js @@ -257,6 +257,13 @@ const SUBTYPE_MAP = { error_during_execution: { stopReason: null, error: 'session_error' }, }; +/** + * Terminals WE impose that ARE stop reasons in the neutral vocabulary. A guard terminal + * (`denied:`/`stuck:`) is deliberately absent — those are faults, not stop reasons. + * @type {Record} + */ +const TERMINAL_STOP = { max_turns: 'max_turns' }; + /** * @param {string|null|undefined} subtype * @returns {{stopReason: string|null, error: string|null}} @@ -291,7 +298,15 @@ function classifySubtype(subtype) { */ function resolveSessionError(facts) { const fromSubtype = classifySubtype(facts.subtype); - if (facts.terminal) return { stopReason: fromSubtype.stopReason, error: facts.terminal }; + if (facts.terminal) { + // A terminal WE imposed kills the session before its `result` event, so there is no subtype to + // read a stop reason from. Where the terminal IS a stop reason in the neutral vocabulary, say so + // — a consumer branching on `stopReason` must not see `null` for a bound it asked for. + // Own-property only: same proto-key footgun as SUBTYPE_MAP. + const named = Object.prototype.hasOwnProperty.call(TERMINAL_STOP, facts.terminal) + ? TERMINAL_STOP[facts.terminal] : null; + return { stopReason: named || fromSubtype.stopReason, error: facts.terminal }; + } const bridgeBroken = facts.bridgeDown || (Number.isFinite(facts.attempted) && Number.isFinite(facts.served) && facts.attempted > facts.served); if (bridgeBroken) return { stopReason: fromSubtype.stopReason, error: 'bridge-failed' }; @@ -302,6 +317,21 @@ function resolveSessionError(facts) { /** * Line-oriented processor for the CLI's `stream-json` stdout. * + * ONE TURN IS ONE ASSISTANT MESSAGE, NOT ONE EVENT (BA-17). Measured on the real wire: the CLI + * emits a SEPARATE `assistant` event per content BLOCK of the same message, and every one of them + * repeats that message's `usage` verbatim — one 13-block message arrived as 13 events carrying the + * same numbers. Treating each event as a turn is wrong on both axes a caller meters: + * - the TURN axis — a caller whose attempt bound is an LLM-turn count sees 14 "turns" for 2 real + * ones (measured 7×; 4.4× on the adopter's failing run), so its net guillotines + * the session at a fraction of the allowance it advertised; + * - the TOKEN axis — the same message's usage is added once per block (measured 5.04× inflated + * against the CLI's own session total), so a budget cap fires early on tokens + * that were never spent. + * So a RUN of consecutive events sharing `message.id` is ONE turn: usage is recorded once and one + * `onTurn` fires. Adjacent-run dedup, not a Set — an id that somehow recurred later must still count + * as a new turn (dropping a real turn is the failure that matters). An event with NO id degrades to + * one-turn-per-event: the pre-BA-17 behaviour, never a collapse of the whole session into one turn. + * * FRAMING IS SYNCHRONOUS. The obvious shape — an `async` stdout handler that `await`s `onTurn` * inside its parse loop — has a data-corruption bug: while the `await` is suspended, the next * `'data'` event re-enters the handler and mutates the SHARED line buffer, so the suspended parse @@ -317,11 +347,28 @@ function resolveSessionError(facts) { * @param {any} o.ctx * @param {number} o.startedAt * @param {(err: Error) => void} o.onHalt - called if a forwarded `onTurn` throws a HaltError. + * @param {number|null} [o.turnCap] - BA-17 backstop: fires `onLimit` the moment a turn BEYOND this + * many is observed. Deliberately not `>=`: `--max-turns` is passed to the CLI too, and when it + * works (measured: it does, and it counts assistant turns) the CLI ends the session ITSELF at the + * cap and emits its `result` event — which is the only place the authoritative session cost + * arrives. Killing the session at exactly N would throw that figure away on every bounded run. So + * this fires ONLY on an overrun, i.e. only if the flag ever stops working — it is undocumented in + * `claude --help`, so the guarantee cannot rest on it alone. + * @param {(() => void)} [o.onLimit] - called once when `turnCap` is exceeded. */ -function createSessionStream({ onTurn, ctx, startedAt, onHalt }) { +function createSessionStream({ onTurn, ctx, startedAt, onHalt, turnCap = null, onLimit = () => {} }) { let buf = ''; let attempted = 0; let final = null; + /** Adjacent-run dedup key: the `message.id` of the turn currently being emitted. */ + let turnId = /** @type {string|null} */ (null); + /** Has the CURRENT turn already contributed its usage? Blocks of one message repeat it. */ + let turnMetered = false; + let turnCount = 0; + let limitFired = false; + /** Text of the current turn, and the last turn that produced any — BA-5 work preservation. */ + let curText = ''; + let lastText = ''; /** @type {import('../types').Usage[]} */ const turns = []; /** @type {any[]} */ const queue = []; /** @type {Promise|null} */ let draining = null; @@ -367,29 +414,59 @@ function createSessionStream({ onTurn, ctx, startedAt, onHalt }) { } } - if (ev.type === 'assistant' && ev.message && ev.message.usage) { - const u = ev.message.usage; - /** @type {import('../types').Usage} */ - const usage = { - inputTokens: Number(u.input_tokens) || 0, - outputTokens: Number(u.output_tokens) || 0, - }; - // Omit an absent tier rather than emit a synthetic 0 (per the Usage contract). - if (Number.isFinite(u.cache_read_input_tokens)) usage.cacheReadTokens = u.cache_read_input_tokens; - if (Number.isFinite(u.cache_creation_input_tokens)) usage.cacheCreationTokens = u.cache_creation_input_tokens; - turns.push(usage); - // Stream it: a session that dies mid-run must already have surfaced every completed turn's - // spend, or the gate loses it. Queued (not awaited here) so framing cannot race the buffer. - if (onTurn) queue.push({ - model: (ev.message && ev.message.model) || null, - provider: 'clipipe', - usage, - costUsd: null, // the CLI prices the SESSION, not the turn — explicitly unpriced, never a synthetic 0. - pricing: 'unpriced', - durationMs: Date.now() - startedAt, - ctx, // what a wired gate records spend against — same as the Loop's onLlmResult. - kind: 'turn', - }); + if (ev.type === 'assistant' && ev.message) { + // Is this event the start of a NEW assistant turn, or another block of the current one? + // No id at all ⇒ its own turn (degrade to the pre-BA-17 shape, never collapse into one). + const id = (typeof ev.message.id === 'string' && ev.message.id) ? ev.message.id : null; + if (id === null || id !== turnId) { + turnId = id; + turnMetered = false; + curText = ''; + turnCount++; + // The overrun backstop. `>` not `>=`, so a CLI that honours --max-turns keeps its clean + // exit (and with it the only report of the session's real cost). + if (!limitFired && Number.isFinite(turnCap) && Number(turnCap) > 0 && turnCount > Number(turnCap)) { + limitFired = true; + onLimit(); + } + } + + // BA-5: keep the turn's own words, so a bound/guard stop still returns the work done. The + // CLI reports `result: null` on a bounded session — measured — so this is the ONLY source. + for (const block of (ev.message.content || [])) { + if (block && block.type === 'text' && typeof block.text === 'string' && block.text) { + curText += block.text; + lastText = curText; + } + } + + // Usage rides on EVERY block-event of the message; count it once per turn. Read on any + // event of the turn (not just the first) — the first block need not be the one carrying it. + if (ev.message.usage && !turnMetered) { + turnMetered = true; + const u = ev.message.usage; + /** @type {import('../types').Usage} */ + const usage = { + inputTokens: Number(u.input_tokens) || 0, + outputTokens: Number(u.output_tokens) || 0, + }; + // Omit an absent tier rather than emit a synthetic 0 (per the Usage contract). + if (Number.isFinite(u.cache_read_input_tokens)) usage.cacheReadTokens = u.cache_read_input_tokens; + if (Number.isFinite(u.cache_creation_input_tokens)) usage.cacheCreationTokens = u.cache_creation_input_tokens; + turns.push(usage); + // Stream it: a session that dies mid-run must already have surfaced every completed turn's + // spend, or the gate loses it. Queued (not awaited here) so framing cannot race the buffer. + if (onTurn) queue.push({ + model: ev.message.model || null, + provider: 'clipipe', + usage, + costUsd: null, // the CLI prices the SESSION, not the turn — explicitly unpriced, never a synthetic 0. + pricing: 'unpriced', + durationMs: Date.now() - startedAt, + ctx, // what a wired gate records spend against — same as the Loop's onLlmResult. + kind: 'turn', + }); + } } if (ev.type === 'result') final = ev; @@ -399,6 +476,10 @@ function createSessionStream({ onTurn, ctx, startedAt, onHalt }) { /** Await every queued per-turn forward — call before resolving the session. */ async flush() { if (draining) await draining; await drain(); }, get turns() { return turns; }, + /** Assistant TURNS observed — including any that carried no usage. */ + get turnCount() { return turnCount; }, + /** The last turn's text. The work a bounded/guard-stopped session still did (BA-5). */ + get lastText() { return lastText; }, get attempted() { return attempted; }, get final() { return final; }, }; @@ -452,11 +533,18 @@ function runSession(opts) { const child = spawn(command, args, { cwd, env, stdio: ['pipe', 'pipe', 'pipe'] }); let stderr = '', settled = false; /** @type {Error|null} */ let turnHalt = null; + /** @type {string|null} A terminal WE imposed from the stream (today: the BA-17 turn backstop). */ + let terminal = null; const started = Date.now(); /** Kill the session now — a guard tripped or governance halted mid-flight. */ const abort = () => { try { child.kill('SIGTERM'); } catch (_) { /* already gone */ } }; - const stream = createSessionStream({ onTurn, ctx, startedAt: started, onHalt: (err) => { turnHalt = err; abort(); } }); + const stream = createSessionStream({ + onTurn, ctx, startedAt: started, + onHalt: (err) => { turnHalt = err; abort(); }, + turnCap: Number.isFinite(maxTurns) ? maxTurns : null, + onLimit: () => { terminal = 'max_turns'; abort(); }, + }); const done = async (extra = {}) => { if (settled) return; @@ -465,7 +553,11 @@ function runSession(opts) { // Flush queued per-turn forwards before resolving — a session that ends while a forward is // pending must still surface that turn's spend to the gate (F12/F18). try { await stream.flush(); } catch (_) { /* onTurn failures are surfaced in-drain, never fatal */ } - resolve({ turns: stream.turns, final: stream.final, stderr, ms: Date.now() - started, turnHalt, attempted: stream.attempted, ...extra }); + resolve({ + turns: stream.turns, turnCount: stream.turnCount, lastText: stream.lastText, + final: stream.final, stderr, ms: Date.now() - started, turnHalt, terminal, + attempted: stream.attempted, ...extra, + }); }; const timer = setTimeout(() => { diff --git a/src/provider-clipipe.js b/src/provider-clipipe.js index 5910450..3e9ad4a 100644 --- a/src/provider-clipipe.js +++ b/src/provider-clipipe.js @@ -43,8 +43,16 @@ const { createBridge, resolveSessionError, runSession } = require('./provider-cl * sum-at-end: a session that dies mid-run must already have surfaced every completed turn's spend or * the gate loses all of it. The event shape mirrors `Loop({onLlmResult})`, so `wireGate(gate).onLlmResult` * drops straight in — and when it is wired the Loop skips its own forward, so nothing is billed twice. - * @property {number} [maxTurns] - (native mode) Maps to the CLI's `--max-turns`. The bound stop is NAMED - * (`error_max_turns` → `session.error:'max_turns'`), never a silent clean success. + * @property {number} [maxTurns] - (native mode) Bound on ASSISTANT/LLM TURNS — the same unit as the + * Loop path's turn bound, so a caller's `maxTurns` means one thing on both surfaces (BA-17). NOT a + * tool-call count: a single turn may issue a dozen parallel tool calls and still be one turn + * (measured: 12 calls across 2 turns, well inside `--max-turns 3`). Enforced twice on purpose — + * the CLI's own `--max-turns` stops the session cleanly at N and emits its result event (the only + * report of the session's real cost), and a parent-side counter kills it if a turn beyond N is + * ever observed, since that flag is undocumented in `claude --help` and a rename would otherwise + * silently unbound the session. Either way the stop is NAMED (`session.error:'max_turns'`, + * `stopReason:'max_turns'`) and carries the last turn's text forward, never a silent clean success + * and never an empty result. * @property {number} [maxConsecutiveDenials=3] - (native mode) BA-11 at the bridge: a single deny stays * advisory so the model can pivot to an allowed tool; N in a row with no allowed call between ends the * session with `denied:`. `0`/`Infinity` disables. @@ -66,6 +74,31 @@ const { createBridge, resolveSessionError, runSession } = require('./provider-cl * @property {boolean} [probeCapability=true] - (EMULATION tool mode only) On the first tool-mode `generate`, run ONE cheap upfront probe that asks the model to obtain unknowable info via a tool. If it answers in prose instead of emitting a tool_call, throw a loud `ProviderError` naming the model — FAIL FAST rather than silently degrade mid-run (the weak-model failure mode). Behaviour-based, never a model name-list (a roster goes stale, BA-10). The verdict is cached per instance (one probe per provider, not per turn). Set `false` to skip when the caller already knows the model is capable. */ +/** + * Session total minus what the per-turn events already reported, per tier, floored at 0. + * + * Floored because a negative would be a CREDIT to a gate's running total — an under-count that + * silently widens a budget cap. If the streamed turns ever overshoot the session total, the honest + * report is "nothing further", never "give some back". + * + * @param {import('../types').Usage} total + * @param {import('../types').Usage[]} streamed + * @returns {import('../types').Usage} + */ +function subtractUsage(total, streamed) { + const sum = (/** @type {keyof import('../types').Usage} */ k) => + streamed.reduce((a, t) => a + (Number(t[k]) || 0), 0); + const at = (/** @type {keyof import('../types').Usage} */ k) => + Math.max(0, (Number(total[k]) || 0) - sum(k)); + /** @type {import('../types').Usage} */ + const out = { inputTokens: at('inputTokens'), outputTokens: at('outputTokens') }; + // Only report a cache tier the session actually had — an absent tier stays absent, never a + // synthetic 0 (the Usage contract). + if (total.cacheReadTokens !== undefined) out.cacheReadTokens = at('cacheReadTokens'); + if (total.cacheCreationTokens !== undefined) out.cacheCreationTokens = at('cacheCreationTokens'); + return out; +} + class CLIPipeProvider { /** * Provider that pipes prompts to a CLI command via stdin and reads stdout. @@ -289,17 +322,25 @@ class CLIPipeProvider { throw new ProviderError(`[CLIPipeProvider] failed to spawn "${this.command}": ${r.spawnError.message}`, /** @type {any} */ ({ status: 0 })); } - /** @type {import('../types').Usage} */ - const usage = { inputTokens: 0, outputTokens: 0, cacheReadTokens: 0, cacheCreationTokens: 0 }; - for (const t of r.turns) { - usage.inputTokens += t.inputTokens || 0; - usage.outputTokens += t.outputTokens || 0; - usage.cacheReadTokens += t.cacheReadTokens || 0; - usage.cacheCreationTokens += t.cacheCreationTokens || 0; - } + // The result event carries the session's authoritative totals. It has no `model` key — the model + // id lives under `modelUsage` — which is exactly what `mapClaudeMeta` already unpacks for the + // emulation path, so the native path reuses it rather than re-deriving three fields by hand. + const meta = r.final ? mapClaudeMeta(r.final) : null; + + // `result.usage` is the authoritative session total and is preferred when present: it also + // captures a turn the CLI billed but never emitted as an event (measured — a bounded session's + // cut-off turn). Summing the per-turn records is the fallback for a session we killed before its + // result event. Either way the arithmetic is per-TURN, never per block-event (BA-17). + const usage = (meta && r.final.usage) ? meta.usage : r.turns.reduce((/** @type {any} */ a, t) => ({ + inputTokens: a.inputTokens + (t.inputTokens || 0), + outputTokens: a.outputTokens + (t.outputTokens || 0), + cacheReadTokens: a.cacheReadTokens + (t.cacheReadTokens || 0), + cacheCreationTokens: a.cacheCreationTokens + (t.cacheCreationTokens || 0), + }), { inputTokens: 0, outputTokens: 0, cacheReadTokens: 0, cacheCreationTokens: 0 }); const { stopReason, error } = resolveSessionError({ - terminal: st.terminal, + // A bridge/guard terminal is more specific than the turn backstop, so it wins the tag. + terminal: st.terminal || r.terminal, bridgeDown: st.bridgeDown, attempted: r.attempted, served: st.toolCalls, @@ -307,17 +348,25 @@ class CLIPipeProvider { subtype: r.final && r.final.subtype, }); - const costUsd = (r.final && Number.isFinite(r.final.total_cost_usd)) ? r.final.total_cost_usd : null; - - // The authoritative price arrives only at session end (the CLI prices the SESSION, not the turn), - // so when per-turn streaming is wired it gets one closing event carrying the cost with zero - // usage — the tokens were already streamed, and double-counting either axis would be a lie. + const costUsd = (meta && Number.isFinite(meta.costUsd)) ? /** @type {number} */ (meta.costUsd) : null; + + // The authoritative figures arrive only at session end — the CLI prices the SESSION, not the + // turn — so when per-turn streaming is wired, one closing event RECONCILES both axes. + // + // Money: the whole cost, which no turn reported. + // Tokens: the RESIDUAL, not zero and not the total. A turn's `message.usage` is a snapshot taken + // when its first block was emitted and never revised (measured: a turn that emitted ~816 output + // tokens reported 2, identically on all 13 of its block-events), so the streamed per-turn sum is + // real but SHORT of the session total. Sending the difference makes a gate's token axis add up + // to exactly what the CLI itself reports — where sending the total would double-count everything + // already streamed, and sending zero would leave the axis quietly under-fed. + const residual = subtractUsage(usage, r.turns); if (this.onTurn) { try { await this.onTurn({ - model: (r.final && r.final.model) || null, + model: (meta && meta.model) || null, provider: 'clipipe', - usage: { inputTokens: 0, outputTokens: 0 }, + usage: residual, costUsd, pricing: costUsd === null ? 'unpriced' : 'priced', durationMs: r.ms, @@ -329,15 +378,23 @@ class CLIPipeProvider { } } + // BA-5 on the native path: a bound or a tripped guard is normal termination for a bounded + // attempt, and the text is the ONLY channel from this attempt to the next. The CLI reports + // `result: null` when it stops on its own bound (measured), and a session we killed never emits + // a result at all — so fall back to the last assistant turn's own words rather than ''. + const finalText = (r.final && typeof r.final.result === 'string' && r.final.result) + ? r.final.result + : (r.lastText || ''); + /** @type {GenerateResult} */ const result = { - text: (r.final && typeof r.final.result === 'string') ? r.final.result : '', + text: finalText, toolCalls: [], usage, - model: (r.final && r.final.model) || null, + model: (meta && meta.model) || null, stopReason, session: { - turns: r.turns.length, + turns: r.turnCount, toolCalls: st.toolCalls, error, // Only true when we ACTUALLY streamed — unwired, the Loop must still forward the total or diff --git a/test/provider-clipipe-mcp.test.js b/test/provider-clipipe-mcp.test.js index 5edbb75..d0049ae 100644 --- a/test/provider-clipipe-mcp.test.js +++ b/test/provider-clipipe-mcp.test.js @@ -472,3 +472,345 @@ describe('BA-16 — provider construction', () => { assert.throws(() => new CLIPipeProvider({ command: 'claude', toolProtocol: 'codex' }), /unknown toolProtocol/); }); }); + +// ───────────────────────────────────────────────────────────────────────────────────────────────── +// BA-17 — one turn is one assistant MESSAGE, not one stream event. +// +// Measured on the real wire (poc/ba17-turn-unit.mjs, poc/ba17-unit-parallel.mjs): the CLI emits a +// SEPARATE `assistant` event per content block of the same message, each repeating that message's +// `usage`. One 13-block message arrived as 13 events. Counting events as turns inflated the turn +// axis 7× and the token axis 5.04× against the CLI's own session total — which is what actually +// guillotined the adopter's 8-turn scout at real turn ~4, not any failure of `--max-turns`. +// ───────────────────────────────────────────────────────────────────────────────────────────────── + +/** One `assistant` stream event, shaped exactly as the CLI emits it. */ +const asstEvent = (id, { usage, text, toolUse, model } = {}) => { + /** @type {any} */ const content = []; + if (text !== undefined) content.push({ type: 'text', text }); + if (toolUse) content.push({ type: 'tool_use', name: 'mcp__bareagent__x' }); + /** @type {any} */ const message = { content }; + if (id !== null) message.id = id; + if (model) message.model = model; + if (usage) message.usage = usage; + return JSON.stringify({ type: 'assistant', message }); +}; +const u = (out) => ({ input_tokens: 2, output_tokens: out, cache_read_input_tokens: 10, cache_creation_input_tokens: 1 }); + +describe('BA-17 — a turn is a message, not an event', () => { + test('a message emitted as SEVERAL block-events is ONE turn, metered ONCE', async () => { + const seen = []; + const s = createSessionStream({ onTurn: async (e) => { seen.push(e.usage.outputTokens); }, ctx: null, startedAt: Date.now(), onHalt: () => {} }); + // The measured shape: same id, same usage, one event per block. + s.feed(asstEvent('msg_1', { usage: u(60), text: 'thinking out loud' }) + '\n'); + s.feed(asstEvent('msg_1', { usage: u(60), toolUse: true }) + '\n'); + s.feed(asstEvent('msg_1', { usage: u(60), toolUse: true }) + '\n'); + await s.flush(); + assert.strictEqual(s.turnCount, 1, 'three events, one assistant message, ONE turn'); + assert.strictEqual(s.turns.length, 1, 'and its usage is recorded once, not three times'); + assert.deepStrictEqual(seen, [60], 'the caller is told about one turn, not three'); + assert.strictEqual(s.attempted, 2, 'tool_use blocks still count individually — that axis IS per call'); + }); + + test('distinct message ids are distinct turns', async () => { + const seen = []; + const s = createSessionStream({ onTurn: async (e) => { seen.push(e.usage.outputTokens); }, ctx: null, startedAt: Date.now(), onHalt: () => {} }); + for (const [id, out] of [['a', 1], ['a', 1], ['b', 2], ['c', 3], ['c', 3]]) s.feed(asstEvent(`msg_${id}`, { usage: u(out) }) + '\n'); + await s.flush(); + assert.strictEqual(s.turnCount, 3); + assert.deepStrictEqual(seen, [1, 2, 3]); + }); + + test('an id that RECURS after another turn counts again (adjacent-run dedup, not a Set)', async () => { + // Dropping a real turn is the failure that matters; a Set would silently swallow this one. + const s = createSessionStream({ onTurn: null, ctx: null, startedAt: Date.now(), onHalt: () => {} }); + for (const id of ['a', 'b', 'a']) s.feed(asstEvent(`msg_${id}`, { usage: u(1) }) + '\n'); + await s.flush(); + assert.strictEqual(s.turnCount, 3); + assert.strictEqual(s.turns.length, 3); + }); + + test('events with NO id degrade to one-turn-per-event, never a collapse into one', async () => { + // The pre-BA-17 behaviour, kept exactly: an unknown shape must not silently zero the turn axis. + const s = createSessionStream({ onTurn: null, ctx: null, startedAt: Date.now(), onHalt: () => {} }); + for (let i = 0; i < 4; i++) s.feed(asstEvent(null, { usage: u(i) }) + '\n'); + await s.flush(); + assert.strictEqual(s.turnCount, 4, 'no id ⇒ each event is its own turn'); + assert.strictEqual(s.turns.length, 4); + }); + + test("usage arriving on a LATER block of a turn is still recorded (once)", async () => { + const s = createSessionStream({ onTurn: null, ctx: null, startedAt: Date.now(), onHalt: () => {} }); + s.feed(asstEvent('msg_1', { text: 'no usage on this block' }) + '\n'); + s.feed(asstEvent('msg_1', { usage: u(42) }) + '\n'); + s.feed(asstEvent('msg_1', { usage: u(42) }) + '\n'); + await s.flush(); + assert.strictEqual(s.turnCount, 1); + assert.deepStrictEqual(s.turns.map((t) => t.outputTokens), [42], 'the first block need not be the one carrying usage'); + }); + + test('the four cache tiers survive per-turn dedup', async () => { + const s = createSessionStream({ onTurn: null, ctx: null, startedAt: Date.now(), onHalt: () => {} }); + s.feed(asstEvent('msg_1', { usage: u(60) }) + '\n'); + s.feed(asstEvent('msg_1', { usage: u(60) }) + '\n'); + await s.flush(); + assert.deepStrictEqual(s.turns[0], { inputTokens: 2, outputTokens: 60, cacheReadTokens: 10, cacheCreationTokens: 1 }); + }); +}); + +describe('BA-17 — the parent-side turn backstop', () => { + const cap3 = (onLimit) => createSessionStream({ onTurn: null, ctx: null, startedAt: Date.now(), onHalt: () => {}, turnCap: 3, onLimit }); + + test('it does NOT fire at the cap — the CLI gets to end cleanly and report its cost', async () => { + let fired = 0; + const s = cap3(() => { fired++; }); + for (const id of ['a', 'b', 'c']) s.feed(asstEvent(`msg_${id}`, { usage: u(1) }) + '\n'); + await s.flush(); + assert.strictEqual(s.turnCount, 3); + assert.strictEqual(fired, 0, 'exactly N turns is the bound being HONOURED, not overrun'); + }); + + test('it fires the moment a turn BEYOND the cap appears', async () => { + let fired = 0; + const s = cap3(() => { fired++; }); + for (const id of ['a', 'b', 'c', 'd']) s.feed(asstEvent(`msg_${id}`, { usage: u(1) }) + '\n'); + await s.flush(); + assert.strictEqual(fired, 1, 'the flag failed to bound — the backstop is the guarantee'); + }); + + test('it fires ONCE even if the session keeps going', async () => { + let fired = 0; + const s = cap3(() => { fired++; }); + for (const id of ['a', 'b', 'c', 'd', 'e', 'f']) s.feed(asstEvent(`msg_${id}`, { usage: u(1) }) + '\n'); + await s.flush(); + assert.strictEqual(fired, 1); + }); + + test('block-events of the SAME turn cannot trip it (the whole point)', async () => { + // Pre-BA-17 this is exactly what went wrong: 13 events of one message read as 13 turns. + let fired = 0; + const s = cap3(() => { fired++; }); + for (let i = 0; i < 13; i++) s.feed(asstEvent('msg_1', { usage: u(1), toolUse: true }) + '\n'); + await s.flush(); + assert.strictEqual(s.turnCount, 1); + assert.strictEqual(fired, 0, 'one turn with 13 blocks is one turn, whatever the cap'); + }); + + for (const [label, turnCap] of [['null', null], ['0', 0], ['Infinity', Infinity], ['undefined', undefined]]) { + test(`turnCap ${label} disables the backstop`, async () => { + let fired = 0; + const s = createSessionStream({ onTurn: null, ctx: null, startedAt: Date.now(), onHalt: () => {}, turnCap, onLimit: () => { fired++; } }); + for (const id of ['a', 'b', 'c', 'd', 'e']) s.feed(asstEvent(`msg_${id}`, { usage: u(1) }) + '\n'); + await s.flush(); + assert.strictEqual(fired, 0); + }); + } +}); + +describe('BA-17 — a bounded session still returns its work (BA-5)', () => { + test('lastText is the last turn that produced words', async () => { + const s = createSessionStream({ onTurn: null, ctx: null, startedAt: Date.now(), onHalt: () => {} }); + s.feed(asstEvent('msg_1', { usage: u(1), text: 'first pass' }) + '\n'); + s.feed(asstEvent('msg_2', { usage: u(1), text: 'second pass' }) + '\n'); + await s.flush(); + assert.strictEqual(s.lastText, 'second pass'); + }); + + test('several text blocks in ONE turn accumulate into that turn', async () => { + const s = createSessionStream({ onTurn: null, ctx: null, startedAt: Date.now(), onHalt: () => {} }); + s.feed(asstEvent('msg_1', { usage: u(1), text: 'part one. ' }) + '\n'); + s.feed(asstEvent('msg_1', { usage: u(1), text: 'part two.' }) + '\n'); + await s.flush(); + assert.strictEqual(s.lastText, 'part one. part two.'); + }); + + test('a wordless final turn does not erase the last text there WAS', async () => { + // The measured bounded shape: the cut-off turn is pure tool_use, and `result.result` is null. + const s = createSessionStream({ onTurn: null, ctx: null, startedAt: Date.now(), onHalt: () => {} }); + s.feed(asstEvent('msg_1', { usage: u(1), text: 'the answer so far' }) + '\n'); + s.feed(asstEvent('msg_2', { usage: u(1), toolUse: true }) + '\n'); + await s.flush(); + assert.strictEqual(s.lastText, 'the answer so far', 'the work must survive the bound'); + }); + + test('no text at all is an empty string, never undefined', async () => { + const s = createSessionStream({ onTurn: null, ctx: null, startedAt: Date.now(), onHalt: () => {} }); + s.feed(asstEvent('msg_1', { usage: u(1), toolUse: true }) + '\n'); + await s.flush(); + assert.strictEqual(s.lastText, ''); + }); +}); + +describe('BA-17 — a terminal we impose carries its own stop reason', () => { + test('the turn backstop reports stopReason max_turns, not null', () => { + // We kill the session, so there is no `result` event and no subtype to read one from. + const out = resolveSessionError({ terminal: 'max_turns', bridgeDown: false, attempted: 0, served: 0, timedOut: false, subtype: undefined }); + assert.deepStrictEqual(out, { stopReason: 'max_turns', error: 'max_turns' }); + }); + + test('a guard terminal is a FAULT, not a stop reason', () => { + const out = resolveSessionError({ terminal: 'denied:writer', bridgeDown: false, attempted: 0, served: 0, timedOut: false, subtype: undefined }); + assert.strictEqual(out.error, 'denied:writer'); + assert.strictEqual(out.stopReason, null, 'only names in the neutral vocabulary become a stopReason'); + }); + + test('a terminal named like an Object.prototype key resolves to nothing (proto-key guard)', () => { + const out = resolveSessionError({ terminal: 'toString', bridgeDown: false, attempted: 0, served: 0, timedOut: false, subtype: 'success' }); + assert.strictEqual(out.error, 'toString'); + assert.strictEqual(out.stopReason, 'end_turn', 'inherited props must never be mistaken for a mapping'); + }); +}); + +// ───────────────────────────────────────────────────────────────────────────────────────────────── +// BA-17 — end to end through the provider, against a fake CLI that speaks the REAL stream-json +// shape captured in poc/ba17-turn-unit.mjs (block-events sharing one message.id and one usage). +// ───────────────────────────────────────────────────────────────────────────────────────────────── + +const fs = require('fs'); +const os = require('os'); +const path = require('path'); + +/** A stand-in `claude` that prints the given stream-json lines, then optionally hangs. */ +function fakeCli(lines, { hang = false } = {}) { + const dir = fs.mkdtempSync(path.join(os.tmpdir(), 'ba17-cli-')); + const p = path.join(dir, 'cli.js'); + fs.writeFileSync(p, ` + process.stdin.resume(); + for (const l of ${JSON.stringify(lines)}) process.stdout.write(l + '\\n'); + ${hang ? 'setTimeout(() => {}, 60000);' : 'process.exit(0);'} + `); + return p; +} + +const nativeProvider = (cliPath, opts = {}) => new CLIPipeProvider({ + command: process.execPath, args: [cliPath], toolProtocol: 'claude-mcp', ...opts, +}); + +describe('BA-17 — what the caller actually receives', () => { + // The exact shape the CLI produced under `--max-turns`: one multi-block message, a wordless + // cut-off turn, and a result event with `result: null`. + const boundedSession = [ + JSON.stringify({ type: 'assistant', message: { id: 'm1', model: 'claude-sonnet-5', usage: { input_tokens: 2, output_tokens: 60, cache_read_input_tokens: 100, cache_creation_input_tokens: 5 }, content: [{ type: 'text', text: 'Here is what I found so far.' }] } }), + JSON.stringify({ type: 'assistant', message: { id: 'm1', model: 'claude-sonnet-5', usage: { input_tokens: 2, output_tokens: 60, cache_read_input_tokens: 100, cache_creation_input_tokens: 5 }, content: [{ type: 'thinking', thinking: '...' }] } }), + JSON.stringify({ type: 'assistant', message: { id: 'm1', model: 'claude-sonnet-5', usage: { input_tokens: 2, output_tokens: 60, cache_read_input_tokens: 100, cache_creation_input_tokens: 5 }, content: [{ type: 'thinking', thinking: '...' }] } }), + JSON.stringify({ type: 'assistant', message: { id: 'm2', model: 'claude-sonnet-5', usage: { input_tokens: 3, output_tokens: 40, cache_read_input_tokens: 200, cache_creation_input_tokens: 7 }, content: [{ type: 'thinking', thinking: 'cut off here' }] } }), + JSON.stringify({ type: 'result', subtype: 'error_max_turns', is_error: true, result: null, num_turns: 5, total_cost_usd: 0.0123, modelUsage: { 'claude-sonnet-5': {} }, usage: { input_tokens: 5, output_tokens: 166, cache_read_input_tokens: 300, cache_creation_input_tokens: 12 } }), + ]; + + test('the session reports REAL turns, not stream events', async () => { + const r = await nativeProvider(fakeCli(boundedSession)).generate( + [{ role: 'user', content: 'go' }], [tool('reader', async () => 'x')], + ); + assert.strictEqual(r.session.turns, 2, 'four events, two assistant messages'); + }); + + test('usage is the CLI\'s own session total, not the per-block-event sum', async () => { + const r = await nativeProvider(fakeCli(boundedSession)).generate( + [{ role: 'user', content: 'go' }], [tool('reader', async () => 'x')], + ); + // Per-EVENT summing (the 0.33.0 bug) would give input 9 / output 220 / read 500 / creation 22. + assert.deepStrictEqual(r.usage, { inputTokens: 5, outputTokens: 166, cacheReadTokens: 300, cacheCreationTokens: 12 }); + }); + + test('a bounded stop is named AND keeps the work (BA-5)', async () => { + const r = await nativeProvider(fakeCli(boundedSession)).generate( + [{ role: 'user', content: 'go' }], [tool('reader', async () => 'x')], + ); + assert.strictEqual(r.session.error, 'max_turns', 'never a silent clean success'); + assert.strictEqual(r.stopReason, 'max_turns'); + assert.strictEqual(r.text, 'Here is what I found so far.', 'the CLI reports result:null here — the work must still come back'); + }); + + test('the model id is read from modelUsage, which is where the result event puts it', async () => { + const r = await nativeProvider(fakeCli(boundedSession)).generate( + [{ role: 'user', content: 'go' }], [tool('reader', async () => 'x')], + ); + assert.strictEqual(r.model, 'claude-sonnet-5'); + assert.strictEqual(r.costUsd, 0.0123); + }); + + test('onTurn fires once per TURN and once for the session — not once per block', async () => { + const seen = []; + const p = nativeProvider(fakeCli(boundedSession), { onTurn: async (e) => { seen.push(e.kind); } }); + await p.generate([{ role: 'user', content: 'go' }], [tool('reader', async () => 'x')]); + assert.deepStrictEqual(seen, ['turn', 'turn', 'session'], 'a gate must not be billed per content block'); + }); + + test('a CLI that overruns its own bound is killed by the backstop, named and with its work', async () => { + // The failure the flag being undocumented would cause: it stops honouring --max-turns. Three + // turns arrive against maxTurns:2, then the CLI hangs — nothing here ends the session but us. + const turn = (id) => JSON.stringify({ type: 'assistant', message: { id, usage: { input_tokens: 1, output_tokens: 5 }, content: [{ type: 'text', text: `work from ${id}` }] } }); + const p = nativeProvider(fakeCli([turn('m1'), turn('m2'), turn('m3')], { hang: true }), { maxTurns: 2, sessionTimeout: 20000 }); + const r = await p.generate([{ role: 'user', content: 'go' }], [tool('reader', async () => 'x')]); + assert.strictEqual(r.session.error, 'max_turns', 'the bound is OUR guarantee, not the flag\'s'); + assert.strictEqual(r.stopReason, 'max_turns'); + assert.strictEqual(r.text, 'work from m3', 'a killed session still returns the last turn it produced'); + // No result event to read totals from — the per-turn records are the honest fallback. + assert.strictEqual(r.usage.outputTokens, 15); + assert.strictEqual(r.costUsd, undefined, 'we killed it before it priced itself — never a synthetic 0'); + }); + + // The turn axis and the usage axis are NOT the same count. If a turn ever arrives without usage + // we cannot meter it — but it still happened, and it still spends the caller's bound. Counting it + // as "not a turn" would under-report the bound in the optimistic direction, which is the whole + // family of bug this module keeps closing. + test('a turn that carries no usage is still a turn against the bound', async () => { + const withUsage = (id) => JSON.stringify({ type: 'assistant', message: { id, usage: { input_tokens: 1, output_tokens: 5 }, content: [{ type: 'text', text: `t ${id}` }] } }); + const noUsage = (id) => JSON.stringify({ type: 'assistant', message: { id, content: [{ type: 'text', text: `t ${id}` }] } }); + const done = JSON.stringify({ type: 'result', subtype: 'success', result: 'ok', total_cost_usd: 0.001 }); + const r = await nativeProvider(fakeCli([withUsage('m1'), noUsage('m2'), withUsage('m3'), done])) + .generate([{ role: 'user', content: 'go' }], [tool('reader', async () => 'x')]); + assert.strictEqual(r.session.turns, 3, 'three assistant messages happened'); + + // …and the backstop spends the bound on it too. + const hung = await nativeProvider(fakeCli([withUsage('m1'), noUsage('m2'), withUsage('m3')], { hang: true }), { maxTurns: 2, sessionTimeout: 20000 }) + .generate([{ role: 'user', content: 'go' }], [tool('reader', async () => 'x')]); + assert.strictEqual(hung.session.error, 'max_turns', 'an unmeterable turn still breaches the bound'); + }); + + // A turn's `message.usage` is a snapshot taken at its first block and never revised — measured, a + // turn that emitted ~816 output tokens reported 2 — so the streamed per-turn sum is SHORT of the + // session total. The closing event carries the difference, so a gate's token axis adds up. + test('the closing session event carries the token RESIDUAL, not zero and not the total', async () => { + const seen = []; + const turn = (id, out) => JSON.stringify({ type: 'assistant', message: { id, usage: { input_tokens: 1, output_tokens: out, cache_read_input_tokens: 10, cache_creation_input_tokens: 2 }, content: [{ type: 'text', text: 't' }] } }); + const done = JSON.stringify({ type: 'result', subtype: 'success', result: 'ok', total_cost_usd: 0.01, usage: { input_tokens: 5, output_tokens: 800, cache_read_input_tokens: 20, cache_creation_input_tokens: 4 } }); + const p = nativeProvider(fakeCli([turn('m1', 2), turn('m2', 3), done]), { onTurn: async (e) => { seen.push(e); } }); + await p.generate([{ role: 'user', content: 'go' }], [tool('reader', async () => 'x')]); + + const closing = seen[seen.length - 1]; + assert.strictEqual(closing.kind, 'session'); + // Streamed: input 2, output 5, read 20, creation 4. Session total: 5 / 800 / 20 / 4. + assert.deepStrictEqual(closing.usage, { inputTokens: 3, outputTokens: 795, cacheReadTokens: 0, cacheCreationTokens: 0 }); + const summed = seen.reduce((a, e) => a + e.usage.inputTokens + e.usage.outputTokens, 0); + assert.strictEqual(summed, 805, "everything the gate is told must add up to the CLI's own total"); + }); + + test('a residual is never negative — an overshoot reports nothing further, never a credit', async () => { + const seen = []; + const turn = (id, out) => JSON.stringify({ type: 'assistant', message: { id, usage: { input_tokens: 1, output_tokens: out }, content: [{ type: 'text', text: 't' }] } }); + // Session total BELOW the streamed sum — a gate must not be handed a negative to subtract. + const done = JSON.stringify({ type: 'result', subtype: 'success', result: 'ok', usage: { input_tokens: 1, output_tokens: 1 } }); + const p = nativeProvider(fakeCli([turn('m1', 50), turn('m2', 50), done]), { onTurn: async (e) => { seen.push(e); } }); + await p.generate([{ role: 'user', content: 'go' }], [tool('reader', async () => 'x')]); + assert.deepStrictEqual(seen[seen.length - 1].usage, { inputTokens: 0, outputTokens: 0 }); + }); + + test('a session we killed has no authoritative total, so there is no residual to add', async () => { + const seen = []; + const turn = (id) => JSON.stringify({ type: 'assistant', message: { id, usage: { input_tokens: 1, output_tokens: 5 }, content: [{ type: 'text', text: 't' }] } }); + const p = nativeProvider(fakeCli([turn('m1'), turn('m2'), turn('m3')], { hang: true }), { maxTurns: 2, sessionTimeout: 20000, onTurn: async (e) => { seen.push(e); } }); + await p.generate([{ role: 'user', content: 'go' }], [tool('reader', async () => 'x')]); + // The fallback total IS the streamed sum, so every tier nets to zero. It carries all four tiers + // because the summing fallback does (unchanged from 0.33.0), and the residual mirrors its shape. + assert.deepStrictEqual(seen[seen.length - 1].usage, { inputTokens: 0, outputTokens: 0, cacheReadTokens: 0, cacheCreationTokens: 0 }); + }); + + test('a session inside its bound is untouched by the backstop (negative control)', async () => { + const turn = (id) => JSON.stringify({ type: 'assistant', message: { id, usage: { input_tokens: 1, output_tokens: 5 }, content: [{ type: 'text', text: `work from ${id}` }] } }); + const done = JSON.stringify({ type: 'result', subtype: 'success', result: 'all done', num_turns: 9, total_cost_usd: 0.002 }); + const p = nativeProvider(fakeCli([turn('m1'), turn('m2'), done]), { maxTurns: 2 }); + const r = await p.generate([{ role: 'user', content: 'go' }], [tool('reader', async () => 'x')]); + assert.strictEqual(r.session.error, null, 'exactly N turns is the bound honoured, not breached'); + assert.strictEqual(r.text, 'all done'); + }); +});