diff --git a/tests/restart-chaos/README.md b/tests/restart-chaos/README.md index ddc2881ae27..295fd115f5c 100644 --- a/tests/restart-chaos/README.md +++ b/tests/restart-chaos/README.md @@ -115,7 +115,10 @@ S1 is the board's Stop button. While the task's run is running, the harness canc comments that it stopped the run on purpose and asks the agent to continue with an extra marker line. The oracle checks that the stopped run ended `cancelled`, that nothing started between the stop and the continue comment (recovery must not restart work the operator stopped), and that the -finished brief has both markers. S1 is not a default workload. +finished brief has both markers. The Stop waits for a ready server with no fault in progress. If the +run already finished when the stop window opens, the harness records a missed Stop +(`task_stop_missed`), skips the stop-triggered fault, still posts the continue comment, and the +oracle checks only the continue. S1 is not a default workload. ## Code change in a real repository (R1, `--workspace-repo`) @@ -306,6 +309,12 @@ re-arms the task's own triggered faults instead of using their offsets. `RESTART_CHAOS_ALLOW_UNSANDBOXED_ORACLE=1` is set inside a disposable VM. - R1 allows the workload budget plus outage time. When a Retry was needed R1 is `n/a` and R3 decides; a task that rests unfinished with no Retry fails both. + A task that never rested within its deadline fails R1 as `no_rest_within_budget`, + whatever its last status. +- Speed: an aggregate p50/p95 row can breach only with at least 5 samples; a + smaller row is reported as `insufficient sample (n < 5)`. Every cold or warm run + over its p95 budget, and every restart recovery whose Paperclip share exceeds + its p95 budget, still fails the wave on its own. - Faults are serialized; each one hits every task running at that moment. - A `todo` or `in_progress` task with no live run and no named wait is not a rest. The observer keeps watching it until it resumes or passes the R5 stall limit. - R5 also fails a run that stays `running` with no live evidence (no new run event, `lastUsefulActionAt` or `execution.lastConfirmedActivityAt`, and no start) for more than 3 minutes after the server is ready. A `running` status alone is not proof of life. A quiet run is still live while a tool it started has not ended (for example a 4-minute `bench.sh`) or while its recorded local runner process still runs with the same PID and start time. diff --git a/tests/restart-chaos/config.ts b/tests/restart-chaos/config.ts index 8852fd00693..246fb37f786 100644 --- a/tests/restart-chaos/config.ts +++ b/tests/restart-chaos/config.ts @@ -136,11 +136,13 @@ export function parseCommand(argv: readonly string[], now = Date.now()): ParsedC } } if (lifecycle !== undefined && lifecycle !== "per_turn" && lifecycle !== "warm" && lifecycle !== "default") throw new Error("--lifecycle must be per_turn, warm or default"); + const adapters = list(values.adapters, ADAPTER_IDS, "adapters", ["codex", "claude"]); const options: WaveOptions = { env, - adapters: list(values.adapters, ADAPTER_IDS, "adapters", ["codex", "claude"]), + adapters, // The governance scenarios (G1, H1) are opt-in: H1 needs a wave of its own. - workloads: list(values.workloads, workloadChoices, "workloads", workloadChoices.filter(id => id !== "G1" && id !== "H1" && id !== "R1" && id !== "S1")), + workloads: list(values.workloads, workloadChoices, "workloads", workloadChoices.filter(id => id !== "G1" && id !== "H1" && id !== "R1" && id !== "S1" + && (id !== "M1" || adapters.length >= 2))), // A crash-point wave schedules no fault; K1 is the restart its self-kill gets. faults: list(values.faults, FAULT_KINDS, "faults", stormMinutes ? STORM_DEFAULT_FAULTS : crashPoint ? ["K1"] : ["K1", "K2", "K4"]), triggers: list(values.triggers, TRIGGER_IDS, "triggers", ["time"]), diff --git a/tests/restart-chaos/governance.test.ts b/tests/restart-chaos/governance.test.ts index 0ce5a2d189b..dd99a549b44 100644 --- a/tests/restart-chaos/governance.test.ts +++ b/tests/restart-chaos/governance.test.ts @@ -6,7 +6,7 @@ import { BUDGET_PAUSE_HOLD_MS, BUDGET_RESUME_HEADROOM_CENTS, REST_CONFIRM_MS, Ta import { planTasks, replayOnCurrentBuild, triggerFitsWorkload } from "./scheduler.js"; import type { ChaosLab } from "./seed.js"; import { Timeline } from "./timeline.js"; -import type { OracleArtifacts, TaskPlan, TaskRecord, TaskSample, WavePlan } from "./types.js"; +import type { FaultReceipt, OracleArtifacts, TaskPlan, TaskRecord, TaskSample, WavePlan } from "./types.js"; import { g1ApprovalTitle, g1ChildTitle, g1Decision, workloadDefinitions } from "./workloads.js"; process.env.RESTART_CHAOS_QUIET = "1"; @@ -127,6 +127,9 @@ describe("G1: approval-gated action across a restart", () => { createdAt: 0, restAt: 60_000, samples: [] } as unknown as TaskRecord; expect(gradeR1(record, 15 * 60_000, []).verdict).toBe("pass"); expect(gradeR1({ ...record, finalStatus: "done" }, 15 * 60_000, []).verdict).toBe("fail"); + const unrested = gradeR1({ ...record, timedOut: true, restAt: null }, 15 * 60_000, + [{ startedAt: 1_000, readyAt: null, healthyAt: null } as unknown as FaultReceipt]); + expect(unrested).toEqual({ verdict: "fail", detail: "no_rest_within_budget (last status cancelled)" }); }); it("counts a redacted approval title as the task's own", () => { diff --git a/tests/restart-chaos/grader.test.ts b/tests/restart-chaos/grader.test.ts index 79f0043516b..424399704b5 100644 --- a/tests/restart-chaos/grader.test.ts +++ b/tests/restart-chaos/grader.test.ts @@ -247,6 +247,11 @@ describe("T-oracles", () => { expect(restarted.checks.find(check => check.name === "nothing_ran_after_stop")).toMatchObject({ ok: false, detail: "continue=true runs=r2" }); expect(workloadDefinitions.S1.grade("abcd1234", { ...base, stop: { ...base.stop!, runStatus: "succeeded" } }).verdict).toBe("fail"); expect(workloadDefinitions.S1.grade("abcd1234", { ...base, stop: undefined }).verdict).toBe("fail"); + const missed = workloadDefinitions.S1.grade("abcd1234", { ...base, stop: { runId: null, runStatus: null, runsStartedBeforeContinue: [], continuePosted: true, missed: true } }); + expect(missed.verdict).toBe("pass"); + expect(missed.checks.find(check => check.name === "stop_took_effect")).toMatchObject({ ok: true, detail: "missed: the run finished before the stop window" }); + expect(workloadDefinitions.S1.grade("abcd1234", { ...base, documents: { brief: "CHAOS-abcd1234\n- one\n- two\n- three\n" }, + stop: { runId: null, runStatus: null, runsStartedBeforeContinue: [], continuePosted: true, missed: true } }).verdict).toBe("fail"); }); it("grades B1 by running the tests and the CLI", () => { diff --git a/tests/restart-chaos/grader.ts b/tests/restart-chaos/grader.ts index 33963debf17..282473f4ecc 100644 --- a/tests/restart-chaos/grader.ts +++ b/tests/restart-chaos/grader.ts @@ -61,8 +61,9 @@ export function gradeR1(record: TaskRecord, budgetMs: number, faults: readonly F if (record.launchError) return { verdict: "fail", detail: `launch_failed: ${record.launchError}` }; if (record.retry) return { verdict: "n/a", detail: "task rested needing Retry; graded under R3" }; const expected = expectedFinalStatus(record); + if (record.timedOut) return { verdict: "fail", detail: `no_rest_within_budget (last status ${record.finalStatus ?? "unknown"})` }; if (record.finalStatus !== expected) { - return { verdict: "fail", detail: record.timedOut ? `no_rest_within_budget (last status ${record.finalStatus ?? "unknown"})` : `rested_not_done (status ${record.finalStatus ?? "unknown"}, no Retry offered)` }; + return { verdict: "fail", detail: `rested_not_done (status ${record.finalStatus ?? "unknown"}, no Retry offered)` }; } const allowed = budgetMs + outageOverlapMs(record, faults); const took = (record.restAt ?? Number.POSITIVE_INFINITY) - record.createdAt!; diff --git a/tests/restart-chaos/main.ts b/tests/restart-chaos/main.ts index 7c3ac613c10..ffaa6943207 100644 --- a/tests/restart-chaos/main.ts +++ b/tests/restart-chaos/main.ts @@ -22,7 +22,7 @@ import { gradeTask } from "./grader.js"; import { checkPlanInvariants, summarizeViolations, type InvariantCheck } from "./invariants.js"; import { appendLedger, ledgerLine, writeSummary, type LedgerLine } from "./ledger.js"; import { collectWaveSpeed, speedMarkdown } from "./wave-speed.js"; -import { TaskObserver } from "./observer.js"; +import { TaskObserver, childSpeedTasksInTurn } from "./observer.js"; import { StormRun, TASK_FAULT_LOG, observedFaultSchedule, planWave, replayOnCurrentBuild, replayRecordFor, replayWave, type TaskFaultLog } from "./scheduler.js"; import { chaosLifecycleOverrides, seedChaosLab } from "./seed.js"; import { ChaosSupervisor } from "./supervisor.js"; @@ -469,8 +469,7 @@ async function main(): Promise { } await writeFile(path.join(waveDir, "faults.json"), `${JSON.stringify(faults, null, 2)}\n`, { mode: 0o600 }); const speed = await (async () => { - const childTasks: Awaited> = []; - for (const observer of launched) childTasks.push(...await observer.childSpeedTasks()); + 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); })().catch(error => { timeline.add("wave_speed_failed", { error: String(error) }); anyFailure = true; return null; }); diff --git a/tests/restart-chaos/observer.test.ts b/tests/restart-chaos/observer.test.ts index 2e0cba8b33f..fc0f5bb3366 100644 --- a/tests/restart-chaos/observer.test.ts +++ b/tests/restart-chaos/observer.test.ts @@ -4,7 +4,7 @@ import os from "node:os"; import path from "node:path"; import { afterEach, describe, expect, it } from "vitest"; import type { ChaosApi } from "./api.js"; -import { CHILD_WAKE_GRACE_MS, REST_CONFIRM_MS, STALL_GIVE_UP_MS, STOP_CONTINUE_AFTER_MS, TaskObserver, childrenPending, listWorkspaceFiles } from "./observer.js"; +import { CHILD_WAKE_GRACE_MS, REST_CONFIRM_MS, STALL_GIVE_UP_MS, STOP_CONTINUE_AFTER_MS, TaskObserver, childSpeedTasksInTurn, childrenPending, listWorkspaceFiles } from "./observer.js"; import { gradeTask } from "./grader.js"; import { createFixtureRepository, type ChaosLab } from "./seed.js"; import { Timeline } from "./timeline.js"; @@ -142,6 +142,31 @@ describe("TaskObserver", () => { expect(childRetries).toHaveLength(1); }); + it("M1: rereads a parent whose read failed on the next poll, and reads each stall wake from the parent's activity", async () => { + const base = fakeApi({ "parentIds=": () => [{ id: "c2", parentId: "i1", status: "blocked" }], "/documents/": () => null, "/comments": () => [], + "/workspace-operations": () => [], "/api/issues/c2": () => ({ id: "c2", status: "blocked", interruption: { canRetry: false } }), + "/activity": () => [{ action: "issue.blocker_stalled_wake", details: { stalledIssueId: "c2", recoveryActionId: "a1" } }, + { action: "issue.updated", details: {} }, { action: "issue.blocker_stalled_wake", details: {} }] }, "blocked"); + let failNextStallRead = false; + const api = { ...base.api, async get(route: string, timeoutMs?: number) { + if (route === "/api/issues/i1") { + if (timeoutMs === undefined && failNextStallRead) { failNextStallRead = false; throw new Error("503"); } + return { id: "i1", status: "blocked", stalledDependencies: [{ stalledIssueId: "c2", relation: "child", recoveryAction: { id: "a1", ownerType: "board" } }] }; + } + return base.api.get(route); + }, post: base.api.post.bind(base.api) } as unknown as ChaosApi; + const observer = new TaskObserver({ ...plan, workload: "M1", followUpAfterMs: null }, api, lab, new Timeline(null), ready); + await observer.launch(); + const start = observer.record.createdAt!; + failNextStallRead = true; + await observer.poll(start + 1_000); + expect(observer.record.childStalls ?? []).toEqual([]); + await observer.poll(start + 2_000); + expect(observer.record.childStalls).toEqual([{ childIssueId: "c2", recoveryActionId: "a1" }]); + const artifacts = await observer.collectArtifacts(); + expect(artifacts.stallWakes).toEqual([{ stalledIssueId: "c2", recoveryActionId: "a1" }, { stalledIssueId: null, recoveryActionId: null }]); + }); + it("S1: stops the running run as the board would, then posts the continue comment only after it settles", async () => { let runStatus = "running"; const base = fakeApi({ "/runs": () => [{ id: "r1", status: runStatus, createdAt: new Date(0).toISOString(), finishedAt: null }] }, "in_progress"); @@ -164,6 +189,67 @@ describe("TaskObserver", () => { expect(posted.filter(route => route.endsWith("/cancel"))).toHaveLength(1); }); + it("S1: holds the Stop while another task's fault has the server down or recovering", async () => { + const base = fakeApi({ "/runs": () => [{ id: "r1", status: "running", createdAt: new Date(0).toISOString(), finishedAt: null }] }, "in_progress"); + const posted: string[] = []; + const api = { ...base.api, get: base.api.get.bind(base.api), async post(route: string) { + posted.push(route); + return route.endsWith("/issues") ? { id: "i1", identifier: "CHA-1" } : { id: "r1" }; + } } as unknown as ChaosApi; + const supervisor = { serverReady: true, faultInProgress: false }; + const observer = new TaskObserver({ ...plan, workload: "S1", followUpAfterMs: 1_000 }, api, lab, new Timeline(null), supervisor); + await observer.launch(); + supervisor.faultInProgress = true; + await observer.poll(observer.record.createdAt! + 2_000); + expect(posted.filter(route => route.endsWith("/cancel"))).toEqual([]); + supervisor.faultInProgress = false; + await observer.poll(observer.record.createdAt! + 3_000); + expect(posted.filter(route => route.endsWith("/cancel"))).toEqual(["/api/heartbeat-runs/r1/cancel"]); + }); + + it("S1: records a missed Stop and still posts the continue comment when the run finished before the stop window", async () => { + const base = fakeApi({ "/runs": () => [{ id: "r1", status: "succeeded", createdAt: new Date(0).toISOString(), finishedAt: new Date(1).toISOString() }], + "/comments": () => [], "/documents/": () => null, "/workspace-operations": () => [] }, "done"); + const posted: string[] = []; + const api = { ...base.api, get: base.api.get.bind(base.api), async post(route: string) { + posted.push(route); + return route.endsWith("/issues") ? { id: "i1", identifier: "CHA-1" } : { id: "comment-1" }; + } } as unknown as ChaosApi; + const timeline = new Timeline(null); + const observer = new TaskObserver({ ...plan, workload: "S1", followUpAfterMs: 1_000 }, api, lab, timeline, ready); + await observer.launch(); + const start = observer.record.createdAt!; + await observer.poll(start + 2_000); + expect(observer.record.stop).toMatchObject({ runId: null, missed: true }); + expect(timeline.entries.some(entry => entry.kind === "task_stop_missed")).toBe(true); + await observer.poll(start + 2_000 + STOP_CONTINUE_AFTER_MS + 1); + expect(observer.record.followUp).toMatchObject({ commentId: "comment-1" }); + expect(posted.filter(route => route.endsWith("/cancel"))).toEqual([]); + expect((await observer.collectArtifacts()).stop).toMatchObject({ missed: true, continuePosted: true, runsStartedBeforeContinue: [] }); + }); + + it("S1: arms a stop-triggered fault at the Stop click plus its delay, and misses it when the Stop was missed", async () => { + const running = fakeApi({ "/runs": () => [{ id: "r1", status: "running", createdAt: new Date(0).toISOString(), finishedAt: null }] }, "in_progress"); + const stopPlan: TaskPlan = { ...plan, workload: "S1", followUpAfterMs: 1_000, trigger: "stop", triggerDelayMs: 500 }; + const observer = new TaskObserver(stopPlan, running.api, lab, new Timeline(null), ready); + await observer.launch(); + const start = observer.record.createdAt!; + expect(observer.faultDue(start + 5_000)).toBeNull(); + await observer.poll(start + 2_000); + const clicked = observer.record.stop!.at; + expect(observer.faultDue(clicked + 499)).toBeNull(); + expect(observer.faultDue(clicked + 500)).toMatchObject({ trigger: "stop", kind: "K1" }); + + const finished = fakeApi({ "/runs": () => [{ id: "r1", status: "succeeded", createdAt: new Date(0).toISOString(), finishedAt: new Date(1).toISOString() }] }, "done"); + const timeline = new Timeline(null); + const missed = new TaskObserver(stopPlan, finished.api, lab, timeline, ready); + await missed.launch(); + await missed.poll(missed.record.createdAt! + 2_000); + expect(missed.record.stop).toMatchObject({ missed: true }); + expect(missed.faultDue(missed.record.createdAt! + 2_600)).toBeNull(); + expect(missed.record.triggerMissed).toEqual(["stop"]); + }); + it("S1: does not count the continue comment's own run as a run after the stop, even when it starts before the comment returns", async () => { let runs: Array> = [{ id: "r1", status: "running", createdAt: new Date(0).toISOString(), finishedAt: null }]; const base = fakeApi({ "/runs": () => runs, "/comments": () => [], "/documents/": () => null, "/workspace-operations": () => [] }, "in_progress"); @@ -294,3 +380,18 @@ describe("childrenPending", () => { expect(childrenPending([{ status: "done" }, { status: "blocked" }])).toBe(false); }); }); + +describe("childSpeedTasksInTurn", () => { + it("reads each observer's subtasks one at a time so a large wave does not flood the API", async () => { + let inFlight = 0, peak = 0; + const observers = [1, 2, 3].map(id => ({ childSpeedTasks: async () => { + inFlight += 1; peak = Math.max(peak, inFlight); + await new Promise(resolve => setTimeout(resolve, 5)); + inFlight -= 1; + return [{ issueId: `c${id}`, adapter: "codex" as const, samples: [] }]; + } })); + expect((await childSpeedTasksInTurn(observers)).map(task => task.issueId)).toEqual(["c1", "c2", "c3"]); + expect(peak).toBe(1); + }); +}); + diff --git a/tests/restart-chaos/observer.ts b/tests/restart-chaos/observer.ts index 54155f1f253..226b53d5b32 100644 --- a/tests/restart-chaos/observer.ts +++ b/tests/restart-chaos/observer.ts @@ -52,6 +52,14 @@ export const CHILD_WAKE_GRACE_MS = 60_000; export const CHILD_STALL_CHECK_MS = 10_000; export const STOP_CONTINUE_AFTER_MS = 20_000; +type ChildSpeedTask = { issueId: string; adapter: AdapterId; samples: Array<{ runs?: RunSample[] }> }; + +export async function childSpeedTasksInTurn(observers: ReadonlyArray<{ childSpeedTasks(): Promise }>): Promise { + const tasks: ChildSpeedTask[] = []; + for (const observer of observers) tasks.push(...await observer.childSpeedTasks()); + return tasks; +} + export function childrenPending(children: ReadonlyArray<{ status: string | null }> | null): boolean { return !children || children.some(child => !["done", "cancelled", "blocked"].includes(child.status ?? "")); } @@ -348,7 +356,7 @@ export class TaskObserver { case "stop": { const stop = this.record.stop; if (!stop) return null; - return stop.error ? "missed" : stop.at; + return stop.error || stop.missed ? "missed" : stop.at; } case "result": { // B8: the run that received the follow-up has accepted its result but @@ -501,10 +509,15 @@ export class TaskObserver { } private async maybeStop(sample: TaskSample, now: number): Promise { - if (!this.definition.stopBeforeFollowUp || this.record.stop || this.plan.followUpAfterMs === null || !sample.reachable) return false; + if (!this.definition.stopBeforeFollowUp || this.record.stop || this.plan.followUpAfterMs === null || !sample.serverReady) return false; if (now < this.record.createdAt! + this.plan.followUpAfterMs) return false; const running = (sample.runs ?? []).find(run => run.status === "running"); - if (!running) return false; + if (!running) { + if (!isResting(sample)) return false; + this.record.stop = { at: now, runId: null, httpStatus: null, error: null, missed: true }; + this.timeline.add("task_stop_missed", { taskId: this.plan.taskId, status: sample.issueStatus ?? null }); + return true; + } const stop: NonNullable = { at: now, runId: running.id, httpStatus: null, error: null }; try { await this.api.post(`/api/heartbeat-runs/${running.id}/cancel`, { cancellationRequestId: randomUUID() }); @@ -588,6 +601,7 @@ export class TaskObserver { .catch(() => null); const blocked = (Array.isArray(rows) ? rows : []).filter(row => row.parentId === this.record.issueId && row.status === "blocked").map(row => String(row.id)); const parent = await this.api.get(`/api/issues/${this.record.issueId}`).catch(() => null); + if (!parent) this.childStallCheckedAt = null; const stalled = Array.isArray(parent?.stalledDependencies) ? parent.stalledDependencies as Json[] : []; for (const dependency of stalled) { if (dependency.relation !== "child" || typeof dependency.stalledIssueId !== "string") continue; @@ -611,8 +625,8 @@ export class TaskObserver { const startedBeforeContinue = [...runs.values()].filter(run => run.id !== stop.runId && run.createdAt && !(continueCommentId && (run.wakeCommentIds ?? []).includes(continueCommentId)) && Date.parse(run.createdAt) > stop.at && (continueAt === null || Date.parse(run.createdAt) < continueAt)).map(run => run.id); - return { runId: stop.runId, runStatus: runs.get(stop.runId)?.status ?? null, runsStartedBeforeContinue: startedBeforeContinue, - continuePosted: Boolean(this.record.followUp?.commentId) }; + return { runId: stop.runId, runStatus: stop.runId ? runs.get(stop.runId)?.status ?? null : null, runsStartedBeforeContinue: startedBeforeContinue, + continuePosted: Boolean(this.record.followUp?.commentId), ...(stop.missed ? { missed: true } : {}) }; } private async retryBlockedChildren(childIds: readonly string[], now: number): Promise { @@ -805,7 +819,7 @@ export class TaskObserver { runsStartedWhilePaused: governance.runsStartedWhilePaused }); } - async childSpeedTasks(): Promise }>> { + async childSpeedTasks(): Promise { if (!this.definition.collect.childDocuments || !this.record.issueId) return []; const rows = await this.api.get(`/api/companies/${this.lab.companyId}/issues?view=index&parentIds=${encodeURIComponent(this.record.issueId)}&limit=20`); const tasks: Array<{ issueId: string; adapter: AdapterId; samples: Array<{ runs?: RunSample[] }> }> = []; diff --git a/tests/restart-chaos/scheduler.test.ts b/tests/restart-chaos/scheduler.test.ts index 9a8c87fddda..455c884bbc5 100644 --- a/tests/restart-chaos/scheduler.test.ts +++ b/tests/restart-chaos/scheduler.test.ts @@ -42,6 +42,11 @@ describe("scheduler determinism", () => { expect(Math.max(...holds)).toBeGreaterThan(K4_HOLD_RANGE_MS[1]); const storm = planStorm(5, 120, ["K4"], 600_000); expect(Math.max(...storm.faults.map(fault => fault.holdMs))).toBeGreaterThan(K4_HOLD_RANGE_MS[1]); + const single = parseCommand(["--adapters", "codex", "--seed", "5"]), both = parseCommand(["--seed", "5"]); + if (single.mode !== "wave" || both.mode !== "wave") throw new Error("expected a wave"); + expect(single.options.workloads).not.toContain("M1"); + expect(both.options.workloads).toContain("M1"); + expect(() => parseCommand(["--adapters", "codex", "--workloads", "M1"])).toThrow(/two agents/); expect(() => parseCommand(["--k4-hold-max-seconds", "601"])).toThrow(/between 120 and 600/); expect(() => parseCommand(["--replay", "w-20261106T101112-s42/t03", "--k4-hold-max-seconds", "400"])).toThrow(/do not combine/); }); diff --git a/tests/restart-chaos/seed.test.ts b/tests/restart-chaos/seed.test.ts index d6a7a920d0a..380fd27f808 100644 --- a/tests/restart-chaos/seed.test.ts +++ b/tests/restart-chaos/seed.test.ts @@ -48,6 +48,18 @@ describe("seedChaosLab workspace isolation", () => { const seed = (api: ChaosApi) => seedChaosLab({ api, env: "local", adapters: ["codex"], concurrency: 2, budgetCents: 3_000, fixtureRoot, waveId: "w-test", timeline: new Timeline(null) }); + it("waits for each seeded agent to reach lifecycleState ready only when the wave asks for it", async () => { + const waiting = fakeApi(body => ({ ...body })); + const timeline = new Timeline(null); + await seedChaosLab({ api: waiting.api, env: "local", adapters: ["codex"], concurrency: 2, budgetCents: 3_000, + fixtureRoot: path.join(fixtureRoot, "waiting"), waveId: "w-test", timeline, waitForReadyAgents: true }); + expect(waiting.calls.some(call => call.method === "GET" && call.route.startsWith("/api/agents/"))).toBe(true); + expect(timeline.entries.filter(entry => entry.kind === "seed_agent_ready")).toEqual([expect.objectContaining({ adapter: "codex" })]); + const skipping = fakeApi(body => ({ ...body })); + await seed(skipping.api); + expect(skipping.calls.some(call => call.method === "GET" && call.route.startsWith("/api/agents/"))).toBe(false); + }); + // RC-21: the project's git_worktree policy is gated behind the instance's // isolated-workspaces setting. Without it every repo task ran in the shared // primary checkout, so concurrent tasks wrote into one tree. @@ -157,9 +169,26 @@ describe("waitForAgentsReady", () => { await expect(waitForAgentsReady(stuck, { codex: { id: "a3" } }, new Timeline(null), 60_000, 1, () => ++polls > 2)).rejects.toThrow(/interrupted/); }); + it("keeps waiting through a deferred verification error and passes once the retry makes the agent ready", async () => { + let reads = 0; + const api = { get: async () => (++reads < 3 ? { lifecycleState: "verifying", lifecycleError: "host busy" } : { lifecycleState: "ready" }) } as unknown as ChaosApi; + const timeline = new Timeline(null); + await waitForAgentsReady(api, { codex: { id: "a1" } }, timeline, 5_000, 1); + expect(timeline.entries.filter(entry => entry.kind === "seed_agent_lifecycle_error")).toEqual([expect.objectContaining({ adapter: "codex", error: "host busy" })]); + }); + + it("names the last read error when an agent never becomes ready", async () => { + const broken = { get: async () => { throw new Error("401 unauthorized"); } } as unknown as ChaosApi; + await expect(waitForAgentsReady(broken, { codex: { id: "a1" } }, new Timeline(null), 20, 5)).rejects.toThrow(/codex \(last read error: 401 unauthorized\)/); + const deferred = { get: async () => ({ lifecycleState: "verifying", lifecycleError: "host busy" }) } as unknown as ChaosApi; + await expect(waitForAgentsReady(deferred, { codex: { id: "a1" } }, new Timeline(null), 20, 5)).rejects.toThrow(/codex \(last lifecycle error: host busy\)/); + }); + it("fails the wave when an agent fails verification or never becomes ready", async () => { - const failed = { get: async () => ({ lifecycleState: "verifying", lifecycleError: "hello probe failed" }) } as unknown as ChaosApi; - await expect(waitForAgentsReady(failed, { claude: { id: "a2" } }, new Timeline(null), 5_000, 1)).rejects.toThrow(/hello probe failed/); + const parked = { get: async () => ({ lifecycleState: "verifying", lifecycleError: "hello probe failed" }) } as unknown as ChaosApi; + await expect(waitForAgentsReady(parked, { claude: { id: "a2" } }, new Timeline(null), 20, 5)).rejects.toThrow(/claude \(last lifecycle error: hello probe failed\)/); + const rejected = { get: async () => ({ lifecycleState: "rejected", lifecycleError: "hire rejected" }) } as unknown as ChaosApi; + await expect(waitForAgentsReady(rejected, { claude: { id: "a2" } }, new Timeline(null), 5_000, 1)).rejects.toThrow(/hire rejected/); const stuck = { get: async () => ({ lifecycleState: "verifying" }) } as unknown as ChaosApi; await expect(waitForAgentsReady(stuck, { claude: { id: "a3" } }, new Timeline(null), 20, 5)).rejects.toThrow(/never reached lifecycleState ready/); }); diff --git a/tests/restart-chaos/seed.ts b/tests/restart-chaos/seed.ts index 2ce62f5ac18..bd3fd179197 100644 --- a/tests/restart-chaos/seed.ts +++ b/tests/restart-chaos/seed.ts @@ -21,25 +21,43 @@ export interface ChaosLab { agents: Record }>; } +export const DAYTONA_AGENT_READY_TIMEOUT_MS = 10 * 60_000; +const TERMINAL_LIFECYCLE_STATES = new Set(["rejected", "terminating", "cleaning_up", "terminated"]); + /** Create the `chaos-sandbox` git repository: python CLI, one failing test, bench.sh. */ export async function waitForAgentsReady(api: ChaosApi, agents: Partial>, timeline: Timeline, timeoutMs = 4 * 60_000, pollMs = 1_000, cancelled: () => boolean = () => false): Promise { const started = Date.now(); const pending = new Map(Object.entries(agents).flatMap(([adapter, agent]) => agent ? [[adapter, agent] as const] : [])); + const lastProblem = new Map(); while (pending.size) { if (cancelled()) throw new Error("Harness interrupted while waiting for agents to finish verification"); for (const [adapter, { id: agentId, createdAt }] of [...pending]) { - const agent = await api.get>(`/api/agents/${agentId}`).catch(() => null); + let agent: Record; + try { + agent = await api.get>(`/api/agents/${agentId}`); + } catch (error) { + lastProblem.set(adapter, `last read error: ${error instanceof Error ? error.message : String(error)}`.slice(0, 300)); + continue; + } + const lifecycleError = agent?.lifecycleError ? String(agent.lifecycleError).slice(0, 300) : null; if (agent?.lifecycleState === "ready") { timeline.add("seed_agent_ready", { adapter, agentId, readyAfterMs: Date.now() - (createdAt ?? started) }); pending.delete(adapter); - } else if (agent?.lifecycleError) { - throw new Error(`Agent ${adapter} (${agentId}) failed lifecycle verification: ${String(agent.lifecycleError).slice(0, 300)}`); + } else if (lifecycleError) { + if (TERMINAL_LIFECYCLE_STATES.has(String(agent.lifecycleState))) { + throw new Error(`Agent ${adapter} (${agentId}) failed lifecycle verification: ${lifecycleError}`); + } + if (lastProblem.get(adapter) !== `last lifecycle error: ${lifecycleError}`) { + timeline.add("seed_agent_lifecycle_error", { adapter, agentId, error: lifecycleError }); + } + lastProblem.set(adapter, `last lifecycle error: ${lifecycleError}`); } } if (!pending.size) return; if (Date.now() - started > timeoutMs) { - throw new Error(`Agents never reached lifecycleState ready within ${Math.round(timeoutMs / 1000)} s: ${[...pending.keys()].join(", ")}`); + const names = [...pending.keys()].map(adapter => lastProblem.has(adapter) ? `${adapter} (${lastProblem.get(adapter)})` : adapter); + throw new Error(`Agents never reached lifecycleState ready within ${Math.round(timeoutMs / 1000)} s: ${names.join(", ")}`); } await new Promise(resolve => setTimeout(resolve, pollMs)); } @@ -242,7 +260,8 @@ export async function seedChaosLab(input: { } if (input.waitForReadyAgents) { await waitForAgentsReady(api, Object.fromEntries(Object.entries(agents).map(([adapter, agent]) => - [adapter, { id: agent.id, createdAt: agentCreatedAt.get(adapter) }])), timeline, input.agentReadyTimeoutMs, 1_000, input.cancelled); + [adapter, { id: agent.id, createdAt: agentCreatedAt.get(adapter) }])), timeline, + input.agentReadyTimeoutMs ?? (input.env === "daytona" ? DAYTONA_AGENT_READY_TIMEOUT_MS : undefined), 1_000, input.cancelled); } // The project's git_worktree policy only takes effect when the instance has diff --git a/tests/restart-chaos/types.ts b/tests/restart-chaos/types.ts index 93676713716..0e430ba82f7 100644 --- a/tests/restart-chaos/types.ts +++ b/tests/restart-chaos/types.ts @@ -221,7 +221,7 @@ export interface OracleArtifacts { workspacePath: string | null; /** B5: distinct `.bench/progress` values the harness itself saw while the task was live. */ benchProgressObserved?: number; - stop?: { runId: string; runStatus: string | null; runsStartedBeforeContinue: string[]; continuePosted: boolean }; + stop?: { runId: string | null; runStatus: string | null; runsStartedBeforeContinue: string[]; continuePosted: boolean; missed?: boolean }; children?: Array<{ id: string; title?: string | null; status: string | null; assigneeAgentId: string | null; documents: Record }>; childStalls?: Array<{ childIssueId: string; recoveryActionId: string | null }>; stallWakes?: Array<{ stalledIssueId: string | null; recoveryActionId: string | null }>; @@ -283,7 +283,7 @@ export interface TaskRecord { deadlineAt: number | null; timedOut: boolean; followUp: { at: number; sentAt?: number; postedAt?: number; commentId: string | null; error: string | null; duringRun?: boolean } | null; - stop?: { at: number; runId: string; httpStatus: number | null; error: string | null }; + stop?: { at: number; runId: string | null; httpStatus: number | null; error: string | null; missed?: boolean }; faultIds: string[]; sweep: RestSweep | null; /** Workspace files present just before the first fault that hit this task (R2). */ diff --git a/tests/restart-chaos/wave-speed.test.ts b/tests/restart-chaos/wave-speed.test.ts index 2a78be4110e..354c5278df6 100644 --- a/tests/restart-chaos/wave-speed.test.ts +++ b/tests/restart-chaos/wave-speed.test.ts @@ -21,9 +21,12 @@ describe("wave speed grade", () => { const slow = gradeWaveSpeed("local", [run("a", "codex", 40_000), run("b", "codex", 40_000, [{ eventType: "run.performance.budget_exceeded", createdAt: "2026-11-08T00:00:00.000Z", payload: {} }])], [], 1); - expect(slow.rows.find(row => row.metric === "time_to_first_activity")?.breaches).toEqual(["p50", "p95"]); + expect(slow.rows.find(row => row.metric === "time_to_first_activity")?.breaches).toEqual([]); expect(slow.rows.find(row => row.metric === "ttft")).toMatchObject({ budget: null, breaches: [] }); - expect(slow).toMatchObject({ breaches: 4, singleRunBreaches: 2, runBudgetExceeded: 1 }); + expect(slow).toMatchObject({ breaches: 2, singleRunBreaches: 2, runBudgetExceeded: 1 }); + const slowFive = gradeWaveSpeed("local", ["a", "b", "c", "d", "e"].map(id => run(id, "codex", 40_000)), [], 0); + expect(slowFive.rows.find(row => row.metric === "time_to_first_activity")?.breaches).toEqual(["p50", "p95"]); + expect(slowFive).toMatchObject({ breaches: 7, singleRunBreaches: 5 }); const heldButFast = gradeWaveSpeed("local", [run("c", "codex", 4_000, [{ eventType: "run.performance.budget_exceeded", createdAt: "2026-11-08T00:00:00.000Z", payload: {} }])], [], 1); expect(heldButFast).toMatchObject({ breaches: 0, singleRunBreaches: 0, runBudgetExceeded: 1 }); @@ -46,7 +49,8 @@ describe("wave speed grade", () => { events: [{ eventType: "turn.started", createdAt: new Date(10_000 + 30_000).toISOString() }] }; const speed = gradeWaveSpeed("local", [recovered], [{ kind: "K1", readyAt: 10_000, runIds: ["r"] }], 0); // Nothing reloaded, so the whole latency is Paperclip's share and is judged. - expect(speed.rows.find(row => row.metric === "restart_recovery_control_plane")).toMatchObject({ adapter: "claude", breaches: ["p50", "p95"] }); + expect(speed.rows.find(row => row.metric === "restart_recovery_control_plane")).toMatchObject({ adapter: "claude", breaches: [] }); + expect(speed).toMatchObject({ singleRunBreaches: 1, breaches: 1 }); expect(speed.rows.find(row => row.metric === "restart_recovery")).toMatchObject({ budget: null, breaches: [], measured: { p50: 30_000 } }); }); @@ -92,6 +96,25 @@ describe("wave speed grade", () => { expect(breachesOf({ n: 1, p50: 99_000, p95: 99_000, max: 99_000 }, null)).toEqual([]); }); + it("judges aggregate p50 and p95 only from five samples and reports smaller rows as an insufficient sample", () => { + const budget = { p50Ms: 1_000, p95Ms: 2_000 }; + expect(breachesOf({ n: 4, p50: 9_000, p95: 9_000, max: 9_000 }, budget)).toEqual([]); + expect(breachesOf({ n: 5, p50: 9_000, p95: 9_000, max: 9_000 }, budget)).toEqual(["p50", "p95"]); + const speed = gradeWaveSpeed("local", [], [], 0); + speed.rows.push({ adapter: "codex", metric: "agent_boot", start: "cold", measured: { n: 2, p50: 9_000, p95: 9_000, max: 9_000 }, + budget, breaches: [] }); + expect(speedMarkdown(speed)).toContain("| insufficient sample (n < 5) |"); + }); + + it("fails a run's speed read instead of paging forever when a full page has no seq", async () => { + let reads = 0; + const api = { get: async () => { reads += 1; return Array.from({ length: 500 }, () => ({ eventType: "x", createdAt: new Date(0).toISOString() })); } } as unknown as ChaosApi; + const speed = await collectWaveSpeed(api, "local", [{ issueId: "i", adapter: "codex", samples: [{ runs: [{ id: "r", status: "succeeded", + createdAt: new Date(0).toISOString(), finishedAt: null }] }] as never }], []); + expect(speed.errors).toEqual([expect.stringMatching(/^r: .*seq/)]); + expect(reads).toBe(3); + }); + const traced = (trace: number, spans: Array<[string, number, number]>): BaselineRun => ({ runId: "t", adapter: "claude", environment: "local", phase: "cold", events: spans.map(([name, offset, duration]) => ({ eventType: "run.performance.span", diff --git a/tests/restart-chaos/wave-speed.ts b/tests/restart-chaos/wave-speed.ts index 065fd1d24ce..314704c2ce6 100644 --- a/tests/restart-chaos/wave-speed.ts +++ b/tests/restart-chaos/wave-speed.ts @@ -46,8 +46,10 @@ export function budgetFor(environment: EnvironmentKind, adapter: string, metric: return byStart[start === "warm" ? "warm" : "cold"]; } +export const MIN_AGGREGATE_SAMPLES = 5; + export function breachesOf(measured: Distribution, budget: SpeedBudget | null): Array<"p50" | "p95"> { - if (!budget) return []; + if (!budget || measured.n < MIN_AGGREGATE_SAMPLES) return []; const out: Array<"p50" | "p95"> = []; if (measured.p50 !== null && measured.p50 > budget.p50Ms) out.push("p50"); if (measured.p95 !== null && measured.p95 > budget.p95Ms) out.push("p95"); @@ -211,6 +213,9 @@ export function gradeWaveSpeed(environment: EnvironmentKind, runs: readonly Base const bootBudget = budgetFor(environment, run.adapter, "agent_boot", start); return (activity !== null && activityBudget !== null && activity > activityBudget.p95Ms) || (boot !== null && bootBudget !== null && boot > bootBudget.p95Ms); + }).length + samples.filter(sample => { + const budget = budgetFor(environment, sample.adapter, "restart_recovery_control_plane", "restart"); + return !sample.interruptedByFault && sample.controlPlaneMs !== null && budget !== null && sample.controlPlaneMs > budget.p95Ms; }).length; const breaches = rows.reduce((total, row) => total + row.breaches.length, 0) + singleRunBreaches; return { environment, rows, @@ -237,7 +242,9 @@ async function runEvents(api: ChaosApi, runId: string): Promise const page = await api.get(`/api/heartbeat-runs/${runId}/events?afterSeq=${afterSeq}&limit=500`, 15_000); for (const row of page) events.push({ eventType: String(row.eventType), createdAt: String(row.createdAt), payload: (row.payload ?? null) as Json | null }); if (page.length < 500) return events; - afterSeq = Number(page[page.length - 1]!.seq); + const next = Number(page[page.length - 1]!.seq); + if (!Number.isFinite(next) || next <= afterSeq) throw new Error(`run events page after seq ${afterSeq} has no later seq`); + afterSeq = next; } } @@ -282,16 +289,21 @@ export async function collectWaveSpeed(api: ChaosApi, environment: EnvironmentKi return gradeWaveSpeed(environment, runs, faultRuns(faults, timing), runBudgetExceeded, errors, outage); } +function breachCell(row: SpeedRow): string { + if (row.breaches.length) return row.breaches.join(", "); + return row.budget && row.measured.n > 0 && row.measured.n < MIN_AGGREGATE_SAMPLES ? `insufficient sample (n < ${MIN_AGGREGATE_SAMPLES})` : "—"; +} + export function speedMarkdown(speed: WaveSpeed): string { const s = (value: number | null) => value === null ? "—" : `${(value / 1000).toFixed(1)} s`; const lines = [`## Speed (${speed.environment})`, "", - `Breaches: ${speed.breaches} (aggregate p50/p95 rows plus ${speed.singleRunBreaches} runs over the p95 budget after outage removal; the server logged ${speed.runBudgetExceeded} budget_exceeded events before removal).`, + `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).`, "", "| 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)} | ` - + `${row.budget ? `${s(row.budget.p50Ms)} / ${s(row.budget.p95Ms)}` : "no budget"} | ${row.breaches.join(", ") || "—"} |`); + + `${row.budget ? `${s(row.budget.p50Ms)} / ${s(row.budget.p95Ms)}` : "no budget"} | ${breachCell(row)} |`); } if (speed.errors.length) lines.push("", `Speed grade incomplete: ${speed.errors.length} run logs not read; the wave fails.`); return `${lines.join("\n")}\n`; diff --git a/tests/restart-chaos/workloads.ts b/tests/restart-chaos/workloads.ts index 3bd8ebc73da..64c376aefd1 100644 --- a/tests/restart-chaos/workloads.ts +++ b/tests/restart-chaos/workloads.ts @@ -270,7 +270,8 @@ export const workloadDefinitions: Record = { return result([ statusCheck(artifacts), ...briefChecks(artifacts.documents.brief, [briefMarker(nonce), continueMarker(nonce)]), - { name: "stop_took_effect", ok: stop?.runStatus === "cancelled", detail: `run=${stop?.runId ?? "none"} status=${stop?.runStatus ?? "none"}` }, + { name: "stop_took_effect", ok: Boolean(stop?.missed) || stop?.runStatus === "cancelled", + detail: stop?.missed ? "missed: the run finished before the stop window" : `run=${stop?.runId ?? "none"} status=${stop?.runStatus ?? "none"}` }, { name: "nothing_ran_after_stop", ok: Boolean(stop) && stop!.continuePosted && stop!.runsStartedBeforeContinue.length === 0, detail: stop ? `continue=${stop.continuePosted} runs=${stop.runsStartedBeforeContinue.join(",") || "none"}` : "not stopped" }, ]);