Files

4.1 KiB

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.