Skip to content

fix(execution): telemetry + transcript on a failing error_during_execution/504 row (#1853) - #2224

Merged
vybe merged 10 commits into
devfrom
AndriiPasternak31/issue-1853
Aug 16, 2026
Merged

fix(execution): telemetry + transcript on a failing error_during_execution/504 row (#1853)#2224
vybe merged 10 commits into
devfrom
AndriiPasternak31/issue-1853

Conversation

@AndriiPasternak31

Copy link
Copy Markdown
Contributor

Fixes #1853

Problem

An execution that ends error_during_execution (Claude Code reports is_error with a non-terminal last message — commonly a fan-out whose <task-notification> lands after stop_reason=end_turn and interrupts the follow-on turn) was written to schedule_executions with status + error string only — no claude_session_id, no cost, no execution_log. The Claude JSONL that would carry the evidence is auto-persisted (#678) but reaped on a 6h sweep / 1h age-guard (1–7h effective), and the row carries no session id to locate it with, so the whole failure class was undiagnosable after the fact.

Measured on an ops instance: 26 success rows all carried log + session_id + cost; 6 failed rows carried none. This is the observability substrate for the Aug-14 "system agent identifies errors" initiative (reliability lane; TOWARD the #1401 recovery trace).

Fix (Approach B — inline the sanitized transcript)

Mirror the SUCCESS applier onto the FAILED path, so an error_during_execution (502) / timeout (504) row is diagnosable via the same API as a SUCCESS row.

Agent (headless_executor.py)

  • New _execution_error_502_detail(ctx, message) mirrors _timeout_504_detail: {message, metadata, execution_log}, where execution_log = ctx.raw_messages (the full stream-json transcript, in-memory so present for short ≤600s runs too — no JSONL dependency).
  • session_id fallback (metadata.session_id or ctx.claude_session_uuid) is UUID-shape-validated via new _valid_session_id (FI-1: the fallback can be an untrusted resume_session_id — a log-forging vector, since sanitize_dict doesn't strip newlines).
  • The 502 message text is byte-identical to before, so fix(agent-server): never surface Claude Code's [ede_diagnostic] header as the error cause (#1849) #1938's error-string fix and the backend's resume-not-found self-heal (which reads detail["message"]) are preserved, and the structured body does not trip _is_reader_race_signature (no false Async chat_with_agent: long execution silently fails with null response (reader-thread) #678 auto-retry).
  • _timeout_504_detail gains the same validated session_id fallback + execution_log, so the 504 path persists them for real too.

Backend (task_execution_service.py)

Invariants preserved: single terminal applier (#1483) — no new CAS writer, _write_terminal_and_gate untouched; CAS-won close/emit (#1578/#1804) — every side-effect stays gated on won. No schema change (execution_log/claude_session_id/tool_calls already exist).

Named residuals: _write_terminal_and_gate terminals (backend timeout/budget/crash) and standalone-scheduler RETRY-001 FAILED writes still land bare — the Aug-14 initiative must not assume every FAILED row carries telemetry.

⚠️ Rollout constraint (agent-server change)

The agent half lives in trinity-agent-base. A running fleet keeps writing bare FAILED rows until ./scripts/deploy/build-base-image.sh runs AND each agent is COLD-recreated — a plain restart may not adopt it (#1809). The backend half is live on backend deploy. Old-image bodies degrade gracefully (bare string → execution_log/session_id stay null = today's behaviour), so a mixed fleet is safe both directions. Same rollout note #1944 (#1870) and #1938 (#1849) carried.

Docs updated

  • docs/memory/requirements/scheduling.md — new §10.4.4
  • docs/memory/architecture.mdtask_execution_service.py apply_result FAILED-branch note
  • docs/memory/feature-flows.md (index) + feature-flows/task-execution-service.md + feature-flows/parallel-headless-execution.md

Tests

tests/unit/test_1853_error_telemetry_salvage.py (26) — agent helpers incl. the FI-1 log-forging guard, the unchanged-message-text (#1938) + no-reader-race-collision regressions, backend FAILED-branch salvage with credential redaction proven in real sqlite, the #1944 §4.4 live-capture pattern (real on-disk error tail → real _finalize_headless_result), and the full real error tail → finalize → _extract_agent_errorapply_result → persisted redacted row chain.

Also migrated two test_1673_execution_error_not_success.py contract tests whose assertions targeted the old bare-string 502 body (now the structured dict) — intent preserved (resume-marker reachability; no reader-race collision).

All touched suites green locally (test_1853, test_1673, test_1083_apply_result, test_1201_timeout_telemetry_salvage, test_792_subscription_retry), including under pytest-randomly.

🤖 Generated with Claude Code

@AndriiPasternak31 AndriiPasternak31 self-assigned this Aug 16, 2026
@AndriiPasternak31
AndriiPasternak31 requested review from obasilakis, vybe and webmixgamer and removed request for obasilakis, vybe and webmixgamer August 16, 2026 01:42
@AndriiPasternak31
AndriiPasternak31 marked this pull request as ready for review August 16, 2026 01:42
@github-actions

Copy link
Copy Markdown

⚠️ Nightly unit-suite check skipped — merge conflict against dev.

Resolve by running git merge dev locally and pushing the result. The next nightly run will re-test once the conflict is gone.

AndriiPasternak31 and others added 10 commits August 16, 2026 14:54
…ing error_during_execution/504 row (#1853)

Trinity Rule #1 (requirements before implementation). Documents Approach B:
the FAILED applier mirrors the SUCCESS branch — persists sanitized
execution_log + tool_calls summary + UUID-validated claude_session_id +
salvaged cost/context on the error_during_execution (502) and timeout (504)
FAILED row. Names the residuals (_write_terminal_and_gate + standalone
scheduler still land bare).

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
…cution 502 and timeout 504 bodies (#1853)

The execution_error 502 raised a bare detail="Execution error: <msg>",
discarding ctx.metadata (session_id/cost/context) and ctx.raw_messages (the
full stream-json transcript) that were in scope. New _execution_error_502_detail
mirrors _timeout_504_detail: {message, metadata, execution_log}. The message
text is byte-identical (preserves #1938 + the backend resume-not-found
self-heal). _timeout_504_detail gains the same validated session_id fallback +
execution_log, so the 504 path persists them for real too.

_valid_session_id UUID-shape-validates the session_id fallback before it is
persisted — ctx.claude_session_uuid can be an untrusted resume_session_id
(log-forging vector; sanitize_dict does not strip newlines) (FI-1).

Also corrects the stale "reaps after 24h" comment (real: 6h sweep / 1h age
guard = 1-7h effective).

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
…ow (#1853)

_extract_agent_error now returns the agent execution_log transcript too;
the httpx handler threads it + the validated session_id onto the existing
TerminalEnvelope fields. apply_result FAILED branch mirrors the SUCCESS
branch: sanitize_execution_log(json.dumps(transcript)) + the #1741 tool_calls
summary + claude_session_id, passed into the EXISTING db.update_execution_status
call. cost/context already salvaged from metadata.

Single terminal applier (#1483) preserved — payload widened, no new CAS writer,
_write_terminal_and_gate untouched. All side-effects stay gated on the existing
won bool (#1578/#1804) — the new columns are added above the gate, no
predicate widened. Bare-string old-image bodies leave the columns null
(graceful mixed-fleet degrade).

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
_SESSION_ID_UUID_RE / _valid_session_id use re.compile; headless_executor
did not import re. Completes the previous agent-side commit.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
…#1853)

New tests/unit/test_1853_error_telemetry_salvage.py (21 tests):
- _valid_session_id UUID guard incl. the FI-1 newline-injection case
- _execution_error_502_detail / _timeout_504_detail carry transcript + validated
  session_id; the structured body does NOT trip _is_reader_race_signature (ENG#2)
- _finalize_headless_result error branch raises a 502 dict with an UNCHANGED
  message (#1938) + transcript + session id (ENG#10)
- _extract_agent_error 3-tuple; resume-not-found message preserved (#1673/#1849)
- apply_result FAILED branch persists the transcript with the embedded secret
  REDACTED, a #1741 tool_calls summary, the validated session id, salvaged cost;
  won-gated close/emit unchanged on a lost CAS (#1578/#1804)
- real-sqlite readback proving the column names (ENG#11)

Refines the now-misleading test_1083 comment (a FAILED write CAN carry the
transcript when the envelope has one).

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
)

task_execution_service bullet: the FAILED branch of apply_result mirrors the
SUCCESS telemetry (execution_log/tool_calls/claude_session_id) above the won
gate; _extract_agent_error 3-tuple + the _timeout_504_detail transcript/session
extension. Names the residual bare-terminal writers.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
)

- task-execution-service.md: FAILED applier mirrors SUCCESS telemetry;
  _extract_agent_error 3-tuple
- parallel-headless-execution.md: structured 502/504 body + _execution_error_502_detail
  + validated session_id fallback; stale 24h->1-7h comment note
- feature-flows.md: Recent Updates index row

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
)

Extends the #1853 suite with the #1944 §4.4 live-capture pattern: a REAL
error tail written into the agent's ~/.claude/projects/-home-developer/
drives the REAL _finalize_headless_result (genuine #1870 recovery decline,
not monkeypatched), so the structured 502 is proven to carry the transcript
+ validated session id on the exact failure path the fleet takes — and a
#1870-recoverable tail is NOT re-failed by #1853. Adds the end-to-end chain
(real error tail -> real finalize 502 body -> backend _extract_agent_error
-> apply_result -> a persisted, redacted, session-tagged FAILED row in real
sqlite).

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
…tured shape (#1853)

#1853 deliberately changed the error_during_execution 502 body from a bare
string to a structured {message, metadata, execution_log} dict. Two #1673
contract tests asserted the old string shape and began failing:

- test_502_detail_carries_the_resume_marker_backend_matches_on: the resume-
  not-found marker the backend substring-matches now lives in detail["message"]
  (carried verbatim, preserving #1938 + the self-heal). Assert the dict shape.
- test_execution_error_not_a_reader_race_dict_body -> _does_not_trip_reader_race:
  "not a dict" is no longer the discriminator (the body IS a dict now). Assert
  the real contract: _is_reader_race_signature(detail) is False (it keys on
  recovery_attempted, which the #1853 body omits).

Intent preserved on both; behavior unchanged.

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
…uctured shape (#1853)

`_detail_for` asserted the error_during_execution 502 `detail` was a plain
string, but #1853 made it a structured body (message + metadata +
execution_log). Mirror the real consumer (`_extract_agent_error` derives
`result.error` from `detail["message"]`) — the same migration already applied
to the sibling test_1673. Fixes the 3 regression-diff failures in
test_1849 (test_resume_fallback_fires_through_the_502_detail,
test_resume_fallback_survives_a_403_bearing_uuid,
test_multi_error_truncation_limit_is_known).

Also fixes a pre-existing test-isolation leak surfaced by this PR's new test
file reordering: test_audit_chain_edges::test_enabling_the_hash_chain_survives_a_restart
(added by #2026) writes `audit_hash_chain_enabled='true'` to the real global
system_settings and never restores it, so a later `platform_audit_service.log()`
silently takes the chained writer — flaking test_1966's
test_real_audit_service_swallows_its_own_failures. Add an autouse
snapshot/restore fixture (mirrors the #762 restore in tests/test_audit_log_unit.py).

Co-Authored-By: Claude Opus 4.8 <noreply@anthropic.com>
@AndriiPasternak31
AndriiPasternak31 force-pushed the AndriiPasternak31/issue-1853 branch from 4baa8f9 to a75ac6b Compare August 16, 2026 13:55
@AndriiPasternak31

Copy link
Copy Markdown
Contributor Author

CodeQL check — 10 pre-existing false positives dismissed

The CodeQL results check flagged 10 py/clear-text-logging-sensitive-data alerts. All 10 are pre-existing lines from Release: v0.6.0 (#998) (an ancestor of dev), not introduced by #1853:

  • docker/base-image/agent_server/services/headless_executor.py (330, 341, 1444, 1474, 1475, 1538)
  • docker/base-image/agent_server/services/error_classifier.py (429 ×3) — not in this PR's diff
  • docker/base-image/agent_server/services/jsonl_recovery.py (848) — not in this PR's diff

Every line logs pure telemetry (cost_usd, duration_ms, session_id, num_turns, counts) or an already-sanitize_text'd message — no sensitive data.

They surfaced as "new" only because dev's stored CodeQL baseline predates the query that catches them (query-pack drift); this PR modifies headless_executor.py, so its fresh analysis emits them while the last 8 dev merges (which don't touch these files) stayed green. Dismissed as false positive (reversible).

All other checks — regression diff, 6 pytest seeds, prod-image-smoke, both Analyze jobs, container-security, guards — are green.

@vybe vybe 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.

Validated via /validate-pr. The FAILED branch mirrors the SUCCESS applier and stays inside the existing db.update_execution_status CAS call — no new terminal writer, _write_terminal_and_gate untouched, and every side-effect remains gated on won (#1483/#1578/#1804 preserved). Transcript is sanitized with the same sanitize_execution_log the SUCCESS branch uses, and the 502 message text is byte-identical so #1938 and the reader-race classifier are unaffected. Old-image bodies degrade to null columns, so a mixed fleet is safe both directions. Residuals (_write_terminal_and_gate terminals, scheduler RETRY-001 writes) are named in the description rather than implied. All checks green.

@vybe
vybe merged commit 657fa64 into dev Aug 16, 2026
24 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants