test(chaos): fail M1 fast on a blocked subtask and grade interrupted waves (#20094)

## Thinking Path

> - Paperclip is the open source app people use to manage AI agents for
work
> - The restart chaos harness proves that real agent tasks survive
control-plane restarts
> - In a K4/K6 wave with the M1 multi-agent scenario, one subtask
failed. Its parent waited on it, and the harness kept watching for over
50 minutes
> - When the operator stopped the wave, the harness wrote no grade
files, so the 17 finished tasks had no grade
> - Separately, master's harness test for time to first activity failed
after #20077 changed how time is measured from run creation
> - This pull request makes M1 fail fast on a blocked subtask, grades
the finished tasks of an interrupted wave, and aligns the speed grade
with #20077
> - The benefit is shorter waves with a grade for every task, and a
green harness suite on master

## Linked Issues or Issue Description

Refs #20071, #20077, #20088

**What happened?**
Wave `w-20261108T181313-s9701` (local, codex and claude, A1/C1/M1, K4
and K6) ran 71 minutes against a planned 30. Task t05 (M1) delegated
CHA-8 and CHA-9. The CHA-8 run failed after a K4 restart (the defect
that #20088 fixes), and CHA-8 went to `blocked`. The observer kept
waiting for CHA-8 to finish. After SIGINT, the harness threw before
grading, so no task had a grade file. Also, `wave-speed.test.ts` fails
on master: #20077 changed `runMetrics` to measure from the start of
`heartbeat.queue`.

**Steps to reproduce**
1. Run an M1 task whose subtask run fails and leaves the subtask
`blocked`.
2. See the observer wait until the parent deadline.
3. Send SIGINT to the harness and see that no grade files are written.

**Expected behavior**
A blocked subtask ends the wait, and the parent is graded as a failure
with a `task_child_blocked` timeline entry. An interrupted wave grades
every finished task and fails the wave.

## What Changed

- `observer.ts`: `childrenPending` treats a `blocked` subtask as
settled, so the parent rests and is graded. The timeline records
`task_child_blocked` with the subtask ids.
- `observer.ts`: `markUnfinished` closes an open task at interrupt as
unfinished (`timedOut`, last seen status) and records
`task_unfinished_at_interrupt`.
- `main.ts`: an interrupt now sets the harness error and grades the
wave, instead of throwing before the grade. The wave still fails.
- `wave-speed.ts`: `firstActivityMs` uses
`runMetrics().firstActivityAfterRunCreatedMs` from #20077, so there is
one definition of time from run creation.
- `wave-speed.test.ts`: the fixture starts `heartbeat.queue` when the
comment wait ends, as in real runs.

## Verification

- `npx vitest run` in `tests/restart-chaos`: 172 passed. Before this
change, the wave-speed test failed on master.
- `node scripts/typecheck-test-projects.mjs tests/restart-chaos`: clean.

## Risks

- A subtask that is `blocked` only for a short time and then resumes
would end the parent's watch after the 60-second grace. The grade then
shows a failure that a longer wait could avoid. M1 subtasks have no
blockers, so `blocked` means a stuck subtask.
- An interrupted wave grades tasks while its server is still up. If the
server is already down, artifact collection fails, and those tasks are
graded as failures.

## Model Used

- Claude Opus 5.5 (`claude-opus-5-5`), Anthropic, with tool use and code
execution in Claude Code.

## Checklist

- [x] I have included a thinking path that traces from project context
to this change
- [x] I have specified the model used (with version and capability
details)
- [x] I have checked ROADMAP.md and confirmed this PR does not duplicate
planned core work
- [x] I have searched GitHub for duplicate or related PRs and linked
them above
- [x] I have either (a) linked existing issues with `Fixes: #` / `Closes
#` / `Refs #` OR (b) described the issue in-PR following the relevant
issue template
- [x] I have not referenced internal/instance-local Paperclip issues or
links (only public GitHub `#NNN` / `github.com/paperclipai/paperclip`
URLs)
- [x] My branch name describes the change (e.g. `docs/...`, `fix/...`)
and contains no internal Paperclip ticket id or instance-derived details
- [x] I have run tests locally and they pass
- [x] I have added or updated tests where applicable
- [x] I have updated relevant documentation to reflect my changes
- [x] I have considered and documented any risks above
- [ ] All Paperclip CI gates are green
- [ ] Greptile is 5/5 with no open P2s, recommendations, or follow-ups
- [x] I will address all Greptile and reviewer comments before
requesting merge

🤖 Generated with [Claude Code](https://claude.com/claude-code)

---------

Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com>
This commit is contained in:
DottaandClaude Opus 5.5 authored and GitHub committed 2026-11-08 14:20:57 -06:00
1 parent c02fd8d427
commit 88835e624a
5 files changed
+76 -10

No files matched your search

+4 -1
View File
@@ -425,7 +425,10 @@ async function main(): Promise<number> {
// An injected fault that did not complete invalidates the wave, even when // An injected fault that did not complete invalidates the wave, even when
// bounded recovery brought the server back and the tasks passed. // 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 (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. // R6: let finalizers settle, then sweep for anything still pending.
const quietFor = Date.now() - lastDoneAt; const quietFor = Date.now() - lastDoneAt;
+48 -1
View File
@@ -4,7 +4,8 @@ import os from "node:os";
import path from "node:path"; import path from "node:path";
import { afterEach, describe, expect, it } from "vitest"; import { afterEach, describe, expect, it } from "vitest";
import type { ChaosApi } from "./api.js"; 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 { createFixtureRepository, type ChaosLab } from "./seed.js";
import { Timeline } from "./timeline.js"; import { Timeline } from "./timeline.js";
import type { TaskPlan } from "./types.js"; import type { TaskPlan } from "./types.js";
@@ -85,6 +86,43 @@ describe("TaskObserver", () => {
expect(observer.record.preFaultSnapshotError).toMatch(/ENOENT/); 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 () => { it("fires the planned fault once, after its offset", async () => {
const { api } = fakeApi(); const { api } = fakeApi();
const observer = new TaskObserver({ ...plan, fireAfterMs: 5_000 }, api, lab, new Timeline(null), ready); 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); expect(record?.result).toBe(BENCH_EXPECTED);
}, 60_000); }, 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);
});
});
+18 -1
View File
@@ -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. */ /** Rest must hold for this long before the observer acts on it. */
export const REST_CONFIRM_MS = 12_000; export const REST_CONFIRM_MS = 12_000;
export const CHILD_WAKE_GRACE_MS = 60_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. */ /** Extra time granted after a Retry click before R3 is graded as timed out. */
export const RETRY_BUDGET_MS = 15 * 60_000; export const RETRY_BUDGET_MS = 15 * 60_000;
/** H1: how long the pause must hold with the server ready before the board resumes. */ /** 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); 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. */ /** Outages extend the deadline: R1 allows budget plus outage time. */
extendDeadline(ms: number) { if (this.record.deadlineAt !== null) this.record.deadlineAt += ms; } 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; const faultSinceRetry = this.record.retry !== null && (this.record.lastFaultAt ?? 0) > this.record.retry.at;
if (status !== "done" && this.definition.collect.childDocuments && this.record.issueId) { if (status !== "done" && this.definition.collect.childDocuments && this.record.issueId) {
const children = await this.collectChildren(this.record.issueId).catch(() => null); 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); this.childrenSettledAt = pending ? null : (this.childrenSettledAt ?? now);
if (pending || now - this.childrenSettledAt! < CHILD_WAKE_GRACE_MS) { if (pending || now - this.childrenSettledAt! < CHILD_WAKE_GRACE_MS) {
this.restCandidateSince = null; this.restCandidateSince = null;
+5 -4
View File
@@ -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 { breachesOf, budgetFor, faultRuns, firstActivityMs, gradeWaveSpeed, outageWindows, speedMarkdown, traceStartMs, withoutOutage } from "./wave-speed.js";
import { runMetrics } from "./ttft-baseline-stats.js"; import { runMetrics } from "./ttft-baseline-stats.js";
const span = (name: string, startOffsetMs: number, durationMs: number) => const span = (name: string, startOffsetMs: number, durationMs: number, extra: Record<string, unknown> = {}) =>
({ eventType: "run.performance.span", createdAt: "2026-11-08T00:00:00.000Z", payload: { span: name, startOffsetMs, durationMs } }); ({ 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 => ({ const run = (runId: string, adapter: string, ttftMs: number, extra: BaselineRun["events"] = []): BaselineRun => ({
runId, adapter, environment: "local", phase: "cold", 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", () => { 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), const withActivity: BaselineRun = { runId: "a", adapter: "codex", environment: "local", phase: "cold",
span("comment.to_run_created", 0, 4_000)]); 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(withActivity)).toBe(5_000);
expect(firstActivityMs(run("b", "codex", 7_000))).toBe(7_000); expect(firstActivityMs(run("b", "codex", 7_000))).toBe(7_000);
const speed = gradeWaveSpeed("local", [withActivity], [], 0); const speed = gradeWaveSpeed("local", [withActivity], [], 0);
+1 -3
View File
@@ -102,9 +102,7 @@ export function withoutOutage(run: BaselineRun, windows: readonly OutageWindow[]
export function firstActivityMs(run: BaselineRun): number | null { export function firstActivityMs(run: BaselineRun): number | null {
const metrics = runMetrics(run); const metrics = runMetrics(run);
const span = runSpans(run).find(candidate => candidate.name === "task.time_to_first_agent_activity"); return metrics.firstActivityAfterRunCreatedMs ?? metrics.ttftAfterRunCreatedMs;
if (!span) return metrics.ttftAfterRunCreatedMs;
return Math.max(0, span.durationMs - (metrics.inputWaitMs ?? 0));
} }
function firstActivityByGroup(runs: readonly BaselineRun[]): Map<string, number[]> { function firstActivityByGroup(runs: readonly BaselineRun[]): Map<string, number[]> {