From 80b2369f26983be3bb8459f00f9cc6f7d271d7f3 Mon Sep 17 00:00:00 2001 From: Dotta <34892728+cryppadotta@users.noreply.github.com> Date: Wed, 11 Nov 2026 15:31:04 -0600 Subject: [PATCH] fix(native): keep remote runnerd exit evidence and report it on failed recovery (#20907) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ## 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 --- .../native-session-executor.test.ts | 3 +- .../native-runtime/native-session-executor.ts | 72 ++++++++++++++++-- .../remote-runner-launch-stderr.test.ts | 74 +++++++++++++++++++ ...remote-runner-recovery-diagnostics.test.ts | 61 ++++++++++++++- .../remote-runner-recovery-diagnostics.ts | 66 ++++++++++++++++- 5 files changed, 265 insertions(+), 11 deletions(-) create mode 100644 server/src/services/native-runtime/remote-runner-launch-stderr.test.ts diff --git a/server/src/services/native-runtime/native-session-executor.test.ts b/server/src/services/native-runtime/native-session-executor.test.ts index f0835396b15..4d03417458e 100644 --- a/server/src/services/native-runtime/native-session-executor.test.ts +++ b/server/src/services/native-runtime/native-session-executor.test.ts @@ -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( diff --git a/server/src/services/native-runtime/native-session-executor.ts b/server/src/services/native-runtime/native-session-executor.ts index 8cf6139f013..6dc376b8069 100644 --- a/server/src/services/native-runtime/native-session-executor.ts +++ b/server/src/services/native-runtime/native-session-executor.ts @@ -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 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[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) => { diff --git a/server/src/services/native-runtime/remote-runner-launch-stderr.test.ts b/server/src/services/native-runtime/remote-runner-launch-stderr.test.ts new file mode 100644 index 00000000000..4a6406a9a65 --- /dev/null +++ b/server/src/services/native-runtime/remote-runner-launch-stderr.test.ts @@ -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(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 }); } + }); +}); diff --git a/server/src/services/native-runtime/remote-runner-recovery-diagnostics.test.ts b/server/src/services/native-runtime/remote-runner-recovery-diagnostics.test.ts index 5fa683e2a49..5b504458ae2 100644 --- a/server/src/services/native-runtime/remote-runner-recovery-diagnostics.test.ts +++ b/server/src/services/native-runtime/remote-runner-recovery-diagnostics.test.ts @@ -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 }); + }); +}); diff --git a/server/src/services/native-runtime/remote-runner-recovery-diagnostics.ts b/server/src/services/native-runtime/remote-runner-recovery-diagnostics.ts index cd6b7710842..c35cee2a9db 100644 --- a/server/src/services/native-runtime/remote-runner-recovery-diagnostics.ts +++ b/server/src/services/native-runtime/remote-runner-recovery-diagnostics.ts @@ -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 | null, redact: (text: string) => string): + Pick { + 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): Pick; + const { stage, reason, runnerLifecycle, runnerSettled, providerTurnIssued, runnerRecoverableFailure, runnerDiagnostics, + runnerExitEvidence } = value as Record; 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;