row 292 (#1797) gate results on 0d0021454: r2 old-test red compactions-launch:229 (exit-22 race, Vikunja 588), mos-1411 diagnostic 0/10 with one not-holder exit 22 seen in the clear test, r3 cli rerun 910/910, ten shells green, M1-M9 killed; rebase receipts (sage-3183, sage-3185, sage-3193)

2026-10-23 00:18:02 -05:00
1 parent e5ffa76932
commit 6aab979e6c
@@ -0,0 +1,60 @@
+# Row 292 gate r2: the old-test red (read-only notes, no node)
+
+Untracked until the results commit, so the round 1 digest 2fa7ae17 stays (sage-3185). Written for sage-3188.
+
+## The red
+
+Gate r2 on 0d0021454, cli suite stage, 04:54:03Z 10-23: 910 tests, 909 pass, 1 fail.
+compactions-launch.test.mjs:206, row 270's store-unreadable test, fails at :229
+`deepEqual(ends[0], ends[1])`. The first run ended `['session-invalid', 22, null]`, and the second
+ended `['stopped', 0, null]`. Every assertion before :229 passed. Log: gizmo-292-out/r2/suite/cli.log:1023-1045.
+
+## Where exit 22 comes from (read from the code, not run)
+
+- packages/harness/src/runner.mjs:43 `EXIT.session` is 22. :55 `SESSION_GONE` is unauthenticated,
+  not-holder and run-ended. The runner exits 22 when a broker call gets one of those:
+  message.receive at :529, state at :550, the reply at :580, and the landing state at :505.
+- packages/seat/src/session.mjs:340 maps 22 to "session-invalid" for the end event.
+- The test's runs end by idle. The fixture sets `launch.threadIdleSeconds = 1`
+  (compactions-launch.test.mjs:72).
+- The idle stop is in packages/cli/src/launcher.mjs:703-717. It calls the broker op `threadIdle`
+  first. packages/bus/src/broker.mjs:1044-1058 releases the claim in that call (`#claimEnd(...,
+  'release')` at :1055). After the op returns, the launcher records `thread-idle` and only then sends
+  SIGTERM (:716). The order is deliberate. Row 121 round 2, Dewey's F3 (broker.mjs:1040-1043), wants
+  a message sent after the snapshot to wait for the next holder.
+- The window: the claim is already released, but the runner's SIGTERM handler hasn't set
+  `stopping` yet. A message.receive poll that the broker answers in that window gets `not-holder`.
+  Polls come every `pollInterval`, which defaults to 2000 ms (runner.mjs:57). The catch at
+  :526-531 sets `code = EXIT.session` without looking at `stopping`. A call already in flight when
+  the release lands ends the same way, even if SIGTERM arrives before its answer. Either way the run
+  ends session-invalid/22 instead of stopped/0.
+
+## Reading
+
+This is a race in the product's idle stop (launcher, broker and runner ordering), not in row 292,
+and not in row 270's collection code. Row 270's test exposes it because :229 asserts that both runs'
+ends are equal, which in practice means both are idle stops ending `stopped`. Row 292's diff
+(stack-release.sh, stack-release.test.mjs, TOOLS.md, packets) doesn't reach any of these files.
+
+I haven't confirmed this. The 10-run diagnostic Sage proposed to Mos (sage-3186) measures how
+often it happens. Two fixes are possible if it reproduces, and both go to a separate row, as Sage
+ruled:
+- Product: in the runner, treat `not-holder` as stopped when it comes after a SIGTERM. That doesn't
+  close the window where the poll lands before SIGTERM, so a cleaner fix is for the launcher to
+  record that it is the one stopping the run, and map the end to stopped.
+- Test: compare only the reason classes the test cares about at :229. That loosens an assertion,
+  which needs Mos under mos-1272.
+
+## Mos's ruling and the diagnostic (mos-1411, sage-3190, CLEAR sage-3193)
+
+Mos ruled that :229 stays as written and that the race gets its own row (owner Gizmoduck, reviewer Dewey,
+Vikunja 588). 292's gate counts after one whole, unedited cli suite rerun, provided that rerun is green.
+
+Diagnostic, 05:01:01Z to 05:03:31Z 10-23, on 0d0021454: compactions-launch.test.mjs whole and unedited,
+10 isolated runs, each with its own TMPDIR. All ten exited rc=0 with 5/5 pass and no red, so `ends[0]`
+was stopped/0 every time. A side loop copied each runner.log every 100 ms before the test removed its
+root. 72 logs end `runner: exiting 0`. 27 were deleted before their last line was copied. One ends
+`runner: session stopped working: not-holder` and then `runner: exiting 22`: run 2, launch
+r846b8d083502, in the clear test (:305). That test doesn't compare ends, so it passed anyway. So the
+race happens, roughly once in a hundred idle stops, and the code is `not-holder`, which matches the
+reading above. Output: gizmo-292-out/diag.out and diag/run2/logs/r846b8d083502/runner.log.
@@ -0,0 +1,75 @@
+# Row 292 (#1797) gate results
+
+Tested head: 0d002145453adc6a47ecf0b8125ab3ee612c1a19 (sage-3185). That's 3fd8f42f6 rebased onto
+c902a767d. It's on gizmoduck/row292-r2. The round 1 manifest digest is still 2fa7ae17 (13 paths). This
+file and RED-r2.md came after the gate and sit outside the manifest.
+
+## Rebase receipts (sage-3183 item 1)
+
+`git range-diff -s b23783f39..3fd8f42f6 c902a767d..0d0021454` shows all six commits as `=`:
+
+```
+1:  3b17c7550 = 1:  89e58f4b1
+2:  a54baff21 = 2:  9f15216f7
+3:  9c6e39b25 = 3:  61fdb6a8d
+4:  4fa7d6834 = 4:  b48e415e4
+5:  f8b9c2f73 = 5:  2db30c687
+6:  3fd8f42f6 = 6:  0d0021454
+```
+
+Stable patch-ids are unchanged: 15f1a38e, 8e9b78ac (e7371025f), fc50b630 (d4c796e44), b5a6c8e8,
+d918d3cd, 9e2b2c2b. Every one of the 13 manifest blobs on 0d0021454 matches the manifest.
+
+## Gate r2 (04:33Z to 04:54Z 10-23, CLEAR sage-3183)
+
+- stack-release.test.mjs whole: rc=0, 224/224, wall 608 s.
+- cli suite whole: rc=1, 910 tests, 909 pass, 1 fail. The failure is in an old test,
+  compactions-launch.test.mjs:206 (row 270's store-unreadable test), at :229
+  `deepEqual(ends[0], ends[1])`. ends[0] was `['session-invalid', 22, null]` and ends[1] was
+  `['stopped', 0, null]`. Under mos-1272 the run stopped with the red unplaced. RED-r2.md has the
+  reading: the idle stop releases the claim before it sends SIGTERM, so a poll in between gets
+  `not-holder` and exits 22. Mos ruled in mos-1411 that :229 stays as written and the race gets its own
+  row, Vikunja 588.
+
+## Diagnostic (mos-1411, CLEAR sage-3193)
+
+05:01:01Z to 05:03:31Z: compactions-launch.test.mjs, whole and unedited, run 10 times, each with its own
+TMPDIR. All ten passed with rc=0 and 5/5, so ends[0] was stopped/0 every time. In the runner.logs, 72
+end in exit 0, 27 were deleted before the copy loop reached their last line, and one ended
+`session stopped working: not-holder` then `exiting 22`. That one was run 2's launch r846b8d083502, in
+the clear test (:305), which doesn't compare ends. So the race happens and the code is `not-holder`.
+
+## Gate r3 (05:03:50Z to 05:16:32Z, run-gate-r3.sh)
+
+- Stage 1 didn't rerun because it was green in r2.
+- cli suite whole and unedited: rc=0, 910/910, 0 skipped, wall 630 s. Under mos-1411, this green rerun
+  is what makes 292's gate count.
+- The ten scripts/test-*.sh all passed with rc=0:
+
+  | Suite | Result |
+  | --- | --- |
+  | auth | 15/0 |
+  | conductor | 17/0 |
+  | config | 55/0 |
+  | discord | 81/0 |
+  | extension-package | 18/0 |
+  | foundation | 44/0 |
+  | land-work | 86/0 |
+  | queue | node 156/156, suite 28/0 |
+  | release | 14/0 |
+  | task | 91/0 |
+
+  The tree was clean afterwards.
+- There were two skips, both the usual ones. test-queue skipped verify/render --check because this
+  checkout isn't the canonical root. test-task skipped the live provider cases (row 244). No Docker group
+  was skipped.
+- All of M1-M9 were killed by the rule: each had fail 1 on the named test, every listed stack line and
+  the kill text. Each restore checked sha256 8f535d53 and found the tree clean. No survivors.
+- When it finished, no node process had its cwd in the worktree.
+
+Logs are in /mnt/storage/scratch/gizmo-292-out: r2.out, r2/, diag.out, diag/, r3.out and r3/.
+
+## For the landing note (mos-1411)
+
+The first red was compactions-launch.test.mjs:229 in gate r2, with ends[0]
+`['session-invalid', 22, null]`. The race is Vikunja 588. The gate counts on the green r3 cli rerun.