diff --git a/tests/restart-chaos/main.ts b/tests/restart-chaos/main.ts index dc02edc393a..a3e77987747 100644 --- a/tests/restart-chaos/main.ts +++ b/tests/restart-chaos/main.ts @@ -425,7 +425,10 @@ async function main(): Promise { // An injected fault that did not complete invalidates the wave, even when // bounded recovery brought the server back and the tasks passed. if (faultFailures) harnessError ??= new Error(`${faultFailures} injected fault(s) failed; see fault_error in the timeline`); - if (interrupted) throw new Error("Harness interrupted before the wave finished"); + if (interrupted) { + harnessError ??= new Error("Harness interrupted before the wave finished"); + for (const observer of launched) observer.markUnfinished(); + } // R6: let finalizers settle, then sweep for anything still pending. const quietFor = Date.now() - lastDoneAt; diff --git a/tests/restart-chaos/observer.test.ts b/tests/restart-chaos/observer.test.ts index 3094909e8a9..51ad4916034 100644 --- a/tests/restart-chaos/observer.test.ts +++ b/tests/restart-chaos/observer.test.ts @@ -4,7 +4,8 @@ import os from "node:os"; import path from "node:path"; import { afterEach, describe, expect, it } from "vitest"; import type { ChaosApi } from "./api.js"; -import { REST_CONFIRM_MS, STALL_GIVE_UP_MS, TaskObserver, listWorkspaceFiles } from "./observer.js"; +import { CHILD_WAKE_GRACE_MS, REST_CONFIRM_MS, STALL_GIVE_UP_MS, TaskObserver, childrenPending, listWorkspaceFiles } from "./observer.js"; +import { gradeTask } from "./grader.js"; import { createFixtureRepository, type ChaosLab } from "./seed.js"; import { Timeline } from "./timeline.js"; import type { TaskPlan } from "./types.js"; @@ -85,6 +86,43 @@ describe("TaskObserver", () => { expect(observer.record.preFaultSnapshotError).toMatch(/ENOENT/); }); + it("keeps an M1 parent watched while a subtask runs, then rests it once a subtask is blocked", async () => { + let childStatus = "in_progress"; + const { api } = fakeApi({ "parentIds=": () => [{ id: "c1", parentId: "i1", status: "done" }, { id: "c2", parentId: "i1", status: childStatus }], + "/documents/": () => null }, "blocked"); + const timeline = new Timeline(null); + const observer = new TaskObserver({ ...plan, workload: "M1", followUpAfterMs: null }, api, lab, timeline, ready); + await observer.launch(); + let now = observer.record.createdAt! + 1_000; + const restWindow = async () => { await observer.poll(now); now += REST_CONFIRM_MS + 1; await observer.poll(now); now += 1_000; }; + await restWindow(); + await restWindow(); + expect(observer.done).toBe(false); + childStatus = "blocked"; + await restWindow(); + expect(observer.done).toBe(false); + expect(timeline.entries.filter(entry => entry.kind === "task_child_blocked")).toHaveLength(1); + now += CHILD_WAKE_GRACE_MS; + await restWindow(); + expect(observer.done).toBe(true); + expect(observer.record.finalStatus).toBe("blocked"); + }); + + it("closes an open task as unfinished at interrupt, so the wave grades it as a failure", async () => { + const { api } = fakeApi({}, "in_progress"); + const timeline = new Timeline(null); + const observer = new TaskObserver({ ...plan, workload: "A1", followUpAfterMs: null }, api, lab, timeline, ready); + await observer.launch(); + await observer.poll(observer.record.createdAt! + 1_000); + observer.markUnfinished(); + expect(observer.done).toBe(true); + expect(observer.record).toMatchObject({ timedOut: true, finalStatus: "in_progress" }); + expect(timeline.entries.some(entry => entry.kind === "task_unfinished_at_interrupt")).toBe(true); + const grade = gradeTask(observer.record, [], observer.definition.budgetMs, { verdict: "pass", checks: [] }); + expect(grade.pass).toBe(false); + expect(grade.rules.R1.detail).toMatch(/no_rest_within_budget/); + }); + it("fires the planned fault once, after its offset", async () => { const { api } = fakeApi(); const observer = new TaskObserver({ ...plan, fireAfterMs: 5_000 }, api, lab, new Timeline(null), ready); @@ -116,3 +154,12 @@ describe("fixture repository", () => { expect(record?.result).toBe(BENCH_EXPECTED); }, 60_000); }); + +describe("childrenPending", () => { + it("waits on running subtasks and stops waiting once each is done, cancelled or blocked", () => { + expect(childrenPending(null)).toBe(true); + expect(childrenPending([{ status: "done" }, { status: "in_progress" }])).toBe(true); + expect(childrenPending([{ status: "done" }, { status: "cancelled" }])).toBe(false); + expect(childrenPending([{ status: "done" }, { status: "blocked" }])).toBe(false); + }); +}); diff --git a/tests/restart-chaos/observer.ts b/tests/restart-chaos/observer.ts index 919d4fdead5..b67ddcd300a 100644 --- a/tests/restart-chaos/observer.ts +++ b/tests/restart-chaos/observer.ts @@ -49,6 +49,10 @@ const RESULT_TRIGGER_EVENTS = new Set(["run.result.proposed", "run.result.accept /** Rest must hold for this long before the observer acts on it. */ export const REST_CONFIRM_MS = 12_000; export const CHILD_WAKE_GRACE_MS = 60_000; + +export function childrenPending(children: ReadonlyArray<{ status: string | null }> | null): boolean { + return !children || children.some(child => !["done", "cancelled", "blocked"].includes(child.status ?? "")); +} /** Extra time granted after a Retry click before R3 is graded as timed out. */ export const RETRY_BUDGET_MS = 15 * 60_000; /** H1: how long the pause must hold with the server ready before the board resumes. */ @@ -386,6 +390,15 @@ export class TaskObserver { if (startedAt !== undefined) this.record.lastFaultAt = Math.max(this.record.lastFaultAt ?? 0, startedAt); } + markUnfinished() { + if (this.done) return; + const last = this.record.samples.at(-1); + this.record.timedOut = true; + this.record.finalStatus = last?.issueStatus ?? this.record.finalStatus; + this.done = true; + this.timeline.add("task_unfinished_at_interrupt", { taskId: this.plan.taskId, status: this.record.finalStatus }); + } + /** Outages extend the deadline: R1 allows budget plus outage time. */ extendDeadline(ms: number) { if (this.record.deadlineAt !== null) this.record.deadlineAt += ms; } @@ -501,7 +514,11 @@ export class TaskObserver { const faultSinceRetry = this.record.retry !== null && (this.record.lastFaultAt ?? 0) > this.record.retry.at; if (status !== "done" && this.definition.collect.childDocuments && this.record.issueId) { const children = await this.collectChildren(this.record.issueId).catch(() => null); - const pending = !children || children.some(child => !["done", "cancelled"].includes(child.status ?? "")); + const pending = childrenPending(children); + const blocked = (children ?? []).filter(child => child.status === "blocked").map(child => child.id); + if (!pending && blocked.length && this.childrenSettledAt === null) { + this.timeline.add("task_child_blocked", { taskId: this.plan.taskId, childIssueIds: blocked }); + } this.childrenSettledAt = pending ? null : (this.childrenSettledAt ?? now); if (pending || now - this.childrenSettledAt! < CHILD_WAKE_GRACE_MS) { this.restCandidateSince = null; diff --git a/tests/restart-chaos/wave-speed.test.ts b/tests/restart-chaos/wave-speed.test.ts index b283fc11f68..9e2ef2f232a 100644 --- a/tests/restart-chaos/wave-speed.test.ts +++ b/tests/restart-chaos/wave-speed.test.ts @@ -4,8 +4,8 @@ import type { FaultReceipt } from "./types.js"; import { breachesOf, budgetFor, faultRuns, firstActivityMs, gradeWaveSpeed, outageWindows, speedMarkdown, traceStartMs, withoutOutage } from "./wave-speed.js"; import { runMetrics } from "./ttft-baseline-stats.js"; -const span = (name: string, startOffsetMs: number, durationMs: number) => - ({ eventType: "run.performance.span", createdAt: "2026-11-08T00:00:00.000Z", payload: { span: name, startOffsetMs, durationMs } }); +const span = (name: string, startOffsetMs: number, durationMs: number, extra: Record = {}) => + ({ eventType: "run.performance.span", createdAt: "2026-11-08T00:00:00.000Z", payload: { span: name, startOffsetMs, durationMs, ...extra } }); const run = (runId: string, adapter: string, ttftMs: number, extra: BaselineRun["events"] = []): BaselineRun => ({ runId, adapter, environment: "local", phase: "cold", @@ -30,8 +30,9 @@ describe("wave speed grade", () => { }); it("judges time to first agent activity when the run logs it, net of the wait behind a live turn", () => { - const withActivity = run("a", "codex", 40_000, [span("task.time_to_first_agent_activity", 0, 9_000), - span("comment.to_run_created", 0, 4_000)]); + const withActivity: BaselineRun = { runId: "a", adapter: "codex", environment: "local", phase: "cold", + events: [span("comment.to_run_created", 0, 4_000), span("heartbeat.queue", 4_000, 100), span("runner.turn.submit", 4_100, 900), + span("task.time_to_first_agent_activity", 0, 9_000, { anchor: "comment" }), span("task.time_to_first_token", 0, 40_000, { anchor: "comment" })] }; expect(firstActivityMs(withActivity)).toBe(5_000); expect(firstActivityMs(run("b", "codex", 7_000))).toBe(7_000); const speed = gradeWaveSpeed("local", [withActivity], [], 0); diff --git a/tests/restart-chaos/wave-speed.ts b/tests/restart-chaos/wave-speed.ts index 61afe2e1001..bfa77ce0d03 100644 --- a/tests/restart-chaos/wave-speed.ts +++ b/tests/restart-chaos/wave-speed.ts @@ -102,9 +102,7 @@ export function withoutOutage(run: BaselineRun, windows: readonly OutageWindow[] export function firstActivityMs(run: BaselineRun): number | null { const metrics = runMetrics(run); - const span = runSpans(run).find(candidate => candidate.name === "task.time_to_first_agent_activity"); - if (!span) return metrics.ttftAfterRunCreatedMs; - return Math.max(0, span.durationMs - (metrics.inputWaitMs ?? 0)); + return metrics.firstActivityAfterRunCreatedMs ?? metrics.ttftAfterRunCreatedMs; } function firstActivityByGroup(runs: readonly BaselineRun[]): Map {