From 26d5524124f4863348329a28332a55c9603eaeab Mon Sep 17 00:00:00 2001 From: Brian Krabach Date: Thu, 3 Sep 2026 00:36:57 -0700 Subject: [PATCH] feat(tool-delegate): return partial results on per-delegate timeout A delegate that exceeds settings.timeout already RETURNED rather than raised (14d5a52), so completed siblings in the same asyncio.gather batch already survived. What it still discarded was the straggler's own work: there was no channel carrying what the sub-session produced before the deadline, and no flag saying whether any such work existed. - add an optional app-layer `session.partial` capability (sub_session_id) -> {"text", "segments", "source"}, sync or async. Absent, empty, malformed or raising degrades to partial_available: false -- never to an error, because raising out of the timeout handler is precisely what would discard the completed siblings this path protects. - carry partial_available / partial_response / partial_segments / partial_source / partial_truncated / partial_chars_total / completed / guidance on both timeout paths (spawn and resume). Preserved text NEVER lands on `response`, the success-only key. - settings.partial_max_chars (default 20000) caps preserved text, keeping the most recent tail. - emit elapsed_s on delegate:error and in metadata, so leg durations are measured rather than inferred. - BREAKING (small): output/event `status` is now "timeout", was "timed_out", via the single constant TIMEOUT_STATUS. Grep shows no consumer outside this module (not elsewhere in foundation, not in amplifier-app-cli). This is the literal string the downstream eval's gate observes. Normal completions are byte-identical: same script run against the parent tree and this one produces the same serialized output, sha256 18dfd629... on both sides. The source diff removes six lines, all of them "timed_out" literals or timeout f-strings; nothing on the success path is touched. This is HALF of the prerequisite. partial_available is false for every timeout until the app-cli producer half registers session.partial. That is expected and documented, not a defect. 11 of 12 new tests fail on parent 5ebf1da; the one that passes is the byte-identity guard, which must pass on both. Full suite: 1905 passed, 1 skipped (parent: 1893 passed, 1 skipped -- delta is exactly the 12 new tests). Co-authored-by: Amplifier <240397093+microsoft-amplifier@users.noreply.github.com> --- .../DONE-NOTE.md | 298 ++++++++++++++ .../after-probe.txt | 102 +++++ .../byte-identity-normal-completion.txt | 13 + .../fail-before-probe.txt | 82 ++++ .../fail-before-tests.txt | 51 +++ .../patch-apply-check.txt | 13 + .../probe_timeout_contract.py | 193 +++++++++ modules/tool-delegate/README.md | 42 +- .../__init__.py | 216 +++++++++- .../tests/test_delegate_timeout.py | 49 ++- .../tests/test_delegate_timeout_partial.py | 370 ++++++++++++++++++ 11 files changed, 1407 insertions(+), 22 deletions(-) create mode 100644 docs/lanes/bp0-delegate-timeout-partial-consumer/DONE-NOTE.md create mode 100644 docs/lanes/bp0-delegate-timeout-partial-consumer/after-probe.txt create mode 100644 docs/lanes/bp0-delegate-timeout-partial-consumer/byte-identity-normal-completion.txt create mode 100644 docs/lanes/bp0-delegate-timeout-partial-consumer/fail-before-probe.txt create mode 100644 docs/lanes/bp0-delegate-timeout-partial-consumer/fail-before-tests.txt create mode 100644 docs/lanes/bp0-delegate-timeout-partial-consumer/patch-apply-check.txt create mode 100644 docs/lanes/bp0-delegate-timeout-partial-consumer/probe_timeout_contract.py create mode 100644 modules/tool-delegate/tests/test_delegate_timeout_partial.py diff --git a/docs/lanes/bp0-delegate-timeout-partial-consumer/DONE-NOTE.md b/docs/lanes/bp0-delegate-timeout-partial-consumer/DONE-NOTE.md new file mode 100644 index 0000000..a0077ce --- /dev/null +++ b/docs/lanes/bp0-delegate-timeout-partial-consumer/DONE-NOTE.md @@ -0,0 +1,298 @@ +# DONE-NOTE — lane bp0, `model_performance-bp0` + +**W3-PREREQ (1 of 2, CONSUMER): tool-delegate per-delegate timeout must RETURN +partial results instead of discarding the sub-session's work.** + +- Item: `model_performance-bp0` (project `model_performance`) +- Repo: `microsoft/amplifier-foundation`, branch `lane/bp0-delegate-timeout-partial-consumer` +- Parent commit: `5ebf1dab1fba33539e15499698f33cb3b9fc2b78` +- Outcome: **branch A — RESOLVED.** All deliverables DONE. No deliverable + recorded NOT-POSSIBLE. +- Spend: **$0.00 of $0.00 authorized.** No API calls, no DTU, no infrastructure + created, no ledger rows opened. The authority was $0 for a pure code change + and the work needed none, so the arithmetic-closure rule in the goal never + binds here — there is no run-buying deliverable to price. Residue: $0, and + the smallest useful purchase it could not buy is *not applicable* (nothing in + this item is purchasable). + +--- + +## 1. Deliverable status + +| # | Deliverable | Status | +|---|---|---| +| 1 | Siblings survive the straggler (k64 gate G-D1) | **DONE (pinned) — but it was ALREADY TRUE on the parent.** See §3, finding F-1. The fail-before test does NOT show siblings being discarded, because they are not. Reported honestly rather than staged. | +| 2 | Timed-out delegate's own result: `status: "timeout"`, no `"response"` key, `partial_available` boolean | **DONE.** Fail-before proves `partial_available` absent and `status == "timed_out"` on the parent. | +| 3 | Normal completions byte-identical | **DONE — shown, not asserted.** `diff` + `sha256` of the same probe section across the two trees; identical. §5. | +| 4 | Full foundation suite green | **DONE.** 1905 passed / 1 skipped / 1 pre-existing warning. Module suite 189, not APPLY.md's 59 — reconciled in §4. | +| 5 | Re-targeting recorded | **DONE.** §2, hunk by hunk. | +| 6 | Fail-before evidence committed + in PR body | **DONE.** `fail-before-probe.txt`, `fail-before-tests.txt`, `patch-apply-check.txt`. | +| 7 | Draft PR on origin | **DONE.** See `DONE.json` `publication` block (remote read-back). | +| 8 | This DONE-NOTE in the PR body | **DONE.** | + +--- + +## 2. Re-targeting record + +**The patch did not apply. This is the literal result, not a paraphrase** +(`patch-apply-check.txt`): + +``` +$ git apply --check PATCH-foundation-tool-delegate.diff +error: patch failed: modules/tool-delegate/amplifier_module_tool_delegate/__init__.py:20 +error: modules/tool-delegate/amplifier_module_tool_delegate/__init__.py: patch does not apply +exit=1 +``` + +**All 10 source hunks failed. Zero applied.** The base moved much further than +PR #350 alone: 37n verified at `cc7e23aa`, **which is not even an object in +this repository** (`git cat-file -t cc7e23aa` → `Not a valid object name`), and +the file grew from ~1400 lines at 37n's base to **2533** at `5ebf1da`. Nothing +was force-applied. Every hunk below was re-targeted by hand against the current +file. + +### 2.1 Hunk-by-hunk + +| 37n hunk | Target | Applied? | How re-targeted | +|---|---|---|---| +| H1 `@@ -20,6 +20,26 @@` module docstring | settings list + contract block | no | Re-anchored after main's much longer `settings.timeout` entry (which now documents the 14400 s Layer-3 backstop). Contract block reworded to state the RETURN-not-raise invariant explicitly. | +| H2 `@@ -35,7 +55,9 @@` imports | `import inspect`, `import time` | no | `inspect` **already present** — PR #350 added it. Only `import time` was needed. Adding `inspect` again would have been a duplicate import. | +| H3 `@@ -44,6 +66,71 @@` constants + `_build_incomplete_result()` | module level | no | Constants kept (`DEFAULT_PARTIAL_MAX_CHARS`). `_build_incomplete_result()` **replaced** by two additive helpers, `_partial_output_fields()` and `_partial_event_fields()` — see RT-1. Added `TIMEOUT_STATUS` (RT-2) and split the guidance string (RT-4). | +| H4 `@@ -129,10 +216,78 @@` settings + `_collect_partial()` | `__init__` + new method | no | `self.timeout` line differs entirely (main: `_validate_timeout(settings.get("timeout", 14400))`); left untouched, `partial_max_chars` added beside it. `_collect_partial()` ported **verbatim** and placed next to `_await_child_with_deadline` / `_cancel_and_detach_child`, the helpers it serves. | +| H5 `@@ -959,6 +1114,8 @@` `started_at` | `_spawn_new_session` | no | Renamed `leg_started_at` and placed immediately after `parent_session_id`, with a comment saying it is read only on the timeout path. | +| H6+H7 spawn timeout handler | `except _DelegateTimeoutExpired:` | no | Main's handler is structurally different from 37n's base (`_DelegateTimeoutExpired`, not `TimeoutError`; already returns a structured `output`; carries `recovery_msg` / `resumable` / `resume_status`). **Merged additively** rather than replaced — see RT-3. | +| H8 `resume_started_at` | `_resume_existing_session` | no | Same rename/placement as H5. Placed before `resume_agent` derivation, which #350-era code hoisted above the `try`. | +| H9+H10 resume timeout handler | `except _DelegateTimeoutExpired:` | no | Same merge as H6+H7. Main's version also conditionally omits `agent` when unresolvable; that behaviour preserved. | +| H11 new test file (289 lines) | `tests/test_delegate_timeout_partial.py` | n/a | Rewritten (12 tests, 341 lines) against main's `MagicMock` harness — 37n's `FakeCoordinator` lacks `session_state`, `_tool_dispatch_context`, `_tool_dispatch_contexts`, and `get`, all of which main's code paths now touch. | + +### 2.2 Re-targeting decisions + +**RT-1 — `_build_incomplete_result()` dropped; two additive helpers instead.** +37n's helper *constructs the whole* `ToolResult`, replacing main's timeout +output wholesale. That would have silently deleted `metadata.resumable`, +`metadata.resume_status`, and `metadata.recovery_message` — the contract +`14d5a52` deliberately shipped. `_partial_output_fields()` / +`_partial_event_fields()` return only the *new* keys, spliced into main's +existing dicts with `**`. Nothing incumbent was removed. + +**RT-2 — `status` changed `"timed_out"` → `"timeout"`. THE ONE BREAKING +CHANGE IN THIS PR; flag it in review.** +k64's gate G-D4 is quoted verbatim in the item: *"every observed timeout +result carries status `"timeout"`"*. `"timed_out"` is not that string and is +not a substring of it, so k64 would fail G-D4 on a string mismatch even after +both halves land. Blast radius measured before changing it: + +``` +$ grep -rn "timed_out" . | grep -v modules/tool-delegate # foundation repo +(no matches) +$ grep -rn "timed_out" +(no matches) +``` + +Only this module's own code, its own README, and its own tests. Changed on +**both** channels (tool result output and the `delegate:error` payload) so the +two never disagree, via a single constant `TIMEOUT_STATUS` — reverting is a +one-line change if a reviewer or the k64 harness prefers the incumbent string. +10 assertions in `test_delegate_timeout.py` and one README line updated. + +**RT-3 — additive merge, not replacement, in both handlers.** New top-level +keys: `completed`, `partial_available`, `partial_response`, `partial_segments`, +`partial_source`, `partial_truncated`, `partial_chars_total`, `guidance`. New +metadata key: `elapsed_s`. Everything already there is unchanged. + +**RT-4 — 37n's `_INCOMPLETE_GUIDANCE` rewritten because it CONTRADICTED main.** +37n's text says *"Either resume the sub-session with the 'session_id' above"*. +Main's `recovery_message` says *"do not resume this session until cleanup and +persistence complete"* and sets `resumable: false`. Shipping both would have +handed the model two opposing instructions in one payload. The guidance was +rewritten to cover only what the partial text *is* (unfinished work, not a +result) and to defer to `metadata.recovery_message` on resumption. Split into +`_PARTIAL_GUIDANCE` / `_NO_PARTIAL_GUIDANCE` so the no-partial case does not +point at a `partial_response` that is `None`. + +**RT-5 — 37n's top-level `timeout_s` dropped.** Main already carries +`metadata.timeout_seconds`. A second key with the same value under a different +name is a trap for consumers. `elapsed_s` is genuinely new, so it was added +(to `metadata`, beside `timeout_seconds`, and to the event payload, where +gate G-D3 needs it). + +**RT-6 — 37n's event key `reason: "timeout"` dropped.** Main already emits +`error_type: "delegate_timeout"` plus `status`. The test was re-targeted to +assert those instead. + +**RT-7 — 37n's `test_timeout_default_remains_disabled` NOT ported.** It asserts +`tool.timeout is None`. `14d5a52` ("bound delegated sessions by default, Layer 3 +wall-clock backstop, 14400s") deliberately changed that default *after* 37n's +base. Porting the assertion would have silently reverted that commit. Replaced +with `test_partial_max_chars_default_is_shipped_not_swept`, which pins only +what this change introduces and asserts `tool.timeout == 14400` to make the +non-regression explicit. The timeout default remains owned by +`test_delegate_timeout.py::test_timeout_defaults_only_when_key_is_absent`. + +**RT-8 — one test added beyond 37n's 11.** +`test_resume_timeout_carries_the_same_partial_contract`. Main has *two* timeout +call sites; 37n's tests only covered spawn. An uncovered second call site is +exactly how the two paths drift apart. + +--- + +## 3. Findings + +### F-1 (material, for k64) — gate G-D1 was ALREADY satisfied on the parent commit + +The item and goal describe two harms. **Only one of them still existed.** + +`14d5a52` (landed after 37n's base) already made the timeout handler *return* a +structured `ToolResult` instead of raising. Measured on `5ebf1da`, unmodified +(`fail-before-probe.txt`, probe C — the real `asyncio.gather` shape, no +`return_exceptions`): + +``` +--- C. G-D1 sibling survival --- +gather returned; completed siblings surviving = 2 of 2; +discarded-completed-sibling count = 0 +``` + +So: **there is no fail-before test proving siblings are discarded, because on +`5ebf1da` they are not.** Writing one that "failed" would have required +staging a defect that no longer exists. What this PR contributes to G-D1 is a +**regression pin** — +`test_straggler_returns_rather_than_raises_so_siblings_survive` — so the +property cannot silently regress. + +Note the trap in the raw pytest output: that test *does* appear in the +fail-before FAILED list (`fail-before-tests.txt`). It fails on its +`status == "timeout"` assertion (deliverable 2), **not** on sibling survival. +The probe is the evidence for G-D1; the pytest run is not. k64's measured +1.2% (4/533) harm rate for discarded siblings predates `14d5a52` and should be +re-derived before it is quoted as current. + +### F-2 — the real remaining gap was deliverable 2, and it was fully unmet + +On `5ebf1da`, both timeout paths: `status == "timed_out"`, `partial_available` +**absent entirely**. `"response"` was already correctly absent. 11 of 12 new +tests fail on the parent; the 1 that passes is +`test_success_result_carries_no_partial_keys` — which is the byte-identity +guard and is *supposed* to pass on both sides. + +### F-3 — `partial_available` is `false` for every timeout in this repo, by design + +Nothing registers a `session.partial` capability in amplifier-foundation, so +`_collect_partial()` always degrades to no-partial. This is the documented, +correct state until the app-cli producer half (`model_performance-9w0`) lands. +**k64 will hit gate G-D4's stop condition — `PARTIAL-PATH-NOT-EXERCISED` — if +it runs with only this half merged.** Not faked, per the goal's explicit +instruction. + +### F-4 — CI does not run these tests (pre-existing, not this lane's to fix) + +`.github/workflows/ci.yml` runs `uv run pytest tests/ -q --tb=short`. +`pyproject.toml` sets `testpaths = ["tests", "modules/tool-delegate/tests"]`, +but the explicit `tests/` argument overrides it. **Every test in this PR, and +all 177 pre-existing module tests, are invisible to CI.** Verified locally +instead; the exact commands are in §4. + +--- + +## 4. Verification + +``` +$ uv run pytest -q # patched tree +1905 passed, 1 skipped, 1 warning in 21.33s + +$ git stash -u && uv run pytest -q # parent 5ebf1da +1893 passed, 1 skipped, 1 warning in 21.91s + +$ uv run pytest modules/tool-delegate/tests -q +189 passed in 0.74s + +$ uv run ruff check modules/tool-delegate/ docs/lanes/bp0-.../ +All checks passed! +``` + +Delta is exactly **+12**, the 12 new tests. The 1 warning is the pre-existing +`RuntimeWarning` in `tests/test_subprocess_runner.py`, present on both sides. + +**Reconciliation of APPLY.md's "59 passed (48 pre-existing + 11 new)".** Both +numbers are stale. The module suite has **177** pre-existing tests at `5ebf1da`, +not 48 — it grew by ~129 across the return-contract, call-budget, +spawn-matrix-provenance and resume-routing work that landed after 37n's base. +12 new tests (11 ported + RT-8) gives **189**, and 189 is what runs. The +predicted 59 was never reachable at this base. + +## 5. Byte-identity for normal completions — shown, not asserted + +Two independent lines of evidence. + +**Empirical** (`byte-identity-normal-completion.txt`). The probe's section D +runs a *normal* delegate completion and prints both the output dict and the +exact serialized string the model receives. Same script, parent tree vs +patched tree, `diff`ed verbatim: + +``` +$ diff <(sed -n "/^--- D./,$p" fail-before-probe.txt) \ + <(sed -n "/^--- D./,$p" after-probe.txt) +(no output -- IDENTICAL) + +18dfd629b68861f7c11e2182a6d730f5e26cef39d48b8d4a9396b63b587a0ab1 D-before.txt +18dfd629b68861f7c11e2182a6d730f5e26cef39d48b8d4a9396b63b587a0ab1 D-after.txt +``` + +**Structural.** `git diff` on the source file removes exactly **6** lines, and +every one of them is a `"timed_out"` status literal or a timeout message +f-string: + +``` +- f"(delegate tool session-level timeout). {recovery_msg}" +- "status": "timed_out", +- "status": "timed_out", +- f"(delegate tool session-level timeout). {recovery_msg}" +- "status": "timed_out", +- "status": "timed_out", +``` + +Zero lines removed from the success-return path. `partial_max_chars` and +`_collect_partial()` are reachable only from inside +`except _DelegateTimeoutExpired:`. `leg_started_at` is one `time.monotonic()` +call per leg, read only on timeout. + +Also pinned as a test: +`test_success_result_carries_no_partial_keys` asserts no key starting with +`partial` and no `completed` key on a success result — and it is the one test +that passes on **both** the parent and the patched tree. + +## 6. Deviations from the goal + +1. **Deliverable 1's fail-before could not be produced as specified**, because + the harm it describes no longer exists on the parent commit (F-1). Recorded + as a finding with the measurement, not worked around. +2. **RT-2 is a breaking change to a shipped string.** The goal did not ask for + one; it asked for `status: "timeout"`, which on this base *is* one. Called + out here and in the PR body so a reviewer can push back explicitly rather + than discover it. +3. **One test beyond 37n's 11** (RT-8), covering the resume timeout path. + +## 7. What remains open + +- **k64 stays blocked.** The producer half, `model_performance-9w0` in + `amplifier-app-cli`, must land before `partial_available` can ever be `true` + and before G-D4 can pass. Not touched by this lane (explicit scope-out). +- **Do not enable `settings.timeout` sweeps or run k64's eval yet** — separate, + separately funded items. +- **F-4 (CI excludes `modules/tool-delegate/tests`)** is unfiled here; it is a + pre-existing gap in another owner's scope. +- **RT-2 needs a decision** from whoever owns k64's harness: keep + `status: "timeout"` (this PR) or revert `TIMEOUT_STATUS` to `"timed_out"` and + teach the harness the incumbent string. One line either way. + +## 8. Artifacts in this directory + +| File | What | +|---|---| +| `DONE-NOTE.md` | this note | +| `probe_timeout_contract.py` | the behavioural probe; runs against any importable tree | +| `fail-before-probe.txt` | probe output on `5ebf1da`, unmodified | +| `after-probe.txt` | probe output on the patched tree | +| `fail-before-tests.txt` | `pytest` on `5ebf1da`: 11 failed, 1 passed | +| `byte-identity-normal-completion.txt` | the `diff` + `sha256` of §5 | +| `patch-apply-check.txt` | `git apply --check` refusing 37n's diff | diff --git a/docs/lanes/bp0-delegate-timeout-partial-consumer/after-probe.txt b/docs/lanes/bp0-delegate-timeout-partial-consumer/after-probe.txt new file mode 100644 index 0000000..d9cc937 --- /dev/null +++ b/docs/lanes/bp0-delegate-timeout-partial-consumer/after-probe.txt @@ -0,0 +1,102 @@ +PATCHED TREE (working copy on top of 5ebf1da) +DATE: 2026-09-03T07:33:00Z +CMD: PYTHONPATH=modules/tool-delegate uv run python docs/lanes/bp0-delegate-timeout-partial-consumer/probe_timeout_contract.py + +Agent 'test-agent' timed out after 0.01s (delegate tool session-level timeout; elapsed 0.01s). Partial output was preserved and is returned under 'partial_response' -- it is UNFINISHED, not a result. Child cancellation cleanup is still in progress; do not resume this session until cleanup and persistence complete. +Resumed agent 'test-agent' timed out after 0.01s (delegate tool session-level timeout; elapsed 0.01s). Partial output was preserved and is returned under 'partial_response' -- it is UNFINISHED, not a result. Child cancellation cleanup is still in progress; do not resume this session until cleanup and persistence complete. +Agent 'test-agent' timed out after 0.01s (delegate tool session-level timeout; elapsed 0.01s). Partial output was preserved and is returned under 'partial_response' -- it is UNFINISHED, not a result. Child cancellation cleanup is still in progress; do not resume this session until cleanup and persistence complete. +--- A. spawn timeout: result.success --- +false + +--- A. spawn timeout: result.output --- +{ + "agent": "test-agent", + "completed": false, + "guidance": "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.", + "metadata": { + "elapsed_s": "", + "recovery_message": "Child cancellation cleanup is still in progress; do not resume this session until cleanup and persistence complete.", + "resumable": false, + "resume_status": "pending_child_cleanup", + "timeout_seconds": 0.01 + }, + "partial_available": true, + "partial_chars_total": 22, + "partial_response": "straggler got this far", + "partial_segments": 7, + "partial_source": "capability", + "partial_truncated": false, + "session_id": "0000000000000000-c7ab32b24e5947fc_test-agent", + "status": "timeout" +} + +--- A. spawn timeout: delegate:error payload (elapsed_s dropped) --- +{ + "agent": "test-agent", + "error": "Agent 'test-agent' timed out after 0.01s (delegate tool session-level timeout; elapsed 0.01s). Partial output was preserved and is returned under 'partial_response' -- it is UNFINISHED, not a result. Child cancellation cleanup is still in progress; do not resume this session until cleanup and persistence complete.", + "error_type": "delegate_timeout", + "parallel_group_id": "parallel-timeout", + "parent_session_id": "parent-session-123", + "partial_available": true, + "partial_chars": 22, + "resumable": false, + "resume_status": "pending_child_cleanup", + "status": "timeout", + "sub_session_id": "", + "timeout_seconds": 0.01, + "tool_call_id": "call-timeout" +} + +A. CONTRACT: status==timeout | 'response' absent==True | 'partial_available' present==True + +--- B. resume timeout: result.output --- +{ + "agent": "test-agent", + "completed": false, + "guidance": "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.", + "metadata": { + "elapsed_s": "", + "recovery_message": "Child cancellation cleanup is still in progress; do not resume this session until cleanup and persistence complete.", + "resumable": false, + "resume_status": "pending_child_cleanup", + "timeout_seconds": 0.01 + }, + "partial_available": true, + "partial_chars_total": 22, + "partial_response": "straggler got this far", + "partial_segments": 7, + "partial_source": "capability", + "partial_truncated": false, + "session_id": "child-session-001_test-agent", + "status": "timeout" +} + +B. CONTRACT: status==timeout | 'response' absent==True | 'partial_available' present==True + +--- C. G-D1 sibling survival --- +gather returned; completed siblings surviving = 2 of 2; discarded-completed-sibling count = 0 + +--- D. normal completion: result.success --- +true + +--- D. normal completion: result.output --- +{ + "agent": "test-agent", + "contract": { + "artifacts": [], + "conformant": null, + "findings": [], + "not_covered": [], + "reason": null, + "summary": null + }, + "metadata": {}, + "response": "the whole answer", + "session_id": "sub-1", + "status": "success", + "turn_count": 3 +} + +D. normal completion: serialized output +{"response": "the whole answer", "session_id": "sub-1", "agent": "test-agent", "turn_count": 3, "status": "success", "metadata": {}, "contract": {"conformant": null, "reason": null, "summary": null, "findings": [], "not_covered": [], "artifacts": []}} + diff --git a/docs/lanes/bp0-delegate-timeout-partial-consumer/byte-identity-normal-completion.txt b/docs/lanes/bp0-delegate-timeout-partial-consumer/byte-identity-normal-completion.txt new file mode 100644 index 0000000..656cdd3 --- /dev/null +++ b/docs/lanes/bp0-delegate-timeout-partial-consumer/byte-identity-normal-completion.txt @@ -0,0 +1,13 @@ +BYTE-IDENTITY CHECK -- normal (non-timeout) delegate completion +DATE: 2026-09-03T07:33:09Z + +Section D of the probe is a NORMAL completion. Compared verbatim between the +parent commit 5ebf1da (fail-before-probe.txt) and the patched tree (after-probe.txt). +It includes the exact serialized string the model receives. + +$ diff <(sed -n "/^--- D./,$p" fail-before-probe.txt) <(sed -n "/^--- D./,$p" after-probe.txt) +(no output -- IDENTICAL) + +RESULT: byte-identical. sha256 of each section: +18dfd629b68861f7c11e2182a6d730f5e26cef39d48b8d4a9396b63b587a0ab1 D-before.txt +18dfd629b68861f7c11e2182a6d730f5e26cef39d48b8d4a9396b63b587a0ab1 D-after.txt diff --git a/docs/lanes/bp0-delegate-timeout-partial-consumer/fail-before-probe.txt b/docs/lanes/bp0-delegate-timeout-partial-consumer/fail-before-probe.txt new file mode 100644 index 0000000..bb9cb92 --- /dev/null +++ b/docs/lanes/bp0-delegate-timeout-partial-consumer/fail-before-probe.txt @@ -0,0 +1,82 @@ +PARENT COMMIT: 5ebf1dab1fba33539e15499698f33cb3b9fc2b78 (fix(activator): install a bundle root's package only when a declared module lives there; fail by name) +DATE: 2026-09-03T07:29:51Z +CMD: PYTHONPATH=modules/tool-delegate uv run python docs/lanes/bp0-delegate-timeout-partial-consumer/probe_timeout_contract.py + +Agent 'test-agent' timed out after 0.01s (delegate tool session-level timeout). Child cancellation cleanup is still in progress; do not resume this session until cleanup and persistence complete. +Resumed agent 'test-agent' timed out after 0.01s (delegate tool session-level timeout). Child cancellation cleanup is still in progress; do not resume this session until cleanup and persistence complete. +Agent 'test-agent' timed out after 0.01s (delegate tool session-level timeout). Child cancellation cleanup is still in progress; do not resume this session until cleanup and persistence complete. +--- A. spawn timeout: result.success --- +false + +--- A. spawn timeout: result.output --- +{ + "agent": "test-agent", + "metadata": { + "recovery_message": "Child cancellation cleanup is still in progress; do not resume this session until cleanup and persistence complete.", + "resumable": false, + "resume_status": "pending_child_cleanup", + "timeout_seconds": 0.01 + }, + "session_id": "0000000000000000-d13c50c4216142b9_test-agent", + "status": "timed_out" +} + +--- A. spawn timeout: delegate:error payload (elapsed_s dropped) --- +{ + "agent": "test-agent", + "error": "Agent 'test-agent' timed out after 0.01s (delegate tool session-level timeout). Child cancellation cleanup is still in progress; do not resume this session until cleanup and persistence complete.", + "error_type": "delegate_timeout", + "parallel_group_id": "parallel-timeout", + "parent_session_id": "parent-session-123", + "resumable": false, + "resume_status": "pending_child_cleanup", + "status": "timed_out", + "sub_session_id": "", + "timeout_seconds": 0.01, + "tool_call_id": "call-timeout" +} + +A. CONTRACT: status==timed_out | 'response' absent==True | 'partial_available' present==False + +--- B. resume timeout: result.output --- +{ + "agent": "test-agent", + "metadata": { + "recovery_message": "Child cancellation cleanup is still in progress; do not resume this session until cleanup and persistence complete.", + "resumable": false, + "resume_status": "pending_child_cleanup", + "timeout_seconds": 0.01 + }, + "session_id": "child-session-001_test-agent", + "status": "timed_out" +} + +B. CONTRACT: status==timed_out | 'response' absent==True | 'partial_available' present==False + +--- C. G-D1 sibling survival --- +gather returned; completed siblings surviving = 2 of 2; discarded-completed-sibling count = 0 + +--- D. normal completion: result.success --- +true + +--- D. normal completion: result.output --- +{ + "agent": "test-agent", + "contract": { + "artifacts": [], + "conformant": null, + "findings": [], + "not_covered": [], + "reason": null, + "summary": null + }, + "metadata": {}, + "response": "the whole answer", + "session_id": "sub-1", + "status": "success", + "turn_count": 3 +} + +D. normal completion: serialized output +{"response": "the whole answer", "session_id": "sub-1", "agent": "test-agent", "turn_count": 3, "status": "success", "metadata": {}, "contract": {"conformant": null, "reason": null, "summary": null, "findings": [], "not_covered": [], "artifacts": []}} + diff --git a/docs/lanes/bp0-delegate-timeout-partial-consumer/fail-before-tests.txt b/docs/lanes/bp0-delegate-timeout-partial-consumer/fail-before-tests.txt new file mode 100644 index 0000000..e9899fa --- /dev/null +++ b/docs/lanes/bp0-delegate-timeout-partial-consumer/fail-before-tests.txt @@ -0,0 +1,51 @@ +PARENT COMMIT: 5ebf1dab1fba33539e15499698f33cb3b9fc2b78 +CMD: uv run pytest -q +WHY THE SHIM: on the parent commit the module exports no DEFAULT_PARTIAL_MAX_CHARS, so the real +file dies at collection and yields ONE error instead of per-behaviour evidence. The shim defaults +that one constant and changes nothing else, so each test fails on its own assertion. + + """ + tool = _make_tool() +> assert tool.partial_max_chars == DEFAULT_PARTIAL_MAX_CHARS == 20000 + ^^^^^^^^^^^^^^^^^^^^^^ +E AttributeError: 'DelegateTool' object has no attribute 'partial_max_chars' + +modules/tool-delegate/tests/test_zz_failbefore_shim.py:349: AttributeError +____________ test_resume_timeout_carries_the_same_partial_contract _____________ + + @pytest.mark.asyncio + async def test_resume_timeout_carries_the_same_partial_contract(): + """The resume path is a second timeout call site; it must not diverge.""" + hooks = _hooks() + tool = _make_tool( + timeout=0.01, + resume_fn=AsyncMock(side_effect=_never_finishes), + partial_fn=lambda sid: {"text": "resumed partial", "segments": 3}, + ) + result = await _resume(tool, hooks) + + assert result.success is False + assert "response" not in result.output +> assert result.output["status"] == "timeout" +E AssertionError: assert 'timed_out' == 'timeout' +E +E - timeout +E + timed_out +E ? ++ + +modules/tool-delegate/tests/test_zz_failbefore_shim.py:366: AssertionError +------------------------------ Captured log call ------------------------------- +WARNING amplifier_module_tool_delegate:__init__.py:2481 Resumed agent 'test-agent' timed out after 0.01s (delegate tool session-level timeout). Child cancellation cleanup is still in progress; do not resume this session until cleanup and persistence complete. +=========================== short test summary info ============================ +FAILED modules/tool-delegate/tests/test_zz_failbefore_shim.py::test_timeout_is_not_success_on_either_channel +FAILED modules/tool-delegate/tests/test_zz_failbefore_shim.py::test_partial_text_never_lands_on_the_success_key +FAILED modules/tool-delegate/tests/test_zz_failbefore_shim.py::test_straggler_returns_rather_than_raises_so_siblings_survive +FAILED modules/tool-delegate/tests/test_zz_failbefore_shim.py::test_no_partial_capability_degrades_to_no_partial_not_to_error +FAILED modules/tool-delegate/tests/test_zz_failbefore_shim.py::test_partial_capability_raising_does_not_break_the_timeout_path +FAILED modules/tool-delegate/tests/test_zz_failbefore_shim.py::test_async_partial_capability_is_supported +FAILED modules/tool-delegate/tests/test_zz_failbefore_shim.py::test_partial_text_is_capped_and_keeps_the_tail +FAILED modules/tool-delegate/tests/test_zz_failbefore_shim.py::test_malformed_partial_payload_is_ignored +FAILED modules/tool-delegate/tests/test_zz_failbefore_shim.py::test_timeout_event_carries_elapsed_and_partial_flags +FAILED modules/tool-delegate/tests/test_zz_failbefore_shim.py::test_partial_max_chars_default_is_shipped_not_swept +FAILED modules/tool-delegate/tests/test_zz_failbefore_shim.py::test_resume_timeout_carries_the_same_partial_contract +11 failed, 1 passed in 0.24s diff --git a/docs/lanes/bp0-delegate-timeout-partial-consumer/patch-apply-check.txt b/docs/lanes/bp0-delegate-timeout-partial-consumer/patch-apply-check.txt new file mode 100644 index 0000000..5603875 --- /dev/null +++ b/docs/lanes/bp0-delegate-timeout-partial-consumer/patch-apply-check.txt @@ -0,0 +1,13 @@ +APPLY.md's literal instruction, run against 5ebf1da: +$ git apply --check PATCH-foundation-tool-delegate.diff +error: patch failed: modules/tool-delegate/amplifier_module_tool_delegate/__init__.py:20 +error: modules/tool-delegate/amplifier_module_tool_delegate/__init__.py: patch does not apply +exit=1 + +$ git apply --3way --check PATCH-foundation-tool-delegate.diff +error: repository lacks the necessary blob to perform 3-way merge. +Falling back to direct application... +error: patch failed: modules/tool-delegate/amplifier_module_tool_delegate/__init__.py:20 +error: modules/tool-delegate/amplifier_module_tool_delegate/__init__.py: patch does not apply +Falling back to direct application... +exit=1 diff --git a/docs/lanes/bp0-delegate-timeout-partial-consumer/probe_timeout_contract.py b/docs/lanes/bp0-delegate-timeout-partial-consumer/probe_timeout_contract.py new file mode 100644 index 0000000..4603dc8 --- /dev/null +++ b/docs/lanes/bp0-delegate-timeout-partial-consumer/probe_timeout_contract.py @@ -0,0 +1,193 @@ +"""Behavioural probe for the per-delegate timeout contract. + +Runs against WHATEVER ``amplifier_module_tool_delegate`` is importable, so the +same script can be executed on the parent commit and on the patched tree and +the two outputs diffed. It asserts nothing: it prints observed facts. + +Probes: + A. the timed-out delegate's own model-visible output (spawn path) + B. the same for the resume path + C. sibling survival under ``asyncio.gather`` (k64 gate G-D1) + D. a NORMAL completion's model-visible output -- the byte-identity baseline + +Usage: + uv run python docs/lanes/bp0-delegate-timeout-partial-consumer/probe_timeout_contract.py +""" + +from __future__ import annotations + +import asyncio +import json +import sys +from unittest.mock import AsyncMock, MagicMock + +from amplifier_module_tool_delegate import DelegateTool + + +def _make_tool(*, timeout, spawn_fn=None, resume_fn=None, partial_fn=None): + coordinator = MagicMock() + coordinator.session_id = "parent-session-123" + coordinator.config = {"agents": {"test-agent": {}}} + coordinator.session_state = {} + coordinator._tool_dispatch_context = {} + coordinator._tool_dispatch_contexts = {} + capabilities = { + "session.spawn": spawn_fn or AsyncMock(), + "session.resume": resume_fn or AsyncMock(), + "self_delegation_depth": 0, + } + if partial_fn is not None: + capabilities["session.partial"] = partial_fn + coordinator.get_capability = lambda name: capabilities.get(name) + coordinator.get = MagicMock(return_value=None) + parent_session = MagicMock() + parent_session.config = {"session": {"orchestrator": {}}} + coordinator.session = parent_session + return DelegateTool( + coordinator, + {"features": {}, "settings": {"exclude_tools": [], "timeout": timeout}}, + ) + + +def _hooks(): + hooks = MagicMock() + hooks.emit = AsyncMock() + return hooks + + +def _emissions(hooks): + return [(a[0], a[1]) for a, _k in hooks.emit.call_args_list] + + +async def _never_finishes(**_kwargs): + await asyncio.Future() + + +async def _completes(**_kwargs): + return {"output": "the whole answer", "session_id": "sub-1", "turn_count": 3} + + +async def _spawn(tool, hooks): + return await tool._spawn_new_session( + agent_name="test-agent", + instruction="Do something", + context_depth="none", + context_scope="conversation", + context_turns=5, + provider_preferences=None, + hooks=hooks, + tool_call_id="call-timeout", + parallel_group_id="parallel-timeout", + ) + + +def _normalise(output): + """Blank out values that legitimately vary run to run.""" + if not isinstance(output, dict): + return output + out = dict(output) + if isinstance(out.get("session_id"), str) and out["session_id"].startswith("sub_"): + out["session_id"] = "" + meta = out.get("metadata") + if isinstance(meta, dict) and "elapsed_s" in meta: + meta = dict(meta) + meta["elapsed_s"] = "" + out["metadata"] = meta + return out + + +def _show(label, value): + print(f"--- {label} ---") + print(json.dumps(value, indent=2, default=str, sort_keys=True)) + print() + + +async def main() -> int: + partial = lambda sid: {"text": "straggler got this far", "segments": 7} # noqa: E731 + + # A. spawn timeout, WITH a session.partial capability registered + tool = _make_tool( + timeout=0.01, + spawn_fn=AsyncMock(side_effect=_never_finishes), + partial_fn=partial, + ) + hooks = _hooks() + res = await _spawn(tool, hooks) + _show("A. spawn timeout: result.success", res.success) + _show("A. spawn timeout: result.output", _normalise(res.output)) + err = next((p for n, p in _emissions(hooks) if n == "delegate:error"), None) + if err is not None: + err = dict(err) + err["sub_session_id"] = "" + err.pop("elapsed_s", None) + _show("A. spawn timeout: delegate:error payload (elapsed_s dropped)", err) + print( + "A. CONTRACT: status=={} | 'response' absent=={} | " + "'partial_available' present=={}\n".format( + (res.output or {}).get("status"), + "response" not in (res.output or {}), + "partial_available" in (res.output or {}), + ) + ) + + # B. resume timeout + tool = _make_tool( + timeout=0.01, + resume_fn=AsyncMock(side_effect=_never_finishes), + partial_fn=partial, + ) + res = await tool._resume_existing_session( + session_id="child-session-001_test-agent", + instruction="Continue", + hooks=_hooks(), + tool_call_id="call-resume-timeout", + parallel_group_id="parallel-resume-timeout", + ) + _show("B. resume timeout: result.output", _normalise(res.output)) + print( + "B. CONTRACT: status=={} | 'response' absent=={} | " + "'partial_available' present=={}\n".format( + (res.output or {}).get("status"), + "response" not in (res.output or {}), + "partial_available" in (res.output or {}), + ) + ) + + # C. G-D1: do completed siblings survive a straggler in the same gather? + fast = _make_tool(timeout=60, spawn_fn=AsyncMock(side_effect=_completes)) + slow = _make_tool( + timeout=0.01, + spawn_fn=AsyncMock(side_effect=_never_finishes), + partial_fn=partial, + ) + try: + results = await asyncio.gather( + _spawn(fast, _hooks()), _spawn(fast, _hooks()), _spawn(slow, _hooks()) + ) + survived = sum(1 for r in results if r.success) + print( + f"--- C. G-D1 sibling survival ---\ngather returned; " + f"completed siblings surviving = {survived} of 2; " + f"discarded-completed-sibling count = {2 - survived}\n" + ) + except BaseException as exc: # noqa: BLE001 - the harm being probed + print( + f"--- C. G-D1 sibling survival ---\ngather RAISED " + f"{type(exc).__name__}: {exc} -> ALL completed siblings discarded\n" + ) + + # D. byte-identity baseline for a NORMAL completion + tool = _make_tool( + timeout=60, spawn_fn=AsyncMock(side_effect=_completes), partial_fn=partial + ) + res = await _spawn(tool, _hooks()) + _show("D. normal completion: result.success", res.success) + _show("D. normal completion: result.output", _normalise(res.output)) + print("D. normal completion: serialized output") + print(res.get_serialized_output()) + print() + return 0 + + +if __name__ == "__main__": + sys.exit(asyncio.run(main())) diff --git a/modules/tool-delegate/README.md b/modules/tool-delegate/README.md index e57f0cb..e5d3951 100644 --- a/modules/tool-delegate/README.md +++ b/modules/tool-delegate/README.md @@ -89,12 +89,44 @@ Layer 1 does not apply. Configure `settings.timeout` with a positive finite number of seconds to change the limit, or set it explicitly to `null` to disable the delegate-level timeout. +A timeout **returns; it never raises.** That is load-bearing: delegates in a +parallel batch are awaited under `asyncio.gather` with no `return_exceptions`, +so a raising straggler would propagate and discard every *completed* sibling's +result in the same batch. + A timeout returns `success: false` with structured output containing -`status: timed_out`, the child `session_id`, the agent identity when available, -and metadata with `timeout_seconds`, `resumable: false`, and -`resume_status: pending_child_cleanup`. It emits `delegate:error` with -`error_type: delegate_timeout`, not `delegate:agent_completed`, because the -cancelled child may still be cleaning up. +`status: timeout`, `completed: false`, the child `session_id`, the agent +identity when available, and metadata with `timeout_seconds`, `elapsed_s`, +`resumable: false`, and `resume_status: pending_child_cleanup`. It emits +`delegate:error` with `error_type: delegate_timeout`, not +`delegate:agent_completed`, because the cancelled child may still be cleaning +up. + +#### Partial results on timeout + +The output also carries a `partial_available` boolean and, when true, the +straggler's recovered text under `partial_response` -- **never** under +`response`, which is the success-only key. Supporting fields: +`partial_segments`, `partial_source`, `partial_truncated`, +`partial_chars_total`, and a `guidance` string stating plainly that the text +is unfinished work, not a result. `settings.partial_max_chars` (default +`20000`) caps the preserved text, keeping the most recent tail. + +Recovery is best-effort and **optional**. The app layer may register a +`session.partial` capability: + +``` +(sub_session_id: str) -> {"text": str, "segments": int, "source": str} | None +``` + +sync or async. When it is absent, returns nothing, returns something +malformed, or raises, the result degrades to `partial_available: false`. It +never degrades to success, and recovery never raises out of the timeout path +-- a raise there would discard the very siblings this path protects. + +**`partial_available` is `false` for every timeout until an app layer +registers that capability.** That is the correct, expected state of this repo +on its own, not a defect to work around. Do not immediately resume the returned session ID. The coordinated persistence-capable `amplifier-app-cli` spawner may persist the interrupted diff --git a/modules/tool-delegate/amplifier_module_tool_delegate/__init__.py b/modules/tool-delegate/amplifier_module_tool_delegate/__init__.py index 79d817a..eaee897 100644 --- a/modules/tool-delegate/amplifier_module_tool_delegate/__init__.py +++ b/modules/tool-delegate/amplifier_module_tool_delegate/__init__.py @@ -29,6 +29,29 @@ needs attention, not that this default is too generous. Timeouts return the child session ID, but callers must wait for app-layer cancellation cleanup and persistence before attempting to resume it. +- settings.partial_max_chars: Cap on preserved partial text on timeout + (default: 20000). See the timeout/partial-result contract below. + +Timeout / partial-result contract: + A delegate that exceeds ``settings.timeout`` returns an INCOMPLETE result, + never a successful one, and never raises -- so completed siblings in the + same parallel batch (``asyncio.gather``, no ``return_exceptions``) keep + their own results. Both channels say the leg is incomplete, and they agree: + + * ``ToolResult.success`` is ``False`` + * the model-visible ``output`` carries ``status: "timeout"``, + ``completed: false``, a ``partial_available`` boolean, and any + recovered text under ``partial_response`` -- NEVER under ``response``, + which is the success-only key. + + Recovering the straggler's own partial text is best-effort and optional. + The app layer may register a ``session.partial`` capability:: + + (sub_session_id: str) -> {"text": str, "segments": int, "source": str} | None + + (sync or async). When it is absent, returns nothing, or raises, the result + degrades to ``partial_available: false``. It never degrades to success, and + partial recovery never raises out of the timeout path. - settings.strict_model_role: When True, a model_role that resolves to no candidates raises ModelRoleUnresolvedError instead of silently falling back to the session default model (default: False). Regardless of this @@ -55,6 +78,7 @@ import logging import math import re +import time from collections.abc import Coroutine from typing import Any @@ -65,6 +89,76 @@ logger = logging.getLogger(__name__) +# Default cap on preserved partial text (characters). A straggler can have +# produced megabytes; the point is to hand the caller the recoverable tail, +# not to blow up its context window. +DEFAULT_PARTIAL_MAX_CHARS = 20000 + +#: The single model-visible ``status`` value for a delegate that exceeded +#: ``settings.timeout``, on BOTH the spawn and resume paths, and on the +#: ``delegate:error`` event that accompanies them. One constant, one string, +#: one place to change it. +TIMEOUT_STATUS = "timeout" + +# Guidance embedded in every timeout result that actually carries partial +# text. The caller is an LLM; "this is not a completed result" has to survive +# being read as prose as well as being read as a field. +# +# Deliberately says NOTHING about resuming. The incumbent timeout contract +# (see metadata.recovery_message) states the child is NOT resumable until +# app-layer cancellation cleanup completes, so guidance that recommended +# resuming would directly contradict it. +_PARTIAL_GUIDANCE = ( + "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." +) + +_NO_PARTIAL_GUIDANCE = ( + "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 work yourself; see metadata.recovery_message before " + "considering this session for resumption." +) + + +def _partial_output_fields(partial: dict[str, Any]) -> dict[str, Any]: + """The additive timeout-result keys describing recovered partial work. + + INVARIANT (tested): none of these is ``response``. Preserved text lives + under ``partial_response`` so that no consumer keyed on the success + channel can read an unfinished delegate as a finished one, and + ``partial_available`` states plainly whether any exists. + """ + text = partial.get("text") or "" + return { + "completed": False, + "partial_available": bool(text), + "partial_response": text or None, + "partial_segments": partial.get("segments", 0), + "partial_source": partial.get("source", "none"), + "partial_truncated": bool(partial.get("truncated")), + "partial_chars_total": partial.get("chars_total", len(text)), + "guidance": _PARTIAL_GUIDANCE if text else _NO_PARTIAL_GUIDANCE, + } + + +def _partial_event_fields(partial: dict[str, Any], elapsed_s: float) -> dict[str, Any]: + """The additive ``delegate:error`` fields for a timeout leg. + + ``elapsed_s`` is emitted rather than inferred so a measurement harness can + read real leg durations off the event stream. + """ + text = partial.get("text") or "" + return { + "elapsed_s": elapsed_s, + "partial_available": bool(text), + "partial_chars": partial.get("chars_total", len(text)), + } + class ModelRoleUnresolvedError(RuntimeError): """Raised when ``model_role`` resolves to no candidates under strict mode. @@ -480,6 +574,12 @@ def __init__(self, coordinator: ModuleCoordinator, config: dict[str, Any]): self.exclude_tools: list[str] = settings.get("exclude_tools", ["tool-delegate"]) self.exclude_hooks: list[str] = settings.get("exclude_hooks", []) self.timeout = _validate_timeout(settings.get("timeout", 14400)) + # Cap on partial text preserved when the timeout above fires. Only + # ever consulted on the timeout path; a normal completion never + # reads it. + self.partial_max_chars: int = settings.get( + "partial_max_chars", DEFAULT_PARTIAL_MAX_CHARS + ) self._detached_child_tasks: set[asyncio.Task[Any]] = set() # When True, model_role resolving to no candidates raises # ModelRoleUnresolvedError instead of silently falling back to the @@ -660,6 +760,68 @@ def _consume_detached_child_result(self, child_task: asyncio.Task[Any]) -> None: finally: self._detached_child_tasks.discard(child_task) + async def _collect_partial(self, sub_session_id: str) -> dict[str, Any]: + """Best-effort recovery of a timed-out delegate's preserved partial text. + + Optional app-layer contract: a ``session.partial`` capability mapping a + sub_session_id to ``{"text", "segments", "source"}``, where ``segments`` + is the count of preserved assistant text segments. Absent, empty, + malformed, or raising -> ``source: "none"`` and no text. + + This function NEVER raises. A failure to recover partial text must not + convert a handled timeout into an unhandled error -- that would discard + the completed siblings this whole path exists to protect. + """ + empty: dict[str, Any] = {"text": "", "segments": 0, "source": "none"} + try: + getter = ( + self.coordinator.get_capability("session.partial") + if hasattr(self.coordinator, "get_capability") + else None + ) + except Exception as e: # pragma: no cover - defensive + logger.debug("session.partial capability lookup failed: %s", e) + return empty + if getter is None: + return empty + + try: + recovered = getter(sub_session_id) + if inspect.isawaitable(recovered): + recovered = await recovered + except Exception as e: + logger.warning( + "session.partial capability raised for %s: %s", sub_session_id, e + ) + return empty + + if not isinstance(recovered, dict): + return empty + text = recovered.get("text") or "" + if not isinstance(text, str): + text = str(text) + chars_total = len(text) + truncated = False + if self.partial_max_chars and chars_total > self.partial_max_chars: + # Keep the TAIL: the most recent work is the most informative and + # the closest to what the agent was about to conclude. + text = ( + f"[... {chars_total - self.partial_max_chars} characters of " + "earlier partial output truncated ...]\n" + + text[-self.partial_max_chars :] + ) + truncated = True + segments = recovered.get("segments", 0) + if not isinstance(segments, int): + segments = 0 + return { + "text": text, + "segments": segments, + "source": recovered.get("source") or ("capability" if text else "none"), + "truncated": truncated, + "chars_total": chars_total, + } + def _compose_feature_descriptions(self) -> str: """Compose feature descriptions based on enabled state. @@ -1765,6 +1927,11 @@ async def _spawn_new_session( """ parent_session_id = self.coordinator.session_id + # Start of this delegation leg's wall clock. Only ever read on the + # timeout path, where the elapsed value is emitted rather than + # inferred so a harness can read real leg durations off the events. + leg_started_at = time.monotonic() + # Generate hierarchical sub-session ID (sanitized for filesystem safety) sub_session_id = generate_sub_session_id( agent_name=agent_name, @@ -2090,13 +2257,27 @@ async def _spawn_new_session( raise except _DelegateTimeoutExpired: + elapsed_s = round(time.monotonic() - leg_started_at, 3) + # Recover whatever the straggler produced before the deadline. + # Never raises; degrades to no-partial rather than to an error -- + # raising here would propagate out of asyncio.gather and discard + # every completed sibling in this parallel batch. + partial = await self._collect_partial(sub_session_id) + recovery_msg = ( "Child cancellation cleanup is still in progress; do not resume " "this session until cleanup and persistence complete." ) timeout_msg = ( f"Agent '{agent_name}' timed out after {self.timeout}s " - f"(delegate tool session-level timeout). {recovery_msg}" + f"(delegate tool session-level timeout; elapsed {elapsed_s}s). " + + ( + "Partial output was preserved and is returned under " + "'partial_response' -- it is UNFINISHED, not a result. " + if partial.get("text") + else "No partial output could be recovered. " + ) + + recovery_msg ) logger.warning(timeout_msg) if hooks: @@ -2108,12 +2289,13 @@ async def _spawn_new_session( "parent_session_id": parent_session_id, "error": timeout_msg, "error_type": "delegate_timeout", - "status": "timed_out", + "status": TIMEOUT_STATUS, "timeout_seconds": self.timeout, "resumable": False, "resume_status": "pending_child_cleanup", "tool_call_id": tool_call_id, "parallel_group_id": parallel_group_id, + **_partial_event_fields(partial, elapsed_s), }, ) return ToolResult( @@ -2121,9 +2303,11 @@ async def _spawn_new_session( output={ "session_id": sub_session_id, "agent": agent_name, - "status": "timed_out", + "status": TIMEOUT_STATUS, + **_partial_output_fields(partial), "metadata": { "timeout_seconds": self.timeout, + "elapsed_s": elapsed_s, "resumable": False, "resume_status": "pending_child_cleanup", "recovery_message": recovery_msg, @@ -2238,6 +2422,11 @@ async def _resume_existing_session( ToolResult with success status and output or error """ parent_session_id = self.coordinator.session_id + + # Start of this resume leg's wall clock -- see the identical comment + # in _spawn_new_session. Only read on the timeout path. + leg_started_at = time.monotonic() + resume_agent = None if "_" in session_id: resume_agent = session_id.rsplit("_", 1)[-1] or None @@ -2470,13 +2659,25 @@ async def _resume_existing_session( # else on this path (cache first, session_id suffix fallback). resume_agent = self._resolve_agent_for_session(session_id) agent_label = resume_agent or "unknown" + elapsed_s = round(time.monotonic() - leg_started_at, 3) + # Same best-effort, never-raising recovery as the spawn path -- + # the two timeout call sites must not diverge in contract. + partial = await self._collect_partial(session_id) + recovery_msg = ( "Child cancellation cleanup is still in progress; do not resume " "this session until cleanup and persistence complete." ) timeout_msg = ( f"Resumed agent '{agent_label}' timed out after {self.timeout}s " - f"(delegate tool session-level timeout). {recovery_msg}" + f"(delegate tool session-level timeout; elapsed {elapsed_s}s). " + + ( + "Partial output was preserved and is returned under " + "'partial_response' -- it is UNFINISHED, not a result. " + if partial.get("text") + else "No partial output could be recovered. " + ) + + recovery_msg ) logger.warning(timeout_msg) if hooks: @@ -2485,21 +2686,24 @@ async def _resume_existing_session( "parent_session_id": parent_session_id, "error": timeout_msg, "error_type": "delegate_timeout", - "status": "timed_out", + "status": TIMEOUT_STATUS, "timeout_seconds": self.timeout, "resumable": False, "resume_status": "pending_child_cleanup", "tool_call_id": tool_call_id, "parallel_group_id": parallel_group_id, + **_partial_event_fields(partial, elapsed_s), } if resume_agent is not None: error_payload["agent"] = resume_agent await hooks.emit("delegate:error", error_payload) timeout_output = { "session_id": session_id, - "status": "timed_out", + "status": TIMEOUT_STATUS, + **_partial_output_fields(partial), "metadata": { "timeout_seconds": self.timeout, + "elapsed_s": elapsed_s, "resumable": False, "resume_status": "pending_child_cleanup", "recovery_message": recovery_msg, diff --git a/modules/tool-delegate/tests/test_delegate_timeout.py b/modules/tool-delegate/tests/test_delegate_timeout.py index 081d042..4c8a3f5 100644 --- a/modules/tool-delegate/tests/test_delegate_timeout.py +++ b/modules/tool-delegate/tests/test_delegate_timeout.py @@ -8,10 +8,31 @@ from unittest.mock import AsyncMock, MagicMock import pytest -from amplifier_module_tool_delegate import DelegateTool +from amplifier_module_tool_delegate import _NO_PARTIAL_GUIDANCE, DelegateTool _ABSENT = object() +#: The additive partial-result keys a timeout result carries when NOTHING was +#: recovered -- i.e. with no ``session.partial`` capability registered, which +#: is every case until the app-layer producer half lands. Kept here so the +#: two exact-shape assertions below stay exact rather than degrading into +#: "contains these keys". +_NO_PARTIAL_FIELDS = { + "completed": False, + "partial_available": False, + "partial_response": None, + "partial_segments": 0, + "partial_source": "none", + "partial_truncated": False, + "partial_chars_total": 0, + "guidance": _NO_PARTIAL_GUIDANCE, +} + + +def _pop_elapsed(output: dict) -> float: + """Remove and return metadata.elapsed_s, which varies run to run.""" + return output["metadata"].pop("elapsed_s") + def _make_tool( *, @@ -138,10 +159,13 @@ async def test_spawn_timeout_reports_pending_cleanup_error_without_completed_eve child_session_id = spawn_fn.call_args.kwargs["sub_session_id"] assert result.success is False + elapsed_s = _pop_elapsed(result.output) + assert elapsed_s >= 0.01 assert result.output == { "session_id": child_session_id, "agent": "test-agent", - "status": "timed_out", + "status": "timeout", + **_NO_PARTIAL_FIELDS, "metadata": { "timeout_seconds": 0.01, "resumable": False, @@ -161,7 +185,7 @@ async def test_spawn_timeout_reports_pending_cleanup_error_without_completed_eve assert error["agent"] == "test-agent" assert error["sub_session_id"] == child_session_id assert error["error_type"] == "delegate_timeout" - assert error["status"] == "timed_out" + assert error["status"] == "timeout" assert error["timeout_seconds"] == 0.01 assert error["resumable"] is False assert error["resume_status"] == "pending_child_cleanup" @@ -185,10 +209,13 @@ async def test_resume_timeout_reports_pending_cleanup_error_without_completed_ev ) assert result.success is False + elapsed_s = _pop_elapsed(result.output) + assert elapsed_s >= 0.01 assert result.output == { "session_id": session_id, "agent": "test-agent", - "status": "timed_out", + "status": "timeout", + **_NO_PARTIAL_FIELDS, "metadata": { "timeout_seconds": 0.01, "resumable": False, @@ -208,7 +235,7 @@ async def test_resume_timeout_reports_pending_cleanup_error_without_completed_ev assert error["agent"] == "test-agent" assert error["session_id"] == session_id assert error["error_type"] == "delegate_timeout" - assert error["status"] == "timed_out" + assert error["status"] == "timeout" assert error["timeout_seconds"] == 0.01 assert error["resumable"] is False assert error["resume_status"] == "pending_child_cleanup" @@ -236,7 +263,7 @@ async def suppresses_cancellation(**_kwargs): elapsed = asyncio.get_running_loop().time() - started_at assert result.output is not None - assert result.output["status"] == "timed_out" + assert result.output["status"] == "timeout" assert 0.01 <= elapsed < 0.12 await asyncio.wait_for(child_finished.wait(), timeout=0.5) @@ -267,7 +294,7 @@ async def remains_pending_after_cancellation(**_kwargs): await asyncio.wait_for(cancellation_suppressed.wait(), timeout=0.5) assert result.output is not None - assert result.output["status"] == "timed_out" + assert result.output["status"] == "timeout" assert len(tool._detached_child_tasks) == 1 gc.collect() @@ -309,7 +336,7 @@ async def raises_after_cancellation(**_kwargs): result = await _spawn(tool, hooks) assert result.output is not None - assert result.output["status"] == "timed_out" + assert result.output["status"] == "timeout" await asyncio.wait_for(child_finished.wait(), timeout=0.5) await asyncio.sleep(0) assert "Task exception was never retrieved" not in caplog.text @@ -338,7 +365,7 @@ async def slow_cancellation_cleanup(**_kwargs): elapsed = asyncio.get_running_loop().time() - started_at assert result.output is not None - assert result.output["status"] == "timed_out" + assert result.output["status"] == "timeout" assert 0.01 <= elapsed < 0.12 await asyncio.wait_for(cleanup_started.wait(), timeout=0.5) await asyncio.wait_for(cleanup_finished.wait(), timeout=0.5) @@ -394,7 +421,7 @@ async def test_spawn_capability_timeout_error_uses_ordinary_error_handling(timeo assert "delegate:error" in event_names assert "delegate:agent_completed" not in event_names assert "delegate:agent_cancelled" not in event_names - assert all(payload.get("status") != "timed_out" for _name, payload in emissions) + assert all(payload.get("status") != "timeout" for _name, payload in emissions) error_payload = next( payload for name, payload in emissions if name == "delegate:error" ) @@ -428,7 +455,7 @@ async def test_resume_capability_timeout_error_uses_ordinary_error_handling(time assert "delegate:error" in event_names assert "delegate:agent_completed" not in event_names assert "delegate:agent_cancelled" not in event_names - assert all(payload.get("status") != "timed_out" for _name, payload in emissions) + assert all(payload.get("status") != "timeout" for _name, payload in emissions) error_payload = next( payload for name, payload in emissions if name == "delegate:error" ) diff --git a/modules/tool-delegate/tests/test_delegate_timeout_partial.py b/modules/tool-delegate/tests/test_delegate_timeout_partial.py new file mode 100644 index 0000000..af73461 --- /dev/null +++ b/modules/tool-delegate/tests/test_delegate_timeout_partial.py @@ -0,0 +1,370 @@ +"""Per-delegate timeout with PARTIAL RESULTS. + +The defect these tests pin down: when ``settings.timeout`` fires, the +straggler delegate's own work is discarded. There is no channel on which a +caller can see what the sub-session produced before the deadline, and no +flag telling it whether any such work exists. + +The contract under test: + + 1. A timeout is NEVER reportable as success -- on either channel. + 2. A timed-out delegate RETURNS (it does not raise), so sibling delegates + running in the same parallel batch keep their completed results. + 3. Whatever the straggler produced is preserved under ``partial_response``, + never under ``response`` (the success-only key), and its presence is + stated by the ``partial_available`` boolean. + 4. Partial recovery is best-effort and must never raise out of the timeout + path -- a failure there would discard the very siblings it protects. + +Origin: lane 37n's ``w3-delegate-timeout/`` design, re-targeted onto +foundation main after ``14d5a52`` (wall-clock backstop, timeout RETURNS) and +``8f45ea4`` / PR #350 (resume-path routing) moved the base. See +``docs/lanes/bp0-delegate-timeout-partial-consumer/DONE-NOTE.md`` for the +per-hunk re-targeting record. +""" + +from __future__ import annotations + +import asyncio +import json +from unittest.mock import AsyncMock, MagicMock + +import pytest +from amplifier_module_tool_delegate import DEFAULT_PARTIAL_MAX_CHARS, DelegateTool + +_ABSENT = object() + + +def _make_tool( + *, + timeout: object = _ABSENT, + spawn_fn=None, + resume_fn=None, + partial_fn=_ABSENT, + settings_extra: dict | None = None, +) -> DelegateTool: + """Build a DelegateTool over a fake coordinator. + + Mirrors ``test_delegate_timeout.py``'s harness so both files exercise the + same code paths, plus an optional ``session.partial`` capability. + """ + coordinator = MagicMock() + coordinator.session_id = "parent-session-123" + coordinator.config = {"agents": {"test-agent": {}}} + coordinator.session_state = {} + coordinator._tool_dispatch_context = {} + coordinator._tool_dispatch_contexts = {} + + capabilities: dict[str, object] = { + "session.spawn": spawn_fn or AsyncMock(), + "session.resume": resume_fn or AsyncMock(), + "self_delegation_depth": 0, + } + if partial_fn is not _ABSENT: + capabilities["session.partial"] = partial_fn + coordinator.get_capability = lambda name: capabilities.get(name) + coordinator.get = MagicMock(return_value=None) + + parent_session = MagicMock() + parent_session.config = {"session": {"orchestrator": {}}} + coordinator.session = parent_session + + settings: dict[str, object] = {"exclude_tools": []} + if timeout is not _ABSENT: + settings["timeout"] = timeout + settings.update(settings_extra or {}) + return DelegateTool(coordinator, {"features": {}, "settings": settings}) + + +def _hooks() -> MagicMock: + hooks = MagicMock() + hooks.emit = AsyncMock() + return hooks + + +def _emissions(hooks: MagicMock) -> list[tuple[str, dict]]: + return [(args[0], args[1]) for args, _kwargs in hooks.emit.call_args_list] + + +async def _never_finishes(**_kwargs): + await asyncio.Future() + + +async def _spawn(tool: DelegateTool, hooks): + return await tool._spawn_new_session( + agent_name="test-agent", + instruction="Do something", + context_depth="none", + context_scope="conversation", + context_turns=5, + provider_preferences=None, + hooks=hooks, + tool_call_id="call-timeout", + parallel_group_id="parallel-timeout", + ) + + +async def _resume(tool: DelegateTool, hooks): + return await tool._resume_existing_session( + session_id="child-session-001_test-agent", + instruction="Continue", + hooks=hooks, + tool_call_id="call-resume-timeout", + parallel_group_id="parallel-resume-timeout", + ) + + +# -------------------------------------------------------------------------- +# 1. Never reportable as success +# -------------------------------------------------------------------------- + + +@pytest.mark.asyncio +async def test_timeout_is_not_success_on_either_channel(): + tool = _make_tool( + timeout=0.01, + spawn_fn=AsyncMock(side_effect=_never_finishes), + partial_fn=lambda sid: {"text": "found three anchors", "segments": 4}, + ) + result = await _spawn(tool, _hooks()) + + # Channel 1: the structured flag. + assert result.success is False + # Channel 2: what the model actually reads. + assert result.output["status"] == "timeout" + assert result.output["completed"] is False + serialized = result.get_serialized_output() + assert '"status": "timeout"' in serialized + assert '"completed": false' in serialized + + +@pytest.mark.asyncio +async def test_partial_text_never_lands_on_the_success_key(): + """``response`` is the success channel. A partial must not occupy it.""" + tool = _make_tool( + timeout=0.01, + spawn_fn=AsyncMock(side_effect=_never_finishes), + partial_fn=lambda sid: {"text": "half an answer", "segments": 2}, + ) + result = await _spawn(tool, _hooks()) + + assert "response" not in result.output + assert result.output["partial_available"] is True + assert result.output["partial_response"] == "half an answer" + assert result.output["partial_segments"] == 2 + # A consumer keyed on the success shape finds nothing to mistake. + assert json.loads(result.get_serialized_output()).get("response") is None + + +@pytest.mark.asyncio +async def test_success_result_carries_no_partial_keys(): + """The inverse guard: a completed delegate never looks partial. + + This is the pin for "default behaviour for normal completions is + unchanged" -- the success shape gains no key from this work. + """ + + async def _completes(**_kwargs): + return {"output": "the whole answer", "session_id": "sub-1", "turn_count": 3} + + tool = _make_tool( + timeout=60, + spawn_fn=AsyncMock(side_effect=_completes), + partial_fn=lambda sid: {"text": "should never be consulted", "segments": 9}, + ) + result = await _spawn(tool, _hooks()) + + assert result.success is True + assert result.output["response"] == "the whole answer" + assert result.output.get("status") == "success" + assert not [k for k in result.output if k.startswith("partial")] + assert "completed" not in result.output + + +# -------------------------------------------------------------------------- +# 2. Siblings survive the straggler (k64 gate G-D1) +# -------------------------------------------------------------------------- + + +@pytest.mark.asyncio +async def test_straggler_returns_rather_than_raises_so_siblings_survive(): + """The measured harm: a straggler discarding completed siblings' work. + + Reproduces the parallel batch shape the orchestrator uses + (``asyncio.gather`` over per-tool coroutines, no ``return_exceptions``). + If the timed-out delegate RAISES, gather propagates and every completed + sibling result in the batch is discarded. It must RETURN instead. + """ + + async def _fast(**_kwargs): + return {"output": "sibling finding", "session_id": "sub-fast", "turn_count": 1} + + fast_tool = _make_tool(timeout=60, spawn_fn=AsyncMock(side_effect=_fast)) + slow_tool = _make_tool( + timeout=0.01, + spawn_fn=AsyncMock(side_effect=_never_finishes), + partial_fn=lambda sid: {"text": "straggler got this far", "segments": 7}, + ) + + results = await asyncio.gather( + _spawn(fast_tool, _hooks()), + _spawn(fast_tool, _hooks()), + _spawn(slow_tool, _hooks()), + ) + + # G-D1 in miniature: zero completed-delegate findings discarded. + completed = [r for r in results if r.success] + assert len(completed) == 2 + assert all(r.output["response"] == "sibling finding" for r in completed) + + straggler = next(r for r in results if not r.success) + assert straggler.output["status"] == "timeout" + assert straggler.output["partial_response"] == "straggler got this far" + + +# -------------------------------------------------------------------------- +# 3. Partial recovery is best-effort and never fatal +# -------------------------------------------------------------------------- + + +@pytest.mark.asyncio +async def test_no_partial_capability_degrades_to_no_partial_not_to_error(): + """The state until the app-cli producer half lands. Not a defect.""" + tool = _make_tool( + timeout=0.01, spawn_fn=AsyncMock(side_effect=_never_finishes) + ) # no session.partial + result = await _spawn(tool, _hooks()) + + assert result.success is False + assert result.output["status"] == "timeout" + assert result.output["partial_available"] is False + assert result.output["partial_response"] is None + assert result.output["partial_source"] == "none" + + +@pytest.mark.asyncio +async def test_partial_capability_raising_does_not_break_the_timeout_path(): + def _explodes(sub_session_id): + raise RuntimeError("partial store unavailable") + + tool = _make_tool( + timeout=0.01, + spawn_fn=AsyncMock(side_effect=_never_finishes), + partial_fn=_explodes, + ) + result = await _spawn(tool, _hooks()) + + assert result.success is False + assert result.output["status"] == "timeout" + assert result.output["partial_available"] is False + + +@pytest.mark.asyncio +async def test_async_partial_capability_is_supported(): + async def _async_partial(sub_session_id): + return {"text": "async partial", "segments": 1, "source": "store"} + + tool = _make_tool( + timeout=0.01, + spawn_fn=AsyncMock(side_effect=_never_finishes), + partial_fn=_async_partial, + ) + result = await _spawn(tool, _hooks()) + + assert result.output["partial_response"] == "async partial" + assert result.output["partial_source"] == "store" + + +@pytest.mark.asyncio +async def test_partial_text_is_capped_and_keeps_the_tail(): + long_text = "x" * 500 + "THE-RECENT-TAIL" + tool = _make_tool( + timeout=0.01, + spawn_fn=AsyncMock(side_effect=_never_finishes), + partial_fn=lambda sid: {"text": long_text, "segments": 9}, + settings_extra={"partial_max_chars": 50}, + ) + result = await _spawn(tool, _hooks()) + + assert result.output["partial_truncated"] is True + assert result.output["partial_chars_total"] == len(long_text) + assert result.output["partial_response"].endswith("THE-RECENT-TAIL") + assert "truncated" in result.output["partial_response"] + + +@pytest.mark.asyncio +async def test_malformed_partial_payload_is_ignored(): + tool = _make_tool( + timeout=0.01, + spawn_fn=AsyncMock(side_effect=_never_finishes), + partial_fn=lambda sid: "not a dict", + ) + result = await _spawn(tool, _hooks()) + + assert result.success is False + assert result.output["partial_available"] is False + + +# -------------------------------------------------------------------------- +# 4. Observability, defaults, and the resume path +# -------------------------------------------------------------------------- + + +@pytest.mark.asyncio +async def test_timeout_event_carries_elapsed_and_partial_flags(): + """G-D3 depends on leg durations being emitted, not inferred.""" + hooks = _hooks() + tool = _make_tool( + timeout=0.01, + spawn_fn=AsyncMock(side_effect=_never_finishes), + partial_fn=lambda sid: {"text": "some work", "segments": 1}, + ) + await _spawn(tool, hooks) + + errors = [d for (name, d) in _emissions(hooks) if name == "delegate:error"] + assert len(errors) == 1 + payload = errors[0] + assert payload["error_type"] == "delegate_timeout" + assert payload["status"] == "timeout" + assert payload["timeout_seconds"] == 0.01 + assert payload["elapsed_s"] >= 0.01 + assert payload["partial_available"] is True + assert payload["partial_chars"] == len("some work") + + +def test_partial_max_chars_default_is_shipped_not_swept(): + """The cap is a real shipped default; the *timeout* remains main's 14400. + + 37n's original asserted ``tool.timeout is None``. That assertion was + written against a base that predates ``14d5a52`` (Layer 3 wall-clock + backstop, default 14400s). Re-asserting it here would silently revert + that commit, so this pins only what this change actually introduces. + ``test_delegate_timeout.py`` still owns the timeout default. + """ + tool = _make_tool() + assert tool.partial_max_chars == DEFAULT_PARTIAL_MAX_CHARS == 20000 + assert tool.timeout == 14400 + + +@pytest.mark.asyncio +async def test_resume_timeout_carries_the_same_partial_contract(): + """The resume path is a second timeout call site; it must not diverge.""" + hooks = _hooks() + tool = _make_tool( + timeout=0.01, + resume_fn=AsyncMock(side_effect=_never_finishes), + partial_fn=lambda sid: {"text": "resumed partial", "segments": 3}, + ) + result = await _resume(tool, hooks) + + assert result.success is False + assert "response" not in result.output + assert result.output["status"] == "timeout" + assert result.output["completed"] is False + assert result.output["partial_available"] is True + assert result.output["partial_response"] == "resumed partial" + assert result.output["partial_segments"] == 3 + + errors = [d for (name, d) in _emissions(hooks) if name == "delegate:error"] + assert errors[0]["partial_available"] is True + assert errors[0]["status"] == "timeout"