Skip to content

fix(installer): last failing command wins, so the report names the real one - #702

Merged
LukasWodka merged 2 commits into
developfrom
fix/691-err-recorder-last-wins
Aug 13, 2026
Merged

fix(installer): last failing command wins, so the report names the real one#702
LukasWodka merged 2 commits into
developfrom
fix/691-err-recorder-last-wins

Conversation

@LukasWodka

@LukasWodkaLukasWodka commented Aug 13, 2026

Copy link
Copy Markdown
Contributor

Fixes the diagnostic regression found by a field report on v1.9.34.

What went wrong

The run printed, confidently:

Stopped at .../lib/common.sh:527 (exit 1).
[..] FAILED at .../lib/common.sh:527 — exit 1 — command: sudo -n true

common.sh:527 is _real_sudo, reached from step a's_probe_privilege — whose sudo -n true returns non-zero to mean "a password is needed", which the installer then prints as a perfectly normal row:

Privilege regular user; sudo needs a password –

The actual failure was two steps later, in preflight_sudo. The ERR trap fires for every failing command, benign ones included, and the first-wins guard I shipped in #683 latched onto that routine probe and refused every later record.

A confidently wrong location is worse than the blank screen #683 replaced — it sends the reader to a line that is working as designed. I lost time to it myself before the breadcrumbs contradicted it.

Why first-wins was wrong in the first place

I built it on the belief that bash's ERR trap does not fire for a command inside a function called from an if/|| condition. It does. Measured:

contexttrap fires?
f || trueyes
if f; thenyes
if ! f; thenyes
while f; doyes

Last-wins is precise instead: errexit stops the script at the fatal command, and the trap fires once per failing command with no per-frame re-firing as the error unwinds (verified on bash 3.2 / macOS and 5.x).

Also in this PR

  • Re-entrancy guard.set -E makes the recorder inherit its own trap, and the new log call is exactly the kind of command that fails inside it — [[ -n "${LOG_FILE:-}" ]] && … returns non-zero with no log open. Without the guard that recurses forever.
  • install_cleanup disarms the ERR trap before reading the record. Its own lines fail routinely — a kill on a dead pid, a false [[ … ]] — and under last-wins each would overwrite the fatal command with a cleanup detail.
  • The full ERR trail goes to the log. The benign entries are not noise; reading them in order is what identified this bug.

Test plan

Five tests, all mutation-real — restoring the first-wins guard fails three of them:

--- with first-wins restored ---
not ok 23 _record_err: last failure wins
not ok 24 _record_err: a benign probe does not mask the fatal command
not ok 26 _record_err: logs the whole trail, not just the last one
--- restored ---
ok 23 ok 24 ok 26

The headline test reproduces the field shape end to end: a probe that fails inside an if, a step that then succeeds, a fatal command afterwards — and asserts the report names the fatal command, not the probe. Another asserts install_cleanup's dead-pid kill cannot overwrite the record.

The recursion test is bounded only where a bound exists — macOS ships no timeout(1), so it runs unbounded locally and Linux CI is the authority. Noted in the test.

  • make check green · make bats982 tests, 0 failures · manifest regenerated.

Follow-up

This does not explain the underlying failure in that report — it makes it reportable. The real defect there is that install_macos has no Tier 0 path and demands sudo on a machine where Docker is already running; that's a separate PR.

🤖 Generated with Claude Code


Note

Low Risk
Changes are limited to bash failure recording and exit cleanup messaging in the installer; no auth, data, or cluster logic is modified.

Overview
Fixes a diagnostic regression where the installer reported the wrong failure site (e.g. sudo -n true from a privilege probe) instead of the command that actually ended the run.

_record_err switches from first-wins to last-wins so expected non-zero exits from probes do not block later fatal records. It adds a _TB_IN_RECORD_ERR re-entrancy guard and writes every ERR to the install log (err: file:line exit=… cmd=…) while TB_ERR_* still reflects the final failure.

install_cleanup runs trap - ERR first so cleanup steps (dead kill, etc.) cannot overwrite that final record under last-wins.

scripts/tests/common.bats gains mutation-real coverage (benign probe vs fatal command, log trail, cleanup overwrite, fixed vacuous recursion test). scripts/manifest.sha256 is updated for common.sh.

Reviewed by Cursor Bugbot for commit cc36208. Bugbot is set up for automated code reviews on this repo. Configure here.

…al one
The ERR recorder shipped in #683 kept the FIRST failure. That is wrong, and a
field report showed why: the run reported
Stopped at .../lib/common.sh:527 (exit 1). command: sudo -n true
for a failure two steps later. common.sh:527 is _real_sudo, reached from step
a's _probe_privilege, whose `sudo -n true` returns non-zero to mean "a password
is needed" — the installer then PRINTS that as a normal row in the host check.
The trap fires for every failing command, benign ones included, so first-wins
latched onto a routine probe inside a step that SUCCEEDED and refused every
later record. The fatal command was never captured.
A confidently wrong location is worse than the blank screen #683 replaced: it
sends the reader to a line that is working as designed.
Last-wins is precise. errexit stops the script AT the fatal command, and the
trap fires once per failing command with no per-frame re-firing as the error
unwinds — verified on bash 3.2 (macOS) and 5.x.
Also:
- Re-entrancy guard. `set -E` makes the recorder inherit its own trap, and the
new `log` call is exactly the kind of command that fails inside it (its
`[[ -n "${LOG_FILE:-}" ]] && …` form returns non-zero with no log open).
Without the guard that recurses forever.
- install_cleanup disarms the ERR trap before reading the record. Its own lines
fail routinely — a `kill` on a dead pid, a false `[[ … ]]` — and under
last-wins each would overwrite the fatal command with a cleanup detail.
- The full ERR trail now goes to the log. The benign entries are not noise:
reading them in order is what identified this bug.
Five bats tests, mutation-real against the first-wins guard, including the
field shape end to end — a probe that fails inside an `if`, a step that then
succeeds, a fatal command afterwards. 982 bats green.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
@LukasWodkaLukasWodka self-assigned this Aug 13, 2026
Comment threadscripts/tests/common.bats
@LukasWodka

Copy link
Copy Markdown
ContributorAuthor

CI triage: Pester (ubuntu-latest) failed once on adopted mode (#388): surgical --reuse-values reconcile heals a STALE (cli#125 numeric) clientId, then passed on re-run. Recording why I treated it as a flake rather than dismissing it:

Now 44 pass / 0 fail.

… the guard (client#702)
The recursion test drove the ERR trap with `command false || true`, which does
not fire it — a command in a || list is excluded from ERR (bash manual). On
bash 5.3 that form fires the trap zero times, so _record_err never ran and
SURVIVED printed with or without the guard. bash 3.2 does fire it, which is why
it looked green on macOS while being vacuous on Linux CI.
`unset LOG_FILE` was the other half: log() is `[[ -n $LOG_FILE ]] && echo …`,
so with no log open the write never attempts and nothing inside the recorder
fails. The failure has to come from the redirection, so point LOG_FILE at a path
whose parent does not exist (fails for root too, unlike chmod 000).
Fixing only that is not enough. bash re-enters an ERR trap at most once, so
deleting _TB_IN_RECORD_ERR does not hang anything and the survival test passes
either way. Add a test for what the guard actually protects: a re-entrant call
must not overwrite TB_ERR_* with the recorder's own log failure, which would
turn 'died at helm upgrade' into 'died writing its log'.
Verified by mutation — with the guard removed, the new test goes red and the
survival test stays green.
Co-Authored-By: Claude Opus 5 <noreply@anthropic.com>
@LukasWodka

Copy link
Copy Markdown
ContributorAuthor

bugbot run

@cursorcursorBot left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

✅ Bugbot reviewed your changes and found no new issues!

Comment @cursor review or bugbot run to trigger another review on this PR

Reviewed by Cursor Bugbot for commit cc36208. Configure here.

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

Solid change, and last-wins is the right call — I checked the semantics rather than taking the comment's word for it:

  • On bash 3.2 (macOS /bin/bash) the ERR trap fires eagerly even for the guarded _real_sudo -n true probe inside _probe_privilege's if, so first-wins really did latch onto that benign probe and mask the fatal command. On bash 5 (Linux CI) only the unguarded fatal command fires ERR, so last-wins is a no-op there. So the motivating example is real, on exactly the platform where it bites.
  • Both new tests are non-vacuous, mutation-checked both ways: remove the _TB_IN_RECORD_ERR early-return and a re-entrant call keeps the first record goes red (the log-write-survives test stays green, matching your note that bash re-enters at most once); restore a first-wins latch and last failure wins + a benign probe does not mask the fatal command both go red. Guard is genuinely exercised. Bugbot finding addressed.
  • Manifest hash matches the file; full common.bats is 82/82 green locally on 3.2.

One loose end: install-k8s.sh:101 still reads Record the site of the first failing command — same subsystem, and this PR makes it false. It's outside the diff so I can't inline it, but worth flipping first -> last here so the trap's own docstring doesn't contradict the record it now keeps.

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

Approving — with one fix pushed to your branch (4e8dcbd), because the Bugbot finding was real and its suggested remedy was not sufficient.

The PR itself is good. Last-wins is the right call and the reasoning is airtight: _probe_privilege reading a non-zero sudo -n true as "a password is needed" is a routine, expected failure, and first-wins latched onto exactly that — reporting the location of a probe inside a step that succeeded. A wrong answer stated confidently is worse than the blank screen it replaced. Disarming the trap before install_cleanup runs its own routinely-failing lines is the necessary companion, and it's tested.

On the Bugbot finding — confirmed, measured:

bash 5.3.15 command false || true -> ERR fired = 0
bash 3.2.57 command false || true -> ERR fired = 1

A command in a || list is excluded from ERR per the bash manual. So on Linux CI the recursion test fired the trap zero times, _record_err never ran, and SURVIVED printed whether the guard existed or not. It passed on macOS because 3.2 fires it — a test that was green locally and vacuous on the platform that counts.

unset LOG_FILE was inert for a second reason: log() is [[ -n "${LOG_FILE:-}" ]] && echo … ; return 0, so with no log open the write never attempts.

Where I went past the suggested fix. I built exactly what Bugbot proposed — unwritable LOG_FILE plus a bare failing command in a function — and it still doesn't detect a missing guard:

guard removed: ok 25 _record_err: survives its own log write failing
not ok 26 _record_err: a re-entrant call keeps the first record

bash re-enters an ERR trap at most once (measured on 5.3: a failing handler reaches depth 2 and stops). There is no infinite recursion, so any test waiting on a hang passes with _TB_IN_RECORD_ERR deleted — and the timeout 10 scaffolding is guarding against something that cannot happen.

What the guard actually buys is that the nested entry can't overwrite TB_ERR_* with the recorder's own log failure — turning "died at helm upgrade" into "died writing its log", which is the exact confidently-wrong failure mode this whole PR exists to eliminate. So the guard defends the PR's own thesis, and now there's a test that says so.

Pushed:

  • the trap driven by a bare failing command in a function with errexit relaxed, so ERR genuinely fires;
  • LOG_FILE pointed at a path whose parent doesn't exist — the redirection then fails for every user including root (a chmod 000 file wouldn't stop root in a container);
  • a new test pinning the re-entrancy property, mutation-verified red with the guard removed.

CI green on the new head, bats (bash unit, mocked): SUCCESS, hygiene 18/18. Thread replied and resolved.

LGTM.

@LukasWodka
LukasWodka merged commit 95a96a2 into developAug 13, 2026
47 checks passed
@LukasWodka
LukasWodka deleted the fix/691-err-recorder-last-wins branch August 13, 2026 14:21
Sign up for freeto 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.

3 participants

@LukasWodka@saadqbal@shujaatTracebloc