diff --git a/tests/restart-chaos/main.ts b/tests/restart-chaos/main.ts index 8ade9bbfe8b..7cac90e6614 100644 --- a/tests/restart-chaos/main.ts +++ b/tests/restart-chaos/main.ts @@ -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 { 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; diff --git a/tests/restart-chaos/timeline.test.ts b/tests/restart-chaos/timeline.test.ts new file mode 100644 index 00000000000..45d15912e91 --- /dev/null +++ b/tests/restart-chaos/timeline.test.ts @@ -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; + } + }); +}); diff --git a/tests/restart-chaos/timeline.ts b/tests/restart-chaos/timeline.ts index 6bc75368189..3324bef18b9 100644 --- a/tests/restart-chaos/timeline.ts +++ b/tests/restart-chaos/timeline.ts @@ -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 = {}): TimelineEntry { + private record(kind: string, data: Record): 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 = {}): 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; }