fix(agent): build/verify failure diagnosis — timeout classify, claude-binary Exec-format, failing-line surfacing

agent/Dockerfile

@@ -61,10 +61,19 @@ RUN corepack enable && corepack prepare yarn@stable --activate || corepack enabl
 # returned creds are cached until 5 min before the JSON's `Expiration`, so an
 # 8 h task re-assumes the 1 h-capped SessionRole before expiry. Older builds
 # only refreshed hourly on a timer, racing the role-chaining cap.
+# claude-code@2.1.x ships an error-shim at bin/claude.exe that its postinstall
+# (install.cjs) replaces with the platform-native ELF binary. That postinstall
+# can silently fall back (leaving the shim in place) — the shim then dies at
+# runtime with "Exec format error: 'claude'" even though the native binary is
+# present as an optional dep, just never wired up. Re-run install.cjs explicitly
+# after the install so the native binary is placed at build time, and hard-verify
+# it exec's (``claude --version`` fails the build if the shim is still on PATH).
 RUN npm install -g npm@latest && \
     npm install -g @anthropic-ai/claude-code@2.1.191 && \
     CLAUDE_NPM_ROOT="$(npm root -g)/@anthropic-ai/claude-code" && \
-    npm --prefix "${CLAUDE_NPM_ROOT}" update tar minimatch glob cross-spawn picomatch
+    npm --prefix "${CLAUDE_NPM_ROOT}" update tar minimatch glob cross-spawn picomatch && \
+    node "${CLAUDE_NPM_ROOT}/install.cjs" && \
+    claude --version
 
 # Install uv (fast Python package manager) — pinned for reproducibility
 COPY --from=ghcr.io/astral-sh/uv:0.11.14 /uv /usr/local/bin/uv

agent/src/shell.py

@@ -160,6 +160,83 @@ def _clean_env() -> dict[str, str]:
     return env
 
 
+# Substrings that mark a line as a real failure in build/test tool output — used
+# to pull the FAILING line out of the MIDDLE of a large interleaved parallel-DAG
+# log (a plain tail misses it). Lower-cased comparison; conservative so we don't
+# flood on benign "warning"/"0 errors" lines.
+_FAILURE_LINE_MARKERS = (
+    "fail ",  # jest "FAIL test/foo.test.ts", pytest "FAILED"
+    "failed",
+    "✕",
+    "✗",
+    "✖",
+    "●",  # jest failed-assertion bullet
+    "error ts",  # tsc "error TS2345:"
+    "error:",
+    "elifecycle",  # yarn/npm lifecycle failure
+    "npm err!",
+    "does not meet",  # jest coverage-threshold "global … does not meet threshold"
+    "coverage threshold",
+    'jest: "global"',
+    "not trusted",  # mise untrusted config
+    "no task ",  # mise "no task named"
+    "missing script",  # npm missing script
+    "assertionerror",
+    "traceback (most recent call last)",
+    "task failed",  # mise "[//pkg:task] ERROR task failed"
+)
+
+# Benign lines that CONTAIN a marker substring but are not failures — filtered so
+# the surfaced set stays signal. e.g. "0 errors", "--no-error-on-unmatched".
+_FAILURE_LINE_NOISE = (
+    "0 errors",
+    "0 failed",
+    "no error",
+    "--no-error",
+    "0 problems",
+    "may fail",  # advisory prose
+)
+
+# Cap surfaced failure lines so a genuinely huge red run (hundreds of failing
+# assertions) can't flood CloudWatch; the count + a tail still convey scale.
+_MAX_SURFACED_FAILURE_LINES = 40
+_FAILURE_TAIL_LINES = 15
+
+
+def _surface_failure_lines(stdout: str) -> list[str]:
+    """From a failed command's stdout, return the lines most likely to name the
+    cause: every failure-signature line (scanning the WHOLE output, not just the
+    tail — a parallel task DAG interleaves output so the red line is often in the
+    middle) followed by a trailing-context tail. Deduped, order-preserving,
+    capped. This is the fix for build-gate failures that a plain tail couldn't
+    explain (ABCA-662: the tail was a passing package's coverage table)."""
+    lines = stdout.strip().splitlines()
+    matched: list[str] = []
+    for ln in lines:
+        low = ln.lower()
+        if any(m in low for m in _FAILURE_LINE_MARKERS) and not any(
+            n in low for n in _FAILURE_LINE_NOISE
+        ):
+            matched.append(ln.rstrip())
+            if len(matched) >= _MAX_SURFACED_FAILURE_LINES:
+                matched.append("… (more failure lines truncated)")
+                break
+    tail = [ln.rstrip() for ln in lines[-_FAILURE_TAIL_LINES:]]
+    # Order: failure-signature lines first (the WHY), then the tail (context),
+    # dropping tail lines already surfaced as matches.
+    seen = set(matched)
+    out = list(matched)
+    if matched and tail:
+        out.append("--- (trailing output) ---")
+    for ln in tail:
+        if ln not in seen:
+            out.append(ln)
+            seen.add(ln)
+    # Fallback: nothing matched a failure marker (unknown tool) → just the tail,
+    # so we never log NOTHING on a failure.
+    return out or tail
+
+
 def run_cmd(
     cmd: list[str],
     label: str,
@@ -182,6 +259,24 @@ def run_cmd(
         if result.stderr:
             for line in result.stderr.strip().splitlines()[:20]:
                 log("CMD", f"  {line}")
+        # ALSO surface stdout on failure. Build/test tooling (jest, tsc, the mise
+        # task DAG) writes the ACTUAL failing-task error to STDOUT, not stderr —
+        # stderr often carries only the runner's plan echo. Logging stderr alone
+        # made build-gate failures undebuggable: a red ``mise run build`` showed
+        # every task STARTING but never WHICH one failed or why (ABCA-662).
+        #
+        # A plain tail is NOT enough for a PARALLEL task DAG: `mise run build`
+        # runs 4 packages concurrently and interleaves their output, so the
+        # failing task's error scrolls into the MIDDLE while the tail captures
+        # whatever finished LAST (e.g. a passing package's coverage table) —
+        # ABCA-662 follow-up: the tail showed a coverage table, not the red task.
+        # So FIRST scan the whole output for failure-signature lines and surface
+        # those (this is what names the failing sub-task), THEN a larger tail for
+        # trailing context. Redact — repo build output is untrusted.
+        if result.stdout:
+            surfaced = _surface_failure_lines(result.stdout)
+            for line in surfaced:
+                log("CMD", f"  {redact_secrets(line)}")
         if check:
             stderr_snippet = redact_secrets(result.stderr.strip()[:500]) if result.stderr else ""
             raise RuntimeError(f"{label} failed (exit {result.returncode}): {stderr_snippet}")

agent/tests/test_shell.py

@@ -6,6 +6,7 @@
 from shell import (
     is_transient_cmd_failure,
     redact_secrets,
+    run_cmd,
     run_cmd_with_backoff,
     slugify,
     truncate,
@@ -185,3 +186,97 @@ def test_backoff_delays_are_exponential(self):
         with patch("shell.run_cmd", side_effect=lambda *a, **k: seq.pop(0)):
             run_cmd_with_backoff(["git", "clone"], "clone", base_delay_s=2.0, sleep=delays.append)
         assert delays == [2.0, 4.0]  # 2 * 2**0, 2 * 2**1
+
+
+class TestRunCmdFailureLogging:
+    """A failing command must surface its ACTUAL error. Build/test tooling (jest,
+    tsc, the mise task DAG) writes the failing-task error to STDOUT, not stderr —
+    so logging stderr alone made build-gate failures undebuggable (ABCA-662: a red
+    ``mise run build`` showed every task starting but never WHICH one failed)."""
+
+    def _completed(self, rc, stdout="", stderr=""):
+        return SimpleNamespace(returncode=rc, stdout=stdout, stderr=stderr)
+
+    def _run_capturing_logs(self, proc):
+        logs = []
+        with (
+            patch("shell.subprocess.run", return_value=proc),
+            patch("shell.log", side_effect=lambda prefix, text: logs.append((prefix, text))),
+        ):
+            run_cmd(["mise", "run", "build"], "verify-build-post", check=False)
+        return logs
+
+    def test_stdout_is_logged_on_failure(self):
+        # The failing task's error lives in stdout — it MUST reach the log.
+        proc = self._completed(
+            1,
+            stdout="[//cdk:test] FAIL test/foo.test.ts\n  expected 1 got 2\n[//cdk:test] exit 1",
+            stderr="",
+        )
+        logs = self._run_capturing_logs(proc)
+        blob = "\n".join(text for _, text in logs)
+        assert "FAIL test/foo.test.ts" in blob
+        assert "expected 1 got 2" in blob
+
+    def test_no_markers_falls_back_to_tail(self):
+        # Unknown tool output with no failure signature → fall back to the tail.
+        proc = self._completed(
+            1,
+            stdout="\n".join(f"line {i}" for i in range(50)),
+            stderr="",
+        )
+        logs = self._run_capturing_logs(proc)
+        blob = "\n".join(text for _, text in logs)
+        assert "line 49" in blob  # last line present (tail)
+        assert "line 0" not in blob  # earliest lines dropped
+
+    def test_failure_line_in_the_MIDDLE_is_surfaced(self):
+        # ABCA-662 root cause of the tooling gap: a PARALLEL mise DAG interleaves
+        # output, so the failing task's line is in the MIDDLE while the tail is a
+        # passing package's coverage table. The failing line MUST be surfaced.
+        mid = "[//cdk:test] FAIL test/handlers/foo.test.ts — expected 1 got 2"
+        stdout = (
+            "\n".join(f"[//cdk:test] passing line {i}" for i in range(30))
+            + f"\n{mid}\n"
+            + "\n".join(f"[//agent:test] coverage {i} | 100 | 100" for i in range(30))
+        )
+        proc = self._completed(1, stdout=stdout, stderr="")
+        logs = self._run_capturing_logs(proc)
+        blob = "\n".join(text for _, text in logs)
+        assert "FAIL test/handlers/foo.test.ts" in blob  # the mid-DAG red is surfaced
+        assert "coverage 29" in blob  # tail context still present
+
+    def test_coverage_threshold_failure_is_surfaced(self):
+        # jest prints a coverage table then exits 1 with "does not meet threshold"
+        # — no ✕/FAIL line. That threshold line must be surfaced.
+        stdout = (
+            "\n".join(f"file{i}.ts | 100 | 100 | 100 | 100" for i in range(40))
+            + '\nJest: "global" coverage threshold for branches (82%) not met: 79%'
+        )
+        proc = self._completed(1, stdout=stdout, stderr="")
+        logs = self._run_capturing_logs(proc)
+        blob = "\n".join(text for _, text in logs)
+        assert "coverage threshold for branches" in blob
+
+    def test_benign_zero_errors_line_not_surfaced_as_failure(self):
+        # "0 errors" / "no error" must NOT be pulled in as a failure marker.
+        stdout = "eslint: 0 errors, 0 warnings\n" + "\n".join(f"ok {i}" for i in range(20))
+        proc = self._completed(1, stdout=stdout, stderr="")
+        logs = self._run_capturing_logs(proc)
+        # It falls back to tail (no real failure markers); the "0 errors" line is
+        # not falsely elevated as THE failure.
+        blob = "\n".join(text for _, text in logs)
+        assert "ok 19" in blob
+
+    def test_stdout_is_redacted(self):
+        proc = self._completed(1, stdout="error: pushing with ghp_supersecrettoken123", stderr="")
+        logs = self._run_capturing_logs(proc)
+        blob = "\n".join(text for _, text in logs)
+        assert "ghp_supersecrettoken123" not in blob
+
+    def test_success_does_not_dump_stdout(self):
+        # On success we don't spam stdout — only the OK line.
+        proc = self._completed(0, stdout="lots of build output", stderr="")
+        logs = self._run_capturing_logs(proc)
+        blob = "\n".join(text for _, text in logs)
+        assert "lots of build output" not in blob

cdk/src/handlers/shared/error-classifier.ts

@@ -433,6 +433,24 @@ const PATTERNS: readonly ErrorPattern[] = [
   },
 
   // --- Timeout ---
+  {
+    // The build/verify command shelled out and was KILLED at the wall-clock cap
+    // (Python subprocess `TimeoutExpired … timed out after N seconds`). Live-caught
+    // on ABCA-667: the fork's full `mise run build` (~2800 tests) exceeded the
+    // 600s default and surfaced as a bare "Unexpected error". This is NOT a code
+    // failure — the build didn't fail, it ran too long — so name it precisely and
+    // point at the timeout, not the diff. On a big repo the fix is a higher
+    // BUILD_VERIFY_TIMEOUT_S (or the ECS build box), which an admin sets — but a
+    // one-off may just be slow, so it's a user-actionable "retry / raise the cap".
+    pattern: /TimeoutExpired.*timed out after \d+ ?s(econds)?|Command .*build.* timed out/i,
+    classification: {
+      category: ErrorCategory.TIMEOUT,
+      title: 'Build/tests didn\'t finish in time (timed out)',
+      description: 'The configured build/verify command was still running when it hit the time limit and was stopped — it did not fail, it ran too long.',
+      remedy: 'This is usually a slow build, not broken code. Retry (a one-off may just be slow); if this repo\'s build is legitimately long, an admin can raise BUILD_VERIFY_TIMEOUT_S or move it to the larger ECS build compute.',
+      retryable: true,
+    },
+  },
   {
     pattern: /poll timeout exceeded/i,
     classification: {

cdk/test/handlers/shared/error-classifier.test.ts

@@ -407,6 +407,22 @@ describe('classifyError', () => {
       expect(result!.title).toBe('Task timed out');
       expect(result!.retryable).toBe(false);
     });
+
+    test('classifies a build/verify command TIMEOUT distinctly from a crash (ABCA-667 live-caught)', () => {
+      // The fork's full `mise run build` exceeded the 600s cap → Python
+      // TimeoutExpired. Before this pattern it fell to "Unexpected error"; now it
+      // reads as a build-time-out (user-actionable: retry / raise the cap), not a
+      // mysterious crash.
+      const result = classifyError(
+        "TimeoutExpired: Command '['bash', '-lc', 'mise run install && MISE_EXPERIMENTAL=1 mise run build']' timed out after 600 seconds",
+      );
+      expect(result!.category).toBe(ErrorCategory.TIMEOUT);
+      expect(result!.title).toMatch(/didn't finish in time|timed out/i);
+      // A timeout is user-actionable (retry / raise the cap), not a hard failure.
+      expect(result!.retryable).toBe(true);
+      // Must NOT fall through to the generic Unexpected error.
+      expect(result!.title).not.toMatch(/Unexpected error/i);
+    });
   });
 
   // --- Environmental blockers (#251) ---