diff --git a/.mux/tool_env b/.mux/tool_env index 883a07b15d..c8f4946331 100644 --- a/.mux/tool_env +++ b/.mux/tool_env @@ -5,6 +5,11 @@ # Keep PATH resolution and step logging deterministic across tool calls. # This mirrors the proven workflow the team liked in coder-k8s. +# Leaked SSH vars make Debian's /etc/bash.bashrc SSH heuristic source itself in +# non-interactive make recipe shells, where its unguarded $PS1 fails under +# `.SHELLFLAGS -eu` and breaks make targets. +unset SSH_CLIENT SSH_CONNECTION SSH2_CLIENT + mux_use_nix_devshell_path() { local flake_root="" diff --git a/src/browser/features/RightSidebar/DevToolsTab/useDevToolsSubscription.ts b/src/browser/features/RightSidebar/DevToolsTab/useDevToolsSubscription.ts index d184dcd6be..df832d18f7 100644 --- a/src/browser/features/RightSidebar/DevToolsTab/useDevToolsSubscription.ts +++ b/src/browser/features/RightSidebar/DevToolsTab/useDevToolsSubscription.ts @@ -68,6 +68,18 @@ export function useDevToolsSubscription(workspaceId: string) { case "step-updated": setStepsByRun((previousStepsByRun) => upsertStep(previousStepsByRun, event.step)); break; + case "runs-evicted": { + const evictedRunIds = new Set(event.runIds); + setRuns((previousRuns) => previousRuns.filter((run) => !evictedRunIds.has(run.id))); + setStepsByRun((previousStepsByRun) => { + const nextStepsByRun = new Map(previousStepsByRun); + for (const runId of evictedRunIds) { + nextStepsByRun.delete(runId); + } + return nextStepsByRun; + }); + break; + } case "cleared": setRuns([]); setStepsByRun(new Map()); diff --git a/src/common/orpc/schemas/api.ts b/src/common/orpc/schemas/api.ts index 688c95bb55..5e670f46ec 100644 --- a/src/common/orpc/schemas/api.ts +++ b/src/common/orpc/schemas/api.ts @@ -2481,6 +2481,10 @@ const DevToolsEventSchema = z.discriminatedUnion("type", [ type: z.literal("step-updated"), step: DevToolsStepSchema, }), + z.object({ + type: z.literal("runs-evicted"), + runIds: z.array(z.string()), + }), z.object({ type: z.literal("cleared"), }), diff --git a/src/common/types/devtools.ts b/src/common/types/devtools.ts index 2c4beb4722..a6f251ccb7 100644 --- a/src/common/types/devtools.ts +++ b/src/common/types/devtools.ts @@ -98,10 +98,19 @@ export type DevToolsEvent = | { type: "run-updated"; run: DevToolsRunSummary } | { type: "step-created"; step: DevToolsStep } | { type: "step-updated"; step: DevToolsStep } + | { type: "runs-evicted"; runIds: string[] } | { type: "cleared" }; -/** One line in devtools.jsonl — append-only log format. */ +/** + * One line in devtools.jsonl — append-only log format. The meta entries pair + * a rotated snapshot with the live log written after it: loading skips a live + * log whose generation predates the snapshot's, so a crash between the + * snapshot rename and the live-log rewrite cannot resurrect evicted runs. + */ export type DevToolsLogEntry = | { type: "run"; run: DevToolsRun } | { type: "step"; step: DevToolsStep } - | { type: "step-update"; stepId: string; update: Partial }; + | { type: "step-update"; stepId: string; update: Partial } + | { type: "snapshot-meta"; generation: number } + | { type: "log-meta"; generation: number } + | { type: "log-retire"; generation: number }; diff --git a/src/constants/devtools.ts b/src/constants/devtools.ts new file mode 100644 index 0000000000..e93ed955fb --- /dev/null +++ b/src/constants/devtools.ts @@ -0,0 +1,4 @@ +// Live workspaces can accumulate API debug logs indefinitely. +export const DEVTOOLS_LOG_MAX_BYTES = 50 * 1024 * 1024; + +export const DEVTOOLS_LOG_ROTATED_SUFFIX = ".1"; diff --git a/src/node/services/__tests__/devToolsService.test.ts b/src/node/services/__tests__/devToolsService.test.ts index 28f8144ebf..b41866eb23 100644 --- a/src/node/services/__tests__/devToolsService.test.ts +++ b/src/node/services/__tests__/devToolsService.test.ts @@ -400,7 +400,13 @@ describe("DevToolsService", () => { expect(await service.getRuns("ws-1")).toEqual([]); expect(await service.getRunWithSteps("ws-1", "run-1")).toBeNull(); - expect(await fs.readFile(getDevtoolsLogPath(sessionsDir, "ws-1"), "utf-8")).toBe(""); + // Only the generation marker remains on disk. + expect( + (await fs.readFile(getDevtoolsLogPath(sessionsDir, "ws-1"), "utf-8")) + .split("\n") + .filter(Boolean) + .map((line) => (JSON.parse(line) as { type: string }).type) + ).toEqual(["log-meta"]); }); it("removeWorkspaceData deletes the log file and in-memory state", async () => { @@ -612,12 +618,17 @@ describe("DevToolsService", () => { expect(runWithSteps?.steps[0]?.error).toBe("boom"); }); - it("clear truncates persisted file", async () => { + it("clear leaves nothing replayable in the persisted file", async () => { const service = new DevToolsService(createTestConfig({ sessionsDir, enabled: true })); await service.createRun("ws-1", makeRun("run-1")); await service.clear("ws-1"); - expect(await fs.readFile(getDevtoolsLogPath(sessionsDir, "ws-1"), "utf-8")).toBe(""); + expect( + (await fs.readFile(getDevtoolsLogPath(sessionsDir, "ws-1"), "utf-8")) + .split("\n") + .filter(Boolean) + .map((line) => (JSON.parse(line) as { type: string }).type) + ).toEqual(["log-meta"]); }); }); @@ -679,4 +690,1272 @@ describe("DevToolsService", () => { expect(events[5]).toEqual({ type: "cleared" }); }); }); + + describe("log rotation", () => { + function getRotatedLogPath(dir: string, workspaceId: string): string { + return `${getDevtoolsLogPath(dir, workspaceId)}.1`; + } + + /** Makes the service's next live-marker write reject (simulated ENOSPC). */ + function installMarkerWriteFailure(service: DevToolsService): { failNext: () => void } { + interface MarkerAccess { + writeLiveMarker(filePath: string, generation: number): Promise; + } + const priv = service as unknown as MarkerAccess; + const originalWriteLiveMarker = priv.writeLiveMarker.bind(service); + let failNextMarkerWrite = false; + priv.writeLiveMarker = (filePath: string, generation: number) => { + if (failNextMarkerWrite) { + failNextMarkerWrite = false; + return Promise.reject(new Error("ENOSPC: simulated marker write failure")); + } + return originalWriteLiveMarker(filePath, generation); + }; + return { + failNext: () => { + failNextMarkerWrite = true; + }, + }; + } + + it("rotates the log exactly once when the cap is crossed and preserves line integrity", async () => { + const config = createTestConfig({ sessionsDir }); + // Cap sized so run + step-1 crosses it but log-meta + step-2 does not. + const service = new DevToolsService(config, 400); + const logPath = getDevtoolsLogPath(sessionsDir, "ws-1"); + const rotatedPath = getRotatedLogPath(sessionsDir, "ws-1"); + + await service.createRun("ws-1", makeRun("run-1")); + expect(await pathExists(rotatedPath)).toBe(false); + + await service.createStep("ws-1", makeStep({ id: "step-1", runId: "run-1" })); + expect(await pathExists(rotatedPath)).toBe(true); + // The live file is rewritten (not removed) so its generation marker + // pairs it with the snapshot. + const retiredLines = (await fs.readFile(logPath, "utf-8")).split("\n").filter(Boolean); + expect(retiredLines.map((line) => (JSON.parse(line) as { type: string }).type)).toEqual([ + "log-meta", + ]); + + const rotatedLines = (await fs.readFile(rotatedPath, "utf-8")).split("\n").filter(Boolean); + expect(rotatedLines.map((line) => (JSON.parse(line) as { type: string }).type)).toEqual([ + "snapshot-meta", + "run", + "step", + ]); + + await service.createStep("ws-1", makeStep({ id: "step-2", runId: "run-1" })); + const liveLines = (await fs.readFile(logPath, "utf-8")).split("\n").filter(Boolean); + expect(liveLines).toHaveLength(2); + expect((JSON.parse(liveLines[1]) as { step: { id: string } }).step.id).toBe("step-2"); + expect((await fs.readFile(rotatedPath, "utf-8")).split("\n").filter(Boolean)).toEqual( + rotatedLines + ); + }); + + it("replays the rotated file on load so history survives a restart", async () => { + const config = createTestConfig({ sessionsDir }); + const service = new DevToolsService(config, 350); + + await service.createRun("ws-1", makeRun("run-1")); + // Crossing the cap moves run-1 and step-1 into the rotated file; the + // step-update for step-1 lands in the fresh live file. + await service.createStep("ws-1", makeStep({ id: "step-1", runId: "run-1" })); + await service.updateStep("ws-1", "step-1", { durationMs: 1234 }); + + // A fresh instance simulates an app restart after rotation. + const reloaded = new DevToolsService(config, 350); + const runs = await reloaded.getRuns("ws-1"); + expect(runs.map((run) => run.id)).toEqual(["run-1"]); + const runWithSteps = await reloaded.getRunWithSteps("ws-1", "run-1"); + expect(runWithSteps?.steps.map((step) => step.id)).toEqual(["step-1"]); + // The live-file step-update found its rotated base record. + expect(runWithSteps?.steps[0]?.durationMs).toBe(1234); + }); + + it("keeps history replayable across repeated rotations", async () => { + const config = createTestConfig({ sessionsDir }); + const service = new DevToolsService(config, 350); + + await service.createRun("ws-1", makeRun("run-1")); + // First rotation: run-1 and step-1 move into the rotated snapshot. + await service.createStep("ws-1", makeStep({ id: "step-1", runId: "run-1" })); + // This update alone crosses the cap, forcing a second rotation while + // the live file holds only a step-update without its base records. + await service.updateStep("ws-1", "step-1", { + rawResponse: "x".repeat(400), + durationMs: 77, + }); + + const reloaded = new DevToolsService(config, 350); + const runWithSteps = await reloaded.getRunWithSteps("ws-1", "run-1"); + expect(runWithSteps?.steps.map((step) => step.id)).toEqual(["step-1"]); + expect(runWithSteps?.steps[0]?.durationMs).toBe(77); + expect(runWithSteps?.steps[0]?.rawResponse).toBe("x".repeat(400)); + }); + + it("retains only the newest runs that fit the cap when compacting", async () => { + const config = createTestConfig({ sessionsDir }); + const service = new DevToolsService(config, 700); + + await service.createRun("ws-1", makeRun("run-1", "2025-06-01T00:00:00Z")); + await service.createStep("ws-1", makeStep({ id: "step-1", runId: "run-1" })); + await service.createRun("ws-1", makeRun("run-2", "2025-06-01T00:01:00Z")); + // Crossing the cap rotates; run-1 + step-1 + run-2 exceed 700 bytes, so + // only the newest run survives in the snapshot. + await service.createStep( + "ws-1", + makeStep({ id: "step-2", runId: "run-2", rawResponse: "y".repeat(400) }) + ); + + const reloaded = new DevToolsService(config, 700); + const runs = await reloaded.getRuns("ws-1"); + expect(runs.map((run) => run.id)).toEqual(["run-2"]); + }); + + it("keeps an older zero-step run when rotation happens before its first step", async () => { + const config = createTestConfig({ sessionsDir }); + const service = new DevToolsService(config, 700); + + // run-pending has no steps yet when the cap is crossed (its caller may + // still be awaiting createRun, with steps in flight). + await service.createRun("ws-1", makeRun("run-pending", "2025-06-01T00:00:00Z")); + await service.createRun("ws-1", makeRun("run-new", "2025-06-01T00:01:00Z")); + await service.createStep( + "ws-1", + makeStep({ id: "step-new", runId: "run-new", rawResponse: "y".repeat(400) }) + ); + const reloaded = new DevToolsService(config, 700); + const runs = await reloaded.getRuns("ws-1"); + expect(runs.map((run) => run.id).sort()).toEqual(["run-new", "run-pending"]); + // The retained record is the original, not a createStep self-heal stub. + expect(runs.find((run) => run.id === "run-pending")?.startedAt).toBe("2025-06-01T00:00:00Z"); + }); + + it("keeps an older still-active run replayable when newer runs fill the cap", async () => { + const config = createTestConfig({ sessionsDir }); + const service = new DevToolsService(config, 700); + + await service.createRun("ws-1", makeRun("run-old", "2025-06-01T00:00:00Z")); + // In-progress step (no duration, no error) marks run-old as active. + await service.createStep( + "ws-1", + makeStep({ id: "step-old", runId: "run-old", durationMs: null }) + ); + await service.createRun("ws-1", makeRun("run-new", "2025-06-01T00:01:00Z")); + // Crossing the cap rotates while run-old is still streaming. + await service.createStep( + "ws-1", + makeStep({ id: "step-new", runId: "run-new", rawResponse: "y".repeat(400) }) + ); + // The active run's completion lands in the fresh live file. + await service.updateStep("ws-1", "step-old", { durationMs: 55 }); + + const reloaded = new DevToolsService(config, 700); + const runs = await reloaded.getRuns("ws-1"); + expect(runs.map((run) => run.id).sort()).toEqual(["run-new", "run-old"]); + const oldRun = await reloaded.getRunWithSteps("ws-1", "run-old"); + expect(oldRun?.steps[0]?.durationMs).toBe(55); + }); + + it("does not resurrect evicted runs from a live log orphaned by a rotation crash", async () => { + const config = createTestConfig({ sessionsDir }); + const logPath = getDevtoolsLogPath(sessionsDir, "ws-1"); + const rotatedPath = getRotatedLogPath(sessionsDir, "ws-1"); + await fs.mkdir(path.dirname(logPath), { recursive: true }); + + // Simulate a crash between the snapshot rename and the live-log + // rewrite: the snapshot (generation 2) already dropped run-evicted, + // but the pre-rotation live log (generation 1) still holds it. + await fs.writeFile( + rotatedPath, + [ + JSON.stringify({ type: "snapshot-meta", generation: 2 }), + JSON.stringify({ type: "run", run: makeRun("run-keep", "2025-06-01T00:01:00Z") }), + ] + .map((line) => `${line}\n`) + .join(""), + "utf-8" + ); + await fs.writeFile( + logPath, + [ + JSON.stringify({ type: "log-meta", generation: 1 }), + JSON.stringify({ type: "run", run: makeRun("run-evicted", "2025-06-01T00:00:00Z") }), + ] + .map((line) => `${line}\n`) + .join(""), + "utf-8" + ); + + const service = new DevToolsService(config, 700); + const runs = await service.getRuns("ws-1"); + expect(runs.map((run) => run.id)).toEqual(["run-keep"]); + + // Load completed the interrupted retirement, so new appends pair with + // the snapshot and survive the next restart. + await service.createRun("ws-1", makeRun("run-after", "2025-06-01T00:02:00Z")); + const reloaded = new DevToolsService(config, 700); + const reloadedRuns = await reloaded.getRuns("ws-1"); + expect(reloadedRuns.map((run) => run.id).sort()).toEqual(["run-after", "run-keep"]); + }); + + it("keeps runs and steps that arrive while snapshot I/O is in flight", async () => { + const config = createTestConfig({ sessionsDir }); + // Cap sized so the oversized step triggers exactly one rotation and the + // mid-I/O appends stay under it (no second rotation evicting them). + const service = new DevToolsService(config, 1500); + type SnapshotFn = (...args: unknown[]) => Promise; + const priv = service as unknown as { commitSnapshotPair: SnapshotFn }; + const originalCommit = priv.commitSnapshotPair.bind(service); + + await service.createRun("ws-1", makeRun("run-old", "2025-06-01T00:00:00Z")); + await service.createStep("ws-1", makeStep({ id: "step-old", runId: "run-old" })); + await service.createRun("ws-1", makeRun("run-new", "2025-06-01T00:01:00Z")); + + // Overlapping provider calls land between the retention decision and + // the snapshot I/O completing: a brand-new run, plus a new step for + // run-old (which lost its snapshot spot to the cap). + let midIo: Promise | undefined; + priv.commitSnapshotPair = async (...args: unknown[]) => { + priv.commitSnapshotPair = originalCommit; + midIo = Promise.all([ + service.createRun("ws-1", makeRun("run-mid", "2025-06-01T00:02:00Z")), + service.createStep("ws-1", makeStep({ id: "step-mid-old", runId: "run-old" })), + ]).then(() => undefined); + await originalCommit(...args); + }; + // Crossing the cap triggers rotation with the wrapped snapshot commit. + await service.createStep( + "ws-1", + makeStep({ id: "step-new", runId: "run-new", rawResponse: "y".repeat(2000) }) + ); + expect(midIo).toBeDefined(); + await midIo; + + const runs = await service.getRuns("ws-1"); + expect(runs.map((run) => run.id).sort()).toEqual(["run-mid", "run-new", "run-old"]); + + // Everything also survives a restart: mid-I/O entities landed in the + // fresh live file with their base records. + const reloaded = new DevToolsService(config, 700); + const reloadedRuns = await reloaded.getRuns("ws-1"); + expect(reloadedRuns.map((run) => run.id).sort()).toEqual(["run-mid", "run-new", "run-old"]); + const oldRun = await reloaded.getRunWithSteps("ws-1", "run-old"); + expect(oldRun?.steps.map((step) => step.id).sort()).toEqual(["step-mid-old", "step-old"]); + }); + + it("removeWorkspaceData removes an abandoned snapshot temp file", async () => { + const config = createTestConfig({ sessionsDir }); + const service = new DevToolsService(config, 700); + const tmpPath = `${getRotatedLogPath(sessionsDir, "ws-1")}.tmp`; + + await service.createRun("ws-1", makeRun("run-1")); + // Simulate a rotation interrupted between the tmp write and the rename. + await fs.writeFile(tmpPath, "orphaned snapshot\n", "utf-8"); + + await service.removeWorkspaceData("ws-1"); + expect(await pathExists(tmpPath)).toBe(false); + }); + + it("treats an empty live log as a legacy clear and keeps later appends durable", async () => { + const config = createTestConfig({ sessionsDir }); + const logPath = getDevtoolsLogPath(sessionsDir, "ws-1"); + const rotatedPath = getRotatedLogPath(sessionsDir, "ws-1"); + await fs.mkdir(path.dirname(logPath), { recursive: true }); + + // Marker writes are atomic, so an empty live file next to a committed + // snapshot can only be a legacy binary's truncating clear; the + // snapshot must stay dropped and later appends must survive restarts. + await fs.writeFile( + rotatedPath, + [ + JSON.stringify({ type: "snapshot-meta", generation: 1 }), + JSON.stringify({ type: "run", run: makeRun("run-keep", "2025-06-01T00:00:00Z") }), + ] + .map((line) => `${line}\n`) + .join(""), + "utf-8" + ); + await fs.writeFile(logPath, "", "utf-8"); + + const service = new DevToolsService(config, 700); + await service.createRun("ws-1", makeRun("run-after", "2025-06-01T00:01:00Z")); + + const reloaded = new DevToolsService(config, 700); + const runs = await reloaded.getRuns("ws-1"); + expect(runs.map((run) => run.id)).toEqual(["run-after"]); + }); + + it("keeps appends durable when the live log is missing next to a snapshot", async () => { + const config = createTestConfig({ sessionsDir }); + const logPath = getDevtoolsLogPath(sessionsDir, "ws-1"); + const rotatedPath = getRotatedLogPath(sessionsDir, "ws-1"); + await fs.mkdir(path.dirname(logPath), { recursive: true }); + + // Only a legacy binary's removal path deletes the live file while + // leaving the rotated snapshot; commits always create the live file + // (retire sentinel) before renaming the snapshot. + await fs.writeFile( + rotatedPath, + `${JSON.stringify({ type: "snapshot-meta", generation: 1 })}\n`, + "utf-8" + ); + + const service = new DevToolsService(config, 700); + await service.createRun("ws-1", makeRun("run-after", "2025-06-01T00:01:00Z")); + + const reloaded = new DevToolsService(config, 700); + const runs = await reloaded.getRuns("ws-1"); + expect(runs.map((run) => run.id)).toEqual(["run-after"]); + }); + + it("evicts compacted-away runs from memory and notifies subscribers", async () => { + const config = createTestConfig({ sessionsDir }); + const service = new DevToolsService(config, 700); + const events: DevToolsEvent[] = []; + service.on("update:ws-1", (event: DevToolsEvent) => { + events.push(event); + }); + + await service.createRun("ws-1", makeRun("run-1", "2025-06-01T00:00:00Z")); + await service.createStep("ws-1", makeStep({ id: "step-1", runId: "run-1" })); + await service.createRun("ws-1", makeRun("run-2", "2025-06-01T00:01:00Z")); + await service.createStep( + "ws-1", + makeStep({ id: "step-2", runId: "run-2", rawResponse: "y".repeat(400) }) + ); + + // The completed run-1 was dropped by compaction; memory agrees with disk. + const runs = await service.getRuns("ws-1"); + expect(runs.map((run) => run.id)).toEqual(["run-2"]); + // Open panels were told to drop the evicted card. + expect(events.filter((event) => event.type === "runs-evicted")).toEqual([ + { type: "runs-evicted", runIds: ["run-1"] }, + ]); + }); + + it("ignores a malformed snapshot generation instead of poisoning workspace state", async () => { + const config = createTestConfig({ sessionsDir }); + const logPath = getDevtoolsLogPath(sessionsDir, "ws-1"); + const rotatedPath = getRotatedLogPath(sessionsDir, "ws-1"); + await fs.mkdir(path.dirname(logPath), { recursive: true }); + + // A malformed metadata line must not set logGeneration to NaN, where + // the stale check would flag the live log but the repair branch + // (logGeneration > 0) would be skipped, discarding appends forever. + await fs.writeFile( + rotatedPath, + [ + JSON.stringify({ type: "snapshot-meta", generation: "bad" }), + JSON.stringify({ type: "run", run: makeRun("run-keep", "2025-06-01T00:00:00Z") }), + ] + .map((line) => `${line}\n`) + .join(""), + "utf-8" + ); + + const service = new DevToolsService(config, 700); + await service.createRun("ws-1", makeRun("run-after", "2025-06-01T00:01:00Z")); + + const reloaded = new DevToolsService(config, 700); + const runs = await reloaded.getRuns("ws-1"); + expect(runs.map((run) => run.id).sort()).toEqual(["run-after", "run-keep"]); + }); + + it("repairs the live marker on the next append when the post-snapshot marker write fails", async () => { + const config = createTestConfig({ sessionsDir }); + const service = new DevToolsService(config, 700); + const markerFailure = installMarkerWriteFailure(service); + + await service.createRun("ws-1", makeRun("run-1", "2025-06-01T00:00:00Z")); + await service.createStep("ws-1", makeStep({ id: "step-1", runId: "run-1" })); + // This append crosses the cap; the snapshot rename lands but the + // live-marker write fails (transient ENOSPC). + markerFailure.failNext(); + let thrownMessage = ""; + try { + await service.createStep( + "ws-1", + makeStep({ id: "step-2", runId: "run-1", rawResponse: "y".repeat(700) }) + ); + } catch (error) { + thrownMessage = error instanceof Error ? error.message : String(error); + } + expect(thrownMessage).toContain("ENOSPC"); + + // The next append must repair the marker first; otherwise this run + // lands in a pre-snapshot live file and is discarded on restart. + await service.createRun("ws-1", makeRun("run-2", "2025-06-01T00:01:00Z")); + + const reloaded = new DevToolsService(config, 700); + const runs = await reloaded.getRuns("ws-1"); + expect(runs.map((run) => run.id).sort()).toEqual(["run-1", "run-2"]); + }); + + it("completes eviction and notifies subscribers when the live-marker write fails", async () => { + const config = createTestConfig({ sessionsDir }); + const service = new DevToolsService(config, 1000); + const markerFailure = installMarkerWriteFailure(service); + const events: DevToolsEvent[] = []; + service.on("update:ws-1", (event: DevToolsEvent) => { + events.push(event); + }); + + await service.createRun("ws-1", makeRun("run-1", "2025-06-01T00:00:00Z")); + await service.createStep( + "ws-1", + makeStep({ id: "step-1", runId: "run-1", durationMs: null }) + ); + await service.createRun("ws-1", makeRun("run-2", "2025-06-01T00:01:00Z")); + await service.createStep( + "ws-1", + makeStep({ id: "step-2", runId: "run-2", durationMs: null }) + ); + + // Completing run-1 crosses the cap: the snapshot rename lands + // (dropping run-1) but the live-marker write fails. + markerFailure.failNext(); + let thrownMessage = ""; + try { + await service.updateStep("ws-1", "step-1", { + durationMs: 100, + rawResponse: "z".repeat(800), + }); + } catch (error) { + thrownMessage = error instanceof Error ? error.message : String(error); + } + expect(thrownMessage).toContain("ENOSPC"); + + // The rename committed the retention decision, so the failed rotation + // must still evict run-1 from memory and notify subscribers; otherwise + // later appends can target a run whose records exist nowhere durable. + expect(events.filter((event) => event.type === "runs-evicted")).toEqual([ + { type: "runs-evicted", runIds: ["run-1"] }, + ]); + const runs = await service.getRuns("ws-1"); + expect(runs.map((run) => run.id)).toEqual(["run-2"]); + }); + + it("rejects an unsafe snapshot generation so a reused generation cannot resurrect dropped runs", async () => { + const config = createTestConfig({ sessionsDir }); + const logPath = getDevtoolsLogPath(sessionsDir, "ws-1"); + const rotatedPath = getRotatedLogPath(sessionsDir, "ws-1"); + await fs.mkdir(path.dirname(logPath), { recursive: true }); + + // Corruption Number.isInteger accepts but that cannot be incremented + // (1e100 + 1 === 1e100): every later rotation would reuse the + // generation, so a crash between the snapshot rename and the live + // rewrite leaves an old marker that still compares as current. + await fs.writeFile( + rotatedPath, + `${JSON.stringify({ type: "snapshot-meta", generation: 1e100 })}\n`, + "utf-8" + ); + + const service = new DevToolsService(config, 1000); + const markerFailure = installMarkerWriteFailure(service); + await service.createRun("ws-1", makeRun("run-1", "2025-06-01T00:00:00Z")); + await service.createStep( + "ws-1", + makeStep({ id: "step-1", runId: "run-1", durationMs: null }) + ); + await service.createRun("ws-1", makeRun("run-2", "2025-06-01T00:01:00Z")); + await service.createStep( + "ws-1", + makeStep({ id: "step-2", runId: "run-2", durationMs: null }) + ); + // Rotation drops the completed run-1; the marker failure leaves the + // pre-rotation live file (which still holds run-1's records) in place. + markerFailure.failNext(); + let thrownMessage = ""; + try { + await service.updateStep("ws-1", "step-1", { + durationMs: 100, + rawResponse: "z".repeat(800), + }); + } catch (error) { + thrownMessage = error instanceof Error ? error.message : String(error); + } + expect(thrownMessage).toContain("ENOSPC"); + + // Restart in that crash window: with the poisoned generation reused, + // the stale live file would pass as current and resurrect run-1. The + // large cap keeps load-time stale-step finalization from triggering + // another rotation that would re-evict it and mask the resurrection. + const reloaded = new DevToolsService(config, 1_000_000); + const runs = await reloaded.getRuns("ws-1"); + expect(runs.map((run) => run.id)).toEqual(["run-2"]); + }); + + it("ignores an unsafe snapshot generation so later appends are not repeatedly discarded", async () => { + const config = createTestConfig({ sessionsDir }); + const logPath = getDevtoolsLogPath(sessionsDir, "ws-1"); + const rotatedPath = getRotatedLogPath(sessionsDir, "ws-1"); + await fs.mkdir(path.dirname(logPath), { recursive: true }); + + // If load accepted 1e100 into logGeneration, the marker repair would + // write a marker the stale check can never trust, so every restart + // would discard all appends since the corruption. + await fs.writeFile( + rotatedPath, + [ + JSON.stringify({ type: "snapshot-meta", generation: 1e100 }), + JSON.stringify({ type: "run", run: makeRun("run-keep", "2025-06-01T00:00:00Z") }), + ] + .map((line) => `${line}\n`) + .join(""), + "utf-8" + ); + + const service = new DevToolsService(config, 700); + await service.createRun("ws-1", makeRun("run-after", "2025-06-01T00:01:00Z")); + + const reloaded = new DevToolsService(config, 700); + const runs = await reloaded.getRuns("ws-1"); + expect(runs.map((run) => run.id).sort()).toEqual(["run-after", "run-keep"]); + }); + + it("treats a live log with an unsafe marker generation as stale", async () => { + const config = createTestConfig({ sessionsDir }); + const logPath = getDevtoolsLogPath(sessionsDir, "ws-1"); + const rotatedPath = getRotatedLogPath(sessionsDir, "ws-1"); + await fs.mkdir(path.dirname(logPath), { recursive: true }); + + await fs.writeFile( + rotatedPath, + [ + JSON.stringify({ type: "snapshot-meta", generation: 1 }), + JSON.stringify({ type: "run", run: makeRun("run-keep", "2025-06-01T00:00:00Z") }), + ] + .map((line) => `${line}\n`) + .join(""), + "utf-8" + ); + // A corrupt out-of-range marker generation must not vouch for the live + // file's currency: its dropped-run records would be resurrected. + await fs.writeFile( + logPath, + [ + JSON.stringify({ type: "log-meta", generation: 1e100 }), + JSON.stringify({ type: "run", run: makeRun("run-dropped", "2025-06-01T00:01:00Z") }), + ] + .map((line) => `${line}\n`) + .join(""), + "utf-8" + ); + + const service = new DevToolsService(config, 700); + const runs = await service.getRuns("ws-1"); + expect(runs.map((run) => run.id)).toEqual(["run-keep"]); + }); + + it("treats a live log whose marker generation exceeds the snapshot generation as stale", async () => { + const config = createTestConfig({ sessionsDir }); + const logPath = getDevtoolsLogPath(sessionsDir, "ws-1"); + const rotatedPath = getRotatedLogPath(sessionsDir, "ws-1"); + await fs.mkdir(path.dirname(logPath), { recursive: true }); + + await fs.writeFile( + rotatedPath, + [ + JSON.stringify({ type: "snapshot-meta", generation: 1 }), + JSON.stringify({ type: "run", run: makeRun("run-keep", "2025-06-01T00:00:00Z") }), + ] + .map((line) => `${line}\n`) + .join(""), + "utf-8" + ); + // The protocol only creates matching pairs, so a finite higher marker + // means the live log belongs to a snapshot that is no longer on disk; + // replaying it beside the older snapshot could resurrect runs its own + // rotation had evicted. + await fs.writeFile( + logPath, + [ + JSON.stringify({ type: "log-meta", generation: 2 }), + JSON.stringify({ type: "run", run: makeRun("run-dropped", "2025-06-01T00:01:00Z") }), + ] + .map((line) => `${line}\n`) + .join(""), + "utf-8" + ); + + const service = new DevToolsService(config, 700); + const runs = await service.getRuns("ws-1"); + expect(runs.map((run) => run.id)).toEqual(["run-keep"]); + }); + + it("still loads the snapshot when the live-marker repair write fails, then repairs on the next append", async () => { + const config = createTestConfig({ sessionsDir }); + const logPath = getDevtoolsLogPath(sessionsDir, "ws-1"); + const rotatedPath = getRotatedLogPath(sessionsDir, "ws-1"); + await fs.mkdir(path.dirname(logPath), { recursive: true }); + + // A first rotation interrupted after the snapshot rename leaves the + // markerless pre-rotation live file ending in the retire sentinel: + // load must repair the marker, but a failing repair write must not + // block reading the already-replayed snapshot. + await fs.writeFile( + rotatedPath, + [ + JSON.stringify({ type: "snapshot-meta", generation: 1 }), + JSON.stringify({ type: "run", run: makeRun("run-keep", "2025-06-01T00:00:00Z") }), + ] + .map((line) => `${line}\n`) + .join(""), + "utf-8" + ); + await fs.writeFile( + logPath, + [ + JSON.stringify({ type: "run", run: makeRun("run-keep", "2025-06-01T00:00:00Z") }), + JSON.stringify({ type: "log-retire", generation: 1 }), + ] + .map((line) => `${line}\n`) + .join(""), + "utf-8" + ); + + const service = new DevToolsService(config, 700); + const markerFailure = installMarkerWriteFailure(service); + markerFailure.failNext(); + const runs = await service.getRuns("ws-1"); + expect(runs.map((run) => run.id)).toEqual(["run-keep"]); + + // The marker generation was left lagging, so the next append rewrites + // the marker first and the appended run survives a restart. + await service.createRun("ws-1", makeRun("run-after", "2025-06-01T00:01:00Z")); + const reloaded = new DevToolsService(config, 700); + const reloadedRuns = await reloaded.getRuns("ws-1"); + expect(reloadedRuns.map((run) => run.id).sort()).toEqual(["run-after", "run-keep"]); + }); + + it("rejects a snapshot generation with no safe increment so rotation cannot resurrect dropped runs", async () => { + const config = createTestConfig({ sessionsDir }); + const logPath = getDevtoolsLogPath(sessionsDir, "ws-1"); + const rotatedPath = getRotatedLogPath(sessionsDir, "ws-1"); + await fs.mkdir(path.dirname(logPath), { recursive: true }); + + // A corrupt MAX_SAFE_INTEGER generation passes Number.isSafeInteger, + // but the next rotation writes generation + 1 = 2^53 (unsafe): if a + // crash then leaves the old live log in place, a load that rejects the + // unsafe snapshot generation would treat the snapshot as absent and + // replay the stale live log, resurrecting the run it just evicted. + await fs.writeFile( + rotatedPath, + `${JSON.stringify({ type: "snapshot-meta", generation: Number.MAX_SAFE_INTEGER })}\n`, + "utf-8" + ); + const evictable = makeRun("run-old", "2025-06-01T00:00:00Z"); + const evictableStep = makeStep({ id: "step-old", runId: "run-old" }); + await fs.writeFile( + logPath, + [ + JSON.stringify({ type: "log-meta", generation: Number.MAX_SAFE_INTEGER }), + JSON.stringify({ type: "run", run: evictable }), + JSON.stringify({ type: "step", step: evictableStep }), + ] + .map((line) => `${line}\n`) + .join(""), + "utf-8" + ); + + const service = new DevToolsService(config, 700); + await service.createRun("ws-1", makeRun("run-new", "2025-06-01T00:01:00Z")); + // Crash window: rotation commits the snapshot (evicting run-old) but + // dies before rewriting the live file. + const markerFailure = installMarkerWriteFailure(service); + markerFailure.failNext(); + await service + .createStep( + "ws-1", + makeStep({ id: "step-new", runId: "run-new", rawResponse: "y".repeat(400) }) + ) + .catch(() => undefined); + + const reloaded = new DevToolsService(config, 700); + const runs = await reloaded.getRuns("ws-1"); + expect(runs.map((run) => run.id)).toEqual(["run-new"]); + }); + + it("honors a clear performed by a downgraded pre-rotation binary", async () => { + const config = createTestConfig({ sessionsDir }); + const logPath = getDevtoolsLogPath(sessionsDir, "ws-1"); + const service = new DevToolsService(config, 1500); + await service.createRun("ws-1", makeRun("run-old")); + await service.createStep( + "ws-1", + makeStep({ id: "step-old", runId: "run-old", rawResponse: "y".repeat(2000) }) + ); + expect(await pathExists(getRotatedLogPath(sessionsDir, "ws-1"))).toBe(true); + + // A pre-rotation binary clears by truncating only the live file; it + // does not know the rotated snapshot exists. + await fs.writeFile(logPath, "", "utf-8"); + + const reloaded = new DevToolsService(config, 1500); + expect(await reloaded.getRuns("ws-1")).toEqual([]); + }); + + it("replays a downgraded binary's post-clear runs instead of the rotated snapshot", async () => { + const config = createTestConfig({ sessionsDir }); + const logPath = getDevtoolsLogPath(sessionsDir, "ws-1"); + const service = new DevToolsService(config, 1500); + await service.createRun("ws-1", makeRun("run-old")); + await service.createStep( + "ws-1", + makeStep({ id: "step-old", runId: "run-old", rawResponse: "y".repeat(2000) }) + ); + expect(await pathExists(getRotatedLogPath(sessionsDir, "ws-1"))).toBe(true); + + // After a legacy clear, the pre-rotation binary keeps appending + // markerless entries to the truncated live file. + const legacyRun = makeRun("run-legacy", "2025-06-02T00:00:00Z"); + await fs.writeFile(logPath, `${JSON.stringify({ type: "run", run: legacyRun })}\n`, "utf-8"); + + const reloaded = new DevToolsService(config, 1500); + const runs = await reloaded.getRuns("ws-1"); + expect(runs.map((run) => run.id)).toEqual(["run-legacy"]); + }); + + it("preserves a downgraded binary's writes appended after an interrupted snapshot commit", async () => { + const config = createTestConfig({ sessionsDir }); + const logPath = getDevtoolsLogPath(sessionsDir, "ws-1"); + const rotatedPath = getRotatedLogPath(sessionsDir, "ws-1"); + await fs.mkdir(path.dirname(logPath), { recursive: true }); + + // Crash after the gen-2 snapshot rename but before the live rewrite + // left the gen-1 live file ending in the retire sentinel; a downgraded + // binary then recorded run-legacy after it. Only a legacy writer + // appends entries after a sentinel, so the live history must win. + await fs.writeFile( + rotatedPath, + [ + JSON.stringify({ type: "snapshot-meta", generation: 2 }), + JSON.stringify({ type: "run", run: makeRun("run-snap", "2025-06-01T00:00:00Z") }), + ] + .map((line) => `${line}\n`) + .join(""), + "utf-8" + ); + await fs.writeFile( + logPath, + [ + JSON.stringify({ type: "log-meta", generation: 1 }), + JSON.stringify({ type: "run", run: makeRun("run-live", "2025-06-01T00:01:00Z") }), + JSON.stringify({ type: "log-retire", generation: 2 }), + JSON.stringify({ type: "run", run: makeRun("run-legacy", "2025-06-02T00:00:00Z") }), + ] + .map((line) => `${line}\n`) + .join(""), + "utf-8" + ); + + const service = new DevToolsService(config, 1500); + const runs = await service.getRuns("ws-1"); + expect(runs.map((run) => run.id).sort()).toEqual(["run-legacy", "run-live"]); + }); + + it("seals a partially written retire sentinel so the next append stays replayable", async () => { + const config = createTestConfig({ sessionsDir }); + const service = new DevToolsService(config, 1500); + + await service.createRun("ws-1", makeRun("run-1", "2025-06-01T00:00:00Z")); + + // Disk fills while rotation appends the retire sentinel: the first + // attempt lands only a fragment before rejecting (the live file's + // unterminated tail), and every retried rotation keeps failing, so + // the live file stays the only durable copy of later appends. + const realAppendFile = fs.appendFile; + let sentinelFailures = 0; + const appendSpy = spyOn(fs, "appendFile").mockImplementation( + async (file, content, options) => { + if (typeof content === "string" && content.includes('"log-retire"')) { + sentinelFailures += 1; + if (sentinelFailures === 1) { + await realAppendFile(file, content.slice(0, 12), options); + } + throw new Error("ENOSPC: simulated sentinel write failure"); + } + return realAppendFile(file, content, options); + } + ); + try { + await service + .createStep( + "ws-1", + makeStep({ id: "step-1", runId: "run-1", rawResponse: "y".repeat(2000) }) + ) + .catch(() => undefined); + expect(sentinelFailures).toBe(1); + // The next ordinary append must not merge with the fragment into one + // malformed line, or this run would be lost on the next load. Its + // rotation retry fails too (still over the cap), so the sealed live + // file is what the next load reads. + await service + .createRun("ws-1", makeRun("run-2", "2025-06-01T00:01:00Z")) + .catch(() => undefined); + expect(sentinelFailures).toBe(2); + } finally { + appendSpy.mockRestore(); + } + + const reloaded = new DevToolsService(config, 1500); + const runs = await reloaded.getRuns("ws-1"); + expect(runs.map((run) => run.id).sort()).toEqual(["run-1", "run-2"]); + }); + + it("emits the mutation event when a rotation commits but the marker write fails", async () => { + const config = createTestConfig({ sessionsDir }); + const service = new DevToolsService(config, 700); + const events: DevToolsEvent[] = []; + service.on("update:ws-1", (event: DevToolsEvent) => { + events.push(event); + }); + const markerFailure = installMarkerWriteFailure(service); + + await service.createRun("ws-1", makeRun("run-1", "2025-06-01T00:00:00Z")); + + // The step's own append crosses the cap; the rotation's snapshot rename + // commits the step durably before the live-marker write fails, so the + // rejected createStep must still tell open panels about the step. + markerFailure.failNext(); + let rejected = false; + await service + .createStep( + "ws-1", + makeStep({ id: "step-1", runId: "run-1", rawResponse: "y".repeat(800) }) + ) + .catch(() => { + rejected = true; + }); + expect(rejected).toBe(true); + + const stepCreated = events.filter((event) => event.type === "step-created"); + expect(stepCreated).toHaveLength(1); + expect(events.some((event) => event.type === "run-updated")).toBe(true); + }); + + it("notifies subscribers of a committed clear even when the live-marker write fails", async () => { + const config = createTestConfig({ sessionsDir }); + const service = new DevToolsService(config, 50_000); + const events: DevToolsEvent[] = []; + service.on("update:ws-1", (event: DevToolsEvent) => { + events.push(event); + }); + + await service.createRun("ws-1", makeRun("run-1")); + + // The empty snapshot rename commits the clear before the marker write + // fails, so panels must drop their run cards even though clear rejects. + const markerFailure = installMarkerWriteFailure(service); + markerFailure.failNext(); + let clearError: Error | undefined; + try { + await service.clear("ws-1"); + } catch (error) { + clearError = error instanceof Error ? error : new Error(String(error)); + } + expect(clearError?.message).toContain("ENOSPC"); + expect(events.filter((event) => event.type === "cleared")).toHaveLength(1); + + // Restarts agree with the notification: the workspace is empty. + const reloaded = new DevToolsService(config, 50_000); + expect(await reloaded.getRuns("ws-1")).toEqual([]); + }); + + it("keeps a clear committed at the generation ceiling cleared across restarts", async () => { + const config = createTestConfig({ sessionsDir }); + const logPath = getDevtoolsLogPath(sessionsDir, "ws-1"); + const rotatedPath = getRotatedLogPath(sessionsDir, "ws-1"); + await fs.mkdir(path.dirname(logPath), { recursive: true }); + + // The highest generation the load guard accepts: its own increment is + // still a safe integer, but the increment's increment is not, so a + // commit that blindly writes generation + 1 produces a snapshot the + // next load rejects. + const ceiling = Number.MAX_SAFE_INTEGER - 1; + await fs.writeFile( + rotatedPath, + `${JSON.stringify({ type: "snapshot-meta", generation: ceiling })}\n`, + "utf-8" + ); + await fs.writeFile( + logPath, + [ + JSON.stringify({ type: "log-meta", generation: ceiling }), + JSON.stringify({ type: "run", run: makeRun("run-stale", "2025-06-01T00:00:00Z") }), + ] + .map((line) => `${line}\n`) + .join(""), + "utf-8" + ); + + const service = new DevToolsService(config, 700); + expect((await service.getRuns("ws-1")).map((run) => run.id)).toEqual(["run-stale"]); + + // Interrupt the clear's commit after the snapshot rename: the written + // generation must still pass the next load's guard, or the stale live + // log would be treated as current and resurrect run-stale. + const markerFailure = installMarkerWriteFailure(service); + markerFailure.failNext(); + await service.clear("ws-1").catch(() => undefined); + + const reloaded = new DevToolsService(config, 700); + expect(await reloaded.getRuns("ws-1")).toEqual([]); + }); + + it("does not let a malformed post-sentinel line discard the snapshot as legacy", async () => { + const config = createTestConfig({ sessionsDir }); + const logPath = getDevtoolsLogPath(sessionsDir, "ws-1"); + const rotatedPath = getRotatedLogPath(sessionsDir, "ws-1"); + await fs.mkdir(path.dirname(logPath), { recursive: true }); + + await fs.writeFile( + rotatedPath, + [ + JSON.stringify({ type: "snapshot-meta", generation: 2 }), + JSON.stringify({ type: "run", run: makeRun("run-kept", "2025-06-01T00:01:00Z") }), + ] + .map((line) => `${line}\n`) + .join(""), + "utf-8" + ); + // An interrupted commit's live file: previous pair's marker, stale + // history, the new commit's retire sentinel, then torn lines that + // parse as JSON with a recognized type but a missing or gutted + // payload. Counting either as legacy evidence would clear the + // snapshot and replay lines that replay into nothing usable. + await fs.writeFile( + logPath, + [ + JSON.stringify({ type: "log-meta", generation: 1 }), + JSON.stringify({ type: "run", run: makeRun("run-stale", "2025-06-01T00:00:00Z") }), + JSON.stringify({ type: "log-retire", generation: 2 }), + JSON.stringify({ type: "step-update" }), + JSON.stringify({ type: "run", run: { id: "x" } }), + ] + .map((line) => `${line}\n`) + .join(""), + "utf-8" + ); + + const service = new DevToolsService(config, 50_000); + expect((await service.getRuns("ws-1")).map((run) => run.id)).toEqual(["run-kept"]); + }); + + it("persists pending base records through the next append when the mid-I/O repair write fails", async () => { + const config = createTestConfig({ sessionsDir }); + // Cap sized so the oversized step triggers exactly one rotation and + // run-old (completed) loses its snapshot spot to run-new. + const service = new DevToolsService(config, 1500); + type SnapshotFn = (...args: unknown[]) => Promise; + type RepairFn = (data: unknown, filePath: string, content: string) => Promise; + const priv = service as unknown as { + commitSnapshotPair: SnapshotFn; + appendWithMarkerRepair: RepairFn; + }; + const originalCommit = priv.commitSnapshotPair.bind(service); + const originalRepair = priv.appendWithMarkerRepair.bind(service); + + await service.createRun("ws-1", makeRun("run-old", "2025-06-01T00:00:00Z")); + await service.createStep("ws-1", makeStep({ id: "step-old", runId: "run-old" })); + await service.createRun("ws-1", makeRun("run-new", "2025-06-01T00:01:00Z")); + + // run-old gains a step while snapshot I/O is in flight, so rotation + // must re-persist its base records into the fresh live file; that + // repair write fails once (simulated EIO). + let failedRepair = false; + priv.appendWithMarkerRepair = (data, filePath, content) => { + if (!failedRepair && content.startsWith('{"type":"run"') && content.includes("run-old")) { + failedRepair = true; + return Promise.reject(new Error("EIO: simulated repair append failure")); + } + return originalRepair(data, filePath, content); + }; + let midIo: Promise | undefined; + priv.commitSnapshotPair = async (...args: unknown[]) => { + priv.commitSnapshotPair = originalCommit; + midIo = service + .createStep("ws-1", makeStep({ id: "step-mid-old", runId: "run-old" })) + .then(() => undefined); + await originalCommit(...args); + }; + await service + .createStep( + "ws-1", + makeStep({ id: "step-new", runId: "run-new", rawResponse: "y".repeat(2000) }) + ) + .catch(() => undefined); + expect(failedRepair).toBe(true); + expect(midIo).toBeDefined(); + await midIo; + + // The queued step append completed the pending base repair first, so + // run-old's records are durable and the run survives a restart. + const reloaded = new DevToolsService(config, 1500); + const runs = await reloaded.getRuns("ws-1"); + expect(runs.map((run) => run.id).sort()).toEqual(["run-new", "run-old"]); + const runWithSteps = await reloaded.getRunWithSteps("ws-1", "run-old"); + expect(runWithSteps?.steps.map((step) => step.id).sort()).toEqual([ + "step-mid-old", + "step-old", + ]); + }); + + it("recovers a pending base repair whose first attempt wrote a partial fragment", async () => { + const config = createTestConfig({ sessionsDir }); + const service = new DevToolsService(config, 1500); + const logPath = getDevtoolsLogPath(sessionsDir, "ws-1"); + type SnapshotFn = (...args: unknown[]) => Promise; + type RepairFn = (data: unknown, filePath: string, content: string) => Promise; + const priv = service as unknown as { + commitSnapshotPair: SnapshotFn; + appendWithMarkerRepair: RepairFn; + }; + const originalCommit = priv.commitSnapshotPair.bind(service); + const originalRepair = priv.appendWithMarkerRepair.bind(service); + + await service.createRun("ws-1", makeRun("run-old", "2025-06-01T00:00:00Z")); + await service.createStep("ws-1", makeStep({ id: "step-old", runId: "run-old" })); + await service.createRun("ws-1", makeRun("run-new", "2025-06-01T00:01:00Z")); + + // The mid-I/O base repair writes only part of run-old's record before + // rejecting (disk full mid-write): the retry must not merge with that + // fragment into one malformed line, or the run stays lost after restart. + let failedRepair = false; + priv.appendWithMarkerRepair = async (data, filePath, content) => { + if (!failedRepair && content.startsWith('{"type":"run"') && content.includes("run-old")) { + failedRepair = true; + await fs.appendFile(filePath, content.slice(0, 30), "utf-8"); + throw new Error("ENOSPC: simulated partial repair write"); + } + return originalRepair(data, filePath, content); + }; + let midIo: Promise | undefined; + priv.commitSnapshotPair = async (...args: unknown[]) => { + priv.commitSnapshotPair = originalCommit; + midIo = service + .createStep("ws-1", makeStep({ id: "step-mid-old", runId: "run-old" })) + .then(() => undefined); + await originalCommit(...args); + }; + await service + .createStep( + "ws-1", + makeStep({ id: "step-new", runId: "run-new", rawResponse: "y".repeat(2000) }) + ) + .catch(() => undefined); + expect(failedRepair).toBe(true); + expect(midIo).toBeDefined(); + await midIo; + // The fragment really is on disk (unterminated), so this exercises the + // seal rather than a clean retry. + expect((await fs.readFile(logPath, "utf-8")).includes('{"type":"run"')).toBe(true); + + const reloaded = new DevToolsService(config, 1500); + const runs = await reloaded.getRuns("ws-1"); + expect(runs.map((run) => run.id).sort()).toEqual(["run-new", "run-old"]); + const runWithSteps = await reloaded.getRunWithSteps("ws-1", "run-old"); + expect(runWithSteps?.steps.map((step) => step.id).sort()).toEqual([ + "step-mid-old", + "step-old", + ]); + }); + + it("does not requeue pre-clear base records when a clear lands during the failed repair append", async () => { + const config = createTestConfig({ sessionsDir }); + const service = new DevToolsService(config, 1500); + type SnapshotFn = (...args: unknown[]) => Promise; + type RepairFn = (data: unknown, filePath: string, content: string) => Promise; + const priv = service as unknown as { + commitSnapshotPair: SnapshotFn; + appendWithMarkerRepair: RepairFn; + }; + const originalCommit = priv.commitSnapshotPair.bind(service); + const originalRepair = priv.appendWithMarkerRepair.bind(service); + + await service.createRun("ws-1", makeRun("run-old", "2025-06-01T00:00:00Z")); + await service.createStep("ws-1", makeStep({ id: "step-old", runId: "run-old" })); + await service.createRun("ws-1", makeRun("run-new", "2025-06-01T00:01:00Z")); + + // clear() lands while reconciliation awaits run-old's failing base + // repair: the clear empties the repair queue, so the catch must not + // repopulate it with pre-clear records that the next successful + // append would flush into the post-clear live file. + let clearPromise: Promise | undefined; + let failedRepair = false; + priv.appendWithMarkerRepair = (data, filePath, content) => { + if (!failedRepair && content.startsWith('{"type":"run"') && content.includes("run-old")) { + failedRepair = true; + clearPromise = service.clear("ws-1"); + return Promise.reject(new Error("EIO: simulated repair append failure")); + } + return originalRepair(data, filePath, content); + }; + let midIo: Promise | undefined; + priv.commitSnapshotPair = async (...args: unknown[]) => { + priv.commitSnapshotPair = originalCommit; + midIo = service + .createStep("ws-1", makeStep({ id: "step-mid-old", runId: "run-old" })) + .catch(() => undefined); + await originalCommit(...args); + }; + await service + .createStep( + "ws-1", + makeStep({ id: "step-new", runId: "run-new", rawResponse: "y".repeat(2000) }) + ) + .catch(() => undefined); + expect(failedRepair).toBe(true); + expect(clearPromise).toBeDefined(); + await clearPromise!.catch(() => undefined); + await midIo; + + // The first post-clear append flushes any queued repairs; cleared + // history must not ride along with it. + await service.createRun("ws-1", makeRun("run-after", "2025-06-01T00:02:00Z")); + + const reloaded = new DevToolsService(config, 1500); + const runs = await reloaded.getRuns("ws-1"); + expect(runs.map((run) => run.id)).toEqual(["run-after"]); + }); + + it("keeps a run recreated after a mid-rotation clear instead of evicting it", async () => { + const config = createTestConfig({ sessionsDir }); + const service = new DevToolsService(config, 1500); + type SnapshotFn = (...args: unknown[]) => Promise; + const priv = service as unknown as { + commitSnapshotPair: SnapshotFn; + workspaces: Map }>; + }; + const originalCommit = priv.commitSnapshotPair.bind(service); + + await service.createRun("ws-1", makeRun("run-old", "2025-06-01T00:00:00Z")); + await service.createStep("ws-1", makeStep({ id: "step-old", runId: "run-old" })); + await service.createRun("ws-1", makeRun("run-new", "2025-06-01T00:01:00Z")); + + // clear() lands while rotation awaits snapshot I/O, then the active + // middleware recreates run-old's frozen ID via createStep's self-heal. + // The recreated run has no steps in the maps yet (createStep awaits the + // queued run append first), so the frozen retention decision would + // otherwise evict it, skip its queued base append, and throw on the + // missing run when createStep resumes. + let clearPromise: Promise | undefined; + let recreatePromise: Promise | undefined; + priv.commitSnapshotPair = async (...args: unknown[]) => { + priv.commitSnapshotPair = originalCommit; + clearPromise = service.clear("ws-1"); + recreatePromise = service.createStep( + "ws-1", + makeStep({ id: "step-post-clear", runId: "run-old", startedAt: "2025-06-01T00:02:00Z" }) + ); + while (!priv.workspaces.get("ws-1")?.runs.has("run-old")) { + await new Promise((resolve) => setTimeout(resolve, 1)); + } + await originalCommit(...args); + }; + await service.createStep( + "ws-1", + makeStep({ id: "step-new", runId: "run-new", rawResponse: "y".repeat(2000) }) + ); + expect(clearPromise).toBeDefined(); + expect(recreatePromise).toBeDefined(); + await clearPromise; + await recreatePromise; + + // Post-clear state is exactly the recreated run and its step, durably. + const reloaded = new DevToolsService(config, 1500); + const runs = await reloaded.getRuns("ws-1"); + expect(runs.map((run) => run.id)).toEqual(["run-old"]); + const runWithSteps = await reloaded.getRunWithSteps("ws-1", "run-old"); + expect(runWithSteps?.steps.map((step) => step.id)).toEqual(["step-post-clear"]); + }); + + it("does not emit a step update after its run was evicted by that append's rotation", async () => { + const config = createTestConfig({ sessionsDir }); + const service = new DevToolsService(config, 1000); + const events: DevToolsEvent[] = []; + service.on("update:ws-1", (event: DevToolsEvent) => { + events.push(event); + }); + + await service.createRun("ws-1", makeRun("run-1", "2025-06-01T00:00:00Z")); + await service.createStep( + "ws-1", + makeStep({ id: "step-1", runId: "run-1", durationMs: null }) + ); + await service.createRun("ws-1", makeRun("run-2", "2025-06-01T00:01:00Z")); + await service.createStep( + "ws-1", + makeStep({ id: "step-2", runId: "run-2", durationMs: null }) + ); + + // The final step-update completes run-1 and crosses the cap, so the + // rotation inside this very append evicts run-1 (run-2 stays active). + await service.updateStep("ws-1", "step-1", { + durationMs: 100, + rawResponse: "z".repeat(800), + }); + + expect(events.filter((event) => event.type === "runs-evicted")).toEqual([ + { type: "runs-evicted", runIds: ["run-1"] }, + ]); + // No step-updated may follow the eviction: subscribers would re-add + // the step that backend and disk no longer contain. + expect(events.filter((event) => event.type === "step-updated")).toEqual([]); + }); + + it("clear() leaves no replayable entries in either log file", async () => { + const config = createTestConfig({ sessionsDir }); + const service = new DevToolsService(config, 1); + const rotatedPath = getRotatedLogPath(sessionsDir, "ws-1"); + + await service.createRun("ws-1", makeRun("run-1")); + expect(await pathExists(rotatedPath)).toBe(true); + + await service.clear("ws-1"); + const entryTypes = async (filePath: string) => + (await fs.readFile(filePath, "utf-8")) + .split("\n") + .filter(Boolean) + .map((line) => (JSON.parse(line) as { type: string }).type); + // Both files hold only generation markers (disk reclaimed, nothing replayable). + expect(await entryTypes(rotatedPath)).toEqual(["snapshot-meta"]); + expect(await entryTypes(getDevtoolsLogPath(sessionsDir, "ws-1"))).toEqual(["log-meta"]); + expect((await new DevToolsService(config, 1).getRuns("ws-1")).length).toBe(0); + }); + + it("an interrupted clear stays cleared after restart", async () => { + const config = createTestConfig({ sessionsDir }); + const service = new DevToolsService(config, 1); + const logPath = getDevtoolsLogPath(sessionsDir, "ws-1"); + const rotatedPath = getRotatedLogPath(sessionsDir, "ws-1"); + + await service.createRun("ws-1", makeRun("run-1")); + const liveBeforeClear = await fs.readFile(logPath, "utf-8"); + await service.clear("ws-1"); + // Simulate a crash between clear's snapshot commit and its live-log + // rewrite: the pre-clear live content is still on disk. + await fs.writeFile(logPath, liveBeforeClear, "utf-8"); + + const reloaded = new DevToolsService(config, 1); + expect((await reloaded.getRuns("ws-1")).length).toBe(0); + expect(await pathExists(rotatedPath)).toBe(true); + }); + + it("removeWorkspaceData also removes the rotated file", async () => { + const config = createTestConfig({ sessionsDir }); + const service = new DevToolsService(config, 1); + const rotatedPath = getRotatedLogPath(sessionsDir, "ws-1"); + + await service.createRun("ws-1", makeRun("run-1")); + expect(await pathExists(rotatedPath)).toBe(true); + + await service.removeWorkspaceData("ws-1"); + expect(await pathExists(rotatedPath)).toBe(false); + expect(await pathExists(getDevtoolsLogPath(sessionsDir, "ws-1"))).toBe(false); + }); + }); }); diff --git a/src/node/services/devToolsService.ts b/src/node/services/devToolsService.ts index f9d1da5566..f3897510c6 100644 --- a/src/node/services/devToolsService.ts +++ b/src/node/services/devToolsService.ts @@ -10,6 +10,7 @@ import type { DevToolsStep, } from "@/common/types/devtools"; import type { Config } from "@/node/config"; +import { DEVTOOLS_LOG_MAX_BYTES, DEVTOOLS_LOG_ROTATED_SUFFIX } from "@/constants/devtools"; import { log } from "@/node/services/log"; interface WorkspaceData { @@ -18,6 +19,191 @@ interface WorkspaceData { loaded: boolean; /** Incremented on each clear() for defense-in-depth against stale state. */ clearGeneration: number; + /** Rotation count, persisted via snapshot-meta/log-meta pairs. */ + logGeneration: number; + /** + * Generation of the log-meta marker actually present in the live file. + * Falls behind logGeneration when a snapshot commits but the live-marker + * write fails (e.g. ENOSPC); appends repair the marker before writing so + * they are not discarded as pre-snapshot on the next load. + */ + liveMarkerGeneration: number; + /** + * Base-record content whose live-file write failed during rotation + * reconciliation. Must land before any later append: a queued step append + * succeeding while its run's base records exist nowhere durable would + * orphan the step on the next load. + */ + pendingLiveRepairs: string[]; + /** + * Set when an append to the live file rejects: the write may have landed + * partially, leaving an unterminated fragment as the file's tail. The + * next append must start with a newline so the fragment seals into its + * own malformed line instead of merging with (and destroying) the next + * record. + */ + liveTailMayBeTorn: boolean; +} + +/** + * Detects a live file shaped like a pre-rotation binary left it. Such a + * binary clears by truncating devtools.jsonl to empty (or removes it + * outright) without touching the rotated snapshot, and its appends carry no + * log-meta marker. A markerless live file also arises when a first + * snapshot commit (generation 0 -> 1) is interrupted before the live + * rewrite; the retire sentinel written by commitSnapshotPair tells those + * apart, so callers must also consult hasRetireSentinel. A partial + * (unparseable) first line is not classified as legacy: marker writes are + * atomic, so only a legacy append crash produces it, and preferring the + * snapshot there merely loses part of one legacy debug session. + */ +function isLegacyLiveLog(liveRaw: string | null): boolean { + if (liveRaw == null) { + return true; + } + const firstLine = liveRaw.split("\n").find((line) => line.trim().length > 0); + if (firstLine == null) { + return true; + } + try { + const entry = JSON.parse(firstLine) as DevToolsLogEntry; + return entry.type !== "log-meta"; + } catch { + return false; + } +} + +/** + * True when the live file carries the retire sentinel for exactly this + * snapshot generation, i.e. the markerless live file is an interrupted + * current-version commit (snapshot wins), not a legacy rewrite (live wins). + * A legacy clear truncates the live file, destroying any sentinel, so a + * post-downgrade clear can never be mistaken for an interrupted commit. + */ +function hasRetireSentinel(liveRaw: string | null, snapshotGeneration: number): boolean { + if (liveRaw == null) { + return false; + } + for (const line of liveRaw.split("\n")) { + if (!line.trim()) { + continue; + } + try { + const entry = JSON.parse(line) as DevToolsLogEntry; + if (entry.type === "log-retire" && entry.generation === snapshotGeneration) { + return true; + } + } catch { + // Partial trailing line from an interrupted append. + } + } + return false; +} + +function isNonEmptyString(value: unknown): value is string { + return typeof value === "string" && value.length > 0; +} + +/** + * True only for a history entry a legacy writer could actually have + * produced: the payload fields replay depends on must be present (a run + * needs id, workspaceId, and startedAt; a step needs id, runId, and + * startedAt). A line that parses as JSON with a recognized type but a + * missing or gutted payload (for example a torn `{"type":"step-update"}` + * or `{"run":{"id":"x"}}`) is corruption, and letting it count as legacy + * evidence would discard the snapshot for a line that replays into + * nothing usable. + */ +function isReplayableHistoryEntry(entry: DevToolsLogEntry): boolean { + switch (entry.type) { + case "run": + return ( + isRecord(entry.run) && + isNonEmptyString(entry.run.id) && + isNonEmptyString(entry.run.workspaceId) && + isNonEmptyString(entry.run.startedAt) + ); + case "step": + return ( + isRecord(entry.step) && + isNonEmptyString(entry.step.id) && + isNonEmptyString(entry.step.runId) && + isNonEmptyString(entry.step.startedAt) + ); + case "step-update": + return typeof entry.stepId === "string" && entry.stepId.length > 0 && isRecord(entry.update); + default: + return false; + } +} + +/** + * True when valid log entries follow the LAST retire sentinel for this + * snapshot generation. The current binary never appends entries after + * writing a sentinel (the commit either rewrites the live file or fails, + * and a failed commit's retry writes a fresh sentinel after any entries it + * appended), so such entries prove a downgraded pre-rotation binary + * recorded them after the interrupted commit; the live history must win or + * the downgraded session's runs would be discarded as stale. + */ +function hasLegacyEntriesAfterRetireSentinel( + liveRaw: string | null, + snapshotGeneration: number +): boolean { + if (liveRaw == null) { + return false; + } + let entriesSinceSentinel = false; + let sawSentinel = false; + for (const line of liveRaw.split("\n")) { + if (!line.trim()) { + continue; + } + try { + const entry = JSON.parse(line) as DevToolsLogEntry; + if (entry.type === "log-retire" && entry.generation === snapshotGeneration) { + sawSentinel = true; + entriesSinceSentinel = false; + continue; + } + if (isReplayableHistoryEntry(entry)) { + entriesSinceSentinel = true; + } + } catch { + // Partial trailing line from an interrupted append. + } + } + return sawSentinel && entriesSinceSentinel; +} + +/** + * A live log written after a rotation starts with a log-meta line carrying + * exactly the snapshot's generation. When a snapshot exists (generation >= 1) + * and the marker generation differs, the pair is broken: replaying the live + * log could resurrect runs a snapshot retirement dropped, so its marker gets + * repaired before ordinary appends land and make the file look pre-snapshot + * forever. Markerless and empty live files are classified by isLegacyLiveLog + * before this check applies. + */ +function isStaleLiveLog(raw: string, snapshotGeneration: number): boolean { + if (snapshotGeneration === 0) { + return false; + } + const firstLine = raw.split("\n").find((line) => line.trim().length > 0); + if (firstLine == null) { + return true; + } + try { + const entry = JSON.parse(firstLine) as DevToolsLogEntry; + // The protocol only commits matching snapshot/live pairs: a lower or + // missing generation predates the snapshot, a higher one pairs with a + // snapshot that is no longer on disk, and either can resurrect dropped + // runs. Strict equality against the validated snapshot generation also + // rejects corrupt markers (numeric strings, unsafe numbers). + return !(entry.type === "log-meta" && entry.generation === snapshotGeneration); + } catch { + return true; + } } function isRecord(value: unknown): value is Record { @@ -97,7 +283,10 @@ export class DevToolsService extends EventEmitter { */ private readonly pendingRunMetadata = new Map>(); - constructor(private readonly config: Config) { + constructor( + private readonly config: Config, + private readonly maxLogBytes: number = DEVTOOLS_LOG_MAX_BYTES + ) { super(); } @@ -199,10 +388,27 @@ export class DevToolsService extends EventEmitter { } data.runs.set(run.id, run); - await this.appendToFile(workspaceId, { type: "run", run }); - - const summary = this.buildRunSummary(data, run.id); - this.emitWorkspaceEvent(workspaceId, { type: "run-created", run: summary }); + // Emit even when the append rejects (guarded against mid-append + // eviction/clear): the run may already be durable (a rotation's snapshot + // rename commits before a failed live-marker write throws), and memory, + // which backs detail lookups, holds it either way; swallowing the event + // would leave open panels inconsistent until resubscribe. + const emitRunCreated = (): void => { + if (!data.runs.has(run.id)) { + return; + } + this.emitWorkspaceEvent(workspaceId, { + type: "run-created", + run: this.buildRunSummary(data, run.id), + }); + }; + try { + await this.appendToFile(workspaceId, { type: "run", run }); + } catch (error) { + emitRunCreated(); + throw error; + } + emitRunCreated(); } async createStep(workspaceId: string, step: DevToolsStep): Promise { @@ -225,21 +431,46 @@ export class DevToolsService extends EventEmitter { startedAt: step.startedAt, }; data.runs.set(autoRun.id, autoRun); - await this.appendToFile(workspaceId, { type: "run", run: autoRun }); - this.emitWorkspaceEvent(workspaceId, { - type: "run-created", - run: this.buildRunSummary(data, autoRun.id), - }); + // Emit-on-failure rationale in createRun. + const emitAutoRunCreated = (): void => { + if (!data.runs.has(autoRun.id)) { + return; + } + this.emitWorkspaceEvent(workspaceId, { + type: "run-created", + run: this.buildRunSummary(data, autoRun.id), + }); + }; + try { + await this.appendToFile(workspaceId, { type: "run", run: autoRun }); + } catch (error) { + emitAutoRunCreated(); + throw error; + } + emitAutoRunCreated(); } data.steps.set(step.id, step); - await this.appendToFile(workspaceId, { type: "step", step }); - - this.emitWorkspaceEvent(workspaceId, { type: "step-created", step }); - if (data.runs.has(step.runId)) { - const summary = this.buildRunSummary(data, step.runId); - this.emitWorkspaceEvent(workspaceId, { type: "run-updated", run: summary }); + // The append itself can trigger a rotation that evicts this step's run; + // emitting after the runs-evicted event would resurrect it in open + // panels. Emit-on-failure rationale in createRun. + const emitStepCreated = (): void => { + if (!data.steps.has(step.id)) { + return; + } + this.emitWorkspaceEvent(workspaceId, { type: "step-created", step }); + if (data.runs.has(step.runId)) { + const summary = this.buildRunSummary(data, step.runId); + this.emitWorkspaceEvent(workspaceId, { type: "run-updated", run: summary }); + } + }; + try { + await this.appendToFile(workspaceId, { type: "step", step }); + } catch (error) { + emitStepCreated(); + throw error; } + emitStepCreated(); } async updateStep( @@ -267,21 +498,35 @@ export class DevToolsService extends EventEmitter { }; data.steps.set(stepId, mergedStep); - await this.appendToFile(workspaceId, { - type: "step-update", - stepId, - update, - }); - - this.emitWorkspaceEvent(workspaceId, { - type: "step-updated", - step: mergedStep, - }); + // The append itself can trigger a rotation that evicts this step's run + // (a final step-update crossing the cap completes the run); emitting + // after the runs-evicted event would resurrect the step in open panels. + // Emit-on-failure rationale in createRun. + const emitStepUpdated = (): void => { + if (!data.steps.has(stepId)) { + return; + } + this.emitWorkspaceEvent(workspaceId, { + type: "step-updated", + step: mergedStep, + }); - if (data.runs.has(mergedStep.runId)) { - const summary = this.buildRunSummary(data, mergedStep.runId); - this.emitWorkspaceEvent(workspaceId, { type: "run-updated", run: summary }); + if (data.runs.has(mergedStep.runId)) { + const summary = this.buildRunSummary(data, mergedStep.runId); + this.emitWorkspaceEvent(workspaceId, { type: "run-updated", run: summary }); + } + }; + try { + await this.appendToFile(workspaceId, { + type: "step-update", + stepId, + update, + }); + } catch (error) { + emitStepUpdated(); + throw error; } + emitStepUpdated(); } async finalizeStaleSteps(workspaceId: string): Promise { @@ -355,18 +600,34 @@ export class DevToolsService extends EventEmitter { const data = this.getOrCreateWorkspaceData(workspaceId); data.runs.clear(); data.steps.clear(); + // Queued base repairs belong to cleared runs; flushing them after the + // clear would resurrect those runs on the next load. + data.pendingLiveRepairs = []; data.clearGeneration += 1; data.loaded = true; this.pendingRunMetadata.delete(workspaceId); - // Enqueue truncation so clear() cannot race with pending appends. + // Enqueue so clear() cannot race with pending appends. An empty snapshot + // pair (instead of truncate-then-remove) keeps an interrupted clear + // cleared: after the snapshot rename commits, a leftover live log is + // stale by generation and skipped on the next load. + let markerError: Error | undefined; await this.enqueueWrite(workspaceId, async () => { - const filePath = this.getSessionFilePath(workspaceId); - await fs.mkdir(path.dirname(filePath), { recursive: true }); - await fs.writeFile(filePath, "", "utf-8"); + markerError = await this.commitSnapshotPair( + workspaceId, + data, + this.getSessionFilePath(workspaceId), + [] + ); }); + // A marker-write failure happens after the snapshot rename committed the + // clear: memory, detail lookups, and future restarts are already empty, + // so subscribers must drop their run cards before the failure propagates. this.emitWorkspaceEvent(workspaceId, { type: "cleared" }); + if (markerError !== undefined) { + throw markerError; + } } /** @@ -399,6 +660,11 @@ export class DevToolsService extends EventEmitter { // Enqueue the deletion so it serializes behind any pending appends. await this.enqueueWrite(workspaceId, async () => { await fs.rm(this.getSessionFilePath(workspaceId), { force: true }); + await fs.rm(this.getRotatedFilePath(workspaceId), { force: true }); + // An interrupted rotation can leave a full compacted snapshot here. + await fs.rm(this.getRotatedTmpFilePath(workspaceId), { force: true }); + // An interrupted marker write can leave its tmp file behind. + await fs.rm(`${this.getSessionFilePath(workspaceId)}.tmp`, { force: true }); }); this.emitWorkspaceEvent(workspaceId, { type: "cleared" }); @@ -412,6 +678,14 @@ export class DevToolsService extends EventEmitter { return path.join(this.config.getSessionDir(workspaceId), "devtools.jsonl"); } + private getRotatedFilePath(workspaceId: string): string { + return `${this.getSessionFilePath(workspaceId)}${DEVTOOLS_LOG_ROTATED_SUFFIX}`; + } + + private getRotatedTmpFilePath(workspaceId: string): string { + return `${this.getRotatedFilePath(workspaceId)}.tmp`; + } + private getOrCreateWorkspaceData(workspaceId: string): WorkspaceData { let data = this.workspaces.get(workspaceId); if (data) { @@ -423,6 +697,10 @@ export class DevToolsService extends EventEmitter { steps: new Map(), loaded: false, clearGeneration: 0, + logGeneration: 0, + liveMarkerGeneration: 0, + pendingLiveRepairs: [], + liveTailMayBeTorn: false, }; this.workspaces.set(workspaceId, data); return data; @@ -455,19 +733,86 @@ export class DevToolsService extends EventEmitter { } private async loadFromDisk(workspaceId: string, data: WorkspaceData): Promise { - const filePath = this.getSessionFilePath(workspaceId); - let raw = ""; + const readOrNull = async (filePath: string): Promise => { + try { + return await fs.readFile(filePath, "utf-8"); + } catch (error) { + if (isRecord(error) && error.code === "ENOENT") { + return null; + } + throw error; + } + }; - try { - raw = await fs.readFile(filePath, "utf-8"); - } catch (error) { - if (isRecord(error) && error.code === "ENOENT") { - data.loaded = true; - return; + const rotatedRaw = await readOrNull(this.getRotatedFilePath(workspaceId)); + const livePath = this.getSessionFilePath(workspaceId); + const liveRaw = await readOrNull(livePath); + + // Rotated log first so live-file step-updates can find their base records. + if (rotatedRaw != null) { + this.replayLogLines(workspaceId, data, rotatedRaw); + } + + // A validly committed snapshot paired with a markerless live file means + // either a downgraded pre-rotation binary rewrote (or cleared) the live + // file, or a commit was interrupted before the live rewrite. The retire + // sentinel separates them: without it, the live file is legacy and wins, + // because replaying the snapshot would resurrect history the user + // cleared while downgraded and discard the legacy binary's newer runs. + // Entries recorded AFTER the sentinel equally prove a legacy writer: + // a downgraded binary appending to an interrupted commit's live file + // leaves the stale marker (or no marker) in place, so without this + // check its writes would be discarded as stale. Generations reset to 0, + // so appends continue markerless until the next rotation re-establishes + // a snapshot/marker pair. + if ( + data.logGeneration > 0 && + (hasLegacyEntriesAfterRetireSentinel(liveRaw, data.logGeneration) || + (isLegacyLiveLog(liveRaw) && !hasRetireSentinel(liveRaw, data.logGeneration))) + ) { + data.runs.clear(); + data.steps.clear(); + data.logGeneration = 0; + data.liveMarkerGeneration = 0; + if (liveRaw != null) { + this.replayLogLines(workspaceId, data, liveRaw); + } + data.loaded = true; + await this.finalizeStaleStepsForLoadedWorkspace(workspaceId, data); + return; + } + + if (liveRaw != null && !isStaleLiveLog(liveRaw, data.logGeneration)) { + this.replayLogLines(workspaceId, data, liveRaw); + data.liveMarkerGeneration = data.logGeneration; + } else if (data.logGeneration > 0) { + // A crash interrupted rotation (or clear) between the snapshot rename + // and the live-log rewrite, leaving the live file stale or missing. + // Replaying a stale file would resurrect dropped runs, and appends + // landing before a marker exists would look pre-snapshot on the next + // load, so finish the interrupted retirement instead. + if (liveRaw != null) { + log.warn("Skipping stale devtools.jsonl superseded by rotated snapshot", { workspaceId }); + } + try { + await this.writeLiveMarker(livePath, data.logGeneration); + data.liveMarkerGeneration = data.logGeneration; + } catch (error) { + // Best-effort: the snapshot already replayed, so loading must not + // fail on an unwritable session dir. The lagging marker generation + // makes the next append retry this repair. + log.warn("Failed to repair devtools.jsonl live marker on load", { + workspaceId, + error: String(error), + }); } - throw error; } + data.loaded = true; + await this.finalizeStaleStepsForLoadedWorkspace(workspaceId, data); + } + + private replayLogLines(workspaceId: string, data: WorkspaceData, raw: string): void { const lines = raw.split("\n"); for (const line of lines) { if (!line.trim()) { @@ -498,6 +843,30 @@ export class DevToolsService extends EventEmitter { } break; } + case "snapshot-meta": { + // A malformed generation would poison logGeneration: a string + // yields NaN (every comparison fails, the repair branch is + // skipped, appends are discarded on each restart) and an unsafe + // number like 1e100 stops incrementing (generation + 1 === + // generation), so rotations reuse the generation and a stale + // live marker can pass as current. The next rotation writes + // generation + 1, so that increment must be safe too, or its + // snapshot would be ignored on the following load and the stale + // live log replayed. Ignore invalid metadata. + if ( + Number.isSafeInteger(entry.generation) && + Number.isSafeInteger(entry.generation + 1) && + entry.generation >= 0 + ) { + data.logGeneration = Math.max(data.logGeneration, entry.generation); + } + break; + } + case "log-meta": + case "log-retire": { + // Pairing is decided in loadFromDisk before replay; nothing to apply. + break; + } default: { log.warn("Skipping unknown devtools.jsonl entry type", { workspaceId, @@ -508,9 +877,6 @@ export class DevToolsService extends EventEmitter { log.warn("Skipping corrupted devtools.jsonl line"); } } - - data.loaded = true; - await this.finalizeStaleStepsForLoadedWorkspace(workspaceId, data); } private async finalizeStaleStepsForLoadedWorkspace( @@ -626,7 +992,294 @@ export class DevToolsService extends EventEmitter { const filePath = this.getSessionFilePath(workspaceId); await fs.mkdir(path.dirname(filePath), { recursive: true }); - await fs.appendFile(filePath, `${JSON.stringify(entry)}\n`, "utf-8"); + await this.appendWithMarkerRepair(data, filePath, `${JSON.stringify(entry)}\n`); + + // The write queue serializes rotation with appends and clear(). + const stats = await fs.stat(filePath); + if (stats.size > this.maxLogBytes) { + await this.rotateLog(workspaceId, data, filePath); + } }); } + + /** + * Rotation compacts in-memory state into a self-contained rotated snapshot + * instead of renaming the live file: the live file may hold step-updates + * whose base records came from the previous rotated file, so a rename chain + * would orphan them on the next rotation. Active runs (zero steps yet, or + * any in-progress step) are always retained so their upcoming steps and + * step-updates keep a persisted base record; completed runs fill the + * remaining cap newest-first. Dropped + * runs are also evicted from memory: a late createStep then self-heals by + * recreating the run record, and a late updateStep no-ops, so the live file + * never references entities missing from the snapshot. + */ + private async rotateLog( + workspaceId: string, + data: WorkspaceData, + filePath: string + ): Promise { + const stepsByRun = new Map(); + for (const step of data.steps.values()) { + const list = stepsByRun.get(step.runId) ?? []; + list.push(step); + stepsByRun.set(step.runId, list); + } + // Zero-step runs are just-created: their createRun caller may still be + // awaiting the queued append, and their first steps are in flight, so + // evicting them would strand those operations without a base record. + const isActiveRun = (runId: string): boolean => { + const steps = stepsByRun.get(runId); + if (steps == null || steps.length === 0) { + return true; + } + return steps.some((step) => step.durationMs == null && step.error == null); + }; + + const runsNewestFirst = Array.from(data.runs.values()).sort((a, b) => + b.startedAt.localeCompare(a.startedAt) + ); + const retainedChunks: string[][] = []; + const retainedRunIds = new Set(); + let retainedBytes = 0; + for (const run of runsNewestFirst) { + const lines = [JSON.stringify({ type: "run", run } satisfies DevToolsLogEntry)]; + for (const step of stepsByRun.get(run.id) ?? []) { + lines.push(JSON.stringify({ type: "step", step } satisfies DevToolsLogEntry)); + } + const chunkBytes = lines.reduce( + (total, line) => total + Buffer.byteLength(line, "utf-8") + 1, + 0 + ); + const overCap = retainedChunks.length > 0 && retainedBytes + chunkBytes > this.maxLogBytes; + // The newest run and active runs are retained even over the cap. + if (overCap && !isActiveRun(run.id)) { + continue; + } + retainedChunks.push(lines); + retainedRunIds.add(run.id); + retainedBytes += chunkBytes; + } + // Chronological order for readability; replay only needs base-before-update. + retainedChunks.reverse(); + + const frozenStepIds = new Set(); + for (const steps of stepsByRun.values()) { + for (const step of steps) { + frozenStepIds.add(step.id); + } + } + const frozenClearGeneration = data.clearGeneration; + + const markerError = await this.commitSnapshotPair(workspaceId, data, filePath, retainedChunks); + + // clear() during the snapshot I/O empties the maps and queues an empty + // snapshot commit behind this rotation, making every frozen retention + // decision stale. Anything now in the maps is a post-clear recreation + // that can reuse a frozen run ID with no steps inserted yet; evicting it + // would make its queued base append skip and strand the first post-clear + // step (createStep would then throw on the missing run). + if (data.clearGeneration !== frozenClearGeneration) { + if (markerError !== undefined) { + throw markerError; + } + return; + } + + // Eviction is restricted to the decision set frozen above: overlapping + // provider calls can add runs and steps while commitSnapshotPair awaits + // filesystem I/O, and those entities were never considered for the + // snapshot, so deleting them would strand their in-flight operations. + // Reconciliation runs even when the live-marker write failed: the + // snapshot rename already committed the retention decision, so leaving + // dropped runs in memory would let later appends target runs whose + // records exist nowhere durable. + let repairError: Error | undefined; + const evictedRunIds: string[] = []; + for (const run of runsNewestFirst) { + // A clear landing during the repair await below supersedes the frozen + // decision set, exactly like the pre-loop check: later iterations + // would evict post-clear recreations or re-persist cleared history. + if (data.clearGeneration !== frozenClearGeneration) { + break; + } + if (retainedRunIds.has(run.id)) { + continue; + } + const liveRun = data.runs.get(run.id); + const midIoSteps = Array.from(data.steps.values()).filter( + (step) => step.runId === run.id && !frozenStepIds.has(step.id) + ); + if (liveRun != null && midIoSteps.length > 0) { + // The run gained activity mid-I/O after losing its snapshot spot. + // Keep it and re-persist its base records into the fresh live file + // so the new steps (whose queued appends land next) stay replayable. + const lines = [JSON.stringify({ type: "run", run: liveRun } satisfies DevToolsLogEntry)]; + for (const step of stepsByRun.get(run.id) ?? []) { + lines.push(JSON.stringify({ type: "step", step } satisfies DevToolsLogEntry)); + } + try { + await this.appendWithMarkerRepair(data, filePath, `${lines.join("\n")}\n`); + } catch (error) { + // Keep the run in memory and queue the base records as a pending + // repair: the queued step appends that motivated keeping this run + // must not land without them, or the next load would orphan the + // steps and drop the run. Replay is Map.set-idempotent, so a + // partially-written repair retried later is harmless. A clear that + // landed during this failed append already emptied the repair + // queue; requeueing these pre-clear base records would flush them + // on the next successful append and resurrect cleared history. + if (data.clearGeneration === frozenClearGeneration) { + data.pendingLiveRepairs.push(`${lines.join("\n")}\n`); + } + repairError ??= error instanceof Error ? error : new Error(String(error)); + } + continue; + } + evictedRunIds.push(run.id); + data.runs.delete(run.id); + for (const step of stepsByRun.get(run.id) ?? []) { + data.steps.delete(step.id); + } + } + if (evictedRunIds.length > 0) { + // Open DevTools panels must drop evicted run cards. + this.emitWorkspaceEvent(workspaceId, { type: "runs-evicted", runIds: evictedRunIds }); + } + const firstError = markerError ?? repairError; + if (firstError !== undefined) { + throw firstError; + } + } + + /** + * Commits a snapshot/live-log pair. Write-then-rename keeps the previous + * snapshot intact if the write is interrupted; rename replaces the + * destination in one step (POSIX rename, MOVEFILE_REPLACE_EXISTING on + * Windows), so no crash window exists where neither snapshot is on disk. + * The generation pair makes live-log retirement recoverable: if the + * process dies before the live file is rewritten, its stale generation + * tells the next load to skip it instead of resurrecting runs the snapshot + * deliberately dropped. clear() commits an empty snapshot through the same + * protocol so an interrupted clear stays cleared. + * + * A live-marker write failure after the rename is returned instead of + * thrown: the snapshot is committed at that point, so callers must finish + * reconciling in-memory state with it before propagating the failure. + */ + private async commitSnapshotPair( + workspaceId: string, + data: WorkspaceData, + filePath: string, + chunks: string[][] + ): Promise { + const rotatedPath = this.getRotatedFilePath(workspaceId); + // The load guard rejects a generation whose own increment is unsafe, so + // the value written here must stay one increment below that ceiling or + // the next load would ignore this snapshot and replay the stale live + // log. Restart the sequence instead; pairing is by strict equality plus + // the retire sentinel, so a restart cannot mis-pair this commit's files. + const generation = Number.isSafeInteger(data.logGeneration + 2) ? data.logGeneration + 1 : 1; + const tmpPath = this.getRotatedTmpFilePath(workspaceId); + await fs.mkdir(path.dirname(filePath), { recursive: true }); + // Retire sentinel before the snapshot commit: if a crash leaves a + // markerless live file next to the renamed snapshot, this line marks it + // as an interrupted commit (snapshot wins) rather than a legacy + // pre-rotation rewrite (live wins). The live rewrite below discards it + // on success, and replay ignores it. + await this.appendToLiveFile( + data, + filePath, + `${JSON.stringify({ type: "log-retire", generation } satisfies DevToolsLogEntry)}\n` + ); + await fs.writeFile( + tmpPath, + [ + `${JSON.stringify({ type: "snapshot-meta", generation } satisfies DevToolsLogEntry)}\n`, + ...chunks.map((lines) => `${lines.join("\n")}\n`), + ].join(""), + "utf-8" + ); + await fs.rename(tmpPath, rotatedPath); + // The snapshot is committed once the rename lands: advance the in-memory + // generation before the live-marker write so a marker failure (e.g. + // ENOSPC) leaves the append path knowing a repair is needed. + data.logGeneration = generation; + try { + await this.writeLiveMarker(filePath, generation); + data.liveMarkerGeneration = generation; + // The marker rewrite replaced the whole file, discarding any torn tail. + data.liveTailMayBeTorn = false; + } catch (error) { + return error instanceof Error ? error : new Error(String(error)); + } + return undefined; + } + + /** + * Appends after repairing a lagging live marker: a snapshot committed but + * its live-marker write failed, so entries appended before the repair + * would be discarded as pre-snapshot on the next load. The stale content + * being truncated is already superseded by the committed snapshot. + */ + private async appendWithMarkerRepair( + data: WorkspaceData, + filePath: string, + content: string + ): Promise { + if (data.liveMarkerGeneration !== data.logGeneration) { + await this.writeLiveMarker(filePath, data.logGeneration); + data.liveMarkerGeneration = data.logGeneration; + // The marker rewrite replaced the whole file, discarding any torn tail. + data.liveTailMayBeTorn = false; + } + // Failed rotation-time base repairs must land before this append (see + // pendingLiveRepairs); a failure here rejects the append too, so a step + // can never be persisted ahead of its run's base records. Each retry + // keeps an unconditional leading newline: the failed attempt that + // queued it may have bypassed the torn-tail flag (it can fail between + // sub-writes), and duplicated records from a fully-written-but-rejected + // attempt are harmless because replay is Map.set-idempotent. + while (data.pendingLiveRepairs.length > 0) { + await this.appendToLiveFile(data, filePath, `\n${data.pendingLiveRepairs[0]}`); + data.pendingLiveRepairs.shift(); + } + await this.appendToLiveFile(data, filePath, content); + } + + /** + * All live-file appends go through this seal. A previously failed append + * may have written a partial fragment as the file's tail; appending + * directly onto it would merge the fragment with this content into one + * malformed line that replay skips, losing this record too. A leading + * newline instead seals the fragment as its own malformed line. A failure + * here may itself be partial, so it re-arms the seal. + */ + private async appendToLiveFile( + data: WorkspaceData, + filePath: string, + content: string + ): Promise { + const sealed = data.liveTailMayBeTorn ? `\n${content}` : content; + try { + await fs.appendFile(filePath, sealed, "utf-8"); + data.liveTailMayBeTorn = false; + } catch (error) { + data.liveTailMayBeTorn = true; + throw error; + } + } + + private async writeLiveMarker(filePath: string, generation: number): Promise { + // Atomic tmp+rename: a crash mid-write must not leave an empty or + // partial live file, which the loader would misread as a legacy + // (pre-rotation) rewrite and skip the snapshot for. + const tmpPath = `${filePath}.tmp`; + await fs.writeFile( + tmpPath, + `${JSON.stringify({ type: "log-meta", generation } satisfies DevToolsLogEntry)}\n`, + "utf-8" + ); + await fs.rename(tmpPath, filePath); + } } diff --git a/src/node/services/tools/file_edit_replace_shared.test.ts b/src/node/services/tools/file_edit_replace_shared.test.ts index 239c2d1830..e26e62a74a 100644 --- a/src/node/services/tools/file_edit_replace_shared.test.ts +++ b/src/node/services/tools/file_edit_replace_shared.test.ts @@ -58,3 +58,57 @@ test("file_edit_replace_lines validation error includes note", () => { expect(result.note).toContain("file was NOT modified"); } }); + +test("file_edit_replace_string replace_count=2 with new_string containing old_string replaces both original sites", () => { + const result = handleStringReplace( + { + path: "test.ts", + old_string: "old", + new_string: "XoldY", + replace_count: 2, + }, + "AoldB-oldC" + ); + + expect(result.success).toBe(true); + if (result.success) { + expect(result.newContent).toBe("AXoldYB-XoldYC"); + expect(result.metadata.edits_applied).toBe(2); + } +}); + +test("file_edit_replace_string replace_count=-1 with new_string containing old_string replaces all sites", () => { + const result = handleStringReplace( + { + path: "test.ts", + old_string: "old", + new_string: "XoldY", + replace_count: -1, + }, + "AoldB-oldC-oldD" + ); + + expect(result.success).toBe(true); + if (result.success) { + expect(result.newContent).toBe("AXoldYB-XoldYC-XoldYD"); + expect(result.metadata.edits_applied).toBe(3); + } +}); + +test("file_edit_replace_string replace_count=2 with non-overlapping strings replaces first two occurrences", () => { + const result = handleStringReplace( + { + path: "test.ts", + old_string: "foo", + new_string: "bar", + replace_count: 2, + }, + "foo one foo two foo three" + ); + + expect(result.success).toBe(true); + if (result.success) { + expect(result.newContent).toBe("bar one bar two foo three"); + expect(result.metadata.edits_applied).toBe(2); + } +}); diff --git a/src/node/services/tools/file_edit_replace_shared.ts b/src/node/services/tools/file_edit_replace_shared.ts index 129196697b..2f6c0d627e 100644 --- a/src/node/services/tools/file_edit_replace_shared.ts +++ b/src/node/services/tools/file_edit_replace_shared.ts @@ -100,24 +100,14 @@ export function handleStringReplace( newContent = parts.join(newStringCoerced); editsApplied = occurrences; } else { - let replacedCount = 0; - let currentContent = originalContent; - - for (let i = 0; i < replaceCount; i++) { - const index = currentContent.indexOf(oldStringToMatch); - if (index === -1) { - break; - } - - currentContent = - currentContent.substring(0, index) + - newStringCoerced + - currentContent.substring(index + oldStringToMatch.length); - replacedCount++; - } - - newContent = currentContent; - editsApplied = replacedCount; + // Rebuild from the pre-split parts so matching cannot resume inside + // just-inserted text when new_string contains old_string. + const countToReplace = Math.max(replaceCount, 0); + const tail = parts.slice(countToReplace + 1); + newContent = + parts.slice(0, countToReplace + 1).join(newStringCoerced) + + (tail.length > 0 ? oldStringToMatch + tail.join(oldStringToMatch) : ""); + editsApplied = countToReplace; } return {