test_install.sh: two tests budget wall-clock time across process startup, so the pre-commit gate fails at random under load

[ghostpsalm]

Found while landing the pre-commit gate (22fd98c, 1da0b27). The gate now runs ./scripts/gate.sh before every commit and every merge, so a test that fails at random no longer costs one re-run — it refuses the commit.

Two tests budget wall-clock time across process startup. Both are correct about what they assert; both measure it in a way that a loaded box can break.

Where

1. test_install.sh:7256 — test_xprobe_wrapper_short_circuits_a_display_already_known_dead

start=$SECONDS
run_xprobe "$d" ":1025"                      # second must be instant
elapsed=$((SECONDS - start))
[ "$elapsed" -le 1 ] || fail "a known-dead display cost ${elapsed}s again ..."

$SECONDS is a whole number of seconds since the shell started, so elapsed counts boundaries crossed, not time spent. A cache hit that genuinely costs ~50 ms reports 1 when it straddles one boundary and 2 when the shell is slow enough to straddle two. run_xprobe spawns a subshell and the wrapper script, so under load that is reachable.

Observed 2026-09-06, in a gate run at commit time:

FAIL: a known-dead display cost 2s again — SC re-probes every few seconds, so this must be free
FAILED: test_xprobe_wrapper_short_circuits_a_display_already_known_dead

Passed on the immediately following run of the same tree, unchanged.

2. test_install.sh:6920 — test_wait_for_user_bus_reports_an_unrunnable_python3_instead_of_a_timeout

run_wait_bus_on_path (test_install.sh:6860) measures in milliseconds, correctly, with date +%s%3N — but the window it measures is not the call under test:

start="$(date +%s%3N)"
BUS_ERR="$(... timeout "$6" env PATH="$1" "$1/bash" -c \
             'set -uo pipefail; hash -r; . "$1"; wait_for_user_bus "$2" "$3"' ...)"
end="$(date +%s%3N)"

assert_bus_probe_unrunnable (test_install.sh:6876) then asserts BUS_MS -lt 1000. That 1000 ms has to cover timeout, env, a fresh bash, hash -r, and sourcing the whole of install-lib.sh — and the test has just started a background python3 to bind the fixture socket. wait_for_user_bus can return instantly and still blow the budget.

Observed once on 2026-09-06, then green on four consecutive full runs of the same tree.

Why it matters

Neither is a product defect: the xprobe cache does short-circuit, and wait_for_user_bus does refuse an unrunnable probe at once. Both are the harness mis-measuring.

The cost has changed, though. Before the pre-commit hook, a flaky suite cost a re-run. Now it blocks a commit, and the obvious way out is --no-verify — which records an ungated commit. A gate people learn to skip is worse than no gate.

Suggested fix

Not "raise the number" in either case. A looser second count still measures boundaries, and a looser millisecond budget stops distinguishing "returned at once" from "waited a bit".

1. xprobe: measure in milliseconds, the way the bus helpers already do (date +%s%3N), and assert against a budget that means "free" — a few hundred ms — rather than <= 1 whole seconds. The first (uncached) probe in the same test already pays a real 1 s timeout, so the two are easy to tell apart on a millisecond clock.
2. bus probe: measure only what is under test, or assert the property rather than the duration. What the test actually needs to know is that the wait did not serve its timeout: it is invoked with timeout_arg=2 and a 6 s watchdog, so "finished well inside 2 s" is the real contract, and the current BUS_RC -ne 124 check already covers the watchdog case. Either subtract a measured baseline (one no-op bash -c through the same fixture PATH) or raise the budget to a fraction of timeout_arg and say in the comment that the window includes interpreter startup.

Both live in test_install.sh and neither touches product code.

Confidence: Confirmed — each failure was observed directly, and each tree passed unchanged on the next run. Severity: low blast radius, high nuisance, now that the gate is what decides whether a commit happens.