diff --git a/.claude-plugin/plugin.json b/.claude-plugin/plugin.json index 22e565a..b4648de 100644 --- a/.claude-plugin/plugin.json +++ b/.claude-plugin/plugin.json @@ -1,6 +1,6 @@ { "name": "allium", - "version": "3.13.0", + "version": "3.14.0", "description": "Velocity through clarity.", "author": { "name": "JUXT", diff --git a/.codex-plugin/plugin.json b/.codex-plugin/plugin.json index e8a6c3f..b44b980 100644 --- a/.codex-plugin/plugin.json +++ b/.codex-plugin/plugin.json @@ -1,6 +1,6 @@ { "name": "allium", - "version": "3.13.0", + "version": "3.14.0", "description": "Velocity through clarity.", "author": { "name": "JUXT", diff --git a/hooks/hooks.json b/hooks/hooks.json index 754294d..6cfd443 100644 --- a/hooks/hooks.json +++ b/hooks/hooks.json @@ -1,5 +1,16 @@ { "hooks": { + "PreToolUse": [ + { + "matcher": "Task|Agent", + "hooks": [ + { + "type": "command", + "command": "node \"${CLAUDE_PLUGIN_ROOT}/hooks/loop-trace.mjs\" pre" + } + ] + } + ], "PostToolUse": [ { "matcher": "Write|Edit", @@ -9,6 +20,15 @@ "command": "node \"${CLAUDE_PLUGIN_ROOT}/hooks/allium-check.mjs\"" } ] + }, + { + "matcher": "Task|Agent", + "hooks": [ + { + "type": "command", + "command": "node \"${CLAUDE_PLUGIN_ROOT}/hooks/loop-trace.mjs\" post" + } + ] } ] } diff --git a/hooks/loop-trace.mjs b/hooks/loop-trace.mjs new file mode 100644 index 0000000..f666bad --- /dev/null +++ b/hooks/loop-trace.mjs @@ -0,0 +1,131 @@ +// Records real per-subagent-call timing into the Allium loop's trace. +// +// Registered twice in hooks.json, matched to the subagent tool: +// PreToolUse → node loop-trace.mjs pre (stamp the call's start) +// PostToolUse → node loop-trace.mjs post (write duration on return) +// +// Timing has to be captured outside the model — a subagent call isn't a Bash +// call the model can wrap in `date`, and the model can't read its own latency. +// A hook fires on the tool events, so it can. It writes one line per call to +// .allium-loop/timings.jsonl; the loop folds those durations into its trace and +// report (driving-the-loop §13). The model's trajectory + routing telemetry is +// the cross-harness baseline; this hook is the deterministic timing layer where +// hooks run (Claude Code and other editors that honour them). +// +// It only records while a loop is active (a .allium-loop/ dir exists), never +// blocks a call (always exits 0), and swallows its own errors. + +import { + existsSync, + readFileSync, + writeFileSync, + appendFileSync, + realpathSync, +} from "fs"; +import path from "path"; + +process.on("uncaughtException", () => process.exit(0)); + +const event = process.argv[2]; // "pre" | "post" +if (event !== "pre" && event !== "post") process.exit(0); + +let data = ""; +for await (const chunk of process.stdin) data += chunk; + +let input; +try { + input = JSON.parse(data); +} catch { + process.exit(0); +} + +// The subagent's type is the useful label ("allium:weed"). Field placement +// varies by harness, so look in the likely spots; fall back to the tool name. +const toolInput = input.tool_input ?? input.tool_info ?? {}; +const agent = + toolInput.subagent_type ?? + toolInput.subagentType ?? + toolInput.agent ?? + input.tool_name ?? + input.tool ?? + "subagent"; + +// A correlation id pairs a pre with its post. If the harness doesn't provide +// one, fall back to FIFO, which is correct for the sequential phase calls the +// loop makes (a documented limitation under parallel calls). +const corrId = + input.tool_use_id ?? input.toolUseId ?? toolInput.id ?? null; + +// Resolve the project root the same way the allium-check hook does. +const payloadRoots = Array.isArray(input.workspace_roots) ? input.workspace_roots : []; +const roots = [process.env.CLAUDE_PROJECT_ROOT, ...payloadRoots].filter(Boolean); +if (roots.length === 0) roots.push(process.cwd()); + +let projectRoot = null; +for (const r of roots) { + try { + projectRoot = realpathSync(r); + break; + } catch { + // try the next root + } +} +if (!projectRoot) process.exit(0); + +// Only trace while a loop is running; otherwise this is an unrelated subagent. +const loopDir = path.join(projectRoot, ".allium-loop"); +if (!existsSync(loopDir)) process.exit(0); + +const pendingPath = path.join(loopDir, ".timing-pending.json"); +const timingsPath = path.join(loopDir, "timings.jsonl"); +const now = Date.now(); + +function readPending() { + try { + const p = JSON.parse(readFileSync(pendingPath, "utf-8")); + return { byId: p.byId ?? {}, fifo: Array.isArray(p.fifo) ? p.fifo : [] }; + } catch { + return { byId: {}, fifo: [] }; + } +} +function writePending(p) { + try { + writeFileSync(pendingPath, JSON.stringify(p)); + } catch { + // best-effort + } +} + +if (event === "pre") { + const p = readPending(); + if (corrId) p.byId[corrId] = { start: now, agent }; + else p.fifo.push({ start: now, agent }); + writePending(p); + process.exit(0); +} + +// event === "post" +const p = readPending(); +let rec = null; +if (corrId && p.byId[corrId]) { + rec = p.byId[corrId]; + delete p.byId[corrId]; +} else if (p.fifo.length > 0) { + rec = p.fifo.shift(); +} +writePending(p); + +if (rec) { + const line = + JSON.stringify({ + ts: new Date(now).toISOString(), + agent: rec.agent, + duration_ms: now - rec.start, + }) + "\n"; + try { + appendFileSync(timingsPath, line); + } catch { + // best-effort + } +} +process.exit(0); diff --git a/hooks/loop-trace.test.mjs b/hooks/loop-trace.test.mjs new file mode 100644 index 0000000..1828ded --- /dev/null +++ b/hooks/loop-trace.test.mjs @@ -0,0 +1,98 @@ +import { execFileSync } from "child_process"; +import { mkdtempSync, mkdirSync, readFileSync, existsSync, rmSync } from "fs"; +import path from "path"; +import { tmpdir } from "os"; + +const hook = new URL("./loop-trace.mjs", import.meta.url).pathname; +let passed = 0; +let failed = 0; + +function assert(name, cond) { + if (cond) { console.log(` pass: ${name}`); passed++; } + else { console.log(` FAIL: ${name}`); failed++; } +} + +// Run the hook once (one event) with a synthetic payload and a project root. +function runHook(event, input, projectRoot) { + try { + execFileSync("node", [hook, event], { + input: JSON.stringify(input), + encoding: "utf-8", + stdio: ["pipe", "pipe", "pipe"], + env: { ...process.env, CLAUDE_PROJECT_ROOT: projectRoot }, + }); + } catch { + // the hook always exits 0; ignore + } +} + +function newProject({ withLoopDir }) { + const dir = mkdtempSync(path.join(tmpdir(), "allium-timing-")); + if (withLoopDir) mkdirSync(path.join(dir, ".allium-loop")); + return dir; +} +function timings(dir) { + const p = path.join(dir, ".allium-loop", "timings.jsonl"); + if (!existsSync(p)) return []; + return readFileSync(p, "utf-8").trim().split("\n").filter(Boolean).map((l) => JSON.parse(l)); +} + +console.log("\n── loop-trace hook ──\n"); + +// 1. pre + post with a correlation id → one timing line, right agent, numeric duration. +{ + const dir = newProject({ withLoopDir: true }); + const payload = { tool_use_id: "abc", tool_name: "Task", tool_input: { subagent_type: "allium:weed" } }; + runHook("pre", payload, dir); + runHook("post", payload, dir); + const t = timings(dir); + assert("records one timing for a paired pre/post", t.length === 1); + assert("labels the timing with the subagent type", t[0]?.agent === "allium:weed"); + assert("duration is a non-negative number", typeof t[0]?.duration_ms === "number" && t[0].duration_ms >= 0); + rmSync(dir, { recursive: true, force: true }); +} + +// 2. No .allium-loop dir → no-op, nothing written. +{ + const dir = newProject({ withLoopDir: false }); + const payload = { tool_use_id: "x", tool_name: "Task", tool_input: { subagent_type: "allium:weed" } }; + runHook("pre", payload, dir); + runHook("post", payload, dir); + assert("does nothing when no loop is active", !existsSync(path.join(dir, ".allium-loop", "timings.jsonl"))); + rmSync(dir, { recursive: true, force: true }); +} + +// 3. FIFO fallback when there is no correlation id: two calls pair in order. +{ + const dir = newProject({ withLoopDir: true }); + runHook("pre", { tool_name: "Task", tool_input: { subagent_type: "allium:distill" } }, dir); + runHook("pre", { tool_name: "Task", tool_input: { subagent_type: "allium:propagate" } }, dir); + runHook("post", { tool_name: "Task", tool_input: {} }, dir); + runHook("post", { tool_name: "Task", tool_input: {} }, dir); + const t = timings(dir); + assert("pairs two unkeyed calls in FIFO order", t.length === 2 && t[0].agent === "allium:distill" && t[1].agent === "allium:propagate"); + rmSync(dir, { recursive: true, force: true }); +} + +// 4. A post with no matching pre writes nothing and does not crash. +{ + const dir = newProject({ withLoopDir: true }); + runHook("post", { tool_use_id: "orphan", tool_name: "Task", tool_input: { subagent_type: "allium:weed" } }, dir); + assert("ignores an unpaired post", timings(dir).length === 0); + rmSync(dir, { recursive: true, force: true }); +} + +// 5. Malformed stdin is swallowed (no crash, no output). +{ + const dir = newProject({ withLoopDir: true }); + try { + execFileSync("node", [hook, "pre"], { input: "not json", encoding: "utf-8", stdio: ["pipe", "pipe", "pipe"], env: { ...process.env, CLAUDE_PROJECT_ROOT: dir } }); + assert("survives malformed input", true); + } catch { + assert("survives malformed input", false); + } + rmSync(dir, { recursive: true, force: true }); +} + +console.log(`\n${passed} passed, ${failed} failed`); +process.exit(failed > 0 ? 1 : 0); diff --git a/scripts/test-skills.mjs b/scripts/test-skills.mjs index 96a33de..c3a4e5d 100644 --- a/scripts/test-skills.mjs +++ b/scripts/test-skills.mjs @@ -10,13 +10,13 @@ * node scripts/test-skills.mjs structure # run one group * node scripts/test-skills.mjs portability links # run multiple groups * - * Groups: structure, codex, consistency, portability, links, routing, generation, loopdocs, hooks, modes, handoffs, discovery, parking, witnessing, crosstalk + * Groups: structure, codex, consistency, portability, links, routing, generation, loopdocs, hooks, modes, handoffs, trace, discovery, parking, witnessing, timinghook, crosstalk * * All groups except discovery, parking, witnessing and crosstalk are offline (free, fast); * those four require --live and make Claude API calls. */ -import { readFileSync, writeFileSync, existsSync, readdirSync, mkdtempSync, rmSync } from "fs"; +import { readFileSync, writeFileSync, existsSync, readdirSync, mkdtempSync, mkdirSync, rmSync } from "fs"; import { execFileSync, execSync } from "child_process"; import { tmpdir } from "os"; import path from "path"; @@ -247,6 +247,39 @@ function isConverged({ weed, propagate, testsFailed, blockingQuestions }) { ); } +// The stall rule, pinned deterministically (driving-the-loop §13). The live +// loop applies this by hand — it is counting over a short log, no tool needed — +// but pinning it here stops the rule drifting and lets it later move into a +// script or the CLI as an accelerator. +function traceMetricImproved(prev, cur) { + return ( + cur.tests.failed < prev.tests.failed || + (prev.weed === "dirty" && cur.weed === "clean") || + cur.uncovered_obligations < prev.uncovered_obligations || + cur.open_questions.blocking < prev.open_questions.blocking + ); +} +function traceEntryConverged(e) { + return e.tests.failed === 0 && e.weed === "clean" && + e.uncovered_obligations === 0 && e.open_questions.blocking === 0; +} +// Count the trailing run of no-progress ticks; a stall once it reaches the +// threshold (config.stall_warning_ticks, default 1). A converged tick or any +// improvement breaks the run. +function detectStall(trace, threshold = 1) { + let run = 0; + for (let i = trace.length - 1; i >= 1; i--) { + if (traceEntryConverged(trace[i])) break; + if (traceMetricImproved(trace[i - 1], trace[i])) break; + run++; + } + return { + stalled: run >= threshold, + flatTicks: run, + sinceTick: run > 0 ? trace[trace.length - run].tick : null, + }; +} + // Pull the JSON record out of a relayed agent message: prefer the marked // region, then take the outermost { ... }. Returns null if none parses. function extractJsonRecord(text) { @@ -663,20 +696,39 @@ if (shouldRun("hooks")) { fail("hooks PostToolUse", "missing or empty"); } else { pass("hooks PostToolUse present"); - let matchersOk = true; - let scriptsOk = true; - for (const entry of post) { + } + + // Validate every event's entries: each has a matcher, and every + // ${CLAUDE_PLUGIN_ROOT}-referenced script exists on disk. + let matchersOk = true; + let scriptsOk = true; + const commands = []; + for (const event of ["PreToolUse", "PostToolUse"]) { + for (const entry of cfg.hooks?.[event] ?? []) { if (!entry || !entry.matcher) matchersOk = false; - const cmds = Array.isArray(entry?.hooks) ? entry.hooks : []; - for (const h of cmds) { - const m = - typeof h.command === "string" && - h.command.match(/\$\{CLAUDE_PLUGIN_ROOT\}\/([^"\s]+)/); + for (const h of Array.isArray(entry?.hooks) ? entry.hooks : []) { + if (typeof h.command === "string") commands.push(h.command); + const m = typeof h.command === "string" && h.command.match(/\$\{CLAUDE_PLUGIN_ROOT\}\/([^"\s]+)/); if (m && !existsSync(path.join(ROOT, m[1]))) scriptsOk = false; } } - matchersOk ? pass("hooks have matchers") : fail("hooks matcher", "an entry is missing a matcher"); - scriptsOk ? pass("hook command scripts exist") : fail("hook command", "referenced script not found"); + } + matchersOk ? pass("hooks have matchers") : fail("hooks matcher", "an entry is missing a matcher"); + scriptsOk ? pass("hook command scripts exist") : fail("hook command", "referenced script not found"); + + // The subagent timing hook is registered on both events (loop-trace pre/post). + const hasPre = commands.some((c) => c.includes("loop-trace.mjs") && /\bpre\b/.test(c)); + const hasPost = commands.some((c) => c.includes("loop-trace.mjs") && /\bpost\b/.test(c)); + hasPre && hasPost + ? pass("loop-trace timing hook registered on pre and post") + : fail("loop-trace hook", `missing registration (pre=${hasPre}, post=${hasPost})`); + + // Run the timing hook's own unit tests, so its logic is covered in CI. + try { + execFileSync("node", [path.join(ROOT, "hooks", "loop-trace.test.mjs")], { encoding: "utf-8", stdio: "pipe" }); + pass("loop-trace hook unit tests pass"); + } catch (e) { + fail("loop-trace hook unit tests", (e.stdout || e.message || "").slice(-160)); } } } @@ -865,6 +917,69 @@ if (shouldRun("handoffs")) { } } +// --------------------------------------------------------------------------- +// Trace — the run trace (driving-the-loop §13). Offline and deterministic: +// trace entries validate against their schema, and the stall rule is proven +// over trajectories. The live loop applies the same rule by hand; this pins it. +// --------------------------------------------------------------------------- + +if (shouldRun("trace")) { + console.log("\n── trace: run trace entries and the stall rule ──\n"); + + const traceSchema = readJson(path.join(ROOT, "skills", "allium", "references", "schemas", "trace-entry.schema.json")); + if (traceSchema) pass("schemas/trace-entry.schema.json is valid JSON"); + + const entry = (tick, failed, weed, uncovered, blocking = 0) => ({ + tick, phases: [{ name: "weed", reason: "spec changed this tick" }], + tests: { passed: 10 - failed, failed }, + weed, uncovered_obligations: uncovered, open_questions: { blocking, parked: 0 }, + }); + + // Schema: a valid entry validates; malformed ones are caught. + if (traceSchema) { + const good = entry(1, 5, "dirty", 3); + validateAgainstSchema(traceSchema, good).length === 0 + ? pass("trace-entry valid fixture") : fail("trace-entry valid fixture", "should validate"); + const bad = [ + ["bad weed enum", { ...good, weed: "greenish" }], + ["tests missing failed", { ...good, tests: { passed: 5 } }], + ["open_questions not object", { ...good, open_questions: 2 }], + ["unexpected property", { ...good, extra: 1 }], + ["tick not integer", { ...good, tick: "1" }], + ["phases item missing name", { ...good, phases: [{ reason: "x" }] }], + ["phases item as bare string", { ...good, phases: ["weed"] }], + ]; + for (const [label, rec] of bad) { + validateAgainstSchema(traceSchema, rec).length > 0 + ? pass(`trace-entry rejects: ${label}`) : fail(`trace-entry rejects: ${label}`, "malformed entry validated"); + } + } + + console.log(""); + + // The stall rule over trajectories. + const converging = [entry(1, 5, "dirty", 3), entry(2, 3, "dirty", 2), entry(3, 1, "clean", 0), entry(4, 0, "clean", 0)]; + const flat = [entry(1, 5, "dirty", 3), entry(2, 5, "dirty", 3), entry(3, 5, "dirty", 3)]; + const recovered = [entry(1, 5, "dirty", 3), entry(2, 5, "dirty", 3), entry(3, 3, "dirty", 2)]; + const converged = [entry(1, 2, "dirty", 1), entry(2, 0, "clean", 0)]; + + const cases = [ + ["converging run is not stalled", detectStall(converging, 1).stalled, false], + ["flat run stalls at threshold 1", detectStall(flat, 1).stalled, true], + ["flat run of 2 not stalled at threshold 3", detectStall(flat, 3).stalled, false], + ["recovered run is not stalled", detectStall(recovered, 1).stalled, false], + ["converged run is not stalled", detectStall(converged, 1).stalled, false], + ]; + for (const [label, got, want] of cases) { + got === want ? pass(`stall: ${label}`) : fail(`stall: ${label}`, `expected ${want}, got ${got}`); + } + // The report points at where it flattened. + const s = detectStall(flat, 1); + s.flatTicks === 2 && s.sinceTick === 2 + ? pass("stall: reports flat run length and first flat tick") + : fail("stall: report", `flatTicks=${s.flatTicks} sinceTick=${s.sinceTick}`); +} + // --------------------------------------------------------------------------- // Discovery — live Claude Code skill and agent loading // --------------------------------------------------------------------------- @@ -1302,6 +1417,47 @@ if (shouldRun("handoffs")) { } } +// --------------------------------------------------------------------------- +// Timing hook (live) — the one thing unit tests can't settle: does the hook +// actually fire against a real Claude Code run? Spawn a real subagent inside a +// dir with .allium-loop/, then assert a timing line landed. If it didn't, the +// matcher name or the payload fields are wrong for this harness — the whole +// reason this probe exists. +// --------------------------------------------------------------------------- + +if (shouldRun("timinghook")) { + console.log("\n── timinghook (live): the hook captures a real subagent call ──\n"); + + if (!LIVE) { + skip("timing hook probe", "pass --live to enable (uses API tokens)"); + } else { + const dir = mkdtempSync(path.join(tmpdir(), "allium-timinghook-")); + try { + mkdirSync(path.join(dir, ".allium-loop")); // the hook only records while a loop is active + writeFileSync(path.join(dir, "giftcard.py"), GIFTCARD_PY); + runAgentProbe( + dir, + "Use the Agent tool to spawn the 'allium:distill' subagent with exactly this task: " + + '"Distil an Allium spec for giftcard.py into giftcard.allium." When it finishes, output only DONE.' + ); + const tp = path.join(dir, ".allium-loop", "timings.jsonl"); + if (!existsSync(tp)) { + fail("timing hook fired", "no .allium-loop/timings.jsonl — matcher/payload mismatch, or hooks not loaded via --plugin-dir"); + } else { + const lines = readFileSync(tp, "utf-8").trim().split("\n").filter(Boolean).map((l) => { try { return JSON.parse(l); } catch { return null; } }); + const hit = lines.find((l) => l && typeof l.duration_ms === "number"); + hit + ? pass(`timing hook captured a real call (agent=${hit.agent}, ${hit.duration_ms}ms)`) + : fail("timing hook entry", "timings.jsonl present but no valid {agent, duration_ms} line"); + } + } catch (e) { + fail("timing hook probe", e.message?.slice(0, 200)); + } finally { + rmSync(dir, { recursive: true, force: true }); + } + } +} + // --------------------------------------------------------------------------- // Crosstalk — skills from the plugin don't bleed into unrelated projects, // and local agents/ don't leak outside the repo diff --git a/skills/allium/references/driving-the-loop.md b/skills/allium/references/driving-the-loop.md index 2094327..d21d6d9 100644 --- a/skills/allium/references/driving-the-loop.md +++ b/skills/allium/references/driving-the-loop.md @@ -32,7 +32,7 @@ Announce each phase as it begins with a one-line marker (shown in parentheses be - a test is wrong → `tend` the spec, then `propagate` again; - `weed` says the spec is wrong → `tend` the spec; - open question → classify and handle (§5). -5. **Record state** in the ledger (§8) and print a one-line summary: `tick n · tests x/y · weed clean/dirty · openQ blocking k / parked m`. +5. **Record state** in the ledger (§8), **append a trace entry** for the tick (§13), and print a one-line summary: `tick n · tests x/y · weed clean/dirty · openQ blocking k / parked m`. If the trace shows the run has stopped making progress, say so out loud this tick (§13) — don't wait for the cap. ## 3. Convergence (when to stop) @@ -50,6 +50,7 @@ The first four are the run's own reading of its state; the witness re-derives th - **Hard cap** — stop after **6** iterations. - **No-progress cap** — stop after **2** iterations with no change in tests / weed verdict / open-question count (catches thrashing against a test you can't satisfy). +- **Surface the stall early** — don't let a flattening run grind to that cap in silence. The trace (§13) shows the trajectory each tick; the moment a tick makes no progress, say so out loud. The cap is the backstop, not the first sign. - **Escalate** on a blocking open question (§5). - **Anti-cheat (non-negotiable, and witnessed)** — never weaken or edit a generated test to pass; honour `config` (no magic numbers in code the spec parameterises). This is not left to good behaviour: the witness (§11) re-derives it from ground truth — a generated test whose recorded hash changed with no intervening `propagate` fails the witness and blocks convergence. - On hitting a cap or an unrecoverable error, **stop and report** — don't spin. @@ -83,7 +84,7 @@ This is what keeps a long or large run within budget: the orchestrator's context Keep loop state in `.allium-loop/.json`: goal, mode, tick count, active inner loop, last verdicts, completed sub-goals, and parked (non-blocking) open questions. This makes the loop resumable — a fresh run reads it and continues where it left off. -The ledger is itself typed — it conforms to [ledger.schema.json](./schemas/ledger.schema.json), so a resuming run reads structured state rather than re-parsing prose. It also carries the evidence the witness (§11) re-derives convergence from, so record it as the phases produce it: `generated_test_hashes` (a content hash per generated test file, written by `propagate`) and the `reconciliation` line, the recorded `weed` verdict, and — for spec-first — the red-before-green observations per new test. The witness reads these; it does not take them on trust, but it needs them to exist. The witness writes its own artefact alongside the ledger, `.allium-loop/.witness.json` — the durable convergence record, keep it out of git the same way. +The ledger is itself typed — it conforms to [ledger.schema.json](./schemas/ledger.schema.json), so a resuming run reads structured state rather than re-parsing prose. It also carries the evidence the witness (§11) re-derives convergence from, so record it as the phases produce it: `generated_test_hashes` (a content hash per generated test file, written by `propagate`) and the `reconciliation` line, the recorded `weed` verdict, and — for spec-first — the red-before-green observations per new test. The witness reads these; it does not take them on trust, but it needs them to exist. The witness writes its own artefact alongside the ledger, `.allium-loop/.witness.json` — the durable convergence record, keep it out of git the same way. The run trace (§13) lives beside them at `.allium-loop/.trace.jsonl`; ignore it the same way. Git-ignore it: resolve the repo root (`git rev-parse --show-toplevel`; skip if not a git repo), then ensure `.allium-loop/` is ignored there — create `.gitignore` if absent, append if missing, no-op if already ignored (`git check-ignore` first). Best-effort: if it can't be written, continue and say so. Mention it once; don't prompt. @@ -93,7 +94,7 @@ The loop is only as good as its verification. Discover the project's test comman ## 10. Report -End with: what converged, per–sub-goal status, tests and weed verdict, the witness verdict and its record path, anything escalated, and all parked questions consolidated. +End with: what converged, per–sub-goal status, tests and weed verdict, the witness verdict and its record path, anything escalated, all parked questions consolidated, and the run's **trajectory** from the trace (§13) — how the metrics moved tick over tick, and any stall that was surfaced. ## 11. Witness the convergence (the gate) @@ -127,3 +128,27 @@ The schemas: [`distill`](./schemas/distill-result.schema.json), [`weed`](./schem | any record fails schema validation | reject the hand-off; the phase must re-emit — a malformed record is never treated as a result | **Convergence** is the boolean over the typed fields: `tests.failed = 0` ∧ `weed.verdict = clean` ∧ no blocking open questions ∧ `propagate.uncovered_obligations` empty ∧ (code-first) a fresh `distill` finds nothing new ∧ `witness.verdict = PASS`. When every conjunct reads from a field, "are we done" stops being a vibe and becomes an evaluation. + +## 13. Trace the run (observability) + +A long autonomous run can fail without failing. Nothing errors, but the loop stops converging — tests stick, `weed` stays dirty, obligations don't shrink — and it grinds tick after tick until a cap trips. The trace makes that visible while it is happening instead of after. + +**Append one entry per tick.** After recording state (§2 step 5), append a line to `.allium-loop/.trace.jsonl` conforming to [trace-entry.schema.json](./schemas/trace-entry.schema.json): the tick number, the `phases` run **and why each was chosen** (the routing decision, so a wrong or repeatedly ineffective call is visible), the tick's `tests` (passed / failed), `weed` verdict, `uncovered_obligations`, and blocking / parked `open_questions`. These come straight from the phases' typed records (§12) — you already hold them, so this is bookkeeping, not new work. Carry a metric forward when its phase didn't run this tick. + +**Which calls, and were they the right ones.** Recording the phase *and its reason* each tick, next to whether that tick made progress, makes the routing auditable: a phase that keeps running and never moves a metric is a wrong or wasted call, and now it shows in the trace rather than hiding in a long run. This is the routing half of the telemetry, and the orchestrator records it directly — it knows which subagent it chose and why. + +**Real per-call timing comes from the hook, not from you.** A subagent call isn't a Bash call you can wrap in `date`, and you can't read your own latency, so precise timing is captured outside the model: the `loop-trace` hook stamps each subagent call's start and end and appends `{agent, duration_ms}` to `.allium-loop/timings.jsonl`. When that file is present, fold its durations into the trace (`durations_s`) and the end report. Where hooks don't run, there is simply no wall-clock — the trajectory and routing above still stand. Don't hand-time calls yourself; trust the hook or omit timing. + +**Watch the trajectory.** A tick makes **progress** if any convergence metric improved: fewer failing tests, `weed` went dirty → clean, fewer uncovered obligations, or fewer blocking questions. A tick with none of those, while not yet converged, is a **no-progress tick**. + +**Surface a stall out loud.** The moment a no-progress tick lands, say so in the run output — name what is stuck and for how long: + +``` +⚠ tick 4 · no progress — tests stuck at 5/10 for 2 ticks, weed still dirty, 3 uncovered +``` + +This is the whole point: the silent slow-down becomes a line you cannot miss. Keep surfacing it each further flat tick; the no-progress cap (§4) is the backstop that finally stops the run, not the first signal. The threshold for the first warning is `config.stall_warning_ticks` (default **1**, so the first flat tick warns); raise it in a `config` block if a run is legitimately slow and the early warning is noise. + +**The rule is simple on purpose.** Deciding "did any metric improve across the last N ticks" is counting over a short log, so the orchestrator applies it directly — no tool required, nothing to install. The same rule is pinned as a deterministic function in the test suite (`detectStall`) so it can't drift, and so it can later move into a script or the CLI as an accelerator, with the orchestrator as the always-present floor (§ the pattern `allium check` already uses: CLI when present, fall back otherwise). + +**Report the trajectory.** At the end (§10), summarise how the metrics moved across the run and call out any stall that was surfaced. A converged run reads as a clean descent to zero; a rescued one shows where it flattened and what unstuck it. diff --git a/skills/allium/references/recommended-loops.md b/skills/allium/references/recommended-loops.md index 0958217..8df6259 100644 --- a/skills/allium/references/recommended-loops.md +++ b/skills/allium/references/recommended-loops.md @@ -131,7 +131,7 @@ Both loops can be driven autonomously — `/distill`, `/propagate`, `/tend`, `/w - **No magic numbers in code that the spec puts in `config`.** Honour the spec's parameters. - **Fix the code, not the contract**, when code and spec disagree and the spec is right. -**State worth tracking across ticks:** tests status (pass/fail counts), `/weed` verdict, count of open questions, and — for code-first — whether the last `/distill` pass found anything new. Convergence is all four trending to zero/clean. +**State worth tracking across ticks:** tests status (pass/fail counts), `/weed` verdict, count of open questions, and — for code-first — whether the last `/distill` pass found anything new. Convergence is all four trending to zero/clean. When driving the loop autonomously, record these into a run trace each tick and surface the moment they stop trending, so a run that has quietly stalled says so instead of grinding to the cap in silence (see [driving the loop](./driving-the-loop.md) §13). ## Driving the loop with one prompt diff --git a/skills/allium/references/schemas/trace-entry.schema.json b/skills/allium/references/schemas/trace-entry.schema.json new file mode 100644 index 0000000..1e4ddd9 --- /dev/null +++ b/skills/allium/references/schemas/trace-entry.schema.json @@ -0,0 +1,56 @@ +{ + "$schema": "http://json-schema.org/draft-07/schema#", + "$id": "allium/handoffs/trace-entry", + "title": "Run trace entry", + "description": "One tick of the loop's run trace, appended to .allium-loop/.trace.jsonl. A snapshot of the convergence state that tick, drawn from the phases' typed records. The trace makes the run's trajectory observable, so a loop that has quietly stopped converging can be seen and surfaced instead of grinding silently.", + "type": "object", + "required": ["tick", "tests", "weed", "uncovered_obligations", "open_questions"], + "additionalProperties": false, + "properties": { + "tick": { "type": "integer", "description": "the tick this entry records, from 1" }, + "phases": { + "type": "array", + "description": "the phases run this tick, in order, each with why it was chosen — the routing decision, so a wrong or repeatedly ineffective call is visible in the trace", + "items": { + "type": "object", + "required": ["name"], + "additionalProperties": false, + "properties": { + "name": { "type": "string", "description": "the phase / subagent, e.g. weed, propagate" }, + "reason": { "type": "string", "description": "why it was chosen this tick, e.g. the field that triggered it" } + } + } + }, + "tests": { + "type": "object", + "description": "the tick's test result; carried forward from the last run if tests did not run this tick", + "required": ["passed", "failed"], + "additionalProperties": false, + "properties": { + "passed": { "type": "integer" }, + "failed": { "type": "integer" } + } + }, + "weed": { + "enum": ["clean", "dirty"], + "description": "the tick's weed verdict, carried forward if weed did not run" + }, + "uncovered_obligations": { + "type": "integer", + "description": "count from propagate; 0 when coverage is complete" + }, + "open_questions": { + "type": "object", + "required": ["blocking", "parked"], + "additionalProperties": false, + "properties": { + "blocking": { "type": "integer" }, + "parked": { "type": "integer" } + } + }, + "durations_s": { + "type": "object", + "description": "best-effort wall-clock seconds per phase this tick, from Bash timestamps; optional" + } + } +}