`claude --print --output-format json` reports its own failures (API error, usage limit, error_max_turns) as the result envelope on stdout and leaves stderr empty, so ask_pm()'s stderr-only message logged "claude exited 1: " with nothing after it, twice on 2026-10-31. describe_cli_failure() now logs the envelope's diagnostic fields plus stdout/stderr tails, redacted (sk-ant-, Bearer/token, URL userinfo). PM_DECISION_MAX_TURNS (default 1, unchanged) makes the max-turns remedy a ConfigMap change if the envelope turns out to say error_max_turns. Co-Authored-By: Claude Opus 5.5 <[email protected]>
78 lines
4.9 KiB
Markdown
78 lines
4.9 KiB
Markdown
---
|
||
date: 2026-10-31
|
||
branch: fix/pm-agent-triage-exit
|
||
title: pm-agent triage fails with "claude exited 1:" and no message; log the CLI's stdout envelope so the cause is visible
|
||
---
|
||
|
||
## What changed
|
||
|
||
- `infra/agent/pm-dispatch.py`, `ask_pm()`: on a non-zero exit the error now comes from a new
|
||
`describe_cli_failure()`, not from `proc.stderr` alone. With `--output-format json` the CLI
|
||
reports its own failures as the result envelope on **stdout** and writes nothing to stderr,
|
||
which is why both failures today logged `claude exited 1: ` with an empty message. The new
|
||
line carries the envelope's `subtype`, `is_error`, `api_error_status`, `num_turns`,
|
||
`duration_ms`, `total_cost_usd`, `stop_reason`, its `result`/`error` text, and the tails of
|
||
stdout and stderr. It names silence explicitly when both streams are empty.
|
||
- `redact()`: everything in that message, and in `extract_decision()`'s "no decision object"
|
||
error, passes through it. It covers `sk-ant-…`, `Bearer`/`token` values, and `user:pass@` in
|
||
both `http://` and `https://` URLs.
|
||
- `PM_DECISION_MAX_TURNS`: a new knob. It defaults to 1, today's value, so behaviour is
|
||
unchanged, and it is bounded to 1–5. If the newly visible envelope says `error_max_turns`,
|
||
the remedy is a ConfigMap change rather than another image build. Documented in
|
||
`platform/pm-agent/README.md`.
|
||
- Selftest: four new assertions. They cover an empty stderr with the cause on stdout, a
|
||
stderr-only failure, total silence, and redaction.
|
||
|
||
## What I verified
|
||
|
||
- **Timeline (Loki, `{namespace="pm-agent"}`, and `kubectl logs`):**
|
||
- **16:37:38 to 16:38:00**: pod `pm-agent-898fd8f5f-dp5hs`, image **c4eba5b3**,
|
||
config-generation 2, dry run. It triaged #97 in **22 s**, logged `PM says comment`, and
|
||
posted the 16:38:00Z comment. The thread then held only the issue body.
|
||
- **16:43:09 to 16:44:00**: pod `pm-agent-f7c9b7fcf-j8mzn`, image **df36d9b7**,
|
||
config-generation 3, **still dry run**. It logged `claude exited 1: ` with an empty
|
||
message after **51 s**.
|
||
- **16:55:42 to 16:56:36**: pod `pm-agent-7796db8bcb-p5dsm`, df36d9b7, config-generation
|
||
4, live. The same empty failure, after **54 s**.
|
||
- The only successful triage ever was the 16:38 one. Every earlier `898fd8f5f`/`5db55d558c`
|
||
log line is a startup crash (Gitea `GET /user` 401), not a triage.
|
||
- **Going live is NOT the cause.** The first failure happened in dry run. `ask_pm()` has no
|
||
dry-run branch: the prompt, flags, tools (`--tools ""`) and cwd are identical in both
|
||
modes. `PM_DRY_RUN` gates only `create_job()`, which runs after the model has answered.
|
||
- **Ruled out, with evidence:**
|
||
- **Timeout**: 51 to 54 s against a 900 s limit, and a timeout raises `TimeoutExpired`,
|
||
not rc 1.
|
||
- **Budget cap**: the PM call passes no `--max-budget-usd`.
|
||
- **Prompt size**: the thread is the issue body (293 chars) plus three comments
|
||
(1871 + 404 + 77 chars), and the persona is 8 KB.
|
||
- **Writable HOME**: HOME=`/workspace` (emptyDir), and `CLAUDE_CONFIG_DIR=/workspace/.claude`
|
||
was written at 16:56.
|
||
- **Egress**: a TLS 1.3 handshake to `api.anthropic.com:443` from the dispatcher pod
|
||
succeeds in 0.06 s.
|
||
- **Model name and CLI version**: the same `claude-opus-5` and CLI 2.1.285 succeeded at
|
||
16:38. Between c4eba5b and df36d9b, `infra/agent/` differs only by a template selftest
|
||
assertion and the toolbox base digest.
|
||
- **A hint, not proof:** `/workspace/.claude/.claude.json` in the live pod has
|
||
`cachedExtraUsageDisabledReason: 'out_of_credits'`. No token was read or printed.
|
||
- Offline selftest: `PM_SELFTEST=1` against the worktree's template and persona prints
|
||
`selftest OK`, including the 4 new assertions.
|
||
- Toolbox gate: see the PR description for the rc and the stages that were skipped.
|
||
|
||
## What I did NOT verify
|
||
|
||
- **The root cause. UNVERIFIED.** The CLI's own message was discarded, `--no-session-persistence`
|
||
leaves no transcript, and I did not run `claude` in the pod. The candidates still open:
|
||
- **Usage or rate limit on the subscription seat.** The seat is shared with the operator's
|
||
interactive use. The `out_of_credits` extra-usage flag fits this. So does a ~50 s run,
|
||
which matches the CLI exhausting its 429/529 retries.
|
||
- **`error_max_turns`.** With `--max-turns 1` and `--json-schema`, an answer that fails the
|
||
schema cannot be retried. The failing thread now invites `implement` (a branch plus a
|
||
long brief), where the 16:38 one produced a short `comment`. ~50 s is about two
|
||
generations of the 22 s success.
|
||
- **The 17:11 retry will NOT reveal the cause.** It runs the old image, which still discards
|
||
stdout. The cause becomes visible only after this PR merges, CI re-publishes agent-runner,
|
||
and a follow-up PR bumps the dispatcher digest (`deployment.yaml` and the `PM_WORKER_IMAGE`
|
||
in `configmap.yaml`, plus a `config-generation` bump).
|
||
- That the CLI's error envelope carries exactly these key names. The parser takes whichever
|
||
keys are present and falls back to raw tails.
|