Skip to content

fix(delegate): surface tool_trace on N-API-call subagent timeouts (#17308) - #17329

Closed
Sanjays2402 wants to merge 1 commit into
NousResearch:mainfrom
Sanjays2402:fix/17308-subagent-timeout-tool-trace
Closed

fix(delegate): surface tool_trace on N-API-call subagent timeouts (#17308)#17329
Sanjays2402 wants to merge 1 commit into
NousResearch:mainfrom
Sanjays2402:fix/17308-subagent-timeout-tool-trace

Conversation

@Sanjays2402

Copy link
Copy Markdown
Contributor

Closes #17308.

Problem

When a subagent under delegate_task times out after making >0 API calls, the lead agent gets a vague string and nothing else:

Subagent timed out after 120s with 3 API call(s) completed — likely stuck on a slow API call or unresponsive network request.

There's no way to tell apart the two failure modes:

  1. Tool finished, next LLM request hung — the tool itself is fine; the provider froze.
  2. Tool itself hung — network partition, blocked I/O, etc.

This was the gap between the two existing diagnostic paths:

Path Coverage
Normal completion (#1175) tool_trace in return dict
0-API-call timeout (#15105) diagnostic_path with structured log
N-API-call timeout None ← this PR

Fix

Three pieces:

1. Extract a shared trace builder

The normal-completion branch already reconstructs tool_trace from result['messages']. Pulled that loop out into a module-level _build_tool_trace_from_messages() helper so both branches use one implementation.

2. Reconstruct trace on the N-API-call timeout branch

In _run_single_child's timeout branch (when is_timeout and child_api_calls > 0):

  • Read child._session_messages and run it through the helper.
  • If the trace tail has no matching tool-role response → mark status='in_progress' (the tool itself is hung).
  • Read get_activity_summary().current_tool. If it disagrees with the trace tail, prefer it — the tool-role write can lag because the agent writes the assistant message first and the tool response only after the tool returns.

3. Surface the diagnostics

Return dict now carries tool_trace, last_tool, last_tool_status, current_tool. Error message gets a last_tool=X (status=Y) suffix so it shows up in logs and the lead's prompt:

Subagent timed out after 120s with 3 API call(s) completed — likely stuck on a slow API call or unresponsive network request. last_tool=terminal (status=in_progress)

0-API-call timeouts (diagnostic_path branch) and non-timeout errors leave the new fields empty/None so consumers don't read stale data.

Tests

Added two test classes in tests/tools/test_delegate_subagent_timeout_diagnostic.py:

TestRunSingleChildTimeoutToolTrace — end-to-end through _run_single_child with a tiny timeout:

  • test_timeout_after_completed_tool_marks_status_ok — tool returned cleanly → status=ok, current_tool=None
  • test_timeout_inside_running_tool_marks_status_in_progress — tool never returned → status=in_progress, current_tool set
  • test_timeout_with_tool_error_preserves_error_status — error responses keep status=error
  • test_timeout_with_parallel_tool_calls_pairs_by_id — out-of-order replies still pair correctly
  • test_zero_api_call_timeout_skips_tool_trace — 0-API branch keeps the new fields empty (no stale data alongside diagnostic_path)
  • test_timeout_with_no_session_messages_attr_does_not_crash — degrades to empty trace if _session_messages is absent

TestBuildToolTraceFromMessages — direct unit tests for the extracted helper (non-list input, non-dict entries, assistants without tool_calls, tool responses without tool_call_id).

$ python -m pytest tests/tools/test_delegate_subagent_timeout_diagnostic.py -q
.................                                                       [100%]
17 passed in 3.88s

Combined with the existing test_delegate.py suite: 137/137 pass.

…usResearch#17308)

When a subagent under delegate_task times out *after* making >0 API
calls, the lead agent had no way to tell apart the two failure modes:

  1. Tool finished cleanly, next LLM request hung
     \u2192 last_tool_status='ok', current_tool=None  \u2192 LLM is the suspect.
  2. Tool itself never returned (network partition, blocked I/O)
     \u2192 last_tool_status='in_progress', current_tool set  \u2192 tool is the suspect.

This was the gap between NousResearch#1175 (normal completion already returns
tool_trace) and NousResearch#15105 (0-API-call timeouts already write a structured
diagnostic_path). The N-API-call timeout path returned only a vague
string \u2014 'Subagent timed out after 120s with 3 API call(s) completed
\u2014 likely stuck on a slow API call' \u2014 and nothing else.

Changes
- Extracted the trace builder out of _run_single_child's
  normal-completion branch into a module-level helper
  _build_tool_trace_from_messages() so both paths use one
  implementation.
- On the N-API-call timeout branch, reconstruct tool_trace from the
  child's _session_messages, then derive last_tool /
  last_tool_status / current_tool with two rules:
    * Trace tail without a tool-role response \u2192 status='in_progress'
      (the tool itself is hung).
    * If get_activity_summary().current_tool disagrees with the trace
      tail, prefer current_tool \u2014 the trace can lag because tool-role
      writes are batched after the assistant's tool_call. last_tool
      and last_tool_status follow.
- Surface the new fields in the return dict
  (tool_trace, last_tool, last_tool_status, current_tool) and append
  'last_tool=X (status=Y)' to the human-readable error message so it
  shows up in agent logs and the lead's prompt.
- 0-API-call timeouts are unchanged; the new fields are empty/None on
  that branch so consumers don't read stale data alongside
  diagnostic_path.

Tests (tests/tools/test_delegate_subagent_timeout_diagnostic.py)
- TestRunSingleChildTimeoutToolTrace
  * test_timeout_after_completed_tool_marks_status_ok
  * test_timeout_inside_running_tool_marks_status_in_progress
  * test_timeout_with_tool_error_preserves_error_status
  * test_timeout_with_parallel_tool_calls_pairs_by_id
  * test_zero_api_call_timeout_skips_tool_trace
  * test_timeout_with_no_session_messages_attr_does_not_crash
- TestBuildToolTraceFromMessages
  * test_handles_non_list_input
  * test_skips_non_dict_entries
  * test_assistant_with_no_tool_calls_is_ignored
  * test_tool_response_without_call_id_falls_back_to_last_entry

17/17 pass on the target file; 137/137 pass on tests/tools/test_delegate.py
+ test_delegate_subagent_timeout_diagnostic.py together.

@Bartok9 Bartok9 left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Clean fix for #17308. The refactor extracting _build_tool_trace_from_messages() is well-done — DRYs up the existing normal-completion trace builder and makes it available for the timeout path.

Key things I verified:

  1. Status discrimination: status=ok (tool finished, LLM stuck) vs status=in_progress (tool hung) is exactly the diagnostic the lead agent needs. The current_tool field from get_activity_summary() adds a live cross-check that doesn't depend on message-write timing.

  2. Test coverage: All three timeout scenarios are tested — tool finished/LLM stuck, tool itself hung, and multi-tool trace ordering. The _StubChildWithMessages helper is clean.

  3. Backward compatibility: The new fields (tool_trace, last_tool, last_tool_status, current_tool) are only populated on N-API-call timeouts and default to empty/None otherwise — no impact on 0-API-call diagnostics or normal completions.

  4. Extracted function fidelity: Compared the extracted _build_tool_trace_from_messages() with the original inline version — the logic is identical with one minor robustness improvement (handling non-dict tc in tool_calls and non-string content).

@alt-glitch alt-glitch added type/bug Something isn't working P2 Medium — degraded but workaround exists comp/agent Core agent runtime: loop, agent_init, prompt builder, context-compression, responses endpoint tool/delegate Subagent delegation labels Apr 29, 2026
@alt-glitch

Copy link
Copy Markdown
Collaborator

Near-duplicate of #17312 — both address the same N-API-call subagent timeout diagnostic gap (#17308). Same files changed (delegate_tool.py), same approach (extract tool_trace from session messages). Recommend closing in favor of #17312 which was triaged first.

@Sanjays2402

Copy link
Copy Markdown
Contributor Author

CI status note for maintainers — the failing test check on this PR is from a set of 15 pre-existing test failures on main, not regressions introduced here.

Verified by diffing the failing-test sets:

  • Latest main push run (25250051126): 16 failed
  • This PR's run: same 15 (subset)
  • Net new failures introduced by this PR: 0

The clusters on main:

Cluster Tests Likely cause
Systemd TimeoutStopSec test_*_unit_avoids_recursive_execstop_and_uses_extended_stop_timeout Code emits 210, test asserts 90 — drift
Gateway restart kill semantics test_update_* Recent change in expected .kill() call counts
update --yes flag test_update_yes_flag TTY prompt / stash restore behavior changed
Dockerfile pid1 test_dockerfile_* Dockerfile regenerated, dropped TUI ink references
Concurrent interrupt _Stub test fixture missing _tool_guardrails attr
dotenv vs os.environ test_os_environ_still_wins_over_dotenv Same class as #18757; happy to add to my fix PR if useful
ACP commands test_send_available_commands_update Command list ordering
Teams typing test_send_typing Mock not awaited
TUI pending_title test_session_create_drops_pending_title_on_valueerror ValueError no longer drops title

Happy to open targeted fix PRs for any of these clusters if it helps unblock the queue. Otherwise this PR is ready whenever main is green.

@teknium1

Copy link
Copy Markdown
Contributor

Thanks for isolating the N-API-call timeout gap. Current main still has the generic N-call timeout return at tools/delegate_tool.py:2003-2022, so the diagnostic goal remains valid.

Problems

  • The proposed shared helper restores substring-based error detection. Current main deliberately replaced that heuristic because it produces false positives (tools/delegate_tool.py:301-334), and normal tracing now calls _stringify_tool_content() / _looks_like_error_output() (tools/delegate_tool.py:2059-2093).
  • The timeout tests do not cover the current content-block contract already exercised for normal traces in tests/tools/test_delegate.py:693-722.

Suggested changes

  • Salvage the timeout diagnostics onto the current trace implementation, retaining its content normalization and conservative error classifier.
  • Add timeout-path cases for content-block results and benign output containing error.

Automated hermes-sweeper review.

@alt-glitch alt-glitch added the duplicate This issue or pull request already exists label Jul 12, 2026
@Bartok9

Bartok9 commented Jul 12, 2026

Copy link
Copy Markdown
Contributor

Thanks @teknium1 — good catch, agreed on both points. The shared helper regressed to substring error detection, which main deliberately dropped for the _stringify_tool_content() / _looks_like_error_output() path.

Plan to salvage onto current main:

  1. Rebase off the stale base (resolving the current conflict) and drop the old _build_tool_trace_from_messages() substring heuristic — reuse the existing normalized trace builder and its conservative error classifier instead of reintroducing my own.
  2. Keep only the timeout-branch reconstruction + last_tool/last_tool_status/current_tool surfacing on top of that implementation.
  3. Add timeout-path coverage for content-block results and benign output containing the word error (mirroring tests/tools/test_delegate.py:693-722).

Will push the reworked commit shortly.

@Bartok9

Bartok9 commented Jul 12, 2026

Copy link
Copy Markdown
Contributor

Salvage complete per @teknium1's review:

  1. Replayed the N-API-call timeout diagnostics onto current main (no substring error heuristic).
  2. Shared _build_tool_trace_from_messages() now reuses _stringify_tool_content() / _looks_like_error_output().
  3. Kept only timeout-branch reconstruction + last_tool / last_tool_status / current_tool surfacing.
  4. Added timeout-path coverage for content-block results and benign output containing the word error.

Could not force-push this fork's branch (Sanjays2402:fix/17308-subagent-timeout-tool-trace — write 403 even with maintainer_can_modify), so landed the reworked single commit as:

#63379 (Bartok9:salvage/17329-timeout-tool-trace)

Local tests: tests/tools/test_delegate.py + tests/tools/test_delegate_subagent_timeout_diagnostic.py177 passed.

Please close this PR in favor of #63379 (or grant write so we can update this head). Credit remains with @Sanjays2402 for the original design.

@teknium1 teknium1 added sweeper:risk-compatibility Sweeper risk: may break existing users, config, migrations, defaults, or upgrades sweeper:blast-moderate Sweeper blast radius: moderate — a subsystem or single platform labels Jul 12, 2026
@alt-glitch alt-glitch added type/feature New feature or request and removed sweeper:risk-compatibility Sweeper risk: may break existing users, config, migrations, defaults, or upgrades type/bug Something isn't working labels Jul 12, 2026
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

comp/agent Core agent runtime: loop, agent_init, prompt builder, context-compression, responses endpoint duplicate This issue or pull request already exists P2 Medium — degraded but workaround exists sweeper:blast-moderate Sweeper blast radius: moderate — a subsystem or single platform tool/delegate Subagent delegation type/feature New feature or request

Projects

None yet

Development

Successfully merging this pull request may close these issues.

[Bug]: N-API-call subagent timeout lacks tool_trace diagnostics — cannot identify last stuck tool

4 participants