From d78a40399d0ecd7bdc435fabe413c19ef95dc30f Mon Sep 17 00:00:00 2001 From: joliverMI Date: Wed, 19 Aug 2026 13:27:17 -0400 Subject: [PATCH 01/11] fix(watcher): re-evaluate arm coalescing when the fleet lock changes Two independent causes made the arm-readiness suite fail a different assertion almost every run: - ensureArm() in the OpenCode watch plugin reused a still-resolving earlier caller's beginArm() result unconditionally. Every ordinary session.idle produces two callers, so when the fleet lock was reacquired while an earlier attempt was mid-flight, the later caller inherited that attempt's stale read-only verdict and never armed. Fixed with premise-validated coalescing: a caller shares an in-flight attempt only while the lock file content it captured is still current; otherwise it evaluates fresh. Two callers on an unchanged lock still coalesce into one subprocess walk, so this costs nothing on the ordinary turn a serialized-everything fix would have doubled. - Both adapters spawn their arm child through a login shell, which sources /etc/profile in addition to the account's own profile files; the system-wide half is not relocatable via HOME. main already raised the readiness timeout to absorb that cost (250ms to 2000ms) and its own measurement shows a worst case of ~1740ms under contention against that budget - narrower headroom, not a removed confound. This adds FM_WATCH_ARM_NO_LOGIN_SHELL, a test-only opt-out that spawns the arm child under plain bash -c, removing the confound instead of padding around it. Production keeps the login shell as the unconditional default. Also fixes three unhandled-EPIPE crash sites found while proving this change under load: child.stdin.end() in fm-primary-turnend-guard.js, fm-primary-turnend-guard.ts, and fm-operational-input.js raises an unhandled 'error' event on the stdin stream (not the ChildProcess) when the child exits before the write lands, which was crashing the whole session process. Each site now no-ops that stream error since the child's own close/error handlers already drive resolution. Adds two regression tests (opencode coalescing on an unchanged lock, login-shell default vs. opt-out for both adapters) and one EPIPE regression test, and rewrites the existing OpenCode lock test to force the stale-verdict race deterministically via a gated ps shim instead of waiting for it. See docs/arm-readiness-determinism-proof.md for the repeated-run proof and docs/configuration.md for the new FM_WATCH_ARM_NO_LOGIN_SHELL entry. Built directly on current main (45bd292); does not touch main's own prior timeout raise or its test_pi_session_transition_generation_owner fixture-ordering fix, both kept as-is. --- .opencode/plugins/fm-primary-turnend-guard.js | 6 + .opencode/plugins/fm-primary-watch-arm.js | 40 ++- .opencode/plugins/lib/fm-operational-input.js | 6 + .pi/extensions/fm-primary-pi-watch.ts | 8 +- .pi/extensions/fm-primary-turnend-guard.ts | 6 + docs/arm-readiness-determinism-proof.md | 71 ++++ docs/configuration.md | 1 + docs/documentation-audiences.json | 8 + docs/watcher-continuity.md | 3 +- tests/fm-operational-input.test.sh | 45 +++ tests/fm-pi-watch-extension.test.sh | 338 ++++++++++++++++-- 11 files changed, 500 insertions(+), 32 deletions(-) create mode 100644 docs/arm-readiness-determinism-proof.md diff --git a/.opencode/plugins/fm-primary-turnend-guard.js b/.opencode/plugins/fm-primary-turnend-guard.js index fb8f42eaf43..2de34163724 100644 --- a/.opencode/plugins/fm-primary-turnend-guard.js +++ b/.opencode/plugins/fm-primary-turnend-guard.js @@ -22,6 +22,12 @@ function runProcess(command, args, input = "") { }); child.on("error", () => resolve({ code: 0, stdout: "", stderr: "" })); child.on("close", (code) => resolve({ code: code ?? 0, stdout, stderr })); + // A child that exits before this write lands makes the write fail with + // EPIPE, which node raises on the stdin stream rather than on the child. + // Unhandled, that stream error throws and takes the whole process down. + // The child's own close/error handlers already settle this promise, so a + // child that no longer wants its input needs nothing further here. + child.stdin.on("error", () => {}); child.stdin.end(input); }); } diff --git a/.opencode/plugins/fm-primary-watch-arm.js b/.opencode/plugins/fm-primary-watch-arm.js index e88c248f786..b527d8fab3b 100644 --- a/.opencode/plugins/fm-primary-watch-arm.js +++ b/.opencode/plugins/fm-primary-watch-arm.js @@ -10,6 +10,12 @@ const COORDINATOR_KEY = "__firstmateOpenCodeWatchArm"; const ARM_READY_TIMEOUT_DEFAULT_MS = process.platform === "win32" ? 35000 : 12000; const ARM_READY_TIMEOUT_MS = positiveInteger("FM_OPENCODE_ARM_READY_TIMEOUT_MS", ARM_READY_TIMEOUT_DEFAULT_MS); const ARM_RETIRE_TIMEOUT_MS = positiveInteger("FM_WATCH_ARM_RETIRE_TIMEOUT_MS", 1000); +// The arm child runs under a login shell so it inherits PATH additions the +// account's profile provides (an nvm-managed node, for instance), which +// bin/fm-watch-arm.sh and its descendants may need. FM_WATCH_ARM_NO_LOGIN_SHELL=1 +// drops to a plain shell for tests that must not pay an unbounded, machine- +// dependent profile-sourcing cost inside a readiness window. +const ARM_SHELL_FLAG = process.env.FM_WATCH_ARM_NO_LOGIN_SHELL === "1" ? "-c" : "-lc"; const REARM_RETRY_BASE_MS = positiveInteger("FM_WATCH_REARM_RETRY_BASE_MS", 250); const REARM_RETRY_MAX_MS = positiveInteger("FM_WATCH_REARM_RETRY_MAX_MS", 4000); const REARM_RETRY_LIMIT = positiveInteger("FM_WATCH_REARM_RETRY_LIMIT", 5); @@ -19,6 +25,7 @@ let armStatus = "idle"; let retryTimer = null; let retryFailures = 0; let launchInFlight = null; +let launchInFlightLock = null; let restorationInFlight = null; let armClose = new WeakMap(); let armReadiness = new WeakMap(); @@ -302,7 +309,7 @@ function spawnArm(paths, sessionID, client, predecessorArmPid = "") { FM_CONFIG_OVERRIDE: paths.config, FM_WATCH_PREDECESSOR_ARM_PID: predecessorArmPid, }; - const armChild = spawn("bash", ["-lc", 'config_dir="${FM_CONFIG_OVERRIDE:-$FM_HOME/config}"; [ -f "$config_dir/x-mode.env" ] && . "$config_dir/x-mode.env"; exec "$FM_ROOT_OVERRIDE/bin/fm-watch-arm.sh" --restart'], { + const armChild = spawn("bash", [ARM_SHELL_FLAG, 'config_dir="${FM_CONFIG_OVERRIDE:-$FM_HOME/config}"; [ -f "$config_dir/x-mode.env" ] && . "$config_dir/x-mode.env"; exec "$FM_ROOT_OVERRIDE/bin/fm-watch-arm.sh" --restart'], { cwd: paths.root, env, stdio: ["ignore", "pipe", "pipe"], @@ -409,18 +416,41 @@ function armAttempt(status, armChild, includeArmChild) { return includeArmChild ? { status, armChild } : status; } +function lockSnapshot(paths) { + try { + return readFileSync(`${paths.state}/.lock`, "utf8"); + } catch { + return null; + } +} + async function ensureArm(paths, sessionID, client, predecessorArmPid = "", includeArmChild = false) { + // Every ordinary idle turn produces two callers (this plugin's own + // session.idle handler and the turn-end guard's coordinator call), so they + // share one in-flight beginArm rather than each paying its own git/ps + // subprocess walk. That share is only sound while the premise the in-flight + // attempt is evaluating still holds: an attempt that read a foreign lock is + // computing a "read-only" verdict, and a caller arriving after the lock was + // reacquired underneath it must not inherit that answer. Comparing the lock + // file's content at call time against what the in-flight attempt captured + // keeps the common case coalesced and forces a fresh evaluation exactly when + // the state it depends on changed. + const currentLock = lockSnapshot(paths); let launchResult = null; - if (!launchInFlight) { + if (launchInFlight && launchInFlightLock === currentLock) { + launchResult = await launchInFlight; + } else { const launch = beginArm(paths, sessionID, client, predecessorArmPid); launchInFlight = launch; + launchInFlightLock = currentLock; try { launchResult = await launch; } finally { - if (launchInFlight === launch) launchInFlight = null; + if (launchInFlight === launch) { + launchInFlight = null; + launchInFlightLock = null; + } } - } else { - launchResult = await launchInFlight; } const armChild = launchResult.armChild; if (!armChild) { diff --git a/.opencode/plugins/lib/fm-operational-input.js b/.opencode/plugins/lib/fm-operational-input.js index f0d05c14448..8ba1c6bc6c4 100644 --- a/.opencode/plugins/lib/fm-operational-input.js +++ b/.opencode/plugins/lib/fm-operational-input.js @@ -32,6 +32,12 @@ export function encodeFirstmateOperationalInput(root, kind, content) { } reject(new Error(stderr.trim() || `operational-input encoder exited ${code ?? "unknown"}`)); }); + // A child that exits before this write lands makes the write fail with + // EPIPE, which node raises on the stdin stream rather than on the child. + // Unhandled, that stream error throws and takes the whole process down. + // The child's own error/close handlers already settle this promise, so a + // child that no longer wants its input needs nothing further here. + child.stdin.on("error", () => {}); child.stdin.end(content); }); } diff --git a/.pi/extensions/fm-primary-pi-watch.ts b/.pi/extensions/fm-primary-pi-watch.ts index 923ec6c310d..d84e505f081 100644 --- a/.pi/extensions/fm-primary-pi-watch.ts +++ b/.pi/extensions/fm-primary-pi-watch.ts @@ -96,6 +96,12 @@ const armReadyTimeoutMs = positiveInteger( process.platform === "win32" ? 35000 : 12000, ); const armRetireTimeoutMs = positiveInteger("FM_WATCH_ARM_RETIRE_TIMEOUT_MS", 1000); +// The arm child runs under a login shell so it inherits PATH additions the +// account's profile provides (an nvm-managed node, for instance), which +// bin/fm-watch-arm.sh and its descendants may need. FM_WATCH_ARM_NO_LOGIN_SHELL=1 +// drops to a plain shell for tests that must not pay an unbounded, machine- +// dependent profile-sourcing cost inside a readiness window. +const armShellFlag = process.env.FM_WATCH_ARM_NO_LOGIN_SHELL === "1" ? "-c" : "-lc"; const repairOnlyHint = "call fm_watch_arm_pi again only after a later notification says the cycle is missing, failed, or unhealthy"; const shuttingDownMessage = "watcher: not armed - Pi session is shutting down"; @@ -394,7 +400,7 @@ export default function (pi: ExtensionAPI) { FM_WATCH_ARM_SCRIPT: armScript, FM_WATCH_PREDECESSOR_ARM_PID: predecessorArmPid, }; - const armChild = spawn("bash", ["-lc", "config_dir=\"${FM_CONFIG_OVERRIDE:-$FM_HOME/config}\"; [ -f \"$config_dir/x-mode.env\" ] && . \"$config_dir/x-mode.env\"; exec \"$FM_WATCH_ARM_SCRIPT\" --restart"], { + const armChild = spawn("bash", [armShellFlag, "config_dir=\"${FM_CONFIG_OVERRIDE:-$FM_HOME/config}\"; [ -f \"$config_dir/x-mode.env\" ] && . \"$config_dir/x-mode.env\"; exec \"$FM_WATCH_ARM_SCRIPT\" --restart"], { cwd: fmRoot, env, stdio: ["ignore", "pipe", "pipe"], diff --git a/.pi/extensions/fm-primary-turnend-guard.ts b/.pi/extensions/fm-primary-turnend-guard.ts index 1b2a3ec39ae..43736f5a9e9 100644 --- a/.pi/extensions/fm-primary-turnend-guard.ts +++ b/.pi/extensions/fm-primary-turnend-guard.ts @@ -163,6 +163,12 @@ function runGuard(): Promise<{ code: number; stderr: string }> { }); child.on("error", () => resolveResult({ code: 0, stderr: "" })); child.on("close", (code) => resolveResult({ code: code ?? 0, stderr })); + // A child that exits before this write lands makes the write fail with + // EPIPE, which node raises on the stdin stream rather than on the child. + // Unhandled, that stream error throws and takes the whole process down. + // The child's own close/error handlers already settle this promise, so a + // child that no longer wants its input needs nothing further here. + child.stdin.on("error", () => {}); child.stdin.end('{"stop_hook_active":false}'); }); } diff --git a/docs/arm-readiness-determinism-proof.md b/docs/arm-readiness-determinism-proof.md new file mode 100644 index 00000000000..a4f2252d343 --- /dev/null +++ b/docs/arm-readiness-determinism-proof.md @@ -0,0 +1,71 @@ +# Arm-readiness suite determinism proof + +This record is the repeated-run proof for `tests/fm-pi-watch-extension.test.sh`, the suite that verifies the Pi and OpenCode arm-readiness contract owned by [`watcher-continuity.md`](watcher-continuity.md#actionable-wake-ordering). +The suite was red for over a day, failing a different assertion on most runs. +By the time this record was written, `main` already carried its own independent partial mitigation for two of the four assertions (see "Base state" below); the numbers here are from a full run against the tree with this change's fixes applied on top of that base, and supersede any earlier in-branch run figures produced against a different tree. + +## The four originally-failing assertions, and which share a cause + +Two independent causes, two assertions each. + +| Assertion | Cause | +|---|---| +| `OpenCode watch plugin must arm only when this session owns the fleet lock` (both reported occurrences) | A - production race in `ensureArm` | +| `Pi must deliver the actionable wake after bounded hung-successor recovery` | B - test window racing an unrelated cost | +| `Pi must fall back without overlapping an unretired successor` | B - test window racing an unrelated cost | + +**Cause A - production code was genuinely racy.** +`ensureArm` in `.opencode/plugins/fm-primary-watch-arm.js` reused a still-resolving earlier caller's `beginArm()` result unconditionally. +Every ordinary `session.idle` produces two callers - the plugin's own handler and the turn-end guard's `coordinator.ensureArmed` call - so when the fleet lock was reacquired while an earlier attempt was mid-flight, the later caller inherited that attempt's `read-only` verdict and never armed. + +**Cause B - the test measured something it did not intend to.** +Both adapters spawn their arm child through `bash -lc`. +A login shell sources `/etc/profile` and `/etc/profile.d/*` in addition to the account's own profile files, and the system-wide half is not relocatable via `HOME`. +That unbounded, machine-specific, load-dependent cost sat inside the tight readiness/retire windows these two cases assert on, so under contention the arm child was SIGTERMed before the fixture could record itself. + +## Base state (already on `main` before this change) + +`main` independently raised `FM_PI_ARM_READY_TIMEOUT_MS` / `FM_OPENCODE_ARM_READY_TIMEOUT_MS` from 250ms to 2000ms and rewrote `test_pi_session_transition_generation_owner`'s fixture to write its arm-log row before the pid-file row that its waiters gate on, both landed independently of this change. +Neither addresses cause A: `ensureArm` still reused an in-flight attempt's result unconditionally, and its own comment on the timeout raise records a measured worst case of ~1740ms against the new 2000ms budget under contention - narrower headroom, not a removed confound. +This change does not touch either of those base fixes and does not re-litigate the timeout value; both are kept exactly as `main` has them. + +## What this change adds + +- **Premise-validated coalescing** (`.opencode/plugins/fm-primary-watch-arm.js`) - the fix for cause A. + `ensureArm` reads the lock file's content synchronously at call time and shares an in-flight `beginArm()` only while that content still matches what the in-flight attempt captured; otherwise it starts its own evaluation. + Two callers on an unchanged lock still coalesce into one `git`/`ps` walk, so the ordinary idle turn pays no extra subprocess cost. + Serializing the callers instead would fix the same race by removing coalescing, at the price of doubling that subprocess work on every idle turn; `test_opencode_watch_arm_coalesces_callers_on_an_unchanged_lock` pins the cheaper contract. +- **`FM_WATCH_ARM_NO_LOGIN_SHELL` opt-out** (`.opencode/plugins/fm-primary-watch-arm.js`, `.pi/extensions/fm-primary-pi-watch.ts`, documented in [`configuration.md`](configuration.md)) - a further reduction of cause A's residual exposure alongside `main`'s own timeout raise, not a replacement for it. + Set to `1`, the arm child spawns under plain `bash -c`. + The login shell remains the unconditional production default because `bin/fm-watch-arm.sh` and its descendants may only reach `node` through PATH additions a profile makes. + The suite exports the opt-out so its timed windows measure only readiness-detection logic instead of racing an unbounded profile-sourcing cost against however much headroom the timeout leaves. + Relocating `HOME` is not sufficient by itself: it removes only the account half of the cost, and `/etc/profile` is still sourced. +- **Three unhandled-EPIPE guards** (`.opencode/plugins/fm-primary-turnend-guard.js`, `.pi/extensions/fm-primary-turnend-guard.ts`, `.opencode/plugins/lib/fm-operational-input.js`) - unrelated to causes A and B, found while proving this change under load. + A child that exits before the parent's `child.stdin.end(...)` write lands makes that write fail with EPIPE, which node raises on the stdin stream rather than on the `ChildProcess`. + Unhandled, it took down the whole session process. + These are every async `stdin.end` site in the adapters; `.pi/extensions/lib/fm-operational-input.ts` uses `spawnSync` with `input:` and has no async pipe. + `test_adapter_surfaces_encoder_exit_instead_of_killing_the_host` in `tests/fm-operational-input.test.sh` pins the shared encoder path: an encoder that exits before reading a body larger than the pipe buffer must fail that one call and leave the host session alive. + +Two regression tests were added inside the arm-readiness suite itself; the existing lock test was rewritten to prove cause A deterministically rather than by waiting for it. + +| Test | Pins | +|---|---| +| `test_opencode_primary_watch_plugin_requires_session_lock` (rewritten) | Cause A. A `ps` shim blocks the first lock-ownership walk mid-flight, so the stale-verdict race is forced deterministically rather than waited for. Also asserts two distinct lock premises produce two evaluations. Fails against the pre-change `ensureArm` (inherits the stale verdict) and against a rejected fully-serialized variant (deadlocks); passes against the shipped premise-validated coalescing. | +| `test_opencode_watch_arm_coalesces_callers_on_an_unchanged_lock` (new) | The other half of cause A: two callers on an unchanged lock must share exactly one evaluation. Unconditional coalescing (the pre-change behavior) already passes this test; it instead guards against the rejected serialized variant, which fails it with two evaluations. | +| `test_watch_arm_login_shell_default_reaches_the_arm_child` (new) | Both branches of the `FM_WATCH_ARM_NO_LOGIN_SHELL` opt-out, for both adapters, via a temp `HOME` whose `.profile` exports a marker the arm child either does or does not observe. | + +## Verification + +- Date: 2026-08-19 +- Command: `tests/fm-pi-watch-extension.test.sh`, run consecutively +- Code under proof: this branch's commit, built directly on `main` at `45bd292` +- Host: 32 cores +- Assertions per run: 32 + +| Phase | Conditions | Result | +|---|---|---| +| Idle | 1-minute load average 0.66 at phase start | **20/20 passed, 0 failed** | +| Loaded | 160 busy-loop processes on 32 cores (5x oversubscription), load average climbing to 163 | **20/20 passed, 0 failed** | +| Total | | **40/40** | + +No run was short of clean, and no assertion failed in either phase. diff --git a/docs/configuration.md b/docs/configuration.md index c80aec31316..3dab1f7cc30 100644 --- a/docs/configuration.md +++ b/docs/configuration.md @@ -578,6 +578,7 @@ FM_ARM_ATTACH_POLL=0.5 # seconds between checks while fm-watch-arm is attached FM_OPENCODE_ARM_READY_TIMEOUT_MS=12000 # milliseconds the OpenCode primary watcher plugin waits for an arm attempt to report started, healthy, wake, or failure; default 35000 on Windows to stay above the MSYS confirm budget FM_PI_ARM_READY_TIMEOUT_MS=12000 # milliseconds the Pi watcher extension waits for a successor arm to report started or attached; default 35000 on Windows to stay above the MSYS confirm budget FM_WATCH_ARM_RETIRE_TIMEOUT_MS=1000 # milliseconds Pi/OpenCode wait for an unready successor arm to exit before abandoning retries +FM_WATCH_ARM_NO_LOGIN_SHELL=1 # test-only: spawn the Pi/OpenCode arm child under bash -c instead of bash -lc, skipping /etc/profile and the account's profile files; leave unset in production so fm-watch-arm.sh inherits PATH additions a profile provides, such as an nvm-managed node FM_WATCH_REARM_RETRY_BASE_MS=250 # Pi/OpenCode adapter base delay for continuity restoration retries FM_WATCH_REARM_RETRY_MAX_MS=4000 # Pi/OpenCode adapter cap for exponential continuity retry delay FM_WATCH_REARM_RETRY_LIMIT=5 # Pi/OpenCode adapter launch-failure retries before surfacing restoration failure diff --git a/docs/documentation-audiences.json b/docs/documentation-audiences.json index bcc8c5225c3..10742654660 100644 --- a/docs/documentation-audiences.json +++ b/docs/documentation-audiences.json @@ -75,6 +75,10 @@ "source": "docs/watcher-continuity.md", "target": "docs/verification/supervision.md" }, + { + "source": "docs/watcher-continuity.md", + "target": "docs/arm-readiness-determinism-proof.md" + }, { "source": "docs/wedge-alarm.md", "target": "docs/verification/supervision.md" @@ -213,6 +217,10 @@ "path": "docs/agent-control.md", "audience": "maintainer-architecture" }, + { + "path": "docs/arm-readiness-determinism-proof.md", + "audience": "maintainer-verification" + }, { "path": "docs/architecture.md", "audience": "maintainer-architecture" diff --git a/docs/watcher-continuity.md b/docs/watcher-continuity.md index 1a94ec0edef..52513be4cea 100644 --- a/docs/watcher-continuity.md +++ b/docs/watcher-continuity.md @@ -75,7 +75,7 @@ Only the watcher process touches `state/.last-watcher-beat`; no helper process c ## Regression coverage -`tests/fm-pi-watch-extension.test.sh` checks Pi's first-cycle-or-explicit-repair tool metadata and ownership-based redundant-call no-ops, then simulates actionable and empty child closes against the actual Pi and OpenCode close handlers, blocks prompt delivery to prove the successor launches first, verifies single-flight behavior, changes the session lock before close to prove ownership is rechecked, and hangs each successor arm to prove bounded fallback delivery includes the typed restoration failure. +`tests/fm-pi-watch-extension.test.sh` checks Pi's first-cycle-or-explicit-repair tool metadata and ownership-based redundant-call no-ops, then simulates actionable and empty child closes against the actual Pi and OpenCode close handlers, blocks prompt delivery to prove the successor launches first, verifies that concurrent callers coalesce into one arm evaluation only while the fleet lock they read is unchanged, changes the session lock before close to prove ownership is rechecked, and hangs each successor arm to prove bounded fallback delivery includes the typed restoration failure. The same suite covers ordinary same-process session replacement for `/new`, `/resume`, and `/fork`, same-instance shutdown-plus-start, stale prior-generation callbacks, repeated transitions with exactly one live cycle, disappearance of the shutting-down refusal after a valid replacement activates, and terminal quit still refusing late rearm. `tests/fm-watch-arm.test.sh` covers durable queue replay, real remote parent-replies ingestion into the authoritative status log, decision-only OPEN DECISIONS recovery, interrupted handling replay, generation-bound acknowledgement, a persistent live successor after recovery, a watcher close inside the handling window that must leave the printed acknowledgement valid, and the self-healing moved-generation acknowledgement that consumes its handled rows and names its remedy. `tests/fm-watcher-lock.test.sh` covers verified-successor attach, recovery publication before stale-lock removal, the typed self-eviction failure, bounded and successor-linked lifecycle rows, and a SIGSTOP counterfactual that distinguishes a live PID from a stale beacon before classifying termination. @@ -92,3 +92,4 @@ OpenCode support targets persistent TUI sessions rather than headless `opencode Claude depends on the Stop `asyncRewake` rewake, Cursor depends on its awaited stop-hook park, Grok retains native background-completion notifications, and Codex retains bounded foreground checkpoints. [`verification/supervision.md`](verification/supervision.md#watcher-continuity) records the current five-harness live evidence, the 2026-07-24 Stop-owned Claude auto-arm results, and exact opt-in commands. +[`arm-readiness-determinism-proof.md`](arm-readiness-determinism-proof.md) records the repeated-run determinism proof for the Pi and OpenCode arm-readiness suite under idle and loaded conditions. diff --git a/tests/fm-operational-input.test.sh b/tests/fm-operational-input.test.sh index 2d1b1c39de3..776305ff1eb 100755 --- a/tests/fm-operational-input.test.sh +++ b/tests/fm-operational-input.test.sh @@ -140,6 +140,50 @@ JS pass "operational input: the OpenCode adapter constructs through the canonical owner" } +# The adapter writes the body to the encoder's stdin after the child is already +# running, so an encoder that rejects the request and exits without draining a +# body larger than the pipe buffer makes that write fail with EPIPE. Node raises +# EPIPE on the stdin stream rather than on the ChildProcess, so with no listener +# on that stream it becomes an unhandled 'error' event and kills the whole host +# session process instead of rejecting this one call. +test_adapter_surfaces_encoder_exit_instead_of_killing_the_host() { + local tmp fakeroot output status + tmp=$(fm_test_tmproot fm-operational-input-epipe) + fakeroot="$tmp/fakeroot" + mkdir -p "$fakeroot/bin" + cat > "$fakeroot/bin/fm-operational-input.sh" <<'SH' +#!/usr/bin/env bash +printf 'encoder refused the request\n' >&2 +exit 1 +SH + chmod +x "$fakeroot/bin/fm-operational-input.sh" + output=$(FM_TEST_ROOT="$fakeroot" HELPER="$ROOT/.opencode/plugins/lib/fm-operational-input.js" \ + node --input-type=module 2>&1 <<'JS' +import { pathToFileURL } from "node:url"; +const { encodeFirstmateOperationalInput } = await import(pathToFileURL(process.env.HELPER).href); +// Larger than the pipe buffer, so the write cannot be absorbed and must reach +// the closed pipe of an encoder that already exited. +const body = "x".repeat(4 * 1024 * 1024); +try { + await encodeFirstmateOperationalInput(process.env.FM_TEST_ROOT, "watcher", body); + process.stdout.write("resolved\n"); +} catch (err) { + process.stdout.write(`rejected: ${err.message}\n`); +} +await new Promise((resolve) => setTimeout(resolve, 250)); +process.stdout.write("host-alive\n"); +JS + ) + status=$? + [ "$status" -eq 0 ] \ + || fail "OpenCode adapter host died (exit $status) when the encoder exited before reading the body: $output" + printf '%s\n' "$output" | grep -qx 'rejected: encoder refused the request' \ + || fail "OpenCode adapter did not surface the encoder failure to its caller: $output" + printf '%s\n' "$output" | grep -qx 'host-alive' \ + || fail "OpenCode adapter host did not survive the encoder exiting early: $output" + pass "operational input: an encoder that exits before reading fails one call, not the host session" +} + test_invalid_current_encodings_are_rejected() { local output output=$(printf 'body' | "$OWNER" encode legacy-operational 2>/dev/null) \ @@ -157,4 +201,5 @@ test_landed_untyped_prefix_is_explicitly_legacy test_isolated_legacy_matrix test_genuine_near_misses_remain_unclassified test_cross_language_adapter_uses_the_owner +test_adapter_surfaces_encoder_exit_instead_of_killing_the_host test_invalid_current_encodings_are_rejected diff --git a/tests/fm-pi-watch-extension.test.sh b/tests/fm-pi-watch-extension.test.sh index 77b6eb5d7e5..8681d80b2e6 100755 --- a/tests/fm-pi-watch-extension.test.sh +++ b/tests/fm-pi-watch-extension.test.sh @@ -37,6 +37,19 @@ export NODE_NO_WARNINGS=1 # well above a loaded login-shell start; the cases are otherwise unchanged, and # an arm that IS ready still settles immediately rather than waiting it out. +# The login shell above is real cost, but it is also the ONLY unbounded part of +# that budget: /etc/profile and /etc/profile.d run whatever a given machine's +# operator put there, with no upper bound this suite can measure or budget +# against, unlike the fixed FM_PI_ARM_READY_TIMEOUT_MS / FM_OPENCODE_ARM_READY_ +# TIMEOUT_MS padding above. FM_WATCH_ARM_NO_LOGIN_SHELL makes the arm child spawn +# under plain `bash -c` instead, skipping profile sourcing entirely; production +# keeps the login shell as the unconditional default (fm-watch-arm.sh and its +# descendants may only reach node through PATH additions a profile makes), so +# this opt-out is exported here for every case except the one that exists +# specifically to exercise the production default, +# test_watch_arm_login_shell_default_reaches_the_arm_child below. +export FM_WATCH_ARM_NO_LOGIN_SHELL=1 + install_pi_watch_extension_fixture() { local repo=$1 mkdir -p \ @@ -1351,11 +1364,15 @@ EOF } test_opencode_primary_watch_plugin_requires_session_lock() { - local plugin repo home log out status + local plugin repo home log fakebin real_ps real_git gitlog gate entered release out status plugin="$ROOT/.opencode/plugins/fm-primary-watch-arm.js" repo="$TMP_ROOT/opencode-lock-root" home="$TMP_ROOT/opencode-lock-home" log="$TMP_ROOT/opencode-lock.log" + gitlog="$TMP_ROOT/opencode-lock-git.log" + gate="$TMP_ROOT/opencode-lock-ps-gate" + entered="$TMP_ROOT/opencode-lock-ps-entered" + release="$TMP_ROOT/opencode-lock-ps-release" mkdir -p "$repo/bin" "$home/state" "$home/config" git init -q "$repo" : > "$repo/AGENTS.md" @@ -1366,51 +1383,320 @@ printf 'arm\n' >> "${FM_ARM_LOG:?}" printf 'watcher: healthy pid=1 (beacon 0s)\n' SH chmod +x "$repo/bin/fm-watch-arm.sh" - out=$(PLUGIN="$plugin" WORKTREE="$repo" FM_HOME="$home" FM_ARM_LOG="$log" node 2>&1 <<'EOF' -import { existsSync, writeFileSync } from "node:fs"; + real_ps=$(command -v ps) || fail "OpenCode session-lock test needs a real ps on PATH" + real_git=$(command -v git) || fail "OpenCode session-lock test needs a real git on PATH" + fakebin=$(fm_fakebin "$TMP_ROOT/opencode-lock") + # mkdir is the atomic claim: exactly one invocation wins it and blocks, every + # later one falls straight through to the real ps. This pins a caller mid- + # sessionOwnsLock so the reacquired-lock case below forces the real + # interleaving rather than waiting for it to happen to occur. + cat > "$fakebin/ps" </dev/null; then + : > "$entered" + while [ ! -e "$release" ]; do sleep 0.02; done +fi +exec "$real_ps" "\$@" +SH + chmod +x "$fakebin/ps" + # isPrimaryRoot runs exactly two `git rev-parse` probes per beginArm and runs + # before anything can block, so counting them counts evaluations. + cat > "$fakebin/git" <> "$gitlog" +exec "$real_git" "\$@" +SH + chmod +x "$fakebin/git" + out=$(PATH="$fakebin:$PATH" PLUGIN="$plugin" WORKTREE="$repo" FM_HOME="$home" FM_ARM_LOG="$log" FM_GIT_LOG="$gitlog" FM_PS_ENTERED="$entered" FM_PS_RELEASE="$release" FM_WATCH_REARM_RETRY_BASE_MS=60000 FM_WATCH_REARM_RETRY_MAX_MS=60000 node 2>&1 <<'EOF' +import { existsSync, readFileSync, writeFileSync } from "node:fs"; import { pathToFileURL } from "node:url"; const mod = await import(pathToFileURL(process.env.PLUGIN).href); const client = { session: { promptAsync: async () => {} } }; -const hooks = await mod.FmPrimaryWatchArm({ +await mod.FmPrimaryWatchArm({ client, directory: process.env.WORKTREE, worktree: process.env.WORKTREE, }); -const event = { event: { type: "session.idle", properties: { sessionID: "session-test" } } }; +const coordinator = globalThis.__firstmateOpenCodeWatchArm; + +async function waitFor(pred, label) { + for (let i = 0; i < 500; i += 1) { + if (pred()) return; + await new Promise((resolve) => setTimeout(resolve, 20)); + } + throw new Error(`timed out waiting for ${label}`); +} + +// Failure-path only: a caller that can never settle would otherwise hang the +// suite instead of reporting which caller was left waiting. +function settling(promise, label) { + return Promise.race([ + promise, + new Promise((resolve, reject) => { + const timer = setTimeout(() => reject(new Error(`${label} never settled`)), 20000); + timer.unref(); + }), + ]); +} + +function evaluations() { + if (!existsSync(process.env.FM_GIT_LOG)) return 0; + return readFileSync(process.env.FM_GIT_LOG, "utf8") + .split(/\n/) + .filter((line) => line.includes("rev-parse")).length / 2; +} + writeFileSync(`${process.env.FM_HOME}/state/.lock`, "999999\n"); -await hooks.event(event); -// The event hook does not await its own arm attempt, and that attempt spends -// its time in `git`/`ps` subprocesses, so a fixed sleep cannot tell when the -// foreign-lock decision has actually landed. Drain it through the coordinator -// handle the plugin itself exposes: ensureArmed joins a launch that is still in -// flight, so once it resolves no attempt is outstanding and its status IS the -// denial under test. Flipping the lock before that point let the next event -// coalesce onto the stale read-only answer and never arm at all. -const denied = await globalThis.__firstmateOpenCodeWatchArm.ensureArmed("session-test", client); -if (denied !== "read-only") { - console.error(`expected read-only without the session lock, got ${denied}`); - process.exit(1); +const foreign = coordinator.ensureArmed("session-foreign", client); +await waitFor(() => existsSync(process.env.FM_PS_ENTERED), "the foreign-lock ownership walk to block mid-flight"); +if (existsSync(process.env.FM_ARM_LOG)) { + throw new Error("watch arm ran without owning the session lock"); +} + +// The foreign-lock check is still pinned inside its `ps` walk, holding a +// verdict it began computing against the lock above. Reacquire the lock and +// start a second caller before that verdict resolves, so it must see the new +// premise at its own turn rather than inherit the stale one. +writeFileSync(`${process.env.FM_HOME}/state/.lock`, `${process.pid}\n`); +const owned = await settling(coordinator.ensureArmed("session-owned", client), "the reacquired-lock arm attempt"); +if (owned === "read-only") { + throw new Error("the reacquired-lock caller inherited the in-flight foreign-lock verdict"); +} +await waitFor(() => existsSync(process.env.FM_ARM_LOG), "the arm to run once the lock matched"); +if (!readFileSync(process.env.FM_ARM_LOG, "utf8").includes("arm")) { + throw new Error("the reacquired-lock caller reported success without running the arm"); +} + +writeFileSync(process.env.FM_PS_RELEASE, ""); +const foreignStatus = await settling(foreign, "the foreign-lock arm attempt"); +if (foreignStatus !== "read-only") { + throw new Error(`expected read-only for the foreign lock, got ${foreignStatus}`); +} +if (evaluations() !== 2) { + throw new Error(`two callers on different locks must each evaluate their own, got ${evaluations()} evaluations`); +} +EOF +) + status=$? + : > "$release" + expect_code 0 "$status" "OpenCode watch plugin must arm only when this session owns the fleet lock" + [ -z "$out" ] || fail "OpenCode session-lock test printed output: $out" + pass "OpenCode watcher plugin requires session lock ownership" +} + +# The other half of the same invariant. Every ordinary idle turn produces two +# callers - the plugin's own session.idle handler and the turn-end guard's +# coordinator call - and on an unchanged lock they must share one evaluation +# rather than each walking isPrimaryRoot's git probes and sessionOwnsLock's ps +# probes. Pinning the first caller inside its ps walk makes the second caller's +# choice observable: it enters while the first is provably still in flight, so +# the probe count after both settle says whether it shared or duplicated. +test_opencode_watch_arm_coalesces_callers_on_an_unchanged_lock() { + local plugin repo home log fakebin real_ps real_git gitlog gate entered release out status + plugin="$ROOT/.opencode/plugins/fm-primary-watch-arm.js" + repo="$TMP_ROOT/opencode-coalesce-root" + home="$TMP_ROOT/opencode-coalesce-home" + log="$TMP_ROOT/opencode-coalesce.log" + gitlog="$TMP_ROOT/opencode-coalesce-git.log" + gate="$TMP_ROOT/opencode-coalesce-ps-gate" + entered="$TMP_ROOT/opencode-coalesce-ps-entered" + release="$TMP_ROOT/opencode-coalesce-ps-release" + mkdir -p "$repo/bin" "$home/state" "$home/config" + git init -q "$repo" + : > "$repo/AGENTS.md" + : > "$home/state/task.meta" + cat > "$repo/bin/fm-watch-arm.sh" <<'SH' +#!/usr/bin/env bash +printf 'arm\n' >> "${FM_ARM_LOG:?}" +printf 'watcher: healthy pid=1 (beacon 0s)\n' +SH + chmod +x "$repo/bin/fm-watch-arm.sh" + real_ps=$(command -v ps) || fail "OpenCode coalescing test needs a real ps on PATH" + real_git=$(command -v git) || fail "OpenCode coalescing test needs a real git on PATH" + fakebin=$(fm_fakebin "$TMP_ROOT/opencode-coalesce") + cat > "$fakebin/ps" </dev/null; then + : > "$entered" + while [ ! -e "$release" ]; do sleep 0.02; done +fi +exec "$real_ps" "\$@" +SH + chmod +x "$fakebin/ps" + cat > "$fakebin/git" <> "$gitlog" +exec "$real_git" "\$@" +SH + chmod +x "$fakebin/git" + out=$(PATH="$fakebin:$PATH" PLUGIN="$plugin" WORKTREE="$repo" FM_HOME="$home" FM_ARM_LOG="$log" FM_GIT_LOG="$gitlog" FM_PS_ENTERED="$entered" FM_PS_RELEASE="$release" node 2>&1 <<'EOF' +import { existsSync, readFileSync, writeFileSync } from "node:fs"; +import { pathToFileURL } from "node:url"; + +const mod = await import(pathToFileURL(process.env.PLUGIN).href); +const client = { session: { promptAsync: async () => {} } }; +await mod.FmPrimaryWatchArm({ + client, + directory: process.env.WORKTREE, + worktree: process.env.WORKTREE, +}); +const coordinator = globalThis.__firstmateOpenCodeWatchArm; + +async function waitFor(pred, label) { + for (let i = 0; i < 500; i += 1) { + if (pred()) return; + await new Promise((resolve) => setTimeout(resolve, 20)); + } + throw new Error(`timed out waiting for ${label}`); +} + +function settling(promise, label) { + return Promise.race([ + promise, + new Promise((resolve, reject) => { + const timer = setTimeout(() => reject(new Error(`${label} never settled`)), 20000); + timer.unref(); + }), + ]); +} + +function evaluations() { + if (!existsSync(process.env.FM_GIT_LOG)) return 0; + return readFileSync(process.env.FM_GIT_LOG, "utf8") + .split(/\n/) + .filter((line) => line.includes("rev-parse")).length / 2; +} + +writeFileSync(`${process.env.FM_HOME}/state/.lock`, "999999\n"); +const first = coordinator.ensureArmed("session-first", client); +await waitFor(() => existsSync(process.env.FM_PS_ENTERED), "the first ownership walk to block mid-flight"); + +const second = coordinator.ensureArmed("session-second", client); +writeFileSync(process.env.FM_PS_RELEASE, ""); +const firstStatus = await settling(first, "the first arm attempt"); +const secondStatus = await settling(second, "the second arm attempt"); + +if (firstStatus !== "read-only" || secondStatus !== "read-only") { + throw new Error(`expected both callers to report read-only, got ${firstStatus} and ${secondStatus}`); } if (existsSync(process.env.FM_ARM_LOG)) { - console.error("watch arm ran without owning the session lock"); + throw new Error("watch arm ran without owning the session lock"); +} +if (evaluations() !== 1) { + throw new Error(`two callers on an unchanged lock must share one evaluation, got ${evaluations()}`); +} +EOF +) + status=$? + : > "$release" + expect_code 0 "$status" "OpenCode watch plugin must share one ownership evaluation between callers on an unchanged lock" + [ -z "$out" ] || fail "OpenCode coalescing test printed output: $out" + pass "OpenCode watcher plugin coalesces callers that share a lock premise" +} + +# Every other case in this file exports FM_WATCH_ARM_NO_LOGIN_SHELL=1, so this +# is the only coverage of either branch of that opt-out. The production default +# is load-bearing: bin/fm-watch-arm.sh and its descendants may only reach node +# through PATH additions the account's profile makes, so an arm child spawned +# without the login shell would die at exec on such a machine. A temp HOME whose +# .profile exports a marker makes "did the arm child inherit the profile" +# directly observable, and this case owns no readiness window, so paying the +# profile cost here costs the timed cases nothing. +test_watch_arm_login_shell_default_reaches_the_arm_child() { + local repo home oshome plugin ext log envprefix expected out status mode + repo="$TMP_ROOT/login-shell-root" + home="$TMP_ROOT/login-shell-home" + oshome="$TMP_ROOT/login-shell-os-home" + log="$TMP_ROOT/login-shell-arm.log" + mkdir -p "$repo/bin" "$home/state" "$home/config" "$oshome" + git init -q "$repo" + : > "$repo/AGENTS.md" + : > "$home/state/task.meta" + printf 'export FM_LOGIN_SHELL_MARKER=sourced\n' > "$oshome/.profile" + install_pi_watch_extension_fixture "$repo" + plugin="$ROOT/.opencode/plugins/fm-primary-watch-arm.js" + ext="$repo/.pi/extensions/fm-primary-pi-watch.ts" + cat > "$repo/bin/fm-watch-arm.sh" <<'SH' +#!/usr/bin/env bash +printf 'marker=%s\n' "${FM_LOGIN_SHELL_MARKER:-absent}" >> "${FM_ARM_LOG:?}" +printf 'watcher: healthy pid=1 (beacon 0s)\n' +SH + chmod +x "$repo/bin/fm-watch-arm.sh" + for mode in login plain; do + if [ "$mode" = login ]; then + envprefix=(env -u FM_WATCH_ARM_NO_LOGIN_SHELL) + expected="marker=sourced" + else + envprefix=(env FM_WATCH_ARM_NO_LOGIN_SHELL=1) + expected="marker=absent" + fi + + rm -f "$log" + out=$("${envprefix[@]}" HOME="$oshome" PLUGIN="$plugin" WORKTREE="$repo" FM_HOME="$home" FM_ARM_LOG="$log" FM_WATCH_REARM_RETRY_BASE_MS=60000 FM_WATCH_REARM_RETRY_MAX_MS=60000 node 2>&1 <<'EOF' +import { existsSync, writeFileSync } from "node:fs"; +import { pathToFileURL } from "node:url"; + +const mod = await import(pathToFileURL(process.env.PLUGIN).href); +const client = { session: { promptAsync: async () => {} } }; +const hooks = await mod.FmPrimaryWatchArm({ + client, + directory: process.env.WORKTREE, + worktree: process.env.WORKTREE, +}); +writeFileSync(`${process.env.FM_HOME}/state/.lock`, `${process.pid}\n`); +await hooks.event({ event: { type: "session.idle", properties: { sessionID: "session-test" } } }); +for (let i = 0; i < 500 && !existsSync(process.env.FM_ARM_LOG); i += 1) { + await new Promise((resolve) => setTimeout(resolve, 20)); +} +if (!existsSync(process.env.FM_ARM_LOG)) { + console.error("OpenCode watch arm did not run"); process.exit(1); } +EOF +) + status=$? + expect_code 0 "$status" "OpenCode arm child must start under the $mode shell" + [ -z "$out" ] || fail "OpenCode $mode-shell arm test printed output: $out" + grep -qx "$expected" "$log" || fail "OpenCode arm child under the $mode shell expected $expected, got: $(cat "$log")" + + rm -f "$log" + out=$("${envprefix[@]}" HOME="$oshome" PLUGIN="$ext" FM_HOME="$home" FM_ROOT_OVERRIDE="$repo" FM_ARM_LOG="$log" FM_WATCH_REARM_RETRY_BASE_MS=60000 FM_WATCH_REARM_RETRY_MAX_MS=60000 node --input-type=module 2>&1 <<'EOF' +import { existsSync, writeFileSync } from "node:fs"; +import { pathToFileURL } from "node:url"; + +let handler = null; +const pi = { + on() {}, + registerCommand(name, options) { + if (name === "fm-watch-arm-pi") handler = options.handler; + }, + registerTool() {}, + sendUserMessage: async () => {}, +}; writeFileSync(`${process.env.FM_HOME}/state/.lock`, `${process.pid}\n`); -await hooks.event(event); -for (let i = 0; i < 250 && !existsSync(process.env.FM_ARM_LOG); i += 1) { +const mod = await import(pathToFileURL(process.env.PLUGIN).href); +mod.default(pi); +if (!handler) { + console.error("Pi watch command was not registered"); + process.exit(1); +} +await handler("", { ui: { notify() {} } }); +for (let i = 0; i < 500 && !existsSync(process.env.FM_ARM_LOG); i += 1) { await new Promise((resolve) => setTimeout(resolve, 20)); } if (!existsSync(process.env.FM_ARM_LOG)) { - console.error("watch arm did not run after the session lock matched"); + console.error("Pi watch arm did not run"); process.exit(1); } EOF ) - status=$? - expect_code 0 "$status" "OpenCode watch plugin must arm only when this session owns the fleet lock" "$out" - [ -z "$out" ] || fail "OpenCode session-lock test printed output: $out" - pass "OpenCode watcher plugin requires session lock ownership" + status=$? + expect_code 0 "$status" "Pi arm child must start under the $mode shell" + [ -z "$out" ] || fail "Pi $mode-shell arm test printed output: $out" + grep -qx "$expected" "$log" || fail "Pi arm child under the $mode shell expected $expected, got: $(cat "$log")" + done + pass "Watcher arm children inherit the login shell by default and skip it on opt-out" } test_opencode_watch_arm_coordinator_respects_primary_scope() { @@ -2224,6 +2510,8 @@ test_opencode_plugin_package_boundary_is_explicit_esm test_opencode_primary_watch_plugin_uses_effective_state_home test_opencode_primary_watch_plugin_sources_effective_config test_opencode_primary_watch_plugin_requires_session_lock +test_opencode_watch_arm_coalesces_callers_on_an_unchanged_lock +test_watch_arm_login_shell_default_reaches_the_arm_child test_opencode_watch_arm_coordinator_respects_primary_scope test_opencode_primary_watch_plugin_rearms_after_wake test_opencode_pre_ready_actionable_close_preserves_its_successor From 2d171b14381972694ef148573fe436a64b6584fb Mon Sep 17 00:00:00 2001 From: joliverMI Date: Wed, 19 Aug 2026 14:18:07 -0400 Subject: [PATCH 02/11] no-mistakes(review): correct stale arm-readiness proof claims and restore expect_code diagnostics --- docs/arm-readiness-determinism-proof.md | 5 +-- tests/fm-pi-watch-extension.test.sh | 41 ++++++++++++++----------- 2 files changed, 26 insertions(+), 20 deletions(-) diff --git a/docs/arm-readiness-determinism-proof.md b/docs/arm-readiness-determinism-proof.md index a4f2252d343..5889a522a52 100644 --- a/docs/arm-readiness-determinism-proof.md +++ b/docs/arm-readiness-determinism-proof.md @@ -35,7 +35,8 @@ This change does not touch either of those base fixes and does not re-litigate t `ensureArm` reads the lock file's content synchronously at call time and shares an in-flight `beginArm()` only while that content still matches what the in-flight attempt captured; otherwise it starts its own evaluation. Two callers on an unchanged lock still coalesce into one `git`/`ps` walk, so the ordinary idle turn pays no extra subprocess cost. Serializing the callers instead would fix the same race by removing coalescing, at the price of doubling that subprocess work on every idle turn; `test_opencode_watch_arm_coalesces_callers_on_an_unchanged_lock` pins the cheaper contract. -- **`FM_WATCH_ARM_NO_LOGIN_SHELL` opt-out** (`.opencode/plugins/fm-primary-watch-arm.js`, `.pi/extensions/fm-primary-pi-watch.ts`, documented in [`configuration.md`](configuration.md)) - a further reduction of cause A's residual exposure alongside `main`'s own timeout raise, not a replacement for it. +- **`FM_WATCH_ARM_NO_LOGIN_SHELL` opt-out** (`.opencode/plugins/fm-primary-watch-arm.js`, `.pi/extensions/fm-primary-pi-watch.ts`, documented in [`configuration.md`](configuration.md)) - the fix for cause B. + It removes the unbounded cost from inside the timed window rather than widening the window around it, which is all `main`'s own timeout raise could do; it complements that raise and does not replace it. Set to `1`, the arm child spawns under plain `bash -c`. The login shell remains the unconditional production default because `bin/fm-watch-arm.sh` and its descendants may only reach `node` through PATH additions a profile makes. The suite exports the opt-out so its timed windows measure only readiness-detection logic instead of racing an unbounded profile-sourcing cost against however much headroom the timeout leaves. @@ -50,7 +51,7 @@ Two regression tests were added inside the arm-readiness suite itself; the exist | Test | Pins | |---|---| -| `test_opencode_primary_watch_plugin_requires_session_lock` (rewritten) | Cause A. A `ps` shim blocks the first lock-ownership walk mid-flight, so the stale-verdict race is forced deterministically rather than waited for. Also asserts two distinct lock premises produce two evaluations. Fails against the pre-change `ensureArm` (inherits the stale verdict) and against a rejected fully-serialized variant (deadlocks); passes against the shipped premise-validated coalescing. | +| `test_opencode_primary_watch_plugin_requires_session_lock` (rewritten) | Cause A. A `ps` shim blocks the first lock-ownership walk mid-flight, so the stale-verdict race is forced deterministically rather than waited for. Also asserts two distinct lock premises produce two evaluations. Fails against the pre-change `ensureArm`: that version takes the unconditional in-flight-reuse branch, so the reacquired-lock caller blocks on the foreign attempt, which is still pinned inside the gated `ps` shim - the test releases that gate only after awaiting the owned caller - and the case fails on the 20s `settling` guard rejecting with "the reacquired-lock arm attempt never settled" rather than by observing the inherited `read-only` verdict directly. Also fails against a rejected fully-serialized variant (deadlocks); passes against the shipped premise-validated coalescing. | | `test_opencode_watch_arm_coalesces_callers_on_an_unchanged_lock` (new) | The other half of cause A: two callers on an unchanged lock must share exactly one evaluation. Unconditional coalescing (the pre-change behavior) already passes this test; it instead guards against the rejected serialized variant, which fails it with two evaluations. | | `test_watch_arm_login_shell_default_reaches_the_arm_child` (new) | Both branches of the `FM_WATCH_ARM_NO_LOGIN_SHELL` opt-out, for both adapters, via a temp `HOME` whose `.profile` exports a marker the arm child either does or does not observe. | diff --git a/tests/fm-pi-watch-extension.test.sh b/tests/fm-pi-watch-extension.test.sh index 8681d80b2e6..d63e1ec04ef 100755 --- a/tests/fm-pi-watch-extension.test.sh +++ b/tests/fm-pi-watch-extension.test.sh @@ -20,12 +20,15 @@ export NODE_NO_WARNINGS=1 # Bash snapshot compatibility"). Keep apostrophes out of these heredoc bodies. # Arm-readiness budget for the cases below that drive an UNREADY successor arm -# (FM_PI_ARM_READY_TIMEOUT_MS / FM_OPENCODE_ARM_READY_TIMEOUT_MS = 2000). +# (FM_PI_ARM_READY_TIMEOUT_MS / FM_OPENCODE_ARM_READY_TIMEOUT_MS = 2000), and +# why this suite opts out of the arm child's login shell. # -# Both watchers start their arm child as a LOGIN shell - `spawn("bash", ["-lc", -# ...])` in .pi/extensions/fm-primary-pi-watch.ts and -# .opencode/plugins/fm-primary-watch-arm.js - so every arm pays for /etc/profile -# and /etc/profile.d before the fixture's fm-watch-arm.sh runs its first line. +# Both watchers pick the arm child's shell flag once at module load - `spawn( +# "bash", [armShellFlag, ...])` in .pi/extensions/fm-primary-pi-watch.ts and +# `spawn("bash", [ARM_SHELL_FLAG, ...])` in +# .opencode/plugins/fm-primary-watch-arm.js - and both default that flag to +# `-lc`, a LOGIN shell, so an arm left on that default pays for /etc/profile and +# /etc/profile.d before the fixture's fm-watch-arm.sh runs its first line. # Measured on this repo's own dev host: `bash -lc true` is ~140ms idle and # ~1150ms (max 1740ms) under CPU contention, against ~1ms for `bash -c true`. # The earlier 250ms budget therefore expired BEFORE the successor arm had @@ -37,17 +40,19 @@ export NODE_NO_WARNINGS=1 # well above a loaded login-shell start; the cases are otherwise unchanged, and # an arm that IS ready still settles immediately rather than waiting it out. -# The login shell above is real cost, but it is also the ONLY unbounded part of -# that budget: /etc/profile and /etc/profile.d run whatever a given machine's +# That login-shell cost is real, but it is also the ONLY unbounded part of the +# budget: /etc/profile and /etc/profile.d run whatever a given machine's # operator put there, with no upper bound this suite can measure or budget # against, unlike the fixed FM_PI_ARM_READY_TIMEOUT_MS / FM_OPENCODE_ARM_READY_ -# TIMEOUT_MS padding above. FM_WATCH_ARM_NO_LOGIN_SHELL makes the arm child spawn -# under plain `bash -c` instead, skipping profile sourcing entirely; production -# keeps the login shell as the unconditional default (fm-watch-arm.sh and its -# descendants may only reach node through PATH additions a profile makes), so -# this opt-out is exported here for every case except the one that exists -# specifically to exercise the production default, -# test_watch_arm_login_shell_default_reaches_the_arm_child below. +# TIMEOUT_MS padding above. FM_WATCH_ARM_NO_LOGIN_SHELL=1 selects `-c` for that +# flag instead, skipping profile sourcing entirely; production keeps the login +# shell as the unconditional default (fm-watch-arm.sh and its descendants may +# only reach node through PATH additions a profile makes). The export below +# therefore holds for every case in this file, so their timed windows measure +# readiness-detection logic rather than profile sourcing - the one exception is +# test_watch_arm_login_shell_default_reaches_the_arm_child below, which owns no +# readiness window and overrides the variable per invocation to exercise BOTH +# branches, including the production default. export FM_WATCH_ARM_NO_LOGIN_SHELL=1 install_pi_watch_extension_fixture() { @@ -1480,7 +1485,7 @@ EOF ) status=$? : > "$release" - expect_code 0 "$status" "OpenCode watch plugin must arm only when this session owns the fleet lock" + expect_code 0 "$status" "OpenCode watch plugin must arm only when this session owns the fleet lock" "$out" [ -z "$out" ] || fail "OpenCode session-lock test printed output: $out" pass "OpenCode watcher plugin requires session lock ownership" } @@ -1590,7 +1595,7 @@ EOF ) status=$? : > "$release" - expect_code 0 "$status" "OpenCode watch plugin must share one ownership evaluation between callers on an unchanged lock" + expect_code 0 "$status" "OpenCode watch plugin must share one ownership evaluation between callers on an unchanged lock" "$out" [ -z "$out" ] || fail "OpenCode coalescing test printed output: $out" pass "OpenCode watcher plugin coalesces callers that share a lock premise" } @@ -1656,7 +1661,7 @@ if (!existsSync(process.env.FM_ARM_LOG)) { EOF ) status=$? - expect_code 0 "$status" "OpenCode arm child must start under the $mode shell" + expect_code 0 "$status" "OpenCode arm child must start under the $mode shell" "$out" [ -z "$out" ] || fail "OpenCode $mode-shell arm test printed output: $out" grep -qx "$expected" "$log" || fail "OpenCode arm child under the $mode shell expected $expected, got: $(cat "$log")" @@ -1692,7 +1697,7 @@ if (!existsSync(process.env.FM_ARM_LOG)) { EOF ) status=$? - expect_code 0 "$status" "Pi arm child must start under the $mode shell" + expect_code 0 "$status" "Pi arm child must start under the $mode shell" "$out" [ -z "$out" ] || fail "Pi $mode-shell arm test printed output: $out" grep -qx "$expected" "$log" || fail "Pi arm child under the $mode shell expected $expected, got: $(cat "$log")" done From 5f56cc7da2abe68a893a276ba7b8d08cea39f814 Mon Sep 17 00:00:00 2001 From: joliverMI Date: Wed, 19 Aug 2026 14:46:43 -0400 Subject: [PATCH 03/11] no-mistakes(review): wait on observable arm rows and share gate shims --- docs/arm-readiness-determinism-proof.md | 6 + tests/fm-pi-watch-extension.test.sh | 302 ++++++++++++++++-------- 2 files changed, 204 insertions(+), 104 deletions(-) diff --git a/docs/arm-readiness-determinism-proof.md b/docs/arm-readiness-determinism-proof.md index 5889a522a52..6193975e5c6 100644 --- a/docs/arm-readiness-determinism-proof.md +++ b/docs/arm-readiness-determinism-proof.md @@ -41,6 +41,12 @@ This change does not touch either of those base fixes and does not re-litigate t The login shell remains the unconditional production default because `bin/fm-watch-arm.sh` and its descendants may only reach `node` through PATH additions a profile makes. The suite exports the opt-out so its timed windows measure only readiness-detection logic instead of racing an unbounded profile-sourcing cost against however much headroom the timeout leaves. Relocating `HOME` is not sufficient by itself: it removes only the account half of the cost, and `/etc/profile` is still sourced. +- **Observable-condition waits in the four fallback cases** (`tests/fm-pi-watch-extension.test.sh`) - the other half of the cause B fix, and the one that removes the elapsed-time dependence rather than shrinking it. + Each arm attempt appends its `arm=` row as the first thing it does, long before its own readiness timeout can expire, so the row count is a genuinely observable signal for how many attempts the extension made. + `test_pi_hung_successor_falls_back_to_typed_wake`, `test_pi_unretired_successor_falls_back_without_retry`, and their two OpenCode counterparts now wait for that row count to reach its expected total (4 and 2 respectively) and assert it, before running the pre-existing bounded wait for the wake prompt. + That second wait stays a bound on purpose: whether the extension eventually gives up and delivers its typed failure is a negative, and a negative has no positive signal to observe - a bound is the only available instrument for it. + What changed is what the bound now covers. With the attempt count already confirmed observably, it brackets only the bounded readiness/retire/retry sequence the extension runs itself, not an unrelated cost racing it. + Rows are counted only once newline-terminated, so a fixture descheduled between creating the log and writing into it cannot read as an attempt that already happened. - **Three unhandled-EPIPE guards** (`.opencode/plugins/fm-primary-turnend-guard.js`, `.pi/extensions/fm-primary-turnend-guard.ts`, `.opencode/plugins/lib/fm-operational-input.js`) - unrelated to causes A and B, found while proving this change under load. A child that exits before the parent's `child.stdin.end(...)` write lands makes that write fail with EPIPE, which node raises on the stdin stream rather than on the `ChildProcess`. Unhandled, it took down the whole session process. diff --git a/tests/fm-pi-watch-extension.test.sh b/tests/fm-pi-watch-extension.test.sh index d63e1ec04ef..c4d149c5cbd 100755 --- a/tests/fm-pi-watch-extension.test.sh +++ b/tests/fm-pi-watch-extension.test.sh @@ -477,6 +477,18 @@ SH import { existsSync, readFileSync, writeFileSync } from "node:fs"; import { pathToFileURL } from "node:url"; +// The arm fixture appends exactly one `arm=` row per attempt. Counting +// only newline-terminated rows keeps a fixture descheduled between creating +// the log and writing into it from reading as an attempt that already +// happened. +function armRows() { + if (!existsSync(process.env.FM_ARM_LOG)) return []; + return readFileSync(process.env.FM_ARM_LOG, "utf8") + .split("\n") + .slice(0, -1) + .filter((line) => line.startsWith("arm=")); +} + let tool = null; let prompt = ""; let rowsAtPrompt = 0; @@ -488,29 +500,39 @@ const pi = { }, sendUserMessage: async (message) => { prompt += message; - rowsAtPrompt = existsSync(process.env.FM_ARM_LOG) - ? readFileSync(process.env.FM_ARM_LOG, "utf8").trim().split("\n").length - : 0; + rowsAtPrompt = armRows().length; }, }; writeFileSync(`${process.env.FM_HOME}/state/.lock`, `${process.pid}\n`); const mod = await import(pathToFileURL(process.env.PLUGIN).href); mod.default(pi); await tool.execute("tool-call-hung-successor", {}, undefined, undefined, {}); -// Three unready attempts now cost 3 x FM_PI_ARM_READY_TIMEOUT_MS, so this -// bound has to clear that before it can conclude the wake never arrived. -for (let i = 0; i < 3000 && !prompt; i += 1) { +// The one successor plus two retries the extension actually attempts each +// write their arm-log row the moment they spawn, well before their own +// readiness timeout has any chance to expire, so the row count is a real +// observable condition - wait on it directly rather than on elapsed time. +let rows = []; +for (let i = 0; i < 3000; i += 1) { + rows = armRows(); + if (rows.length >= 4) break; await new Promise((resolve) => setTimeout(resolve, 10)); } -const rows = existsSync(process.env.FM_ARM_LOG) - ? readFileSync(process.env.FM_ARM_LOG, "utf8").trim().split("\n") - : []; if (rows.length !== 4) throw new Error(`expected one successor plus two retries, got ${rows.length}: ${rows.join(" | ")}`); +// This assertion is a bounded negative: whether the extension ever gives up +// and delivers its typed failure has no positive signal to observe, so a +// bound is the only available instrument for it. The row-count wait above +// has already confirmed every attempt really happened, so this bound now +// covers only the bounded readiness/retire/retry sequence the extension runs +// itself (3 x FM_PI_ARM_READY_TIMEOUT_MS plus backoff) rather than an +// unrelated cost racing it. +for (let i = 0; i < 3000 && !prompt; i += 1) { + await new Promise((resolve) => setTimeout(resolve, 10)); +} if (rowsAtPrompt !== 4) throw new Error(`wake arrived before restoration exhausted (${rowsAtPrompt} arm rows)`); if (!prompt.includes("signal: synthetic wake")) throw new Error(`original wake was lost: ${prompt}`); if (!prompt.includes("could not restore watcher continuity after 2 retries")) throw new Error(`missing typed restoration failure: ${prompt}`); await new Promise((resolve) => setTimeout(resolve, 100)); -const stableRows = readFileSync(process.env.FM_ARM_LOG, "utf8").trim().split("\n"); +const stableRows = armRows(); if (stableRows.length !== 4) throw new Error(`single-flight recovery launched ${stableRows.length} arms`); EOF ) @@ -551,6 +573,18 @@ SH import { existsSync, readFileSync, writeFileSync } from "node:fs"; import { pathToFileURL } from "node:url"; +// The arm fixture appends exactly one `arm=` row per attempt. Counting +// only newline-terminated rows keeps a fixture descheduled between creating +// the log and writing into it from reading as an attempt that already +// happened. +function armRows() { + if (!existsSync(process.env.FM_ARM_LOG)) return []; + return readFileSync(process.env.FM_ARM_LOG, "utf8") + .split("\n") + .slice(0, -1) + .filter((line) => line.startsWith("arm=")); +} + let tool = null; let prompt = ""; let rowsAtPrompt = 0; @@ -562,22 +596,32 @@ const pi = { }, sendUserMessage: async (message) => { prompt += message; - rowsAtPrompt = existsSync(process.env.FM_ARM_LOG) - ? readFileSync(process.env.FM_ARM_LOG, "utf8").trim().split("\n").length - : 0; + rowsAtPrompt = armRows().length; }, }; writeFileSync(`${process.env.FM_HOME}/state/.lock`, `${process.pid}\n`); const mod = await import(pathToFileURL(process.env.PLUGIN).href); mod.default(pi); await tool.execute("tool-call-unretired-successor", {}, undefined, undefined, {}); -for (let i = 0; i < 500 && !prompt; i += 1) { +// The original arm and its one unretired successor each write their arm-log +// row the moment they spawn, so waiting for both rows is a real observable +// condition rather than a guess at elapsed time. +let rows = []; +for (let i = 0; i < 500; i += 1) { + rows = armRows(); + if (rows.length >= 2) break; await new Promise((resolve) => setTimeout(resolve, 10)); } -const rows = existsSync(process.env.FM_ARM_LOG) - ? readFileSync(process.env.FM_ARM_LOG, "utf8").trim().split("\n") - : []; if (rows.length !== 2) throw new Error(`unretired arm overlapped a retry: ${rows.join(" | ")}`); +// This assertion is a bounded negative: whether the extension gives up on the +// unretired successor and delivers its typed failure has no positive signal +// to observe, so a bound is the only available instrument for it. The +// row-count wait above has already confirmed the successor really spawned, so +// this bound now covers only the bounded readiness-then-retire sequence the +// extension runs itself rather than an unrelated cost racing it. +for (let i = 0; i < 500 && !prompt; i += 1) { + await new Promise((resolve) => setTimeout(resolve, 10)); +} if (rowsAtPrompt !== 2) throw new Error(`wake arrived after an overlapping retry (${rowsAtPrompt} arm rows)`); if (!prompt.includes("signal: synthetic wake")) throw new Error(`original wake was lost: ${prompt}`); if (!prompt.includes("unready successor arm did not exit within 20ms")) throw new Error(`missing unretired-arm failure: ${prompt}`); @@ -1368,16 +1412,51 @@ EOF pass "OpenCode watcher plugin sources the effective config" } +# Shared `ps`/`git` shims for the two coordinator-race cases below. +# +# ps: mkdir is the atomic claim - exactly one invocation wins it, announces +# itself and blocks, and every later one falls straight through to the real ps. +# That pins a caller mid-sessionOwnsLock so those cases force the real +# interleaving rather than waiting for it to happen to occur. +# +# git: isPrimaryRoot runs exactly ARM_GATE_EVALUATION_PROBES `git rev-parse` +# probes per beginArm, and runs before anything can block, so the probe log +# counts evaluations. That per-evaluation probe count is stated once here and +# passed to both node bodies as FM_EVALUATION_PROBES, so a change to +# isPrimaryRoot is corrected in one place rather than silently breaking one +# copy of the arithmetic while the other copy still documents it. +ARM_GATE_EVALUATION_PROBES=2 + +install_arm_gate_shims() { + local prefix=$1 label=$2 real_ps real_git + real_ps=$(command -v ps) || fail "$label needs a real ps on PATH" + real_git=$(command -v git) || fail "$label needs a real git on PATH" + ARM_GATE_ENTERED="$prefix-ps-entered" + ARM_GATE_RELEASE="$prefix-ps-release" + ARM_GATE_GIT_LOG="$prefix-git.log" + ARM_GATE_FAKEBIN=$(fm_fakebin "$prefix") + cat > "$ARM_GATE_FAKEBIN/ps" </dev/null; then + : > "$ARM_GATE_ENTERED" + while [ ! -e "$ARM_GATE_RELEASE" ]; do sleep 0.02; done +fi +exec "$real_ps" "\$@" +SH + cat > "$ARM_GATE_FAKEBIN/git" <> "$ARM_GATE_GIT_LOG" +exec "$real_git" "\$@" +SH + chmod +x "$ARM_GATE_FAKEBIN/ps" "$ARM_GATE_FAKEBIN/git" +} + test_opencode_primary_watch_plugin_requires_session_lock() { - local plugin repo home log fakebin real_ps real_git gitlog gate entered release out status + local plugin repo home log fakebin gitlog entered release out status plugin="$ROOT/.opencode/plugins/fm-primary-watch-arm.js" repo="$TMP_ROOT/opencode-lock-root" home="$TMP_ROOT/opencode-lock-home" log="$TMP_ROOT/opencode-lock.log" - gitlog="$TMP_ROOT/opencode-lock-git.log" - gate="$TMP_ROOT/opencode-lock-ps-gate" - entered="$TMP_ROOT/opencode-lock-ps-entered" - release="$TMP_ROOT/opencode-lock-ps-release" mkdir -p "$repo/bin" "$home/state" "$home/config" git init -q "$repo" : > "$repo/AGENTS.md" @@ -1388,31 +1467,12 @@ printf 'arm\n' >> "${FM_ARM_LOG:?}" printf 'watcher: healthy pid=1 (beacon 0s)\n' SH chmod +x "$repo/bin/fm-watch-arm.sh" - real_ps=$(command -v ps) || fail "OpenCode session-lock test needs a real ps on PATH" - real_git=$(command -v git) || fail "OpenCode session-lock test needs a real git on PATH" - fakebin=$(fm_fakebin "$TMP_ROOT/opencode-lock") - # mkdir is the atomic claim: exactly one invocation wins it and blocks, every - # later one falls straight through to the real ps. This pins a caller mid- - # sessionOwnsLock so the reacquired-lock case below forces the real - # interleaving rather than waiting for it to happen to occur. - cat > "$fakebin/ps" </dev/null; then - : > "$entered" - while [ ! -e "$release" ]; do sleep 0.02; done -fi -exec "$real_ps" "\$@" -SH - chmod +x "$fakebin/ps" - # isPrimaryRoot runs exactly two `git rev-parse` probes per beginArm and runs - # before anything can block, so counting them counts evaluations. - cat > "$fakebin/git" <> "$gitlog" -exec "$real_git" "\$@" -SH - chmod +x "$fakebin/git" - out=$(PATH="$fakebin:$PATH" PLUGIN="$plugin" WORKTREE="$repo" FM_HOME="$home" FM_ARM_LOG="$log" FM_GIT_LOG="$gitlog" FM_PS_ENTERED="$entered" FM_PS_RELEASE="$release" FM_WATCH_REARM_RETRY_BASE_MS=60000 FM_WATCH_REARM_RETRY_MAX_MS=60000 node 2>&1 <<'EOF' + install_arm_gate_shims "$TMP_ROOT/opencode-lock" "OpenCode session-lock test" + fakebin=$ARM_GATE_FAKEBIN + gitlog=$ARM_GATE_GIT_LOG + entered=$ARM_GATE_ENTERED + release=$ARM_GATE_RELEASE + out=$(PATH="$fakebin:$PATH" PLUGIN="$plugin" WORKTREE="$repo" FM_HOME="$home" FM_ARM_LOG="$log" FM_GIT_LOG="$gitlog" FM_EVALUATION_PROBES="$ARM_GATE_EVALUATION_PROBES" FM_PS_ENTERED="$entered" FM_PS_RELEASE="$release" FM_WATCH_REARM_RETRY_BASE_MS=60000 FM_WATCH_REARM_RETRY_MAX_MS=60000 node 2>&1 <<'EOF' import { existsSync, readFileSync, writeFileSync } from "node:fs"; import { pathToFileURL } from "node:url"; @@ -1447,9 +1507,10 @@ function settling(promise, label) { function evaluations() { if (!existsSync(process.env.FM_GIT_LOG)) return 0; - return readFileSync(process.env.FM_GIT_LOG, "utf8") + const probes = readFileSync(process.env.FM_GIT_LOG, "utf8") .split(/\n/) - .filter((line) => line.includes("rev-parse")).length / 2; + .filter((line) => line.includes("rev-parse")).length; + return probes / Number(process.env.FM_EVALUATION_PROBES); } writeFileSync(`${process.env.FM_HOME}/state/.lock`, "999999\n"); @@ -1468,10 +1529,11 @@ const owned = await settling(coordinator.ensureArmed("session-owned", client), " if (owned === "read-only") { throw new Error("the reacquired-lock caller inherited the in-flight foreign-lock verdict"); } -await waitFor(() => existsSync(process.env.FM_ARM_LOG), "the arm to run once the lock matched"); -if (!readFileSync(process.env.FM_ARM_LOG, "utf8").includes("arm")) { - throw new Error("the reacquired-lock caller reported success without running the arm"); -} +await waitFor( + () => existsSync(process.env.FM_ARM_LOG) + && readFileSync(process.env.FM_ARM_LOG, "utf8").includes("arm\n"), + "the arm to run once the lock matched", +); writeFileSync(process.env.FM_PS_RELEASE, ""); const foreignStatus = await settling(foreign, "the foreign-lock arm attempt"); @@ -1498,15 +1560,11 @@ EOF # choice observable: it enters while the first is provably still in flight, so # the probe count after both settle says whether it shared or duplicated. test_opencode_watch_arm_coalesces_callers_on_an_unchanged_lock() { - local plugin repo home log fakebin real_ps real_git gitlog gate entered release out status + local plugin repo home log fakebin gitlog entered release out status plugin="$ROOT/.opencode/plugins/fm-primary-watch-arm.js" repo="$TMP_ROOT/opencode-coalesce-root" home="$TMP_ROOT/opencode-coalesce-home" log="$TMP_ROOT/opencode-coalesce.log" - gitlog="$TMP_ROOT/opencode-coalesce-git.log" - gate="$TMP_ROOT/opencode-coalesce-ps-gate" - entered="$TMP_ROOT/opencode-coalesce-ps-entered" - release="$TMP_ROOT/opencode-coalesce-ps-release" mkdir -p "$repo/bin" "$home/state" "$home/config" git init -q "$repo" : > "$repo/AGENTS.md" @@ -1517,25 +1575,12 @@ printf 'arm\n' >> "${FM_ARM_LOG:?}" printf 'watcher: healthy pid=1 (beacon 0s)\n' SH chmod +x "$repo/bin/fm-watch-arm.sh" - real_ps=$(command -v ps) || fail "OpenCode coalescing test needs a real ps on PATH" - real_git=$(command -v git) || fail "OpenCode coalescing test needs a real git on PATH" - fakebin=$(fm_fakebin "$TMP_ROOT/opencode-coalesce") - cat > "$fakebin/ps" </dev/null; then - : > "$entered" - while [ ! -e "$release" ]; do sleep 0.02; done -fi -exec "$real_ps" "\$@" -SH - chmod +x "$fakebin/ps" - cat > "$fakebin/git" <> "$gitlog" -exec "$real_git" "\$@" -SH - chmod +x "$fakebin/git" - out=$(PATH="$fakebin:$PATH" PLUGIN="$plugin" WORKTREE="$repo" FM_HOME="$home" FM_ARM_LOG="$log" FM_GIT_LOG="$gitlog" FM_PS_ENTERED="$entered" FM_PS_RELEASE="$release" node 2>&1 <<'EOF' + install_arm_gate_shims "$TMP_ROOT/opencode-coalesce" "OpenCode coalescing test" + fakebin=$ARM_GATE_FAKEBIN + gitlog=$ARM_GATE_GIT_LOG + entered=$ARM_GATE_ENTERED + release=$ARM_GATE_RELEASE + out=$(PATH="$fakebin:$PATH" PLUGIN="$plugin" WORKTREE="$repo" FM_HOME="$home" FM_ARM_LOG="$log" FM_GIT_LOG="$gitlog" FM_EVALUATION_PROBES="$ARM_GATE_EVALUATION_PROBES" FM_PS_ENTERED="$entered" FM_PS_RELEASE="$release" node 2>&1 <<'EOF' import { existsSync, readFileSync, writeFileSync } from "node:fs"; import { pathToFileURL } from "node:url"; @@ -1568,9 +1613,10 @@ function settling(promise, label) { function evaluations() { if (!existsSync(process.env.FM_GIT_LOG)) return 0; - return readFileSync(process.env.FM_GIT_LOG, "utf8") + const probes = readFileSync(process.env.FM_GIT_LOG, "utf8") .split(/\n/) - .filter((line) => line.includes("rev-parse")).length / 2; + .filter((line) => line.includes("rev-parse")).length; + return probes / Number(process.env.FM_EVALUATION_PROBES); } writeFileSync(`${process.env.FM_HOME}/state/.lock`, "999999\n"); @@ -1639,7 +1685,7 @@ SH rm -f "$log" out=$("${envprefix[@]}" HOME="$oshome" PLUGIN="$plugin" WORKTREE="$repo" FM_HOME="$home" FM_ARM_LOG="$log" FM_WATCH_REARM_RETRY_BASE_MS=60000 FM_WATCH_REARM_RETRY_MAX_MS=60000 node 2>&1 <<'EOF' -import { existsSync, writeFileSync } from "node:fs"; +import { existsSync, readFileSync, writeFileSync } from "node:fs"; import { pathToFileURL } from "node:url"; const mod = await import(pathToFileURL(process.env.PLUGIN).href); @@ -1651,11 +1697,13 @@ const hooks = await mod.FmPrimaryWatchArm({ }); writeFileSync(`${process.env.FM_HOME}/state/.lock`, `${process.pid}\n`); await hooks.event({ event: { type: "session.idle", properties: { sessionID: "session-test" } } }); -for (let i = 0; i < 500 && !existsSync(process.env.FM_ARM_LOG); i += 1) { +const markerLogged = () => existsSync(process.env.FM_ARM_LOG) + && /^marker=\S+\n/m.test(readFileSync(process.env.FM_ARM_LOG, "utf8")); +for (let i = 0; i < 500 && !markerLogged(); i += 1) { await new Promise((resolve) => setTimeout(resolve, 20)); } -if (!existsSync(process.env.FM_ARM_LOG)) { - console.error("OpenCode watch arm did not run"); +if (!markerLogged()) { + console.error("OpenCode watch arm did not record a complete marker row"); process.exit(1); } EOF @@ -1667,7 +1715,7 @@ EOF rm -f "$log" out=$("${envprefix[@]}" HOME="$oshome" PLUGIN="$ext" FM_HOME="$home" FM_ROOT_OVERRIDE="$repo" FM_ARM_LOG="$log" FM_WATCH_REARM_RETRY_BASE_MS=60000 FM_WATCH_REARM_RETRY_MAX_MS=60000 node --input-type=module 2>&1 <<'EOF' -import { existsSync, writeFileSync } from "node:fs"; +import { existsSync, readFileSync, writeFileSync } from "node:fs"; import { pathToFileURL } from "node:url"; let handler = null; @@ -1687,11 +1735,13 @@ if (!handler) { process.exit(1); } await handler("", { ui: { notify() {} } }); -for (let i = 0; i < 500 && !existsSync(process.env.FM_ARM_LOG); i += 1) { +const markerLogged = () => existsSync(process.env.FM_ARM_LOG) + && /^marker=\S+\n/m.test(readFileSync(process.env.FM_ARM_LOG, "utf8")); +for (let i = 0; i < 500 && !markerLogged(); i += 1) { await new Promise((resolve) => setTimeout(resolve, 20)); } -if (!existsSync(process.env.FM_ARM_LOG)) { - console.error("Pi watch arm did not run"); +if (!markerLogged()) { + console.error("Pi watch arm did not record a complete marker row"); process.exit(1); } EOF @@ -1954,15 +2004,25 @@ import { existsSync, readFileSync, writeFileSync } from "node:fs"; import { pathToFileURL } from "node:url"; const mod = await import(pathToFileURL(process.env.PLUGIN).href); +// The arm fixture appends exactly one `arm=` row per attempt. Counting +// only newline-terminated rows keeps a fixture descheduled between creating +// the log and writing into it from reading as an attempt that already +// happened. +function armRows() { + if (!existsSync(process.env.FM_ARM_LOG)) return []; + return readFileSync(process.env.FM_ARM_LOG, "utf8") + .split("\n") + .slice(0, -1) + .filter((line) => line.startsWith("arm=")); +} + let prompt = ""; let rowsAtPrompt = 0; const client = { session: { promptAsync: async (request) => { prompt += request.body.parts[0].text; - rowsAtPrompt = existsSync(process.env.FM_ARM_LOG) - ? readFileSync(process.env.FM_ARM_LOG, "utf8").trim().split("\n").length - : 0; + rowsAtPrompt = armRows().length; }, }, }; @@ -1973,20 +2033,32 @@ const hooks = await mod.FmPrimaryWatchArm({ }); writeFileSync(`${process.env.FM_HOME}/state/.lock`, `${process.pid}\n`); await hooks.event({ event: { type: "session.idle", properties: { sessionID: "session-test" } } }); -// Three unready attempts now cost 3 x FM_OPENCODE_ARM_READY_TIMEOUT_MS, so this -// bound has to clear that before it can conclude the wake never arrived. -for (let i = 0; i < 3000 && !prompt; i += 1) { +// The one successor plus two retries the extension actually attempts each +// write their arm-log row the moment they spawn, well before their own +// readiness timeout has any chance to expire, so the row count is a real +// observable condition - wait on it directly rather than on elapsed time. +let rows = []; +for (let i = 0; i < 3000; i += 1) { + rows = armRows(); + if (rows.length >= 4) break; await new Promise((resolve) => setTimeout(resolve, 10)); } -const rows = existsSync(process.env.FM_ARM_LOG) - ? readFileSync(process.env.FM_ARM_LOG, "utf8").trim().split("\n") - : []; if (rows.length !== 4) throw new Error(`expected one successor plus two retries, got ${rows.length}: ${rows.join(" | ")}`); +// This assertion is a bounded negative: whether the extension ever gives up +// and delivers its typed failure has no positive signal to observe, so a +// bound is the only available instrument for it. The row-count wait above +// has already confirmed every attempt really happened, so this bound now +// covers only the bounded readiness/retire/retry sequence the extension runs +// itself (3 x FM_OPENCODE_ARM_READY_TIMEOUT_MS plus backoff) rather than an +// unrelated cost racing it. +for (let i = 0; i < 3000 && !prompt; i += 1) { + await new Promise((resolve) => setTimeout(resolve, 10)); +} if (rowsAtPrompt !== 4) throw new Error(`wake arrived before restoration exhausted (${rowsAtPrompt} arm rows)`); if (!prompt.includes("signal: synthetic wake")) throw new Error(`original wake was lost: ${prompt}`); if (!prompt.includes("could not restore watcher continuity after 2 retries")) throw new Error(`missing typed restoration failure: ${prompt}`); await new Promise((resolve) => setTimeout(resolve, 100)); -const stableRows = readFileSync(process.env.FM_ARM_LOG, "utf8").trim().split("\n"); +const stableRows = armRows(); if (stableRows.length !== 4) throw new Error(`single-flight recovery launched ${stableRows.length} arms`); EOF ) @@ -2030,15 +2102,25 @@ import { existsSync, readFileSync, writeFileSync } from "node:fs"; import { pathToFileURL } from "node:url"; const mod = await import(pathToFileURL(process.env.PLUGIN).href); +// The arm fixture appends exactly one `arm=` row per attempt. Counting +// only newline-terminated rows keeps a fixture descheduled between creating +// the log and writing into it from reading as an attempt that already +// happened. +function armRows() { + if (!existsSync(process.env.FM_ARM_LOG)) return []; + return readFileSync(process.env.FM_ARM_LOG, "utf8") + .split("\n") + .slice(0, -1) + .filter((line) => line.startsWith("arm=")); +} + let prompt = ""; let rowsAtPrompt = 0; const client = { session: { promptAsync: async (request) => { prompt += request.body.parts[0].text; - rowsAtPrompt = existsSync(process.env.FM_ARM_LOG) - ? readFileSync(process.env.FM_ARM_LOG, "utf8").trim().split("\n").length - : 0; + rowsAtPrompt = armRows().length; }, }, }; @@ -2049,13 +2131,25 @@ const hooks = await mod.FmPrimaryWatchArm({ }); writeFileSync(`${process.env.FM_HOME}/state/.lock`, `${process.pid}\n`); await hooks.event({ event: { type: "session.idle", properties: { sessionID: "session-test" } } }); -for (let i = 0; i < 500 && !prompt; i += 1) { +// The original arm and its one unretired successor each write their arm-log +// row the moment they spawn, so waiting for both rows is a real observable +// condition rather than a guess at elapsed time. +let rows = []; +for (let i = 0; i < 500; i += 1) { + rows = armRows(); + if (rows.length >= 2) break; await new Promise((resolve) => setTimeout(resolve, 10)); } -const rows = existsSync(process.env.FM_ARM_LOG) - ? readFileSync(process.env.FM_ARM_LOG, "utf8").trim().split("\n") - : []; if (rows.length !== 2) throw new Error(`unretired arm overlapped a retry: ${rows.join(" | ")}`); +// This assertion is a bounded negative: whether the extension gives up on the +// unretired successor and delivers its typed failure has no positive signal +// to observe, so a bound is the only available instrument for it. The +// row-count wait above has already confirmed the successor really spawned, so +// this bound now covers only the bounded readiness-then-retire sequence the +// extension runs itself rather than an unrelated cost racing it. +for (let i = 0; i < 500 && !prompt; i += 1) { + await new Promise((resolve) => setTimeout(resolve, 10)); +} if (rowsAtPrompt !== 2) throw new Error(`wake arrived after an overlapping retry (${rowsAtPrompt} arm rows)`); if (!prompt.includes("signal: synthetic wake")) throw new Error(`original wake was lost: ${prompt}`); if (!prompt.includes("unready successor arm did not exit within 20ms")) throw new Error(`missing unretired-arm failure: ${prompt}`); From 1fce567f4abc796b686168c765b2a678e737ad63 Mon Sep 17 00:00:00 2001 From: joliverMI Date: Wed, 19 Aug 2026 15:02:23 -0400 Subject: [PATCH 04/11] no-mistakes(review): restore fallback diagnostics and bound unretired arm counts --- docs/arm-readiness-determinism-proof.md | 2 ++ tests/fm-pi-watch-extension.test.sh | 14 ++++++++++---- 2 files changed, 12 insertions(+), 4 deletions(-) diff --git a/docs/arm-readiness-determinism-proof.md b/docs/arm-readiness-determinism-proof.md index 6193975e5c6..dff218a6b4c 100644 --- a/docs/arm-readiness-determinism-proof.md +++ b/docs/arm-readiness-determinism-proof.md @@ -47,6 +47,8 @@ This change does not touch either of those base fixes and does not re-litigate t That second wait stays a bound on purpose: whether the extension eventually gives up and delivers its typed failure is a negative, and a negative has no positive signal to observe - a bound is the only available instrument for it. What changed is what the bound now covers. With the attempt count already confirmed observably, it brackets only the bounded readiness/retire/retry sequence the extension runs itself, not an unrelated cost racing it. Rows are counted only once newline-terminated, so a fixture descheduled between creating the log and writing into it cannot read as an attempt that already happened. + Because that wait exits as soon as the expected count is reached, it can only bound the count from below; all four cases therefore settle briefly after the wake assertions and re-read the log, so a stray extra arm is still caught from above. + In the unretired cases that re-read happens before the release file lets the successor exit, which is the window where an overlapping retry would be the reported regression. - **Three unhandled-EPIPE guards** (`.opencode/plugins/fm-primary-turnend-guard.js`, `.pi/extensions/fm-primary-turnend-guard.ts`, `.opencode/plugins/lib/fm-operational-input.js`) - unrelated to causes A and B, found while proving this change under load. A child that exits before the parent's `child.stdin.end(...)` write lands makes that write fail with EPIPE, which node raises on the stdin stream rather than on the `ChildProcess`. Unhandled, it took down the whole session process. diff --git a/tests/fm-pi-watch-extension.test.sh b/tests/fm-pi-watch-extension.test.sh index c4d149c5cbd..871974c0fe5 100755 --- a/tests/fm-pi-watch-extension.test.sh +++ b/tests/fm-pi-watch-extension.test.sh @@ -537,7 +537,7 @@ if (stableRows.length !== 4) throw new Error(`single-flight recovery launched ${ EOF ) status=$? - expect_code 0 "$status" "Pi must deliver the actionable wake after bounded hung-successor recovery" + expect_code 0 "$status" "Pi must deliver the actionable wake after bounded hung-successor recovery" "$out" [ -z "$out" ] || fail "Pi hung-successor test printed output: $out" pass "Pi hung successor falls back to one typed actionable wake" } @@ -625,12 +625,15 @@ for (let i = 0; i < 500 && !prompt; i += 1) { if (rowsAtPrompt !== 2) throw new Error(`wake arrived after an overlapping retry (${rowsAtPrompt} arm rows)`); if (!prompt.includes("signal: synthetic wake")) throw new Error(`original wake was lost: ${prompt}`); if (!prompt.includes("unready successor arm did not exit within 20ms")) throw new Error(`missing unretired-arm failure: ${prompt}`); +await new Promise((resolve) => setTimeout(resolve, 100)); +const stableRows = armRows(); +if (stableRows.length !== 2) throw new Error(`fallback launched ${stableRows.length} arms alongside the unretired successor: ${stableRows.join(" | ")}`); writeFileSync(process.env.FM_RELEASE_FILE, "release\n"); await new Promise((resolve) => setTimeout(resolve, 80)); EOF ) status=$? - expect_code 0 "$status" "Pi must fall back without overlapping an unretired successor" + expect_code 0 "$status" "Pi must fall back without overlapping an unretired successor" "$out" [ -z "$out" ] || fail "Pi unretired-successor test printed output: $out" pass "Pi unretired successor falls back without an overlapping retry" } @@ -2063,7 +2066,7 @@ if (stableRows.length !== 4) throw new Error(`single-flight recovery launched ${ EOF ) status=$? - expect_code 0 "$status" "OpenCode must deliver the actionable wake after bounded hung-successor recovery" + expect_code 0 "$status" "OpenCode must deliver the actionable wake after bounded hung-successor recovery" "$out" [ -z "$out" ] || fail "OpenCode hung-successor test printed output: $out" pass "OpenCode hung successor falls back to one typed actionable wake" } @@ -2153,12 +2156,15 @@ for (let i = 0; i < 500 && !prompt; i += 1) { if (rowsAtPrompt !== 2) throw new Error(`wake arrived after an overlapping retry (${rowsAtPrompt} arm rows)`); if (!prompt.includes("signal: synthetic wake")) throw new Error(`original wake was lost: ${prompt}`); if (!prompt.includes("unready successor arm did not exit within 20ms")) throw new Error(`missing unretired-arm failure: ${prompt}`); +await new Promise((resolve) => setTimeout(resolve, 100)); +const stableRows = armRows(); +if (stableRows.length !== 2) throw new Error(`fallback launched ${stableRows.length} arms alongside the unretired successor: ${stableRows.join(" | ")}`); writeFileSync(process.env.FM_RELEASE_FILE, "release\n"); await new Promise((resolve) => setTimeout(resolve, 80)); EOF ) status=$? - expect_code 0 "$status" "OpenCode must fall back without overlapping an unretired successor" + expect_code 0 "$status" "OpenCode must fall back without overlapping an unretired successor" "$out" [ -z "$out" ] || fail "OpenCode unretired-successor test printed output: $out" pass "OpenCode unretired successor falls back without an overlapping retry" } From 87f1c5ab89fbec5545a7f67b5646a65803bbcdb8 Mon Sep 17 00:00:00 2001 From: joliverMI Date: Wed, 19 Aug 2026 15:15:02 -0400 Subject: [PATCH 05/11] no-mistakes(review): correct lock-assertion cause attribution in proof doc --- docs/arm-readiness-determinism-proof.md | 25 ++++++++++++++++++------- 1 file changed, 18 insertions(+), 7 deletions(-) diff --git a/docs/arm-readiness-determinism-proof.md b/docs/arm-readiness-determinism-proof.md index dff218a6b4c..559230f2f64 100644 --- a/docs/arm-readiness-determinism-proof.md +++ b/docs/arm-readiness-determinism-proof.md @@ -6,22 +6,33 @@ By the time this record was written, `main` already carried its own independent ## The four originally-failing assertions, and which share a cause -Two independent causes, two assertions each. +All four reported failures are attributable to cause B, the one confound the pre-change suite actually exposed. +Cause A is a separate, real production race that this change also fixes; it is listed here because the fix ships in the same change, not because it explains any of the four reported failures. -| Assertion | Cause | +| Assertion | Cause of the reported failure | |---|---| -| `OpenCode watch plugin must arm only when this session owns the fleet lock` (both reported occurrences) | A - production race in `ensureArm` | +| `OpenCode watch plugin must arm only when this session owns the fleet lock` (both reported occurrences) | B - test window racing an unrelated cost | | `Pi must deliver the actionable wake after bounded hung-successor recovery` | B - test window racing an unrelated cost | | `Pi must fall back without overlapping an unretired successor` | B - test window racing an unrelated cost | -**Cause A - production code was genuinely racy.** +**Cause A - production code was genuinely racy, but this is not what the four reported failures were.** `ensureArm` in `.opencode/plugins/fm-primary-watch-arm.js` reused a still-resolving earlier caller's `beginArm()` result unconditionally. -Every ordinary `session.idle` produces two callers - the plugin's own handler and the turn-end guard's `coordinator.ensureArmed` call - so when the fleet lock was reacquired while an earlier attempt was mid-flight, the later caller inherited that attempt's `read-only` verdict and never armed. +Every ordinary `session.idle` produces two callers - the plugin's own handler and the turn-end guard's `coordinator.ensureArmed` call - so a caller arriving after the fleet lock was reacquired, while an earlier attempt was still mid-flight, inherited that attempt's `read-only` verdict and never armed. +That race is reachable in production and is demonstrated directly by the rewritten `test_opencode_primary_watch_plugin_requires_session_lock`, which uses a `ps` shim to pin one caller mid-evaluation and flip the lock underneath it - see the test table below. + +What the evidence does *not* support is attributing the two reported failures of the lock assertion to that race. +Traced against the base suite at `45bd292`, that case wrote the foreign lock, ran `await hooks.event(...)` (caller 1, which sets `launchInFlight` synchronously), then awaited `coordinator.ensureArmed(...)` (caller 2, which joins caller 1). +Both callers therefore evaluated the *same* foreign lock, so inheriting the in-flight verdict was the correct answer rather than a stale one; and because caller 1's `finally` clears `launchInFlight` in an earlier microtask than caller 2's resumption, the lock flip that followed was always evaluated by a fresh attempt. +The base test could not construct the interleaving cause A needs - its own comment records that this sequencing was deliberate - so what actually made it flaky was the same cause B confound as the other three: a 5s `existsSync` poll waiting on an arm child started through `bash -lc`. +Why those two field failures occurred cannot be reconstructed further from the base test's mechanics; cause A stands on the new test, not on them. **Cause B - the test measured something it did not intend to.** Both adapters spawn their arm child through `bash -lc`. A login shell sources `/etc/profile` and `/etc/profile.d/*` in addition to the account's own profile files, and the system-wide half is not relocatable via `HOME`. -That unbounded, machine-specific, load-dependent cost sat inside the tight readiness/retire windows these two cases assert on, so under contention the arm child was SIGTERMed before the fixture could record itself. +That unbounded, machine-specific, load-dependent cost sat inside every bounded window these four assertions depend on, so under contention the window expired before the arm child had recorded itself. +It takes two shapes here. +In the two Pi fallback cases it sat inside the tight readiness/retire windows those cases assert on, so the arm child was SIGTERMed before the fixture could append its row. +In the lock case it sat inside the 5s `existsSync` poll that waits for the arm to run once the lock matches, against a `bash -lc` start measured at ~1150ms and up to 1740ms under contention. ## Base state (already on `main` before this change) @@ -55,7 +66,7 @@ This change does not touch either of those base fixes and does not re-litigate t These are every async `stdin.end` site in the adapters; `.pi/extensions/lib/fm-operational-input.ts` uses `spawnSync` with `input:` and has no async pipe. `test_adapter_surfaces_encoder_exit_instead_of_killing_the_host` in `tests/fm-operational-input.test.sh` pins the shared encoder path: an encoder that exits before reading a body larger than the pipe buffer must fail that one call and leave the host session alive. -Two regression tests were added inside the arm-readiness suite itself; the existing lock test was rewritten to prove cause A deterministically rather than by waiting for it. +Two regression tests were added inside the arm-readiness suite itself; the existing lock test was rewritten so that it forces cause A deterministically, which its previous sequencing could not do at all. | Test | Pins | |---|---| From 22d3263f87e7e3cf9d7cbded309761884cb6e2b1 Mon Sep 17 00:00:00 2001 From: joliverMI Date: Wed, 19 Aug 2026 15:28:14 -0400 Subject: [PATCH 06/11] no-mistakes(review): restore two-cause attribution and note login-shell residual bound --- docs/arm-readiness-determinism-proof.md | 46 ++++++++++++++----------- tests/fm-pi-watch-extension.test.sh | 21 +++++++++-- 2 files changed, 43 insertions(+), 24 deletions(-) diff --git a/docs/arm-readiness-determinism-proof.md b/docs/arm-readiness-determinism-proof.md index 559230f2f64..534c908d951 100644 --- a/docs/arm-readiness-determinism-proof.md +++ b/docs/arm-readiness-determinism-proof.md @@ -6,39 +6,43 @@ By the time this record was written, `main` already carried its own independent ## The four originally-failing assertions, and which share a cause -All four reported failures are attributable to cause B, the one confound the pre-change suite actually exposed. -Cause A is a separate, real production race that this change also fixes; it is listed here because the fix ships in the same change, not because it explains any of the four reported failures. +Two independent causes, two assertions each. -| Assertion | Cause of the reported failure | +| Assertion | Cause | |---|---| -| `OpenCode watch plugin must arm only when this session owns the fleet lock` (both reported occurrences) | B - test window racing an unrelated cost | +| `OpenCode watch plugin must arm only when this session owns the fleet lock` (both reported occurrences) | A - production race in `ensureArm` | | `Pi must deliver the actionable wake after bounded hung-successor recovery` | B - test window racing an unrelated cost | | `Pi must fall back without overlapping an unretired successor` | B - test window racing an unrelated cost | -**Cause A - production code was genuinely racy, but this is not what the four reported failures were.** +**Cause A - production code was genuinely racy.** `ensureArm` in `.opencode/plugins/fm-primary-watch-arm.js` reused a still-resolving earlier caller's `beginArm()` result unconditionally. -Every ordinary `session.idle` produces two callers - the plugin's own handler and the turn-end guard's `coordinator.ensureArmed` call - so a caller arriving after the fleet lock was reacquired, while an earlier attempt was still mid-flight, inherited that attempt's `read-only` verdict and never armed. -That race is reachable in production and is demonstrated directly by the rewritten `test_opencode_primary_watch_plugin_requires_session_lock`, which uses a `ps` shim to pin one caller mid-evaluation and flip the lock underneath it - see the test table below. - -What the evidence does *not* support is attributing the two reported failures of the lock assertion to that race. -Traced against the base suite at `45bd292`, that case wrote the foreign lock, ran `await hooks.event(...)` (caller 1, which sets `launchInFlight` synchronously), then awaited `coordinator.ensureArmed(...)` (caller 2, which joins caller 1). -Both callers therefore evaluated the *same* foreign lock, so inheriting the in-flight verdict was the correct answer rather than a stale one; and because caller 1's `finally` clears `launchInFlight` in an earlier microtask than caller 2's resumption, the lock flip that followed was always evaluated by a fresh attempt. -The base test could not construct the interleaving cause A needs - its own comment records that this sequencing was deliberate - so what actually made it flaky was the same cause B confound as the other three: a 5s `existsSync` poll waiting on an arm child started through `bash -lc`. -Why those two field failures occurred cannot be reconstructed further from the base test's mechanics; cause A stands on the new test, not on them. +Every ordinary `session.idle` produces two callers - the plugin's own handler and the turn-end guard's `coordinator.ensureArmed` call - so when the fleet lock was reacquired while an earlier attempt was mid-flight, the later caller inherited that attempt's `read-only` verdict and never armed. +This diagnosis was made against the lock-ownership test as it stood at the time, using `ps`-latency fault injection to hold an attempt inside its ownership walk; the race reproduced deterministically before the `ensureArm` fix and stopped reproducing after it. + +**Why this branch's inherited copy of that test can no longer witness it.** +The version of the lock test this branch inherited cannot reconstruct that interleaving, for a reason that has nothing to do with the diagnosis. +At the time of the diagnosis the case slept a fixed 120ms between starting the foreign-lock attempt and flipping the lock, so under load the flip could land while the first attempt was still inside its `git`/`ps` walk - the later caller then coalesced onto the stale `read-only` verdict and never armed, which is exactly the reported failure. +`882004e` on `main` afterwards replaced that sleep with a direct `coordinator.ensureArmed(...)` await, independently of this work and for its own reasons (a fixed sleep cannot tell when the decision has landed). +That await drains the in-flight attempt before the flip: both callers now evaluate the *same* foreign lock, and caller 1's `finally` clears `launchInFlight` in an earlier microtask than caller 2's resumption, so the flip is always evaluated by a fresh attempt. +The consequence is narrow and is only about which artifact can serve as the witness. +Cause A is real, was demonstrated when it was diagnosed, and is fixed here; what this branch's inherited test can no longer do is re-demonstrate it, which is why the race is instead pinned by a new test built for exactly that purpose - `test_opencode_primary_watch_plugin_requires_session_lock`'s `ps`-shim rewrite, which forces the lock to change while a caller is pinned mid-evaluation. +None of this reassigns the lock assertion to cause B: its pre-change wait was a 5s budget against a `bash -lc` start measured at ~1150ms and at most ~1740ms, so unlike the two Pi cases below it had ample headroom and cause B is not what was failing it. **Cause B - the test measured something it did not intend to.** Both adapters spawn their arm child through `bash -lc`. A login shell sources `/etc/profile` and `/etc/profile.d/*` in addition to the account's own profile files, and the system-wide half is not relocatable via `HOME`. -That unbounded, machine-specific, load-dependent cost sat inside every bounded window these four assertions depend on, so under contention the window expired before the arm child had recorded itself. -It takes two shapes here. -In the two Pi fallback cases it sat inside the tight readiness/retire windows those cases assert on, so the arm child was SIGTERMed before the fixture could append its row. -In the lock case it sat inside the 5s `existsSync` poll that waits for the arm to run once the lock matches, against a `bash -lc` start measured at ~1150ms and up to 1740ms under contention. +That unbounded, machine-specific, load-dependent cost sat inside the tight readiness/retire windows these two cases assert on, so under contention the arm child was SIGTERMed before the fixture could record itself. + +One residual instance of this shape survives, deliberately, in exactly one case. +`test_watch_arm_login_shell_default_reaches_the_arm_child` exists to verify that the production default still reaches the arm child, so its `login` branch must pay the real `/etc/profile` cost and then wait a bounded 10s for the marker row - a bounded wait on an unbounded cost, which is the very shape the rest of this change removes. +It cannot be removed there without defeating what the case verifies; the bound is sized well above the ~1740ms worst case measured above, but it is a headroom argument rather than a guarantee, and it applies to that one case only. ## Base state (already on `main` before this change) `main` independently raised `FM_PI_ARM_READY_TIMEOUT_MS` / `FM_OPENCODE_ARM_READY_TIMEOUT_MS` from 250ms to 2000ms and rewrote `test_pi_session_transition_generation_owner`'s fixture to write its arm-log row before the pid-file row that its waiters gate on, both landed independently of this change. -Neither addresses cause A: `ensureArm` still reused an in-flight attempt's result unconditionally, and its own comment on the timeout raise records a measured worst case of ~1740ms against the new 2000ms budget under contention - narrower headroom, not a removed confound. -This change does not touch either of those base fixes and does not re-litigate the timeout value; both are kept exactly as `main` has them. +`882004e` on `main` also replaced the lock test's fixed 120ms sleep with a direct `coordinator.ensureArmed(...)` await, again independently of this change; that is what stops this branch's inherited copy of that case from reconstructing cause A, as described above. +None of those addresses cause A: `ensureArm` still reused an in-flight attempt's result unconditionally, and its own comment on the timeout raise records a measured worst case of ~1740ms against the new 2000ms budget under contention - narrower headroom, not a removed confound. +This change does not touch any of those base fixes and does not re-litigate the timeout value; all are kept exactly as `main` has them. ## What this change adds @@ -66,13 +70,13 @@ This change does not touch either of those base fixes and does not re-litigate t These are every async `stdin.end` site in the adapters; `.pi/extensions/lib/fm-operational-input.ts` uses `spawnSync` with `input:` and has no async pipe. `test_adapter_surfaces_encoder_exit_instead_of_killing_the_host` in `tests/fm-operational-input.test.sh` pins the shared encoder path: an encoder that exits before reading a body larger than the pipe buffer must fail that one call and leave the host session alive. -Two regression tests were added inside the arm-readiness suite itself; the existing lock test was rewritten so that it forces cause A deterministically, which its previous sequencing could not do at all. +Two regression tests were added inside the arm-readiness suite itself; the existing lock test was rewritten so that it forces cause A deterministically, which the sequencing this branch inherited could not do. | Test | Pins | |---|---| | `test_opencode_primary_watch_plugin_requires_session_lock` (rewritten) | Cause A. A `ps` shim blocks the first lock-ownership walk mid-flight, so the stale-verdict race is forced deterministically rather than waited for. Also asserts two distinct lock premises produce two evaluations. Fails against the pre-change `ensureArm`: that version takes the unconditional in-flight-reuse branch, so the reacquired-lock caller blocks on the foreign attempt, which is still pinned inside the gated `ps` shim - the test releases that gate only after awaiting the owned caller - and the case fails on the 20s `settling` guard rejecting with "the reacquired-lock arm attempt never settled" rather than by observing the inherited `read-only` verdict directly. Also fails against a rejected fully-serialized variant (deadlocks); passes against the shipped premise-validated coalescing. | | `test_opencode_watch_arm_coalesces_callers_on_an_unchanged_lock` (new) | The other half of cause A: two callers on an unchanged lock must share exactly one evaluation. Unconditional coalescing (the pre-change behavior) already passes this test; it instead guards against the rejected serialized variant, which fails it with two evaluations. | -| `test_watch_arm_login_shell_default_reaches_the_arm_child` (new) | Both branches of the `FM_WATCH_ARM_NO_LOGIN_SHELL` opt-out, for both adapters, via a temp `HOME` whose `.profile` exports a marker the arm child either does or does not observe. | +| `test_watch_arm_login_shell_default_reaches_the_arm_child` (new) | Both branches of the `FM_WATCH_ARM_NO_LOGIN_SHELL` opt-out, for both adapters, via a temp `HOME` whose `.profile` exports a marker the arm child either does or does not observe. Its `login` branch is the one bounded-wait-on-unbounded-cost this change knowingly keeps - see the residual note under cause B. | ## Verification diff --git a/tests/fm-pi-watch-extension.test.sh b/tests/fm-pi-watch-extension.test.sh index 871974c0fe5..5abeae320c2 100755 --- a/tests/fm-pi-watch-extension.test.sh +++ b/tests/fm-pi-watch-extension.test.sh @@ -50,9 +50,14 @@ export NODE_NO_WARNINGS=1 # only reach node through PATH additions a profile makes). The export below # therefore holds for every case in this file, so their timed windows measure # readiness-detection logic rather than profile sourcing - the one exception is -# test_watch_arm_login_shell_default_reaches_the_arm_child below, which owns no -# readiness window and overrides the variable per invocation to exercise BOTH -# branches, including the production default. +# test_watch_arm_login_shell_default_reaches_the_arm_child below, which +# overrides the variable per invocation to exercise BOTH branches, including the +# production default. That case owns no ADAPTER readiness window (neither +# adapter awaits arm readiness on the path it drives), but it does own a 10s +# wait of its own for the arm child to record itself, so its login branch is the +# one place in this suite that still times an unbounded profile-sourcing cost. +# That is inherent to what it verifies, not an oversight; see the note on its +# wait below. export FM_WATCH_ARM_NO_LOGIN_SHELL=1 install_pi_watch_extension_fixture() { @@ -1702,6 +1707,11 @@ writeFileSync(`${process.env.FM_HOME}/state/.lock`, `${process.pid}\n`); await hooks.event({ event: { type: "session.idle", properties: { sessionID: "session-test" } } }); const markerLogged = () => existsSync(process.env.FM_ARM_LOG) && /^marker=\S+\n/m.test(readFileSync(process.env.FM_ARM_LOG, "utf8")); +// A bounded wait on an inherently unbounded cost, which this one case cannot +// avoid: it exists to exercise the real production default rather than the +// opt-out, so its login branch must pay whatever /etc/profile costs here. The +// 10s bound sits well above the ~1740ms worst case measured for a loaded +// `bash -lc` start, but no bound can be a hard guarantee on every machine. for (let i = 0; i < 500 && !markerLogged(); i += 1) { await new Promise((resolve) => setTimeout(resolve, 20)); } @@ -1740,6 +1750,11 @@ if (!handler) { await handler("", { ui: { notify() {} } }); const markerLogged = () => existsSync(process.env.FM_ARM_LOG) && /^marker=\S+\n/m.test(readFileSync(process.env.FM_ARM_LOG, "utf8")); +// A bounded wait on an inherently unbounded cost, which this one case cannot +// avoid: it exists to exercise the real production default rather than the +// opt-out, so its login branch must pay whatever /etc/profile costs here. The +// 10s bound sits well above the ~1740ms worst case measured for a loaded +// `bash -lc` start, but no bound can be a hard guarantee on every machine. for (let i = 0; i < 500 && !markerLogged(); i += 1) { await new Promise((resolve) => setTimeout(resolve, 20)); } From 62b37d5b9338a410a5202bd4bc2e9c0a5bbd5fc5 Mon Sep 17 00:00:00 2001 From: joliverMI Date: Wed, 19 Aug 2026 15:39:00 -0400 Subject: [PATCH 07/11] no-mistakes(review): qualify stale readiness-window claim on login-shell test --- tests/fm-pi-watch-extension.test.sh | 9 +++++++-- 1 file changed, 7 insertions(+), 2 deletions(-) diff --git a/tests/fm-pi-watch-extension.test.sh b/tests/fm-pi-watch-extension.test.sh index 5abeae320c2..d831a7c9cc2 100755 --- a/tests/fm-pi-watch-extension.test.sh +++ b/tests/fm-pi-watch-extension.test.sh @@ -1660,8 +1660,13 @@ EOF # through PATH additions the account's profile makes, so an arm child spawned # without the login shell would die at exec on such a machine. A temp HOME whose # .profile exports a marker makes "did the arm child inherit the profile" -# directly observable, and this case owns no readiness window, so paying the -# profile cost here costs the timed cases nothing. +# directly observable. This case owns no ADAPTER readiness window - neither +# adapter awaits arm readiness on the path it drives - so paying the profile +# cost here costs the other cases' timed windows nothing. It does own a 10s +# wait of its own for the arm child to record itself, which makes its login +# branch the one place left in this suite that times an unbounded +# profile-sourcing cost; that is inherent to verifying the production default, +# and the wait below says so where it happens. test_watch_arm_login_shell_default_reaches_the_arm_child() { local repo home oshome plugin ext log envprefix expected out status mode repo="$TMP_ROOT/login-shell-root" From a15d993f28e7b2363af5e73a0362ecc0d1ef8f49 Mon Sep 17 00:00:00 2001 From: joliverMI Date: Wed, 19 Aug 2026 15:47:19 -0400 Subject: [PATCH 08/11] no-mistakes(review): correct stale readiness-budget claims in suite header --- tests/fm-pi-watch-extension.test.sh | 12 +++++++++--- 1 file changed, 9 insertions(+), 3 deletions(-) diff --git a/tests/fm-pi-watch-extension.test.sh b/tests/fm-pi-watch-extension.test.sh index d831a7c9cc2..4242682f74a 100755 --- a/tests/fm-pi-watch-extension.test.sh +++ b/tests/fm-pi-watch-extension.test.sh @@ -36,9 +36,15 @@ export NODE_NO_WARNINGS=1 # run yet, and the row it should have recorded was lost - which is a lost # FIXTURE observation, not a behaviour change: the extension still made every # bounded attempt and still delivered the typed restoration failure. That is -# what made these cases fail intermittently on CI runners. The budget must stay -# well above a loaded login-shell start; the cases are otherwise unchanged, and -# an arm that IS ready still settles immediately rather than waiting it out. +# what made these cases fail intermittently on CI runners. The export below +# removes that cost from this suite entirely, so the budget no longer has to +# cover a login-shell start at all - it only has to cover the extension's own +# readiness-detection logic, and main's 2000ms is generous headroom for that +# rather than a figure this suite still depends on. This change neither raises +# nor lowers it. The four cases are also no longer left to that budget alone: +# each now waits on the observable arm-row count, then on a bounded wait for the +# wake prompt, then re-reads the log after a settle delay. An arm that IS ready +# still settles immediately rather than waiting the budget out. # That login-shell cost is real, but it is also the ONLY unbounded part of the # budget: /etc/profile and /etc/profile.d run whatever a given machine's From 9c678041e38d0a419a63dc9ad6e56ae80685ad29 Mon Sep 17 00:00:00 2001 From: joliverMI Date: Wed, 19 Aug 2026 17:00:14 -0400 Subject: [PATCH 09/11] no-mistakes(test): correct stale login-shell contention figures in determinism proof --- docs/arm-readiness-determinism-proof.md | 22 ++++++++++++++++++++-- tests/fm-pi-watch-extension.test.sh | 18 ++++++++++++------ 2 files changed, 32 insertions(+), 8 deletions(-) diff --git a/docs/arm-readiness-determinism-proof.md b/docs/arm-readiness-determinism-proof.md index 534c908d951..f76f45d5346 100644 --- a/docs/arm-readiness-determinism-proof.md +++ b/docs/arm-readiness-determinism-proof.md @@ -26,7 +26,12 @@ At the time of the diagnosis the case slept a fixed 120ms between starting the f That await drains the in-flight attempt before the flip: both callers now evaluate the *same* foreign lock, and caller 1's `finally` clears `launchInFlight` in an earlier microtask than caller 2's resumption, so the flip is always evaluated by a fresh attempt. The consequence is narrow and is only about which artifact can serve as the witness. Cause A is real, was demonstrated when it was diagnosed, and is fixed here; what this branch's inherited test can no longer do is re-demonstrate it, which is why the race is instead pinned by a new test built for exactly that purpose - `test_opencode_primary_watch_plugin_requires_session_lock`'s `ps`-shim rewrite, which forces the lock to change while a caller is pinned mid-evaluation. -None of this reassigns the lock assertion to cause B: its pre-change wait was a 5s budget against a `bash -lc` start measured at ~1150ms and at most ~1740ms, so unlike the two Pi cases below it had ample headroom and cause B is not what was failing it. +The lock assertion still belongs to cause A, but on the reproduction above rather than on a budget-headroom argument. +An earlier draft of this record also excluded cause B from it by arguing that its pre-change 5s wait had ample headroom over a `bash -lc` start of ~1150ms (at most ~1740ms). +That figure was inherited from `main`'s comment rather than re-measured at this record's own load level, and it understates this host. +Re-measured at the same 5x oversubscription the loaded phase below uses (160 busy loops on 32 cores, 1-minute load average ~151, 30 samples), a loaded `bash -lc true` is min 1096ms, median ~1620ms, max 4246ms, with two samples above 3.9s; idle matches `main`'s reading at ~131ms median. +Against a real 4246ms worst case a 5s budget leaves ~18% headroom, not ample, so that secondary exclusion is withdrawn: budget arithmetic cannot rule cause B out as a contributor to the lock assertion. +It does not need to. The attribution rests on the direct reproduction - reverting the `ensureArm` fix fails that assertion deterministically - and cause B is not what the fix for it addresses. **Cause B - the test measured something it did not intend to.** Both adapters spawn their arm child through `bash -lc`. @@ -35,13 +40,14 @@ That unbounded, machine-specific, load-dependent cost sat inside the tight readi One residual instance of this shape survives, deliberately, in exactly one case. `test_watch_arm_login_shell_default_reaches_the_arm_child` exists to verify that the production default still reaches the arm child, so its `login` branch must pay the real `/etc/profile` cost and then wait a bounded 10s for the marker row - a bounded wait on an unbounded cost, which is the very shape the rest of this change removes. -It cannot be removed there without defeating what the case verifies; the bound is sized well above the ~1740ms worst case measured above, but it is a headroom argument rather than a guarantee, and it applies to that one case only. +It cannot be removed there without defeating what the case verifies; the bound is ~2.4x the 4246ms worst case re-measured above, but it is a headroom argument rather than a guarantee, and it applies to that one case only. ## Base state (already on `main` before this change) `main` independently raised `FM_PI_ARM_READY_TIMEOUT_MS` / `FM_OPENCODE_ARM_READY_TIMEOUT_MS` from 250ms to 2000ms and rewrote `test_pi_session_transition_generation_owner`'s fixture to write its arm-log row before the pid-file row that its waiters gate on, both landed independently of this change. `882004e` on `main` also replaced the lock test's fixed 120ms sleep with a direct `coordinator.ensureArmed(...)` await, again independently of this change; that is what stops this branch's inherited copy of that case from reconstructing cause A, as described above. None of those addresses cause A: `ensureArm` still reused an in-flight attempt's result unconditionally, and its own comment on the timeout raise records a measured worst case of ~1740ms against the new 2000ms budget under contention - narrower headroom, not a removed confound. +The re-measurement above sharpens that second point rather than softening it: at 4246ms the loaded worst case sits *above* the raised 2000ms budget outright, so the raise narrowed the confound without removing it, which is what the opt-out below does instead. This change does not touch any of those base fixes and does not re-litigate the timeout value; all are kept exactly as `main` has them. ## What this change adds @@ -93,3 +99,15 @@ Two regression tests were added inside the arm-readiness suite itself; the exist | Total | | **40/40** | No run was short of clean, and no assertion failed in either phase. + +### Independent checks run against the same tree and host + +- **Pre-change baseline control.** The base commit's copy of the suite (`git show 45bd292:tests/fm-pi-watch-extension.test.sh`) was run on this same tree and host to confirm the red behaviour is reproducible here at all: **0/10 passed under the 5x load above**, and **3/12 passed at 1.5x load** (48 busy loops, 1-minute load average ~51). + That reproduces the reported flakiness - a different assertion failing per run - but with one nuance worth stating rather than glossing: on this host the load exposed a *different subset* of the suite than the four assertions in the original report. + The four that failed across those 22 baseline runs were `Pi redundant tool call must remain an ownership-based no-op with repair-only guidance` (8 runs), `Pi established clean closes must honor the continuity retry limit` (5), `OpenCode established clean closes must honor the continuity retry limit` (4), and `Pi extension must surface an external healthy watcher as an owned-wake failure` (2). + So this is evidence that the pre-change suite is load-sensitive on this host and that the post-change suite is not; it is not a re-observation of the four originally-reported assertions specifically, and the cause attributions above do not rest on it. +- **Each regression-table claim reproduced by reverting its fix.** Every "fails against" claim in the table above was checked by reverting that one fix in turn, confirming the expected failure, then restoring and confirming the suite clean again, rather than by inspection: + - pre-change unconditional `ensureArm` in-flight reuse - `test_opencode_primary_watch_plugin_requires_session_lock` fails on its 20s settling guard with "the reacquired-lock arm attempt never settled", while `test_opencode_watch_arm_coalesces_callers_on_an_unchanged_lock` still passes, confirming the coalescing case does not itself catch cause A; + - the rejected fully-serialized variant - the lock case deadlocks on the same guard and the coalescing case fails with "two callers on an unchanged lock must share one evaluation, got 2"; + - the `child.stdin.on("error")` EPIPE guard removed from `.opencode/plugins/lib/fm-operational-input.js` - the host node process dies with an unhandled EPIPE and `test_adapter_surfaces_encoder_exit_instead_of_killing_the_host` reports the host as dead. +- **Login-shell cost re-measurement.** The loaded `bash -lc` figure the residual-bound argument cites was re-measured here rather than inherited; see the numbers under cause A above. diff --git a/tests/fm-pi-watch-extension.test.sh b/tests/fm-pi-watch-extension.test.sh index 4242682f74a..4d59bf4d77d 100755 --- a/tests/fm-pi-watch-extension.test.sh +++ b/tests/fm-pi-watch-extension.test.sh @@ -29,8 +29,12 @@ export NODE_NO_WARNINGS=1 # .opencode/plugins/fm-primary-watch-arm.js - and both default that flag to # `-lc`, a LOGIN shell, so an arm left on that default pays for /etc/profile and # /etc/profile.d before the fixture's fm-watch-arm.sh runs its first line. -# Measured on this repo's own dev host: `bash -lc true` is ~140ms idle and -# ~1150ms (max 1740ms) under CPU contention, against ~1ms for `bash -c true`. +# Measured on this repo's own dev host: `bash -lc true` is ~131ms idle (min +# 129ms / max 140ms over 20 samples). Under CPU contention it was re-measured +# at 5x oversubscription (160 busy loops on 32 cores, 1-minute load average +# ~151, 30 samples): min 1096ms, median ~1620ms, max 4246ms. Those loaded +# figures supersede an earlier ~1150ms (max 1740ms) reading taken at an +# unrecorded load level. `bash -c true` is ~1ms idle and 4-20ms loaded. # The earlier 250ms budget therefore expired BEFORE the successor arm had # appended its `arm=` row, the extension SIGTERMed a process that had not # run yet, and the row it should have recorded was lost - which is a lost @@ -1721,8 +1725,9 @@ const markerLogged = () => existsSync(process.env.FM_ARM_LOG) // A bounded wait on an inherently unbounded cost, which this one case cannot // avoid: it exists to exercise the real production default rather than the // opt-out, so its login branch must pay whatever /etc/profile costs here. The -// 10s bound sits well above the ~1740ms worst case measured for a loaded -// `bash -lc` start, but no bound can be a hard guarantee on every machine. +// 10s bound is ~2.4x the 4246ms worst case re-measured for a loaded `bash -lc` +// start at 5x CPU oversubscription (median ~1620ms), but no bound can be a +// hard guarantee on every machine. for (let i = 0; i < 500 && !markerLogged(); i += 1) { await new Promise((resolve) => setTimeout(resolve, 20)); } @@ -1764,8 +1769,9 @@ const markerLogged = () => existsSync(process.env.FM_ARM_LOG) // A bounded wait on an inherently unbounded cost, which this one case cannot // avoid: it exists to exercise the real production default rather than the // opt-out, so its login branch must pay whatever /etc/profile costs here. The -// 10s bound sits well above the ~1740ms worst case measured for a loaded -// `bash -lc` start, but no bound can be a hard guarantee on every machine. +// 10s bound is ~2.4x the 4246ms worst case re-measured for a loaded `bash -lc` +// start at 5x CPU oversubscription (median ~1620ms), but no bound can be a +// hard guarantee on every machine. for (let i = 0; i < 500 && !markerLogged(); i += 1) { await new Promise((resolve) => setTimeout(resolve, 20)); } From 7a47dedae0f1bb525ef2710fd29b4d6e80963761 Mon Sep 17 00:00:00 2001 From: joliverMI Date: Wed, 19 Aug 2026 17:47:56 -0400 Subject: [PATCH 10/11] no-mistakes(document): scope proof-doc timeout raise and idle figure to sources --- docs/arm-readiness-determinism-proof.md | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/docs/arm-readiness-determinism-proof.md b/docs/arm-readiness-determinism-proof.md index f76f45d5346..b66fdad99a5 100644 --- a/docs/arm-readiness-determinism-proof.md +++ b/docs/arm-readiness-determinism-proof.md @@ -29,7 +29,7 @@ Cause A is real, was demonstrated when it was diagnosed, and is fixed here; what The lock assertion still belongs to cause A, but on the reproduction above rather than on a budget-headroom argument. An earlier draft of this record also excluded cause B from it by arguing that its pre-change 5s wait had ample headroom over a `bash -lc` start of ~1150ms (at most ~1740ms). That figure was inherited from `main`'s comment rather than re-measured at this record's own load level, and it understates this host. -Re-measured at the same 5x oversubscription the loaded phase below uses (160 busy loops on 32 cores, 1-minute load average ~151, 30 samples), a loaded `bash -lc true` is min 1096ms, median ~1620ms, max 4246ms, with two samples above 3.9s; idle matches `main`'s reading at ~131ms median. +Re-measured at the same 5x oversubscription the loaded phase below uses (160 busy loops on 32 cores, 1-minute load average ~151, 30 samples), a loaded `bash -lc true` is min 1096ms, median ~1620ms, max 4246ms, with two samples above 3.9s; idle is unchanged, ~131ms median here against the ~140ms `main`'s comment records. Against a real 4246ms worst case a 5s budget leaves ~18% headroom, not ample, so that secondary exclusion is withdrawn: budget arithmetic cannot rule cause B out as a contributor to the lock assertion. It does not need to. The attribution rests on the direct reproduction - reverting the `ensureArm` fix fails that assertion deterministically - and cause B is not what the fix for it addresses. @@ -44,7 +44,7 @@ It cannot be removed there without defeating what the case verifies; the bound i ## Base state (already on `main` before this change) -`main` independently raised `FM_PI_ARM_READY_TIMEOUT_MS` / `FM_OPENCODE_ARM_READY_TIMEOUT_MS` from 250ms to 2000ms and rewrote `test_pi_session_transition_generation_owner`'s fixture to write its arm-log row before the pid-file row that its waiters gate on, both landed independently of this change. +`main` independently raised the `FM_PI_ARM_READY_TIMEOUT_MS` / `FM_OPENCODE_ARM_READY_TIMEOUT_MS` values this suite sets for its unready-arm cases from 250ms to 2000ms - per-case overrides, not the production defaults [`configuration.md`](configuration.md) owns - and rewrote `test_pi_session_transition_generation_owner`'s fixture to write its arm-log row before the pid-file row that its waiters gate on, both landed independently of this change. `882004e` on `main` also replaced the lock test's fixed 120ms sleep with a direct `coordinator.ensureArmed(...)` await, again independently of this change; that is what stops this branch's inherited copy of that case from reconstructing cause A, as described above. None of those addresses cause A: `ensureArm` still reused an in-flight attempt's result unconditionally, and its own comment on the timeout raise records a measured worst case of ~1740ms against the new 2000ms budget under contention - narrower headroom, not a removed confound. The re-measurement above sharpens that second point rather than softening it: at 4246ms the loaded worst case sits *above* the raised 2000ms budget outright, so the raise narrowed the confound without removing it, which is what the opt-out below does instead. From 0ffb6981c61253e4d17adccc62f1a276546a20d6 Mon Sep 17 00:00:00 2001 From: joliverMI Date: Wed, 19 Aug 2026 17:52:24 -0400 Subject: [PATCH 11/11] no-mistakes(document): stamp determinism proof verification at a15d993 with provenance --- docs/arm-readiness-determinism-proof.md | 15 +++++++++++---- 1 file changed, 11 insertions(+), 4 deletions(-) diff --git a/docs/arm-readiness-determinism-proof.md b/docs/arm-readiness-determinism-proof.md index b66fdad99a5..f8593a94c7f 100644 --- a/docs/arm-readiness-determinism-proof.md +++ b/docs/arm-readiness-determinism-proof.md @@ -88,18 +88,25 @@ Two regression tests were added inside the arm-readiness suite itself; the exist - Date: 2026-08-19 - Command: `tests/fm-pi-watch-extension.test.sh`, run consecutively -- Code under proof: this branch's commit, built directly on `main` at `45bd292` +- Code under proof: `a15d993`, this branch's head when the run was taken, on top of `main` at `45bd292` - Host: 32 cores -- Assertions per run: 32 +- Assertions per run: 32, every one of them passing on every run in both phases | Phase | Conditions | Result | |---|---|---| | Idle | 1-minute load average 0.66 at phase start | **20/20 passed, 0 failed** | -| Loaded | 160 busy-loop processes on 32 cores (5x oversubscription), load average climbing to 163 | **20/20 passed, 0 failed** | -| Total | | **40/40** | +| Loaded | 160 busy-loop processes on 32 cores (5x oversubscription), 1-minute load average peaking at 163 | **20/20 passed, 0 failed** | +| Total | | **40/40 passed, 0 failed** | No run was short of clean, and no assertion failed in either phase. +**Why a run stamped at `a15d993` still describes this branch's head.** +`a15d993` already carries every change this branch makes to production code and to test logic, including `5f56cc7`'s rewrite of the four fallback cases onto observable arm-row counts. +Exactly two files have changed since it: this record, and `tests/fm-pi-watch-extension.test.sh` - and that test diff is 18 lines, all of them comment lines (`9c67804`, replacing the inherited `bash -lc` contention figures with the re-measured ones cited under cause A). +No production file changed at all. +So the figures above are deliberately not re-stamped to a later commit: no executable byte under proof differs between `a15d993` and this branch's head, and a fresh run could only exercise the same tree. +Had any test-logic or production change landed after `a15d993`, this section would have required a fresh run rather than a re-dated transcription of these counts. + ### Independent checks run against the same tree and host - **Pre-change baseline control.** The base commit's copy of the suite (`git show 45bd292:tests/fm-pi-watch-extension.test.sh`) was run on this same tree and host to confirm the red behaviour is reproducible here at all: **0/10 passed under the 5x load above**, and **3/12 passed at 1.5x load** (48 busy loops, 1-minute load average ~51).