diff --git a/agents/dewey/work/queue-47/candidate-manifest.sha256 b/agents/dewey/work/queue-47/candidate-manifest.sha256 new file mode 100644 index 00000000..2721c6e8 --- /dev/null +++ b/agents/dewey/work/queue-47/candidate-manifest.sha256 @@ -0,0 +1,6 @@ +dfd9be08c4a31ee536bbcd9bfd8e73cd8baa4114086b55845627ea0c97023e2a agents/dewey/work/queue-47/evidence.md +061ca09644d03690c92b2d09f3b13d407f194fe0b590125692c359d10bace395 packages/conversation/tests/claim.test.mjs +9bb32c730e6fd1d6648ff623cd6ded71cda300ede2d618e28ee6b682626d4d01 packages/conversation/tests/cohort.test.mjs +896f09586916ffdb399b2b5bd04770473a6dd62938d1e9cc0a7e0239f32a36ef packages/conversation/tests/flows.test.mjs +ca003075749dec9368c91f282c8218d602eeb8c6290282a884876be5af2d87e6 packages/conversation/tests/harness.mjs +2ae5d7b8119f29654e1672d1948992be79e973049a50da99250de7ade26b2071 packages/conversation/tests/races.test.mjs diff --git a/agents/dewey/work/queue-47/evidence.md b/agents/dewey/work/queue-47/evidence.md new file mode 100644 index 00000000..9ce925cb --- /dev/null +++ b/agents/dewey/work/queue-47/evidence.md @@ -0,0 +1,127 @@ +# Row 47 (#1533): Mr flows test and the leftover shim + +Dewey, 2026-10-10. Brief: `docs/plans/2026-10-10_s5-follow-up-and-hygiene.md` +§ "S5 follow-up". Base 21e0f1a3. The candidate touches five test files in +`packages/conversation/tests/` and this file. No `src/` file and no README +changes. + +## Mr + +`flows.test.mjs` gains "terminal: a hold inside held input holds again, and +once it is drained later input and Ctrl-C still reach the terminal (Darkwing +note 1 on #1522)". It is the draft in `~/dewey-scratch/s5/mr-test.patch` +unchanged. Under Mr (`holds = this.held !== null;` after the re-parse in +`#run` becomes `holds = false;`) it is the only failing test, 164/165. + +## Why the shim outlived the suite + +- `src/shim.mjs` ignores SIGTERM and SIGHUP (line 188) and exits only on the + `release` op once `engine` reports `populated 0` (line 160). +- No `src/` code sends `release`. `forceStopCohort` (`src/cohort.mjs:150`) + runs term, freeze, members and kill, then returns its proof. Controller + close doesn't release either. So after a force stop the scope stays up + with its shim, reparented to the systemd user manager, until something + SIGKILLs the unit. +- Two claim tests force-stop a scope and leave it: W5's probe fixture + (the traced release run) and W13. Both relied on the file's `after` + hook, whose `reap` sends `systemctl --user kill` and `stop` with a 5 s + timeout and checks neither result. +- On 7ab2f92d with logging added (scratch only, + `~/dewey-scratch/s5/probe-instrumentation.diff`), the W5 probe unit was + `active` from probe close (03:29:14.783Z) to the start of `after` + (03:29:43.671Z), and `inactive` after `reap` (03:29:44.211Z). +- In Filbert's row 41 round 2 gate the shim left running was + `chat03-nWFPcN/f55`, unit `mosaic-chat-cd9f5111af2b95a6b6110b9a1`. That is + the W5 probe: f55 is the probe fixture in claim.test, and the `afterleak` + mutant below leaks the same fixture. The user journal shows it started at + 20:43:51.093 local and never killed. + +Limit of the evidence: that journal has no `mosaic-chat` lines after +20:43:56 local, though W5 ran 33.7 s and passed +(`~/filbert-scratch/s6-logs/gate-r2/node-conversation.txt`). The system +journal isn't readable to me. So I can show the probe was left for `after` +and that `after`'s kill didn't land in that run, but not why the +`systemctl` call missed. + +## The change + +- `harness.mjs`: `liveShims(root)` lists running shims whose socket is + under `root`, from `/proc` cmdline and cgroup. `killShims(root)` SIGKILLs + each one's scope and then the shim by PID. `shimsGone(root, ms)` waits up + to 5 s and returns what is left. `reap(fx)` ends with + `killShims(fx.base)`, so a shim the records don't name, or one the + unchecked `systemctl` calls missed, is still killed. +- `claim.test.mjs`: W5 reaps its probe and W13 reaps its fixture as soon + as they close, not in `after`. +- `cohort.test.mjs` K19: if its own kill or release fails, the `finally` + SIGKILLs the scope before asserting, so a failure doesn't leave the + shim for `after`. +- claim, cohort and races (the files that launch scopes): `after` reaps, + sweeps with `killShims()`, waits with `shimsGone()`, and then asserts + that no shim is left ("no shim outlives this file (#1533)"). A failing + `after` hook fails the file in node:test, with exit 1. Each file also + ends with a test "no shim from this file's tests is left running for the + after hook", which names the test's leak before `after` cleans it up. + `tmp` is per process, so each file checks only its own shims. + +The shim keeps ignoring SIGTERM. That is deliberate (README, force stop: +"so that a stray TERM never drops the scope's anchor"), so the fix is in the +tests that spawn it. + +## Finding for Sage (out of scope, not fixed) + +A force-stopped scope never ends on its own: nothing in `src/` sends +`release`, so its shim and the empty scope stay up until something kills the +unit. In tests that is now handled. In a running controller each force stop +leaves one `mosaic-chat-*.scope` with an idle node shim. This is in +`cohort.mjs`/`controller.mjs`, which the brief puts out of scope, so I +haven't touched it. I recommend a follow-up row: after a proven force stop +(and on close of a stopped binding), send `release`, with a test that the +unit is gone afterwards. + +## Mutation check + +Scratch copies of the working tree, the full conversation suite per mutant +(`~/dewey-scratch/s5/mut-tools/run.sh`). After each run the runner lists +any shim left under the mutant's TMPDIR, then SIGKILLs its scope and PID. + +| Mutant | Change | Result | Shims left after the suite | Killed by | +|---|---|---|---|---| +| base | none | 165/165 | none | (baseline) | +| Mr | `holds = false;` after re-parsing held text | killed, 164/165 | none | terminal: a hold inside held input holds again … | +| noprobe | W5 doesn't reap its probe | killed, 164/165 | none | claim: no shim from this file's tests is left running for the after hook | +| now13 | W13 doesn't reap its fixture | killed, 164/165 | none | the same test | +| afterleak | noprobe, and `after` doesn't reap or sweep | killed, 164 pass, 2 fail | 1 (`mosaic-chat-c719df56e9490f21f5919fe8e`, killed by the runner) | the same test, and the claim file's `after` hook | + +The `afterleak` hook failure: + +``` +✖ .../packages/conversation/tests/claim.test.mjs (5101.703413ms) + AssertionError [ERR_ASSERTION]: no shim outlives this file (#1533) + + [ + + { + + pid: 3106581, + + socket: '/home/jwoltje/dewey-scratch/s5/tmp/chat03-S6WdOu/f55/sock/shim-c719df56e949.sock', + + unit: 'mosaic-chat-c719df56e9490f21f5919fe8e' + + } + + ] + - [] +``` + +That run is the round 2 leak reproduced on purpose: the probe's shim +outlives the suite. With the candidate's `after` hook it can't. + +## Gate + +Sequential, on a detached worktree of 21e0f1a3 with the candidate's test +changes applied (patch sha256 `f57759e0…41df9d`), 03:42:59Z to 03:47:11Z, +output in `~/dewey-scratch/s5/r47-gate/out/`: + +- conversation 165/0, webui 22/0 +- test-auth 15/0, test-conductor 17/0, test-config 24/0, test-discord 66/0, + test-extension-package 18/0, test-foundation 44/0, test-release 14/0, + test-task 98/0 +- test-queue 27/0 (node 148/0). Its canonical-root check skips in a + worktree, as it does in every worktree gate. + +No shim was running after the gate. diff --git a/packages/conversation/tests/claim.test.mjs b/packages/conversation/tests/claim.test.mjs index 65e85fab..c6b29671 100644 --- a/packages/conversation/tests/claim.test.mjs +++ b/packages/conversation/tests/claim.test.mjs @@ -21,14 +21,17 @@ import { bootId } from "../../discord/src/journal.mjs"; import { FakeLauncher } from "./fake-pi.mjs"; import { REPO, FAST, fixture, controllerFor, started, spawnController, killChildren, cleanupAll, reap, claimRecords, - userEntry, assistantEntry, thinkingEntry, receiptState, noUnits, tick, + userEntry, assistantEntry, thinkingEntry, receiptState, noUnits, tick, killShims, shimsGone, } from "./harness.mjs"; const reaped = []; -after(() => { +after(async () => { for (const fx of reaped) reap(fx); + killShims(); + const left = await shimsGone(); killChildren(); cleanupAll(); + assert.deepEqual(left, [], "no shim outlives this file (#1533)"); }); const track = (fx) => (reaped.push(fx), fx); @@ -317,6 +320,8 @@ test("W5: SIGKILL between every publication barrier of release; restart finishes const { ch, mark } = await runRelease(probe); ch.send("close"); await ch.exited; + // The force stop leaves the probe's shim running: nothing sends `release`. + reap(probe); const points = ch.msgs.slice(mark).filter((m) => m.barrier).map((m) => [m.barrier, m.n]); assert.ok(points.some(([b]) => b === "phase-kill")); for (const [name, n] of points) { @@ -434,6 +439,8 @@ test("W13: crash after the engine spawns, before active; restart finds the live c.close(); b.send("close"); await b.exited; + // The force stop leaves the shim running: nothing sends `release`. + reap(fx); }); test("W14: crash after reservation, before the spawn marker: stopped with a no-unit observation; the pair is free", async () => { @@ -705,3 +712,9 @@ test("G3: a fixture path swapped for a live path after construction is refused a rmSync(live, { recursive: true, force: true }); } }); + +// Last in the file. A shim ignores SIGTERM and outlives its controller, so a +// test that leaves one running relies on the after hook's kill (#1533). +test("no shim from this file's tests is left running for the after hook", async () => { + assert.deepEqual(await shimsGone(), [], "a test left its shim running"); +}); diff --git a/packages/conversation/tests/cohort.test.mjs b/packages/conversation/tests/cohort.test.mjs index 6ce979e7..6723c16a 100644 --- a/packages/conversation/tests/cohort.test.mjs +++ b/packages/conversation/tests/cohort.test.mjs @@ -19,11 +19,11 @@ import { Controller, ELIGIBILITY, TEST_ENGINE } from "../src/controller.mjs"; import { ENGINE_ENV, ENGINE_PIN_MISMATCH, engineEnv } from "../src/pi-pin.mjs"; import { FixtureVerifier, newId } from "../src/records.mjs"; import { ControlClient, FakeLauncher } from "./fake-pi.mjs"; -import { FAST, REPO, assistantEntry, claimRecords, cleanupAll, controllerFor, fixture, killChildren, noUnits, reap, receiptState, spawnController, started, tick } from "./harness.mjs"; +import { FAST, REPO, assistantEntry, claimRecords, cleanupAll, controllerFor, fixture, killChildren, killShims, noUnits, reap, receiptState, shimsGone, spawnController, started, tick } from "./harness.mjs"; const reaped = []; const strays = new Set(); -after(() => { +after(async () => { for (const pid of strays) { try { process.kill(pid, "SIGKILL"); @@ -32,8 +32,11 @@ after(() => { } } for (const fx of reaped) reap(fx); + killShims(); + const left = await shimsGone(); killChildren(); cleanupAll(); + assert.deepEqual(left, [], "no shim outlives this file (#1533)"); }); const track = (fx) => (reaped.push(fx), fx); const SCOPE = scopeAvailable(); @@ -735,8 +738,18 @@ test("K19: a scope launched with only the engine environment still reaches the u for (const k of names) assert.ok(ENGINE_ENV.includes(k) || ScopeLauncher.MANAGER_ENV.includes(k) || set.includes(k), k); for (const k of ScopeLauncher.MANAGER_ENV) if (typeof process.env[k] === "string") assert.ok(names.includes(k), k); } finally { - assert.equal((await shimRequest(socketPath, "kill", { timeoutMs: 5000 }, 8000)).ok, true); - assert.equal((await shimRequest(socketPath, "release")).ok, true); + // A failed kill or release still ends the scope here, not in the after hook. + const killed = await shimRequest(socketPath, "kill", { timeoutMs: 5000 }, 8000); + const released = killed.ok ? await shimRequest(socketPath, "release") : killed; + if (!released.ok) spawnSync("systemctl", ["--user", "kill", "--signal=SIGKILL", `${unitName}.scope`], { stdio: "ignore", timeout: 5000 }); await proc.exited; + assert.equal(killed.ok, true, JSON.stringify(killed)); + assert.equal(released.ok, true, JSON.stringify(released)); } }); + +// Last in the file. A shim ignores SIGTERM and outlives its controller, so a +// test that leaves one running relies on the after hook's kill (#1533). +test("no shim from this file's tests is left running for the after hook", async () => { + assert.deepEqual(await shimsGone(), [], "a test left its shim running"); +}); diff --git a/packages/conversation/tests/flows.test.mjs b/packages/conversation/tests/flows.test.mjs index da0677f0..acd84aa3 100644 --- a/packages/conversation/tests/flows.test.mjs +++ b/packages/conversation/tests/flows.test.mjs @@ -703,6 +703,27 @@ test("terminal: input held behind Ctrl-T waits for that takeover while an earlie } }); +test("terminal: a hold inside held input holds again, and once it is drained later input and Ctrl-C still reach the terminal (Darkwing note 1 on #1522)", async () => { + // Ctrl-T, then Ctrl-O inside the text held behind it, then "hi" Enter. The + // drain re-parses the held text, Ctrl-O holds again, and that hold must be + // drained too; otherwise `held` stays set and every later chunk is held + // for good. + for (const chunks of [["\x14", "\x0f", "hi\r"], ["\x14\x0fhi\r"]]) { + const { stub, sent, open } = takeoverStub(); + let quit = false; + const term = new Terminal({ client: stub, onQuit: () => (quit = true) }); + const done = Promise.all(chunks.map((c) => term.key(c))); + open(); + await done; + assert.deepEqual(sent, ["hi"], JSON.stringify(chunks)); + assert.equal(term.held, null, `${JSON.stringify(chunks)}: nothing stays held`); + await term.key("yo\r"); + assert.deepEqual(sent, ["hi", "yo"], `${JSON.stringify(chunks)}: later input runs`); + await term.key("\x03"); + assert.equal(quit, true, `${JSON.stringify(chunks)}: Ctrl-C quits`); + } +}); + test("terminal: an action that throws still releases the input held behind it, in order, then rethrows", async () => { const { stub, sent, open } = takeoverStub(); stub.takeover = async () => { diff --git a/packages/conversation/tests/harness.mjs b/packages/conversation/tests/harness.mjs index 4d6fd199..618d678e 100644 --- a/packages/conversation/tests/harness.mjs +++ b/packages/conversation/tests/harness.mjs @@ -216,4 +216,50 @@ export function reap(fx) { // gone } } + // A shim the records don't name (a direct launch), or one the systemctl + // calls above didn't reach: neither result is checked. + killShims(fx.base); +} + +// The shims under `root` still running, read from /proc. A shim ignores +// SIGTERM and only exits on `release` (src/shim.mjs), and a force stop +// never sends `release`, so a stopped scope stays up until it is killed. +export function liveShims(root = tmp) { + const out = []; + for (const pid of lsdir("/proc").filter((n) => /^\d+$/.test(n))) { + let argv, cgroup; + try { + argv = readFileSync(`/proc/${pid}/cmdline`, "utf8").split("\0"); + if (!argv[1]?.endsWith("/shim.mjs") || argv[2] !== "--socket" || !argv[3]?.startsWith(root + "/")) continue; + cgroup = readFileSync(`/proc/${pid}/cgroup`, "utf8"); + } catch { + continue; // gone + } + const scope = cgroup.trim().split("/").find((s) => s.endsWith(".scope")); + out.push({ pid: Number(pid), socket: argv[3], unit: scope ? scope.slice(0, -".scope".length) : null }); + } + return out; +} + +// SIGKILLs each shim's scope, which takes the engine with it, and the shim +// itself in case the scope kill doesn't land. +export function killShims(root = tmp) { + for (const s of liveShims(root)) { + if (s.unit) spawnSync("systemctl", ["--user", "kill", "--signal=SIGKILL", `${s.unit}.scope`], { stdio: "ignore", timeout: 5000 }); + try { + process.kill(s.pid, "SIGKILL"); + } catch { + // gone + } + } +} + +// Waits up to `ms` for every shim under `root` to go; returns those left. +export async function shimsGone(root = tmp, ms = 5000) { + const end = Date.now() + ms; + for (;;) { + const left = liveShims(root); + if (left.length === 0 || Date.now() >= end) return left; + await tick(50); + } } diff --git a/packages/conversation/tests/races.test.mjs b/packages/conversation/tests/races.test.mjs index e358cdd1..1752fbd5 100644 --- a/packages/conversation/tests/races.test.mjs +++ b/packages/conversation/tests/races.test.mjs @@ -15,13 +15,16 @@ import { EngineLink } from "../src/engine.mjs"; import { newId } from "../src/records.mjs"; import { ControlClient, FakeLauncher } from "./fake-pi.mjs"; import { scopeAvailable } from "../src/cohort.mjs"; -import { controllerFor, started, receiptState, spawnController, killChildren, cleanupAll, reap, fixture, tick } from "./harness.mjs"; +import { controllerFor, started, receiptState, spawnController, killChildren, cleanupAll, reap, fixture, tick, killShims, shimsGone } from "./harness.mjs"; const reaped = []; -after(() => { +after(async () => { for (const fx of reaped) reap(fx); + killShims(); + const left = await shimsGone(); killChildren(); cleanupAll(); + assert.deepEqual(left, [], "no shim outlives this file (#1533)"); }); const track = (fx) => (reaped.push(fx), fx); const SCOPE = scopeAvailable(); @@ -894,3 +897,9 @@ test("H23: requests pending at a restart are not resent; each shows outcome unkn await b.exited; reap(fx); }); + +// Last in the file. A shim ignores SIGTERM and outlives its controller, so a +// test that leaves one running relies on the after hook's kill (#1533). +test("no shim from this file's tests is left running for the after hook", async () => { + assert.deepEqual(await shimsGone(), [], "a test left its shim running"); +});