mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-11-10 01:50:13 +01:00
fix(restart-chaos): stop the timeline echo loop when stdout breaks (#19695)
## Thinking Path
> - Paperclip is the open source app people use to manage AI agents for
work
> - The restart chaos harness (`tests/restart-chaos/`) runs waves of
real agent tasks while it restarts the control plane on purpose
> - A wave writes a timeline file and also echoes every timeline entry
to stdout
> - When the process that reads that stdout exits, every echo fails with
EPIPE. The uncaught-exception handler then records the error with
another echo, so the loop never ends
> - In one Daytona wave this wrote 3.2 million entries (2.5 GB) in 30
minutes. It also stopped the wave from grading its tasks
> - This pull request stops the echo after the first stdout error, and
records the stdout loss once
> - The benefit is that a wave keeps running and grading when its log
reader goes away
## Linked Issues or Issue Description
**Bug description**
`Timeline.add` echoes with `console.info`. After stdout breaks, each
echo raises EPIPE as an uncaught exception. The handler in `main.ts`
calls `timeline.add("harness_uncaught_exception")`, and that call echoes
again.
**Steps to reproduce**
Run a wave as a child process that reads its stdout, for example from a
wave-loop script. Kill the parent while the wave runs. `timeline.jsonl`
then grows without bound with `harness_uncaught_exception` / `write
EPIPE` entries.
**Expected behavior**
The wave goes on writing its files (timeline, grades, ledger) and stops
writing to the broken stdout.
Refs #19544
## What Changed
- `tests/restart-chaos/timeline.ts`: a `process.stdout` error listener
and a guard around `console.info` turn off the echo for good after a
broken-pipe error. The timeline file is still written. On the first
entry after the echo stops, the timeline writes one
`harness_stdout_lost` entry (file only) with the error. The file adds
`isBrokenStdoutError` and `markTimelineEchoBroken`.
- `tests/restart-chaos/main.ts`: the uncaught-exception handler passes
broken-stdout errors to `markTimelineEchoBroken`. It does not mark the
wave as interrupted and does not set a harness error.
- `tests/restart-chaos/timeline.test.ts` (new): the error
classification, and the file-but-no-echo behaviour with exactly one
`harness_stdout_lost` entry.
## Verification
- `pnpm exec vitest run --config tests/restart-chaos/vitest.config.ts`:
102/102 pass.
- `node scripts/typecheck-test-projects.mjs tests/restart-chaos`: clean.
- Incident: wave `w-20261107T001552-s13`. Its timeline had 76 real
entries, then 3,242,762 `harness_uncaught_exception` entries. Those 3.2
million entries came from the loop this pull request removes.
## Risks
- This change touches the test harness only.
- After stdout breaks, the console shows no wave progress, but every
result is still in the wave's files. A different uncaught exception
still stops the wave as before.
> For core feature work, check [`ROADMAP.md`](ROADMAP.md) first and
discuss it in `#dev` before opening the PR. Feature PRs that overlap
with planned core work may need to be redirected — check the roadmap
first. See `CONTRIBUTING.md`.
## Model Used
- Claude Opus 5.5 (`claude-opus-5-5`), Anthropic, in Claude Code with
tool use (shell, file edits, GitHub CLI). Default context window,
extended thinking.
## 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
803cb3bfe3
commit
aca908a165
3 files changed
+89
-3
No files matched your search
@@ -23,7 +23,7 @@ import { TaskObserver } from "./observer.js";
|
||||
import { StormRun, observedFaultSchedule, planWave, replayWave } from "./scheduler.js";
|
||||
import { seedChaosLab } from "./seed.js";
|
||||
import { ChaosSupervisor } from "./supervisor.js";
|
||||
import { Timeline } from "./timeline.js";
|
||||
import { isBrokenStdoutError, markTimelineEchoBroken, Timeline } from "./timeline.js";
|
||||
import type { FaultKind, FaultReceipt, OracleArtifacts, TriggerId, WavePlan } from "./types.js";
|
||||
|
||||
const repositoryRoot = path.resolve(import.meta.dirname, "../..");
|
||||
@@ -122,6 +122,9 @@ async function main(): Promise<number> {
|
||||
let harnessError: unknown;
|
||||
process.on("uncaughtException", error => {
|
||||
if (isSocketTypeOfServiceRace(error)) { timeline.add("harness_socket_race_ignored", { error: String(error) }); return; }
|
||||
// A reader of our stdout went away. Keep running (results go to files); the
|
||||
// timeline records harness_stdout_lost once on its next entry.
|
||||
if (isBrokenStdoutError(error)) { markTimelineEchoBroken(error); return; }
|
||||
timeline.add("harness_uncaught_exception", { error: error.stack ?? String(error) });
|
||||
harnessError ??= error;
|
||||
interrupted = true;
|
||||
|
||||
@@ -0,0 +1,43 @@
|
||||
import { mkdtemp, readFile, rm } from "node:fs/promises";
|
||||
import os from "node:os";
|
||||
import path from "node:path";
|
||||
import { afterEach, describe, expect, it, vi } from "vitest";
|
||||
import { isBrokenStdoutError, Timeline, timelineEchoBroken } from "./timeline.js";
|
||||
|
||||
describe("Timeline with a broken stdout", () => {
|
||||
const directories: string[] = [];
|
||||
afterEach(async () => {
|
||||
vi.restoreAllMocks();
|
||||
await Promise.all(directories.splice(0).map(directory => rm(directory, { recursive: true, force: true })));
|
||||
});
|
||||
|
||||
it("classifies broken-pipe errors only", () => {
|
||||
expect(isBrokenStdoutError(Object.assign(new Error("write EPIPE"), { code: "EPIPE" }))).toBe(true);
|
||||
expect(isBrokenStdoutError(Object.assign(new Error("destroyed"), { code: "ERR_STREAM_DESTROYED" }))).toBe(true);
|
||||
expect(isBrokenStdoutError(new Error("other"))).toBe(false);
|
||||
expect(isBrokenStdoutError(null)).toBe(false);
|
||||
});
|
||||
|
||||
it("keeps writing the file but stops echoing once stdout fails, so errors cannot feed back", async () => {
|
||||
const directory = await mkdtemp(path.join(os.tmpdir(), "chaos-timeline-"));
|
||||
directories.push(directory);
|
||||
const file = path.join(directory, "timeline.jsonl");
|
||||
const timeline = new Timeline(file);
|
||||
const echo = vi.spyOn(console, "info").mockImplementation(() => undefined);
|
||||
const previousQuiet = process.env.RESTART_CHAOS_QUIET;
|
||||
delete process.env.RESTART_CHAOS_QUIET;
|
||||
try {
|
||||
timeline.add("before");
|
||||
expect(echo).toHaveBeenCalledTimes(1);
|
||||
process.stdout.emit("error", Object.assign(new Error("write EPIPE"), { code: "EPIPE" }));
|
||||
expect(timelineEchoBroken()).toBe(true);
|
||||
for (let index = 0; index < 5; index += 1) timeline.add("after", { index });
|
||||
expect(echo).toHaveBeenCalledTimes(1);
|
||||
const kinds = (await readFile(file, "utf8")).trim().split("\n").map(line => (JSON.parse(line) as { kind: string }).kind);
|
||||
expect(kinds).toEqual(["before", "after", "harness_stdout_lost", "after", "after", "after", "after"]);
|
||||
expect(timeline.entries.find(entry => entry.kind === "harness_stdout_lost")).toMatchObject({ error: "EPIPE write EPIPE" });
|
||||
} finally {
|
||||
if (previousQuiet === undefined) delete process.env.RESTART_CHAOS_QUIET; else process.env.RESTART_CHAOS_QUIET = previousQuiet;
|
||||
}
|
||||
});
|
||||
});
|
||||
@@ -2,17 +2,57 @@ import { appendFileSync } from "node:fs";
|
||||
|
||||
export interface TimelineEntry { at: string; t: number; kind: string; [key: string]: unknown }
|
||||
|
||||
/**
|
||||
* Console echo stops for good once stdout fails (for example EPIPE after the
|
||||
* parent that read our output exited). Otherwise every echo raises another
|
||||
* error, the uncaught-exception handler records it with another echo, and the
|
||||
* timeline grows without bound.
|
||||
*/
|
||||
let echoBroken = false;
|
||||
let echoBrokenBy: string | null = null;
|
||||
function markEchoBroken(error: unknown) {
|
||||
if (echoBroken) return;
|
||||
echoBroken = true;
|
||||
echoBrokenBy = error instanceof Error ? `${(error as NodeJS.ErrnoException).code ?? ""} ${error.message}`.trim() : String(error);
|
||||
}
|
||||
process.stdout.on("error", markEchoBroken);
|
||||
|
||||
export function isBrokenStdoutError(error: unknown): boolean {
|
||||
const code = (error as NodeJS.ErrnoException | null)?.code;
|
||||
return code === "EPIPE" || code === "ERR_STREAM_DESTROYED" || code === "ERR_STREAM_WRITE_AFTER_END";
|
||||
}
|
||||
|
||||
/** Append-only action timeline. Every supervisor and launcher action lands here. */
|
||||
export class Timeline {
|
||||
readonly entries: TimelineEntry[] = [];
|
||||
private stdoutLossRecorded = false;
|
||||
constructor(private readonly path: string | null, readonly origin = Date.now()) {}
|
||||
|
||||
add(kind: string, data: Record<string, unknown> = {}): TimelineEntry {
|
||||
private record(kind: string, data: Record<string, unknown>): TimelineEntry {
|
||||
const now = Date.now();
|
||||
const entry: TimelineEntry = { ...data, at: new Date(now).toISOString(), t: now - this.origin, kind };
|
||||
this.entries.push(entry);
|
||||
if (this.path) appendFileSync(this.path, `${JSON.stringify(entry)}\n`, { mode: 0o600 });
|
||||
if (process.env.RESTART_CHAOS_QUIET !== "1") console.info(`[chaos +${Math.round(entry.t / 1000)}s] ${kind} ${JSON.stringify(data)}`);
|
||||
return entry;
|
||||
}
|
||||
|
||||
add(kind: string, data: Record<string, unknown> = {}): TimelineEntry {
|
||||
const entry = this.record(kind, data);
|
||||
if (process.env.RESTART_CHAOS_QUIET !== "1" && !echoBroken && process.stdout.writable) {
|
||||
try { console.info(`[chaos +${Math.round(entry.t / 1000)}s] ${kind} ${JSON.stringify(data)}`); }
|
||||
catch (error) { if (isBrokenStdoutError(error)) markEchoBroken(error); else throw error; }
|
||||
}
|
||||
// Say once, in the file only, why the console went quiet.
|
||||
if (echoBroken && !this.stdoutLossRecorded) {
|
||||
this.stdoutLossRecorded = true;
|
||||
this.record("harness_stdout_lost", { error: echoBrokenBy });
|
||||
}
|
||||
return entry;
|
||||
}
|
||||
}
|
||||
|
||||
/** For a broken-stdout error that surfaced elsewhere (for example as an uncaught exception). */
|
||||
export function markTimelineEchoBroken(error: unknown): void { markEchoBroken(error); }
|
||||
|
||||
/** Test hook: whether console echo has been disabled by a broken stdout. */
|
||||
export function timelineEchoBroken(): boolean { return echoBroken; }
|
||||
Reference in new issue
Block a user