Log every stop/nudge intervention (CL-6938)

CHANGELOG.md

@@ -15,6 +15,18 @@ parallel copies under `docs/` or `scripts/notes/`. At cut time: rename
 
 ### Agent
 
+- **Every stop and nudge is now logged, and so is what each dispatch produced.**
+  `interventions.jsonl` in the worker's trace dir records each intervention with
+  its measured value beside the threshold it crossed, the model family it fired
+  on, and the run state at that moment — plus refused parent re-dispatches and,
+  now, one outcome record per completed dispatch (the salvage kind or a
+  clean-complete marker, plus the dispatch count). `bun run
+  scripts/intervention-forensics.ts` aggregates them: counts by family, value
+  distribution against threshold, two context columns (stops on runs that had
+  already edited files, stops before half the turn budget — not a measured
+  false-positive rate), and outcome counts by kind. Threshold changes can now
+  cite data instead of judgment.
+
 - **Shell file work counts as evidence.** A worker that edited with `sed -i`, a
   heredoc, or `>` redirection had `editedPaths` empty and salvaged as
   `never-edited` — a sticky hard block that then refused the parent an identical

docs/ARCHITECTURE.md

@@ -152,6 +152,8 @@ Because the operator explicitly wants long autonomous runs to keep going, reachi
 
 `SubAgentDirector` tracks `lastActivityAt`, updated on every real `inference.done` and `tool.done`. Directors are pure `decide(event, ...)` functions with no timer of their own and the reactor has no proactive "idle" event, so a genuinely silent leaf (e.g. parked on a long-running background command with nothing else to do) produces no event for the director to react to. `runSubAgent` (`src/subagent/index.ts`) arms an external interval, at `subAgentStallTimeoutMs`, that pings the same content-less continuation channel the compaction governor uses to re-enter an idle reactor (`requestContinuation`). The director only acts on a ping if the elapsed time since `lastActivityAt` has crossed the timeout — a ping delivered while a tool call is still executing simply queues until that cycle finishes, so "no pending harness-tracked work" falls out of when the check can run at all rather than needing separate bookkeeping. The first stall past the timeout gets one continuation nudge (asking the leaf to check on the background work or report status); a second **consecutive** stall (no activity since that nudge) escalates to the existing salvage path, returning a `stalled` `forcedStopReport` with the same structured shape (summary/findings/blockers) as `no-progress` / `turn-budget` / `thrash` / `never-acted` / `never-edited`. Any real activity between pings resets the streak, so a leaf that is genuinely working through a slow single turn is never penalized.
 
+**Intervention log**: every stop and nudge is appended as one JSONL record to `interventions.jsonl` in the firing leaf's trace dir (`src/subagent/intervention-log.ts`), carrying the trigger's measured value beside the threshold it crossed, the provider/model/family it fired on, and the run state at that moment (turns used vs budget, tool calls, read/edit counts). A refused parent re-dispatch is recorded on the parent side, where no leaf run exists to record it. The parent also appends one `outcome` record per completed dispatch — the salvage kind `classifyBriefSalvage` assigned, or a clean-complete marker, plus the dispatch count — so the log carries dispatch outcomes as well as interventions, and a stop record can later be read alongside what the dispatch it touched actually produced. Writes are fire-and-forget and swallow their own errors — a diagnostic must not be able to fail a run. `scripts/intervention-forensics.ts` aggregates these across local sessions: per-intervention counts by model family, the measured-value distribution against the threshold, two context columns (stops that fired on runs which had already edited files; stops that fired before half the turn budget was spent — neither is a measured false-positive rate, since either is equally consistent with a correct stop or a wrong one), and outcome counts by kind. This exists because every threshold in this tree was set by judgment and four of those judgments were later reverted — a threshold change is expected to cite this data (CL-6938).
+
 **Precedence**: stall detection sits **below** no-progress and turn-budget — those are evaluated from real `inference.done` turns inside `evaluateSubAgentStop` and always take priority; the stall check only ever fires on a continuation ping that inference/tool-result handling did not already consume that cycle. Report-forced (near-budget wrap-up) is an independent one-shot, turn-count-driven signal, not a competing stop reason in the sense no-progress/turn-budget are. Stall nudging is wall-clock driven and likewise independent of both.
 
 The reactor only persists a response turn to `turns.jsonl` on `inference.done`, so a cycle that is cancelled, aborted, errors, or is otherwise interrupted mid-stream would leave nothing behind. A cycle-text recorder (`src/session/stream-journal.ts`) closes that gap by buffering the in-flight cycle's streamed text in memory — no writes on the happy path — and appending one JSON record (`{reason, chars, text}`) to `partial.jsonl`, alongside `turns.jsonl` in the session context dir, on abnormal cycle end. It is wired into the sub-agent run loop, the exec runner (flushed on failed sends), and the TUI runner (flushed on interrupt and on session rotation, before the context dir is repointed).

scripts/intervention-forensics.ts

@@ -0,0 +1,182 @@
+// Aggregate scan over the intervention logs written by src/subagent/intervention-log.ts
+// (~/.corbits/projects/**/interventions.jsonl) — the data that has to exist
+// before any stop/nudge threshold is changed again (CL-6938).
+//
+// Reports, per intervention id: how often it fired, split by model family, with
+// the measured value distribution beside the threshold it crossed, and two
+// context columns. These are NOT a measured false-positive rate — a stop on a
+// run that had already edited files, or one that fired with turn budget still
+// left, is equally consistent with a correct stop or a wrong one:
+//
+//   edited  — stops that fired on a run which had already edited files.
+//   early   — stops that fired before half the turn budget was spent.
+//
+// Also aggregates outcome records (CL-6938): what each completed dispatch
+// actually produced (a salvage kind, or clean-complete), by kind. This is the
+// log's only outcome signal, letting a stop record be read alongside what the
+// dispatch it touched actually produced — it is still not gate-pass or
+// retry-success tracking.
+//
+// Run: bun run scripts/intervention-forensics.ts
+//
+// Prints only aggregate counts and the `detail` field's first token, never turn
+// content, so it is safe to run without pulling trace data into a context window.
+
+import { readdirSync, lstatSync, readFileSync } from "node:fs";
+import { join } from "node:path";
+import { homedir } from "node:os";
+
+import { INTERVENTION_FILE, type InterventionRecord } from "../src/subagent/intervention-log.js";
+
+// lstat, and skip symlinks: session dirs carry a `latest` symlink to a real
+// session, and following it double-counts every record in that session.
+function findAll(dir: string, name: string, out: string[]): void {
+  let entries: string[];
+  try {
+    entries = readdirSync(dir);
+  } catch {
+    return;
+  }
+  for (const entry of entries) {
+    const path = join(dir, entry);
+    let info: ReturnType<typeof lstatSync>;
+    try {
+      info = lstatSync(path);
+    } catch {
+      continue;
+    }
+    if (info.isSymbolicLink()) continue;
+    if (info.isDirectory()) findAll(path, name, out);
+    else if (entry === name) out.push(path);
+  }
+}
+
+function percentile(sorted: readonly number[], p: number): number {
+  if (sorted.length === 0) return 0;
+  const index = Math.min(sorted.length - 1, Math.floor((p / 100) * sorted.length));
+  return sorted[index]!;
+}
+
+interface Bucket {
+  count: number;
+  byFamily: Map<string, number>;
+  values: number[];
+  thresholds: Set<number>;
+  editedWork: number;
+  earlyBudget: number;
+}
+
+function emptyBucket(): Bucket {
+  return {
+    count: 0,
+    byFamily: new Map(),
+    values: [],
+    thresholds: new Set(),
+    editedWork: 0,
+    earlyBudget: 0,
+  };
+}
+
+const root = join(homedir(), ".corbits", "projects");
+const files: string[] = [];
+findAll(root, INTERVENTION_FILE, files);
+
+const buckets = new Map<string, Bucket>();
+const outcomes = new Map<string, number>();
+let records = 0;
+let malformed = 0;
+
+for (const file of files) {
+  let lines: string[];
+  try {
+    lines = readFileSync(file, "utf8").split("\n");
+  } catch {
+    continue;
+  }
+  for (const line of lines) {
+    if (line.trim().length === 0) continue;
+    let record: InterventionRecord;
+    try {
+      record = JSON.parse(line) as InterventionRecord;
+    } catch {
+      malformed++;
+      continue;
+    }
+    if (typeof record.id !== "string") {
+      malformed++;
+      continue;
+    }
+    records++;
+    if (record.class === "outcome" && record.outcome !== undefined) {
+      const kind = record.outcome.kind;
+      outcomes.set(kind, (outcomes.get(kind) ?? 0) + 1);
+      continue;
+    }
+    const key = `${record.class ?? "?"}/${record.id}`;
+    let bucket = buckets.get(key);
+    if (bucket === undefined) {
+      bucket = emptyBucket();
+      buckets.set(key, bucket);
+    }
+    bucket.count++;
+    const family = record.family ?? record.model ?? "unknown";
+    bucket.byFamily.set(family, (bucket.byFamily.get(family) ?? 0) + 1);
+    if (record.measurement !== undefined) {
+      bucket.values.push(record.measurement.value);
+      if (record.measurement.threshold !== undefined) {
+        bucket.thresholds.add(record.measurement.threshold);
+      }
+    }
+    const state = record.state;
+    if (record.class === "stop" && state !== undefined) {
+      if ((state.editedPaths ?? 0) > 0) bucket.editedWork++;
+      const turns = state.turnsCompleted ?? 0;
+      const max = state.maxTurns ?? 0;
+      if (max > 0 && turns < max / 2) bucket.earlyBudget++;
+    }
+  }
+}
+
+console.log(`intervention logs: ${files.length}`);
+console.log(`records: ${records}${malformed > 0 ? ` (${malformed} malformed, skipped)` : ""}`);
+if (records === 0) {
+  console.log("\nNo interventions logged yet. Run some sessions first.");
+  process.exit(0);
+}
+
+const rows = [...buckets.entries()].sort((a, b) => b[1].count - a[1].count);
+console.log(
+  "\nintervention                       n   value p50/p90/max   threshold  edited  early",
+);
+for (const [key, bucket] of rows) {
+  const sorted = [...bucket.values].sort((a, b) => a - b);
+  const dist =
+    sorted.length === 0
+      ? "-"
+      : `${percentile(sorted, 50)}/${percentile(sorted, 90)}/${sorted[sorted.length - 1]!}`;
+  const thresholds = bucket.thresholds.size === 0 ? "-" : [...bucket.thresholds].join(",");
+  console.log(
+    `${key.padEnd(33)} ${String(bucket.count).padStart(3)}   ${dist.padEnd(16)} ${thresholds.padEnd(10)} ${String(bucket.editedWork).padStart(5)}  ${String(bucket.earlyBudget).padStart(5)}`,
+  );
+}
+
+console.log("\nby family");
+for (const [key, bucket] of rows) {
+  const families = [...bucket.byFamily.entries()]
+    .sort((a, b) => b[1] - a[1])
+    .map(([family, count]) => `${family}=${count}`)
+    .join(" ");
+  console.log(`${key.padEnd(33)} ${families}`);
+}
+
+console.log(
+  "\nedited = stops on runs that had already edited files; early = stops before half the turn budget (context, not a false-positive rate).",
+);
+
+if (outcomes.size > 0) {
+  console.log("\ndispatch outcomes");
+  const outcomeRows = [...outcomes.entries()].sort((a, b) => b[1] - a[1]);
+  for (const [kind, count] of outcomeRows) {
+    console.log(`${kind.padEnd(20)} ${count}`);
+  }
+}

src/subagent/index.test.ts

@@ -1121,6 +1121,42 @@ describe("SubAgentDirector report-forced wiring", () => {
     return Array.isArray(result) ? result : [result];
   }
 
+  test("stops and nudges are recorded with their measured value and threshold (CL-6938)", async () => {
+    const director = new SubAgentDirector("system", [], undefined, 3);
+    const capabilities = makeCapabilities();
+    const recorded: { id: string; class: string; value?: number; threshold?: number }[] = [];
+    director.observeInterventions((event) => {
+      recorded.push({
+        id: event.id,
+        class: event.class,
+        ...(event.measurement !== undefined
+          ? {
+              value: event.measurement.value,
+              ...(event.measurement.threshold !== undefined
+                ? { threshold: event.measurement.threshold }
+                : {}),
+            }
+          : {}),
+      });
+    });
+
+    // Turn 1 of 3 fires report-forced (a nudge); repeating one identical call
+    // to the repeat limit then fires no-progress (a stop).
+    for (let i = 0; i < 6; i++) {
+      await director.decide(
+        makeInferenceDoneEvent([{ id: "r1", name: "read_file", args: { path: "a.ts" } }]),
+        mockState,
+        capabilities,
+      );
+    }
+
+    const nudge = recorded.find((r) => r.id === "report-forced");
+    expect(nudge?.class).toBe("nudge");
+    const stop = recorded.find((r) => r.id === "no-progress");
+    expect(stop?.class).toBe("stop");
+    expect(stop?.value).toBeGreaterThanOrEqual(stop?.threshold ?? 0);
+  });
+
   // maxTurns=3, forceReportWithin (default 2) → report-forced fires exactly
   // at turnsCompleted===1, leaving turns 2 and 3 for turn-budget to remain
   // reachable (regression for the report-forced turn-budget blocker).

src/subagent/intervention-log.test.ts

@@ -0,0 +1,94 @@
+import { describe, expect, test } from "bun:test";
+import { mkdtemp, readFile } from "node:fs/promises";
+import { tmpdir } from "node:os";
+import { join } from "node:path";
+
+import {
+  createInterventionLog,
+  INTERVENTION_FILE,
+  NOOP_INTERVENTION_SINK,
+  type InterventionRecord,
+} from "./intervention-log.js";
+
+async function readRecords(dir: string): Promise<InterventionRecord[]> {
+  const raw = await readFile(join(dir, INTERVENTION_FILE), "utf8");
+  return raw
+    .split("\n")
+    .filter((line) => line.trim().length > 0)
+    .map((line) => JSON.parse(line) as InterventionRecord);
+}
+
+async function flush(): Promise<void> {
+  // Appends are fire-and-forget; yield until the chained writes settle.
+  for (let i = 0; i < 20; i++) await Promise.resolve();
+  await new Promise((resolve) => setTimeout(resolve, 10));
+}
+
+describe("intervention log (CL-6938)", () => {
+  test("records carry the shared context, the measurement, and the run state", async () => {
+    const dir = await mkdtemp(join(tmpdir(), "intervention-log-"));
+    const sink = createInterventionLog(
+      dir,
+      {
+        role: "leaf",
+        provider: "xai",
+        model: "grok-4.6",
+        family: "grok",
+        intent: "implement",
+      },
+      () => new Date("2026-08-23T12:00:00.000Z"),
+    );
+
+    sink({
+      id: "no-progress",
+      class: "stop",
+      measurement: { metric: "consecutiveIdentical", value: 5, threshold: 5 },
+      state: { turnsCompleted: 7, maxTurns: 30, editedPaths: 2 },
+      detail: "identical tool call × 5",
+    });
+    await flush();
+
+    const [record] = await readRecords(dir);
+    expect(record).toBeDefined();
+    expect(record?.ts).toBe("2026-08-23T12:00:00.000Z");
+    expect(record?.id).toBe("no-progress");
+    expect(record?.class).toBe("stop");
+    expect(record?.family).toBe("grok");
+    expect(record?.intent).toBe("implement");
+    expect(record?.measurement).toEqual({
+      metric: "consecutiveIdentical",
+      value: 5,
+      threshold: 5,
+    });
+    // The false-positive proxy the forensics script reads: a stop that fired on
+    // a run which had already edited files.
+    expect(record?.state?.editedPaths).toBe(2);
+  });
+
+  test("appends in order, one JSON object per line", async () => {
+    const dir = await mkdtemp(join(tmpdir(), "intervention-log-"));
+    const sink = createInterventionLog(dir, { role: "leaf" });
+    sink({ id: "report-forced", class: "nudge" });
+    sink({ id: "turn-budget", class: "stop" });
+    await flush();
+
+    const records = await readRecords(dir);
+    expect(records.map((r) => r.id)).toEqual(["report-forced", "turn-budget"]);
+  });
+
+  test("a write failure never throws into the caller", async () => {
+    const sink = createInterventionLog(join(tmpdir(), "intervention-log-missing-dir-xyz"), {
+      role: "leaf",
+    });
+    expect(() => {
+      sink({ id: "stalled", class: "stop" });
+    }).not.toThrow();
+    await flush();
+  });
+
+  test("the no-op sink accepts events and writes nothing", () => {
+    expect(() => {
+      NOOP_INTERVENTION_SINK({ id: "no-progress", class: "stop" });
+    }).not.toThrow();
+  });
+});