Skip to content

test(e2e): Never let a failing command hide its output - #1097

Open
KeyZer wants to merge 1 commit into
moonrepo:masterfrom
KeyZer:e2e/never-hide-a-failure
Open

test(e2e): Never let a failing command hide its output#1097
KeyZer wants to merge 1 commit into
moonrepo:masterfrom
KeyZer:e2e/never-hide-a-failure

Conversation

@KeyZer

@KeyZer KeyZer commented Aug 21, 2026

Copy link
Copy Markdown
Contributor

Refs #1095, independent of #1096 (either can land first).

The E2E logs for both failures in run 32400669447 end on Verifying shim version... — no exit code, no output, no assertion message, 290 KB of trace logging and the actual error nowhere in it. The cause is in lib/utils.sh:

ver=$("$shim" "$version_arg" 2>&1)   # set -e aborts the test here
shim_rc=$?                           # never runs
echo "  exit=$shim_rc"               # never runs
echo "  output=$ver"                 # never runs, the error dies with $ver

Under set -e a failing command substitution aborts immediately, so every if [[ $rc -ne 0 ]] below it was dead code, and the same pattern was in test_bin, install_tool and install_backend.

Changes

  • run_probe / echo_probe (lib/assert.sh) — run a command, record RUN_RC / RUN_OUT / RUN_ERR keeping the two streams apart, never abort the caller. test_bin and test_shim now log the exit code, the output and the stderr before asserting on any of it. Keeping stderr separate also means proto bin's path can't be polluted by whatever it logs.

  • ERR trap with a stack trace (lib/assert.sh) — any unhandled failure now prints the command, file:line and the call stack. Failures inside a command substitution are skipped (BASH_SUBSHELL), as they are either handled by the caller or reported again by the assignment around them, so tests like 41-bin-shim that deliberately tolerate failures stay quiet.

    ASSERT FAIL: expected substring '999' in: moon 2.2.6
    COMMAND FAILED (exit=1) at e2e/lib/assert.sh:49: return 1
      called from assert_contains (e2e/lib/utils.sh:112)
      called from test_shim (e2e/lib/utils.sh:150)
      called from install_tool (e2e/tests/18-install-moon.sh:6)
    
  • Post-mortem on failure (run.sh) — writes .logs/<name>.postmortem.txt with the shared .prototools, the shim registry, the shims dir and proto status, captured while the state still exists. None of that is visible in a test's own log, and it is where cross-test failures actually live. The failure report also leads with the ASSERT FAIL / COMMAND FAILED lines instead of burying them under the tail.

  • GitHub Actions annotations + step summary (run.sh) — a red E2E job showed nothing beyond Process completed with exit code 1, not even which test failed. Failures now emit ::error annotations carrying the assertion message, and the step summary lists every failed and skipped test with its cause. Both are guarded on GITHUB_ACTIONS / GITHUB_STEP_SUMMARY, so a local run is unchanged.

  • E2E_SERIAL=1 (run.sh) — never run a group in parallel. The first thing to reach for when a failure smells like tests interfering with their peers.

  • E2E_TAIL, E2E_KEEP_SCRATCH (run.sh) — inline tail size, and keeping the shared work dir so it can be poked at afterwards.

  • PROTO_HOME defaults to e2e/.proto-home (lib/env.sh) — it pointed at $HOME/.proto, so just test-e2e installed 20+ tools into the developer's own store, then 90-uninstall removed their uv and 99-clean pruned it. e2e/.gitignore already lists .proto-home/ and the README already documented that location, so this is the drift being closed rather than a new choice. E2E_USE_REAL_HOME=1 opts back in.

  • READMEPROTO_BIN_DIR doesn't exist in any script, the group names were stale (install-base / install-deps vs tools / tools-secondary / backends), and the store is not "wiped at the start of each run". Documents the knobs and how to debug a failure.

Also found while testing this

Running the suite from inside an AI agent (Claude Code, Codex, Cursor) failed on assert_executable, because proto detects the agent and switches its output to NDJSON — so proto bin node returned a JSON envelope instead of a path. lib/env.sh now blanks the same env vars crates/core/src/test_utils.rs does and pins PROTO_REPORTER=text, so the suite behaves the same whoever runs it.

Deliberately not changing

The shared scratch cwd. Nine parallel installs pinning into one .prototools is what caught a real lost-update bug in proto; isolating each test would have hidden it.

Both E2E failures on master (run 32400669447) produced logs that stop on
`Verifying shim version...` — no exit code, no output, no assertion message,
290 KB of trace logging and the actual error nowhere in it. The cause was in
`test_shim`:

    ver=$("$shim" "$version_arg" 2>&1)   # set -e aborts the test here
    shim_rc=$?                           # never runs
    echo "  exit=$shim_rc"               # never runs
    echo "  output=$ver"                 # never runs, the error dies with $ver

Under `set -e` a failing command substitution aborts immediately, so every
`if [[ $rc -ne 0 ]]` below it was dead code. `test_bin`, `install_tool`,
`install_backend` and 9 test scripts had the same shape.

`run_probe` now runs a command and records `RUN_RC` / `RUN_OUT` / `RUN_ERR` /
`RUN_ALL` without aborting, `echo_probe` writes all of it to the log, and
`assert_probe_ok` names the command that failed. Keeping the streams apart also
stops `proto bin`'s stdout path from being polluted by whatever it logs.

An `errtrace` ERR trap reports anything still unhandled, with the failing
command, its file:line and the call stack. Failures inside a command
substitution are skipped via `BASH_SUBSHELL`, so tests that deliberately
tolerate a failure (41-bin-shim) stay quiet.

On failure the harness now leads with the `ASSERT FAIL` / `COMMAND FAILED`
lines instead of burying them under the tail, and writes
`.logs/<name>.postmortem.txt` with the shared `.prototools`, the shim registry,
the shims dir and `proto status` — captured while that state still exists, and
none of it visible in a test's own log. Under GitHub Actions it also emits
`::error` annotations and a step summary, so a red job no longer says only
"Process completed with exit code 1".

New knobs: `E2E_SERIAL=1` (never run a group in parallel — the first thing to
reach for when a failure smells like tests interfering with each other),
`E2E_TAIL`, `E2E_KEEP_SCRATCH`.

Two things found while testing this:

`PROTO_HOME` pointed at `$HOME/.proto`, so `just test-e2e` installed 20+ tools
into the developer's own store, then 90-uninstall removed their `uv` and
99-clean pruned it. `e2e/.gitignore` already lists `.proto-home/` and the README
already documented that location, so this is drift being closed rather than a
new choice; `E2E_USE_REAL_HOME=1` opts back in.

proto switches to NDJSON when it detects an AI agent, so running the suite from
inside Claude Code or Codex failed on `assert_executable` with a JSON envelope
where a path should be. `env.sh` now blanks the same env vars
`crates/core/src/test_utils.rs` does and pins `PROTO_REPORTER=text`.

The shared scratch cwd is deliberately left alone: 9 parallel installs pinning
into one `.prototools` is what caught a real lost-update bug in proto, and
isolating each test would have hidden it.
@KeyZer

KeyZer commented Aug 21, 2026

Copy link
Copy Markdown
Contributor Author

The Suite (ubuntu-latest) leg here is red, and it is the bug in #1095 rather than anything in this PR: this branch has the harness changes but not the fix, so the race is still live. It hit 17-install-uv this time.

It is also the clearest demonstration of why this PR exists. Everything needed to diagnose it is in the run without opening a single log:

  • The run page annotation reads E2E (linux) 17-install-uv: ASSERT FAIL: .../shims/uv --version exited 1.
  • The log records the error the old harness discarded — proto::detect::failed, "Failed to detect an applicable version to run uv with".
  • 17-install-uv.postmortem.txt shows the shared .prototools holding 8 tools and no uv, moments after uv = "0.11.33" was pinned.

The same two legs are green on #1096, which carries the fix. So this one should go green once #1096 lands — happy to rebase on top of it if you'd rather see that before merging, or it can just wait its turn.

@milesj

milesj commented Aug 23, 2026

Copy link
Copy Markdown
Contributor

@KeyZer Can you rebase master and try again.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Development

Successfully merging this pull request may close these issues.

2 participants