mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-11-14 00:26:28 +01:00
test(restart-chaos): K15 long hold, T1 mid-tool workload, sandbox Runner log capture
Co-Authored-By: Claude <noreply@anthropic.com>
This commit is contained in:
1 parent
a1ec05a1a4
commit
4bb4b7dd33
11 files changed
+356
-12
No files matched your search
@@ -337,6 +337,45 @@ Limits:
|
||||
- Combine K15 with `--adapters opencode` and `--daytona-reuse-lease` or
|
||||
`--daytona-warm` to match staging's workload mix.
|
||||
|
||||
### Long mid-tool redeploy (`--k15-hold-seconds`, T1, Runner logs)
|
||||
|
||||
```sh
|
||||
node cli/node_modules/tsx/dist/cli.mjs tests/restart-chaos/main.ts --env daytona --daytona-image $IMG --daytona-cpu 3 \
|
||||
--adapters opencode --workloads T1 --faults K15 --k15-hold-seconds 240-480 --concurrency 2 --tasks 4 --seed 9310
|
||||
```
|
||||
|
||||
A staging deploy usually lands mid-turn and keeps the server down for 4–7
|
||||
minutes. In staging class R, recovery then found the remote Runner gone
|
||||
(`runner_remote_process_identity_unavailable`).
|
||||
|
||||
- **`--k15-hold-seconds <n>` or `<min>-<max>`** (0–600 s) seeds each K15's
|
||||
outage. The server stops with SIGTERM and stays down for the hold. Then the
|
||||
next deploy generation starts. Without the option, a K15 restarts at once.
|
||||
The range is drawn only for K15 cells, so other seeds keep their plans.
|
||||
- **T1** (opt-in workload) has the agent run one shell command in the
|
||||
foreground for about 100 s (50 ticks of 2 s). It then saves `brief`, whose
|
||||
first line is `TICKS-<nonce>=50`. Its fault window (35–80 s after launch)
|
||||
lands while the tool runs in the sandbox. The window stays short of provider
|
||||
shell-tool timeouts.
|
||||
- **Runner evidence:** on a Daytona K15 wave, the harness captures every
|
||||
started sandbox of the wave three times:
|
||||
- right after the server stopped (`<fault>-stopped`);
|
||||
- after the hold, just before the next deploy starts (`<fault>-before_start`);
|
||||
- at wave end (`wave-end`).
|
||||
|
||||
Each capture is written to `results/<wave>/daytona-runner/<label>/<sandbox>.txt`,
|
||||
with an `index.json`, and to `runner_logs_captured` in the timeline.
|
||||
`daytona-runner-logs.ts` runs one fixed, read-only probe through the Daytona
|
||||
toolbox. It reads:
|
||||
- the Runner and provider processes (`ps`);
|
||||
- memory, disk, and OOM lines from `dmesg`;
|
||||
- the tail of every `runnerd.stderr.log`, `runner-process.identity` and
|
||||
`runner-state.json`.
|
||||
|
||||
The probe never stops, starts or deletes a sandbox. It only touches sandboxes
|
||||
that carry the wave's company and environment labels. Known secret values are
|
||||
redacted. A failed capture is recorded and does not fail the wave.
|
||||
|
||||
## Absolute symlink in the workspace (F1)
|
||||
|
||||
```sh
|
||||
@@ -1061,7 +1100,7 @@ re-arms the task's own triggered faults instead of using their offsets.
|
||||
| `grader.ts` | Pure R1–R6 grading over the samples, plus the universal checks. |
|
||||
| `universal.ts`, `universal-audit.ts` | U1–U4 on every task, and their audit over saved waves. |
|
||||
| `contention.ts` | L1 workload, its accounting oracle and the `--db-pressure` writers. |
|
||||
| `workloads.ts` | A1 brief document, B1 python CLI with tests, B5 long bench, C1 comment while running, M1 delegation, G1 approval across a restart, H1 budget hard stop across a restart, F1 absolute symlink kept in the workspace, with their T-oracles. |
|
||||
| `workloads.ts` | A1 brief document, B1 python CLI with tests, B5 long bench, C1 comment while running, M1 delegation, G1 approval across a restart, H1 budget hard stop across a restart, F1 absolute symlink kept in the workspace, T1 long shell tool, with their T-oracles. |
|
||||
| `journeys.ts`, `journey-driver.ts`, `journey-oauth-app.ts`, `journey-matrix.ts` | Q2 and Q3 definitions and oracles, the board's side of each, Q3's loopback OAuth/MCP app, and the `--matrix` planner. |
|
||||
| `evidence.ts`, `ledger.ts` | Evidence bundle for each failure and the JSONL ledger plus `SUMMARY.md`. |
|
||||
| `daytona-image.ts` | Docker-free extraction of the image's runnerd and provider pack, cached per digest, and the controller/image content-ID check. |
|
||||
@@ -1071,7 +1110,8 @@ re-arms the task's own triggered faults instead of using their offsets.
|
||||
| `time-faults.ts`, `time-faults-config.ts` | TM1–TM3: process freezing, database aging with recorded rows, and the time-corrected API the grader reads through. |
|
||||
| `multi-server.ts` | MS1–MS3: the second server's steps, the seeded holds, and the cross-server invariant over the wave database. |
|
||||
| `repeated-restarts.ts` | RR1–RR3: seeded restart steps, `--rr-gap-seconds`, and the stop-and-replace loop the supervisor runs. |
|
||||
| `redeploy.ts`, `redeploy-preload.mjs` | K15: per-generation emulated host name and Railway deployment identity, and the preload that applies the host name. |
|
||||
| `redeploy.ts`, `redeploy-preload.mjs` | K15: per-generation emulated host name and Railway deployment identity, the preload that applies the host name, and `--k15-hold-seconds`. |
|
||||
| `daytona-runner-logs.ts` | K15 on Daytona: read-only capture of each wave sandbox's Runner stderr log, identity, state and process, memory and OOM evidence. |
|
||||
| `daytona-sweep.ts` | Daytona R6: read-only reconciliation of this wave's labelled sandboxes with leases; cleanup only through Paperclip. |
|
||||
|
||||
## Output (gitignored)
|
||||
|
||||
@@ -5,6 +5,7 @@ import { applyJourneyOptions } from "./journey-matrix.js";
|
||||
import { takesJourneyTriggers } from "./journeys.js";
|
||||
import { STORAGE_FAULT_KINDS, type StorageFaultKind } from "./storage-chaos.js";
|
||||
import { isMultiServerFault, validateMultiServerOptions } from "./multi-server.js";
|
||||
import { parseK15HoldSeconds } from "./redeploy.js";
|
||||
import { parseTimeFaultOptions } from "./time-faults-config.js";
|
||||
import { parseStorageTrigger } from "./storage-trigger.js";
|
||||
import { parseNativeTrigger, parseNativeTriggerOutage } from "./native-trigger.js";
|
||||
@@ -132,13 +133,14 @@ export function parseCommand(argv: readonly string[], now = Date.now()): ParsedC
|
||||
"provider-fault-restart-after-seconds": { type: "string" },
|
||||
"rr-gap-seconds": { type: "string" },
|
||||
"rr-stop-on": { type: "string" },
|
||||
"k15-hold-seconds": { 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", "daytona-warm", "daytona-inherit", "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", "native-trigger", "native-trigger-outage", "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) {
|
||||
for (const key of ["env", "adapters", "workloads", "faults", "triggers", "concurrency", "tasks", "seed", "daytona-image", "daytona-cpu", "daytona-reuse-lease", "daytona-warm", "daytona-inherit", "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", "native-trigger", "native-trigger-outage", "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", "k15-hold-seconds"] 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,
|
||||
@@ -179,7 +181,7 @@ export function parseCommand(argv: readonly string[], now = Date.now()): ParsedC
|
||||
env,
|
||||
adapters,
|
||||
// The governance scenarios (G1, H1), the journeys (Q1–Q3) and the contention run (L1) are opt-in: H1 needs a wave of its own.
|
||||
workloads: list<WorkloadId>(values.workloads, workloadChoices, "workloads", workloadChoices.filter(id => id !== "G1" && id !== "H1" && id !== "R1" && id !== "S1" && id !== "L1" && id !== "F1"
|
||||
workloads: list<WorkloadId>(values.workloads, workloadChoices, "workloads", workloadChoices.filter(id => id !== "G1" && id !== "H1" && id !== "R1" && id !== "S1" && id !== "L1" && id !== "F1" && id !== "T1"
|
||||
&& !takesJourneyTriggers(id) && (id !== "M1" || adapters.length >= 2))),
|
||||
// A crash-point wave schedules no fault; K1 is the restart its self-kill gets.
|
||||
faults: allFaults.filter((fault): fault is FaultKind => !isProviderFault(fault)),
|
||||
@@ -242,6 +244,7 @@ export function parseCommand(argv: readonly string[], now = Date.now()): ParsedC
|
||||
}
|
||||
Object.assign(options, parseTimeFaultOptions(options, values["time-age-hours"]));
|
||||
Object.assign(options, parseRepeatedRestartOptions(options, values["rr-gap-seconds"], values["rr-stop-on"]));
|
||||
Object.assign(options, parseK15HoldSeconds(options, values["k15-hold-seconds"]));
|
||||
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");
|
||||
|
||||
@@ -0,0 +1,95 @@
|
||||
/**
|
||||
* Sandbox-side evidence for `--env daytona`: what the remote Runner was doing when the control plane went
|
||||
* away and when it came back. Staging class R (`runner_remote_process_identity_unavailable`, see
|
||||
* doc/plans/2026-11-11-staging-failures-vs-chaos-coverage.md) found the Runner gone after a 4–7 minute
|
||||
* mid-turn outage; this captures its stderr log, process identity, durable state and the sandbox's
|
||||
* process, memory, disk and OOM evidence so the exit reason is visible in the wave folder.
|
||||
*
|
||||
* Read-only by construction: it lists this wave's sandboxes by their company and environment labels
|
||||
* (the same selection as daytona-sweep.ts) and runs one fixed probe that only reads (`ps`, `tail`, `stat`,
|
||||
* `find`, `free`, `df`, `dmesg`). It never stops, starts, archives or deletes a sandbox, and never runs a
|
||||
* command derived from wave data.
|
||||
*/
|
||||
import { mkdir, writeFile } from "node:fs/promises";
|
||||
import path from "node:path";
|
||||
import { createRemoteFixtureClient } from "../runner-e2e/remote-native-bootstrap.js";
|
||||
import { selectWaveSandboxes, type DaytonaSandboxRow } from "./daytona-sweep.js";
|
||||
import { redactKnownSecrets } from "./evidence.js";
|
||||
|
||||
/** The fixed read-only probe. Every file read is bounded with `tail -c`. */
|
||||
export const RUNNER_LOG_PROBE = [
|
||||
'echo "== observed_at $(date -u +%Y-%m-%dT%H:%M:%SZ)"',
|
||||
'echo "== uptime"; cat /proc/uptime 2>/dev/null',
|
||||
'echo "== runner and provider processes"; ps -eo pid,ppid,sid,etimes,stat,rss,args 2>/dev/null'
|
||||
+ ' | grep -E "paperclip-runner|runnerd|opencode|codex|claude|acpx" | grep -v grep | cut -c1-400',
|
||||
'echo "== memory"; free -m 2>/dev/null',
|
||||
'echo "== disk"; df -h / /tmp 2>/dev/null',
|
||||
'echo "== oom"; dmesg 2>/dev/null | grep -iE "oom|killed process" | tail -n 20',
|
||||
'for f in $(find / -xdev \\( -name runnerd.stderr.log -o -name runner-process.identity -o -name runner-state.json \\) -type f 2>/dev/null | head -n 30); do'
|
||||
+ ' echo "== file $f $(stat -c "%s bytes, modified %y" "$f" 2>/dev/null)"; tail -c 24576 "$f"; echo; done',
|
||||
].join("; ");
|
||||
|
||||
export interface RunnerLogCapture {
|
||||
label: string;
|
||||
observedAt: string;
|
||||
sandboxes: Array<{ id: string; name: string | null; state: string | null; file: string | null; exitCode: number | null; error: string | null }>;
|
||||
error: string | null;
|
||||
}
|
||||
|
||||
interface ProbeSandbox { process: { executeCommand(command: string, cwd?: string, env?: Record<string, string>, timeout?: number): Promise<{ exitCode: number; result: string }> } }
|
||||
interface ProbeClient {
|
||||
list(query: { labels: Record<string, string> }): AsyncIterable<DaytonaSandboxRow>;
|
||||
get(id: string): Promise<ProbeSandbox>;
|
||||
}
|
||||
|
||||
/** A capture label safe as a directory name (fault id and phase). */
|
||||
export function captureDirectoryName(label: string): string {
|
||||
const safe = label.replace(/[^A-Za-z0-9._-]+/g, "-").replace(/^-+|-+$/g, "");
|
||||
if (!safe) throw new Error("Runner log capture needs a non-empty label");
|
||||
return safe.slice(0, 80);
|
||||
}
|
||||
|
||||
/** Only started sandboxes can run the probe; stopped or archived ones are recorded by state alone. */
|
||||
export function probeableSandbox(sandbox: DaytonaSandboxRow): boolean {
|
||||
return String(sandbox.state ?? "").toLowerCase() === "started";
|
||||
}
|
||||
|
||||
/**
|
||||
* Capture every wave sandbox's Runner evidence into `<outDir>/<label>/<sandboxId>.txt` and an index.
|
||||
* Failures are recorded, never thrown: evidence capture must not fail or delay a wave beyond its timeout.
|
||||
*/
|
||||
export async function captureWaveRunnerLogs(input: {
|
||||
apiKey: string; companyId: string; environmentId: string; outDir: string; label: string; secrets: readonly string[];
|
||||
client?: ProbeClient; timeoutSeconds?: number;
|
||||
}): Promise<RunnerLogCapture> {
|
||||
const label = captureDirectoryName(input.label);
|
||||
const capture: RunnerLogCapture = { label, observedAt: new Date().toISOString(), sandboxes: [], error: null };
|
||||
const directory = path.join(input.outDir, label);
|
||||
try {
|
||||
await mkdir(directory, { recursive: true, mode: 0o700 });
|
||||
const client = input.client ?? await createRemoteFixtureClient(input.apiKey) as unknown as ProbeClient;
|
||||
const wave = { companyId: input.companyId, environmentId: input.environmentId };
|
||||
const rows: DaytonaSandboxRow[] = [];
|
||||
for await (const row of client.list({ labels: { "paperclip-company-id": wave.companyId, "paperclip-environment-id": wave.environmentId } })) rows.push(row);
|
||||
for (const row of selectWaveSandboxes(rows, wave)) {
|
||||
const entry: RunnerLogCapture["sandboxes"][number] = { id: row.id, name: row.name ?? null, state: row.state ?? null, file: null, exitCode: null, error: null };
|
||||
capture.sandboxes.push(entry);
|
||||
if (!probeableSandbox(row)) continue;
|
||||
try {
|
||||
const sandbox = await client.get(row.id);
|
||||
const response = await sandbox.process.executeCommand(`sh -c '${RUNNER_LOG_PROBE.replace(/'/g, `'\\''`)}'`, undefined, {}, input.timeoutSeconds ?? 20);
|
||||
entry.exitCode = response.exitCode;
|
||||
entry.file = `${row.id}.txt`;
|
||||
await writeFile(path.join(directory, entry.file), redactKnownSecrets(String(response.result ?? ""), input.secrets), { mode: 0o600 });
|
||||
} catch (error) {
|
||||
entry.error = error instanceof Error ? error.message : String(error);
|
||||
}
|
||||
}
|
||||
} catch (error) {
|
||||
capture.error = error instanceof Error ? error.message : String(error);
|
||||
}
|
||||
try {
|
||||
await writeFile(path.join(directory, "index.json"), `${JSON.stringify(capture, null, 2)}\n`, { mode: 0o600 });
|
||||
} catch { /* the directory itself failed; the returned record still carries the error */ }
|
||||
return capture;
|
||||
}
|
||||
@@ -35,7 +35,7 @@ export type JourneyTrigger = (typeof JOURNEY_TRIGGERS)[number];
|
||||
/** Each workload's own fault boundaries, for the journey × fault matrix. */
|
||||
export const WORKLOAD_TRIGGERS: Record<WorkloadId, readonly TriggerId[]> = {
|
||||
A1: ["time"], B1: ["time"], B5: ["tool"], C1: ["comment", "result"], M1: ["time"], G1: ["approval"],
|
||||
H1: ["paused"], R1: ["time"], S1: ["stop"], L1: ["time"], F1: ["time"], Q1: JOURNEY_TRIGGERS, Q2: JOURNEY_TRIGGERS, Q3: JOURNEY_TRIGGERS,
|
||||
H1: ["paused"], R1: ["time"], S1: ["stop"], L1: ["time"], F1: ["time"], T1: ["time"], Q1: JOURNEY_TRIGGERS, Q2: JOURNEY_TRIGGERS, Q3: JOURNEY_TRIGGERS,
|
||||
};
|
||||
|
||||
/** Q3 reviews must survive a delay longer than the implicit deadline #20340 removed. */
|
||||
|
||||
@@ -0,0 +1,117 @@
|
||||
import { mkdtemp, readFile, readdir } from "node:fs/promises";
|
||||
import os from "node:os";
|
||||
import path from "node:path";
|
||||
import { describe, expect, it, vi } from "vitest";
|
||||
import { parseCommand } from "./config.js";
|
||||
import { RUNNER_LOG_PROBE, captureDirectoryName, captureWaveRunnerLogs, probeableSandbox } from "./daytona-runner-logs.js";
|
||||
import { WORKLOAD_TRIGGERS } from "./journeys.js";
|
||||
import { K15_MAX_HOLD_SECONDS } from "./redeploy.js";
|
||||
import { planStorm, planTasks } from "./scheduler.js";
|
||||
import type { OracleArtifacts } from "./types.js";
|
||||
import { T1_TICKS, t1Command, t1Marker, workloadDefinitions } from "./workloads.js";
|
||||
|
||||
const IMAGE = `ghcr.io/paperclipai/paperclip-daytona-runner@sha256:${"c".repeat(64)}`;
|
||||
const COMPANY = "11111111-1111-4111-8111-111111111111";
|
||||
const ENVIRONMENT = "22222222-2222-4222-8222-222222222222";
|
||||
|
||||
describe("--k15-hold-seconds", () => {
|
||||
it("seeds a K15 outage inside the range, like a staging deploy's 4-7 minutes down", () => {
|
||||
const parsed = parseCommand(["--env", "daytona", "--daytona-image", IMAGE, "--faults", "K15", "--k15-hold-seconds", "240-480",
|
||||
"--adapters", "opencode", "--workloads", "T1", "--tasks", "6", "--seed", "11"]);
|
||||
if (parsed.mode !== "wave") throw new Error("expected a wave");
|
||||
expect(parsed.options.k15HoldMs).toEqual([240_000, 480_000]);
|
||||
const holds = planTasks(parsed.options).map(task => task.holdMs);
|
||||
expect(holds.every(hold => hold >= 240_000 && hold <= 480_000)).toBe(true);
|
||||
const fixed = parseCommand(["--faults", "K15", "--k15-hold-seconds", "300", "--workloads", "A1", "--tasks", "2", "--seed", "11"]);
|
||||
expect(fixed.mode === "wave" && planTasks(fixed.options).map(task => task.holdMs)).toEqual([300_000, 300_000]);
|
||||
});
|
||||
|
||||
it("keeps K15 immediate without the option, and leaves other faults' holds alone", () => {
|
||||
const parsed = parseCommand(["--faults", "K2,K15", "--workloads", "A1", "--tasks", "4", "--seed", "11"]);
|
||||
if (parsed.mode !== "wave") throw new Error("expected a wave");
|
||||
expect(planTasks(parsed.options).every(task => task.holdMs === 0)).toBe(true);
|
||||
const storm = planStorm(5, 20, ["K2", "K15"], undefined, [60_000, 60_000]);
|
||||
expect(storm.faults.every(fault => fault.holdMs === (fault.kind === "K15" ? 60_000 : 0))).toBe(true);
|
||||
});
|
||||
|
||||
it("refuses a range without K15, out of bounds or reversed", () => {
|
||||
expect(() => parseCommand(["--faults", "K2", "--k15-hold-seconds", "300", "--workloads", "A1"])).toThrow(/add K15/);
|
||||
expect(() => parseCommand(["--faults", "K15", "--k15-hold-seconds", `${K15_MAX_HOLD_SECONDS + 1}`, "--workloads", "A1"])).toThrow(/between 0 and 600/);
|
||||
expect(() => parseCommand(["--faults", "K15", "--k15-hold-seconds", "400-300", "--workloads", "A1"])).toThrow(/min not above max/);
|
||||
expect(() => parseCommand(["--faults", "K15", "--k15-hold-seconds", "5m", "--workloads", "A1"])).toThrow(/<seconds> or <min>-<max>/);
|
||||
expect(() => parseCommand(["--replay", "w-1/t01", "--k15-hold-seconds", "300"])).toThrow(/--replay reproduces the saved plan/);
|
||||
});
|
||||
});
|
||||
|
||||
describe("T1: long shell tool in the agent's workspace", () => {
|
||||
const t1 = workloadDefinitions.T1;
|
||||
const NONCE = "0badc0de";
|
||||
const done = (brief: string): OracleArtifacts => ({ issueStatus: "done", documents: { brief }, agentComments: [], files: {}, commands: {},
|
||||
workspacePath: null }) as OracleArtifacts;
|
||||
|
||||
it("runs about 100 s in the foreground and fires its fault while the tool runs", () => {
|
||||
expect(T1_TICKS * 2).toBe(100);
|
||||
expect(t1.description(NONCE)).toContain(t1Command(NONCE));
|
||||
expect(t1.description(NONCE)).toContain("in the foreground");
|
||||
expect(t1.fireWindowMs[0]).toBeGreaterThanOrEqual(30_000);
|
||||
expect(t1.fireWindowMs[1]).toBeLessThanOrEqual(90_000);
|
||||
expect(WORKLOAD_TRIGGERS.T1).toEqual(["time"]);
|
||||
const defaults = parseCommand(["--seed", "1"]);
|
||||
expect(defaults.mode === "wave" && defaults.options.workloads).not.toContain("T1");
|
||||
});
|
||||
|
||||
it("passes only when the finished tool's count is reported and the task is done", () => {
|
||||
expect(t1.grade(NONCE, done(`${t1Marker(NONCE)}=${T1_TICKS}\nmore`)).verdict).toBe("pass");
|
||||
expect(t1.grade(NONCE, done(`${t1Marker(NONCE)}=49`)).verdict).toBe("fail");
|
||||
expect(t1.grade(NONCE, done("")).verdict).toBe("fail");
|
||||
expect(t1.grade(NONCE, { ...done(`${t1Marker(NONCE)}=${T1_TICKS}`), issueStatus: "blocked" }).verdict).toBe("fail");
|
||||
});
|
||||
});
|
||||
|
||||
describe("Daytona Runner log capture", () => {
|
||||
it("probes only by reading", () => {
|
||||
expect(RUNNER_LOG_PROBE).toContain("runnerd.stderr.log");
|
||||
expect(RUNNER_LOG_PROBE).toContain("runner-process.identity");
|
||||
expect(RUNNER_LOG_PROBE).toContain("runner-state.json");
|
||||
expect(RUNNER_LOG_PROBE).not.toMatch(/\b(rm|kill|mv|cp|chmod|chown|truncate|tee|mkdir|touch)\b/);
|
||||
// The only redirections are stderr to /dev/null.
|
||||
expect(RUNNER_LOG_PROBE.replace(/2>\/dev\/null/g, "")).not.toMatch(/>/);
|
||||
expect(captureDirectoryName("f01 before_start")).toBe("f01-before_start");
|
||||
expect(() => captureDirectoryName("///")).toThrow(/non-empty/);
|
||||
expect(probeableSandbox({ id: "a", state: "started" })).toBe(true);
|
||||
expect(probeableSandbox({ id: "a", state: "stopped" })).toBe(false);
|
||||
});
|
||||
|
||||
it("captures this wave's started sandboxes only, redacts secrets, and records failures instead of throwing", async () => {
|
||||
const outDir = await mkdtemp(path.join(os.tmpdir(), "runner-logs-"));
|
||||
const labels = { "paperclip-company-id": COMPANY, "paperclip-environment-id": ENVIRONMENT };
|
||||
const executeCommand = vi.fn(async () => ({ exitCode: 0, result: "== runnerd.stderr.log\nruntime token sk-live-secret exited signal=9\n" }));
|
||||
const get = vi.fn(async (id: string) => {
|
||||
if (id === "broken") throw new Error("toolbox unavailable");
|
||||
return { process: { executeCommand } };
|
||||
});
|
||||
const client = {
|
||||
async *list() {
|
||||
yield { id: "live", state: "started", labels };
|
||||
yield { id: "stopped", state: "stopped", labels };
|
||||
yield { id: "broken", state: "started", labels };
|
||||
yield { id: "other-wave", state: "started", labels: { ...labels, "paperclip-environment-id": "33333333-3333-4333-8333-333333333333" } };
|
||||
},
|
||||
get,
|
||||
};
|
||||
const capture = await captureWaveRunnerLogs({ apiKey: "unused", companyId: COMPANY, environmentId: ENVIRONMENT, outDir,
|
||||
label: "f01-stopped", secrets: ["sk-live-secret"], client });
|
||||
expect(capture.error).toBeNull();
|
||||
expect(capture.sandboxes.map(sandbox => [sandbox.id, sandbox.file, sandbox.error])).toEqual([
|
||||
["live", "live.txt", null], ["stopped", null, null], ["broken", null, "toolbox unavailable"]]);
|
||||
expect(get).not.toHaveBeenCalledWith("other-wave");
|
||||
expect(get).not.toHaveBeenCalledWith("stopped");
|
||||
const text = await readFile(path.join(outDir, "f01-stopped", "live.txt"), "utf8");
|
||||
expect(text).toContain("exited signal=9");
|
||||
expect(text).not.toContain("sk-live-secret");
|
||||
expect((await readdir(path.join(outDir, "f01-stopped"))).sort()).toEqual(["index.json", "live.txt"]);
|
||||
const failed = await captureWaveRunnerLogs({ apiKey: "unused", companyId: COMPANY, environmentId: ENVIRONMENT, outDir, label: "f02-stopped",
|
||||
secrets: [], client: { async *list() { throw new Error("list failed"); }, get } });
|
||||
expect(failed.error).toBe("list failed");
|
||||
});
|
||||
});
|
||||
@@ -39,6 +39,7 @@ import { TaskObserver, childSpeedTasksInTurn } from "./observer.js";
|
||||
import { closeJourneyApps } from "./journey-driver.js";
|
||||
import { matrixMayLaunch, planMatrixWave } from "./journey-matrix.js";
|
||||
import { redeployWave } from "./redeploy.js";
|
||||
import { captureWaveRunnerLogs } from "./daytona-runner-logs.js";
|
||||
import { StormRun, TASK_FAULT_LOG, observedFaultSchedule, planWave, replayOnCurrentBuild, replayRecordFor, replayWave, type TaskFaultLog } from "./scheduler.js";
|
||||
import { chaosLifecycleOverrides, seedChaosLab } from "./seed.js";
|
||||
import { ChaosSupervisor } from "./supervisor.js";
|
||||
@@ -239,6 +240,14 @@ async function main(): Promise<number> {
|
||||
}
|
||||
let sweeper: DaytonaWaveSweeper | null = null;
|
||||
let sandboxSweep: DaytonaSweepResult | null = null;
|
||||
let runnerLogTarget: { companyId: string; environmentId: string } | null = null;
|
||||
const captureRunnerLogs = async (label: string) => {
|
||||
if (!runnerLogTarget) return;
|
||||
const capture = await captureWaveRunnerLogs({ apiKey: process.env.DAYTONA_API_KEY!, ...runnerLogTarget,
|
||||
outDir: path.join(waveDir, "daytona-runner"), label, secrets: knownSecretValues() });
|
||||
timeline.add("runner_logs_captured", { label: capture.label, error: capture.error,
|
||||
sandboxes: capture.sandboxes.map(sandbox => `${sandbox.id}:${sandbox.state ?? "?"}${sandbox.file ? ":probed" : ""}${sandbox.error ? `:error=${sandbox.error.slice(0, 120)}` : ""}`) });
|
||||
};
|
||||
let interrupted = false;
|
||||
const onSignal = (signal: NodeJS.Signals) => { if (!interrupted) { interrupted = true; timeline.add("harness_interrupted", { signal }); } };
|
||||
process.on("SIGINT", onSignal); process.on("SIGTERM", onSignal);
|
||||
@@ -342,6 +351,11 @@ async function main(): Promise<number> {
|
||||
adapterConfigOverrides: chaosLifecycleOverrides(plan.options.lifecycle),
|
||||
onEnvironment: owned => {
|
||||
sweeper = new DaytonaWaveSweeper({ apiKey: process.env.DAYTONA_API_KEY!, companyId: owned.companyId, environmentId: owned.environmentId, api });
|
||||
// K15 on Daytona: the remote Runner's logs, identity and state while the controller is down (daytona-runner-logs.ts).
|
||||
if (redeployWave(plan)) {
|
||||
runnerLogTarget = { companyId: owned.companyId, environmentId: owned.environmentId };
|
||||
supervisor.redeployEvidence = (faultId, phase) => captureRunnerLogs(`${faultId}-${phase}`);
|
||||
}
|
||||
} });
|
||||
spendTarget = { api, companyId: lab.companyId };
|
||||
// --db-pressure: contend with the wave's running run rows from outside the server (contention.ts).
|
||||
@@ -626,6 +640,7 @@ async function main(): Promise<number> {
|
||||
if (quietFor < QUIET_BEFORE_SWEEP_MS) await delay(QUIET_BEFORE_SWEEP_MS - quietFor);
|
||||
await recordWaveSpend();
|
||||
timeline.add("wave_sweep", {});
|
||||
if (runnerLogTarget) await captureRunnerLogs("wave-end");
|
||||
if (sweeper) {
|
||||
sandboxSweep = await (sweeper as DaytonaWaveSweeper).sweep();
|
||||
timeline.add("daytona_sweep", { ...sandboxSweep });
|
||||
|
||||
@@ -25,6 +25,32 @@ export function redeployWave(plan: Pick<WavePlan, "options" | "tasks" | "storm">
|
||||
|| plan.tasks.some(task => task.fault === "K15" || (task.replayFaults?.some(fault => fault.kind === "K15") ?? false));
|
||||
}
|
||||
|
||||
/** `--k15-hold-seconds` upper bound: the controller-outage cap (tests/runner-e2e/controller-outage.ts). */
|
||||
export const K15_MAX_HOLD_SECONDS = 600;
|
||||
|
||||
/**
|
||||
* `--k15-hold-seconds <n>` or `<min>-<max>` (0–600 s): how long a K15 keeps the server down between its SIGTERM
|
||||
* and the next deploy's start. Staging deploys were down 4–7 minutes, so the remote Runner has to survive the
|
||||
* gap mid-turn. Without it a K15 restarts at once.
|
||||
*/
|
||||
export function parseK15HoldSeconds(options: { faults: readonly string[] }, raw: string | undefined): { k15HoldMs?: [number, number] } {
|
||||
if (raw === undefined) return {};
|
||||
if (!options.faults.includes("K15")) throw new Error("--k15-hold-seconds sets the K15 outage; add K15 to --faults");
|
||||
const match = /^([0-9]+)(?:-([0-9]+))?$/.exec(raw.trim());
|
||||
if (!match) throw new Error("--k15-hold-seconds takes <seconds> or <min>-<max> seconds");
|
||||
const min = Number(match[1]);
|
||||
const max = match[2] === undefined ? min : Number(match[2]);
|
||||
if (max > K15_MAX_HOLD_SECONDS || max < min) {
|
||||
throw new Error(`--k15-hold-seconds must be between 0 and ${K15_MAX_HOLD_SECONDS} seconds, min not above max`);
|
||||
}
|
||||
return { k15HoldMs: [min * 1000, max * 1000] };
|
||||
}
|
||||
|
||||
/** The seeded hold of one K15. Draws only when a range is set, so existing seeds keep their plans. */
|
||||
export function k15HoldMs(range: readonly [number, number] | undefined, int: (min: number, max: number) => number): number {
|
||||
return range ? int(range[0], range[1]) : 0;
|
||||
}
|
||||
|
||||
/** The preload that applies the emulated host name before the server loads. */
|
||||
export const REDEPLOY_PRELOAD_PATH = fileURLToPath(new URL("./redeploy-preload.mjs", import.meta.url));
|
||||
/** Read by the preload: the host name `os.hostname()` returns in the server process. */
|
||||
|
||||
@@ -4,6 +4,7 @@ import { workloadDefinitions } from "./workloads.js";
|
||||
import { isTimeFault, timeFaultHoldMs } from "./time-faults-config.js";
|
||||
import { isMultiServerFault, multiServerHoldMs } from "./multi-server.js";
|
||||
import { isRepeatedRestartFault, planRestartSteps, type RestartStep } from "./repeated-restarts.js";
|
||||
import { k15HoldMs } from "./redeploy.js";
|
||||
import { K4_MIN_HOLD_MS, type AdapterId, type FaultKind, type ScheduledFault, type StormFault, type StormPlan, type TaskFaultKind, type TaskPlan, type TriggerId, type WavePlan, type WaveOptions, type WorkloadId } from "./types.js";
|
||||
import type { ReplayRef } from "./config.js";
|
||||
|
||||
@@ -95,7 +96,7 @@ function pinnedFireAfterMs(faultAfterMs: number | undefined, drawn: number): num
|
||||
return faultAfterMs ?? drawn;
|
||||
}
|
||||
|
||||
export function planTasks(options: Pick<WaveOptions, "seed" | "tasks" | "workloads" | "adapters" | "faults" | "triggers" | "stormMinutes" | "k4HoldMaxMs" | "faultAfterMs" | "providerFaults" | "rrGapMs">): TaskPlan[] {
|
||||
export function planTasks(options: Pick<WaveOptions, "seed" | "tasks" | "workloads" | "adapters" | "faults" | "triggers" | "stormMinutes" | "k4HoldMaxMs" | "k15HoldMs" | "faultAfterMs" | "providerFaults" | "rrGapMs">): TaskPlan[] {
|
||||
const rng = createRng(options.seed);
|
||||
const triggers = options.triggers?.length ? options.triggers : ["time" as const];
|
||||
for (const trigger of triggers) {
|
||||
@@ -127,7 +128,8 @@ export function planTasks(options: Pick<WaveOptions, "seed" | "tasks" | "workloa
|
||||
...(trigger === "time" ? {} : { trigger, triggerDelayMs: rng.int(...TRIGGER_DELAY_RANGE_MS[trigger]) }),
|
||||
fireAfterMs: cell.fault === "K13" ? 0 : pinnedFireAfterMs(options.faultAfterMs, rng.int(fireMin, fireMax)),
|
||||
holdMs: cell.fault === "K4" ? rng.int(...k4HoldRange(options.k4HoldMaxMs)) : isTimeFault(cell.fault) ? timeFaultHoldMs(cell.fault, rng.int)
|
||||
: isMultiServerFault(cell.fault) ? multiServerHoldMs(cell.fault, rng.int) : 0,
|
||||
: isMultiServerFault(cell.fault) ? multiServerHoldMs(cell.fault, rng.int)
|
||||
: cell.fault === "K15" ? k15HoldMs(options.k15HoldMs, rng.int) : 0,
|
||||
// Drawn only for RR tasks, so the plans of existing seeds do not change.
|
||||
...(isRepeatedRestartFault(cell.fault) ? { restartSteps: planRestartSteps(cell.fault, rng.int, options.rrGapMs) } : {}),
|
||||
followUpAfterMs: definition.followUpWindowMs ? rng.int(definition.followUpWindowMs[0], definition.followUpWindowMs[1]) : null,
|
||||
@@ -151,7 +153,7 @@ function replayMasks(source: readonly string[] | undefined, added: readonly stri
|
||||
export function planWave(waveId: string, options: WaveOptions, createdAt = new Date()): WavePlan {
|
||||
return { schema: "paperclip.restart-chaos.wave-plan/v1", waveId, seed: options.seed,
|
||||
createdAt: createdAt.toISOString(), options, tasks: withProviderFaultRules(planTasks(options), options),
|
||||
...(options.stormMinutes ? { storm: planStorm(options.seed, options.stormMinutes, options.faults, options.k4HoldMaxMs) } : {}) };
|
||||
...(options.stormMinutes ? { storm: planStorm(options.seed, options.stormMinutes, options.faults, options.k4HoldMaxMs, options.k15HoldMs) } : {}) };
|
||||
}
|
||||
|
||||
/** K13: the gap between one storm fault settling and the next one firing. */
|
||||
@@ -162,7 +164,8 @@ export const STORM_GAP_RANGE_MS: readonly [number, number] = [120_000, 240_000];
|
||||
* after a 2-4 minute gap, long enough to fill `minutes`. It uses its own RNG
|
||||
* stream so adding a storm does not change the task cells for a seed.
|
||||
*/
|
||||
export function planStorm(seed: number, minutes: number, faults: readonly FaultKind[], k4HoldMaxMs?: number): StormPlan {
|
||||
export function planStorm(seed: number, minutes: number, faults: readonly FaultKind[], k4HoldMaxMs?: number,
|
||||
k15HoldRangeMs?: readonly [number, number]): StormPlan {
|
||||
if (!faults.length) throw new Error("A K13 storm needs at least one fault kind");
|
||||
const rng = createRng((seed ^ 0x6b313353) >>> 0);
|
||||
const durationMs = minutes * 60_000;
|
||||
@@ -170,7 +173,8 @@ export function planStorm(seed: number, minutes: number, faults: readonly FaultK
|
||||
for (let planned = 0; planned < durationMs;) {
|
||||
const gapMs = rng.int(...STORM_GAP_RANGE_MS);
|
||||
const kind = faults[rng.int(0, faults.length - 1)]!;
|
||||
sequence.push({ kind, gapMs, holdMs: kind === "K4" ? rng.int(...k4HoldRange(k4HoldMaxMs)) : 0 });
|
||||
sequence.push({ kind, gapMs, holdMs: kind === "K4" ? rng.int(...k4HoldRange(k4HoldMaxMs))
|
||||
: kind === "K15" ? k15HoldMs(k15HoldRangeMs, rng.int) : 0 });
|
||||
planned += gapMs;
|
||||
}
|
||||
return { durationMs, faults: sequence };
|
||||
|
||||
@@ -157,6 +157,11 @@ export class ChaosSupervisor {
|
||||
private extraEnvironment: Record<string, string> = {};
|
||||
/** K15 waves: the wave id the emulated deploy identities derive from, and the generation serving now. */
|
||||
private redeploy: { waveId: string; identity: RedeployIdentity } | null = null;
|
||||
/**
|
||||
* K15 evidence hook (main.ts sets it on Daytona waves): runs right after the server stopped and again just
|
||||
* before the next deploy starts, while the server is down. It must not throw.
|
||||
*/
|
||||
redeployEvidence: ((faultId: string, phase: "stopped" | "before_start") => Promise<void>) | null = null;
|
||||
/** Wave secrets, kept across a K14 switch as an in-place upgrade keeps its configuration. */
|
||||
private readonly secrets = { PAPERCLIP_AGENT_JWT_SECRET: secret(), PAPERCLIP_DECISION_SIGNING_SECRET: secret(),
|
||||
PAPERCLIP_TOOL_ACTION_SIGNING_SECRET: secret(), BETTER_AUTH_SECRET: secret() };
|
||||
@@ -485,6 +490,8 @@ export class ChaosSupervisor {
|
||||
waitForUnhealthy: async () => { await this.waitForHealthToStop(); receipt.stoppedAt = Date.now(); this.timeline.add("fault_server_down", { faultId: receipt.faultId }); },
|
||||
// K1/K2/K4 keep the controller runtime cache; K11 will discard it.
|
||||
discardCache: async () => {},
|
||||
// K15: capture the sandbox side as soon as the controller is gone (redeployEvidence).
|
||||
...(kind === "K15" && this.redeployEvidence ? { afterStopped: async () => { await this.redeployEvidence?.(receipt.faultId, "stopped"); } } : {}),
|
||||
// TM3: the server is down; every database timestamp moves back by the age before the replacement starts.
|
||||
...(kind === "TM3" ? { afterStopped: async () => {
|
||||
const timeFault: TimeFaultRecord = { kind };
|
||||
@@ -496,7 +503,11 @@ export class ChaosSupervisor {
|
||||
// K14: the replacement is the current build, on the same database and instance directory.
|
||||
if (kind === "K14") receipt.upgrade = await this.switchToCurrentBuild(receipt.faultId);
|
||||
// K15: the replacement is the next deploy: a new process space and deployment id on the same volume.
|
||||
if (kind === "K15") receipt.redeploy = this.advanceDeploy(receipt.faultId);
|
||||
if (kind === "K15") {
|
||||
// After the hold, before the next deploy starts: what its recovery will find in the sandboxes.
|
||||
await this.redeployEvidence?.(receipt.faultId, "before_start");
|
||||
receipt.redeploy = this.advanceDeploy(receipt.faultId);
|
||||
}
|
||||
this.timeline.add("fault_restarting", { faultId: receipt.faultId });
|
||||
return this.spawnServer();
|
||||
},
|
||||
|
||||
@@ -28,8 +28,9 @@ export type TaskFaultKind = FaultKind | "K13" | "K0" | ProviderFaultKind;
|
||||
* Q1: a saved question (question-handoff.ts). Q2, Q3: journeys.ts.
|
||||
* L1: high-output, high-accounting run for database contention (contention.ts).
|
||||
* F1: an absolute symlink pointing out of the repository workspace, kept at rest (staging save-back class F).
|
||||
* T1: a 100-second shell tool in the agent's workspace, so a fault lands while the remote Runner runs a tool (staging class R).
|
||||
*/
|
||||
export const WORKLOAD_IDS = ["A1", "B1", "B5", "C1", "M1", "G1", "H1", "R1", "S1", "Q1", "L1", "Q2", "Q3", "F1"] as const;
|
||||
export const WORKLOAD_IDS = ["A1", "B1", "B5", "C1", "M1", "G1", "H1", "R1", "S1", "Q1", "L1", "Q2", "Q3", "F1", "T1"] as const;
|
||||
export type WorkloadId = (typeof WORKLOAD_IDS)[number];
|
||||
|
||||
export const ADAPTER_IDS = ["codex", "claude", "opencode"] as const;
|
||||
@@ -68,6 +69,8 @@ export interface WaveOptions {
|
||||
daytonaInherit?: boolean;
|
||||
/** `--k4-hold-max-seconds`: upper end of the seeded K4 hold (default 300 s, cap 600 s). */
|
||||
k4HoldMaxMs?: number;
|
||||
/** `--k15-hold-seconds`: the seeded K15 outage range (redeploy.ts); absent restarts at once. */
|
||||
k15HoldMs?: [number, number];
|
||||
faultAfterMs?: number;
|
||||
/**
|
||||
* Known product signatures this wave deliberately masks. "rc06" keeps the
|
||||
|
||||
@@ -43,6 +43,11 @@ const continueMarker = (nonce: string) => `CONTINUE-${nonce}`;
|
||||
const notesFile = (nonce: string) => `NOTES-${nonce}.md`;
|
||||
/** F1: the absolute symlink the agent creates and keeps in the repository root. */
|
||||
export const f1LinkName = (nonce: string) => `hosts-link-${nonce}`;
|
||||
/** T1: ticks of the long tool (2 s each) and the line the agent reports after it finished. */
|
||||
export const T1_TICKS = 50;
|
||||
export const t1Marker = (nonce: string) => `TICKS-${nonce}`;
|
||||
export const t1Command = (nonce: string) =>
|
||||
`i=0; while [ $i -lt ${T1_TICKS} ]; do i=$((i+1)); echo tick-$i; sleep 2; done > ticks-${nonce}.txt; wc -l < ticks-${nonce}.txt`;
|
||||
/** F1: an `ls -l` line for that link: a symlink (`l` mode) naming the link and its absolute target. */
|
||||
export const f1LinkListing = (nonce: string) => new RegExp(`^l\\S*\\s.*\\s${f1LinkName(nonce)} -> /etc/hosts$`);
|
||||
const benchFile = (nonce: string) => `bench-result-${nonce}.txt`;
|
||||
@@ -354,6 +359,31 @@ export const workloadDefinitions: Record<WorkloadId, WorkloadDefinition> = {
|
||||
]);
|
||||
},
|
||||
},
|
||||
T1: {
|
||||
// Staging class R (`runner_remote_process_identity_unavailable`): the controller went away mid-turn while a
|
||||
// tool ran in the sandbox, and recovery 4–7 minutes later found the remote Runner gone. T1 keeps one shell
|
||||
// tool running for about 100 s (short of provider shell-tool timeouts), so a fault in its window lands mid-tool.
|
||||
id: "T1",
|
||||
label: "Long shell tool in the agent's workspace",
|
||||
usesRepository: false,
|
||||
fireWindowMs: [35_000, 80_000],
|
||||
budgetMs: 15 * 60_000,
|
||||
title: nonce => `Chaos T1 long tool ${nonce}`,
|
||||
description: nonce => [
|
||||
"Run this exact shell command in your working directory as one tool call, in the foreground, and wait for it to finish",
|
||||
`(about 100 seconds; do not run it in the background): \`${t1Command(nonce)}\``,
|
||||
`Then save this issue's document with key \`brief\` (title "Brief"). Its first line is \`${t1Marker(nonce)}=<the number the command printed>\`.`,
|
||||
"Do not create other files or tasks. When the document is saved, mark this task done.",
|
||||
].join("\n"),
|
||||
collect: { documents: ["brief"], files: () => [], commands: [] },
|
||||
grade(nonce, artifacts) {
|
||||
const first = (artifacts.documents.brief ?? "").split(/\r?\n/).map(line => line.trim()).find(Boolean) ?? "";
|
||||
return result([
|
||||
statusCheck(artifacts),
|
||||
{ name: "tool_finished", ok: first === `${t1Marker(nonce)}=${T1_TICKS}`, detail: JSON.stringify(first.slice(0, 120)) },
|
||||
]);
|
||||
},
|
||||
},
|
||||
R1: {
|
||||
id: "R1",
|
||||
label: "Code change in a Paperclip clone",
|
||||
|
||||
Reference in new issue
Block a user