diff --git a/amplifier_app_cli/session_spawner.py b/amplifier_app_cli/session_spawner.py index 6cbe456..552ced6 100644 --- a/amplifier_app_cli/session_spawner.py +++ b/amplifier_app_cli/session_spawner.py @@ -69,32 +69,182 @@ # dependence on cancellation ordering -- and is REMOVED when the sub-session # completes normally. `get_partial_output` reads a snapshot; nothing here awaits. +# WHY `text` BLOCKS ALONE WERE NOT ENOUGH (model_performance-eem) +# +# This accumulator originally collected `content_block:end` payloads where +# `block["type"] == "text"` and nothing else. Wired correctly, tested on both +# sides, and STRUCTURALLY INCAPABLE of ever firing on a real workload. +# +# Measured by lane k64 across 18 delegate legs in 7 runs +# (openai-evals-team-ci probes/k64-delegate-timeout-eval/TEXT-WINDOW-TABLE.md): +# +# * a leg emits AT MOST ONE `text` block (16 legs: exactly 1; 2 legs: zero); +# * it lands in the final 0.19-0.72 s (mean 0.331 s) of a leg lasting +# 5.4-222.0 s -- about 0.5% of the leg; +# * everything before it is `thinking` (1-25 blocks/leg) and `tool_call` +# (0-5). +# +# So a delegate killed by a per-delegate timeout had, by construction, +# accumulated nothing. The one real timeout k64 observed had done 10 thinking +# blocks, 45 tool calls and 11 provider responses -- and correctly returned +# `partial_available: false`, because there was a great deal of work and no +# *text*. +# +# The accumulator therefore also collects `thinking` and `tool_call` blocks, +# in a SEPARATE channel used only when no assistant text exists at all. That +# split is not tidiness, it is the honesty constraint below. +# +# THE HONESTY CONSTRAINT +# +# The CONSUMER (amplifier-foundation f42f48c) picks its own guidance string +# from `bool(text)`, and that string says the partial "is unfinished work +# salvaged from the agent mid-flight -- it has NOT been checked, concluded, +# or self-reviewed". True of assistant prose. NOT true of raw thinking: prose +# is at least addressed to a reader, private reasoning never was. Handing a +# model its own unreviewed reasoning under that sentence is its own defect. +# +# foundation is a different repo and this change does not cross that boundary, +# so honesty is carried the two ways the PRODUCER owns: +# +# 1. `source` becomes "spawn-accumulator:reasoning", distinct from the +# "spawn-accumulator" a text partial still returns, so a consumer can +# branch without parsing prose; +# 2. the payload labels itself, at the head AND the tail -- the tail because +# foundation truncates to the LAST `partial_max_chars` characters +# (default 20,000), which 25 thinking blocks routinely exceed, so a +# head-only label is lost on exactly the long partials that need it. +# +# A leg that DID emit assistant text still returns the pre-widening record +# byte for byte -- same text, same segments, same source, therefore the same +# guidance string. The widening only reaches cases that previously returned +# nothing at all. + _PARTIAL_OUTPUTS: dict[str, dict] = {} _PARTIAL_MAX_SESSIONS = 64 +# CHOSEN, NOT MEASURED. `chunks` was effectively self-limiting (at most one +# text block per leg); reasoning is not -- k64 saw up to 25 thinking blocks on +# a single leg, and the wall-clock backstop allows legs of hours. Retain the +# most recent reasoning up to this budget, oldest-first, so the registry +# cannot grow without bound. 5x foundation's 20,000-char forward cap: large +# enough that trimming here is not what the consumer sees, small enough that +# 64 concurrent records stay bounded. +_PARTIAL_REASONING_MAX_CHARS = 100_000 + +# Per-tool-call rendering limits. A tool input can carry a whole file body; +# the trace is for "what was it doing", not for replaying the call. +_PARTIAL_TOOL_ARGS_SHOWN = 6 +_PARTIAL_TOOL_ARG_MAX_CHARS = 120 + +_RECOVERED_HEADER = ( + "[RECOVERED FROM AN UNFINISHED DELEGATE -- NOT DRAFT OUTPUT]\n" + "This delegate was killed before it wrote any answer at all. What follows " + "is NOT prose the agent composed for a reader: it is the agent's own " + "private reasoning and the trace of the tool calls it made, recovered " + "from its event stream. None of it was checked, concluded, self-reviewed, " + "or addressed to anyone. Read it as evidence of what the agent was doing " + "and what it had already looked at -- never as a partial answer.\n" +) + +_RECOVERED_FOOTER = ( + "\n[END OF RECOVERED WORK -- unreviewed agent reasoning and tool-call " + "trace, not a partial answer]" +) + + +def _describe_tool_call(block: dict) -> str: + """One line naming a tool call the agent made, with a short argument digest. + + Shape is measured, not assumed: a real `tool_call` block carries + ``{"type", "id", "name", "input", "visibility"}`` -- the arguments live + under ``input``, NOT ``arguments``. + """ + name = block.get("name") or "" + raw = block.get("input") + if not isinstance(raw, dict) or not raw: + return f"{name}()" + parts: list[str] = [] + for key, value in list(raw.items())[:_PARTIAL_TOOL_ARGS_SHOWN]: + # Drop the empties that tool schemas default in; they carry no signal + # and crowd out the arguments that do. + if value is None or value is False or value == "" or value == [] or value == {}: + continue + if isinstance(value, str): + rendered = value + if len(rendered) > _PARTIAL_TOOL_ARG_MAX_CHARS: + rendered = rendered[:_PARTIAL_TOOL_ARG_MAX_CHARS] + "..." + rendered = repr(rendered) + else: + rendered = repr(value) + if len(rendered) > _PARTIAL_TOOL_ARG_MAX_CHARS: + rendered = rendered[:_PARTIAL_TOOL_ARG_MAX_CHARS] + "..." + parts.append(f"{key}={rendered}") + return f"{name}({', '.join(parts)})" + + +def _render_recovered_work(reasoning: list[str], tool_calls: list[str]) -> str: + """Render the no-text channel as a self-labelling payload.""" + sections = [_RECOVERED_HEADER] + if tool_calls: + sections.append( + f"\nTOOL CALLS THE AGENT MADE ({len(tool_calls)}), in order:\n" + + "\n".join(f" {i}. {call}" for i, call in enumerate(tool_calls, 1)) + + "\n" + ) + if reasoning: + sections.append( + f"\nAGENT REASONING ({len(reasoning)} segment(s)) -- unreviewed, " + "never addressed to a reader:\n\n" + "\n\n".join(reasoning) + "\n" + ) + sections.append(_RECOVERED_FOOTER) + return "".join(sections) + + +def _record_has_content(record: dict) -> bool: + """True when anything at all was accumulated, in any channel.""" + return bool( + record.get("chunks") or record.get("reasoning") or record.get("tool_calls") + ) + def get_partial_output(sub_session_id: str) -> dict | None: """``session.partial`` capability: what a sub-session produced before it died. Returns ``{"text", "segments", "source"}`` for a sub-session that was cancelled or timed out mid-flight, or ``None`` when nothing was preserved. - ``segments`` counts preserved assistant text segments, not turns. + + Two channels, and the first that has anything wins: + + * assistant **text** -> exactly the pre-widening record + (``source: "spawn-accumulator"``, ``segments`` counting text segments); + * otherwise the agent's **reasoning and tool-call trace** -> a labelled + payload under ``source: "spawn-accumulator:reasoning"``, with + ``segments`` counting reasoning segments plus tool calls. Reads are destructive -- one delegate call consumes one record -- so the registry cannot grow without bound on a long-lived root session. A record - with no text yet reads as ``None``: "produced nothing" and "produced - nothing recoverable" are the same answer to the consumer. + with nothing in either channel reads as ``None``: "produced nothing" and + "produced nothing recoverable" are the same answer to the consumer, and + the widening must not manufacture a partial out of an empty accumulator. """ record = _PARTIAL_OUTPUTS.pop(sub_session_id, None) if not record: return None chunks = list(record.get("chunks") or ()) - if not chunks: + if chunks: + return { + "text": "".join(chunks), + "segments": len(chunks), + "source": "spawn-accumulator", + } + reasoning = list(record.get("reasoning") or ()) + tool_calls = list(record.get("tool_calls") or ()) + if not reasoning and not tool_calls: return None return { - "text": "".join(chunks), - "segments": len(chunks), - "source": "spawn-accumulator", + "text": _render_recovered_work(reasoning, tool_calls), + "segments": len(reasoning) + len(tool_calls), + "source": "spawn-accumulator:reasoning", } @@ -126,30 +276,55 @@ def _seal_partial(sub_session_id: str, record: dict) -> None: Synchronous by design: awaiting anything while unwinding a timeout risks blocking past the very deadline that caused the unwind. """ - if not record.get("chunks"): + if not _record_has_content(record): return if sub_session_id not in _PARTIAL_OUTPUTS: _publish_partial(sub_session_id, record) + chunks = record.get("chunks") or [] + reasoning = record.get("reasoning") or [] + tool_calls = record.get("tool_calls") or [] logger.warning( - "Sub-session %s did not complete; preserved %d partial text segment(s), %d chars", + "Sub-session %s did not complete; preserved %d assistant text " + "segment(s) (%d chars), %d reasoning segment(s) (%d chars), " + "%d tool call(s)", sub_session_id, - len(record["chunks"]), - sum(len(c) for c in record["chunks"]), + len(chunks), + sum(len(c) for c in chunks), + len(reasoning), + sum(len(r) for r in reasoning), + len(tool_calls), ) +def _trim_reasoning(reasoning: list[str]) -> None: + """Bound retained reasoning in place, dropping oldest segments first. + + Keeps the most recent thinking, which is both the closest to what the + agent was doing when it died and consistent with the consumer's own + tail-keeping truncation. + """ + total = sum(len(segment) for segment in reasoning) + while len(reasoning) > 1 and total > _PARTIAL_REASONING_MAX_CHARS: + total -= len(reasoning.pop(0)) + + def _open_partial(sub_session_id: str, hooks): - """Start accumulating assistant text, published from the first moment. + """Start accumulating the agent's in-flight work, published from the first moment. Returns ``(record, unregister)``. ``unregister`` is ``None`` when there is no hooks coordinator to register against -- in that case nothing can ever be accumulated, so nothing is published either and the consumer correctly degrades to ``partial_available: false``. + Three channels are collected, and only one is ever returned (see + ``get_partial_output``): assistant ``text``, the agent's ``thinking``, and + its ``tool_call`` trace. Collecting the last two is what makes the feature + reachable on a real leg at all -- see the module note above. + The hook is registered at low priority so it observes blocks after the UI has rendered them and never influences rendering. """ - record: dict = {"chunks": []} + record: dict = {"chunks": [], "reasoning": [], "tool_calls": []} if not hooks: return record, None @@ -158,10 +333,22 @@ def _open_partial(sub_session_id: str, hooks): async def _accumulate_partial(event: str, data: dict) -> HookResult: block = data.get("block") - if isinstance(block, dict) and block.get("type") == "text": + if not isinstance(block, dict): + return HookResult() + block_type = block.get("type") + if block_type == "text": text = block.get("text") or "" if text: record["chunks"].append(text) + elif block_type == "thinking": + # Measured shape: a thinking block carries its reasoning under + # `text`, the same field name a text block uses. + text = block.get("text") or "" + if text: + record["reasoning"].append(text) + _trim_reasoning(record["reasoning"]) + elif block_type == "tool_call": + record["tool_calls"].append(_describe_tool_call(block)) return HookResult() unregister = hooks.register( diff --git a/docs/lanes/eem-partial-accumulator-widen/DONE-NOTE.md b/docs/lanes/eem-partial-accumulator-widen/DONE-NOTE.md new file mode 100644 index 0000000..3967cff --- /dev/null +++ b/docs/lanes/eem-partial-accumulator-widen/DONE-NOTE.md @@ -0,0 +1,205 @@ +# DONE-NOTE — `model_performance-eem` · lane `eem-partial-accumulator-widen` + +**Item:** PREREQUISITE ($0, app-cli): the partial-result accumulator collects only `text` blocks, +so a timed-out delegate can never carry a partial. +**Repo:** `microsoft/amplifier-app-cli` · branch `lane/eem-partial-accumulator-widen` · parent `26e5f10` (#297) +**Date:** 2026-09-03 +**Spend:** **$0.00** of a **$0.00** authority. No runs, no container, no DTU, no API calls. +The cap's arithmetic (`0 runs x 0 arms x $0 / 1.00 = $0.00`) closes: this is a pure code change, +and every number below is a **reanalysis of k64's already-purchased captures** ($14.70, already spent), +not a new purchase. + +**Terminal state: RESOLVED (OUTCOME branch A).** Every deliverable is DONE. Nothing was recorded +NOT-POSSIBLE, and the cap never bound — because nothing this item required cost money. + +--- + +## 1. THE DEFECT, AND WHY IT WAS UNREACHABLE BY TEST + +`session_spawner._open_partial._accumulate_partial` collected `content_block:end` payloads where +`block["type"] == "text"` and nothing else. Correctly wired (`session.partial` IS registered), a +correct consumer (foundation `f42f48c`), and **structurally incapable of firing on a real workload**. + +k64 measured it across 18 delegate legs in 7 runs: a leg emits **at most one `text` block**, in the +final 0.19–0.72 s of a 5.4–222.0 s leg. Everything before it is `thinking` (1–25/leg) and `tool_call` +(0–5) — invisible to the filter. + +The cross-repo round-trip test passed anyway, for **two** reasons, and both are now closed: + +1. its fixture sub-session emitted **text** blocks, which real legs do not until they finish; +2. it called `_seal_partial` with a hand-built `{"chunks": [...]}` record — **bypassing `_open_partial` + entirely**, i.e. never running the accumulator whose filter was the whole defect. A test that never + executes the broken code cannot fail on it. (Point 2 is not in the item text; it was found here and + is the more general lesson.) + +--- + +## 2. THE FIX — option (a), picked with evidence; (b) considered and declined + +**Chosen: (a), widen the accumulator**, with the text channel kept strictly separate. + +`_open_partial` now collects three channels — assistant `text`, `thinking`, and a rendered +`tool_call` trace. `get_partial_output` returns the **first channel that has anything**: + +| leg produced | returns | `source` | +|---|---|---| +| assistant text | exactly today's record, field for field | `spawn-accumulator` | +| no text, but thinking and/or tool calls | a labelled reasoning payload | `spawn-accumulator:reasoning` | +| nothing at all | `None` (unchanged) | — | + +Block shapes are **measured, not assumed**, from k64's captures (236 `thinking`, 53 `tool_call`, +38 `text` blocks inspected): `thinking` carries its reasoning under `text` (same field name as a text +block); a `tool_call` carries `{"id", "name", "input", "visibility"}` — arguments live under **`input`**, +not `arguments`. Guessing `arguments` would have produced a silently empty trace. + +**(b) reading the child's `transcript.jsonl` was declined, and here is the reason rather than a +preference.** The transcript is checkpointed on `provider:request`, throttled to one write per 30 s +(`_DEFAULT_CHECKPOINT_INTERVAL_S`), so it lags the live event stream by up to a full window and adds +filesystem I/O plus a `SessionStore` layout dependency to the read path. It buys one thing the +accumulator lacks — tool *results* — and, per §4 below, the accumulator already reaches +`partial_available: true` on **18/18** measured legs without it. (b) is therefore a strictly more +expensive route to a result already obtained. It stays available as a later enrichment if tool +*results* are ever wanted; it is not needed to make the feature reachable. Option (c) collapses to (a) +for the same reason. + +**Memory.** `chunks` was self-limiting (≤1 text block/leg); reasoning is not, and the wall-clock +backstop allows legs of hours. Retained reasoning is bounded at 100,000 chars, oldest-first +(`_PARTIAL_REASONING_MAX_CHARS`). **CHOSEN, NOT MEASURED** — 5× the consumer's 20,000-char forward cap, +so trimming here is never what the consumer sees. + +--- + +## 3. THE GUIDANCE STRING — what was done, and what is foundation's to do + +foundation `f42f48c` picks its guidance from `bool(text)` alone: + +> `_PARTIAL_GUIDANCE`: "…is unfinished work salvaged from the agent mid-flight — it has NOT been +> checked, concluded, or self-reviewed…" + +That is true of assistant prose and **overclaims for raw thinking**: unfinished prose was at least +addressed to a reader; private reasoning never was. Handing a model its own unreviewed reasoning under +that sentence is its own defect, exactly as the item warned. + +**This lane stops at the repo boundary and reports.** What the producer owns, it did: + +1. **`partial_source` distinguishes the kinds** — `spawn-accumulator` vs `spawn-accumulator:reasoning` + — so a consumer can branch **without parsing prose**; +2. **the payload labels itself, at head AND tail.** The tail matters: foundation truncates to the + **last** `partial_max_chars` (default 20,000), and 25 thinking blocks routinely exceed that, so a + head-only label is lost on exactly the long partials that most need it. A test pins the footer's + survival through a >20,000-char tail cut. + +### REPORTED, NOT CROSSED — the change that belongs in `amplifier-foundation` + +`modules/tool-delegate/amplifier_module_tool_delegate/__init__.py`, `_partial_output_fields`: +select the guidance on the **kind** of partial, not only on `bool(text)`. Concretely, add a third +string used when `partial.get("source")` ends in `:reasoning`, saying the content is the agent's +own private reasoning and tool trace — evidence of what it was doing — rather than "unfinished work". +Two lines and a constant; it needs a foundation PR and is **not** made here. + +Until it lands, `test_guidance_string_for_the_reasoning_case_is_foundations_to_change` (in the +round-trip file) **asserts today's real behaviour**, so the day foundation changes the string this +check fails loudly instead of drifting silently. + +--- + +## 4. IS `partial_available: true` REACHABLE ON A REAL LEG SHAPE? — YES, measured + +Full table: `evidence/07-real-leg-reachability.md`. Recomputed from k64's own captures, $0, no new runs, +same 18 delegate legs. + +| | before (text only) | after (widened) | +|---|---|---| +| legs that could ever recover anything | **16/18** | **18/18** | +| recoverable share of a leg, mean | **0.05%** | **82.2%** | +| recoverable share, range | 0.00–0.24% | 0.3–98.6% | + +The two zero-text legs (`caeba80f`, `cbdb7bf1` — 18 and 10 thinking blocks, no text, previously +unrecoverable **by construction**) become recoverable for ~97% of their duration. + +**The honest limit, stated rather than buried.** The first evidence block lands 3.15–41.03 s into a leg, +so a timeout shorter than that still recovers nothing — correctly. The worst case measured +(`bcb7ec94`: first evidence at 35.54 s of a 41.6 s leg) leaves 85% of that leg dark. This is a +~1,700× wider window, **not** a guarantee. + +*(knob moved: none — reanalysis · terra S1 root, sub-work matrix-routed · confidence: **measured**, +n=18 legs / 7 runs · evidence: `treatment-validation/20260903-k64-delegate-timeout/runs/*/all-sessions/projects/*/sessions/0000000000000000-*/events.jsonl`)* + +--- + +## 5. NORMAL COMPLETIONS BYTE-IDENTICAL — shown, not asserted + +`evidence/03-byte-identity.txt` runs the same probe against a `cp -rL` copy of the parent producer and +of this branch, and diffs the canonical JSON: + +``` +IDENTICAL normal_completion_result +IDENTICAL normal_completion_registry_after +IDENTICAL normal_completion_partial +IDENTICAL timeout_with_text_partial <- the text case: same bytes => same guidance string +CHANGED timeout_no_text_partial <- null -> a record. This is the fix. +``` + +Exactly one key moves, and it is the one the item exists to move. + +--- + +## 6. EVIDENCE INDEX + +| file | what | +|---|---| +| `evidence/00-baseline-suite-parent.txt` | parent suite green before any edit (1659 passed) | +| `evidence/01-fail-before.txt` | same unit tests, both producers: **parent 5 failed / 18 passed**, patched **23 passed** | +| `evidence/03-byte-identity.txt` (+ `03a`/`03b` JSON) | serialized results diffed, parent vs patched | +| `evidence/04-roundtrip.txt` | cross-repo, foundation `f42f48c`: **parent 2 failed / 3 passed**, patched **5 passed** | +| `evidence/05-full-suite.txt` | **1670 passed**, 1 skipped, 13 deselected, 1 xfailed | +| `evidence/06-integration.txt` | `pytest -m integration`: 13 passed | +| `evidence/07-real-leg-reachability.md` | the reachability table above | +| `byte_identity_probe.py` | the probe behind §5 | +| `test_partial_roundtrip.py` | 37n's check, extended with the no-text case | + +Suites run with the repo's own `uv sync --all-extras` venv, matching CI (`.github/workflows/ci.yml`: +`uv run pytest -q` plus `pytest -m integration`). + +--- + +## 7. INCIDENT — a false green, caught, disclosed + +The first cross-repo run reported **5 passed on the parent producer**, i.e. the fail-before arm +"passing". Cause: the overlay was on `PYTHONPATH`, but the run was launched **from the checkout**, and +`sys.path[0]` is the CWD — so both arms imported the working tree and the parent arm was never +exercised. Caught by asking the interpreter which file it had actually loaded, rather than trusting the +exit code. + +Nothing was published from that run. Every arm is now preceded by a printed +`session_spawner.__file__` + `widened: True/False` check (top of `evidence/04-roundtrip.txt`), and both +round-trip and unit fail-before runs execute from `/tmp`. **This is the same failure shape as the item +itself** — a check that could not fail — one layer further out, and it is recorded here rather than +quietly fixed. + +--- + +## 8. DEVIATIONS + +* **`docs/lanes/.../evidence/02-pass-after.txt` was folded into `01-fail-before.txt`** so the two arms + sit side by side in one file. No content lost. +* **`ruff format` was applied to the two files touched** (repo style; `ruff check` clean). All evidence + was regenerated afterwards against the formatted tree — no capture predates the final source. +* **No foundation change**, per the item's scope-out. §3 names the change and where it goes. +* **Baseline capture note:** `00-baseline-suite-parent.txt` was taken before the new tests existed, so + it reports 1659 rather than 1670. The parent-vs-patched comparison that matters is + `01-fail-before.txt`, which runs the *same* file against both producers. + +--- + +## 9. WHAT REMAINS OPEN + +* **The foundation guidance string** (§3) — a separate, named, two-line change in another repo. +* **`model_performance-bnj`** (k64's $45.30 residue, owner-gated) is unblocked by this: a timeout now + exercises the partial path on a real leg shape, so buying runs can no longer come back + PARTIAL-PATH-NOT-EXERCISED. Its arithmetic should be re-checked against the then-current price + before it is funded. +* **Tool *results*** are still not recovered (only the calls). If they are ever wanted, option (b) + (`transcript.jsonl`) is the route — costed and declined in §2, not forgotten. +* **The sub-second head of a leg** stays unrecoverable (§4). A timeout set below ~3 s recovers nothing, + correctly. diff --git a/docs/lanes/eem-partial-accumulator-widen/byte_identity_probe.py b/docs/lanes/eem-partial-accumulator-widen/byte_identity_probe.py new file mode 100644 index 0000000..5ea16f1 --- /dev/null +++ b/docs/lanes/eem-partial-accumulator-widen/byte_identity_probe.py @@ -0,0 +1,187 @@ +"""Serialize what a delegate leg hands back, so parent vs patched can be DIFFED. + +The deliverable is "normal completions byte-identical -- show it, do not assert +it". An assertion on a key set proves the keys did not change; it does not +prove the bytes did not. This probe drives `spawn_sub_session` against whichever +`amplifier_app_cli` is first on `sys.path` and dumps, canonically: + + 1. NORMAL COMPLETION -- the full result dict a finished delegate returns, + for a leg that emitted thinking + tool_call + text blocks (i.e. one whose + blocks the widening now observes). + 2. TIMEOUT, TEXT PRESENT -- the `session.partial` record for a leg that DID + emit assistant text. This is the case foundation's shipped guidance + string already describes correctly, so it must not move either. + 3. TIMEOUT, NO TEXT -- the real leg shape (k64: thinking + tool_call, no + text). Expected to differ: `null` on the parent, a record on the patched + build. That difference IS the fix. + +Run under each build with PYTHONPATH pointed at a `cp -rL` copy; diff the two +JSON files. See evidence/03-byte-identity.txt. +""" + +import asyncio +import json +import sys +from unittest.mock import AsyncMock, MagicMock, patch + +from amplifier_core.events import CONTENT_BLOCK_END + +from amplifier_app_cli import session_spawner +from amplifier_app_cli.session_spawner import get_partial_output, spawn_sub_session + + +class FakeHooks: + def __init__(self): + self.handlers = {} + + def register(self, event, handler, priority=0, name=None): + self.handlers.setdefault(event, []).append(handler) + + def _unregister(): + if handler in self.handlers.get(event, []): + self.handlers[event].remove(handler) + + return _unregister + + async def emit(self, event, data): + for handler in list(self.handlers.get(event, [])): + await handler(event, data) + + async def block(self, block): + await self.emit(CONTENT_BLOCK_END, {"block": block}) + + +def _parent_session(): + coord = MagicMock() + coord.get.return_value = None + coord.get_capability.return_value = None + coord.display_system = MagicMock() + coord.cancellation = MagicMock() + session = MagicMock() + session.coordinator = coord + session.config = { + "session": {"orchestrator": "loop-basic", "context": "context-simple"} + } + session.session_id = "parent-123" + session.trace_id = "trace-abc" + session.loader = None + return session + + +def _child_session(hooks, body): + coord = MagicMock() + coord.register_capability = MagicMock() + coord.get_capability.return_value = None + coord.display_system = MagicMock() + + def _get(name): + if name == "hooks": + return hooks + if name == "context": + ctx = AsyncMock() + ctx.get_messages = AsyncMock(return_value=[]) + ctx.add_message = AsyncMock() + return ctx + return None + + coord.get = _get + coord.mount = AsyncMock() + coord.collect_contributions = AsyncMock(return_value=[]) + + child = MagicMock() + child.coordinator = coord + child.initialize = AsyncMock() + child.execute = AsyncMock(side_effect=body) + child.cleanup = AsyncMock() + child.session_id = "child-001" + return child + + +async def _spawn(child): + with ( + patch("amplifier_app_cli.session_spawner.AmplifierSession", return_value=child), + patch( + "amplifier_app_cli.session_spawner.generate_sub_session_id", + return_value="child-001", + ), + patch("amplifier_app_cli.paths.create_foundation_resolver"), + patch("amplifier_app_cli.session_store.SessionStore.save"), + ): + return await spawn_sub_session( + agent_name="test-agent", + instruction="Do something", + parent_session=_parent_session(), + agent_configs={"test-agent": {"description": "A test agent"}}, + ) + + +THINKING = {"type": "thinking", "text": "the router loads a matrix; check it"} +TOOL_CALL = { + "type": "tool_call", + "id": "call_1", + "name": "read_file", + "input": {"file_path": "/repo/router.py", "limit": 40, "search": ""}, + "visibility": None, +} +TEXT = {"type": "text", "text": "the finished answer"} + + +async def main(): + out = {} + + # 1. NORMAL COMPLETION ----------------------------------------------- + hooks = FakeHooks() + + async def _completes(instruction): + await hooks.block(THINKING) + await hooks.block(TOOL_CALL) + await hooks.block(TEXT) + await hooks.emit( + "orchestrator:complete", + {"status": "success", "turn_count": 5, "metadata": {"o": "loop-basic"}}, + ) + return "agent response" + + session_spawner._PARTIAL_OUTPUTS.clear() + out["normal_completion_result"] = await _spawn(_child_session(hooks, _completes)) + out["normal_completion_registry_after"] = sorted(session_spawner._PARTIAL_OUTPUTS) + out["normal_completion_partial"] = get_partial_output("child-001") + + # 2. TIMEOUT, TEXT PRESENT ------------------------------------------- + hooks = FakeHooks() + + async def _text_then_dies(instruction): + await hooks.block(THINKING) + await hooks.block(TOOL_CALL) + await hooks.block({"type": "text", "text": "anchor A1 confirmed. "}) + await hooks.block({"type": "text", "text": "anchor A2 confirmed. "}) + raise TimeoutError("wall clock") + + session_spawner._PARTIAL_OUTPUTS.clear() + try: + await _spawn(_child_session(hooks, _text_then_dies)) + except TimeoutError: + pass + out["timeout_with_text_partial"] = get_partial_output("child-001") + + # 3. TIMEOUT, NO TEXT (the real leg shape) ---------------------------- + hooks = FakeHooks() + + async def _no_text(instruction): + await hooks.block(THINKING) + await hooks.block(TOOL_CALL) + raise TimeoutError("wall clock") + + session_spawner._PARTIAL_OUTPUTS.clear() + try: + await _spawn(_child_session(hooks, _no_text)) + except TimeoutError: + pass + out["timeout_no_text_partial"] = get_partial_output("child-001") + + print(json.dumps(out, indent=2, sort_keys=True, default=str)) + + +if __name__ == "__main__": + print(f"# amplifier_app_cli from: {session_spawner.__file__}", file=sys.stderr) + asyncio.run(main()) diff --git a/docs/lanes/eem-partial-accumulator-widen/evidence/00-baseline-suite-parent.txt b/docs/lanes/eem-partial-accumulator-widen/evidence/00-baseline-suite-parent.txt new file mode 100644 index 0000000..be63169 --- /dev/null +++ b/docs/lanes/eem-partial-accumulator-widen/evidence/00-baseline-suite-parent.txt @@ -0,0 +1,26 @@ +........................................................................ [ 4%] +........................................................................ [ 8%] +........................................................................ [ 13%] +........................................................................ [ 17%] +......................................s................................. [ 21%] +........................................................................ [ 26%] +........................................................................ [ 30%] +........................................................................ [ 34%] +........................................................................ [ 39%] +........................................................................ [ 43%] +........................................................................ [ 47%] +........................................................................ [ 52%] +........................................................................ [ 56%] +........................................................................ [ 60%] +........................................................................ [ 65%] +........................................................................ [ 69%] +........................................................................ [ 73%] +........................................................................ [ 78%] +........................................................................ [ 82%] +........................................................................ [ 86%] +........................................................................ [ 91%] +........................................................................ [ 95%] +.......x................................................................ [ 99%] +..... [100%] +1659 passed, 1 skipped, 13 deselected, 1 xfailed in 12.60s +EXIT=0 diff --git a/docs/lanes/eem-partial-accumulator-widen/evidence/01-fail-before.txt b/docs/lanes/eem-partial-accumulator-widen/evidence/01-fail-before.txt new file mode 100644 index 0000000..f6f16e7 --- /dev/null +++ b/docs/lanes/eem-partial-accumulator-widen/evidence/01-fail-before.txt @@ -0,0 +1,149 @@ +# FAIL-BEFORE / PASS-AFTER: tests/test_session_spawner_partial.py +# Same test file, two producers, overlaid copies -- run from /tmp/eem-unit so +# sys.path[0] cannot shadow the overlay with the checkout. +# parent = app-cli 26e5f10 (#297) -- accumulator filters block['type'] == 'text' +# patched = this branch +# date: 2026-09-03T13:06:21Z + +=== A. PARENT PRODUCER (26e5f10) -- FAIL-BEFORE === +............FFF...FF... [100%] +=================================== FAILURES =================================== +_________ test_leg_with_no_text_block_still_carries_a_partial[asyncio] _________ + + async def test_leg_with_no_text_block_still_carries_a_partial(): + """FAIL-BEFORE (26e5f10): the ~99.5% real case recovered nothing. + + This is the single fact that made the whole bp0+9w0 chain inert. + """ + hooks = FakeHooks() + + async def _thinks_and_calls_tools_then_dies(instruction): + await hooks.fire_thinking_block("I should start by reading the router.") + await hooks.fire_tool_call_block("read_file", {"file_path": "/repo/router.py"}) + await hooks.fire_thinking_block("That names a matrix loader. Check it.") + await hooks.fire_tool_call_block("grep", {"pattern": "load_matrix"}) + raise TimeoutError("wall clock") + + with pytest.raises(TimeoutError): + await _spawn(_child_session(hooks, _thinks_and_calls_tools_then_dies)) + + partial = get_partial_output("child-001") +> assert partial is not None, ( + "a delegate that did 2 thinking blocks and 2 tool calls recovered " + "NOTHING -- this is the defect model_performance-eem exists to close" + ) +E AssertionError: a delegate that did 2 thinking blocks and 2 tool calls recovered NOTHING -- this is the defect model_performance-eem exists to close +E assert None is not None + +test_session_spawner_partial.py:415: AssertionError +___________ test_measured_k64_timeout_shape_is_recoverable[asyncio] ____________ + + async def test_measured_k64_timeout_shape_is_recoverable(): + """The exact leg k64 watched die: 10 thinking blocks, 45 tool calls, 0 text. + + Source: probes/k64-delegate-timeout-eval/FINDINGS.md ("THE HEADLINE") and + TEXT-WINDOW-TABLE.md row `005_anchors-amp-dev-explorer` (90.016 s, 10 + thinking, 1 tool_call, 0 text). The 45 tool calls are the count reported + for the timed-out leg itself. + """ + hooks = FakeHooks() + + async def _the_observed_timeout(instruction): + for i in range(10): + await hooks.fire_thinking_block(f"reasoning step {i}") + for i in range(45): + await hooks.fire_tool_call_block("read_file", {"file_path": f"/f{i}.py"}) + raise TimeoutError("90s rung") + + with pytest.raises(TimeoutError): + await _spawn(_child_session(hooks, _the_observed_timeout)) + + partial = get_partial_output("child-001") +> assert partial is not None +E assert None is not None + +test_session_spawner_partial.py:448: AssertionError +________________ test_tool_calls_alone_are_recoverable[asyncio] ________________ + + async def test_tool_calls_alone_are_recoverable(): + """A non-reasoning model emits no `thinking` blocks at all.""" + hooks = FakeHooks() + + async def _only_tools(instruction): + await hooks.fire_tool_call_block("bash", {"command": "pytest -q"}) + raise TimeoutError("wall clock") + + with pytest.raises(TimeoutError): + await _spawn(_child_session(hooks, _only_tools)) + + partial = get_partial_output("child-001") +> assert partial is not None +E assert None is not None + +test_session_spawner_partial.py:465: AssertionError +_ test_recovered_reasoning_names_itself_as_reasoning_not_draft_output[asyncio] _ + + async def test_recovered_reasoning_names_itself_as_reasoning_not_draft_output(): + """The content says what it is, because the guidance string cannot. + + Handing a model its own unreviewed reasoning while calling it "unfinished + work" is a weaker claim than the shipped guidance makes. The producer + cannot change that string (it lives in amplifier-foundation), so it + labels the payload and distinguishes the `source`. + """ + hooks = FakeHooks() + + async def _no_text(instruction): + await hooks.fire_thinking_block("maybe the bug is in the loader") + raise TimeoutError("wall clock") + + with pytest.raises(TimeoutError): + await _spawn(_child_session(hooks, _no_text)) + + partial = get_partial_output("child-001") +> assert partial["source"] == "spawn-accumulator:reasoning", ( + ^^^^^^^^^^^^^^^^^ + "a consumer must be able to tell recovered reasoning from recovered " + "prose WITHOUT parsing the text" + ) +E TypeError: 'NoneType' object is not subscriptable + +test_session_spawner_partial.py:570: TypeError +________ test_the_label_survives_the_consumers_tail_truncation[asyncio] ________ + + async def test_the_label_survives_the_consumers_tail_truncation(): + """foundation keeps the TAIL, so a leading-only label would be cut off. + + `_read_partial` (foundation f42f48c) truncates to the LAST + `partial_max_chars` characters. 25 thinking blocks routinely exceed the + 20,000-char default, so the label has to be at the end as well as the + start or it is exactly the long partials that lose it. + """ + hooks = FakeHooks() + + async def _very_talkative(instruction): + for i in range(30): + await hooks.fire_thinking_block("x" * 2000 + f" step {i}") + raise TimeoutError("wall clock") + + with pytest.raises(TimeoutError): + await _spawn(_child_session(hooks, _very_talkative)) + +> text = get_partial_output("child-001")["text"] + ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^ +E TypeError: 'NoneType' object is not subscriptable + +test_session_spawner_partial.py:599: TypeError +=========================== short test summary info ============================ +FAILED test_session_spawner_partial.py::test_leg_with_no_text_block_still_carries_a_partial[asyncio] +FAILED test_session_spawner_partial.py::test_measured_k64_timeout_shape_is_recoverable[asyncio] +FAILED test_session_spawner_partial.py::test_tool_calls_alone_are_recoverable[asyncio] +FAILED test_session_spawner_partial.py::test_recovered_reasoning_names_itself_as_reasoning_not_draft_output[asyncio] +FAILED test_session_spawner_partial.py::test_the_label_survives_the_consumers_tail_truncation[asyncio] +5 failed, 18 passed in 0.22s +EXIT=1 + +=== B. PATCHED PRODUCER (this branch) -- PASS-AFTER === +....................... [100%] +23 passed in 0.17s +EXIT=0 diff --git a/docs/lanes/eem-partial-accumulator-widen/evidence/03-byte-identity.txt b/docs/lanes/eem-partial-accumulator-widen/evidence/03-byte-identity.txt new file mode 100644 index 0000000..7e1167e --- /dev/null +++ b/docs/lanes/eem-partial-accumulator-widen/evidence/03-byte-identity.txt @@ -0,0 +1,34 @@ +# BYTE-IDENTITY: serialized delegate results, parent vs patched +# parent = git show 26e5f10:amplifier_app_cli/session_spawner.py (26e5f10, #297) +# patched = this branch's working tree +# probe = docs/lanes/eem-partial-accumulator-widen/byte_identity_probe.py +# both producers are cp -rL copies under /tmp; the repo is not mutated +# date = 2026-09-03T13:05:40Z + +## sha256 of each serialized capture +9d9ed8b1f972f315260d351a3614a5a14f5830e8bf164f318f330ea28bf5933e 03a-parent.json +71bb1a57cc8fb44a3112aee15f81c51e4db4cf76075a1b679cab62ae3bc22099 03b-patched.json + +## per-key comparison + IDENTICAL normal_completion_partial + IDENTICAL normal_completion_registry_after + IDENTICAL normal_completion_result + CHANGED timeout_no_text_partial + IDENTICAL timeout_with_text_partial + +## full unified diff +--- /home/bkrabach/dev/hw-model-performance/lanes/eem-partial-accumulator-widen/amplifier-app-cli/docs/lanes/eem-partial-accumulator-widen/evidence/03a-parent.json 2026-09-03 06:05:39.876381723 -0700 ++++ /home/bkrabach/dev/hw-model-performance/lanes/eem-partial-accumulator-widen/amplifier-app-cli/docs/lanes/eem-partial-accumulator-widen/evidence/03b-patched.json 2026-09-03 06:05:40.262380587 -0700 +@@ -10,7 +10,11 @@ + "status": "success", + "turn_count": 5 + }, +- "timeout_no_text_partial": null, ++ "timeout_no_text_partial": { ++ "segments": 2, ++ "source": "spawn-accumulator:reasoning", ++ "text": "[RECOVERED FROM AN UNFINISHED DELEGATE -- NOT DRAFT OUTPUT]\nThis delegate was killed before it wrote any answer at all. What follows is NOT prose the agent composed for a reader: it is the agent's own private reasoning and the trace of the tool calls it made, recovered from its event stream. None of it was checked, concluded, self-reviewed, or addressed to anyone. Read it as evidence of what the agent was doing and what it had already looked at -- never as a partial answer.\n\nTOOL CALLS THE AGENT MADE (1), in order:\n 1. read_file(file_path='/repo/router.py', limit=40)\n\nAGENT REASONING (1 segment(s)) -- unreviewed, never addressed to a reader:\n\nthe router loads a matrix; check it\n\n[END OF RECOVERED WORK -- unreviewed agent reasoning and tool-call trace, not a partial answer]" ++ }, + "timeout_with_text_partial": { + "segments": 2, + "source": "spawn-accumulator", diff --git a/docs/lanes/eem-partial-accumulator-widen/evidence/03a-parent.json b/docs/lanes/eem-partial-accumulator-widen/evidence/03a-parent.json new file mode 100644 index 0000000..96b48da --- /dev/null +++ b/docs/lanes/eem-partial-accumulator-widen/evidence/03a-parent.json @@ -0,0 +1,19 @@ +{ + "normal_completion_partial": null, + "normal_completion_registry_after": [], + "normal_completion_result": { + "metadata": { + "o": "loop-basic" + }, + "output": "agent response", + "session_id": "child-001", + "status": "success", + "turn_count": 5 + }, + "timeout_no_text_partial": null, + "timeout_with_text_partial": { + "segments": 2, + "source": "spawn-accumulator", + "text": "anchor A1 confirmed. anchor A2 confirmed. " + } +} diff --git a/docs/lanes/eem-partial-accumulator-widen/evidence/03b-patched.json b/docs/lanes/eem-partial-accumulator-widen/evidence/03b-patched.json new file mode 100644 index 0000000..45e8fe5 --- /dev/null +++ b/docs/lanes/eem-partial-accumulator-widen/evidence/03b-patched.json @@ -0,0 +1,23 @@ +{ + "normal_completion_partial": null, + "normal_completion_registry_after": [], + "normal_completion_result": { + "metadata": { + "o": "loop-basic" + }, + "output": "agent response", + "session_id": "child-001", + "status": "success", + "turn_count": 5 + }, + "timeout_no_text_partial": { + "segments": 2, + "source": "spawn-accumulator:reasoning", + "text": "[RECOVERED FROM AN UNFINISHED DELEGATE -- NOT DRAFT OUTPUT]\nThis delegate was killed before it wrote any answer at all. What follows is NOT prose the agent composed for a reader: it is the agent's own private reasoning and the trace of the tool calls it made, recovered from its event stream. None of it was checked, concluded, self-reviewed, or addressed to anyone. Read it as evidence of what the agent was doing and what it had already looked at -- never as a partial answer.\n\nTOOL CALLS THE AGENT MADE (1), in order:\n 1. read_file(file_path='/repo/router.py', limit=40)\n\nAGENT REASONING (1 segment(s)) -- unreviewed, never addressed to a reader:\n\nthe router loads a matrix; check it\n\n[END OF RECOVERED WORK -- unreviewed agent reasoning and tool-call trace, not a partial answer]" + }, + "timeout_with_text_partial": { + "segments": 2, + "source": "spawn-accumulator", + "text": "anchor A1 confirmed. anchor A2 confirmed. " + } +} diff --git a/docs/lanes/eem-partial-accumulator-widen/evidence/04-roundtrip.txt b/docs/lanes/eem-partial-accumulator-widen/evidence/04-roundtrip.txt new file mode 100644 index 0000000..b8dba58 --- /dev/null +++ b/docs/lanes/eem-partial-accumulator-widen/evidence/04-roundtrip.txt @@ -0,0 +1,123 @@ +# CROSS-REPO ROUND TRIP (per ai-notes w3-delegate-timeout/APPLY.md) +# consumer: amplifier-foundation f42f48c (tool-delegate), extracted read-only with git archive +# blob eaee8970d72c474adc26a80da52910dc856a10e4 +# producer: /tmp/eem-parent (app-cli 26e5f10) and /tmp/eem-patched (this branch), both cp -rL +# NEITHER REPO MUTATED. +# +# RUN FROM /tmp/eem-rt, NOT FROM THE CHECKOUT. sys.path[0] is the CWD, so running +# this from the repo silently imports the WORKING TREE producer and BOTH arms pass. +# That happened once in this lane before it was caught -- DONE-NOTE.md, Incident. +# date: 2026-09-03T13:05:53Z + +=== producer resolution check (proves the two arms really differ) === +A parent -> /tmp/eem-parent/amplifier_app_cli/session_spawner.py | widened: False +B patched -> /tmp/eem-patched/amplifier_app_cli/session_spawner.py | widened: True + +=== A. PARENT PRODUCER (26e5f10) -- expected: the no-text cases FAIL === +.F.F. [100%] +=================================== FAILURES =================================== +_________ test_a_leg_that_never_emits_text_still_round_trips_a_partial _________ + + @pytest.mark.asyncio + async def test_a_leg_that_never_emits_text_still_round_trips_a_partial(): + """FAIL-BEFORE on app-cli 26e5f10: this returned `partial_available: false`. + + Block shapes are measured, not assumed -- taken from + treatment-validation/20260903-k64-delegate-timeout captures + (236 thinking, 53 tool_call, 38 text blocks inspected): + + thinking {"type": "thinking", "text": ...} + tool_call {"type": "tool_call", "id": ..., "name": ..., + "input": {...}, "visibility": ...} + """ + captured_ids = {} + + async def _thinks_and_calls_tools_then_hangs(**kwargs): + sub_id = kwargs["sub_session_id"] + captured_ids["sub"] = sub_id + child_hooks = ChildHooks() + # The REAL accumulator, registered exactly as spawn_sub_session does. + _open_partial(sub_id, child_hooks) + await child_hooks.block( + {"type": "thinking", "text": "the anchors are probably in the PR body"} + ) + await child_hooks.block( + { + "type": "tool_call", + "id": "call_1", + "name": "grep", + "input": {"pattern": "#281", "path": "/repo", "search": ""}, + "visibility": None, + } + ) + await child_hooks.block( + {"type": "thinking", "text": "no hit; try the changelog instead"} + ) + # No text block, ever -- this is the ~99.5% real case. + await asyncio.sleep(3600) + + result = await _run_delegate(_thinks_and_calls_tools_then_hangs) + + assert result.success is False + assert result.output["status"] == "timeout" +> assert result.output["partial_available"] is True, ( + "a leg with 2 thinking blocks and a tool call recovered nothing -- " + "this is exactly the defect model_performance-eem closes" + ) +E AssertionError: a leg with 2 thinking blocks and a tool call recovered nothing -- this is exactly the defect model_performance-eem closes +E assert False is True + +test_partial_roundtrip.py:190: AssertionError +------------------------------ Captured log call ------------------------------- +WARNING amplifier_module_tool_delegate:__init__.py:2282 Agent 'explorer' timed out after 1s (delegate tool session-level timeout; elapsed 1.001s). No partial output could be recovered. Child cancellation cleanup is still in progress; do not resume this session until cleanup and persistence complete. +_____ test_guidance_string_for_the_reasoning_case_is_foundations_to_change _____ + + @pytest.mark.asyncio + async def test_guidance_string_for_the_reasoning_case_is_foundations_to_change(): + """PINS THE GAP THIS LANE DOES NOT CROSS. + + foundation picks its guidance from `bool(text)` alone, so a recovered + REASONING partial is currently described by `_PARTIAL_GUIDANCE` -- "...is + unfinished work salvaged from the agent mid-flight -- it has NOT been + checked, concluded, or self-reviewed...". That is a stronger claim than + raw thinking supports: unfinished prose was at least addressed to a + reader; private reasoning never was. + + amplifier-foundation is a different repo and this lane stops at the + boundary (see DONE-NOTE.md, "The guidance string"). What the PRODUCER can + do it does: `partial_source` distinguishes the two kinds without parsing, + and the payload labels itself at head AND tail. This test asserts today's + real behaviour so the day foundation makes the string kind-aware, this + check fails loudly instead of drifting. + """ + + async def _thinks_then_hangs(**kwargs): + child_hooks = ChildHooks() + _open_partial(kwargs["sub_session_id"], child_hooks) + await child_hooks.block({"type": "thinking", "text": "maybe the loader"}) + await asyncio.sleep(3600) + + result = await _run_delegate(_thinks_then_hangs) + + # Current, shipped consumer behaviour -- text-shaped guidance. +> assert result.output["guidance"] == _PARTIAL_GUIDANCE +E AssertionError: assert 'INCOMPLETE: ...r resumption.' == 'INCOMPLETE: ...r resumption.' +E +E - INCOMPLETE: this delegate did not finish. The text in 'partial_response' is unfinished work salvaged from the agent mid-flight -- it has NOT been checked, concluded, or self-reviewed by that agent. Do not report it as a completed result and do not treat its conclusions as final. Re-delegate a narrower task or complete the work yourself; see metadata.recovery_message before considering this session for resumption. +E + INCOMPLETE: this delegate did not finish and no partial output could be recovered. Nothing here is a result. Re-delegate a narrower task or complete the wor... +E +E ...Full output truncated (1 line hidden), use '-vv' to show + +test_partial_roundtrip.py:253: AssertionError +------------------------------ Captured log call ------------------------------- +WARNING amplifier_module_tool_delegate:__init__.py:2282 Agent 'explorer' timed out after 1s (delegate tool session-level timeout; elapsed 1.001s). No partial output could be recovered. Child cancellation cleanup is still in progress; do not resume this session until cleanup and persistence complete. +=========================== short test summary info ============================ +FAILED test_partial_roundtrip.py::test_a_leg_that_never_emits_text_still_round_trips_a_partial +FAILED test_partial_roundtrip.py::test_guidance_string_for_the_reasoning_case_is_foundations_to_change +2 failed, 3 passed in 5.15s +EXIT=1 + +=== B. PATCHED PRODUCER (this branch) -- expected: all pass === +..... [100%] +5 passed in 5.13s +EXIT=0 diff --git a/docs/lanes/eem-partial-accumulator-widen/evidence/05-full-suite.txt b/docs/lanes/eem-partial-accumulator-widen/evidence/05-full-suite.txt new file mode 100644 index 0000000..2020ab4 --- /dev/null +++ b/docs/lanes/eem-partial-accumulator-widen/evidence/05-full-suite.txt @@ -0,0 +1,29 @@ +# FULL SUITE, patched working tree (post-format) +# date: 2026-09-03T13:06:22Z + +........................................................................ [ 4%] +........................................................................ [ 8%] +........................................................................ [ 12%] +........................................................................ [ 17%] +......................................s................................. [ 21%] +........................................................................ [ 25%] +........................................................................ [ 30%] +........................................................................ [ 34%] +........................................................................ [ 38%] +........................................................................ [ 43%] +........................................................................ [ 47%] +........................................................................ [ 51%] +........................................................................ [ 55%] +........................................................................ [ 60%] +........................................................................ [ 64%] +........................................................................ [ 68%] +........................................................................ [ 73%] +........................................................................ [ 77%] +........................................................................ [ 81%] +........................................................................ [ 86%] +........................................................................ [ 90%] +........................................................................ [ 94%] +..................x..................................................... [ 99%] +................ [100%] +1670 passed, 1 skipped, 13 deselected, 1 xfailed in 7.96s +EXIT=0 diff --git a/docs/lanes/eem-partial-accumulator-widen/evidence/06-integration.txt b/docs/lanes/eem-partial-accumulator-widen/evidence/06-integration.txt new file mode 100644 index 0000000..429a545 --- /dev/null +++ b/docs/lanes/eem-partial-accumulator-widen/evidence/06-integration.txt @@ -0,0 +1,6 @@ +# INTEGRATION JOB (pytest -m integration), patched working tree +# date: 2026-09-03T13:03:39Z + +............. [100%] +13 passed, 1672 deselected in 26.02s +EXIT=0 diff --git a/docs/lanes/eem-partial-accumulator-widen/evidence/07-real-leg-reachability.md b/docs/lanes/eem-partial-accumulator-widen/evidence/07-real-leg-reachability.md new file mode 100644 index 0000000..d4bf76b --- /dev/null +++ b/docs/lanes/eem-partial-accumulator-widen/evidence/07-real-leg-reachability.md @@ -0,0 +1,53 @@ +# Is `partial_available: true` reachable on a REAL leg shape? + +Recomputed from k64's own captures (`treatment-validation/20260903-k64-delegate-timeout/`), +$0, no new runs. Population: the 18 delegate sub-sessions (`0000000000000000-*`) -- +the same 18 legs k64's TEXT-WINDOW-TABLE.md reports. Timestamps are each leg's own +`events.jsonl`; `dur_s` is first-to-last event, which is why it differs from k64's +harness-measured duration by a few tenths. + +* **evidence_window** = the share of the leg during which the WIDENED accumulator holds + something (from the first `thinking`/`tool_call` block to the end of the leg). +* **text_window** = the share during which the OLD accumulator held something (from the + single `text` block to the end). This is k64's ~0.5% figure. + +| leg | dur_s | think | tool | text | 1st evidence s | 1st text s | evidence_window | text_window | +|---|---|---|---|---|---|---|---|---| +| `27fd2a47` | 221.8 | 25 | 0 | 1 | 3.15 | 221.75 | 98.6% | 0.02% | +| `760e7ff5` | 156.2 | 20 | 1 | 1 | 5.26 | 156.11 | 96.6% | 0.03% | +| `3d698bd3` | 144.2 | 24 | 0 | 1 | 3.64 | 144.16 | 97.5% | 0.03% | +| `cbdb7bf1` | 117.2 | 10 | 1 | 0 | 3.16 | never | 97.3% | 0.00% | +| `1f4bec9b` | 115.7 | 7 | 5 | 1 | 3.15 | 115.69 | 97.3% | 0.04% | +| `2b4aa500` | 105.4 | 8 | 3 | 1 | 3.98 | 105.35 | 96.2% | 0.02% | +| `caeba80f` | 101.0 | 18 | 0 | 0 | 3.52 | never | 96.5% | 0.00% | +| `da8990c3` | 94.1 | 10 | 0 | 1 | 41.03 | 94.11 | 56.4% | 0.02% | +| `d0bd9db3` | 82.8 | 12 | 0 | 1 | 4.87 | 82.80 | 94.1% | 0.04% | +| `813e7db0` | 72.8 | 6 | 5 | 1 | 4.46 | 72.77 | 93.9% | 0.05% | +| `5019ae7b` | 60.7 | 6 | 0 | 1 | 3.64 | 60.66 | 94.0% | 0.08% | +| `05148a3b` | 54.8 | 2 | 0 | 1 | 3.46 | 54.74 | 93.7% | 0.09% | +| `7015903a` | 50.3 | 7 | 3 | 1 | 3.30 | 50.32 | 93.4% | 0.03% | +| `59997875` | 49.5 | 10 | 0 | 1 | 6.77 | 49.45 | 86.3% | 0.03% | +| `bcb7ec94` | 41.6 | 1 | 0 | 1 | 35.54 | 41.57 | 14.5% | 0.03% | +| `a5f1b7ee` | 29.4 | 5 | 1 | 1 | 3.34 | 29.41 | 88.7% | 0.04% | +| `080c7821` | 20.6 | 3 | 2 | 1 | 3.31 | 20.62 | 84.0% | 0.05% | +| `e8811418` | 5.2 | 1 | 0 | 1 | 5.20 | 5.20 | 0.3% | 0.24% | + +**Legs with at least one `thinking` or `tool_call` block: 18/18.** +**Legs with a `text` block: 16/18.** + +* evidence_window: min **0.3%**, max **98.6%**, mean **82.2%** (n=18) +* text_window: min **0.00%**, max **0.24%**, mean **0.05%** (n=18) + +**ANSWER: yes, on this measured population.** A timeout firing uniformly at random inside a +leg now recovers content on **82.2%** of the leg on average, against +**0.05%** before -- a ~1779x wider window -- and the two zero-text legs +(which could NEVER have recovered anything) become recoverable for ~97% of their duration. + +**The honest limit.** The first evidence block lands 3.15-41.03 s into a leg, so a timeout +shorter than the first block still recovers nothing -- correctly. And the worst case here +(`bcb7ec94`, first evidence at 35.54 s of a 41.6 s leg) shows the head of a slow leg is +still dark. This is a much wider window, not a guarantee. + +*(knob moved: none -- reanalysis of k64's captures . terra S1 root, sub-work matrix-routed . +confidence: **measured**, n=18 legs / 7 runs . evidence pointer: +`treatment-validation/20260903-k64-delegate-timeout/runs/*/all-sessions/projects/*/sessions/0000000000000000-*/events.jsonl`)* diff --git a/docs/lanes/eem-partial-accumulator-widen/test_partial_roundtrip.py b/docs/lanes/eem-partial-accumulator-widen/test_partial_roundtrip.py new file mode 100644 index 0000000..ebc54c1 --- /dev/null +++ b/docs/lanes/eem-partial-accumulator-widen/test_partial_roundtrip.py @@ -0,0 +1,276 @@ +"""Cross-repo integration check for the partial-result path. + +Foundation (tool-delegate) is the CONSUMER of the partial; app-cli +(session_spawner) is the PRODUCER. Each half is unit-tested in its own repo +against a fake counterpart; this check wires the two real halves together so +the contract cannot drift silently between them. + +Run: PYTHONPATH=: python -m pytest test_partial_roundtrip.py + +-------------------------------------------------------------------------- +EXTENDED for model_performance-eem. + +The original check (`test_producer_and_consumer_agree_on_the_partial_contract`, +kept below verbatim) passed on the parent commit and the feature was still +inert in production. Two reasons, and both are fixed here: + + 1. its fixture sub-session emitted TEXT blocks. k64 measured 18 real delegate + legs: a leg emits at most ONE text block, in the final 0.19-0.72 s of a + 5.4-222.0 s leg. A timeout fires in the text-free phase ~99.5% of the + time, so the fixture tested the case that does not occur; + 2. it called `_seal_partial` with a hand-built `{"chunks": [...]}` record, + which BYPASSES `_open_partial`'s accumulator entirely -- the very filter + that was the defect. A test that never runs the accumulator cannot fail + when the accumulator is wrong. + +The added cases drive the REAL accumulator hook with the REAL block shapes +(measured from k64's captures) and emit NO text block at all. +-------------------------------------------------------------------------- +""" + +import asyncio + +import pytest +from amplifier_core.events import CONTENT_BLOCK_END + +from amplifier_app_cli.session_spawner import _open_partial +from amplifier_app_cli.session_spawner import _seal_partial +from amplifier_app_cli.session_spawner import get_partial_output +from amplifier_module_tool_delegate import DelegateTool +from amplifier_module_tool_delegate import _NO_PARTIAL_GUIDANCE +from amplifier_module_tool_delegate import _PARTIAL_GUIDANCE + + +class FakeSession: + def __init__(self): + self.session_id = "parent-session" + self.config = {} + + +class FakeCoordinator: + def __init__(self, capabilities): + self.session_id = "parent-session" + self.session = FakeSession() + self.config = {"agents": {"explorer": {}}} + self._capabilities = capabilities + + def get_capability(self, name): + return self._capabilities.get(name) + + +class FakeHooks: + def __init__(self): + self.events = [] + + async def emit(self, event, data): + self.events.append((event, data)) + return None + + +class ChildHooks: + """A hook coordinator the real `_open_partial` can register against.""" + + def __init__(self): + self.handlers = {} + + def register(self, event, handler, priority=0, name=None): + self.handlers.setdefault(event, []).append(handler) + + def _unregister(): + if handler in self.handlers.get(event, []): + self.handlers[event].remove(handler) + + return _unregister + + async def block(self, block): + for handler in list(self.handlers.get(CONTENT_BLOCK_END, [])): + await handler(CONTENT_BLOCK_END, {"block": block}) + + +async def _run_delegate(spawn_fn): + tool = DelegateTool( + FakeCoordinator( + { + "session.spawn": spawn_fn, + "session.partial": get_partial_output, # the REAL app-side reader + } + ), + {"settings": {"timeout": 1}}, + ) + return await tool._spawn_new_session( + agent_name="explorer", + instruction="find the anchors", + context_depth="none", + context_scope="conversation", + context_turns=0, + provider_preferences=None, + hooks=FakeHooks(), + agents={"explorer": {}}, + ) + + +@pytest.mark.asyncio +async def test_producer_and_consumer_agree_on_the_partial_contract(): + captured_ids = {} + + async def _never_finishes(**kwargs): + # Stand in for a straggler: record the id the delegate assigned, seal + # partial text against it the way the real accumulator does, then hang. + captured_ids["sub"] = kwargs["sub_session_id"] + _seal_partial( + kwargs["sub_session_id"], + {"chunks": ["anchor A1 confirmed. ", "anchor A2 confirmed. "]}, + ) + await asyncio.sleep(3600) + + result = await _run_delegate(_never_finishes) + + assert result.success is False + assert result.output["status"] == "timeout" + assert result.output["partial_available"] is True + assert ( + result.output["partial_response"] + == "anchor A1 confirmed. anchor A2 confirmed. " + ) + assert result.output["partial_segments"] == 2 + assert result.output["partial_source"] == "spawn-accumulator" + assert "response" not in result.output + + # Reads are destructive: the registry does not leak across delegate calls. + assert get_partial_output(captured_ids["sub"]) is None + + +# --------------------------------------------------------------------------- +# THE CASE THAT ACTUALLY OCCURS: a sub-session that emits NO text block +# --------------------------------------------------------------------------- + + +@pytest.mark.asyncio +async def test_a_leg_that_never_emits_text_still_round_trips_a_partial(): + """FAIL-BEFORE on app-cli 26e5f10: this returned `partial_available: false`. + + Block shapes are measured, not assumed -- taken from + treatment-validation/20260903-k64-delegate-timeout captures + (236 thinking, 53 tool_call, 38 text blocks inspected): + + thinking {"type": "thinking", "text": ...} + tool_call {"type": "tool_call", "id": ..., "name": ..., + "input": {...}, "visibility": ...} + """ + captured_ids = {} + + async def _thinks_and_calls_tools_then_hangs(**kwargs): + sub_id = kwargs["sub_session_id"] + captured_ids["sub"] = sub_id + child_hooks = ChildHooks() + # The REAL accumulator, registered exactly as spawn_sub_session does. + _open_partial(sub_id, child_hooks) + await child_hooks.block( + {"type": "thinking", "text": "the anchors are probably in the PR body"} + ) + await child_hooks.block( + { + "type": "tool_call", + "id": "call_1", + "name": "grep", + "input": {"pattern": "#281", "path": "/repo", "search": ""}, + "visibility": None, + } + ) + await child_hooks.block( + {"type": "thinking", "text": "no hit; try the changelog instead"} + ) + # No text block, ever -- this is the ~99.5% real case. + await asyncio.sleep(3600) + + result = await _run_delegate(_thinks_and_calls_tools_then_hangs) + + assert result.success is False + assert result.output["status"] == "timeout" + assert result.output["partial_available"] is True, ( + "a leg with 2 thinking blocks and a tool call recovered nothing -- " + "this is exactly the defect model_performance-eem closes" + ) + assert result.output["partial_segments"] == 3 + assert result.output["partial_source"] == "spawn-accumulator:reasoning" + assert "grep" in result.output["partial_response"] + assert "changelog" in result.output["partial_response"] + + # The contract's own invariants still hold on this path. + assert "response" not in result.output + assert result.output["completed"] is False + assert get_partial_output(captured_ids["sub"]) is None + + +@pytest.mark.asyncio +async def test_guidance_string_is_unchanged_for_the_text_case(): + """The case foundation's shipped guidance already describes correctly.""" + + async def _text_then_hangs(**kwargs): + sub_id = kwargs["sub_session_id"] + child_hooks = ChildHooks() + _open_partial(sub_id, child_hooks) + await child_hooks.block({"type": "thinking", "text": "private reasoning"}) + await child_hooks.block({"type": "text", "text": "anchor A1 confirmed. "}) + await asyncio.sleep(3600) + + result = await _run_delegate(_text_then_hangs) + + assert result.output["partial_source"] == "spawn-accumulator" + assert result.output["partial_response"] == "anchor A1 confirmed. " + assert result.output["guidance"] == _PARTIAL_GUIDANCE + assert "private reasoning" not in result.output["partial_response"] + + +@pytest.mark.asyncio +async def test_guidance_string_for_the_reasoning_case_is_foundations_to_change(): + """PINS THE GAP THIS LANE DOES NOT CROSS. + + foundation picks its guidance from `bool(text)` alone, so a recovered + REASONING partial is currently described by `_PARTIAL_GUIDANCE` -- "...is + unfinished work salvaged from the agent mid-flight -- it has NOT been + checked, concluded, or self-reviewed...". That is a stronger claim than + raw thinking supports: unfinished prose was at least addressed to a + reader; private reasoning never was. + + amplifier-foundation is a different repo and this lane stops at the + boundary (see DONE-NOTE.md, "The guidance string"). What the PRODUCER can + do it does: `partial_source` distinguishes the two kinds without parsing, + and the payload labels itself at head AND tail. This test asserts today's + real behaviour so the day foundation makes the string kind-aware, this + check fails loudly instead of drifting. + """ + + async def _thinks_then_hangs(**kwargs): + child_hooks = ChildHooks() + _open_partial(kwargs["sub_session_id"], child_hooks) + await child_hooks.block({"type": "thinking", "text": "maybe the loader"}) + await asyncio.sleep(3600) + + result = await _run_delegate(_thinks_then_hangs) + + # Current, shipped consumer behaviour -- text-shaped guidance. + assert result.output["guidance"] == _PARTIAL_GUIDANCE + assert result.output["guidance"] != _NO_PARTIAL_GUIDANCE + + # The producer-side honesty that compensates for it, until it changes. + assert result.output["partial_source"] == "spawn-accumulator:reasoning" + body = result.output["partial_response"] + assert body.lstrip().startswith("[RECOVERED FROM AN UNFINISHED DELEGATE") + assert body.rstrip().endswith("not a partial answer]") + + +@pytest.mark.asyncio +async def test_a_leg_that_produced_nothing_still_degrades_to_false(): + """The widening must not manufacture a partial out of an empty accumulator.""" + + async def _produces_nothing(**kwargs): + _open_partial(kwargs["sub_session_id"], ChildHooks()) + await asyncio.sleep(3600) + + result = await _run_delegate(_produces_nothing) + + assert result.output["partial_available"] is False + assert result.output["partial_response"] is None + assert result.output["partial_source"] == "none" + assert result.output["guidance"] == _NO_PARTIAL_GUIDANCE diff --git a/tests/test_session_spawner_partial.py b/tests/test_session_spawner_partial.py index 7d0934e..d77585b 100644 --- a/tests/test_session_spawner_partial.py +++ b/tests/test_session_spawner_partial.py @@ -66,6 +66,37 @@ async def emit(self, event, data): async def fire_text_block(self, text: str): await self.emit(CONTENT_BLOCK_END, {"block": {"type": "text", "text": text}}) + async def fire_thinking_block(self, text: str): + """A `thinking` block, in the exact shape a real provider emits. + + Measured from k64's captures (20260903-k64-delegate-timeout, 236 + thinking blocks): `{"type": "thinking", "text": ...}` -- the reasoning + rides in `text`, the same field name a `text` block uses. + """ + await self.emit( + CONTENT_BLOCK_END, {"block": {"type": "thinking", "text": text}} + ) + + async def fire_tool_call_block(self, name: str, tool_input: dict | None = None): + """A `tool_call` block, in the exact shape a real provider emits. + + Measured from the same captures (53 tool_call blocks): + `{"type": "tool_call", "id": ..., "name": ..., "input": {...}, + "visibility": None}` -- note `input`, NOT `arguments`. + """ + await self.emit( + CONTENT_BLOCK_END, + { + "block": { + "type": "tool_call", + "id": f"call_{name}", + "name": name, + "input": tool_input or {}, + "visibility": None, + } + }, + ) + def _parent_session(): parent_coordinator = MagicMock() @@ -344,3 +375,272 @@ async def test_root_session_registers_session_partial(): register_session_spawning(session) assert registered["session.partial"] is get_partial_output + + +# --------------------------------------------------------------------------- +# The leg shape that ACTUALLY occurs: no text block at all +# +# Everything above this line was true and still passed while the feature was +# inert in production. k64 measured 18 delegate legs across 7 runs +# (probes/k64-delegate-timeout-eval/TEXT-WINDOW-TABLE.md): a leg emits AT MOST +# ONE `text` block and it lands in the final 0.19-0.72 s (mean 0.331 s) of a +# leg lasting 5.4-222.0 s. Everything before it is `thinking` (1-25/leg) and +# `tool_call` (0-5). A timeout therefore fires in the text-free phase ~99.5% +# of the time. The one real timeout k64 observed had done 10 thinking blocks +# and 45 tool calls and returned `partial_available: false`. +# +# These tests replay that shape. On the parent commit (26e5f10) every one of +# them fails, because `_accumulate_partial` filtered on `type == "text"`. +# --------------------------------------------------------------------------- + + +async def test_leg_with_no_text_block_still_carries_a_partial(): + """FAIL-BEFORE (26e5f10): the ~99.5% real case recovered nothing. + + This is the single fact that made the whole bp0+9w0 chain inert. + """ + hooks = FakeHooks() + + async def _thinks_and_calls_tools_then_dies(instruction): + await hooks.fire_thinking_block("I should start by reading the router.") + await hooks.fire_tool_call_block("read_file", {"file_path": "/repo/router.py"}) + await hooks.fire_thinking_block("That names a matrix loader. Check it.") + await hooks.fire_tool_call_block("grep", {"pattern": "load_matrix"}) + raise TimeoutError("wall clock") + + with pytest.raises(TimeoutError): + await _spawn(_child_session(hooks, _thinks_and_calls_tools_then_dies)) + + partial = get_partial_output("child-001") + assert partial is not None, ( + "a delegate that did 2 thinking blocks and 2 tool calls recovered " + "NOTHING -- this is the defect model_performance-eem exists to close" + ) + assert partial["text"], "partial exists but carries no content" + # The consumer's `partial_available` is `bool(text)` -- foundation + # f42f48c, _partial_output_fields. Non-empty text IS the deliverable. + assert "read_file" in partial["text"] + assert "grep" in partial["text"] + assert "reading the router" in partial["text"] + + +async def test_measured_k64_timeout_shape_is_recoverable(): + """The exact leg k64 watched die: 10 thinking blocks, 45 tool calls, 0 text. + + Source: probes/k64-delegate-timeout-eval/FINDINGS.md ("THE HEADLINE") and + TEXT-WINDOW-TABLE.md row `005_anchors-amp-dev-explorer` (90.016 s, 10 + thinking, 1 tool_call, 0 text). The 45 tool calls are the count reported + for the timed-out leg itself. + """ + hooks = FakeHooks() + + async def _the_observed_timeout(instruction): + for i in range(10): + await hooks.fire_thinking_block(f"reasoning step {i}") + for i in range(45): + await hooks.fire_tool_call_block("read_file", {"file_path": f"/f{i}.py"}) + raise TimeoutError("90s rung") + + with pytest.raises(TimeoutError): + await _spawn(_child_session(hooks, _the_observed_timeout)) + + partial = get_partial_output("child-001") + assert partial is not None + assert partial["segments"] == 55, "every block the leg produced should count" + assert "reasoning step 9" in partial["text"] + + +async def test_tool_calls_alone_are_recoverable(): + """A non-reasoning model emits no `thinking` blocks at all.""" + hooks = FakeHooks() + + async def _only_tools(instruction): + await hooks.fire_tool_call_block("bash", {"command": "pytest -q"}) + raise TimeoutError("wall clock") + + with pytest.raises(TimeoutError): + await _spawn(_child_session(hooks, _only_tools)) + + partial = get_partial_output("child-001") + assert partial is not None + assert "bash" in partial["text"] + + +async def test_a_leg_that_produced_literally_nothing_still_reads_as_none(): + """ "Produced nothing" and "produced nothing recoverable" stay the same answer. + + The widening must not manufacture a partial out of an empty accumulator -- + that would turn `partial_available: false` into a lie in the other + direction. + """ + hooks = FakeHooks() + + async def _dies_immediately(instruction): + raise TimeoutError("wall clock") + + with pytest.raises(TimeoutError): + await _spawn(_child_session(hooks, _dies_immediately)) + + assert get_partial_output("child-001") is None + + +# --------------------------------------------------------------------------- +# GUIDANCE HONESTY +# +# foundation f42f48c picks the guidance string itself, from `bool(text)`: +# +# _PARTIAL_GUIDANCE: "...is unfinished work salvaged from the agent +# mid-flight -- it has NOT been checked, concluded, or self-reviewed..." +# +# That sentence is TRUE of assistant prose and FALSE of raw thinking: prose +# is at least addressed to a reader, reasoning never was. foundation is a +# different repo and this lane does not cross that boundary, so the honesty +# is carried two ways the producer DOES own -- the `source` field, and a +# label inside the content itself. +# --------------------------------------------------------------------------- + + +async def test_text_only_case_is_byte_identical_so_the_guidance_is_unchanged(): + """A leg that DID emit text gets exactly today's record, field for field. + + This is what keeps foundation's `_PARTIAL_GUIDANCE` honest where it was + already honest: same `text`, same `segments`, same `source`, therefore + the same guidance string, byte for byte. + """ + hooks = FakeHooks() + + async def _text_then_dies(instruction): + await hooks.fire_text_block("anchor A1 confirmed. ") + await hooks.fire_text_block("anchor A2 confirmed. ") + raise TimeoutError("wall clock") + + with pytest.raises(TimeoutError): + await _spawn(_child_session(hooks, _text_then_dies)) + + assert get_partial_output("child-001") == { + "text": "anchor A1 confirmed. anchor A2 confirmed. ", + "segments": 2, + "source": "spawn-accumulator", + } + + +async def test_assistant_text_wins_over_reasoning_when_both_exist(): + """Reasoning never dilutes or displaces real assistant prose. + + A leg that emitted text is the case the shipped guidance already + describes correctly -- so it must keep producing the pre-widening record + even though thinking blocks were also captured. + """ + hooks = FakeHooks() + + async def _thinks_then_writes_then_dies(instruction): + await hooks.fire_thinking_block("private reasoning that is not an answer") + await hooks.fire_tool_call_block("read_file", {"file_path": "/x.py"}) + await hooks.fire_text_block("the actual finding") + raise TimeoutError("wall clock") + + with pytest.raises(TimeoutError): + await _spawn(_child_session(hooks, _thinks_then_writes_then_dies)) + + partial = get_partial_output("child-001") + assert partial["text"] == "the actual finding" + assert partial["segments"] == 1 + assert partial["source"] == "spawn-accumulator" + assert "private reasoning" not in partial["text"] + + +async def test_recovered_reasoning_names_itself_as_reasoning_not_draft_output(): + """The content says what it is, because the guidance string cannot. + + Handing a model its own unreviewed reasoning while calling it "unfinished + work" is a weaker claim than the shipped guidance makes. The producer + cannot change that string (it lives in amplifier-foundation), so it + labels the payload and distinguishes the `source`. + """ + hooks = FakeHooks() + + async def _no_text(instruction): + await hooks.fire_thinking_block("maybe the bug is in the loader") + raise TimeoutError("wall clock") + + with pytest.raises(TimeoutError): + await _spawn(_child_session(hooks, _no_text)) + + partial = get_partial_output("child-001") + assert partial["source"] == "spawn-accumulator:reasoning", ( + "a consumer must be able to tell recovered reasoning from recovered " + "prose WITHOUT parsing the text" + ) + head = partial["text"].lstrip() + assert head.startswith("[RECOVERED FROM AN UNFINISHED DELEGATE"), head[:120] + lowered = partial["text"].lower() + assert "reasoning" in lowered + assert "not" in lowered and "answer" in lowered + + +async def test_the_label_survives_the_consumers_tail_truncation(): + """foundation keeps the TAIL, so a leading-only label would be cut off. + + `_read_partial` (foundation f42f48c) truncates to the LAST + `partial_max_chars` characters. 25 thinking blocks routinely exceed the + 20,000-char default, so the label has to be at the end as well as the + start or it is exactly the long partials that lose it. + """ + hooks = FakeHooks() + + async def _very_talkative(instruction): + for i in range(30): + await hooks.fire_thinking_block("x" * 2000 + f" step {i}") + raise TimeoutError("wall clock") + + with pytest.raises(TimeoutError): + await _spawn(_child_session(hooks, _very_talkative)) + + text = get_partial_output("child-001")["text"] + assert len(text) > 20000, "fixture is not long enough to exercise truncation" + tail = text[-20000:] # what the consumer would actually forward + assert "[END OF RECOVERED" in tail + assert "not a partial answer" in tail + + +# --------------------------------------------------------------------------- +# The inverse guard, restated for the widened accumulator +# --------------------------------------------------------------------------- + + +async def test_normal_completion_with_thinking_still_gains_no_key(): + """Byte-identical result shape for a delegate that finishes normally.""" + hooks = FakeHooks() + + async def _completes(instruction): + await hooks.fire_thinking_block("plenty of reasoning") + await hooks.fire_tool_call_block("read_file", {"file_path": "/x.py"}) + await hooks.fire_text_block("the finished answer") + await hooks.emit( + "orchestrator:complete", + {"status": "success", "turn_count": 5, "metadata": {"o": "loop-basic"}}, + ) + return "agent response" + + result = await _spawn(_child_session(hooks, _completes)) + + assert set(result) == {"output", "session_id", "status", "turn_count", "metadata"} + assert result["output"] == "agent response" + assert session_spawner._PARTIAL_OUTPUTS == {} + assert get_partial_output("child-001") is None + + +async def test_seal_accepts_a_legacy_chunks_only_record(): + """`_seal_partial` predates the widening; old-shaped records still work.""" + _seal_partial("legacy", {"chunks": ["a", "b"]}) + assert get_partial_output("legacy") == { + "text": "ab", + "segments": 2, + "source": "spawn-accumulator", + } + + +async def test_seal_of_a_fully_empty_record_publishes_nothing(): + _seal_partial("empty", {"chunks": [], "reasoning": [], "tool_calls": []}) + assert get_partial_output("empty") is None + assert session_spawner._PARTIAL_OUTPUTS == {}