fix(tests): widen _wait_pidfile's window and name what it saw (#595)

[fujibee]

Declared reviewers: 1

Refs #595, #758.

Landing on integration/remote. Head cfc642428c6ce1111f087fa9698343e396ed5b18.

This PR does not fix the failing assertion. It was opened as a candidate fix, CI refuted that, and what it is now is the instrument that produced the first real information about the failure in three days. Read the next two sections before the rest.

The window hypothesis is dead, and this PR is what killed it

Commit 1 is #758's fix, ported here: _wait_pidfile's poll window widened from ~3s to ~10s.

It ran on an idle queue — every other run was frozen, so this was the only thing on CI — and bats (ubuntu-latest 4/4) failed anyway, on the same assertion, in 7m27s:

not ok 265 watch: relaunch with the SAME instance id replaces the previous watcher (#66 preserved)
#   `_wait_pidfile "$pf" "$w2"' failed
# _wait_pidfile: timed out waiting for '/tmp/…/run/watch.solo.168226.pid' to record pid 168580 (last saw: '<missing>')

So: not the window, and the "loaded runner" account is weaker too, since this was the least-loaded state all night. Every other check on that run was green (14 success, 1 failure) and the shard's only failure was this one line.

Reading it the other way — that a widened window proves the machine was not slow — would be reading more than the log carries, and the same log is why (below).

The number is #595, not #769

Both issues are about the same test, and they are different assertions:

tests/test_watch.bats:495   _wait_pidfile "$pf" "$w2"        the successor's pid never appears
tests/test_watch.bats:501   run kill -0 "$w1"; [ $status -ne 0 ]   the predecessor is still alive

#769 is :501 — its body quotes that line. #595 is :495, and names the assertion outright: "failing at _wait_pidfile "$pf" "$w2"". What fails on CI tonight is :495. An earlier version of this body cited #769 for a property measured about the other assertion; it does not, and the reference is removed.

What the failure now says, and what it still does not

last saw: '<missing>' is the last poll only. It cannot tell "the file never appeared" from "it appeared and then went away", because each poll overwrites the previous value — raised in review, and correct. What the log supports is exactly this:

at the timeout, the expected pid had not been observed within ~10s, and the file was not readable at that moment.

Commit 2 closes that gap. Every distinct value is kept with the poll it first appeared at, and the timeout also reports whether the wanted pid is still alive — which separates a successor that died before writing from a successor that is running while something else removes its record:

(a) never arrived, wanted pid dead    poll1='<missing>'                            GONE
(b) arrived as another pid            poll1='9999'                                 ALIVE
(c) appeared, then removed            poll1='9999' poll11='4242' poll20='<missing>'  ALIVE

(c) is the case last saw could not express, and it is the one that would point at ownership rather than timing.

All three were forced locally and printed — including the wanted-pid liveness line in both directions. A first draft got (a) wrong: last was seeded with "", so a file missing from the very first poll produced an empty trail — the one case that matters most, silently dropped. It is seeded with a value no read can produce now, and (a) prints.

The directory listing is dumped too, so "the file is gone" can be told from "something else is in there".

Commit 2 is beyond #758

Commit 1 is byte-identical to #758's added lines — verified with diff, not by reading:

gh pr diff 758 | grep '^+' | grep -v '^+++' | sed 's/^+//'  >  a
git diff       | grep '^+' | grep -v '^+++' | sed 's/^+//'  >  b
diff a b   →   no output

Commit 2 is not in #758. It answers the same ask #595 made — a failure message that distinguishes what happened — with what the CI run showed to be necessary. If #758 lands on main later, commit 1 is the same change from the other direction and commit 2 is additive.

Why land a change that fixes nothing

Because the next occurrence answers the question instead of restating it. Tonight's log could not distinguish three causes; the next one can. Against that:

• scripts/ is untouched. Nothing here can change what any shipped code does.
• The window going 3s → 10s costs ~7s only on a test that is already failing. A passing run returns on the first matching poll, as before.
• It does not make the red go away, and this body does not claim it does.

Measurements, at this head

bats tests/test_watch.bats                     19 tests, 0 failures
.github/scripts/check-enforced-assertions.sh   638, at the baseline (638)

That green proves only that nothing regressed. The assertion under investigation passes locally on this machine every time — #769 records the same thing for its own assertion — so a local pass is what both hypotheses predict and it discriminates nothing. The CI run is the evidence.

No mutation table: this changes a test helper's timing and its diagnostics, not a behaviour. There is no property to break. The forced (a)/(b)/(c) cases above are what stands in for one — each print was made to appear rather than assumed.

Drift

From the repo root, immediately before the push, against origin/integration/remote:

HEAD                       cfc642428c6ce1111f087fa9698343e396ed5b18
merge-base                 d0b762d47747682e5a466cc1ad0df903c2712ac1
origin/integration/remote  d0b762d47747682e5a466cc1ad0df903c2712ac1
RESULT: STRUCTURAL, NOT MEASURED — merge-base == destination.

Re-measured immediately before landing.

Boundaries

• fix(tests): widen _wait_pidfile's window and name what it saw (#595) #758 observed this on macos-latest 4/4; tonight's runs are ubuntu-latest 4/4. Same helper, same assertion, different shard and OS.
• The cause is not established here. Three candidates remain open, and this PR's only claim about them is that the next failure will name which.
• A verdict on aa8077e3 was given before commit 2 existed and does not carry to this head.