diff --git a/CHANGELOG.md b/CHANGELOG.md index f8e70d1d1..c59066879 100644 --- a/CHANGELOG.md +++ b/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 diff --git a/docs/ARCHITECTURE.md b/docs/ARCHITECTURE.md index 0cb3415bd..494357e11 100644 --- a/docs/ARCHITECTURE.md +++ b/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). diff --git a/scripts/intervention-forensics.ts b/scripts/intervention-forensics.ts new file mode 100644 index 000000000..7c518f3ee --- /dev/null +++ b/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; + 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; + values: number[]; + thresholds: Set; + 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(); +const outcomes = new Map(); +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}`); + } +} diff --git a/src/subagent/index.test.ts b/src/subagent/index.test.ts index 50a35c05f..4e356be55 100644 --- a/src/subagent/index.test.ts +++ b/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). diff --git a/src/subagent/intervention-log.test.ts b/src/subagent/intervention-log.test.ts new file mode 100644 index 000000000..8299d0cb8 --- /dev/null +++ b/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 { + 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 { + // 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(); + }); +}); diff --git a/src/subagent/intervention-log.ts b/src/subagent/intervention-log.ts new file mode 100644 index 000000000..67f290247 --- /dev/null +++ b/src/subagent/intervention-log.ts @@ -0,0 +1,136 @@ +/** + * Intervention log: one record every time the harness decides a run is stuck. + * + * We ship ~14 stop reasons and ~20 injected-text interventions, and until now + * there was no way to tell how often any of them was wrong. Every threshold in + * the tree was set by judgment, and the tuning history is a record of that not + * working — a grok 6/10 pair reverted as miscalibrated, IDENTICAL_REPEAT_MIN + * moved 4 -> 5 after polling false positives, a grok stall timeout reverted, + * and TURNS_SINCE_USER_MESSAGE_BACKSTOP resting on a justification the code + * itself retracts (CL-6938). + * + * The point of this file is that a threshold change can cite data. Each record + * carries the trigger's *measured value beside its threshold*, the identity of + * the model it fired on, and enough run state to judge afterwards whether the + * run was actually stuck — did it edit files, how far into its budget was it, + * did the parent later succeed on a mutated brief. + * + * Writes are best effort and never block or throw: a diagnostic must not be + * able to fail a run. + */ + +import { appendFile } from "node:fs/promises"; +import { join } from "node:path"; + +import { getLogger } from "@intx/log"; + +import { LOG_NAMESPACE_ROOT } from "../branding.js"; + +export const INTERVENTION_FILE = "interventions.jsonl"; + +/** + * What the harness did. `stop` ends the run, `nudge` injects text and keeps + * running, `block` refuses a parent re-dispatch. `outcome` records what a + * completed dispatch actually produced (a salvage kind or a clean complete), + * independent of any stop/nudge/block — it is the log's real outcome signal: + * a `block` record can be read alongside the `outcome` record(s) for later + * dispatches of the same brief fingerprint to see what, if anything, the + * parent's re-dispatch after a mutated brief actually produced. + */ +export type InterventionClass = "stop" | "nudge" | "block" | "outcome"; + +/** What a completed dispatch produced, for correlating against earlier stops. */ +export interface InterventionOutcome { + /** Salvage kind classified from the report, or "clean-complete" for none. */ + kind: string; + /** Total dispatches of this brief fingerprint so far (including this one). */ + dispatchCount: number; +} + +/** The trigger's measured value beside the threshold it crossed. */ +export interface InterventionMeasurement { + /** What was counted, e.g. "consecutiveIdentical", "silenceMs", "turns". */ + metric: string; + value: number; + /** The threshold the value met, when the trigger has one. */ + threshold?: number; +} + +export interface InterventionRecord { + ts: string; + /** Stable id of the intervention, e.g. "no-progress", "report-forced". */ + id: string; + class: InterventionClass; + /** "leaf" | "orchestrator" — which side of a dispatch fired it. */ + role: string; + provider?: string; + model?: string; + /** Model family the policy resolved, e.g. "grok" | "default". */ + family?: string; + /** task() intent when the run had one. */ + intent?: string; + measurement?: InterventionMeasurement; + /** Present on `class: "outcome"` records only. */ + outcome?: InterventionOutcome; + /** + * Run state at the moment of the decision — the raw material for judging the + * decision later. `editedPaths` is the count of paths the run had already + * written when the trigger fired, recorded so a stop can be weighed against + * what the run had already produced, not treated as proof either way. + */ + state?: { + turnsCompleted?: number; + maxTurns?: number; + totalToolCalls?: number; + readCounts?: number; + editedPaths?: number; + }; + /** Free-form specifics, kept short (a looped window, a refused fingerprint). */ + detail?: string; +} + +/** Fields every record from one run shares, supplied once at construction. */ +export type InterventionContext = Pick< + InterventionRecord, + "role" | "provider" | "model" | "family" | "intent" +>; + +export type InterventionSink = ( + event: Omit, +) => void; + +/** Sink that drops everything — the default, so logging is never required. */ +export const NOOP_INTERVENTION_SINK: InterventionSink = () => {}; + +/** + * Append-only sink over `/interventions.jsonl`. + * + * Appends are fire-and-forget: the caller is a director decision path, and a + * diagnostic write must not add latency to it or fail the run. Ordering within + * a run is preserved by chaining each append onto the previous one. + */ +export function createInterventionLog( + dir: string, + context: InterventionContext, + now: () => Date = () => new Date(), +): InterventionSink { + const path = join(dir, INTERVENTION_FILE); + const log = getLogger(`${LOG_NAMESPACE_ROOT}:intervention-log`); + let tail: Promise = Promise.resolve(); + + return (event) => { + const record: InterventionRecord = { + ts: now().toISOString(), + ...context, + ...event, + }; + const line = `${JSON.stringify(record)}\n`; + tail = tail.then( + () => + appendFile(path, line, "utf8").catch((err: unknown) => { + log.debug?.(`intervention log append failed: ${String(err)}`); + }), + () => undefined, + ); + }; +} diff --git a/src/subagent/nudge-director.ts b/src/subagent/nudge-director.ts index d0c62d26b..0e3edb6e9 100644 --- a/src/subagent/nudge-director.ts +++ b/src/subagent/nudge-director.ts @@ -15,7 +15,13 @@ import type { } from "@intx/types/runtime"; import { createCompactionGovernor, type CompactionGovernor } from "../agent/compaction.js"; import { onTurnBoundary } from "../agent/reactor-events.js"; -import { EMPTY_THRASH_STATE, nextThrashState, type ThrashState } from "./thrash.js"; +import { + DEFAULT_THRASH_CONFIG, + EMPTY_THRASH_STATE, + nextThrashState, + type ThrashState, +} from "./thrash.js"; +import { NOOP_INTERVENTION_SINK, type InterventionSink } from "./intervention-log.js"; import { DEFAULT_SUBAGENT_REPEAT_LIMIT, evaluateSubAgentStop, @@ -119,6 +125,32 @@ export class SubAgentDirector extends DefaultDirector { private lastActivityAt: number; private consecutiveStalls = 0; private lastAssistantText = ""; + // Every stop and nudge is recorded with its measured value beside its + // threshold, so a later threshold change can cite data instead of judgment + // (CL-6938). Defaults to a no-op: logging is diagnostic, never required. + private interventions: InterventionSink = NOOP_INTERVENTION_SINK; + + /** Route this leaf's stop/nudge decisions to an intervention log. */ + observeInterventions(sink: InterventionSink): void { + this.interventions = sink; + } + + /** Run state every intervention record carries, for judging it afterwards. */ + private interventionState(): { + turnsCompleted: number; + maxTurns: number; + totalToolCalls: number; + readCounts: number; + editedPaths: number; + } { + return { + turnsCompleted: this.turnsCompleted, + maxTurns: this.maxTurns, + totalToolCalls: this.thrashState.totalToolCalls, + readCounts: this.thrashState.readCounts.size, + editedPaths: this.thrashState.editedPaths.size, + }; + } constructor( systemPrompt: string, @@ -219,12 +251,24 @@ export class SubAgentDirector extends DefaultDirector { // Tool-less turn after tools, no report envelope. Must not fall through // to super.decide — DefaultDirector completes any tool-less turn. this.incompleteReportNudgeFired = true; + this.interventions({ + id: "incomplete-report", + class: "nudge", + state: this.interventionState(), + detail: "tool-less turn after tools with no report envelope", + }); return [ capabilities.checkpoint("subagent-incomplete-report-nudge"), inferWithSubAgentNudge(capabilities, INCOMPLETE_REPORT_NUDGE), ]; } if (stop === "incomplete-report-stop") { + this.interventions({ + id: "incomplete-report-stop", + class: "stop", + state: this.interventionState(), + detail: "no report envelope after the wrap-up nudge", + }); const terminal: ReactorAction[] = [ capabilities.checkpoint("subagent-incomplete-report"), capabilities.reply(forcedStopReport("incomplete-report", this.lastAssistantText)), @@ -240,6 +284,16 @@ export class SubAgentDirector extends DefaultDirector { // follows once their results land. Turn-budget stays reachable — // this fires once, forceReportWithin turns before the cap. this.pendingNudgeText = REPORT_FORCED_WRAP_UP_NUDGE; + this.interventions({ + id: "report-forced", + class: "nudge", + measurement: { + metric: "turnsRemaining", + value: this.maxTurns - this.turnsCompleted, + threshold: DEFAULT_THRASH_CONFIG.forceReportWithin, + }, + state: this.interventionState(), + }); } else if ( stop === "no-progress" || stop === "turn-budget" || @@ -263,6 +317,20 @@ export class SubAgentDirector extends DefaultDirector { : stop === "turn-budget" ? `${this.turnsCompleted}/${this.maxTurns} turns` : undefined; + this.interventions({ + id: stop, + class: "stop", + measurement: + stop === "no-progress" + ? { + metric: "consecutiveIdentical", + value: this.streak.consecutiveIdentical, + threshold: this.repeatLimit, + } + : { metric: "turnsCompleted", value: this.turnsCompleted, threshold: this.maxTurns }, + state: this.interventionState(), + ...(detail !== undefined ? { detail } : {}), + }); const terminal: ReactorAction[] = [ capabilities.checkpoint(checkpoint), capabilities.reply(forcedStopReport(stop, lastText(content), detail)), @@ -279,6 +347,11 @@ export class SubAgentDirector extends DefaultDirector { if (event.result.isError === true && this.pendingNudgeText !== REPORT_FORCED_WRAP_UP_NUDGE) { // Mandatory wrap-up wins over failed-tool recovery guidance. this.pendingNudgeText = TOOL_FAILURE_RECOVERY_NUDGE; + this.interventions({ + id: "tool-failure-recovery", + class: "nudge", + state: this.interventionState(), + }); } } const base = await super.decide(event, state, capabilities); @@ -317,11 +390,24 @@ export class SubAgentDirector extends DefaultDirector { this.consecutiveStalls++; if (this.consecutiveStalls === 1) { + this.interventions({ + id: "stall-nudge", + class: "nudge", + measurement: { metric: "silenceMs", value: elapsed, threshold: this.stallTimeoutMs }, + state: this.interventionState(), + }); return [ capabilities.checkpoint("subagent-stall-nudge"), inferWithSubAgentNudge(capabilities, SUBAGENT_STALL_NUDGE), ]; } + this.interventions({ + id: "stalled", + class: "stop", + measurement: { metric: "silenceMs", value: elapsed, threshold: this.stallTimeoutMs }, + state: this.interventionState(), + detail: `no activity for ${Math.round(elapsed / 1000)}s after stall nudge`, + }); const terminal: ReactorAction[] = [ capabilities.checkpoint("subagent-stalled"), capabilities.reply( diff --git a/src/subagent/run.ts b/src/subagent/run.ts index 26ac71ab5..4f0c265f4 100644 --- a/src/subagent/run.ts +++ b/src/subagent/run.ts @@ -53,6 +53,11 @@ import { createCompositeBlobReader } from "../agent/lazy-blob-reader.js"; import { buildSubAgentSystemPrompt } from "../agent/prompts.js"; import { shouldApplyGrokAntiThrash } from "./provider-family.js"; import { resolveModelFamilyPolicy } from "../agent/model-family-policy.js"; +import { + createInterventionLog, + NOOP_INTERVENTION_SINK, + type InterventionSink, +} from "./intervention-log.js"; import { normalizeToolDefinitionsForProvider } from "../agent/tool-schema-normalize.js"; import { COMPACTOR_KEEP_RECENT_TURNS, createPruningCompactor } from "../session/compactor.js"; @@ -459,6 +464,9 @@ export async function runSubAgent(params: RunSubAgentParams): Promise { }), }); + // Assigned once the leaf's trace dir exists; the director factory closes + // over this binding and only fires after that point. + let interventions: InterventionSink = NOOP_INTERVENTION_SINK; let agentHandle: Awaited> | null = null; const requestContinuation = (): void => { try { @@ -482,8 +490,8 @@ export async function runSubAgent(params: RunSubAgentParams): Promise { const directorDef = defineDirector({ id: `${ID_PREFIX}/subagent`, configSchema: type({}), - factory: (_config, _env, agentCtx) => - new SubAgentDirector( + factory: (_config, _env, agentCtx) => { + const director = new SubAgentDirector( agentCtx.systemPrompt, normalizeToolDefinitionsForProvider([...agentCtx.toolDefinitions], { providerName: params.provider.providerName, @@ -496,7 +504,12 @@ export async function runSubAgent(params: RunSubAgentParams): Promise { Date.now, params.intent === "implement", shouldRequireEvidence(params), - ), + ); + director.observeInterventions((event) => { + interventions(event); + }); + return director; + }, }); // Directors are pure decide(event, ...) functions with no timer of their @@ -536,6 +549,15 @@ export async function runSubAgent(params: RunSubAgentParams): Promise { const workdir = join(params.workdirBase, "subagents", generateSessionId()); await mkdir(workdir, { recursive: true }); + // One record per stop/nudge, with its measured value beside its threshold, + // written into this leaf's own trace dir (CL-6938). + interventions = createInterventionLog(workdir, { + role: params.orchestrator === true ? "orchestrator" : "leaf", + provider: params.provider.providerName, + model: params.provider.model, + family: modelFamilyPolicy.family, + ...(params.intent !== undefined ? { intent: params.intent } : {}), + }); const def = defineAgent({ id: `${ID_PREFIX}/subagent`, @@ -828,6 +850,20 @@ export async function runSubAgent(params: RunSubAgentParams): Promise { : reason === "deadline" && resolvedDeadlineMs !== undefined ? `${resolvedDeadlineMs}ms elapsed` : abortReasonText(runController.signal); + interventions({ + id: reason, + class: "stop", + ...(repetition.hit !== null + ? { + measurement: { + metric: "repeats", + value: repetition.hit.repeats, + }, + } + : {}), + state: { totalToolCalls: toolNamesUsed.length }, + ...(detail !== undefined ? { detail } : {}), + }); return appendActivitySummary(forcedStopReport(reason, partial, detail), toolNamesUsed); } } diff --git a/src/subagent/task-tool.ts b/src/subagent/task-tool.ts index 7035aff07..f2cc67a65 100644 --- a/src/subagent/task-tool.ts +++ b/src/subagent/task-tool.ts @@ -42,6 +42,7 @@ import { fingerprintTaskBrief, TURN_BUDGET_STOP_AFTER_DISPATCHES, } from "./brief-dispatch.js"; +import { createInterventionLog, type InterventionSink } from "./intervention-log.js"; import { isSubAgentCancelError } from "./dispose.js"; import { cleanupSubAgentWorktree, createSubAgentWorktree, WorktreeError } from "./worktree.js"; import { generateSessionId } from "../session/index.js"; @@ -245,6 +246,22 @@ export function createTaskTool(deps: TaskToolDeps): AgentTool { const telemetry = deps.telemetry ?? NOOP_TELEMETRY; // Session-scoped re-dispatch ledger: one per parent task tool instance. const briefLedger = createBriefDispatchLedger(); + // A refused re-dispatch is the sharpest false-positive signal we have: the + // parent wanted this brief again and the harness said no on the strength of + // an earlier salvage classification (CL-6938). Logged on the parent side + // because no leaf run exists to log it. + let refusalLog: InterventionSink | null = null; + const recordRefusal = (event: Parameters[0]): void => { + refusalLog ??= createInterventionLog(deps.getWorkdirBase(), { role: "parent" }); + refusalLog(event); + }; + // Every completed dispatch gets an outcome record — the log otherwise + // carries shape and run state but never what the run actually produced. + let outcomeLog: InterventionSink | null = null; + const recordOutcome = (kind: string, dispatchCount: number): void => { + outcomeLog ??= createInterventionLog(deps.getWorkdirBase(), { role: "parent" }); + outcomeLog({ id: "dispatch-outcome", class: "outcome", outcome: { kind, dispatchCount } }); + }; return tool({ definition: taskToolDefinition, handler: async (call, signal): Promise => { @@ -560,6 +577,11 @@ export function createTaskTool(deps: TaskToolDeps): AgentTool { }); const admission = briefLedger.admit(fingerprint); if (!admission.ok) { + recordRefusal({ + id: "re-dispatch-refused", + class: "block", + detail: admission.message.slice(0, 300), + }); return taskToolResult(call.id, admission.message); } const dispatchCount = admission.dispatchCount; @@ -727,6 +749,7 @@ export function createTaskTool(deps: TaskToolDeps): AgentTool { (session !== undefined && deps.sessions?.get(session.id)?.status === "cancelled"); const salvage = classifyBriefSalvage(result); briefLedger.recordOutcome(fingerprint, salvage); + recordOutcome(salvage ?? "clean-complete", dispatchCount); const hintOptions = { dispatchCount, turnBudgetStopAfterDispatches: TURN_BUDGET_STOP_AFTER_DISPATCHES,