mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-11-13 07:12:00 +01:00
test(restart-chaos): long mid-tool K15 outages, Runner evidence, and TM1 stalls on Daytona (#20711)
## Thinking Path > - Paperclip is the open source app people use to manage AI agents for work. > - The restart-chaos harness (`tests/restart-chaos/`) restarts or stalls the control plane while real agent tasks run. > - The staging census (#20679, `doc/plans/2026-11-11-staging-failures-vs-chaos-coverage.md`) found two open classes that the harness could not create. In class R, a deploy lands mid-turn, the server stays down for 4–7 minutes, and recovery then finds the remote Runner gone (`runner_remote_process_identity_unavailable`). In class L, the server stalls for about 100 s without a restart, and legacy runs that are still `preparing` end up waiting for a manual Retry. > - K15 restarted at once. No Daytona workload kept a tool running across the fault. TM1 was local-only with a fixed range. Nothing recorded what the remote Runner did while the controller was away. > - This pull request adds a K15 outage hold, a mid-tool workload, sandbox-side Runner evidence, and TM1 stalls on Daytona with a configurable hold. > - The benefit: these staging failure shapes can now be reproduced, and each wave records the Runner's own state. ## Linked Issues or Issue Description Refs #20679 **What happened?** On staging, two failure shapes had no matching chaos scenario: - Class R: a deploy landed mid-turn and the server stayed down for 4–7 minutes. Recovery then found the remote Runner gone. Nothing captured why the Runner exited. - Class L: a 100 s server stall without a restart lapsed every controller lease. Legacy `preparing` runs then waited for a manual Retry. **What did you expect?** The harness should create a long mid-turn deploy outage and a stall without a restart on Daytona. It should also save the sandbox-side Runner evidence. **Steps to reproduce** 1. Use the census report and the staging run records listed in it. 2. Compare them with the harness options before this change: K15 has no hold, TM1 is local-only, and there is no Daytona tool workload. ## What Changed - `--k15-hold-seconds <n|min-max>` (0–600). A K15 stops the server with SIGTERM, keeps it down for the seeded hold, then starts the next deploy generation. The range is drawn only for K15 cells, so existing seeds keep their plans. Storms use it too. - New opt-in workload `T1`. The agent runs one shell loop in the foreground for about 100 s, then saves `TICKS-<nonce>=50`. Its fault window, 35–80 s after launch, lands mid-tool. - New `daytona-runner-logs.ts`, a read-only probe of each wave sandbox through the Daytona toolbox. It runs only on sandboxes with the wave's labels, and only on `started` ones. It records every process, memory, disk, `dmesg` OOM lines, and the tails of `runnerd.stderr.log`, `runner-process.identity` and `runner-state.json`. It redacts known secrets. It runs right after a K15 stop, just before the next deploy starts, and at wave end. Output goes to `results/<wave>/daytona-runner/` and to `runner_logs_captured` in the timeline. The probe never stops, starts or deletes a sandbox, and a failed capture is recorded instead of thrown. - TM1 now runs on `--env daytona`, and `--tm1-hold-seconds <n|min-max>` (10–600) replaces its default 95–150 s range with the same single draw. TM2 and TM3 stay local. - Tests: `k15-long-hold.test.ts` and `tm1-stall.test.ts`. The README is updated. ## Verification - `pnpm exec vitest run --config tests/restart-chaos/vitest.config.ts`: 45 files and 531 tests pass. - `node scripts/typecheck-test-projects.mjs tests/restart-chaos`: passes. - Daytona waves, all with T1 and K15: | Wave | Revision and image | Hold | Result | | --- | --- | --- | --- | | `w-20261111T015441-s9310` | master8f6ca25976, image `bc7ca92d…` | 267–408 s, OpenCode | 4 of 4 pass | | `w-20261111T022637-s9311` | master8f6ca25976, image `bc7ca92d…` | 300 s, OpenCode and Claude | 4 of 4 pass. Every stop capture shows the T1 loop running. | | `w-20261111T025307-s9320` | mastera1ec05a1a4, image `09321542…` | 460–482 s, past the Runner's 7-minute reconnect grace | 4 of 4 pass | - In every pre-restart capture, the same `runnerd` PID was alive for the whole outage (etimes 491–549 s in the last wave). Every sandbox was `started`. There was no `transport_reconnect_grace_exceeded` and no OOM. - So the class R Runner loss does not reproduce on current master with the e2e image. The census document lists the remaining differences from staging. - TM1 Daytona waves on mastera1ec05a1a4found a **new product gap** (RED; the harness only reports it): - `w-20261111T034105-s9330` (TM1 at `--fault-after-seconds 10`): 2 of 3 pass. The failing OpenCode run was stalled at `native.process_start_requested`. Afterwards it waited forever with `controller_still_alive` / `restartKind: hard`, where the controller it waited for was its own live server. - `w-20261111T040439-s9331` (TM1 mid-tool, T1): 0 of 3 pass. After the stall the run had no further events and stayed `running` for more than 20 minutes, with no Retry. - Review fixes in3540bfe700: matrix cells take both holds, T1's `fault_crossed_tool` check, and one 45 s deadline per Runner capture. The suite is now 45 files and 531 tests. ## Risks - Low risk. This change is test harness and docs only, with no product code. - The Runner probe executes one fixed read-only command in this wave's own sandboxes through the Daytona toolbox. It never targets fleet sandboxes, because it filters on the wave's company and environment labels. ## Model Used - Claude Opus 5.5 (`claude-opus-5-5`), Anthropic, in Claude Code with tool use (shell, file edit, GitHub CLI). ## 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
f25fee3532
commit
62b7733161
15 files changed
+698
-27
No files matched your search
@@ -307,3 +307,41 @@ What this shows:
|
||||
- The next scenario to build is **K15 with `--upgrade-from` on Daytona**: start with the older
|
||||
checkout and its image, redeploy to the current checkout, and keep the older runner in the
|
||||
retained sandboxes. Today the Daytona image check refuses that mixed state on purpose.
|
||||
|
||||
### Follow-up: long mid-tool outages and server stalls (PR #20711)
|
||||
|
||||
Built after review by the class R and class L fix owners:
|
||||
|
||||
- `--k15-hold-seconds` holds a K15 outage, because staging deploys were down 4–7 minutes.
|
||||
- The T1 workload keeps a shell tool running across the fault, and `fault_crossed_tool` proves it.
|
||||
- Sandbox-side Runner evidence is captured in `results/<wave>/daytona-runner/`.
|
||||
- TM1 stalls now run on Daytona, with `--tm1-hold-seconds`.
|
||||
|
||||
Class L turned out not to be a deploy. The server process stalled for about 100 s at 08:19Z on Nov 10.
|
||||
|
||||
| Wave | Revision | Scenario | Result |
|
||||
| --- | --- | --- | --- |
|
||||
| `w-20261111T015441-s9310` | 8f6ca25976 | K15 hold 267–408 s, T1, OpenCode | 4 of 4 pass. The Runner was alive through every outage. |
|
||||
| `w-20261111T022637-s9311` | 8f6ca25976 | K15 hold 300 s, T1, OpenCode and Claude | 4 of 4 pass. The stop captures show the T1 loop running. |
|
||||
| `w-20261111T025307-s9320` | a1ec05a1a4 | K15 hold 460–482 s, past the Runner's 420 s reconnect grace | 4 of 4 pass. The same `runnerd` PID was alive 491–549 s after the stop, every sandbox was `started`, and there was no `transport_reconnect_grace_exceeded`. |
|
||||
| `w-20261111T034105-s9330` | a1ec05a1a4 | TM1 70–120 s at `--fault-after-seconds 10`, A1, all three adapters | **RED, 1 of 3 fail.** An OpenCode run was stalled at `native.process_start_requested`. Afterwards it waited forever on `native.recovery.transition` with `reason: controller_still_alive` and `restartKind: hard`. The controller it waited for was its own live, unrestarted process. No Retry was offered. |
|
||||
| `w-20261111T040439-s9331` | a1ec05a1a4 | TM1 70–120 s mid-tool, T1, all three adapters | **RED, 3 of 3 fail.** After the stall, `native.session.execute` ended, but the run never got another event: no terminal and no recovery. It stayed `running` for more than 20 minutes with no Retry. Each task crossed three back-to-back stalls. |
|
||||
| `w-20261111T043759-s9340` | a1ec05a1a4 | One TM1 stall of 90 s mid-tool, T1, Codex | 1 of 1 pass. `fault_crossed_tool` confirms the stall landed in the loop. The mid-tool wedge needs repeated stalls; one did not cause it. |
|
||||
|
||||
Conclusions:
|
||||
|
||||
- Class R's Runner loss (`runner_remote_process_identity_unavailable`) does **not** reproduce on current
|
||||
master with the e2e image, even past the reconnect grace.
|
||||
- Staging differs from these waves in four ways:
|
||||
- its sandboxes come from the managed fleet snapshot (`fleet-sbx-…`, last updated Nov 5), not the e2e image;
|
||||
- it ran older runner builds;
|
||||
- Railway drains the server before it stops;
|
||||
- the cloud manages the sandbox lifecycle.
|
||||
- The next step needs staging-side `runnerd.stderr.log` from a retained sandbox of a failed run.
|
||||
- A control-plane stall **without** a restart is a new open product class. A native run whose lease
|
||||
lapses while its own server is frozen is never taken back by that same server:
|
||||
- **stall during preparation:** the run waits forever on `controller_still_alive`;
|
||||
- **stall mid-turn:** the run is orphaned while still `running`. This took three back-to-back stalls of about 90 s; a single 90 s stall recovered.
|
||||
- #20694 fixed the legacy `preparing` case only.
|
||||
- Code pointer: `server/src/services/native-runtime/native-restart-recovery.ts` (the same-boot owner is not
|
||||
recognized as the server itself).
|
||||
@@ -337,6 +337,58 @@ 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). The command prints the loop's
|
||||
own clock window. The agent then saves `brief`, whose first line is
|
||||
`TICKS-<nonce>=50 start=<epoch s> end=<epoch s>`. Its fault window (35–80 s
|
||||
after launch) aims to land while the tool runs in the sandbox, and stays short
|
||||
of provider shell-tool timeouts.
|
||||
|
||||
The `fault_crossed_tool` check (skipped for `K0` baselines and provider faults;
|
||||
a storm task counts the storm's faults) fails the task unless one of its own faults
|
||||
started inside the reported window, with 5 s of clock slack. A fault that hit
|
||||
preparation, with the loop run afterwards, tested nothing mid-tool, as a
|
||||
provider-fault task whose fault never applied.
|
||||
- **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:
|
||||
- every process (`ps`), so a running tool shows as a child of the Runner;
|
||||
- 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.
|
||||
|
||||
The whole capture (client, listing and every probe) has one 45 s deadline.
|
||||
The capture runs while the server is down, so a slow Daytona API adds at most
|
||||
that much to the outage. A capture that hits the deadline is recorded as
|
||||
`deadlineExceeded`, and the restart continues. A probe that answers after the
|
||||
deadline writes nothing, because its evidence is from after the outage window.
|
||||
|
||||
## Absolute symlink in the workspace (F1)
|
||||
|
||||
```sh
|
||||
@@ -845,8 +897,26 @@ node cli/node_modules/tsx/dist/cli.mjs tests/restart-chaos/main.ts --env local \
|
||||
# The aged wait: an approval left pending for a day across a restart.
|
||||
node cli/node_modules/tsx/dist/cli.mjs tests/restart-chaos/main.ts --env local \
|
||||
--adapters codex --workloads G1 --faults TM3 --triggers approval --concurrency 2 --tasks 2 --seed 302
|
||||
# Staging's 100 s event-loop stall: TM1 on Daytona, stalled during workspace preparation or mid-tool.
|
||||
node cli/node_modules/tsx/dist/cli.mjs tests/restart-chaos/main.ts --env daytona --daytona-image $IMG --daytona-cpu 3 \
|
||||
--adapters codex,claude,opencode --workloads A1,T1 --faults TM1 --tm1-hold-seconds 70-120 --storage s3 \
|
||||
--concurrency 3 --tasks 6 --seed 303
|
||||
```
|
||||
|
||||
TM1 also runs on `--env daytona`. It stalls only the control plane, with no
|
||||
restart and no new deployment identity. The remote Runner keeps working while
|
||||
every controller lease of the stalled process lapses. This is staging's class L:
|
||||
a server stall of about 100 s at 08:19Z on Nov 10.
|
||||
|
||||
`--tm1-hold-seconds <n>` or `<min>-<max>` (10–600 s) replaces TM1's default
|
||||
95–150 s range. It uses the same single draw, so seeds keep their cells.
|
||||
|
||||
To stall a run while it is still `preparing`, use `--fault-after-seconds`, as in
|
||||
`--fault-after-seconds 10 --storage s3`. A stall while preparing needs a
|
||||
preparation that outlasts the fault time, such as a remote workspace restore.
|
||||
|
||||
TM2 and TM3 age the wave database and freeze local runners, so they stay local.
|
||||
|
||||
The fourth fault family. Every other wave is minutes long on a fresh instance, so nothing time-bound
|
||||
expires. A time fault makes deadlines lapse during a run or across a restart. No product code changes.
|
||||
|
||||
@@ -1064,7 +1134,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. |
|
||||
@@ -1074,7 +1144,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,15 @@ 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" },
|
||||
"tm1-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", "tm1-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 +182,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)),
|
||||
@@ -240,8 +243,9 @@ export function parseCommand(argv: readonly string[], now = Date.now()): ParsedC
|
||||
if (options.faults.includes("K15") && options.faults.some(isMultiServerFault)) {
|
||||
throw new Error("K15 (redeploy) does not combine with MS1-MS3: the second server would not share the emulated deploy identity");
|
||||
}
|
||||
Object.assign(options, parseTimeFaultOptions(options, values["time-age-hours"]));
|
||||
Object.assign(options, parseTimeFaultOptions(options, values["time-age-hours"], values["tm1-hold-seconds"]));
|
||||
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,137 @@
|
||||
/**
|
||||
* 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',
|
||||
// Every process, not only the Runner's: a tool the agent started (for example T1's loop) shows as a child.
|
||||
'echo "== processes"; ps -eo pid,ppid,sid,etimes,stat,rss,args 2>/dev/null | cut -c1-400 | head -n 120',
|
||||
'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("; ");
|
||||
|
||||
/** The whole capture (client, listing and every probe) gets this long; the outage it runs in must not grow. */
|
||||
export const RUNNER_LOG_CAPTURE_DEADLINE_MS = 45_000;
|
||||
|
||||
export interface RunnerLogCapture {
|
||||
label: string;
|
||||
observedAt: string;
|
||||
/** True when the deadline ended the capture; sandboxes not reached are recorded with `error: "deadline"`. */
|
||||
deadlineExceeded?: boolean;
|
||||
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; deadlineMs?: number;
|
||||
}): Promise<RunnerLogCapture> {
|
||||
// An unusable label must not throw out of the restart path: fall back to a fixed directory and record why.
|
||||
let label = "capture";
|
||||
let labelError: string | null = null;
|
||||
try { label = captureDirectoryName(input.label); } catch (error) { labelError = error instanceof Error ? error.message : String(error); }
|
||||
const capture: RunnerLogCapture = { label, observedAt: new Date().toISOString(), sandboxes: [], error: labelError };
|
||||
const directory = path.join(input.outDir, label);
|
||||
const deadlineMs = input.deadlineMs ?? RUNNER_LOG_CAPTURE_DEADLINE_MS;
|
||||
const deadlineAt = Date.now() + deadlineMs;
|
||||
let timer: NodeJS.Timeout | undefined;
|
||||
const deadline = new Promise<"deadline">(resolve => { timer = setTimeout(() => resolve("deadline"), deadlineMs); });
|
||||
// The probe races the shared deadline. A probe that loses may still be awaiting Daytona in the background:
|
||||
// `expired` stops it from probing or writing anything once the capture has been saved.
|
||||
let expired = false;
|
||||
const live = () => !expired && Date.now() < deadlineAt;
|
||||
try {
|
||||
const outcome = await Promise.race([probeWave(), deadline]);
|
||||
if (outcome === "deadline") {
|
||||
expired = true;
|
||||
capture.deadlineExceeded = true;
|
||||
// A probe still in flight when the deadline won left its entry with neither a file nor an error.
|
||||
for (const entry of capture.sandboxes) if (entry.file === null && entry.error === null && probeableSandbox({ id: entry.id, state: entry.state ?? undefined })) entry.error = "deadline";
|
||||
capture.error = `capture deadline ${deadlineMs} ms exceeded`;
|
||||
}
|
||||
} finally {
|
||||
clearTimeout(timer);
|
||||
}
|
||||
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;
|
||||
|
||||
async function probeWave(): Promise<void> {
|
||||
try {
|
||||
await mkdir(directory, { recursive: true, mode: 0o700 });
|
||||
const client = input.client ?? await createRemoteFixtureClient(input.apiKey) as unknown as ProbeClient;
|
||||
if (!live()) return;
|
||||
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);
|
||||
if (!live()) return;
|
||||
// Every wave sandbox gets its entry before any probe, so a deadline marks the ones it never reached.
|
||||
const targets = selectWaveSandboxes(rows, wave).map(row => ({ row,
|
||||
entry: { id: row.id, name: row.name ?? null, state: row.state ?? null, file: null, exitCode: null, error: null } as RunnerLogCapture["sandboxes"][number] }));
|
||||
capture.sandboxes.push(...targets.map(target => target.entry));
|
||||
for (const { row, entry } of targets) {
|
||||
if (expired) return;
|
||||
if (!probeableSandbox(row)) continue;
|
||||
if (!live()) { if (!expired) entry.error = "deadline"; continue; }
|
||||
try {
|
||||
const sandbox = await client.get(row.id);
|
||||
if (!live()) { if (!expired) entry.error = "deadline"; continue; }
|
||||
const response = await sandbox.process.executeCommand(`sh -c '${RUNNER_LOG_PROBE.replace(/'/g, `'\\''`)}'`, undefined, {}, input.timeoutSeconds ?? 20);
|
||||
// Evidence that arrives after the deadline was taken after the outage window: never write it.
|
||||
if (!live()) { if (!expired) entry.error = "deadline"; continue; }
|
||||
entry.exitCode = response.exitCode;
|
||||
// The id names the file: keep it one safe path segment, and list the file only once it is written.
|
||||
const file = `${captureDirectoryName(row.id)}.txt`;
|
||||
await writeFile(path.join(directory, file), redactKnownSecrets(String(response.result ?? ""), input.secrets), { mode: 0o600 });
|
||||
entry.file = file;
|
||||
} catch (error) {
|
||||
if (!expired) entry.error = error instanceof Error ? error.message : String(error);
|
||||
}
|
||||
}
|
||||
} catch (error) {
|
||||
if (!expired) capture.error = error instanceof Error ? error.message : String(error);
|
||||
}
|
||||
}
|
||||
}
|
||||
@@ -10,6 +10,7 @@
|
||||
* share the server with a fault cell (`matrixMayLaunch`).
|
||||
*/
|
||||
import path from "node:path";
|
||||
import { k15HoldMs } from "./redeploy.js";
|
||||
import { WORKLOAD_TRIGGERS } from "./journeys.js";
|
||||
import { withProviderFaultRules } from "./provider-faults.js";
|
||||
import { createRng, k4HoldRange, TRIGGER_DELAY_RANGE_MS } from "./scheduler.js";
|
||||
@@ -43,7 +44,7 @@ export function matrixMayLaunch(next: Pick<TaskPlan, "fault">, inFlight: Readonl
|
||||
return inFlight.every(task => (task.fault === "K0") === baseline);
|
||||
}
|
||||
|
||||
export function planMatrixTasks(options: Pick<WaveOptions, "seed" | "workloads" | "adapters" | "faults" | "providerFaults" | "k4HoldMaxMs" | "faultAfterMs" | "rrGapMs">): TaskPlan[] {
|
||||
export function planMatrixTasks(options: Pick<WaveOptions, "seed" | "workloads" | "adapters" | "faults" | "providerFaults" | "k4HoldMaxMs" | "k15HoldMs" | "tm1HoldMs" | "faultAfterMs" | "rrGapMs">): TaskPlan[] {
|
||||
const rng = createRng((options.seed ^ 0x6a6d7478) >>> 0);
|
||||
return matrixCells(options).map((cell, index) => {
|
||||
const definition = workloadDefinitions[cell.workload];
|
||||
@@ -58,8 +59,10 @@ export function planMatrixTasks(options: Pick<WaveOptions, "seed" | "workloads"
|
||||
...(cell.trigger === "time" ? {} : { trigger: cell.trigger, triggerDelayMs: rng.int(...TRIGGER_DELAY_RANGE_MS[cell.trigger]) }),
|
||||
// `--fault-after-seconds` pins time-fired restarts, as it does outside the matrix.
|
||||
fireAfterMs: cell.fault === "K0" || cell.fault.startsWith("PV") ? 0 : cell.trigger === "time" ? options.faultAfterMs ?? drawn : drawn,
|
||||
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,
|
||||
holdMs: cell.fault === "K4" ? rng.int(...k4HoldRange(options.k4HoldMaxMs))
|
||||
: isTimeFault(cell.fault) ? timeFaultHoldMs(cell.fault, rng.int, options.tm1HoldMs)
|
||||
: isMultiServerFault(cell.fault) ? multiServerHoldMs(cell.fault, rng.int)
|
||||
: cell.fault === "K15" ? k15HoldMs(options.k15HoldMs, rng.int) : 0,
|
||||
...(isRepeatedRestartFault(cell.fault) ? { restartSteps: planRestartSteps(cell.fault, rng.int, options.rrGapMs) } : {}),
|
||||
followUpAfterMs: definition.followUpWindowMs ? rng.int(definition.followUpWindowMs[0], definition.followUpWindowMs[1]) : null,
|
||||
nonce: rng.hex(8),
|
||||
|
||||
@@ -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,222 @@
|
||||
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_CAPTURE_DEADLINE_MS, 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_CLOCK_SLACK_MS, T1_TICKS, parseT1Report, t1Command, t1Marker, withT1CrossingCheck, workloadDefinitions } from "./workloads.js";
|
||||
import { planMatrixTasks } from "./journey-matrix.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");
|
||||
});
|
||||
|
||||
const START = 1_794_370_000;
|
||||
const line = (ticks: number, start = START, end = START + 100) => `${t1Marker(NONCE)}=${ticks} start=${start} end=${end}`;
|
||||
|
||||
it("passes only when the finished tool's count and window are reported and the task is done", () => {
|
||||
expect(t1.grade(NONCE, done(`${line(T1_TICKS)}\nmore`)).verdict).toBe("pass");
|
||||
expect(t1.grade(NONCE, done(line(49))).verdict).toBe("fail");
|
||||
expect(t1.grade(NONCE, done(`${t1Marker(NONCE)}=${T1_TICKS}`)).verdict).toBe("fail");
|
||||
expect(t1.grade(NONCE, done("")).verdict).toBe("fail");
|
||||
expect(t1.grade(NONCE, { ...done(line(T1_TICKS)), issueStatus: "blocked" }).verdict).toBe("fail");
|
||||
expect(parseT1Report(NONCE, line(T1_TICKS, START + 10, START))).toBeNull();
|
||||
});
|
||||
|
||||
it("counts a mid-tool test only when one of the task's own faults started inside the loop's window", () => {
|
||||
const plan = { taskId: "t01", workload: "T1" as const, nonce: NONCE, fault: "TM1" };
|
||||
const pass = t1.grade(NONCE, done(line(T1_TICKS)));
|
||||
const fault = (taskId: string, atSeconds: number) => ({ faultId: "f01", requestedBy: taskId, startedAt: atSeconds * 1000 });
|
||||
expect(withT1CrossingCheck(pass, plan, line(T1_TICKS), [fault("t01", START + 40)]).verdict).toBe("pass");
|
||||
// Clock slack at the edges, but a fault during preparation (before the loop) tested nothing mid-tool.
|
||||
expect(withT1CrossingCheck(pass, plan, line(T1_TICKS), [fault("t01", START - T1_CLOCK_SLACK_MS / 1000)]).verdict).toBe("pass");
|
||||
const missed = withT1CrossingCheck(pass, plan, line(T1_TICKS), [fault("t01", START - 30)]);
|
||||
expect(missed.verdict).toBe("fail");
|
||||
expect(missed.checks.find(check => check.name === "fault_crossed_tool")?.ok).toBe(false);
|
||||
// Another task's fault does not count, and other workloads are untouched.
|
||||
expect(withT1CrossingCheck(pass, plan, line(T1_TICKS), [fault("t02", START + 40)]).verdict).toBe("fail");
|
||||
expect(withT1CrossingCheck(pass, { ...plan, workload: "A1" }, null, [])).toBe(pass);
|
||||
// A matrix baseline expects no fault, and a provider message fault restarts nothing of its own.
|
||||
expect(withT1CrossingCheck(pass, { ...plan, fault: "K0" }, line(T1_TICKS), [])).toBe(pass);
|
||||
expect(withT1CrossingCheck(pass, { ...plan, fault: "PV1" }, line(T1_TICKS), [])).toBe(pass);
|
||||
// A storm task is crossed by the storm's faults, which are requested by "storm".
|
||||
expect(withT1CrossingCheck(pass, { ...plan, fault: "K13" }, line(T1_TICKS), [fault("storm", START + 40)]).verdict).toBe("pass");
|
||||
expect(withT1CrossingCheck(pass, { ...plan, fault: "K13" }, line(T1_TICKS), [fault("storm", START - 60)]).verdict).toBe("fail");
|
||||
});
|
||||
|
||||
it("prints the loop's own clock window", () => {
|
||||
expect(t1Command(NONCE)).toContain("start=$s end=$(date +%s)");
|
||||
});
|
||||
});
|
||||
|
||||
describe("hold options in --matrix", () => {
|
||||
it("plans the requested K15 and TM1 holds for matrix cells", () => {
|
||||
const parsed = parseCommand(["--matrix", "--workloads", "T1", "--adapters", "codex", "--faults", "K15,TM1",
|
||||
"--k15-hold-seconds", "300", "--tm1-hold-seconds", "100", "--seed", "5"]);
|
||||
if (parsed.mode !== "wave") throw new Error("expected a wave");
|
||||
const cells = planMatrixTasks(parsed.options);
|
||||
expect(cells.filter(cell => cell.fault === "K15").every(cell => cell.holdMs === 300_000)).toBe(true);
|
||||
expect(cells.filter(cell => cell.fault === "TM1").every(cell => cell.holdMs === 100_000)).toBe(true);
|
||||
expect(cells.some(cell => cell.fault === "K15") && cells.some(cell => cell.fault === "TM1")).toBe(true);
|
||||
});
|
||||
});
|
||||
|
||||
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");
|
||||
});
|
||||
|
||||
it("stops at one deadline for the whole capture, so the outage it runs in does not grow", async () => {
|
||||
const outDir = await mkdtemp(path.join(os.tmpdir(), "runner-logs-"));
|
||||
const labels = { "paperclip-company-id": COMPANY, "paperclip-environment-id": ENVIRONMENT };
|
||||
const hung = { async *list() { yield { id: "slow", state: "started", labels }; },
|
||||
get: () => new Promise<never>(() => { /* a Daytona API that never answers */ }) };
|
||||
const started = Date.now();
|
||||
const capture = await captureWaveRunnerLogs({ apiKey: "unused", companyId: COMPANY, environmentId: ENVIRONMENT, outDir,
|
||||
label: "f03-stopped", secrets: [], client: hung, deadlineMs: 200 });
|
||||
expect(Date.now() - started).toBeLessThan(2_000);
|
||||
expect(capture.deadlineExceeded).toBe(true);
|
||||
expect(capture.error).toMatch(/deadline 200 ms exceeded/);
|
||||
expect(JSON.parse(await readFile(path.join(outDir, "f03-stopped", "index.json"), "utf8")).deadlineExceeded).toBe(true);
|
||||
expect(RUNNER_LOG_CAPTURE_DEADLINE_MS).toBeLessThanOrEqual(60_000);
|
||||
});
|
||||
|
||||
it("keeps a sandbox id to one path segment and lists only files it wrote", async () => {
|
||||
const outDir = await mkdtemp(path.join(os.tmpdir(), "runner-logs-"));
|
||||
const labels = { "paperclip-company-id": COMPANY, "paperclip-environment-id": ENVIRONMENT };
|
||||
const client = { async *list() { yield { id: "../escape", state: "started", labels }; },
|
||||
get: async () => ({ process: { executeCommand: async () => ({ exitCode: 0, result: "ok" }) } }) };
|
||||
const capture = await captureWaveRunnerLogs({ apiKey: "unused", companyId: COMPANY, environmentId: ENVIRONMENT, outDir,
|
||||
label: "f05-stopped", secrets: [], client });
|
||||
expect(capture.sandboxes[0]?.file).toBe("..-escape.txt");
|
||||
expect((await readdir(path.join(outDir, "f05-stopped"))).sort()).toEqual(["..-escape.txt", "index.json"]);
|
||||
expect(await readdir(outDir)).toEqual(["f05-stopped"]);
|
||||
});
|
||||
|
||||
it("never writes evidence that arrives after the deadline", 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: "late evidence" }));
|
||||
let release: (() => void) | undefined;
|
||||
const late = { async *list() { yield { id: "late", state: "started", labels }; yield { id: "unreached", state: "started", labels }; },
|
||||
get: () => new Promise<{ process: { executeCommand: typeof executeCommand } }>(resolve => {
|
||||
release = () => resolve({ process: { executeCommand } });
|
||||
}) };
|
||||
const capture = await captureWaveRunnerLogs({ apiKey: "unused", companyId: COMPANY, environmentId: ENVIRONMENT, outDir,
|
||||
label: "f04-before_start", secrets: [], client: late, deadlineMs: 100 });
|
||||
expect(capture.deadlineExceeded).toBe(true);
|
||||
release?.();
|
||||
await new Promise(resolve => setTimeout(resolve, 50));
|
||||
expect(executeCommand).not.toHaveBeenCalled();
|
||||
expect((await readdir(path.join(outDir, "f04-before_start"))).sort()).toEqual(["index.json"]);
|
||||
expect(capture.sandboxes.map(sandbox => [sandbox.id, sandbox.file, sandbox.error])).toEqual([["late", null, "deadline"], ["unreached", null, "deadline"]]);
|
||||
});
|
||||
|
||||
it("drops a probe result that arrives after the deadline, and records an unusable label instead of throwing", async () => {
|
||||
const outDir = await mkdtemp(path.join(os.tmpdir(), "runner-logs-"));
|
||||
const labels = { "paperclip-company-id": COMPANY, "paperclip-environment-id": ENVIRONMENT };
|
||||
let release: ((value: { exitCode: number; result: string }) => void) | undefined;
|
||||
const client = { async *list() { yield { id: "slow-probe", state: "started", labels }; },
|
||||
get: async () => ({ process: { executeCommand: () => new Promise<{ exitCode: number; result: string }>(resolve => { release = resolve; }) } }) };
|
||||
const capture = await captureWaveRunnerLogs({ apiKey: "unused", companyId: COMPANY, environmentId: ENVIRONMENT, outDir,
|
||||
label: "///", secrets: [], client, deadlineMs: 100 });
|
||||
expect(capture.label).toBe("capture");
|
||||
expect(capture.error).toMatch(/deadline 100 ms exceeded/);
|
||||
release?.({ exitCode: 0, result: "too late" });
|
||||
await new Promise(resolve => setTimeout(resolve, 50));
|
||||
expect((await readdir(path.join(outDir, "capture"))).sort()).toEqual(["index.json"]);
|
||||
expect(capture.sandboxes.map(sandbox => [sandbox.id, sandbox.file, sandbox.error])).toEqual([["slow-probe", null, "deadline"]]);
|
||||
});
|
||||
});
|
||||
@@ -39,6 +39,8 @@ 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 { withT1CrossingCheck } from "./workloads.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 +241,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 +352,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 +641,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 });
|
||||
@@ -662,7 +678,9 @@ async function main(): Promise<number> {
|
||||
const restart = faults.find(receipt => receipt.requestedBy === observer.plan.taskId && receipt.trigger === "provider");
|
||||
const oracle = withProviderFaultCheck(graded, observer.plan, artifacts?.providerFaultEvents ?? [], restart?.startedAt ?? null,
|
||||
restart?.stoppedAt ?? restart?.startedAt ?? null);
|
||||
const grade = gradeTask(observer.record, faults, observer.definition.budgetMs, oracle, universalByIssue ? {
|
||||
// T1: a mid-tool fault only counts when one of the task's faults started while its loop ran (workloads.ts).
|
||||
const toolOracle = withT1CrossingCheck(oracle, observer.plan, artifacts?.documents.brief, faults);
|
||||
const grade = gradeTask(observer.record, faults, observer.definition.budgetMs, toolOracle, universalByIssue ? {
|
||||
runMessages: allRunMessages, recoveryActions: universalByIssue.get(observer.record.issueId ?? "")?.recoveryActions ?? [] } : undefined);
|
||||
let evidence: string | null = null;
|
||||
if (!grade.pass) {
|
||||
|
||||
@@ -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" | "tm1HoldMs" | "faultAfterMs" | "providerFaults" | "rrGapMs">): TaskPlan[] {
|
||||
const rng = createRng(options.seed);
|
||||
const triggers = options.triggers?.length ? options.triggers : ["time" as const];
|
||||
for (const trigger of triggers) {
|
||||
@@ -126,8 +127,9 @@ export function planTasks(options: Pick<WaveOptions, "seed" | "tasks" | "workloa
|
||||
...cellRest,
|
||||
...(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,
|
||||
holdMs: cell.fault === "K4" ? rng.int(...k4HoldRange(options.k4HoldMaxMs)) : isTimeFault(cell.fault) ? timeFaultHoldMs(cell.fault, rng.int, options.tm1HoldMs)
|
||||
: 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();
|
||||
},
|
||||
|
||||
@@ -18,29 +18,54 @@ export const TIME_FREEZE_HOLD_RANGE_MS: Record<"TM1" | "TM2", readonly [number,
|
||||
/** Default age: past a day, so hourly, daily and 1 h deadlines all lapse. `--time-age-hours` sets it (1–72). */
|
||||
export const DEFAULT_TIME_AGE_MS = DEFAULT_TIME_AGE_HOURS * 3_600_000;
|
||||
|
||||
/** Seeded freeze length for a TM task; 0 for TM3 (its time passes through aging). Draws only for TM1/TM2. */
|
||||
export function timeFaultHoldMs(kind: TimeFaultKind, int: (min: number, max: number) => number): number {
|
||||
return kind === "TM3" ? 0 : int(...TIME_FREEZE_HOLD_RANGE_MS[kind]);
|
||||
/**
|
||||
* Seeded freeze length for a TM task; 0 for TM3 (its time passes through aging). Draws only for TM1/TM2.
|
||||
* `tm1RangeMs` (`--tm1-hold-seconds`) replaces TM1's default range with the same single draw, so seeds keep their cells.
|
||||
*/
|
||||
export function timeFaultHoldMs(kind: TimeFaultKind, int: (min: number, max: number) => number,
|
||||
tm1RangeMs?: readonly [number, number]): number {
|
||||
if (kind === "TM3") return 0;
|
||||
return int(...(kind === "TM1" && tm1RangeMs ? tm1RangeMs : TIME_FREEZE_HOLD_RANGE_MS[kind]));
|
||||
}
|
||||
|
||||
/** `--tm1-hold-seconds` bounds: long enough to matter, within the controller-outage cap. */
|
||||
export const TM1_HOLD_SECONDS_RANGE: readonly [number, number] = [10, 600];
|
||||
|
||||
const MIN_HOURS = 1;
|
||||
const MAX_HOURS = 72;
|
||||
|
||||
export function parseTimeFaultOptions(options: Pick<WaveOptions, "env" | "faults" | "stormMinutes" | "crashPoint">,
|
||||
rawAgeHours: string | undefined): Pick<WaveOptions, "timeAgeMs"> {
|
||||
rawAgeHours: string | undefined, rawTm1HoldSeconds?: string): Pick<WaveOptions, "timeAgeMs" | "tm1HoldMs"> {
|
||||
const time = options.faults.filter(isTimeFault);
|
||||
const ages = time.some(kind => kind === "TM2" || kind === "TM3");
|
||||
if (rawAgeHours !== undefined && !ages) throw new Error("--time-age-hours sets the TM2/TM3 age; add TM2 or TM3 to --faults");
|
||||
if (rawTm1HoldSeconds !== undefined && !time.includes("TM1")) throw new Error("--tm1-hold-seconds sets the TM1 stall; add TM1 to --faults");
|
||||
if (!time.length) return {};
|
||||
// A freeze sends SIGSTOP to processes under the local server; a remote runner is not one of them.
|
||||
if (options.env !== "local") throw new Error("Time faults (TM*) freeze and age a local instance; run them with --env local");
|
||||
// TM1 stalls the control plane alone (SIGSTOP, then SIGCONT, no restart): on Daytona the remote Runner keeps
|
||||
// working while the controller's leases lapse, as in staging's 100 s event-loop stall. TM2 and TM3 age the
|
||||
// wave database and freeze local runners, so they stay local.
|
||||
if (options.env !== "local" && time.some(kind => kind !== "TM1")) {
|
||||
throw new Error("Time faults TM2 and TM3 freeze and age a local instance; run them with --env local (TM1 also runs on Daytona)");
|
||||
}
|
||||
if (options.stormMinutes) throw new Error("Time faults (TM*) are planned per task; do not combine them with --storm-minutes");
|
||||
if (options.crashPoint) throw new Error("Time faults (TM*) do not combine with --crash-point");
|
||||
if (options.faults.includes("K14")) throw new Error("Time faults (TM*) do not combine with K14; age the upgraded build in its own wave");
|
||||
if (!ages) return {};
|
||||
if (rawAgeHours === undefined) return { timeAgeMs: DEFAULT_TIME_AGE_HOURS * 3_600_000 };
|
||||
const tm1 = parseTm1HoldSeconds(rawTm1HoldSeconds);
|
||||
if (!ages) return tm1;
|
||||
if (rawAgeHours === undefined) return { ...tm1, timeAgeMs: DEFAULT_TIME_AGE_HOURS * 3_600_000 };
|
||||
if (!/^[0-9]+$/.test(rawAgeHours)) throw new Error("--time-age-hours must be a whole number of hours");
|
||||
const hours = Number(rawAgeHours);
|
||||
if (hours < MIN_HOURS || hours > MAX_HOURS) throw new Error(`--time-age-hours must be between ${MIN_HOURS} and ${MAX_HOURS}`);
|
||||
return { timeAgeMs: hours * 3_600_000 };
|
||||
return { ...tm1, timeAgeMs: hours * 3_600_000 };
|
||||
}
|
||||
|
||||
function parseTm1HoldSeconds(raw: string | undefined): Pick<WaveOptions, "tm1HoldMs"> {
|
||||
if (raw === undefined) return {};
|
||||
const match = /^([0-9]+)(?:-([0-9]+))?$/.exec(raw.trim());
|
||||
if (!match) throw new Error("--tm1-hold-seconds takes <seconds> or <min>-<max> seconds");
|
||||
const min = Number(match[1]);
|
||||
const max = match[2] === undefined ? min : Number(match[2]);
|
||||
const [low, high] = TM1_HOLD_SECONDS_RANGE;
|
||||
if (min < low || max > high || max < min) throw new Error(`--tm1-hold-seconds must be between ${low} and ${high} seconds, min not above max`);
|
||||
return { tm1HoldMs: [min * 1000, max * 1000] };
|
||||
}
|
||||
@@ -0,0 +1,40 @@
|
||||
import { describe, expect, it } from "vitest";
|
||||
import { parseCommand } from "./config.js";
|
||||
import { planTasks } from "./scheduler.js";
|
||||
import { TIME_FREEZE_HOLD_RANGE_MS, timeFaultHoldMs } from "./time-faults-config.js";
|
||||
|
||||
const IMAGE = `ghcr.io/paperclipai/paperclip-daytona-runner@sha256:${"d".repeat(64)}`;
|
||||
|
||||
describe("TM1 control-plane stall on Daytona (--tm1-hold-seconds)", () => {
|
||||
it("stalls a Daytona wave's server without a restart, for the seeded range", () => {
|
||||
const parsed = parseCommand(["--env", "daytona", "--daytona-image", IMAGE, "--faults", "TM1", "--tm1-hold-seconds", "70-120",
|
||||
"--adapters", "codex,claude,opencode", "--workloads", "A1,T1", "--tasks", "6", "--seed", "21"]);
|
||||
if (parsed.mode !== "wave") throw new Error("expected a wave");
|
||||
expect(parsed.options.tm1HoldMs).toEqual([70_000, 120_000]);
|
||||
const holds = planTasks(parsed.options).map(task => task.holdMs);
|
||||
expect(holds.every(hold => hold >= 70_000 && hold <= 120_000)).toBe(true);
|
||||
});
|
||||
|
||||
it("keeps the default TM1 range and every existing seed's cells without the option", () => {
|
||||
const draws: Array<[number, number]> = [];
|
||||
const int = (min: number, max: number) => { draws.push([min, max]); return min; };
|
||||
expect(timeFaultHoldMs("TM1", int)).toBe(TIME_FREEZE_HOLD_RANGE_MS.TM1[0]);
|
||||
expect(timeFaultHoldMs("TM1", int, [70_000, 120_000])).toBe(70_000);
|
||||
expect(timeFaultHoldMs("TM3", int, [70_000, 120_000])).toBe(0);
|
||||
expect(draws).toEqual([[...TIME_FREEZE_HOLD_RANGE_MS.TM1], [70_000, 120_000]]);
|
||||
const a = parseCommand(["--faults", "TM1", "--workloads", "A1", "--tasks", "3", "--seed", "4"]);
|
||||
const b = parseCommand(["--faults", "TM1", "--workloads", "A1", "--tasks", "3", "--seed", "4", "--tm1-hold-seconds", "100"]);
|
||||
if (a.mode !== "wave" || b.mode !== "wave") throw new Error("expected waves");
|
||||
const strip = (tasks: ReturnType<typeof planTasks>) => tasks.map(({ holdMs: _hold, ...rest }) => rest);
|
||||
expect(strip(planTasks(b.options))).toEqual(strip(planTasks(a.options)));
|
||||
expect(planTasks(b.options).every(task => task.holdMs === 100_000)).toBe(true);
|
||||
});
|
||||
|
||||
it("keeps TM2 and TM3 local, and refuses a TM1 range without TM1 or out of bounds", () => {
|
||||
expect(() => parseCommand(["--env", "daytona", "--daytona-image", IMAGE, "--faults", "TM1,TM3", "--workloads", "A1"])).toThrow(/TM2 and TM3 .*--env local/);
|
||||
expect(() => parseCommand(["--faults", "K2", "--tm1-hold-seconds", "90", "--workloads", "A1"])).toThrow(/add TM1/);
|
||||
expect(() => parseCommand(["--faults", "TM1", "--tm1-hold-seconds", "5", "--workloads", "A1"])).toThrow(/between 10 and 600/);
|
||||
expect(() => parseCommand(["--faults", "TM1", "--tm1-hold-seconds", "120-70", "--workloads", "A1"])).toThrow(/min not above max/);
|
||||
expect(() => parseCommand(["--replay", "w-1/t01", "--tm1-hold-seconds", "90"])).toThrow(/--replay reproduces the saved plan/);
|
||||
});
|
||||
});
|
||||
@@ -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,10 @@ 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];
|
||||
/** `--tm1-hold-seconds`: the seeded TM1 stall range (time-faults-config.ts); absent uses 95–150 s. */
|
||||
tm1HoldMs?: [number, number];
|
||||
faultAfterMs?: number;
|
||||
/**
|
||||
* Known product signatures this wave deliberately masks. "rc06" keeps the
|
||||
|
||||
@@ -43,6 +43,47 @@ 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}`;
|
||||
/** Prints `<ticks> start=<epoch s> end=<epoch s>`: the loop's own clock window, so the harness can check a fault crossed it. */
|
||||
export const t1Command = (nonce: string) =>
|
||||
`s=$(date +%s); i=0; while [ $i -lt ${T1_TICKS} ]; do i=$((i+1)); echo tick-$i; sleep 2; done > ticks-${nonce}.txt;`
|
||||
+ ` echo "$(wc -l < ticks-${nonce}.txt | tr -d ' ') start=$s end=$(date +%s)"`;
|
||||
|
||||
/** The brief's first line, `TICKS-<nonce>=<ticks> start=<s> end=<s>`, parsed; null when it does not match. */
|
||||
export function parseT1Report(nonce: string, brief: string | null | undefined): { ticks: number; startMs: number; endMs: number } | null {
|
||||
const first = (brief ?? "").split(/\r?\n/).map(line => line.trim()).find(Boolean) ?? "";
|
||||
const match = new RegExp(`^${t1Marker(nonce)}=([0-9]+) start=([0-9]{9,11}) end=([0-9]{9,11})$`).exec(first);
|
||||
if (!match) return null;
|
||||
const [ticks, start, end] = [Number(match[1]), Number(match[2]) * 1000, Number(match[3]) * 1000];
|
||||
return end >= start ? { ticks, startMs: start, endMs: end } : null;
|
||||
}
|
||||
|
||||
/** Sandbox and host clocks are not the same clock: a fault this close to the loop's edges still counts as crossing it. */
|
||||
export const T1_CLOCK_SLACK_MS = 5_000;
|
||||
|
||||
/**
|
||||
* T1 tested a mid-tool fault only if one of the task's own faults started while the loop ran. A fault that landed
|
||||
* during preparation, with the loop run afterwards, tested nothing mid-tool: the task fails `fault_crossed_tool`,
|
||||
* as a provider-fault task whose fault never applied does.
|
||||
*/
|
||||
export function withT1CrossingCheck(oracle: OracleResult, plan: { taskId: string; workload: WorkloadId; nonce: string; fault: string },
|
||||
brief: string | null | undefined, faults: ReadonlyArray<{ requestedBy: string; startedAt: number; faultId: string }>): OracleResult {
|
||||
// A matrix baseline (K0) expects no fault, and a provider message fault (PV*) restarts nothing of its own.
|
||||
if (plan.workload !== "T1" || plan.fault === "K0" || plan.fault.startsWith("PV")) return oracle;
|
||||
const report = parseT1Report(plan.nonce, brief);
|
||||
// A storm task (K13) has no fault of its own: the storm's faults (requested by "storm") are the ones that cross it.
|
||||
const own = faults.filter(fault => fault.requestedBy === plan.taskId || (plan.fault === "K13" && fault.requestedBy === "storm"));
|
||||
const crossing = report ? own.filter(fault => fault.startedAt >= report.startMs - T1_CLOCK_SLACK_MS
|
||||
&& fault.startedAt <= report.endMs + T1_CLOCK_SLACK_MS) : [];
|
||||
const check = { name: "fault_crossed_tool", ok: crossing.length > 0,
|
||||
detail: report ? `loop ${new Date(report.startMs).toISOString()}..${new Date(report.endMs).toISOString()}; `
|
||||
+ `faults ${own.map(fault => `${fault.faultId}@${new Date(fault.startedAt).toISOString()}`).join(",") || "none"}`
|
||||
: "no loop window reported" };
|
||||
const checks = [...oracle.checks, check];
|
||||
return { ...oracle, checks, verdict: checks.every(entry => entry.ok) ? "pass" : "fail" };
|
||||
}
|
||||
/** 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 +395,32 @@ 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 exact line 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 report = parseT1Report(nonce, artifacts.documents.brief);
|
||||
const first = (artifacts.documents.brief ?? "").split(/\r?\n/).map(line => line.trim()).find(Boolean) ?? "";
|
||||
return result([
|
||||
statusCheck(artifacts),
|
||||
{ name: "tool_finished", ok: report?.ticks === 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