From 6178265f70c8a2abbef2b1c78bd591475eeb97a5 Mon Sep 17 00:00:00 2001 From: jenkins Date: Tue, 29 Sep 2026 16:45:53 -0500 Subject: [PATCH] fix(hermes): retain safe CLI failure categories --- docs/hermes_suite_61_failure_20260929.md | 73 +++++++++++++++++++ .../ops/hermes_suite_proposal_diagnostic.py | 65 +++++++++++++++++ services/hermes/scripts/suite_backends.py | 22 ++++-- .../hermes/scripts/suite_cli_diagnostics.py | 25 ++++++- services/hermes/scripts/suite_contract.py | 2 +- services/hermes/suite-planner-deployment.yaml | 2 +- testing/tests/test_suite_cli_diagnostics.py | 50 +++++++++++++ 7 files changed, 230 insertions(+), 9 deletions(-) create mode 100644 docs/hermes_suite_61_failure_20260929.md create mode 100755 scripts/ops/hermes_suite_proposal_diagnostic.py diff --git a/docs/hermes_suite_61_failure_20260929.md b/docs/hermes_suite_61_failure_20260929.md new file mode 100644 index 00000000..bb11a42c --- /dev/null +++ b/docs/hermes_suite_61_failure_20260929.md @@ -0,0 +1,73 @@ +# Suite proposal failure diagnosis + +The real job `ca6290e71cb14bd1af64864f7c3ea256` failed in `proposal_a` +after 30.264 seconds, with no completed model pass. Only stored operational +metadata was inspected. No real case content was read or resubmitted. + +## Established failure + +`parse_claude()` rejected the terminal CLI result in its `cli_final_result` +branch because `is_error` was true. The subtype was `success`, which alone +does not establish successful generation. The process exited with code 1. +The final result event and initialization event were both present. + +The CLI reported one of six turns, `stop_sequence`, zero input/output/cache +tokens, zero API duration, and no runtime model-usage entry. There was no +structured result, structured tool input, or JSON text candidate. The job +did not reach schema extraction or assignment validation. + +There is no evidence of a turn limit, structured-output retry limit, explicit +context/output exhaustion, process signal, cancellation, or subprocess timeout. +The subprocess allowance was 1799.965410697274 seconds. The provider timeout +and reasoning-token limit remain unknown. The configured output cap was +64000 tokens; no observed output-limit entry was returned for this job. +Zero reported usage does not prove that no content reached the provider. + +The original CLI/provider cause is unknown. CLI output and temporary files +were deleted by normal cleanup; the old diagnostics did not preserve the +assistant error category. There is no complete answer to recover. The +61-case count is not an established cause. + +## Server-only diagnostic correction + +Execution revision `suite-multipass-v8-20260929` preserves the prompt revision +`implementation-proximity-multipass-v4-20260929`, compatibility revision +`suite-v6-20260929`, selected model, effort policy, authentication, routing, +timeouts, six-turn limit, and strict output/coverage checks. + +It adds `assistant_error_code`, `assistant_api_error_seen`, and +`cli_transport_error` to safe CLI diagnostics. Categories use fixed allowlists; +transport signatures use exact CLI-marked error messages, without retaining +the message. Recognized upstream failures receive specific existing error +codes. Unknown failures remain explicit errors. No retry or fallback is added. + +The previous hardcoded `reasoning_effort: medium` diagnostic was incorrect. +The real job selected `high`; v8 reports the actual invocation configuration. + +## Validation + +- 149 focused tests pass, including terminal error flags, category mapping, + privacy canaries, process exits/signals/timeouts, turn limits, and coverage. +- Kustomize render and client dry-run pass for `services/hermes`. +- Isolated native Claude CLI 2.1.285 tests with a loopback mock returned + `subtype: success`, `is_error: true`, exit 1, one turn, zero usage for HTTP + 400/401/429/503 failures. A refused loopback connection produced the same + pattern with no HTTP status and assistant category `server_error`. +- These reproductions establish the adapter/envelope behavior, not the + specific historical upstream failure. They used fake credentials and no + hosted inference. + +The separately recorded live synthetic check exercises one complete 61-case +proposal, not the full multi-pass workflow. It must not be represented as a +rerun or recovery of the failed real job. + +## Client handling and rollback + +No client request/schema change is required. Reusing the old idempotency key +returns the old failed job. A user-initiated retry requires a fresh attempt +and idempotency key; the prepared source can be reused. Do not automatically +resubmit the real suite. + +Rollback by reverting the v8 diagnostic commit in Git and reconciling the +`hermes` Flux Kustomization. This restores v7 diagnostics; it does not recover +deleted output or change any completed/failed job record. diff --git a/scripts/ops/hermes_suite_proposal_diagnostic.py b/scripts/ops/hermes_suite_proposal_diagnostic.py new file mode 100755 index 00000000..d22e4d2c --- /dev/null +++ b/scripts/ops/hermes_suite_proposal_diagnostic.py @@ -0,0 +1,65 @@ +#!/usr/bin/env python3 +"""Run exactly one synthetic 61-case proposal through the deployed Claude adapter. + +Server-side only. Accepts no case input, never resumes a suite, and prints only +operational metadata and synthetic coverage scores. This is not a full workflow. +""" +import json +import sys +import threading +import time + +sys.path.insert(0, "/opt/planner") +from suite_contract import (EXECUTION_REVISION, PROMPT_REVISION, Problem, + encoded, validate_partition, validate_request) +from suite_multipass import Workflow, ordered_request, preflight_workflow +from suite_synthetic import fixture, score + + +def main(): + """Exercise the failing stage once, with complete synthetic fields and aliases.""" + request, expected = fixture(75) + request["cases"] = request["cases"][:59] + request["cases"][-2:] + request["suite"] = "SYNTHETIC-PROPOSAL-61" + for case in request["cases"]: + case["success_criteria"] += ( + " Record the configured input, observed result, and pass/fail outcome separately." + " Repeat the observation after fixture reset to distinguish persistent state from" + " the intended variation. Missing procedure details remain unknown; do not infer" + " additional interfaces or equipment from the shared reference placeholder.") + aliases = {case["alias"] for case in request["cases"]} + expected = {alias: family for alias, family in expected.items() if alias in aliases} + request["routing"] = {"allow_external": True, "allowed_external_providers": ["claude"]} + request = validate_request(request, ["claude"]) + selected = preflight_workflow(request) + report = {"test": "synthetic_proposal_a_only", "case_count": len(aliases), + "request_bytes": len(encoded(request)), "selection": selected, + "execution_revision": EXECUTION_REVISION, "prompt_revision": PROMPT_REVISION, + "automatic_retries": 0} + started, last_report = time.monotonic(), 0.0 + + def progress(value): + """Publish a content-free heartbeat during the single model invocation.""" + nonlocal last_report + if time.monotonic() - last_report >= 20: + print(json.dumps({key: value.get(key) for key in ( + "current_pass", "completed_model_passes", "job_elapsed_seconds", + "cli_running", "cli_output_bytes")}), file=sys.stderr, flush=True) + last_report = time.monotonic() + + workflow = Workflow(request, selected, threading.Event(), "192.168.22.8", progress) + try: + source = ordered_request(request) + result = workflow.call("proposal_a", source) + validate_partition(result, source, name_limit=56, unique_names=False) + report.update(status="completed", quality=score(result, expected), + passes=workflow.records, metadata=workflow.last_metadata) + except Problem as exc: + report.update(status="failed", **exc.document()) + report["wall_seconds"] = round(time.monotonic() - started, 3) + print(json.dumps(report, sort_keys=True), flush=True) + return 0 if report["status"] == "completed" else 1 + + +if __name__ == "__main__": + raise SystemExit(main()) diff --git a/services/hermes/scripts/suite_backends.py b/services/hermes/scripts/suite_backends.py index 4eb28ed9..def8b5af 100644 --- a/services/hermes/scripts/suite_backends.py +++ b/services/hermes/scripts/suite_backends.py @@ -183,9 +183,19 @@ def parse_claude(raw, expected_model, **process_info): if final.get("subtype") == "error_max_budget_usd": fail("job_cost_budget_exhausted", "cli_final_result") status = final.get("api_error_status") - code = "rate_limit" if status == 429 else "incomplete_generation" - if status in (401, 403): + assistant_error = diagnostics["assistant_error_code"] + transport_error = diagnostics["cli_transport_error"] + code = "incomplete_generation" + if status == 429 or assistant_error == "rate_limit": + code = "rate_limit" + elif status in (401, 403) or assistant_error in {"authentication_failed", "oauth_org_not_allowed"}: code = "provider_authentication" + elif transport_error == "request_timeout": + code = "backend_timeout_or_unavailable" + elif (transport_error in {"connection_error", "connection_refused"} + or assistant_error in {"overloaded", "server_error"} + or (type(status) is int and 500 <= status <= 599)): + code = "backend_unavailable" fail(code, "cli_final_result") if final.get("stop_reason") in {"max_tokens", "model_context_window_exceeded"}: fail("incomplete_generation", "provider_stop") @@ -226,11 +236,12 @@ def claude_generate(request, cancel, *, invocation=None, progress=None): if not token: raise Problem("provider_authentication", 503) model = MODELS["claude"]["model"] + effort = invocation.get("reasoning", MODELS["claude"]["reasoning"]) if invocation else MODELS["claude"]["reasoning"] with tempfile.TemporaryDirectory(prefix="suite-", dir="/jobs") as directory: root = Path(directory) (root / "input").write_text(invocation["input"] if invocation else prompt(request)) command = claude_command(model, request["execution"]["max_cost_usd"], - reasoning=invocation.get("reasoning") if invocation else None) + reasoning=effort) if invocation: command[command.index("--system-prompt") + 1] = invocation["system"] command[command.index("--json-schema") + 1] = encoded(invocation["schema"]).decode() @@ -244,7 +255,8 @@ def claude_generate(request, cancel, *, invocation=None, progress=None): env=env, cwd=directory, start_new_session=True) except OSError: raise Problem("backend_unavailable", 503, failure_stage="process_start", - **snapshot("", subprocess_timeout_seconds=seconds)) from None + **snapshot("", subprocess_timeout_seconds=seconds, + reasoning_effort=effort)) from None deadline = time.monotonic() + seconds next_progress = 0.0 try: @@ -272,7 +284,7 @@ def claude_generate(request, cancel, *, invocation=None, progress=None): with (root / "output").open("rb") as output: raw = output.read(OUTPUT_BYTES).decode("utf-8", errors="replace") info = {"exit_code": process.returncode, "subprocess_timeout_seconds": seconds, - "termination_reason": failure.code if failure else None} + "termination_reason": failure.code if failure else None, "reasoning_effort": effort} if failure: raise Problem(failure.code, failure.status, failure_stage="subprocess", **snapshot(raw, **info)) diff --git a/services/hermes/scripts/suite_cli_diagnostics.py b/services/hermes/scripts/suite_cli_diagnostics.py index 157c9a6a..db8dd709 100644 --- a/services/hermes/scripts/suite_cli_diagnostics.py +++ b/services/hermes/scripts/suite_cli_diagnostics.py @@ -10,6 +10,14 @@ SUBTYPES = {"success", "error_max_turns", "error_max_structured_output_retries", "error_max_budget_usd", "error_during_execution"} STOP_REASONS = {"end_turn", "tool_use", "max_tokens", "stop_sequence", "refusal", "pause_turn", "model_context_window_exceeded"} +ASSISTANT_ERRORS = {"authentication_failed", "oauth_org_not_allowed", "account_on_hold", + "billing_error", "rate_limit", "overloaded", "invalid_request", + "model_not_found", "server_error", "unknown", "max_output_tokens"} +TRANSPORT_MESSAGES = { + "API Error: Connection error.": "connection_error", + "API Error: Request timed out.": "request_timeout", + "API Error: Connection refused \u2014 a firewall or proxy may be blocking it (ECONNREFUSED)": "connection_refused", +} def number(value): @@ -47,10 +55,13 @@ def object_text(value): return False -def snapshot(raw, *, exit_code=None, subprocess_timeout_seconds=None, termination_reason=None): +def snapshot(raw, *, exit_code=None, subprocess_timeout_seconds=None, termination_reason=None, + reasoning_effort=None): """Return bounded diagnostic fields from a CLI stream, including failed runs.""" final, last_assistant = None, {} initialized = compacted = tool_candidate = text_candidate = False + assistant_error_code, transport_error = None, None + assistant_api_error_seen = False invalid_events = 0 for line in raw.splitlines(): try: @@ -67,6 +78,10 @@ def snapshot(raw, *, exit_code=None, subprocess_timeout_seconds=None, terminatio final = event if event.get("type") == "assistant" and isinstance(event.get("message"), dict): last_assistant = event["message"] + if event.get("error") is not None: + assistant_error_code = enum(event["error"], ASSISTANT_ERRORS) + api_error = event.get("is_api_error_message") is True + assistant_api_error_seen |= api_error content = last_assistant.get("content", []) for block in content if isinstance(content, list) else []: if isinstance(block, dict): @@ -74,6 +89,9 @@ def snapshot(raw, *, exit_code=None, subprocess_timeout_seconds=None, terminatio block.get("name") == "StructuredOutput" and isinstance(block.get("input"), dict)) text_candidate |= block.get("type") == "text" and object_text(block.get("text")) + if api_error and block.get("type") == "text" and isinstance(block.get("text"), str): + # Match only exact CLI-generated signatures; never retain error text. + transport_error = TRANSPORT_MESSAGES.get(block["text"].strip(), transport_error) result = final or {} subtype = enum(result.get("subtype"), SUBTYPES) stop_reason = enum(result.get("stop_reason"), STOP_REASONS) @@ -101,6 +119,9 @@ def snapshot(raw, *, exit_code=None, subprocess_timeout_seconds=None, terminatio "provider_stop_reason": stop_reason, "last_assistant_stop_reason": enum(last_assistant.get("stop_reason"), STOP_REASONS), "api_error_status": number(result.get("api_error_status")), + "assistant_error_code": assistant_error_code, + "assistant_api_error_seen": assistant_api_error_seen, + "cli_transport_error": transport_error, "invalid_event_count": invalid_events, "structured_output_present": result.get("structured_output") is not None if final is not None else None, "structured_output_is_object": isinstance(result.get("structured_output"), dict) if final is not None else None, @@ -114,6 +135,6 @@ def snapshot(raw, *, exit_code=None, subprocess_timeout_seconds=None, terminatio "cost_usd_estimate": number(result.get("total_cost_usd")), "observed_model_limits": limits[:8], "configured_max_output_tokens": 64000, - "reasoning_effort": "medium", + "reasoning_effort": enum(reasoning_effort, {"high", "xhigh"}), "reasoning_token_limit": None, } diff --git a/services/hermes/scripts/suite_contract.py b/services/hermes/scripts/suite_contract.py index 9814e2fb..a6f468c0 100644 --- a/services/hermes/scripts/suite_contract.py +++ b/services/hermes/scripts/suite_contract.py @@ -9,7 +9,7 @@ from collections import Counter REVISION = "suite-v6-20260929" PROMPT_REVISION = "implementation-proximity-multipass-v4-20260929" -EXECUTION_REVISION = "suite-multipass-v7-20260929" +EXECUTION_REVISION = "suite-multipass-v8-20260929" CLAUDE_VERSION = "2.1.285" CLAUDE_MODELS = { "claude-opus-4-8": 64000, diff --git a/services/hermes/suite-planner-deployment.yaml b/services/hermes/suite-planner-deployment.yaml index 1a4aae16..ed34dddd 100644 --- a/services/hermes/suite-planner-deployment.yaml +++ b/services/hermes/suite-planner-deployment.yaml @@ -36,7 +36,7 @@ spec: app: hermes-suite-planner annotations: fluentbit.io/exclude: "true" - ai.bstein.dev/config-rev: suite-v6-multipass-cap5-v7-20260929 + ai.bstein.dev/config-rev: suite-v6-multipass-cap5-v8-20260929 vault.hashicorp.com/agent-inject: "true" vault.hashicorp.com/agent-pre-populate-only: "true" vault.hashicorp.com/agent-init-first: "true" diff --git a/testing/tests/test_suite_cli_diagnostics.py b/testing/tests/test_suite_cli_diagnostics.py index c8b9dceb..09eda314 100644 --- a/testing/tests/test_suite_cli_diagnostics.py +++ b/testing/tests/test_suite_cli_diagnostics.py @@ -70,6 +70,54 @@ def test_provider_error_status_is_preserved(status, code): assert raised.value.details["api_error_status"] == status +@pytest.mark.parametrize("category,code", [ + ("authentication_failed", "provider_authentication"), + ("oauth_org_not_allowed", "provider_authentication"), + ("rate_limit", "rate_limit"), ("server_error", "backend_unavailable"), + ("overloaded", "backend_unavailable"), ("unknown", "incomplete_generation"), + (CANARY, "incomplete_generation"), +]) +def test_error_flag_on_success_subtype_uses_safe_assistant_category(category, code): + """A result subtype alone does not mean the CLI completed successfully.""" + assistant = {"type": "assistant", "error": category, "is_api_error_message": True, + "message": {"content": [{"type": "text", "text": CANARY}]}} + raw = json.dumps(assistant) + "\n" + envelope(is_error=True, structured_output=None, + num_turns=1, usage={"output_tokens": 0}) + with pytest.raises(Problem, match=code) as raised: + suite_backends.parse_claude(raw, MODEL, exit_code=1, reasoning_effort="high") + details = raised.value.details + assert details["final_event_subtype"] == "success" and details["final_is_error"] is True + assert details["assistant_error_code"] == ("other" if category == CANARY else category) + assert details["assistant_api_error_seen"] is True + assert details["failure_stage"] == "cli_final_result" and details["turns"] == 1 + assert details["turn_limit_reached"] is False and details["reasoning_effort"] == "high" + assert CANARY not in json.dumps(raised.value.document()) + + +@pytest.mark.parametrize("text,marked,transport,code", [ + ("API Error: Connection error.", True, "connection_error", "backend_unavailable"), + ("API Error: Connection refused \u2014 a firewall or proxy may be blocking it (ECONNREFUSED)", + True, "connection_refused", "backend_unavailable"), + ("API Error: Request timed out.", True, "request_timeout", "backend_timeout_or_unavailable"), + ("API Error: Connection error.", False, None, "incomplete_generation"), + ("API Error: Connection error. " + CANARY, True, None, "incomplete_generation"), +]) +def test_transport_signatures_require_exact_cli_error_marker(text, marked, transport, code): + """Provider text never becomes a diagnostic string or a substring classifier.""" + assistant = {"type": "assistant", "error": "unknown", "is_api_error_message": marked, + "message": {"content": [{"type": "text", "text": text}]}} + raw = json.dumps(assistant) + "\n" + envelope(is_error=True, structured_output=None) + with pytest.raises(Problem, match=code) as raised: + suite_backends.parse_claude(raw, MODEL, exit_code=1) + assert raised.value.details["cli_transport_error"] == transport + assert CANARY not in json.dumps(raised.value.document()) + + +@pytest.mark.parametrize("effort", ["high", "xhigh", None]) +def test_reasoning_effort_reports_actual_configuration_or_unknown(effort): + assert snapshot(envelope(), reasoning_effort=effort)["reasoning_effort"] == effort + + @pytest.mark.parametrize("reason", ["max_tokens", "model_context_window_exceeded"]) def test_explicit_provider_stop_distinct_from_turn_limit(reason): with pytest.raises(Problem, match="incomplete_generation") as raised: @@ -193,6 +241,7 @@ def test_actual_subprocess_paths_cleanup_and_safe_metadata(tmp_path, monkeypatch suite_backends.claude_generate(value, cancel) details = raised.value.details assert details["failure_stage"] == stage + assert details["reasoning_effort"] == MODELS["claude"]["reasoning"] if mode in {"timeout", "cancel"}: assert details["termination_signal"] == signal.SIGTERM assert details["termination_reason"] == mode.replace("cancel", "cancelled") @@ -201,6 +250,7 @@ def test_actual_subprocess_paths_cleanup_and_safe_metadata(tmp_path, monkeypatch updates = [] _, metadata = suite_backends.claude_generate(value, cancel, progress=updates.append) assert metadata["cli_diagnostics"]["exit_code"] == 0 + assert metadata["cli_diagnostics"]["reasoning_effort"] == MODELS["claude"]["reasoning"] assert metadata["temporary_files_deleted"] is True assert updates and updates[-1]["cli_output_bytes"] > 0 assert updates[-1]["cli_running"] is True