mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-11-10 01:50:13 +01:00
test(restart-chaos): add a result trigger and recovered-run comment-wake guards (#19689)
## Thinking Path > - Paperclip is the open source app people use to manage AI agents for work > - The restart chaos harness kills the control plane at chosen moments and grades whether each task still finishes correctly > - One wave lost a user's follow-up comment after a kill that landed after the run accepted its result but before the run settled > - No existing trigger aims a fault at that moment, so the case was hard to reproduce on purpose > - The recovery path that settles such a run had no regression test that covers the saved comment > - This pull request adds a `result` trigger to the harness and a regression test for the recovery path > - The benefit is that the harness can aim faults at the result-accepted window, and a change that drops, repeats, or re-wakes a saved comment fails a test ## Linked Issues or Issue Description **What happened?** In a restart-chaos storm wave, a user posted a comment while a native run was active. A hard kill (K1) landed after the run accepted its result and before the run settled. The run settled `succeeded` and the task stayed `done`, but no follow-up run read the comment. **Steps to reproduce** The original failure did not reproduce. Three targeted waves ran 12 tasks with K1 at comment time or in the new result window. Every follow-up comment was consumed exactly once. The new regression test also passes on current `master`. The test and the trigger guard the path and do not claim a fix. **Expected behavior** A comment posted during a run is consumed exactly once after the run ends, including when restart recovery settles the run. ## What Changed - `tests/restart-chaos`: add `--triggers result` (C1 only). K1 fires 0–3 s after the run that received the follow-up proposes or accepts its result (`run.result.proposed` or `run.result.accepted`). The fault fires only while that run is still `running`: the observer checks the latest sample and rereads the runs right before dispatch. A run that settled during the delay, or a follow-up posted at rest, records a `result` miss. Add poll-driven unit tests for these cases and a README row. - `server/src/__tests__/native-run-projection-work.test.ts`: add embedded Postgres tests in which background recovery, not the executor, settles the run (projection, environment settlement, and deferred-receipt workers), with a deferred user comment and an active local lease left by the killed executor. The tests check: - The comment is promoted into exactly one follow-up run, and a second restart adds none. - A comment the run already received as a same-turn steer is not woken again. The other saved comment still is. - A queue whose only comment was steered stays cancelled, and no follow-up starts. - A Retry click does not consume the comment a second time. A click that observed the source is stale. A click that observed the follow-up joins it. ## Verification - `cd tests/restart-chaos && npx vitest run --config vitest.config.ts` (96 tests pass) - `cd server && npx vitest run src/__tests__/native-run-projection-work.test.ts` (54 tests pass) - Live, local, ACPX Claude, Codex and OpenCode: `node cli/node_modules/tsx/dist/cli.mjs tests/restart-chaos/main.ts --env local --workloads C1 --triggers comment --faults K1 --adapters codex,claude,opencode --tasks 4 --concurrency 2 --rc06-masked` passed 4 of 4. Two waves with `--triggers result` consumed each follow-up exactly once. One task in those waves found a separate defect: a kill 1.4 s after the result commit left the run `running` behind the dead controller's 20-minute finalization lease. A separate pull request fixes that defect. ## Risks - Low risk. These are test and harness changes only. No production code changes. - The `result` trigger depends on the observer's poll interval (about 3 s), so the exact kill point within the window varies. ## Model Used - Claude Opus 5.5 (`claude-opus-5-5`), Anthropic, run as an agent in Claude Code with tool use (shell, file editing, local test execution). ## 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:
1 parent
5e4d24b6c8
commit
d26372dc8a
6 files changed
+244
-7
No files matched your search
@@ -21,7 +21,7 @@ pnpm exec vitest run --config tests/restart-chaos/vitest.config.ts # credential
|
||||
node scripts/typecheck-test-projects.mjs tests/restart-chaos # typecheck
|
||||
```
|
||||
|
||||
Options: `--triggers time,comment,retry,queued,tool` (fault timing, below),
|
||||
Options: `--triggers time,comment,retry,queued,tool,result` (fault timing, below),
|
||||
`--workloads A1,B1,B5,C1`, `--budget-cents` (company hard cap,
|
||||
default 3000), `--poll-ms` (2000–5000), `--keep` (keep the temporary instance).
|
||||
|
||||
@@ -137,6 +137,7 @@ the observer, after a seeded delay:
|
||||
| Trigger | Fires | Plan |
|
||||
| --- | --- | --- |
|
||||
| `comment` | 0–5 s after the C1 follow-up was posted to a live run (C1 only) | C1 + K1, B8 |
|
||||
| `result` | 0–3 s after the run that received the C1 follow-up proposed or accepted its result, only while that run is still `running` (C1 only) | C1 + K1, B8 |
|
||||
| `retry` | 0–2 s after an accepted Retry click, as an extra K1 after the planned fault | K8 |
|
||||
| `queued` | on the first poll whose run is still `queued` with no start | B1 |
|
||||
| `tool` | 15–60 s after `bench.sh` progress first appears (B5 only) | B6 |
|
||||
|
||||
@@ -39,6 +39,8 @@ function stillQueued(runs: readonly RunSample[]): boolean {
|
||||
return runs.some(run => run.status === "queued" && !run.startedAt) && !runs.some(run => run.startedAt || run.status === "running");
|
||||
}
|
||||
export const TRIGGER_LATE_MS = 10_000;
|
||||
/** The run settles soon after acceptance; arming on the proposal keeps the window reachable. */
|
||||
const RESULT_TRIGGER_EVENTS = new Set(["run.result.proposed", "run.result.accepted"]);
|
||||
|
||||
/** Rest must hold for this long before the observer acts on it. */
|
||||
export const REST_CONFIRM_MS = 12_000;
|
||||
@@ -160,6 +162,7 @@ export class TaskObserver {
|
||||
|
||||
private triggerWindowOpen(fault: ScheduledFault, now: number, dueAt: number): boolean {
|
||||
if (now - dueAt > TRIGGER_LATE_MS) return false;
|
||||
if (fault.trigger === "result") return this.resultRunStillRunning(this.latestReachableRuns());
|
||||
if (fault.trigger !== "queued") return true;
|
||||
const latest = [...this.record.samples].reverse().find(sample => sample.reachable);
|
||||
return stillQueued(latest?.runs ?? []);
|
||||
@@ -169,6 +172,11 @@ export class TaskObserver {
|
||||
if (!fault.trigger || fault.trigger === "time") return true;
|
||||
const armedAt = this.triggerArmedAt(fault);
|
||||
let open = typeof armedAt === "number" && now - (armedAt + (fault.delayMs ?? 0)) <= TRIGGER_LATE_MS;
|
||||
if (open && fault.trigger === "result") {
|
||||
const runs = await this.api.get<Json[]>(`/api/issues/${this.record.issueId}/runs`, 5_000)
|
||||
.then(rows => (rows ?? []).map(toRunSample)).catch(() => null);
|
||||
open = runs !== null && this.resultRunStillRunning(runs);
|
||||
}
|
||||
if (open && fault.trigger === "queued") {
|
||||
const runs = await this.api.get<Json[]>(`/api/issues/${this.record.issueId}/runs`, 5_000)
|
||||
.then(rows => (rows ?? []).map(toRunSample)).catch(() => null);
|
||||
@@ -178,6 +186,15 @@ export class TaskObserver {
|
||||
return open;
|
||||
}
|
||||
|
||||
private latestReachableRuns(): RunSample[] {
|
||||
return [...this.record.samples].reverse().find(sample => sample.reachable)?.runs ?? [];
|
||||
}
|
||||
|
||||
/** A `result` fault outside the accepted-but-unsettled window would test a different boundary. */
|
||||
private resultRunStillRunning(runs: readonly RunSample[]): boolean {
|
||||
return runs.some(run => run.id === this.record.resultRunId && run.status === "running");
|
||||
}
|
||||
|
||||
private noteTriggerMissed(fault: ScheduledFault) {
|
||||
const trigger = fault.trigger ?? "time";
|
||||
(this.record.triggerMissed ??= []).push(trigger);
|
||||
@@ -206,6 +223,14 @@ export class TaskObserver {
|
||||
return queued && !started ? first.at : "missed";
|
||||
}
|
||||
case "tool": return this.record.benchFirstSeenAt ?? null;
|
||||
case "result": {
|
||||
// B8: the run that received the follow-up has accepted its result but
|
||||
// has not settled yet. A follow-up posted at rest cannot cross it.
|
||||
const followUp = this.record.followUp;
|
||||
if (!followUp) return null;
|
||||
if (!followUp.commentId || !followUp.duringRun) return "missed";
|
||||
return this.record.resultAcceptedAt ?? null;
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
@@ -294,6 +319,10 @@ export class TaskObserver {
|
||||
if (!events?.length) break;
|
||||
for (const event of events) {
|
||||
if (typeof event.seq === "number" && event.seq > cursor.seq) cursor.seq = event.seq;
|
||||
if (RESULT_TRIGGER_EVENTS.has(String(event.eventType)) && this.record.followUp?.duringRun && !this.record.resultAcceptedAt) {
|
||||
this.record.resultAcceptedAt = Date.now();
|
||||
this.record.resultRunId = run.id;
|
||||
}
|
||||
cursor.lastAt = latestIso([cursor.lastAt, event.createdAt]);
|
||||
}
|
||||
if (events.length < RUN_EVENT_PAGE) break;
|
||||
|
||||
@@ -34,10 +34,11 @@ export const TRIGGER_DELAY_RANGE_MS: Record<Exclude<TriggerId, "time">, readonly
|
||||
retry: [0, 2_000],
|
||||
queued: [0, 0],
|
||||
tool: [15_000, 60_000],
|
||||
result: [0, 3_000],
|
||||
};
|
||||
|
||||
export function triggerFitsWorkload(trigger: TriggerId, workload: WorkloadId): boolean {
|
||||
if (trigger === "comment") return workload === "C1";
|
||||
if (trigger === "comment" || trigger === "result") return workload === "C1";
|
||||
if (trigger === "tool") return workload === "B5";
|
||||
return true;
|
||||
}
|
||||
@@ -54,7 +55,7 @@ export function planTasks(options: Pick<WaveOptions, "seed" | "tasks" | "workloa
|
||||
if (options.stormMinutes && triggers.some(trigger => trigger !== "time")) throw new Error("A K13 storm fires on its own clock; use --triggers time");
|
||||
for (const trigger of triggers) {
|
||||
if (!options.workloads.some(workload => triggerFitsWorkload(trigger, workload))) {
|
||||
throw new Error(`Trigger "${trigger}" needs workload ${trigger === "comment" ? "C1" : "B5"} in --workloads`);
|
||||
throw new Error(`Trigger "${trigger}" needs workload ${trigger === "comment" || trigger === "result" ? "C1" : "B5"} in --workloads`);
|
||||
}
|
||||
}
|
||||
const cells: Array<{ workload: WorkloadId; adapter: AdapterId; fault: TaskFaultKind; trigger: TriggerId }> = [];
|
||||
|
||||
@@ -25,9 +25,15 @@ const options: WaveOptions = { env: "local", adapters: ["codex", "claude", "open
|
||||
triggers: ["time", "comment", "retry", "queued", "tool"] };
|
||||
|
||||
type Json = Record<string, unknown>;
|
||||
function scriptedApi(state: { runs: Json[]; issue: Json; retry?: Json }) {
|
||||
function scriptedApi(state: { runs: Json[]; issue: Json; retry?: Json; events?: Json[] }) {
|
||||
const api = {
|
||||
async get(route: string) { return route.endsWith("/runs") ? state.runs : route.endsWith("/comments") ? [] : state.issue; },
|
||||
async get(route: string) {
|
||||
if (route.includes("/events")) {
|
||||
const after = Number(new URL(route, "http://x").searchParams.get("afterSeq") ?? 0);
|
||||
return (state.events ?? []).filter(event => Number(event.seq) > after);
|
||||
}
|
||||
return route.endsWith("/runs") ? state.runs : route.endsWith("/comments") ? [] : state.issue;
|
||||
},
|
||||
async post(route: string) {
|
||||
if (route.endsWith("/issues")) return { id: "i1", identifier: "CHA-1" };
|
||||
if (route.endsWith("/retry")) return state.retry ?? { accepted: true };
|
||||
@@ -198,6 +204,56 @@ describe("trigger firing", () => {
|
||||
expect(observer.faultDue(start + 50_000)).toMatchObject({ trigger: "tool" });
|
||||
});
|
||||
|
||||
it("result: arms from the target run's result event and fires only while that run is running", async () => {
|
||||
const running = { runId: "r1", status: "running", startedAt: new Date().toISOString() };
|
||||
const state = { runs: [running] as Json[], issue: { id: "i1", status: "in_progress" },
|
||||
events: [{ seq: 1, eventType: "turn.started", createdAt: new Date().toISOString() }] as Json[] };
|
||||
const observer = new TaskObserver({ ...base, trigger: "result", triggerDelayMs: 2_000 }, scriptedApi(state), lab, new Timeline(null), ready);
|
||||
await observer.launch();
|
||||
const start = observer.record.createdAt!;
|
||||
observer.record.followUp = { at: start, postedAt: start, commentId: "c1", error: null, duringRun: true };
|
||||
await observer.poll(start + 1_000);
|
||||
// An unrelated event does not arm the trigger.
|
||||
expect(observer.record.resultAcceptedAt).toBeUndefined();
|
||||
state.events.push({ seq: 2, eventType: "run.result.accepted", createdAt: new Date().toISOString() });
|
||||
await observer.poll(start + 2_000);
|
||||
const armedAt = observer.record.resultAcceptedAt!;
|
||||
expect(observer.record.resultRunId).toBe("r1");
|
||||
expect(observer.faultDue(armedAt + 1_999)).toBeNull();
|
||||
const fault = observer.faultDue(armedAt + 2_000);
|
||||
expect(fault).toMatchObject({ trigger: "result" });
|
||||
expect(await observer.confirmTrigger(fault!, armedAt + 2_000)).toBe(true);
|
||||
// The run settled before dispatch: the fault would land outside the window.
|
||||
state.runs = [{ ...running, status: "succeeded", finishedAt: new Date().toISOString() }];
|
||||
expect(await observer.confirmTrigger(fault!, armedAt + 2_000)).toBe(false);
|
||||
expect(observer.record.triggerMissed).toEqual(["result"]);
|
||||
});
|
||||
|
||||
it("result: records a miss when the target run settled during the delay", async () => {
|
||||
const state = { runs: [{ runId: "r1", status: "running" }] as Json[], issue: { id: "i1", status: "in_progress" },
|
||||
events: [{ seq: 1, eventType: "run.result.proposed", createdAt: new Date().toISOString() }] as Json[] };
|
||||
const observer = new TaskObserver({ ...base, trigger: "result", triggerDelayMs: 3_000 }, scriptedApi(state), lab, new Timeline(null), ready);
|
||||
await observer.launch();
|
||||
const start = observer.record.createdAt!;
|
||||
observer.record.followUp = { at: start, postedAt: start, commentId: "c1", error: null, duringRun: true };
|
||||
await observer.poll(start + 1_000);
|
||||
const armedAt = observer.record.resultAcceptedAt!;
|
||||
state.runs = [{ runId: "r1", status: "succeeded" }];
|
||||
await observer.poll(armedAt + 1_000);
|
||||
expect(observer.faultDue(armedAt + 3_000)).toBeNull();
|
||||
expect(observer.record.triggerMissed).toEqual(["result"]);
|
||||
});
|
||||
|
||||
it("result: misses when the follow-up was posted at rest", async () => {
|
||||
const observer = new TaskObserver({ ...base, trigger: "result", triggerDelayMs: 0 },
|
||||
scriptedApi({ runs: [], issue: { id: "i1", status: "done" } }), lab, new Timeline(null), ready);
|
||||
await observer.launch();
|
||||
const start = observer.record.createdAt!;
|
||||
observer.record.followUp = { at: start, postedAt: start, commentId: "c1", error: null, duringRun: false };
|
||||
expect(observer.faultDue(start + 1)).toBeNull();
|
||||
expect(observer.record.triggerMissed).toEqual(["result"]);
|
||||
});
|
||||
|
||||
it("records a miss instead of firing a triggered fault after its window has passed", async () => {
|
||||
const observer = new TaskObserver({ ...base, workload: "B5", trigger: "tool", triggerDelayMs: 1_000 },
|
||||
scriptedApi({ runs: [], issue: { id: "i1", status: "in_progress" } }), lab, new Timeline(null), ready);
|
||||
|
||||
@@ -11,7 +11,7 @@ export type WorkloadId = (typeof WORKLOAD_IDS)[number];
|
||||
export const ADAPTER_IDS = ["codex", "claude", "opencode"] as const;
|
||||
export type AdapterId = (typeof ADAPTER_IDS)[number];
|
||||
|
||||
export const TRIGGER_IDS = ["time", "comment", "retry", "queued", "tool"] as const;
|
||||
export const TRIGGER_IDS = ["time", "comment", "retry", "queued", "tool", "result"] as const;
|
||||
export type TriggerId = (typeof TRIGGER_IDS)[number];
|
||||
|
||||
export const ENVIRONMENT_KINDS = ["local", "daytona"] as const;
|
||||
@@ -227,6 +227,10 @@ export interface TaskRecord {
|
||||
/** B5: distinct bench progress values the observer read during polling. */
|
||||
benchProgressSeen?: string[];
|
||||
benchFirstSeenAt?: number | null;
|
||||
/** C1: first time the observer saw the run that received the follow-up propose or accept its result. */
|
||||
resultAcceptedAt?: number | null;
|
||||
/** The run whose result armed the `result` trigger; the fault fires only while it is still running. */
|
||||
resultRunId?: string | null;
|
||||
triggerMissed?: TriggerId[];
|
||||
}
|
||||
|
||||
|
||||
Reference in new issue
Block a user