Skip to content

Commit b5a452f

Browse files
committed
perf(session): coalesce per-turn persistence to ~2 disk-touching writes
A tool-using turn performed ~6 separate disk-touching persists and one commit per tool batch. response.jsonl folded (nothing read it); tool batches now touch segments only, with the full commit cycle at reply/wait/done terminals; run.json snapshots debounce with an identical-payload skip and flush at every observable state expose; token usage moves to an append-only sidecar so metadata rewrites stop re-hashing it; empty manifest writes converge to removals. On a 60-turn census, disk-touching persists drop to ~3-4 on real turns and wall time 10.2 to 3.9 ms/turn. Crash recovery still rebuilds from on-disk segments (compaction atomicity, crash finalize, exec signal finalize all green); dooms-loop aborts still durably stage turns as before.
1 parent 8d879e9 commit b5a452f

14 files changed

Lines changed: 1356 additions & 57 deletions

‎scripts/turn-persistence-census.ts‎

Lines changed: 277 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,277 @@
1+
#!/usr/bin/env bun
2+
/**
3+
* CL-10667 before/after measurement: per-turn session persistence write ops.
4+
*
5+
* Mirrors the reactor's persist sequence for one agentic turn: one inference
6+
* cycle (writePrompt + writeResponse) and two tool batches followed by the
7+
* cycle terminal. Every write-kind fs.promises call of the store stack is
8+
* counted (split by whether the path is under .git), so the coalescing becomes
9+
* an honest before/after delta on the same host and scenario.
10+
*
11+
* The flow itself changed shape with CL-10667, so the same script models both:
12+
* --flow=legacy replicates the pre-coalescing reactor (tool-batch commitCycle
13+
* per batch); --flow=coalesced replicates the post-coalescing one (writeTurns
14+
* per tool batch, full commitCycle only at the cycle terminal).
15+
*
16+
* Usage:
17+
* bun scripts/turn-persistence-census.ts [turnCount] [--flow=legacy|coalesced] [--json]
18+
*/
19+
20+
import fs from "node:fs";
21+
import path from "node:path";
22+
import type { ConversationTurn, TokenUsage } from "@intx/types/runtime";
23+
import { TransformRecord } from "@intx/types/runtime";
24+
import { createOptimizedContextStore } from "../src/session/optimized-context-store.js";
25+
26+
const WRITE_OPS = [
27+
"writeFile",
28+
"appendFile",
29+
"rename",
30+
"unlink",
31+
"truncate",
32+
"mkdir",
33+
"copyFile",
34+
] as const;
35+
36+
const counts: Record<string, number> = {};
37+
const gitPaths: Record<string, number> = {};
38+
39+
function bump(table: Record<string, number>, op: string): void {
40+
table[op] = (table[op] ?? 0) + 1;
41+
}
42+
43+
function installCounters(): void {
44+
const target = fs.promises as unknown as Record<string, unknown>;
45+
for (const op of WRITE_OPS) {
46+
const original = target[op];
47+
if (typeof original !== "function") continue;
48+
target[op] = function counted(this: unknown, ...args: unknown[]) {
49+
const first = args[0];
50+
if (typeof first === "string" && first.includes(`/.git/`)) {
51+
bump(gitPaths, op);
52+
}
53+
bump(counts, op);
54+
return (original as (...args: unknown[]) => unknown).apply(this, args);
55+
};
56+
}
57+
}
58+
59+
function turn(text: string): ConversationTurn {
60+
return { role: "user", content: [{ type: "text", text }], timestamp: 1 };
61+
}
62+
63+
function assistantTurn(text: string): ConversationTurn {
64+
return {
65+
role: "assistant",
66+
content: [{ type: "text", text }],
67+
timestamp: 2,
68+
};
69+
}
70+
71+
function toolResultTurn(name: string): ConversationTurn {
72+
return {
73+
role: "user",
74+
content: [
75+
{
76+
type: "tool_result",
77+
callId: `call-${name}`,
78+
content: [{ type: "text", text: `${name} result` }],
79+
},
80+
],
81+
timestamp: 3,
82+
};
83+
}
84+
85+
function turnBody(index: number): string {
86+
return (
87+
`turn ${index}: ` + "census padding. ".repeat(40) + `end-of-turn ${index}`
88+
);
89+
}
90+
91+
const EMPTY_USAGE: TokenUsage = {
92+
input: 0,
93+
output: 0,
94+
cacheRead: 0,
95+
cacheWrite: 0,
96+
thinking: 0,
97+
};
98+
99+
function usageForTurn(turnCount: number): TokenUsage {
100+
return {
101+
...EMPTY_USAGE,
102+
input: 1000 * turnCount,
103+
output: 500 * turnCount,
104+
};
105+
}
106+
107+
async function runScenario(
108+
dir: string,
109+
turnCount: number,
110+
flow: string,
111+
): Promise<{ turns: number; persistCalls: Record<string, number> }> {
112+
const base = await createOptimizedContextStore(dir);
113+
const PERSIST_METHODS = [
114+
"writePrompt",
115+
"writeResponse",
116+
"writeTurns",
117+
"writeManifest",
118+
"writeMetadata",
119+
"commit",
120+
] as const;
121+
const persistCalls: Record<string, number> = {};
122+
const store = Object.assign(Object.create(base), base) as typeof base;
123+
for (const method of PERSIST_METHODS) {
124+
const original = base[method] as (
125+
...callArgs: unknown[]
126+
) => Promise<unknown>;
127+
(store as never as Record<string, unknown>)[method] = (
128+
...callArgs: unknown[]
129+
) => {
130+
bump(persistCalls, method);
131+
return original.apply(base, callArgs);
132+
};
133+
}
134+
const history: ConversationTurn[] = [];
135+
const record: () => TransformRecord = () => ({
136+
strategy: "test.transform",
137+
version: "1",
138+
parameters: {},
139+
reason: "census",
140+
decisions: {},
141+
});
142+
for (let t = 0; t < turnCount; t++) {
143+
// Inference cycle: prompt + assistant turn.
144+
history.push(turn(turnBody(t)));
145+
history.push(assistantTurn(`reply to ${t}`));
146+
await store.writePrompt(history);
147+
148+
if (flow === "legacy") {
149+
const last = history[history.length - 1];
150+
if (last !== undefined && last.role === "assistant") {
151+
await store.writeResponse({
152+
...last,
153+
role: "assistant",
154+
model: last.model ?? "census-model",
155+
});
156+
}
157+
}
158+
159+
for (let batch = 0; batch < 2; batch++) {
160+
history.push(toolResultTurn(`tool-${t}-${batch}`));
161+
if (flow === "legacy") {
162+
// Old tool-batch path: a full commitCycle per batch.
163+
await store.writeTurns(history);
164+
await store.writeManifest([record()]);
165+
await store.writeMetadata({
166+
pendingOperations: [],
167+
tokenUsage: usageForTurn(t + 1),
168+
});
169+
await store.commit({ message: "checkpoint: tool-execution" });
170+
} else {
171+
// Coalesced tool-batch path: segments on disk only.
172+
await store.writeTurns(history);
173+
}
174+
}
175+
176+
// Cycle terminal (reply/wait/done): the remaining cycle persists.
177+
if (flow !== "legacy") {
178+
await store.writeTurns(history);
179+
// Two transforms happened; the terminal commit carries them.
180+
await store.writeManifest([record(), record()]);
181+
await store.writeMetadata({
182+
pendingOperations: [],
183+
tokenUsage: usageForTurn(t),
184+
});
185+
await store.commit({ message: "Cycle: done" });
186+
}
187+
}
188+
const fresh = await createOptimizedContextStore(dir);
189+
const turns = (await fresh.load()).turns.length;
190+
return { turns, persistCalls };
191+
}
192+
193+
function sortedEntries(table: Record<string, number>): [string, number][] {
194+
return Object.entries(table).sort((a, b) => b[1] - a[1]);
195+
}
196+
197+
async function main(argv: string[]): Promise<number> {
198+
const arg = argv[2];
199+
const flow = argv.find((a) => a.startsWith("--flow="))?.split("=")[1];
200+
if (flow !== "legacy" && flow !== "coalesced") {
201+
console.error(
202+
"usage: bun scripts/turn-persistence-census.ts [turnCount] --flow=legacy|coalesced [--json]",
203+
);
204+
return 1;
205+
}
206+
const turnCount =
207+
arg !== undefined && !arg.startsWith("-") ? Number(arg) : 40;
208+
if (!Number.isFinite(turnCount) || turnCount < 1) {
209+
console.error(`invalid turnCount: ${arg}`);
210+
return 1;
211+
}
212+
installCounters();
213+
214+
const prefix = `census-${flow}-`;
215+
const dir = await fs.promises.mkdtemp(path.join(process.cwd(), prefix));
216+
const started = performance.now();
217+
const { turns: loadedTurns, persistCalls } = await runScenario(
218+
dir,
219+
turnCount,
220+
flow,
221+
);
222+
const wallMs = Math.round(performance.now() - started);
223+
224+
const totalOps = Object.values(counts).reduce((sum, n) => sum + n, 0);
225+
const gitOps = Object.values(gitPaths).reduce((sum, n) => sum + n, 0);
226+
227+
const asJson = argv.includes("--json");
228+
if (asJson) {
229+
console.log(
230+
JSON.stringify(
231+
{
232+
flow,
233+
turnCount,
234+
wallMs,
235+
loadedTurns,
236+
totalWriteOps: totalOps,
237+
gitPathWriteOps: gitOps,
238+
byName: counts,
239+
gitByPath: gitPaths,
240+
perTurn: {
241+
wallMs: +(wallMs / turnCount).toFixed(2),
242+
writeOps: +(totalOps / turnCount).toFixed(2),
243+
},
244+
persistCalls,
245+
persistCallsPerTurn: Object.fromEntries(
246+
Object.entries(persistCalls).map(([k, v]) => [
247+
k,
248+
+(v / turnCount).toFixed(3),
249+
]),
250+
),
251+
},
252+
null,
253+
2,
254+
),
255+
);
256+
} else {
257+
console.log(
258+
`flow=${flow} ${turnCount} turns; verified ${loadedTurns} turns at the end`,
259+
);
260+
console.log(
261+
`wall: ${wallMs} ms (${(wallMs / turnCount).toFixed(2)} ms/turn)`,
262+
);
263+
console.log(
264+
`write ops: ${totalOps} total (${(totalOps / turnCount).toFixed(2)}/turn), of which ${gitOps} under .git`,
265+
);
266+
for (const [op, n] of sortedEntries(counts)) {
267+
console.log(` ${op}: ${n}`);
268+
}
269+
for (const [op, n] of sortedEntries(gitPaths)) {
270+
console.log(` (.git) ${op}: ${n}`);
271+
}
272+
}
273+
await fs.promises.rm(dir, { recursive: true, force: true });
274+
return 0;
275+
}
276+
277+
process.exit(await main(process.argv));

‎src/exec/runner.test.ts‎

Lines changed: 94 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,6 @@
11
import { describe, expect, spyOn, test } from "bun:test";
22
import type { ToolCall } from "@intx/types/runtime";
3+
import { defined } from "../../testkit/defined.js";
34
import type { AgentTool } from "@intx/agent";
45
import { submitOutputDefinition } from "../agent/director.js";
56
import { DIRECTOR_REGISTRY } from "../agent/directors/registry.js";
@@ -564,6 +565,99 @@ describe("runExec", () => {
564565
cleanup();
565566
}
566567
});
568+
569+
test("heartbeat forces identical-payload writes; a failed save does not take the baseline", async () => {
570+
// CL-10667 review fix: the exec heartbeat tick must bypass the
571+
// identical-payload skip (mtime freshness is a liveness contract read
572+
// cross-process by ageStaleRunningState), and the baseline must record
573+
// only successes so a transient save failure cannot freeze run.json.
574+
const previous = getActiveRun();
575+
clearActiveRun();
576+
const sessionId = "exec-heartbeat-fail";
577+
const { cwd, home, cleanup } = createTempDirs(
578+
"corbits-exec-heartbeat-cwd-",
579+
"corbits-exec-heartbeat-home-",
580+
);
581+
try {
582+
const saveCalls: { ok: boolean; status?: string }[] = [];
583+
await withMockedHomedir(home, () =>
584+
withMockedModuleDuring(
585+
import.meta.resolve("../session/state.js"),
586+
(real: typeof import("../session/state.js")) =>
587+
({
588+
...real,
589+
saveState(
590+
cwd: string,
591+
sessionId: string,
592+
state: import("../session/state.js").RunState,
593+
dir?: string,
594+
) {
595+
if (saveCalls.length === 0) {
596+
saveCalls.push({ ok: false, status: state.status });
597+
// Transient failure on the first running write.
598+
return Promise.reject(new Error("ENOSPC-like"));
599+
}
600+
saveCalls.push({ ok: true, status: state.status });
601+
return real.saveState(cwd, sessionId, state, dir);
602+
},
603+
}) as typeof real,
604+
() =>
605+
withMockedModuleDuring(
606+
import.meta.resolve("../session/run-liveness.js"),
607+
(real: typeof import("../session/run-liveness.js")) =>
608+
({
609+
...real,
610+
RUN_HEARTBEAT_INTERVAL_MS: 10,
611+
}) as typeof real,
612+
() =>
613+
withMockedModuleDuring(
614+
import.meta.resolve("../session/assemble-runtime.js"),
615+
(inner: typeof import("../session/assemble-runtime.js")) =>
616+
({
617+
...inner,
618+
assembleInferenceBase: () =>
619+
// Delay the bootstrap failure so heartbeat ticks run
620+
// while the run is unsettled.
621+
new Promise<never>((_, reject) => {
622+
setTimeout(
623+
() => reject(new Error("bootstrap failed")),
624+
80,
625+
);
626+
}),
627+
}) as typeof inner,
628+
async () => {
629+
const { runExec: runExecUnderMock } =
630+
await import("./runner.js");
631+
const result = await runExecUnderMock({
632+
...bareConfig("do the thing"),
633+
cwd,
634+
sessionId,
635+
});
636+
expect(result.status).toBe("failed");
637+
},
638+
),
639+
),
640+
),
641+
);
642+
643+
// Write 1 (running) failed; the heartbeat retried the identical payload
644+
// and forced a disk write past any baseline; the terminal wrote last.
645+
expect(saveCalls[0]).toEqual({ ok: false, status: "running" });
646+
const runningOk = saveCalls.findIndex((call) => call.ok);
647+
expect(runningOk).toBeGreaterThan(0);
648+
expect(defined(saveCalls[runningOk]).status).toBe("running");
649+
expect(defined(saveCalls[saveCalls.length - 1]).status).toBe("failed");
650+
const finalPersisted = await loadState(cwd, sessionId, home);
651+
expect(finalPersisted).toMatchObject({
652+
kind: "ok",
653+
state: { status: "failed" },
654+
});
655+
} finally {
656+
if (previous !== null) setActiveRun(previous);
657+
else clearActiveRun();
658+
cleanup();
659+
}
660+
});
567661
});
568662

569663
describe("resolveExecDirectorOverlay", () => {

0 commit comments

Comments
 (0)