mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-11-13 07:12:00 +01:00
fix(native): keep remote runnerd exit evidence and report it on failed recovery (#20907)
## Thinking Path > - Paperclip is the open source app people use to manage AI agents for work > - Native runs on Daytona start a detached `paperclip-runnerd` in the sandbox, and the controller adopts it after a restart > - On staging, recovery fails with `runner_remote_process_identity_unavailable` when the Runner is gone, but nobody can see why it exited > - The launch script sends runnerd's stdout and stderr to `/dev/null`, so only a panic or a graceful error reaches `runnerd.stderr.log`, and the recovery event does not read that file > - This pull request keeps runnerd's stderr in a bounded file in its private diagnostics directory, and adds the exit reason to the `native.remote_runner_recovery_failed` event > - The benefit is that the reason a Runner exited shows in the run log on staging without SSH, which the class R investigation needs ## Linked Issues or Issue Description **What happened?** Staging runs fail with `runner_remote_process_identity_unavailable` after the remote Runner exits (`native.remote_runner_recovery_failed` with `stage: process_verification`, `reason: process_not_running`). The event does not say why the Runner exited. **What did you expect?** The run log names the Runner's exit reason: its durable `recoverableFailure` and diagnostics, and what it wrote to stderr. **Steps to reproduce** Restart-chaos re-wake and stall cells reproduce the refusal. Each failed run log shows only `runnerLifecycle` and `runnerSettled`. Refs #20893 ## What Changed - `REMOTE_RUNNER_CHILD_LAUNCH_SCRIPT` sends runnerd's stderr to `diagnostics/runnerd.process-stderr.log` (mode 0600, in the 0700 directory) instead of `/dev/null`. - At launch, a file above 1 MiB is rotated once to `.1`. - While runnerd runs, a detached trimmer is a disk backstop. Past 8 MiB, it keeps the last 1 MiB. It checks every 15 s and ends when runnerd ends. It is double-forked with its own argv, so it is not a child of runnerd and does not carry runnerd's arguments. runnerd's own exit reason goes to `runnerd.stderr.log`, which is never trimmed. - A symlink or non-file at that path keeps the old `/dev/null` behavior. - Stdout is unchanged (`/dev/null`). Runnerd's PID is still the launch shell's PID, so the identity marker and fingerprint are unchanged. - `remote-runner-recovery-diagnostics.ts` has a read-only `REMOTE_RUNNER_EXIT_EVIDENCE_SCRIPT`. It prints a 2 KiB tail of `runnerd.stderr.log` and of `runnerd.process-stderr.log`. It reads the session diagnostics directory first, then the shared runtime-root directory used by external Runners (Dot, Muse, grok_bot). It never reads through a symlink. Each file keeps its own share of the 4 KiB budget. - When recovery's process verification finds `process_not_running`, the diagnostic adds these fields: - `runnerRecoverableFailure`: a code-shaped string from `runner-state.json`; - `runnerDiagnostics`: the last 4 entries, redacted, 500 characters each; - `runnerExitEvidence`: the redacted file tails, 4 KiB at most. `native.remote_runner_recovery_failed` carries them. - The live process monitor's exit report now puts the durable state summary first, then the file tails. Before, it used one or the other. - `run-failure-diagnostics.ts` is unchanged. It still copies only the closed labels, so no free text reaches failure reports. ## Verification - `pnpm exec vitest run server/src/services/native-runtime/remote-runner-launch-stderr.test.ts`: the launch writer keeps stderr in the file, writes the identity marker with the child's PID, appends across relaunches, rotates an oversized file, trims a growing file while the child runs, and never writes through a symlink. - `pnpm exec vitest run server/src/services/native-runtime/remote-runner-recovery-diagnostics.test.ts`: the evidence script output is bounded and refuses symlinks. Redaction and bounds hold, and the new fields survive the event payload. - `pnpm exec vitest run server/src/services/native-runtime/native-session-executor.test.ts` passes (1374 tests). One expectation was updated for the combined exit report. - `npx tsc --noEmit -p server/tsconfig.json` is clean. - Older runner images: the script is server-side. It adds only `wc`, `tr`, `tail`, `cat`, `mv`, `sleep` and `kill`. The script already needed `node`, `date`, `chmod`, `mv` and `printf`, so any image that launched runnerd before has these tools. The runner content ID is unchanged, so the current Daytona image runs it unmodified. The restart-chaos waves run on that image. ## Risks - Low. A sandbox disk that is already full could make the stderr redirect fail. `exec ... 2>>file` then fails, and the launch reports `runner_remote_process_identity_unavailable` the same way a launch that cannot write its identity marker does. The marker is written first, in the same directory tree. - Stderr content stays in the sandbox. Only a redacted 4 KiB tail goes into the instance's own run log (run-log data path; not Telemetry and not Observability). - No wait is added before `turn.start`. The evidence read runs only on the recovery failure path, with its own 10 s bound. ## Model Used - Claude Opus 5.5 (`claude-opus-5-5`), via Claude Code with tool use (shell, file edits, test runs). ## 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:
DottaandClaude authored and GitHub committed
1 parent
b2779054d4
commit
80b2369f26
5 files changed
+265
-11
No files matched your search
@@ -1693,7 +1693,8 @@ fs.readFileSync = function(path, ...args) {
|
||||
});
|
||||
await expect(handle.completion).resolves.toMatchObject({
|
||||
code: null,
|
||||
stderr: "paperclip-runnerd: provider transport closed",
|
||||
// The durable exit state comes first, then the sandbox-local exit evidence.
|
||||
stderr: 'runner_remote_process_exited lifecycle=ready diagnostics=["last durable diagnostic"]\npaperclip-runnerd: provider transport closed',
|
||||
});
|
||||
|
||||
const launch = execute.mock.calls.find(
|
||||
|
||||
@@ -278,8 +278,8 @@ import { issueRecoveryActionService } from "../issue-recovery-actions.js";
|
||||
import { reportRunFailure } from "../run-failure-report.js";
|
||||
import {
|
||||
REMOTE_RECOVERY_MARKER_READ_SCRIPT, REMOTE_RECOVERY_PROCESS_CHECK_SCRIPT,
|
||||
RemoteRunnerRecoveryError, attachRemoteRunnerRecoveryDiagnostic, describeExitedRemoteRunner, readRemoteRunnerRecoveryError,
|
||||
remoteRecoveryProbeReason,
|
||||
REMOTE_RUNNER_EXIT_EVIDENCE_SCRIPT, RemoteRunnerRecoveryError, attachRemoteRunnerRecoveryDiagnostic, boundRemoteRunnerExitEvidence,
|
||||
describeExitedRemoteRunner, describeExitedRemoteRunnerReason, readRemoteRunnerRecoveryError, remoteRecoveryProbeReason,
|
||||
} from "./remote-runner-recovery-diagnostics.js";
|
||||
import { readRemoteRunnerRecoveryProbe, REMOTE_RUNNER_RECOVERY_PROBE_BUDGET_MS } from "./remote-runner-recovery-probe.js";
|
||||
import { describeOwnFailedAttachment, inspectRemoteWarmSessionRecovery, isSettledRemoteWarmControlState, summarizePostTerminalEvents, type RemoteWarmSessionRecovery, unsettledControllerCommands } from "./remote-warm-session-recovery.js";
|
||||
@@ -14556,10 +14556,44 @@ export const REMOTE_RUNNER_AUTHORITY_ARCHIVE_SCRIPT =
|
||||
'elif test -f "$1" && test ! -L "$1" && test -f "$3" && test ! -L "$3" && command -v cmp >/dev/null 2>&1 && cmp -s "$1" "$3"; then rm -f -- "$1"; ' +
|
||||
'else exit 1; fi; base64 < "$3"';
|
||||
|
||||
/**
|
||||
* A detached remote runnerd has no controller-side stderr. Its stderr goes to
|
||||
* this file in its private diagnostics directory instead of /dev/null, so the
|
||||
* reason a Runner exited stays in the sandbox for recovery to read. The file
|
||||
* never leaves the sandbox on its own; recovery reads a short redacted tail.
|
||||
*/
|
||||
export const REMOTE_RUNNER_PROCESS_STDERR_FILE = "runnerd.process-stderr.log";
|
||||
/** Above this size the file is rotated once at launch, so each runnerd starts with a fresh file. */
|
||||
export const REMOTE_RUNNER_PROCESS_STDERR_MAX_BYTES = 1_048_576;
|
||||
/** The disk backstop for one runnerd's lifetime: above this size the trimmer keeps the last 1 MiB. */
|
||||
export const REMOTE_RUNNER_PROCESS_STDERR_TRIM_BYTES = 8_388_608;
|
||||
const REMOTE_RUNNER_PROCESS_STDERR_KEEP_BYTES = 1_048_576;
|
||||
|
||||
/**
|
||||
* The disk backstop for a running runnerd's stderr file ($1 pid, $2 file). It
|
||||
* runs detached from runnerd (double fork) with its own argv and ends with
|
||||
* runnerd. Rewriting the kept tail can drop a line runnerd appends between the
|
||||
* copy and the rewrite, so it acts only past 8 MiB, which ordinary stderr
|
||||
* volume never reaches. runnerd's own exit reason is not on this stream: it
|
||||
* writes that to `runnerd.stderr.log` itself, which no trimmer touches.
|
||||
*/
|
||||
const REMOTE_RUNNER_PROCESS_STDERR_TRIM_SCRIPT =
|
||||
`pid=$1; log=$2; while kill -0 "$pid" 2>/dev/null; do sleep 15; size=$(wc -c 2>/dev/null < "$log" | tr -d " "); ` +
|
||||
`if test "\${size:-0}" -gt ${REMOTE_RUNNER_PROCESS_STDERR_TRIM_BYTES} && test -f "$log" && test ! -L "$log"; then ` +
|
||||
`tail -c ${REMOTE_RUNNER_PROCESS_STDERR_KEEP_BYTES} -- "$log" > "$log.trim" && cat -- "$log.trim" > "$log"; rm -f -- "$log.trim"; fi; done`;
|
||||
|
||||
export const REMOTE_RUNNER_CHILD_LAUNCH_SCRIPT =
|
||||
'set -eu; identity_path=$1; identity_nonce=$2; runner_instance_id=$3; diagnostics_directory=$4; shift 4; umask 077; test ! -L "$diagnostics_directory"; if test -e "$diagnostics_directory"; then test -d "$diagnostics_directory"; else mkdir -p -- "$diagnostics_directory"; fi; chmod 0700 "$diagnostics_directory"; started_at=$(date -u +"%Y-%m-%dT%H:%M:%S.%3NZ"); pid=$$; process_fingerprint=""; if ' +
|
||||
REMOTE_RUNNER_PROCESS_FINGERPRINT_SCRIPT +
|
||||
'; then :; else process_fingerprint=""; fi; identity_tmp="${identity_path}.tmp.$$"; printf "%s\\n%s\\n%s\\n%s\\n%s\\n" "$identity_nonce" "$$" "$started_at" "$runner_instance_id" "$process_fingerprint" > "$identity_tmp"; chmod 0600 "$identity_tmp"; mv -f -- "$identity_tmp" "$identity_path"; exec "$@"';
|
||||
'; then :; else process_fingerprint=""; fi; ' +
|
||||
// Bounded stderr evidence: rotate an oversized file once, then trim it in place while runnerd runs.
|
||||
// A symlink or non-file at the path keeps the old /dev/null behavior.
|
||||
`stderr_log="$diagnostics_directory/${REMOTE_RUNNER_PROCESS_STDERR_FILE}"; ` +
|
||||
'if test -L "$stderr_log" || { test -e "$stderr_log" && test ! -f "$stderr_log"; }; then stderr_log=/dev/null; else ' +
|
||||
'stderr_size=0; if test -f "$stderr_log"; then stderr_size=$(wc -c < "$stderr_log" | tr -d " "); fi; ' +
|
||||
`if test "\${stderr_size:-0}" -gt ${REMOTE_RUNNER_PROCESS_STDERR_MAX_BYTES}; then mv -f -- "$stderr_log" "$stderr_log.1"; fi; ` +
|
||||
`( ( exec sh -c '${REMOTE_RUNNER_PROCESS_STDERR_TRIM_SCRIPT}' paperclip-runner-stderr-trim "$pid" "$stderr_log" </dev/null >/dev/null 2>&1 ) & ); fi; ` +
|
||||
'identity_tmp="${identity_path}.tmp.$$"; printf "%s\\n%s\\n%s\\n%s\\n%s\\n" "$identity_nonce" "$$" "$started_at" "$runner_instance_id" "$process_fingerprint" > "$identity_tmp"; chmod 0600 "$identity_tmp"; mv -f -- "$identity_tmp" "$identity_path"; exec "$@" 2>>"$stderr_log"';
|
||||
|
||||
const REMOTE_RUNNER_FAILED_IDENTITY_CLEANUP_SCRIPT =
|
||||
'set -eu; identity_path=$1; expected_nonce=$2; expected_runner_id=$3; marker_wait=0; while { test ! -f "$identity_path" || test -L "$identity_path"; } && test "$marker_wait" -lt 50; do marker_wait=$((marker_wait + 1)); sleep 0.1; done; test -f "$identity_path" && test ! -L "$identity_path" || exit 3; { IFS= read -r nonce; IFS= read -r pid; IFS= read -r started_at; IFS= read -r runner_id; } < "$identity_path"; test "$nonce" = "$expected_nonce" && test "$runner_id" = "$expected_runner_id" && test -n "$started_at" || exit 4; case "$pid" in ""|*[!0-9]*) exit 4 ;; esac; test "$pid" -gt 0 || exit 4; if kill -0 "$pid" 2>/dev/null; then if test -r "/proc/$pid/cmdline"; then command_line=$(tr "\\000" "\\n" < "/proc/$pid/cmdline"); printf "%s\\n" "$command_line" | grep -Fqx -- "--runner-id" || exit 4; printf "%s\\n" "$command_line" | grep -Fqx -- "$expected_runner_id" || exit 4; fi; signal_target=$pid; if command -v ps >/dev/null 2>&1; then session_id=$(ps -o sid= -p "$pid" 2>/dev/null | tr -d " ") || true; if test "$session_id" = "$pid"; then signal_target="-$pid"; fi; fi; kill -TERM -- "$signal_target" 2>/dev/null || kill -TERM "$pid" 2>/dev/null || true; term_wait=0; while kill -0 "$pid" 2>/dev/null && test "$term_wait" -lt 50; do term_wait=$((term_wait + 1)); sleep 0.1; done; if kill -0 "$pid" 2>/dev/null; then kill -KILL -- "$signal_target" 2>/dev/null || kill -KILL "$pid" 2>/dev/null || true; kill_wait=0; while kill -0 "$pid" 2>/dev/null && test "$kill_wait" -lt 50; do kill_wait=$((kill_wait + 1)); sleep 0.1; done; fi; kill -0 "$pid" 2>/dev/null && exit 5; fi; test -f "$identity_path" && test ! -L "$identity_path" || exit 4; { IFS= read -r final_nonce; IFS= read -r final_pid; IFS= read -r final_started_at; IFS= read -r final_runner_id; } < "$identity_path"; test "$final_nonce" = "$nonce" && test "$final_pid" = "$pid" && test "$final_started_at" = "$started_at" && test "$final_runner_id" = "$runner_id" || exit 4; rm -f -- "$identity_path"';
|
||||
@@ -14704,7 +14738,15 @@ export async function verifyRemoteRunnerReattachment(input: {
|
||||
const verified = await check(undefined, probeDeadline);
|
||||
if (!verified.alive) {
|
||||
throw new RemoteRunnerRecoveryError({ stage: "process_verification", reason: verified.reason,
|
||||
...(verified.reason === "process_not_running" ? describeExitedRemoteRunner(runnerState) : {}) });
|
||||
...(verified.reason === "process_not_running" ? {
|
||||
...describeExitedRemoteRunner(runnerState),
|
||||
// Why the Runner exited, from its own durable state and sandbox-local files, so the run log names it.
|
||||
...describeExitedRemoteRunnerReason(runnerState, redactSensitiveText),
|
||||
// A session Runner logs beside its state; external (Dot, Muse, grok_bot) Runners log in the shared runtime root.
|
||||
...await readRemoteRunnerExitEvidence(runner, [posix.join(posix.dirname(stateDirectory), "diagnostics"),
|
||||
posix.join(target.remoteCwd, ".paperclip-runtime", "paperclip-runner", "diagnostics")],
|
||||
Math.min(input.recoveryDeadline ?? Number.POSITIVE_INFINITY, Date.now() + 10_000)),
|
||||
} : {}) });
|
||||
}
|
||||
// These checks authorize an attempt to reconnect, not the task itself. The
|
||||
// transport still requires authentication against the exact durable PRP key.
|
||||
@@ -14716,6 +14758,23 @@ export async function verifyRemoteRunnerReattachment(input: {
|
||||
};
|
||||
}
|
||||
|
||||
/** Best effort: a missing, slow or unreadable file leaves the recovery outcome unchanged. */
|
||||
async function readRemoteRunnerExitEvidence(runner: CommandManagedRuntimeRunner, diagnosticsDirectories: string[], deadline: number):
|
||||
Promise<{ runnerExitEvidence?: string }> {
|
||||
try {
|
||||
const result = await readRemoteRunnerRecoveryProbe({
|
||||
runner, stage: "process_verification", deadline, readOnly: true,
|
||||
request: { command: "sh", args: ["-c", REMOTE_RUNNER_EXIT_EVIDENCE_SCRIPT, "paperclip-runner-exit-evidence", ...diagnosticsDirectories],
|
||||
bypassSession: true },
|
||||
});
|
||||
if (result.exitCode !== 0 || result.timedOut) return {};
|
||||
const evidence = boundRemoteRunnerExitEvidence(result.stdout, redactSensitiveText);
|
||||
return evidence ? { runnerExitEvidence: evidence } : {};
|
||||
} catch {
|
||||
return {};
|
||||
}
|
||||
}
|
||||
|
||||
export async function verifyRemoteRunnerOrSettledExit(
|
||||
input: Parameters<typeof verifyRemoteRunnerReattachment>[0] & { providerAttempt: number },
|
||||
) {
|
||||
@@ -15102,7 +15161,7 @@ export function createRemoteRunnerProcessLauncher(input: {
|
||||
command: "sh",
|
||||
args: [
|
||||
"-c",
|
||||
'set -eu; directory=$1; file="$directory/runnerd.stderr.log"; test -d "$directory" && test ! -L "$directory" && test -f "$file" && test ! -L "$file"; tail -c 65536 -- "$file"',
|
||||
REMOTE_RUNNER_EXIT_EVIDENCE_SCRIPT,
|
||||
"paperclip-runner-diagnostics",
|
||||
input.diagnosticsDirectory,
|
||||
],
|
||||
@@ -15139,7 +15198,8 @@ export function createRemoteRunnerProcessLauncher(input: {
|
||||
code: null,
|
||||
signal: null,
|
||||
stdout: "",
|
||||
stderr: diagnosticTail || stateSummary,
|
||||
// The durable state names a graceful exit; the files name a panic or what runnerd wrote to stderr.
|
||||
stderr: diagnosticTail ? `${stateSummary}\n${diagnosticTail}` : stateSummary,
|
||||
};
|
||||
}
|
||||
})().catch((error: unknown) => {
|
||||
|
||||
@@ -0,0 +1,74 @@
|
||||
import { spawn } from "node:child_process";
|
||||
import { lstat, mkdir, mkdtemp, readFile, rm, stat, symlink, writeFile } from "node:fs/promises";
|
||||
import { tmpdir } from "node:os";
|
||||
import { join } from "node:path";
|
||||
import { describe, expect, it } from "vitest";
|
||||
import {
|
||||
REMOTE_RUNNER_CHILD_LAUNCH_SCRIPT, REMOTE_RUNNER_PROCESS_STDERR_FILE, REMOTE_RUNNER_PROCESS_STDERR_MAX_BYTES,
|
||||
REMOTE_RUNNER_PROCESS_STDERR_TRIM_BYTES,
|
||||
} from "./native-session-executor.js";
|
||||
|
||||
/** Runs the launch writer as the remote launcher does, with a Node child standing in for runnerd. */
|
||||
async function launch(root: string, childSource: string, script = REMOTE_RUNNER_CHILD_LAUNCH_SCRIPT) {
|
||||
const child = spawn("/bin/sh", ["-c", script, "paperclip-runner-child", join(root, "state", "identity"), "nonce", "runner-id",
|
||||
join(root, "diagnostics"), process.execPath, "-e", childSource, "--", "--runner-id", "runner-id"],
|
||||
{ stdio: ["ignore", "pipe", "pipe"] });
|
||||
let stderr = "";
|
||||
child.stderr.on("data", chunk => { stderr += String(chunk); });
|
||||
const code = await new Promise<number | null>(resolve => child.once("exit", resolve));
|
||||
return { code, stderr, pid: child.pid! };
|
||||
}
|
||||
|
||||
describe("remote runnerd stderr evidence", () => {
|
||||
it("keeps runnerd's stderr in its private diagnostics directory and still writes the identity marker", async () => {
|
||||
const root = await mkdtemp(join(tmpdir(), "runner-launch-stderr-"));
|
||||
try {
|
||||
await mkdir(join(root, "state"));
|
||||
const result = await launch(root, 'process.stderr.write("paperclip-runnerd: lease expired\\n"); process.exit(3)');
|
||||
expect(result.code).toBe(3);
|
||||
// Nothing reaches the launcher's own stderr; the reason stays in the sandbox file.
|
||||
expect(result.stderr).toBe("");
|
||||
const file = join(root, "diagnostics", REMOTE_RUNNER_PROCESS_STDERR_FILE);
|
||||
expect(await readFile(file, "utf8")).toBe("paperclip-runnerd: lease expired\n");
|
||||
expect((await stat(file)).mode & 0o077).toBe(0);
|
||||
expect((await readFile(join(root, "state", "identity"), "utf8")).split("\n")[1]).toBe(String(result.pid));
|
||||
// A second launch appends: the earlier exit reason survives the relaunch.
|
||||
await launch(root, 'process.stderr.write("second\\n")');
|
||||
expect(await readFile(file, "utf8")).toBe("paperclip-runnerd: lease expired\nsecond\n");
|
||||
} finally { await rm(root, { recursive: true, force: true }); }
|
||||
});
|
||||
|
||||
it("rotates an oversized file at launch and trims it while runnerd runs", async () => {
|
||||
const root = await mkdtemp(join(tmpdir(), "runner-launch-rotate-"));
|
||||
try {
|
||||
await mkdir(join(root, "state"));
|
||||
await mkdir(join(root, "diagnostics"), { mode: 0o700 });
|
||||
const file = join(root, "diagnostics", REMOTE_RUNNER_PROCESS_STDERR_FILE);
|
||||
await writeFile(file, "o".repeat(REMOTE_RUNNER_PROCESS_STDERR_MAX_BYTES + 1));
|
||||
await launch(root, 'process.stderr.write("fresh\\n")');
|
||||
expect((await stat(`${file}.1`)).size).toBe(REMOTE_RUNNER_PROCESS_STDERR_MAX_BYTES + 1);
|
||||
// The trimmer checks every 15 s in production; check it quickly here.
|
||||
const fast = REMOTE_RUNNER_CHILD_LAUNCH_SCRIPT.replace("sleep 15", "sleep 0.2");
|
||||
expect(fast).not.toBe(REMOTE_RUNNER_CHILD_LAUNCH_SCRIPT);
|
||||
await launch(root, `process.stderr.write("z".repeat(${REMOTE_RUNNER_PROCESS_STDERR_TRIM_BYTES + 4096}) + "\\nend\\n"); setTimeout(() => {}, 1500)`, fast);
|
||||
const size = (await stat(file)).size;
|
||||
// Past the 8 MiB backstop the trimmer keeps the last 1 MiB, the most recent lines included.
|
||||
expect(size).toBeLessThanOrEqual(REMOTE_RUNNER_PROCESS_STDERR_MAX_BYTES + 4096);
|
||||
expect((await readFile(file, "utf8")).endsWith("end\n")).toBe(true);
|
||||
} finally { await rm(root, { recursive: true, force: true }); }
|
||||
});
|
||||
|
||||
it("never writes through a symlink at the stderr path", async () => {
|
||||
const root = await mkdtemp(join(tmpdir(), "runner-launch-symlink-"));
|
||||
try {
|
||||
await mkdir(join(root, "state"));
|
||||
await mkdir(join(root, "diagnostics"), { mode: 0o700 });
|
||||
await writeFile(join(root, "target"), "");
|
||||
await symlink(join(root, "target"), join(root, "diagnostics", REMOTE_RUNNER_PROCESS_STDERR_FILE));
|
||||
const result = await launch(root, 'process.stderr.write("must not land\\n")');
|
||||
expect(result.code).toBe(0);
|
||||
expect(await readFile(join(root, "target"), "utf8")).toBe("");
|
||||
expect((await lstat(join(root, "diagnostics", REMOTE_RUNNER_PROCESS_STDERR_FILE))).isSymbolicLink()).toBe(true);
|
||||
} finally { await rm(root, { recursive: true, force: true }); }
|
||||
});
|
||||
});
|
||||
@@ -1,11 +1,12 @@
|
||||
import { execFileSync } from "node:child_process";
|
||||
import { mkdtemp, rm, symlink, writeFile } from "node:fs/promises";
|
||||
import { mkdir, mkdtemp, rm, symlink, writeFile } from "node:fs/promises";
|
||||
import { tmpdir } from "node:os";
|
||||
import { join } from "node:path";
|
||||
import { describe, expect, it } from "vitest";
|
||||
import {
|
||||
REMOTE_RECOVERY_MARKER_READ_SCRIPT, REMOTE_RECOVERY_PROCESS_CHECK_SCRIPT,
|
||||
RemoteRunnerRecoveryError, readRemoteRunnerRecoveryError,
|
||||
REMOTE_RECOVERY_MARKER_READ_SCRIPT, REMOTE_RECOVERY_PROCESS_CHECK_SCRIPT, REMOTE_RUNNER_EXIT_EVIDENCE_MAX_CHARS,
|
||||
REMOTE_RUNNER_EXIT_EVIDENCE_SCRIPT, RemoteRunnerRecoveryError, boundRemoteRunnerExitEvidence, describeExitedRemoteRunnerReason,
|
||||
readRemoteRunnerRecoveryDiagnostic, readRemoteRunnerRecoveryError,
|
||||
} from "./remote-runner-recovery-diagnostics.js";
|
||||
|
||||
function shellExit(script: string, args: string[]) {
|
||||
@@ -102,3 +103,57 @@ describe("remote recovery diagnostic shell receipts", () => {
|
||||
} finally { await rm(root, { recursive: true, force: true }); }
|
||||
});
|
||||
});
|
||||
|
||||
describe("exited remote runner evidence", () => {
|
||||
it("prints bounded tails of the exit diagnostic and redirected stderr, never through a symlink", async () => {
|
||||
const root = await mkdtemp(join(tmpdir(), "remote-exit-evidence-"));
|
||||
const directory = join(root, "diagnostics");
|
||||
try {
|
||||
expect(execFileSync("sh", ["-c", REMOTE_RUNNER_EXIT_EVIDENCE_SCRIPT, "t", directory], { encoding: "utf8" })).toBe("");
|
||||
await mkdir(directory);
|
||||
await writeFile(join(directory, "runnerd.stderr.log"), "paperclip-runnerd: transport reconnect grace exceeded");
|
||||
await writeFile(join(directory, "runnerd.process-stderr.log"), `${"x".repeat(10_000)}\nlast stderr line`);
|
||||
const output = execFileSync("sh", ["-c", REMOTE_RUNNER_EXIT_EVIDENCE_SCRIPT, "t", directory], { encoding: "utf8" });
|
||||
expect(output).toContain("== runnerd.stderr.log\npaperclip-runnerd: transport reconnect grace exceeded");
|
||||
expect(output).toContain("== runnerd.process-stderr.log\n");
|
||||
expect(output).toContain("last stderr line");
|
||||
expect(output.length).toBeLessThan(4_200);
|
||||
// Each file keeps its share: a long stderr tail cannot crowd out the exit diagnostic.
|
||||
const bounded = boundRemoteRunnerExitEvidence(output, text => text)!;
|
||||
expect(bounded.length).toBeLessThanOrEqual(REMOTE_RUNNER_EXIT_EVIDENCE_MAX_CHARS);
|
||||
expect(bounded).toContain("paperclip-runnerd: transport reconnect grace exceeded");
|
||||
expect(bounded).toContain("last stderr line");
|
||||
// The first candidate directory with evidence wins; a later shared directory is read only when it has none.
|
||||
const shared = join(root, "shared");
|
||||
await mkdir(shared);
|
||||
await writeFile(join(shared, "runnerd.stderr.log"), "shared runner exit");
|
||||
expect(execFileSync("sh", ["-c", REMOTE_RUNNER_EXIT_EVIDENCE_SCRIPT, "t", directory, shared], { encoding: "utf8" })).not.toContain("shared runner exit");
|
||||
expect(execFileSync("sh", ["-c", REMOTE_RUNNER_EXIT_EVIDENCE_SCRIPT, "t", join(root, "missing"), shared], { encoding: "utf8" }))
|
||||
.toBe("== runnerd.stderr.log\nshared runner exit\n");
|
||||
await writeFile(join(root, "secret"), "private");
|
||||
await rm(join(directory, "runnerd.stderr.log"));
|
||||
await symlink(join(root, "secret"), join(directory, "runnerd.stderr.log"));
|
||||
expect(execFileSync("sh", ["-c", REMOTE_RUNNER_EXIT_EVIDENCE_SCRIPT, "t", directory], { encoding: "utf8" })).not.toContain("private");
|
||||
} finally { await rm(root, { recursive: true, force: true }); }
|
||||
});
|
||||
|
||||
it("names the durable exit reason, redacted and bounded", () => {
|
||||
const redact = (text: string) => text.replaceAll("sk-secret", "[redacted]");
|
||||
expect(describeExitedRemoteRunnerReason({ lifecycle: "suspended", recoverableFailure: "transport_reconnect_grace_exceeded",
|
||||
diagnostics: ["a", "b", "c", "d", "token sk-secret", 7] }, redact)).toEqual({
|
||||
runnerRecoverableFailure: "transport_reconnect_grace_exceeded", runnerDiagnostics: ["b", "c", "d", "token [redacted]"] });
|
||||
expect(describeExitedRemoteRunnerReason({ recoverableFailure: "free text with spaces" }, redact)).toEqual({});
|
||||
expect(describeExitedRemoteRunnerReason(null, redact)).toEqual({});
|
||||
expect(boundRemoteRunnerExitEvidence(" ", redact)).toBeNull();
|
||||
expect(boundRemoteRunnerExitEvidence("y".repeat(9_000), redact)!.length).toBeLessThanOrEqual(REMOTE_RUNNER_EXIT_EVIDENCE_MAX_CHARS);
|
||||
});
|
||||
|
||||
it("keeps the exit reason through the recorded event payload", () => {
|
||||
const diagnostic = { stage: "process_verification", reason: "process_not_running", runnerLifecycle: "ready", runnerSettled: false,
|
||||
runnerRecoverableFailure: "lease_expired_requires_bootstrap", runnerDiagnostics: ["connection lease expired"],
|
||||
runnerExitEvidence: "== runnerd.stderr.log\npaperclip-runnerd: connection lease expired" };
|
||||
expect(readRemoteRunnerRecoveryDiagnostic(JSON.parse(JSON.stringify(diagnostic)))).toEqual(diagnostic);
|
||||
expect(readRemoteRunnerRecoveryDiagnostic({ ...diagnostic, runnerRecoverableFailure: "bad value", runnerDiagnostics: [1],
|
||||
runnerExitEvidence: 4 })).toEqual({ stage: "process_verification", reason: "process_not_running", runnerLifecycle: "ready", runnerSettled: false });
|
||||
});
|
||||
});
|
||||
@@ -23,6 +23,60 @@ export interface RemoteRunnerRecoveryDiagnostic {
|
||||
runnerSettled?: boolean;
|
||||
/** Present only as `false`: the controller journal proves no turn command was ever issued. */
|
||||
providerTurnIssued?: false;
|
||||
/** process_not_running: the exited Runner's own recoverable-failure code from its durable state. */
|
||||
runnerRecoverableFailure?: string;
|
||||
/** process_not_running: the last durable state diagnostics, redacted and bounded. */
|
||||
runnerDiagnostics?: string[];
|
||||
/** process_not_running: a redacted tail of the Runner's sandbox-local stderr and exit diagnostic files. */
|
||||
runnerExitEvidence?: string;
|
||||
}
|
||||
|
||||
/** Bounds for the exit evidence a recovery event carries. */
|
||||
export const REMOTE_RUNNER_EXIT_EVIDENCE_MAX_CHARS = 4_096;
|
||||
const RUNNER_DIAGNOSTIC_MAX_CHARS = 500;
|
||||
const RUNNER_DIAGNOSTIC_COUNT = 4;
|
||||
const RECOVERABLE_FAILURE_PATTERN = /^[A-Za-z0-9_.:-]{1,120}$/;
|
||||
|
||||
/**
|
||||
* Prints a bounded tail of the exited Runner's sandbox-local exit evidence: the
|
||||
* bounded exit diagnostic runnerd writes itself (`runnerd.stderr.log`) and its
|
||||
* redirected stderr (`runnerd.process-stderr.log`). Each argument is a candidate
|
||||
* diagnostics directory, most specific first; the first that holds either file
|
||||
* is the one read. Read-only; missing or unsafe files print nothing.
|
||||
*/
|
||||
export const REMOTE_RUNNER_EXIT_EVIDENCE_SCRIPT =
|
||||
'for directory in "$@"; do test -d "$directory" && test ! -L "$directory" || continue; found=""; ' +
|
||||
'for name in runnerd.stderr.log runnerd.process-stderr.log; do file="$directory/$name"; ' +
|
||||
'if test -f "$file" && test ! -L "$file"; then found=1; printf "== %s\\n" "$name"; tail -c 2048 -- "$file"; printf "\\n"; fi; done; ' +
|
||||
'test -z "$found" || exit 0; done; exit 0';
|
||||
|
||||
/** The durable reason an exited Runner recorded, redacted and bounded for a run event. */
|
||||
export function describeExitedRemoteRunnerReason(state: Record<string, unknown> | null, redact: (text: string) => string):
|
||||
Pick<RemoteRunnerRecoveryDiagnostic, "runnerRecoverableFailure" | "runnerDiagnostics"> {
|
||||
if (!state) return {};
|
||||
const failure = typeof state.recoverableFailure === "string" ? state.recoverableFailure
|
||||
: typeof state.recoverable_failure === "string" ? state.recoverable_failure : null;
|
||||
const diagnostics = Array.isArray(state.diagnostics)
|
||||
? state.diagnostics.filter((value): value is string => typeof value === "string").slice(-RUNNER_DIAGNOSTIC_COUNT)
|
||||
.map(value => redact(value).slice(-RUNNER_DIAGNOSTIC_MAX_CHARS))
|
||||
: [];
|
||||
return {
|
||||
...(failure && RECOVERABLE_FAILURE_PATTERN.test(failure) ? { runnerRecoverableFailure: failure } : {}),
|
||||
...(diagnostics.length ? { runnerDiagnostics: diagnostics } : {}),
|
||||
};
|
||||
}
|
||||
|
||||
/** The tail of the exit evidence script's output, redacted and bounded; null when there is none. */
|
||||
export function boundRemoteRunnerExitEvidence(output: string, redact: (text: string) => string): string | null {
|
||||
// Each file gets its own share of the budget, so a long stderr tail cannot crowd out the exit diagnostic.
|
||||
const sections = redact(output).split(/^(?=== runnerd\.)/m).map(section => section.trim()).filter(Boolean);
|
||||
if (!sections.length) return null;
|
||||
const share = Math.floor(REMOTE_RUNNER_EXIT_EVIDENCE_MAX_CHARS / sections.length) - 1;
|
||||
return sections.map(section => {
|
||||
if (section.length <= share) return section;
|
||||
const header = section.slice(0, section.indexOf("\n") + 1);
|
||||
return header + section.slice(-(share - header.length));
|
||||
}).join("\n");
|
||||
}
|
||||
|
||||
export function describeExitedRemoteRunner(state: Record<string, unknown>): Pick<RemoteRunnerRecoveryDiagnostic,
|
||||
@@ -57,13 +111,23 @@ export class RemoteRunnerRecoveryError extends Error {
|
||||
export function readRemoteRunnerRecoveryDiagnostic(value: unknown): RemoteRunnerRecoveryDiagnostic | null {
|
||||
if (!value || typeof value !== "object") return null;
|
||||
try {
|
||||
const { stage, reason, runnerLifecycle, runnerSettled, providerTurnIssued } = value as Record<string, unknown>;
|
||||
const { stage, reason, runnerLifecycle, runnerSettled, providerTurnIssued, runnerRecoverableFailure, runnerDiagnostics,
|
||||
runnerExitEvidence } = value as Record<string, unknown>;
|
||||
if (!stages.some(candidate => candidate === stage) || !reasons.some(candidate => candidate === reason)) return null;
|
||||
const diagnostics = Array.isArray(runnerDiagnostics)
|
||||
? runnerDiagnostics.filter((entry): entry is string => typeof entry === "string").slice(-RUNNER_DIAGNOSTIC_COUNT)
|
||||
.map(entry => entry.slice(-RUNNER_DIAGNOSTIC_MAX_CHARS))
|
||||
: [];
|
||||
return {
|
||||
stage, reason,
|
||||
...(runnerLifecycles.some(candidate => candidate === runnerLifecycle) ? { runnerLifecycle } : {}),
|
||||
...(typeof runnerSettled === "boolean" ? { runnerSettled } : {}),
|
||||
...(providerTurnIssued === false ? { providerTurnIssued } : {}),
|
||||
...(typeof runnerRecoverableFailure === "string" && RECOVERABLE_FAILURE_PATTERN.test(runnerRecoverableFailure)
|
||||
? { runnerRecoverableFailure } : {}),
|
||||
...(diagnostics.length ? { runnerDiagnostics: diagnostics } : {}),
|
||||
...(typeof runnerExitEvidence === "string" && runnerExitEvidence
|
||||
? { runnerExitEvidence: runnerExitEvidence.slice(-REMOTE_RUNNER_EXIT_EVIDENCE_MAX_CHARS) } : {}),
|
||||
} as RemoteRunnerRecoveryDiagnostic;
|
||||
} catch {
|
||||
return null;
|
||||
|
||||
Reference in new issue
Block a user