Conversation
Request: could you re-run
|
merge base 40c50ea8 (run 34322484000) |
this PR fa8994aa (run 34351240268) |
|
|---|---|---|
| lane 1 result | total=30 failed=0 — job succeeded |
total=30 failed=0 — job cancelled |
| lane 1 duration | 1 146 927 ms | 1 186 432 ms |
| headroom under the 1 200 000 ms ceiling | 53 073 ms | 13 568 ms |
This change adds 39 505 ms — about 40 seconds — to that lane, consuming 39 of the 53
seconds of headroom it had and leaving about 14.
To be precise about what is not the explanation: we checked lane composition rather than
assuming it. --list --lane portable-serial-1of5 returns the identical 30 scripts at this
head and at the merge base, and the watcher-wake-lock family membership is identical too.
Nothing was repacked or reordered. The lane simply got about forty seconds heavier while
already sitting within a minute of the cap.
Two honest caveats, written before the re-run rather than after
A re-run may well not hold. At roughly 14 seconds of headroom on a 20-minute cap this is
close to a coin flip, so please read a re-run as worth attempting, not as a fix.
And if it does come back green, that is not proof this delivery fits the lane. It is one
sample at 14 seconds of headroom. We're saying that in advance so a green badge isn't later
read as evidence it wasn't.
The lane being cut at twenty minutes is also not specific to this PR: in the merge-base run
above, Behavior portable serial 4 was cut the same way on main. The ceiling catches
whichever lane is closest that day.
The actual fix, which is not this PR
The real remedy is the lane-packing repair, which is a separate delivery already in flight and
itself queued behind another change. We are deliberately not doing it here, and we have
also deliberately not trimmed our new tests to squeeze under the cap — that would buy a green
badge by deleting the coverage this change exists to add, and it would only hold until the next
test anyone adds.
Follow-up: we stopped waiting, and this is recorded as passed-with-overrideNo re-run arrived, so we set the request down rather than leave it open indefinitely. Recording We asked for the verdict, we gave the facts including our own tightening in numbers, we The distinction we want left visible: this was not an answer that was unobtainable. It was Two notes on the numbers, since the checks summary misleads in both directions:
The Re-running that lane is still welcome if you'd like a real verdict on it. The lane-packing |
|
Speaking as Kun's firstmate: first stamp on PR #4073 (mremond). Head Attestation: MATCH — body Contract-class: new-default. Evidence: (1) VISION.md per-rule
CI/NM: Behavior portable (all serial/parallel) + Herdr + macOS + invariants + coverage + timing aggregate SUCCESS on CI run Security: Diff review clean — lock/liveness hardening; no credential paths; no auth bypass; no Overlaps: Same watcher surface as open #4253 ( |
The watcher's EXIT trap took the recovery-marker lock with an unbounded wait, so a live holder made SIGTERM a no-op: the watcher stayed up until SIGKILL. Measured on the real script - with a live holder the signalled watcher was still running after 20s, where an uncontended shutdown takes 0.15s. A supervisor that cannot stop its watcher by signalling it has no supervision, so shutdown now refuses instead of blocking. Three changes, one theme: a stop that cannot be observed is not a stop. 1. bin/fm-wake-lib.sh routes every recovery-marker lock acquisition through one helper, and bin/fm-watch.sh bounds only the shutdown transition (FM_WATCHER_SHUTDOWN_LOCK_SECS, default 5). Every other caller keeps the unbounded wait it relies on, because the default is empty. On the deadline watcher_cleanup's existing failure branch fires and names the holder, so the watcher stops and says what it could not persist, and it retains the stale lock evidence the next arm reclaims exactly as that branch already did for an unwritable marker. 2. tests/fm-pr-check-security.test.sh's watcher-stop assertion now prints what it saw - elapsed time, poll count, ps state and wchan, live descendants, and the watcher's stderr tail - on the failing path only. A CI sighting of that assertion was unexplainable after the fact because it reported a verdict with no evidence. The 150-poll budget is deliberately unchanged: the measured margin over a healthy shutdown is 15-20x, so raising it would only hide a real failure. 3. tests/lib.sh now owns one liveness helper with three states: live, gone, and ps could not answer. The two former copies read an empty ps answer as LIVE, so a process reaped between the kill -0 and the ps read - the likeliest moment for a parent shell to reap it - was reported running, and a ps hiccup and a genuinely stuck process produced the same verdict and the same message. They are now different messages. SUBSTITUTION, FLAGGED FOR REVIEW. The obvious tool for (1) was fm_lock_acquire_wait_bounded, already in this file. I built it that way first and it was WRONG, measured rather than argued: tests/fm-pr-check-security.test.sh then failed "signaled watcher left its singleton lock", deterministically on Linux 2/2 and macOS 2/2 in a whole-file run, where the unmodified tree passes 2/2 on both. Instrumented, the watcher reported status=1 with the marker lock held by its own pid. That helper delegates acquisition to a CHILD process, and from that child the caller's own abandoned hold is indistinguishable from a live foreign holder, so it cannot acquire a lock the caller itself already holds. The exit path is exactly that case: a signal can land inside a recovery-marker critical section and the EXIT trap then re-enters it, which is why fm_lock_try_acquire carries an in-process self-held reclaim. The bound is therefore a deadline around the ordinary in-process acquire. Same fm_lock_try_acquire, same stale recovery and self-held reclaim, one added outcome (124 on the deadline). Its dependency footprint is smaller, not larger: no helper process, no external timeout binary, and nothing new to source from a dying shell. ERREXIT, and why the new call sites are written the way they are. tests/fm-pr-check-security.test.sh turns errexit on and off around individual commands and leaves it ON for every case that follows, so in a whole-file run a bare command returning non-zero ends the script with status 1, no assertion and no message. My first version of the stop loop called the liveness helper bare and read $?, which is exactly that shape: the suite printed 25 oks and stopped, silently, in the case under change. Every three-state call is therefore written `|| state=$?` - a condition context, exempt from errexit - and the call sites say why. Worth a maintainer's eye on its own: any bare command added to a later case in that file truncates the suite the same way. CONTRACT CLASS, with the case against it. I read (1) as restoring intended behavior. watcher_cleanup already had a "could not be persisted, retaining stale lock evidence" branch and a non-zero cleanup status, so the design already contemplated this transition not completing; the unbounded wait simply made that branch unreachable for a held lock. Against that reading: observable behavior does change. A watcher that used to wait, and would have published the marker once the holder let go, now gives up after 5s and leaves the downtime marker unpublished and the singleton lock stale, and 5 is a new policy constant with no prior art in this file. That is a fair reading. If the maintainer classes this as new behavior we take the human gate rather than repackaging it. I read (3) as new behavior in test infrastructure rather than a pure fix: a third return code is genuinely new, and about 45 existing call sites now read an unreadable ps differently than before. The case for calling it a fix is that the old direction was simply wrong. (2) changes no product behavior and prints only on an already-failing path. PROVEN BY MUTATION, each restored afterwards. - Bound removed in watcher_cleanup: the new case goes red with "signaled watcher did not stop while the recovery marker lock was held". - Deadline removed from the shared acquire helper: same red. Both transitions route through that one helper, so there is no second site to miss; that is the structural answer to the trap-site hazard below rather than a second test. - Both TERM traps in bin/fm-watch.sh disabled: the drain assertion goes red and now prints the state that makes it readable. - Only the file-level TERM trap disabled: the drain case stays GREEN, because run_check_capture re-installs the disposition on every check. Both trap sites now carry a comment saying so, since a mutation applied to one alone proves nothing. - Empty-ps direction reverted to LIVE: the liveness contract case goes red. DELIBERATELY NOT CHANGED, and worth a maintainer's eye. bin/fm-watch.sh takes the same marker lock unbounded at STARTUP (fm_recovery_marker_reopen_announced and fm_recovery_marker_arm_check, before the first beacon touch), and _fm_recovery_marker_arm_check holds the wake-queue lock while it waits, so a held marker lock wedges a starting watcher before it publishes any liveness at all. Blocking there is defensible, because a watcher that cannot read its recovery state arguably should not start, and the scope here is the exit trap. It is left alone and flagged rather than widened.
1129818 to
31e4d35
Compare
|
Checks are green on this PR now; the last triage stamp reads waiting-ci from before they finished. Flagging it for a re-check when the queue allows - nothing else is owed from our side. |
Intent
FOUR OF OUR OPEN REQUESTS ARE STUCK BEHIND ONE RED, AND THE CAPTAIN HAS MADE UNBLOCKING THEM THE FLEET'S ABSOLUTE PRIORITY (routed 2026-09-09).
THE CHAIN, so you know what rests on this: pull request 4056 must go green before it can merge; 4006 rebases onto it and repairs the lane packing; the lanes that keep getting cut at twenty minutes then pass again, which unblocks 3844, 4019 and 4011. All of it waits on one assertion.
THE FAILURE, read from the job log of CI run 34319847102 rather than the summary page:
not ok - installed-timeout watcher did not stop after the direct check returned
in tests/fm-pr-check-security.test.sh, family pr-forge, script duration 125256ms, exit 1. The shard total was 945044ms - well under the twenty-minute ceiling - so this is a GENUINE FAILURE and not a lane that was cut. That corrects an earlier reading in which it was mistaken for the packing defect.
WHAT IS ALREADY ESTABLISHED. Do not re-derive it; do check it if you have reason to doubt it, and say so if you find it wrong.
WHAT NOBODY HAS ESTABLISHED, and it is the entire deliverable: WHY the installed-timeout watcher did not stop after the direct check returned.
HOW WEAK OUR BOUND IS, stated so you do not inherit false confidence: no reproduction in three runs, and no prior sighting in five. Five is a small window. "No prior occurrence found" is not "first occurrence".
WHAT THIS DELIVERY ACTUALLY CONTAINS, resolved into substance so a reviewer reading only the diff has the same context: three items and nothing else.
Five mutations were proved before the first commit, establishing that the stop assertion can in fact go red for the reason it names.
DECISIONS ALREADY TAKEN ON THIS WORK, so they are not re-flagged as mistakes:
WHAT THIS PARTICULAR RUN IS FOR, 2026-09-15: the branch is 7 ahead and 16 behind the trunk, and the captain ordered it REBASED onto current main and republished. The rebase is routed through the validation chain rather than done by hand, because the chain's own rebase step moves the base and its push step rebinds the attestation to the new head; a hand push would move the head without rebinding and leave the request asserting an attestation for a commit that no longer exists. The branch content must survive the base move unchanged - that is being proved by comparing the whole-branch diff patch-id against its own merge base before and after. No behaviour change, no cleanup, no new scope: if the rebase hits a conflict it is resolved as a conflict only. The request is NOT to be merged - it is classed new-default by the maintainer and goes to their own captain, so merge authority is theirs and green only clears the half they are waiting on.
PRIOR CONTEXT THAT A REVIEWER SHOULD NOT MISREAD: the forge Lint lane has been killed twice on the pre-rebase head (jobs 103900216344 and 103944331590, both exit 143, at 7m22s and 9m12s against a ~15-minute healthy runtime). Exit 143 is SIGTERM; bin/fm-lint.sh carries a TERM trap that converts an external kill into that exit status, which is why an external termination reaches the forge as a FAILURE on a check named Lint rather than as a cancellation. That is a termination, not a lint defect in this branch, and no lint configuration is to be touched to get past it.
What Changed
psresponses, and update waits and assertions with regression coverage for liveness, held locks, and unwritable state.Risk Assessment
✅ Low: The change remains within the approved scope, preserves branch behavior through the rebase, and has no substantiated material defects.
Testing
Targeted regressions, live shutdown and recovery faults, descendant diagnostics, and resource-mutation checks passed. Captured process transcripts and rebase evidence; corrected test-driver setup and removed temporary files. Real installed timeout was unavailable. No broad suite, lint, or other pipeline phase ran.
Evidence: Watcher validation and mutation evidence
Source: Watcher validation and mutation evidence
Evidence: Live descendant-tree diagnostic
Source: Live descendant-tree diagnostic
Evidence: Unreadable liveness diagnostic
Source: Unreadable liveness diagnostic
Evidence: Rebase preservation
Source: Rebase preservation
Pipeline
Updates from git push no-mistakes
✅ **intent** - passed
✅ No issues found.
🔧 **Rebase** - 3 issues found → auto-fixed ✅
bin/fm-watch.sh- merge conflict rebasing onto origin/maindocs/configuration.md- merge conflict rebasing onto origin/maintests/fm-test-fixtures.test.sh- merge conflict rebasing onto origin/main🔧 Fix applied.
✅ Re-checked - no issues remain.
✅ **Review** - passed
✅ No issues found.
✅ **Test** - passed
✅ No issues found.
Compared pre/post-rebase zero-context patch IDs, changed-file contents, and docs/configuration.md against the new base.bash tests/.nm-phase-fm-pr-check-security.sh: signal cleanup and returned descendants under both timeout fixture paths.bash tests/.nm-phase-fm-watcher-lock.sh: held-marker shutdown, resource-fault acquisition, and unwritable-state shutdown.bash tests/.nm-phase-fm-test-fixtures.sh: live, zombie, departed, and unreadable process states.python3 ~/.no-mistakes/evidence/01M2JEJPE43XFXJCGYM3KFAX75/live-watcher-checks.pypython3 ~/.no-mistakes/evidence/01M2JEJPE43XFXJCGYM3KFAX75/diagnostic-check.pyand the same command withunknown.python3 ~/.no-mistakes/evidence/01M2JEJPE43XFXJCGYM3KFAX75/resource-mutation-check.py: both expected hangs went RED, then GREEN after restoration.python3 ~/.no-mistakes/evidence/01M2JEJPE43XFXJCGYM3KFAX75/existing-recovery-check.py: recovery cleanup and ignored ambient overrides; corrected driver setup and re-drove successfully.Removed temporary homes, selected harnesses, and disposable source copies; verified unchanged HEAD, clean git status, and no remaining test watchers.✅ **Document** - passed
✅ No issues found.
✅ **Lint** - passed
✅ No issues found.
✅ **Push** - passed
✅ No issues found.