diff --git a/tests/restart-chaos/README.md b/tests/restart-chaos/README.md index 5451c5cf1bc..c7fd0370cb7 100644 --- a/tests/restart-chaos/README.md +++ b/tests/restart-chaos/README.md @@ -374,6 +374,9 @@ that re-resolves its credentials after a rejection keeps going. Rotations and pu `--storage-fault-seconds 15-45` sets the window length range (5–900 s), for example to find how long an outage a run survives. The windows are logged in the timeline and written to `storage-faults.json`. +The speed grade removes storage fault window time from spans and restart recoveries the same way it +removes restart outage time (overlap counted once), and reports the removed time on its own line in +`SUMMARY.md` and as `storageFaultRemovedMs` in `speed.json`. With `--env daytona --storage s3`, each task's workspace is a remote workspace: the controller saves and restores it through the store, so the faults also hit workspace save, restore and copyback. R1 diff --git a/tests/restart-chaos/main.ts b/tests/restart-chaos/main.ts index dfb91f50ce4..2b8b04e545b 100644 --- a/tests/restart-chaos/main.ts +++ b/tests/restart-chaos/main.ts @@ -595,7 +595,7 @@ async function main(): Promise { const speed = await (async () => { const childTasks = await childSpeedTasksInTurn(launched); return collectWaveSpeed(api, plan.options.env, [...launched.flatMap(observer => observer.record.issueId - ? [{ issueId: observer.record.issueId, adapter: observer.plan.adapter, samples: observer.record.samples }] : []), ...childTasks], faults); + ? [{ issueId: observer.record.issueId, adapter: observer.plan.adapter, samples: observer.record.samples }] : []), ...childTasks], faults, storageChaos?.receipts ?? []); })().catch(error => { timeline.add("wave_speed_failed", { error: String(error) }); anyFailure = true; return null; }); if (speed) { speedSection = speedMarkdown(speed); diff --git a/tests/restart-chaos/wave-speed.test.ts b/tests/restart-chaos/wave-speed.test.ts index 354c5278df6..34a7a046f67 100644 --- a/tests/restart-chaos/wave-speed.test.ts +++ b/tests/restart-chaos/wave-speed.test.ts @@ -2,7 +2,7 @@ import { describe, expect, it } from "vitest"; import type { BaselineRun } from "./ttft-baseline-stats.js"; import type { ChaosApi } from "./api.js"; import type { FaultReceipt } from "./types.js"; -import { bootWithoutProvisionMs, breachesOf, budgetFor, collectWaveSpeed, faultBeforeFirstActivity, faultRuns, firstActivityMs, gradeWaveSpeed, outageWindows, speedMarkdown, traceStartMs, withoutOutage } from "./wave-speed.js"; +import { bootWithoutProvisionMs, breachesOf, budgetFor, collectWaveSpeed, faultBeforeFirstActivity, faultRuns, firstActivityMs, gradeWaveSpeed, outageFreeClock, outageWindows, speedMarkdown, storageFaultWindows, traceStartMs, withoutOutage } from "./wave-speed.js"; import { runMetrics } from "./ttft-baseline-stats.js"; const span = (name: string, startOffsetMs: number, durationMs: number, extra: Record = {}) => @@ -90,6 +90,40 @@ describe("wave speed grade", () => { expect(speed.rows.find(row => row.metric === "restart_recovery_control_plane")).toMatchObject({ measured: { p50: 2_000 }, breaches: [] }); }); + it("removes storage fault window time from restart recovery and reports it apart from restart outage", () => { + const recovered: BaselineRun = { runId: "r", adapter: "claude", environment: "local", phase: "cold", + events: [{ eventType: "session.resumed", createdAt: new Date(10_000 + 62_000).toISOString() }] }; + const restart = outageWindows([{ startedAt: 1_000, readyAt: 10_000 } as FaultReceipt]); + const storage = storageFaultWindows([{ kind: "ST5R", startedAt: 5_000, endedAt: 70_000, rules: [] }, + { kind: "ST1", startedAt: 90_000, endedAt: null, rules: [] }], 95_000); + expect(storage).toEqual([{ startedAt: 5_000, readyAt: 70_000 }, { startedAt: 90_000, readyAt: 95_000 }]); + const faults = [{ kind: "K1", startedAt: 1_000, readyAt: 10_000, runIds: ["r"] }]; + const unadjusted = gradeWaveSpeed("local", [recovered], faults, 0, [], { adjusted: 0, removedMs: 0, windows: restart }); + expect(unadjusted).toMatchObject({ singleRunBreaches: 1, breaches: 1 }); + const speed = gradeWaveSpeed("local", [recovered], faults, 0, [], { adjusted: 0, removedMs: 0, windows: restart, storageWindows: storage }); + expect(speed.rows.find(row => row.metric === "restart_recovery_control_plane")).toMatchObject({ measured: { p50: 2_000 }, breaches: [] }); + expect(speed).toMatchObject({ breaches: 0, storageFaultWindows: 2, storageFaultRemovedMs: 60_000 }); + expect(speedMarkdown(speed)).toContain("Storage fault time removed: 60.0 s across 2 windows"); + }); + + it("removes overlapping restart and storage fault time once", () => { + const clock = outageFreeClock([{ startedAt: 10_000, readyAt: 50_000 }, { startedAt: 30_000, readyAt: 70_000 }]); + expect(clock(100_000)).toBe(40_000); + expect(clock(40_000)).toBe(10_000); + }); + + it("removes storage fault time from spans in a collected wave and counts it apart", async () => { + const run = traced(1_000_000, [["heartbeat.queue", 0, 100], ["task.time_to_first_agent_activity", 0, 70_000]]); + const api = { get: async (route: string) => route.includes("workspace-operations") ? [] + : run.events.map((event, seq) => ({ ...event, seq })) } as unknown as ChaosApi; + const sample = { runs: [{ id: "t", status: "succeeded", createdAt: new Date(1_000_000).toISOString(), + finishedAt: new Date(1_080_000).toISOString() }] } as never; + const speed = await collectWaveSpeed(api, "local", [{ issueId: "i", adapter: "claude", samples: [sample] }], [], + [{ kind: "ST1", startedAt: 1_005_000, endedAt: 1_065_000, rules: [] }]); + expect(speed.rows.find(row => row.metric === "time_to_first_activity")).toMatchObject({ measured: { p50: 10_000 } }); + expect(speed).toMatchObject({ storageFaultWindows: 1, storageFaultRemovedMs: 60_000, outageRemovedMs: 0, outageAdjustedSpans: 0 }); + }); + it("has no budget for remote environments or unbudgeted adapters", () => { expect(budgetFor("daytona", "codex", "ttft", "cold")).toBeNull(); expect(budgetFor("local", "unknown", "ttft", "cold")).toBeNull(); diff --git a/tests/restart-chaos/wave-speed.ts b/tests/restart-chaos/wave-speed.ts index 314704c2ce6..ea351f52d1a 100644 --- a/tests/restart-chaos/wave-speed.ts +++ b/tests/restart-chaos/wave-speed.ts @@ -4,6 +4,7 @@ import { baselineRows, distribution, recoverySamples, runMetrics, runSpans, runWarmth, stampProviderLoadStarts, type BaselineEvent, type BaselineFault, type BaselineRun, type Distribution, } from "./ttft-baseline-stats.js"; +import type { StorageFaultReceipt } from "./storage-chaos.js"; import type { AdapterId, EnvironmentKind, FaultReceipt, RunSample } from "./types.js"; type Json = Record; @@ -21,6 +22,8 @@ export interface WaveSpeed { rows: SpeedRow[]; outageAdjustedSpans: number; outageRemovedMs: number; + storageFaultWindows: number; + storageFaultRemovedMs: number; recoveryWithoutProviderEvent: number; /** Recovery samples a later fault interrupted before their next provider event (not graded). */ recoveryInterruptedByFault: number; @@ -68,6 +71,23 @@ export function outageWindows(faults: readonly FaultReceipt[]): OutageWindow[] { return faults.filter(fault => fault.readyAt !== null).map(fault => ({ startedAt: fault.startedAt, readyAt: fault.readyAt! })); } +export function storageFaultWindows(receipts: readonly StorageFaultReceipt[], now: number): OutageWindow[] { + return receipts.flatMap(receipt => { + const readyAt = receipt.endedAt ?? now; + return readyAt > receipt.startedAt ? [{ startedAt: receipt.startedAt, readyAt }] : []; + }); +} + +export function mergeWindows(windows: readonly OutageWindow[]): OutageWindow[] { + const merged: OutageWindow[] = []; + for (const window of [...windows].sort((a, b) => a.startedAt - b.startedAt)) { + const last = merged.at(-1); + if (last && window.startedAt <= last.readyAt) last.readyAt = Math.max(last.readyAt, window.readyAt); + else merged.push({ ...window }); + } + return merged; +} + export function traceStartMs(run: BaselineRun): number | null { let earliest: number | null = null; for (const event of run.events) { @@ -82,7 +102,8 @@ export function traceStartMs(run: BaselineRun): number | null { } export function outageFreeClock(windows: readonly OutageWindow[]): (at: number) => number { - return at => at - windows.reduce((total, window) => + const merged = mergeWindows(windows); + return at => at - merged.reduce((total, window) => total + Math.max(0, Math.min(at, window.readyAt) - window.startedAt), 0); } @@ -172,7 +193,8 @@ function firstActivityByGroup(runs: readonly BaselineRun[]): Map ms === null ? null : Math.max(0, clock(readyAt + ms) - clock(readyAt)); - const samples = recoverySamples(runs, faults).map(sample => sample.latencyMs === null ? sample : { + let storageRemovedMs = outage.storageRemovedMs ?? 0; + const samples = recoverySamples(runs, faults).map(sample => { + if (sample.latencyMs !== null) { + const end = sample.readyAt + sample.latencyMs; + storageRemovedMs += (restartClock(end) - restartClock(sample.readyAt)) - (clock(end) - clock(sample.readyAt)); + } + return sample; + }).map(sample => sample.latencyMs === null ? sample : { ...sample, latencyMs: outageFree(sample.readyAt, sample.latencyMs), controlPlaneMs: outageFree(sample.readyAt, sample.controlPlaneMs), providerLoadMs: sample.providerLoadMs === null || sample.controlPlaneMs === null ? sample.providerLoadMs @@ -221,7 +252,8 @@ export function gradeWaveSpeed(environment: EnvironmentKind, runs: readonly Base return { environment, rows, recoveryWithoutProviderEvent: samples.filter(sample => sample.latencyMs === null && !sample.interruptedByFault).length, recoveryInterruptedByFault: samples.filter(sample => sample.interruptedByFault).length, - runBudgetExceeded, singleRunBreaches, breaches, errors, outageAdjustedSpans: outage.adjusted, outageRemovedMs: outage.removedMs }; + runBudgetExceeded, singleRunBreaches, breaches, errors, outageAdjustedSpans: outage.adjusted, outageRemovedMs: outage.removedMs, + storageFaultWindows: storageWindows.length, storageFaultRemovedMs: storageRemovedMs }; } async function runEventsWithRetry(api: ChaosApi, runId: string, attempts = 3): Promise { @@ -249,12 +281,13 @@ async function runEvents(api: ChaosApi, runId: string): Promise } export async function collectWaveSpeed(api: ChaosApi, environment: EnvironmentKind, tasks: readonly WaveSpeedTask[], - faults: readonly FaultReceipt[]): Promise { + faults: readonly FaultReceipt[], storageReceipts: readonly StorageFaultReceipt[] = [], now = Date.now()): Promise { const runs: BaselineRun[] = []; const timing: Array<{ id: string; createdAt: number; finishedAt: number | null }> = []; const errors: string[] = []; const windows = outageWindows(faults); - const outage = { adjusted: 0, removedMs: 0, windows }; + const storageWindows = storageFaultWindows(storageReceipts, now); + const outage = { adjusted: 0, removedMs: 0, windows, storageWindows, storageRemovedMs: 0 }; const perTask = tasks.map(task => { const seen = new Map(); for (const sample of task.samples) for (const run of sample.runs ?? []) if (run.createdAt) seen.set(run.id, run); @@ -275,8 +308,11 @@ export async function collectWaveSpeed(api: ChaosApi, environment: EnvironmentKi if (run.retryOfRunId && faultHit.has(run.retryOfRunId)) raw.phase = "restart"; if (faultBeforeFirstActivity(raw, windows, Date.parse(run.createdAt!))) raw.phase = "restart"; // Stamp provider load starts from raw offsets before outage removal rewrites them. - const trimmed = withoutOutage(stampProviderLoadStarts(raw), windows); - outage.adjusted += trimmed.adjusted; outage.removedMs += trimmed.removedMs; + const stamped = stampProviderLoadStarts(raw); + const restartOnly = withoutOutage(stamped, windows); + const trimmed = withoutOutage(stamped, [...windows, ...storageWindows]); + outage.adjusted += restartOnly.adjusted; outage.removedMs += restartOnly.removedMs; + outage.storageRemovedMs += trimmed.removedMs - restartOnly.removedMs; runs.push(trimmed.run); timing.push({ id: run.id, createdAt: Date.parse(run.createdAt!), finishedAt: run.finishedAt ? Date.parse(run.finishedAt) : null }); } catch (error) { @@ -299,7 +335,8 @@ export function speedMarkdown(speed: WaveSpeed): string { const lines = [`## Speed (${speed.environment})`, "", `Breaches: ${speed.breaches} (aggregate p50/p95 rows with at least ${MIN_AGGREGATE_SAMPLES} samples plus ${speed.singleRunBreaches} runs or restart recoveries over the p95 budget after outage removal; the server logged ${speed.runBudgetExceeded} budget_exceeded events before removal).`, `Restart samples with no provider event after ready: ${speed.recoveryWithoutProviderEvent}. Interrupted by a later fault (not graded): ${speed.recoveryInterruptedByFault}.`, - `Outage time removed from ${speed.outageAdjustedSpans} spans: ${s(speed.outageRemovedMs)} (fault start to server ready; budgets judge the rest).`, "", + `Outage time removed from ${speed.outageAdjustedSpans} spans: ${s(speed.outageRemovedMs)} (fault start to server ready; budgets judge the rest).`, + ...(speed.storageFaultWindows ? [`Storage fault time removed: ${s(speed.storageFaultRemovedMs)} across ${speed.storageFaultWindows} windows (storage fault start to end, from storage-faults.json; overlap with restart outage counted once).`] : []), "", "| Adapter | Metric | Start | n | p50 | p95 | Budget p50 / p95 | Breach |", "|---|---|---|---|---|---|---|---|"]; for (const row of speed.rows) { lines.push(`| ${row.adapter} | ${row.metric} | ${row.start} | ${row.measured.n} | ${s(row.measured.p50)} | ${s(row.measured.p95)} | `