mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-11-11 05:11:49 +01:00
test(restart-chaos): add --rr-stop-on recovering so RR follow-up stops land inside recovery (#20511)
## Thinking Path > - Paperclip is the open source app people use to manage AI agents for work. > - The restart chaos harness (`tests/restart-chaos/`) tests if agent tasks survive control-plane restarts. > - #20480 added repeated restarts (RR1–RR3): a K1, then more restarts while the replacement recovers. > - In the first four live waves, no follow-up stop landed inside recovery. Every stop saw `/api/ready` report `ready`. > - The saved receipts show why. `/api/ready` reports `recovering` only 15–80 ms before `/api/health` answers, and `ready` 0.25–0.5 s after it. A gap measured from health, even 1 s, always lands after recovery. > - This pull request adds `--rr-stop-on recovering`. Each follow-up stop fires on the first `recovering` status, polled from the replacement's spawn. > - The benefit is that RR waves now test a restart that interrupts recovery itself. ## Linked Issues or Issue Description Refs #20480 **What is the problem?** RR follow-up stops wait a gap from the replacement's health. On a local host recovery ends about 0.3 s after health, so no stop in four waves (14 tasks, 18 follow-up stops) landed inside recovery. **What is the solution?** Add `--rr-stop-on recovering`. It replaces the gap: the harness polls `/api/ready` every 50 ms from spawn and stops the replacement on its first `recovering` status. This is the phase poll that K6 already uses. **Why is it needed?** The deploy loops of 2026-11-08 and 2026-11-09 restarted the server while it recovered interrupted runs. The harness must reach that window to test it. ## What Changed - `repeated-restarts.ts`: `--rr-stop-on recovering` is parsed by `parseRepeatedRestartOptions`. It needs an RR fault and does not combine with `--rr-gap-seconds` or `--replay`. `runRepeatedRestarts` takes `stopOn`: with it, no gap is slept, each stop waits on the new `waitForStopPhase` hook, and only the last replacement is waited on to health. - `supervisor.ts`: `waitForStopPhase` reuses the K6 phase poll (`waitForCrashLoopPhase`, 50 ms). The record carries `stopOn`. - `types.ts`, `config.ts`, `main.ts`: the `rrStopOn` option, its flag, and one line to pass it to the supervisor. - The evidence shows each stop's `/api/ready` status (`phaseAtStop`). With `stopOn`, `gapMs` is null, and the earlier entries have no `healthyAt`. - README: the option and the measured timings. ## Verification - `pnpm exec vitest run --config tests/restart-chaos/vitest.config.ts`: 35 files, 438 tests pass. New tests cover option parsing, stops on the first `recovering` with no sleep, health waits only on the last replacement, a `ready` stop when recovery was too short to see, an exit before a status, and a missing watcher. - `node scripts/typecheck-test-projects.mjs tests/restart-chaos` passes. - A live wave from this branch (`--workloads A1,B5,C1 --faults RR1,RR3 --rr-stop-on recovering`, codex, 4 tasks) follows; its results go to a comment. ## Risks - Harness-only change; no product code changes. RR waves without the flag are unchanged. - A stop on `recovering` lands before the replacement answers health. This is the K6 behavior, and the server log shows it. A replacement that never reports a status fails the fault after the 5-minute ready timeout, as K6 does. > 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 - Anthropic Claude, model ID `claude-opus-5-5`, used through Claude Code with tool use (shell, file edits) and 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 <noreply@anthropic.com>
This commit is contained in:
1 parent
a09093a5c5
commit
1a89fca1ce
7 files changed
+191
-19
No files matched your search
@@ -826,8 +826,16 @@ moment the replacement reports healthy, it stops that replacement and starts ano
|
||||
|
||||
The gaps are seeded per task (`restartSteps` in `plan.json`), and drawn only for RR tasks, so the plans
|
||||
of existing seeds do not change. `--rr-gap-seconds <n>` or `<min>-<max>` (1–300) replaces every RR
|
||||
gap: for example `--rr-gap-seconds 5` for a stop that always lands in recovery, or `30-60` for a slow
|
||||
deploy loop. RR faults do not combine with `--storm-minutes`, whose faults carry no planned steps.
|
||||
gap: for example `--rr-gap-seconds 5` for a short deploy-loop gap, or `30-60` for a slow
|
||||
deploy loop. To stop inside recovery, use `--rr-stop-on recovering` (below). RR faults do not combine with `--storm-minutes`, whose faults carry no planned steps.
|
||||
|
||||
`--rr-stop-on recovering` replaces the gap: each follow-up stop fires on the first `/api/ready` poll
|
||||
(every 50 ms, from the replacement's spawn) that reports `recovering`, the K6 phase poll. Use it to
|
||||
land the stops inside recovery. In the first live waves `/api/ready` reported `recovering` only
|
||||
15–80 ms before `/api/health` answered, and `ready` 0.25–0.5 s after it, so every gap from health
|
||||
(even 1 s) landed after recovery. A replacement that goes straight to `ready` is stopped there and
|
||||
records `ready`. The receipt records `stopOn`, and each follow-up entry has `gapMs: null`; only the last
|
||||
replacement is waited on to health, so the earlier entries have no `healthyAt`. The first replacement (of the K1 kill) is also watched from its spawn, not from its health.
|
||||
|
||||
**Evidence.** Each stop and replacement (the first kill included) is recorded with its signal, planned
|
||||
gap, stopped PID, the `/api/ready` status just before the stop (`recovering` means it landed inside
|
||||
|
||||
@@ -120,13 +120,14 @@ export function parseCommand(argv: readonly string[], now = Date.now()): ParsedC
|
||||
"provider-fault-restart": { type: "string" },
|
||||
"provider-fault-restart-after-seconds": { type: "string" },
|
||||
"rr-gap-seconds": { type: "string" },
|
||||
"rr-stop-on": { type: "string" },
|
||||
},
|
||||
});
|
||||
const keep = values.keep === true;
|
||||
const pollMs = integer(values["poll-ms"], "poll-ms", 3_000, 2_000, 5_000);
|
||||
const budgetCents = integer(values["budget-cents"], "budget-cents", 3_000, 1, 100_000);
|
||||
if (values.replay !== undefined) {
|
||||
for (const key of ["env", "adapters", "workloads", "faults", "triggers", "concurrency", "tasks", "seed", "daytona-image", "daytona-cpu", "daytona-reuse-lease", "storm-minutes", "lifecycle", "k4-hold-max-seconds", "crash-point", "crash-point-hold-ms", "upgrade-from", "workspace-repo", "storage", "storage-faults", "storage-fault-seconds", "storage-trigger", "fault-after-seconds", "provider-fault-message", "provider-fault-delays", "db-pressure", "matrix", "server-from", "time-age-hours", "provider-fault-restart", "provider-fault-restart-after-seconds", "rr-gap-seconds"] as const) {
|
||||
for (const key of ["env", "adapters", "workloads", "faults", "triggers", "concurrency", "tasks", "seed", "daytona-image", "daytona-cpu", "daytona-reuse-lease", "storm-minutes", "lifecycle", "k4-hold-max-seconds", "crash-point", "crash-point-hold-ms", "upgrade-from", "workspace-repo", "storage", "storage-faults", "storage-fault-seconds", "storage-trigger", "fault-after-seconds", "provider-fault-message", "provider-fault-delays", "db-pressure", "matrix", "server-from", "time-age-hours", "provider-fault-restart", "provider-fault-restart-after-seconds", "rr-gap-seconds", "rr-stop-on"] as const) {
|
||||
if (values[key] !== undefined) throw new Error(`--replay reproduces the saved plan; do not combine it with --${key}`);
|
||||
}
|
||||
return { mode: "replay", ref: parseReplayRef(values.replay), keep,
|
||||
@@ -224,7 +225,7 @@ export function parseCommand(argv: readonly string[], now = Date.now()): ParsedC
|
||||
throw new Error("--provider-fault-message, --provider-fault-delays and --provider-fault-restart need a provider fault (PV1, PV2 or PV3) in --faults");
|
||||
}
|
||||
Object.assign(options, parseTimeFaultOptions(options, values["time-age-hours"]));
|
||||
Object.assign(options, parseRepeatedRestartOptions(options, values["rr-gap-seconds"]));
|
||||
Object.assign(options, parseRepeatedRestartOptions(options, values["rr-gap-seconds"], values["rr-stop-on"]));
|
||||
const upgradeFrom = values["upgrade-from"];
|
||||
if (options.faults.includes("K14") !== (upgradeFrom !== undefined)) {
|
||||
throw new Error("K14 (upgrade mid-run) and --upgrade-from <older checkout> go together: pass both or neither");
|
||||
|
||||
@@ -321,6 +321,7 @@ async function main(): Promise<number> {
|
||||
rules: plan.tasks.flatMap(task => task.providerFault ? [`${task.taskId}:${describeProviderFault(task.providerFault)}`] : []) });
|
||||
}
|
||||
if (plan.options.timeAgeMs) supervisor.timeAgeMs = plan.options.timeAgeMs;
|
||||
if (plan.options.rrStopOn) supervisor.rrStopOn = plan.options.rrStopOn;
|
||||
await supervisor.start(serverEnvironment);
|
||||
// TM2/TM3 age the database; the observer and grader read run times back at their real times.
|
||||
const api: ChaosApi = new TimeShiftedApi(supervisor.baseUrl, supervisor.agingShifts);
|
||||
|
||||
@@ -4,7 +4,7 @@ import { crossingFaults } from "./grader.js";
|
||||
import { planMatrixWave } from "./journey-matrix.js";
|
||||
import { createRng, observedFaultSchedule, planTasks, taskFaultSchedule } from "./scheduler.js";
|
||||
import {
|
||||
RR3_KILL_RANGE, RR_GAP_RANGE_MS, newRepeatedRestartRecord, planRestartSteps, recordFirstRestart, runRepeatedRestarts, type RepeatedRestartRecord, type RestartStep,
|
||||
RR3_KILL_RANGE, RR_GAP_RANGE_MS, newRepeatedRestartRecord, planRestartSteps, recordFirstRestart, runRepeatedRestarts, stopPhaseWatcher, type RepeatedRestartRecord, type RestartStep,
|
||||
} from "./repeated-restarts.js";
|
||||
import type { FaultReceipt, TaskRecord } from "./types.js";
|
||||
|
||||
@@ -27,6 +27,17 @@ describe("repeated restart options", () => {
|
||||
expect(() => parseCommand(["--faults", "RR1", "--rr-gap-seconds", "5s", "--workloads", "A1"])).toThrow(/<seconds> or <min>-<max>/);
|
||||
});
|
||||
|
||||
it("takes --rr-stop-on recovering instead of a gap, only with an RR fault", () => {
|
||||
const parsed = parseCommand(["--faults", "RR1,RR3", "--rr-stop-on", "recovering", "--workloads", "A1", "--seed", "1"]);
|
||||
expect(parsed.mode === "wave" && parsed.options.rrStopOn).toBe("recovering");
|
||||
expect(parsed.mode === "wave" && parsed.options.rrGapMs).toBeUndefined();
|
||||
expect(() => parseCommand(["--faults", "K1", "--rr-stop-on", "recovering", "--workloads", "A1"])).toThrow(/add RR1, RR2 or RR3/);
|
||||
expect(() => parseCommand(["--faults", "RR1", "--rr-stop-on", "ready", "--workloads", "A1"])).toThrow(/must be recovering/);
|
||||
expect(() => parseCommand(["--faults", "RR1", "--rr-stop-on", "recovering", "--rr-gap-seconds", "1", "--workloads", "A1"]))
|
||||
.toThrow(/do not combine it with --rr-gap-seconds/);
|
||||
expect(() => parseCommand(["--replay", "w-20261110T000000-s1/t01", "--rr-stop-on", "recovering"])).toThrow(/--rr-stop-on/);
|
||||
});
|
||||
|
||||
it("refuses a storm, whose faults carry no planned restarts", () => {
|
||||
expect(() => parseCommand(["--faults", "RR1", "--storm-minutes", "10"])).toThrow(/storm/);
|
||||
});
|
||||
@@ -151,6 +162,19 @@ describe("the record built before the first kill", () => {
|
||||
expect(build(undefined).planned).toEqual(planRestartSteps("RR3", createRng(9).int));
|
||||
});
|
||||
|
||||
it("never gives the first replacement the last one's health time", () => {
|
||||
const watched = { ...build(planned), stopOn: "recovering" as const };
|
||||
recordFirstRestart(watched, { stoppedAt: 5_400, restartedAt: 5_400, healthyAt: null }, 77);
|
||||
watched.restarts.push({ ...watched.restarts[0]!, index: 1, healthyAt: 40_000 });
|
||||
// The evidence write after the sequence sees the receipt's health: the last replacement's.
|
||||
recordFirstRestart(watched, { stoppedAt: 5_400, restartedAt: 5_400, healthyAt: 40_000 }, null);
|
||||
expect(watched.restarts[0]!.healthyAt).toBeNull();
|
||||
const gapped = build(planned);
|
||||
gapped.restarts.push({ ...gapped.restarts[0]!, index: 1, healthyAt: 40_000 });
|
||||
recordFirstRestart(gapped, { stoppedAt: 5_400, restartedAt: 5_400, healthyAt: 40_000 }, null);
|
||||
expect(gapped.restarts[0]!.healthyAt).toBeNull();
|
||||
});
|
||||
|
||||
it("does not overwrite first-kill times already recorded", () => {
|
||||
const rr = build(planned);
|
||||
recordFirstRestart(rr, { stoppedAt: 5_400, restartedAt: 5_400, healthyAt: 13_000 }, 77);
|
||||
@@ -217,6 +241,76 @@ describe("runRepeatedRestarts", () => {
|
||||
});
|
||||
});
|
||||
|
||||
describe("runRepeatedRestarts with --rr-stop-on recovering", () => {
|
||||
it("stops each replacement on its first recovering status, with no gap, and waits for health only on the last", async () => {
|
||||
const steps: RestartStep[] = [{ signal: "SIGKILL", gapMs: 12_000 }, { signal: "SIGKILL", gapMs: 25_000 }];
|
||||
const fake = fakeHooks();
|
||||
const watched: number[] = [];
|
||||
let healthChecks = 0;
|
||||
const hooks = { ...fake.hooks,
|
||||
waitForStopPhase: async (server: { pid: number }, target: "recovering") => { watched.push(server.pid); await fake.hooks.sleep(150); return target; },
|
||||
waitHealthy: async () => { healthChecks += 1; return fake.hooks.waitHealthy(); } };
|
||||
const rr = record("RR3", steps);
|
||||
const result = await runRepeatedRestarts({ record: rr, steps, server: { pid: 100 }, healthyAt: fake.now(), hooks, stopOn: "recovering" });
|
||||
expect(watched).toEqual([100, 200]);
|
||||
expect(fake.log).toEqual(["sleep 150", "stop 100 SIGKILL", "start 200", "sleep 150", "stop 200 SIGKILL", "start 201"]);
|
||||
expect(healthChecks).toBe(1);
|
||||
expect(rr.restarts.map(entry => [entry.phaseAtStop, entry.gapMs, entry.replacementPid])).toEqual([["recovering", null, 200], ["recovering", null, 201]]);
|
||||
expect(rr.restarts[0]!.healthyAt).toBeNull();
|
||||
expect(rr.restarts[1]!.healthyAt).toBe(result.healthyAt);
|
||||
});
|
||||
|
||||
it("uses the status the first replacement fired on from spawn, without waiting for its health", async () => {
|
||||
const steps: RestartStep[] = [{ signal: "SIGKILL", gapMs: 12_000 }, { signal: "SIGKILL", gapMs: 25_000 }];
|
||||
const fake = fakeHooks();
|
||||
const first = { pid: 100 };
|
||||
const watched: number[] = [];
|
||||
const watch = async (server: { pid: number }) => { watched.push(server.pid); return "recovering"; };
|
||||
const rr = record("RR3", steps);
|
||||
// The first kill's restart watched pid 100 from spawn and saw `recovering`; health was never awaited.
|
||||
await runRepeatedRestarts({ record: rr, steps, server: first, healthyAt: fake.now(), stopOn: "recovering",
|
||||
hooks: { ...fake.hooks, waitForStopPhase: stopPhaseWatcher(first, "recovering", watch) } });
|
||||
expect(watched).toEqual([200]);
|
||||
expect(rr.restarts.map(entry => entry.phaseAtStop)).toEqual(["recovering", "recovering"]);
|
||||
expect(fake.log).toEqual(["stop 100 SIGKILL", "start 200", "stop 200 SIGKILL", "start 201"]);
|
||||
});
|
||||
|
||||
it("uses the first status once, and watches the first server when none was recorded", async () => {
|
||||
const first = { pid: 100 };
|
||||
const watch = async () => "ready";
|
||||
const cached = stopPhaseWatcher(first, "recovering", watch);
|
||||
expect(await cached(first, "recovering")).toBe("recovering");
|
||||
expect(await cached(first, "recovering")).toBe("ready");
|
||||
expect(await stopPhaseWatcher(first, undefined, watch)(first, "recovering")).toBe("ready");
|
||||
});
|
||||
|
||||
it("records `ready` when recovery was too short to see", async () => {
|
||||
const steps: RestartStep[] = [{ signal: "SIGTERM", gapMs: 5_000 }];
|
||||
const fake = fakeHooks();
|
||||
const rr = record("RR2", steps);
|
||||
await runRepeatedRestarts({ record: rr, steps, server: { pid: 100 }, healthyAt: fake.now(), stopOn: "recovering",
|
||||
hooks: { ...fake.hooks, waitForStopPhase: async () => "ready" } });
|
||||
expect(rr.restarts[0]!.phaseAtStop).toBe("ready");
|
||||
expect(fake.log).toEqual(["stop 100 SIGTERM", "start 200"]);
|
||||
});
|
||||
|
||||
it("fails when the replacement exits before it reports a status", async () => {
|
||||
const steps: RestartStep[] = [{ signal: "SIGKILL", gapMs: 1_000 }];
|
||||
const fake = fakeHooks();
|
||||
await expect(runRepeatedRestarts({ record: record("RR1", steps), steps, server: { pid: 100 }, healthyAt: fake.now(), stopOn: "recovering",
|
||||
hooks: { ...fake.hooks, waitForStopPhase: async () => { throw new Error("Paperclip server exited during the crash loop"); } } }))
|
||||
.rejects.toThrow(/exited/);
|
||||
expect(fake.log).toEqual([]);
|
||||
});
|
||||
|
||||
it("refuses to run without a phase watcher", async () => {
|
||||
const steps: RestartStep[] = [{ signal: "SIGKILL", gapMs: 1_000 }];
|
||||
const fake = fakeHooks();
|
||||
await expect(runRepeatedRestarts({ record: record("RR1", steps), steps, server: { pid: 100 }, healthyAt: fake.now(), stopOn: "recovering",
|
||||
hooks: fake.hooks })).rejects.toThrow(/phase watcher/);
|
||||
});
|
||||
});
|
||||
|
||||
describe("grading a repeated restart as one fault", () => {
|
||||
it("crosses a task with one fault window from the first kill to the last replacement's ready", () => {
|
||||
const receipt = {
|
||||
|
||||
@@ -49,14 +49,29 @@ export function planRestartSteps(kind: RepeatedRestartKind, int: (min: number, m
|
||||
const MIN_GAP_SECONDS = 1;
|
||||
const MAX_GAP_SECONDS = 300;
|
||||
|
||||
/** `--rr-gap-seconds <n>` or `<min>-<max>` (1–300 s): the gap from a replacement's health to the next stop. */
|
||||
/** `--rr-stop-on recovering`: stop each replacement on its first `recovering` status instead of after a gap. */
|
||||
export const RR_STOP_ON = ["recovering"] as const;
|
||||
export type RepeatedRestartStopOn = (typeof RR_STOP_ON)[number];
|
||||
|
||||
/**
|
||||
* `--rr-gap-seconds <n>` or `<min>-<max>` (1–300 s): the gap from a replacement's health to the next stop.
|
||||
* `--rr-stop-on recovering`: no gap; each follow-up stop fires on the first `/api/ready` poll (every 50 ms
|
||||
* from spawn) that reports `recovering`. On a local host `ready` follows health by about 0.3 s, so any
|
||||
* gap from health lands after recovery.
|
||||
*/
|
||||
export function parseRepeatedRestartOptions(options: Pick<WaveOptions, "faults" | "stormMinutes">,
|
||||
rawGapSeconds: string | undefined): Pick<WaveOptions, "rrGapMs"> {
|
||||
rawGapSeconds: string | undefined, rawStopOn?: string): Pick<WaveOptions, "rrGapMs" | "rrStopOn"> {
|
||||
const repeated = options.faults.some(isRepeatedRestartFault);
|
||||
if (rawGapSeconds !== undefined && !repeated) throw new Error("--rr-gap-seconds sets the RR restart gap; add RR1, RR2 or RR3 to --faults");
|
||||
if (rawStopOn !== undefined && !repeated) throw new Error("--rr-stop-on sets when RR restarts fire; add RR1, RR2 or RR3 to --faults");
|
||||
if (!repeated) return {};
|
||||
// A storm fault carries no planned restart steps, and a storm already restarts again and again.
|
||||
if (options.stormMinutes) throw new Error("Repeated restarts (RR*) are planned per task; do not combine them with --storm-minutes");
|
||||
if (rawStopOn !== undefined) {
|
||||
if (!(RR_STOP_ON as readonly string[]).includes(rawStopOn)) throw new Error(`--rr-stop-on must be ${RR_STOP_ON.join(" or ")}`);
|
||||
if (rawGapSeconds !== undefined) throw new Error("--rr-stop-on replaces the RR gap; do not combine it with --rr-gap-seconds");
|
||||
return { rrStopOn: rawStopOn as RepeatedRestartStopOn };
|
||||
}
|
||||
if (rawGapSeconds === undefined) return {};
|
||||
const match = /^([0-9]+)(?:-([0-9]+))?$/.exec(rawGapSeconds.trim());
|
||||
if (!match) throw new Error("--rr-gap-seconds takes <seconds> or <min>-<max> seconds");
|
||||
@@ -86,6 +101,10 @@ export interface RepeatedRestartEntry {
|
||||
|
||||
export interface RepeatedRestartRecord {
|
||||
kind: RepeatedRestartKind;
|
||||
/** `--rr-stop-on`: the follow-up stops fired on this status instead of after `planned[].gapMs`. */
|
||||
stopOn?: RepeatedRestartStopOn;
|
||||
/** `stopOn`: the status the first replacement reported when the watch from its spawn fired. */
|
||||
firstStopPhase?: string;
|
||||
planned: RestartStep[];
|
||||
restarts: RepeatedRestartEntry[];
|
||||
/** `<wave>/repeated-restarts/<faultId>.json`. */
|
||||
@@ -111,10 +130,27 @@ export function recordFirstRestart(record: RepeatedRestartRecord, receipt: { sto
|
||||
const first = record.restarts[0]!;
|
||||
first.stoppedAt ??= receipt.stoppedAt;
|
||||
first.restartedAt ??= receipt.restartedAt;
|
||||
first.healthyAt ??= receipt.healthyAt;
|
||||
// The receipt's health is the first replacement's only before any follow-up stop; later it is the last
|
||||
// replacement's. With `stopOn` the first replacement is never waited on to health at all.
|
||||
if (!record.stopOn && record.restarts.length === 1) first.healthyAt ??= receipt.healthyAt;
|
||||
first.replacementPid ??= replacementPid;
|
||||
}
|
||||
|
||||
/**
|
||||
* `stopOn`: the stop-status watcher for `runRepeatedRestarts`. The first replacement was already watched
|
||||
* from its spawn (inside the first kill's restart) and fired with `firstPhase`; it is used once, for that
|
||||
* server, so the first follow-up stop does not wait for health and miss a short recovery. Every later
|
||||
* replacement is watched with `watch`.
|
||||
*/
|
||||
export function stopPhaseWatcher<P>(first: P, firstPhase: string | null | undefined,
|
||||
watch: (server: P, target: RepeatedRestartStopOn) => Promise<string>): (server: P, target: RepeatedRestartStopOn) => Promise<string> {
|
||||
let cached = firstPhase ?? null;
|
||||
return async (server, target) => {
|
||||
if (server === first && cached !== null) { const phase = cached; cached = null; return phase; }
|
||||
return watch(server, target);
|
||||
};
|
||||
}
|
||||
|
||||
export interface RepeatedRestartHooks<P> {
|
||||
now(): number;
|
||||
sleep(ms: number): Promise<void>;
|
||||
@@ -128,6 +164,11 @@ export interface RepeatedRestartHooks<P> {
|
||||
start(): Promise<P>;
|
||||
/** Resolves with the time the replacement reported healthy. */
|
||||
waitHealthy(server: P): Promise<number>;
|
||||
/**
|
||||
* `stopOn`: poll `/api/ready` from the replacement's spawn until it reports `recovering` (or already `ready`,
|
||||
* when recovery was too short to see), and resolve with that status. Rejects if the server exits first.
|
||||
*/
|
||||
waitForStopPhase?(server: P, target: RepeatedRestartStopOn): Promise<string>;
|
||||
onEntry?(entry: RepeatedRestartEntry, stage: "stopping" | "healthy"): void;
|
||||
}
|
||||
|
||||
@@ -142,19 +183,24 @@ export async function runRepeatedRestarts<P>(input: {
|
||||
server: P;
|
||||
healthyAt: number;
|
||||
hooks: RepeatedRestartHooks<P>;
|
||||
/** `--rr-stop-on`: fire each follow-up stop on this status, polled from spawn, instead of after the gap. */
|
||||
stopOn?: RepeatedRestartStopOn;
|
||||
}): Promise<{ server: P; healthyAt: number }> {
|
||||
const { record, steps, hooks } = input;
|
||||
const { record, steps, hooks, stopOn } = input;
|
||||
if (stopOn && !hooks.waitForStopPhase) throw new Error("--rr-stop-on needs a phase watcher");
|
||||
let server = input.server;
|
||||
let healthyAt = input.healthyAt;
|
||||
for (const step of steps) {
|
||||
for (const [stepIndex, step] of steps.entries()) {
|
||||
const index = record.restarts.length;
|
||||
const wait = healthyAt + step.gapMs - hooks.now();
|
||||
if (wait > 0) await hooks.sleep(wait);
|
||||
if (!stopOn) {
|
||||
const wait = healthyAt + step.gapMs - hooks.now();
|
||||
if (wait > 0) await hooks.sleep(wait);
|
||||
}
|
||||
if (hooks.cancelled()) throw new Error(`Harness shutdown interrupted repeated restart ${index}`);
|
||||
const exited = hooks.exitStatus(server);
|
||||
if (exited) throw new Error(`Paperclip server exited on its own before repeated restart ${index} (code=${exited.code} signal=${exited.signal})`);
|
||||
const phaseAtStop = await hooks.readPhase();
|
||||
const entry: RepeatedRestartEntry = { index, signal: step.signal, gapMs: step.gapMs, pid: hooks.pidOf(server), phaseAtStop,
|
||||
const phaseAtStop = stopOn ? await hooks.waitForStopPhase!(server, stopOn) : await hooks.readPhase();
|
||||
const entry: RepeatedRestartEntry = { index, signal: step.signal, gapMs: stopOn ? null : step.gapMs, pid: hooks.pidOf(server), phaseAtStop,
|
||||
stopAt: hooks.now(), stoppedAt: null, restartedAt: null, replacementPid: null, healthyAt: null };
|
||||
record.restarts.push(entry);
|
||||
hooks.onEntry?.(entry, "stopping");
|
||||
@@ -164,6 +210,9 @@ export async function runRepeatedRestarts<P>(input: {
|
||||
entry.restartedAt = hooks.now();
|
||||
server = await hooks.start();
|
||||
entry.replacementPid = hooks.pidOf(server);
|
||||
// `stopOn`: a replacement that is stopped again is watched from spawn, before it is healthy
|
||||
// (`recovering` shows just before health). Only the last one is waited on to health.
|
||||
if (stopOn && stepIndex < steps.length - 1) continue;
|
||||
healthyAt = await hooks.waitHealthy(server);
|
||||
entry.healthyAt = healthyAt;
|
||||
hooks.onEntry?.(entry, "healthy");
|
||||
|
||||
@@ -35,7 +35,7 @@ import { runnerE2ETypeScriptProcessArgs } from "../runner-e2e/web-server-command
|
||||
import type { MatrixExecution } from "../runner-e2e/types.js";
|
||||
import { DEFAULT_TIME_AGE_MS, ProcessFreezer, ageWaveDatabase, databaseUrlFromConfig, runFreezeFault, type AgingShift, type TimeFaultRecord } from "./time-faults.js";
|
||||
import type { Timeline } from "./timeline.js";
|
||||
import { isRepeatedRestartFault, newRepeatedRestartRecord, recordFirstRestart, runRepeatedRestarts, type RepeatedRestartKind,
|
||||
import { isRepeatedRestartFault, newRepeatedRestartRecord, recordFirstRestart, runRepeatedRestarts, stopPhaseWatcher, type RepeatedRestartKind, type RepeatedRestartStopOn,
|
||||
type RepeatedRestartRecord, type RestartStep } from "./repeated-restarts.js";
|
||||
import type { FaultKind, FaultReceipt, TriggerId } from "./types.js";
|
||||
|
||||
@@ -138,6 +138,8 @@ export class ChaosSupervisor {
|
||||
crashPointHoldMs = 0;
|
||||
/** TM2/TM3: how far each aging fault shifts the wave's database back. */
|
||||
timeAgeMs = DEFAULT_TIME_AGE_MS;
|
||||
/** RR1–RR3 (`--rr-stop-on`): stop each replacement on this `/api/ready` status instead of after its gap. */
|
||||
rrStopOn: RepeatedRestartStopOn | null = null;
|
||||
/** Every aging shift so far, in order; the grader's API reads times through them (time-faults.ts). */
|
||||
readonly agingShifts: AgingShift[] = [];
|
||||
private readonly createdAt = Date.now();
|
||||
@@ -460,7 +462,15 @@ export class ChaosSupervisor {
|
||||
this.timeline.add("fault_restarting", { faultId: receipt.faultId });
|
||||
return this.spawnServer();
|
||||
},
|
||||
waitForReady: async replacement => { receipt.healthyAt = await this.waitForHealth(replacement, receipt.phases); },
|
||||
waitForReady: async replacement => {
|
||||
// RR with `--rr-stop-on`: watch the first replacement from spawn; waiting for health first would let a
|
||||
// short recovery pass between two 250 ms health polls. Only the last replacement is waited on to health.
|
||||
if (receipt.repeatedRestart?.stopOn) {
|
||||
receipt.repeatedRestart.firstStopPhase = await this.waitForCrashLoopPhase(replacement, receipt.repeatedRestart.stopOn, receipt.phases);
|
||||
return;
|
||||
}
|
||||
receipt.healthyAt = await this.waitForHealth(replacement, receipt.phases);
|
||||
},
|
||||
cancelled: () => this.shuttingDown,
|
||||
record: async progress => { outage = progress; },
|
||||
});
|
||||
@@ -542,9 +552,10 @@ export class ChaosSupervisor {
|
||||
/** RR1–RR3: the planned steps and the first kill (as K1), recorded before that kill. */
|
||||
private repeatedRestartRecord(kind: RepeatedRestartKind, receipt: FaultReceipt, planned: readonly RestartStep[] | undefined,
|
||||
firstPid: number | null): RepeatedRestartRecord {
|
||||
return newRepeatedRestartRecord({ kind, planned, firstPid, startedAt: receipt.startedAt,
|
||||
const record = newRepeatedRestartRecord({ kind, planned, firstPid, startedAt: receipt.startedAt,
|
||||
evidencePath: path.join(path.dirname(this.paths.serverLogPath), "repeated-restarts", `${receipt.faultId}.json`),
|
||||
int: (min, max) => min + Math.floor(Math.random() * (max - min + 1)) });
|
||||
return this.rrStopOn ? { ...record, stopOn: this.rrStopOn } : record;
|
||||
}
|
||||
|
||||
/**
|
||||
@@ -554,8 +565,12 @@ export class ChaosSupervisor {
|
||||
private async repeatedRestarts(record: RepeatedRestartRecord, receipt: FaultReceipt): Promise<number> {
|
||||
const first = this.child;
|
||||
recordFirstRestart(record, receipt, first?.pid ?? null);
|
||||
if (!first || receipt.healthyAt === null) throw new Error(`${record.kind} has no healthy replacement after its first kill`);
|
||||
const result = await runRepeatedRestarts({ record, steps: record.planned, server: first, healthyAt: receipt.healthyAt, hooks: {
|
||||
if (!first || (receipt.healthyAt === null && !record.stopOn)) throw new Error(`${record.kind} has no healthy replacement after its first kill`);
|
||||
// `--rr-stop-on`: the first replacement was already watched from spawn to its stop status (`firstStopPhase`).
|
||||
const waitForStopPhase = stopPhaseWatcher(first, record.firstStopPhase,
|
||||
(server: ChildProcess, target: RepeatedRestartStopOn) => this.waitForCrashLoopPhase(server, target, receipt.phases));
|
||||
const result = await runRepeatedRestarts({ record, steps: record.planned, server: first, healthyAt: receipt.healthyAt ?? Date.now(),
|
||||
...(record.stopOn ? { stopOn: record.stopOn } : {}), hooks: {
|
||||
now: () => Date.now(),
|
||||
sleep: ms => delay(ms),
|
||||
cancelled: () => this.shuttingDown,
|
||||
@@ -570,6 +585,8 @@ export class ChaosSupervisor {
|
||||
},
|
||||
start: () => this.spawnServer(),
|
||||
waitHealthy: server => this.waitForHealth(server, receipt.phases),
|
||||
// The K6 phase poll (50 ms): fires on `recovering`, or on `ready` when recovery was too short to see.
|
||||
waitForStopPhase,
|
||||
onEntry: (entry, stage) => {
|
||||
if (stage === "stopping") {
|
||||
this.timeline.add("repeated_restart_stop", { faultId: receipt.faultId, index: entry.index, signal: entry.signal, gapMs: entry.gapMs,
|
||||
|
||||
@@ -117,6 +117,8 @@ export interface WaveOptions {
|
||||
providerFaultRestartAfterMs?: number;
|
||||
/** RR1–RR3: the gap from a replacement's health to the next stop (`--rr-gap-seconds`); absent keeps each kind's default. */
|
||||
rrGapMs?: [number, number];
|
||||
/** RR1–RR3 (`--rr-stop-on recovering`): stop each replacement on its first `recovering` status instead of after a gap. */
|
||||
rrStopOn?: "recovering";
|
||||
}
|
||||
|
||||
export interface StormFault {
|
||||
|
||||
Reference in new issue
Block a user