mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-11-07 06:16:06 -10:00
fix(recovery): require a 1 s start-time gap and treat EPERM as alive in owner proofs (#19848)
## Thinking Path > - Paperclip is the open source app people use to manage AI agents for work > - After a restart, recovery code decides whether the process that owns an in-progress run is gone > - Two proofs compare process start times to the millisecond, but `ps -o lstart` on macOS and BSD reports whole seconds > - So a live owner can look like a reused PID, and recovery can release it while it still runs > - Signal-0 handling also disagrees: one check treats EPERM as dead, while all others treat it as alive > - This pull request puts one start-time rule and one EPERM rule in `controller-process-identity.ts` and uses them at every site the Phase 0 ownership inventory named > - The benefit is that no proof releases a live owner because of clock precision or a permission error ## Linked Issues or Issue Description **Bug description** The Phase 0 ownership inventory (finding 1) found inconsistent "owner gone" proofs. `native-failed-run-owner-release.ts` (`recordedProcessMayBeLive`, `runProcessMayBeLive`) and `native-session-executor.ts` (`verifiedRecoveryProcessIsAlive`) treat any start-time difference of 1 ms or more as a reused PID. `native-restart-recovery.ts` and `controllerProcessExited` require a gap of at least 1 s. `local-service-supervisor.ts` (`isPidAlive`, `isProcessGroupAlive`) treats EPERM as dead. **Steps to reproduce** 1. On macOS, record a live process start time with millisecond precision. 2. Run the abandoned-owner release pass, or the recovered-runner liveness check, against that live PID. 3. The pass releases the owner, or the check reports the runner as gone. **Expected behavior** A sub-second start-time gap is ambiguous and keeps the owner. EPERM means the process exists. Refs #19846 ## What Changed - `controller-process-identity.ts`: export `processExists` (EPERM = alive) and `processStartsDefinitelyDiffer` (gap >= 1 s; a missing time proves nothing). `controllerProcessExited` uses the new helper. - `native-failed-run-owner-release.ts`: the controller and run-process checks use the shared helpers instead of exact millisecond equality. - `native-session-executor.ts`: `verifiedRecoveryProcessIsAlive` accepts a start time within 1 s as the same runner. Its signal path uses the same check. - `native-restart-recovery.ts`: `definitivelyDifferentProcessStart` delegates to the shared helper. No behavior change. - `local-service-supervisor.ts`: `isPidAlive` and `isProcessGroupAlive` treat EPERM as alive. ## Verification - New `controller-process-identity.test.ts`: the 1 s boundary, EPERM and ESRCH for every signal-0 check, and a live spawned runner whose recorded start is 500 ms off. - `native-failed-run-owner-release.test.ts`: two new cases (controller and run process) with a live child and a recorded start 500 ms off. The owner stays `observed`. - Red before the fix: with the old call sites, all 4 new cases fail (`releaseAbandonedNativeOwners` returns 1 and releases the live owner; EPERM returns false; the live runner reads as gone). Green after the fix. - `npx vitest run src/services/controller-process-identity.test.ts src/services/native-runtime/native-failed-run-owner-release.test.ts src/services/native-runtime/native-restart-recovery.test.ts src/__tests__/local-service-supervisor.test.ts`: 59 passed. ## Risks - Low risk. The change only makes proofs stricter: a sub-second gap or EPERM now keeps an owner that the old code released. Such a row waits for the existing lease, TTL, or real process exit. - A recycled PID whose new process started within 1 s of the recorded one now stays held until it exits. That is the same rule the takeover path already used. - Previous-release story: no persisted shape changes. Rows saved by the previous release are evaluated with the stricter rule. ## Model Used - Claude Opus 5.5 (`claude-opus-5-5`), Anthropic, used with tool use and code execution in Claude Code. ## 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 Opus 5.5 <[email protected]>
This commit is contained in:
1 parent
e2d490c61b
commit
630411af53
7 files changed
+124
-32
No files matched your search
@@ -0,0 +1,53 @@
|
||||
import { spawn } from "node:child_process";
|
||||
import { once } from "node:events";
|
||||
import { afterEach, describe, expect, it, vi } from "vitest";
|
||||
import { processExists, processStartsDefinitelyDiffer } from "./controller-process-identity.js";
|
||||
import { isPidAlive, isProcessGroupAlive } from "./local-service-supervisor.js";
|
||||
import { readProcessStartedAt } from "./hot-restart.js";
|
||||
import { verifiedRecoveryProcessIsAlive } from "./native-runtime/native-session-executor.js";
|
||||
|
||||
describe("shared process identity proof", () => {
|
||||
afterEach(() => vi.restoreAllMocks());
|
||||
|
||||
it("needs a start-time gap of at least one second to prove a recycled PID", () => {
|
||||
const at = new Date("2026-11-07T10:00:00.000Z");
|
||||
expect(processStartsDefinitelyDiffer(at, new Date(at.getTime() + 999))).toBe(false);
|
||||
expect(processStartsDefinitelyDiffer(at, "2026-11-07T09:59:59.001Z")).toBe(false);
|
||||
expect(processStartsDefinitelyDiffer(at, new Date(at.getTime() + 1_000))).toBe(true);
|
||||
expect(processStartsDefinitelyDiffer(at, null)).toBe(false);
|
||||
expect(processStartsDefinitelyDiffer("not a date", at)).toBe(false);
|
||||
});
|
||||
|
||||
it("treats EPERM as a live process in every signal-0 check", () => {
|
||||
vi.spyOn(process, "kill").mockImplementation(() => {
|
||||
throw Object.assign(new Error("operation not permitted"), { code: "EPERM" });
|
||||
});
|
||||
expect(processExists(4242)).toBe(true);
|
||||
expect(isPidAlive(4242)).toBe(true);
|
||||
if (process.platform !== "win32" && process.platform !== "linux") expect(isProcessGroupAlive(4242)).toBe(true);
|
||||
});
|
||||
|
||||
it("treats ESRCH as a gone process", () => {
|
||||
vi.spyOn(process, "kill").mockImplementation(() => {
|
||||
throw Object.assign(new Error("no such process"), { code: "ESRCH" });
|
||||
});
|
||||
expect(processExists(4242)).toBe(false);
|
||||
expect(isPidAlive(4242)).toBe(false);
|
||||
});
|
||||
|
||||
it.skipIf(process.platform === "win32")("keeps a live recovered runner whose recorded start differs by under a second", async () => {
|
||||
const live = spawn(process.execPath, ["-e", "setInterval(() => {}, 1_000)"], { stdio: "ignore" });
|
||||
await once(live, "spawn");
|
||||
try {
|
||||
const observed = new Date((await readProcessStartedAt(live.pid!))!);
|
||||
const startedAt = new Date(observed.getTime() + 500).toISOString();
|
||||
await expect(verifiedRecoveryProcessIsAlive({ pid: live.pid!, startedAt })).resolves.toBe(true);
|
||||
const recycled = new Date(observed.getTime() + 5_000).toISOString();
|
||||
await expect(verifiedRecoveryProcessIsAlive({ pid: live.pid!, startedAt: recycled })).resolves.toBe(false);
|
||||
} finally {
|
||||
const exited = once(live, "exit");
|
||||
live.kill("SIGKILL");
|
||||
await exited;
|
||||
}
|
||||
});
|
||||
});
|
||||
@@ -68,7 +68,11 @@ export function readControllerProcess(value: unknown): ControllerProcess | null
|
||||
processStartedAt: typeof record.processStartedAt === "string" ? record.processStartedAt : null };
|
||||
}
|
||||
|
||||
function processExists(pid: number): boolean {
|
||||
/**
|
||||
* True when some process owns the PID in this PID space. EPERM means the
|
||||
* process exists but belongs to another user, so it counts as alive.
|
||||
*/
|
||||
export function processExists(pid: number): boolean {
|
||||
try {
|
||||
process.kill(pid, 0);
|
||||
return true;
|
||||
@@ -77,6 +81,24 @@ function processExists(pid: number): boolean {
|
||||
}
|
||||
}
|
||||
|
||||
/** Process start times closer than this may be the same process. */
|
||||
export const PROCESS_START_PRECISION_MS = 1_000;
|
||||
|
||||
/**
|
||||
* True only when two start times for one PID prove different processes.
|
||||
* `ps -o lstart` on macOS and BSD has whole-second precision, while a recorded
|
||||
* start can come from a millisecond clock, so a sub-second gap is ambiguous
|
||||
* and fails closed (same process). A missing or unparsable time proves nothing.
|
||||
*/
|
||||
export function processStartsDefinitelyDiffer(
|
||||
recorded: Date | string | null | undefined,
|
||||
observed: Date | string | null | undefined,
|
||||
): boolean {
|
||||
const left = recorded instanceof Date ? recorded.getTime() : Date.parse(recorded ?? "");
|
||||
const right = observed instanceof Date ? observed.getTime() : Date.parse(observed ?? "");
|
||||
return Number.isFinite(left) && Number.isFinite(right) && Math.abs(left - right) >= PROCESS_START_PRECISION_MS;
|
||||
}
|
||||
|
||||
/** True only with proof, in this process's own PID space, that the recorded
|
||||
* server process has exited. Another space, an unreadable space, this server,
|
||||
* or an ambiguous live PID returns false. */
|
||||
@@ -85,7 +107,6 @@ export async function controllerProcessExited(controller: ControllerProcess): Pr
|
||||
if (!processExists(controller.pid)) return true;
|
||||
// The PID now belongs to a live process, possibly this restarted server.
|
||||
// Only a definitely different start time proves the recorded process is gone.
|
||||
const recorded = Date.parse(controller.processStartedAt ?? "");
|
||||
const observed = await observedProcessStartedAt(controller.pid);
|
||||
return Number.isFinite(recorded) && observed !== null && Math.abs(observed - recorded) >= 1_000;
|
||||
return observed !== null && processStartsDefinitelyDiffer(controller.processStartedAt, new Date(observed));
|
||||
}
|
||||
@@ -6,6 +6,7 @@ import path from "node:path";
|
||||
import { setTimeout as delay } from "node:timers/promises";
|
||||
import { promisify } from "node:util";
|
||||
import { resolvePaperclipInstanceRoot } from "../home-paths.js";
|
||||
import { processExists } from "./controller-process-identity.js";
|
||||
|
||||
const execFileAsync = promisify(execFile);
|
||||
|
||||
@@ -242,24 +243,16 @@ export async function findLocalServiceRegistryRecordByRuntimeServiceId(input: {
|
||||
return candidate;
|
||||
}
|
||||
|
||||
/** EPERM means the process exists under another user, so it is alive. */
|
||||
export function isPidAlive(pid: number) {
|
||||
if (!Number.isInteger(pid) || pid <= 0) return false;
|
||||
try {
|
||||
process.kill(pid, 0);
|
||||
return true;
|
||||
} catch {
|
||||
return false;
|
||||
}
|
||||
return processExists(pid);
|
||||
}
|
||||
|
||||
export function isProcessGroupAlive(processGroupId: number | null | undefined) {
|
||||
if (process.platform === "win32") return false;
|
||||
if (typeof processGroupId !== "number" || !Number.isInteger(processGroupId) || processGroupId <= 0) return false;
|
||||
try {
|
||||
process.kill(-processGroupId, 0);
|
||||
} catch {
|
||||
return false;
|
||||
}
|
||||
if (!processExists(-processGroupId)) return false;
|
||||
|
||||
if (process.platform === "linux") {
|
||||
const liveMember = readLinuxProcessGroupActivity(processGroupId);
|
||||
|
||||
@@ -17,6 +17,7 @@ import {
|
||||
} from "@paperclipai/db";
|
||||
import { startEmbeddedPostgresTestDatabase } from "../../__tests__/helpers/embedded-postgres.js";
|
||||
import { agentExecutionsHaveStopped } from "../agent-execution-stop.js";
|
||||
import { readProcessStartedAt } from "../hot-restart.js";
|
||||
import { DELIVERY_QUEUES } from "../delivery-work-notifications.js";
|
||||
import { environmentService } from "../environments.js";
|
||||
import { executionControlSchedule } from "../execution-control-work.js";
|
||||
@@ -253,6 +254,32 @@ describe("failed native run owner release", () => {
|
||||
}
|
||||
});
|
||||
|
||||
// `ps -o lstart` on macOS reports whole seconds, while a recorded start can
|
||||
// carry milliseconds. A sub-second gap must not be read as a recycled PID.
|
||||
it.each(["controller", "run process"])("keeps the owner when the live %s start time differs by under a second", async (holder) => {
|
||||
const { runId } = await nativeRun({ status: "failed", errorCode: "adapter_failed",
|
||||
coordinator: { leaseOwner: `default:resume:${randomUUID()}`, leaseExpiresAt: new Date(0) } });
|
||||
const live = spawn(process.execPath, ["-e", "setInterval(() => {}, 1_000)"], { stdio: "ignore", detached: true });
|
||||
await once(live, "spawn");
|
||||
try {
|
||||
const observed = new Date((await readProcessStartedAt(live.pid!))!);
|
||||
const recorded = new Date(observed.getTime() + 500);
|
||||
if (holder === "controller") {
|
||||
await db.update(nativeRunFinalizations).set({ controllerPid: live.pid!, controllerBootId: randomUUID(),
|
||||
controllerProcessStartedAt: recorded }).where(eq(nativeRunFinalizations.runId, runId));
|
||||
} else {
|
||||
await db.update(heartbeatRuns).set({ processPid: live.pid!, processGroupId: live.pid!, processStartedAt: recorded })
|
||||
.where(eq(heartbeatRuns.id, runId));
|
||||
}
|
||||
await expect(releaseAbandonedNativeOwners(db)).resolves.toBe(0);
|
||||
expect(await coordinator(runId)).toMatchObject({ phase: "observed", leaseOwner: expect.any(String) });
|
||||
} finally {
|
||||
const exited = once(live, "exit");
|
||||
live.kill("SIGKILL");
|
||||
await exited;
|
||||
}
|
||||
});
|
||||
|
||||
it("rotates bounded passes past owners that a live controller still holds", async () => {
|
||||
const runs = await Promise.all([0, 1, 2].map(() => nativeRun({ status: "failed", errorCode: "adapter_failed",
|
||||
coordinator: { leaseOwner: `default:resume:${randomUUID()}`, leaseExpiresAt: new Date(0) } })));
|
||||
|
||||
@@ -2,6 +2,7 @@ import { and, asc, eq, gt, inArray, isNotNull, isNull, lte, or, sql } from "driz
|
||||
import { environmentLeases, heartbeatRuns, issues, nativeRunFinalizations, nativeRunResults, type Db } from "@paperclipai/db";
|
||||
import { logger } from "../../middleware/logger.js";
|
||||
import { adapterExecutionControls } from "../adapter-execution-control.js";
|
||||
import { processExists, processStartsDefinitelyDiffer } from "../controller-process-identity.js";
|
||||
import { logActivity, publishActivity, type ActivityPublication } from "../activity-log.js";
|
||||
import { DELIVERY_QUEUES, notifyDeliveryWork } from "../delivery-work-notifications.js";
|
||||
import { notifyExecutionRunWork } from "../execution-control-notifications.js";
|
||||
@@ -85,8 +86,7 @@ export async function nextAbandonedNativeOwnerReleaseAt(db: Db): Promise<Date |
|
||||
}
|
||||
|
||||
function processAbsent(pid: number): boolean {
|
||||
try { process.kill(pid, 0); return false; }
|
||||
catch (error) { return (error as NodeJS.ErrnoException).code === "ESRCH"; }
|
||||
return !processExists(pid);
|
||||
}
|
||||
|
||||
/** True unless the recorded process is gone or provably a different process. */
|
||||
@@ -94,7 +94,7 @@ async function recordedProcessMayBeLive(pid: number | null, startedAt: Date | nu
|
||||
if (!pid || processAbsent(pid)) return false;
|
||||
if (!startedAt) return true;
|
||||
const observed = await readProcessStartedAt(pid).catch(() => null);
|
||||
return !observed || new Date(observed).getTime() === startedAt.getTime();
|
||||
return !processStartsDefinitelyDiffer(startedAt, observed);
|
||||
}
|
||||
|
||||
/**
|
||||
@@ -110,7 +110,7 @@ async function runProcessMayBeLive(run: Run, now: Date): Promise<boolean> {
|
||||
let groupAlive = Boolean(run.processGroupId && !processAbsent(-run.processGroupId));
|
||||
if (processAlive && run.processStartedAt) {
|
||||
const observed = await readProcessStartedAt(run.processPid!).catch(() => null);
|
||||
if (observed && new Date(observed).getTime() !== run.processStartedAt.getTime()) {
|
||||
if (processStartsDefinitelyDiffer(run.processStartedAt, observed)) {
|
||||
processAlive = false;
|
||||
if (run.processGroupId === run.processPid) groupAlive = false;
|
||||
}
|
||||
|
||||
@@ -35,6 +35,7 @@ import {
|
||||
} from "@paperclipai/db";
|
||||
import { REMOTE_CONTROLLER_LEASE_MS } from "./native-runner-recovery-contract.js";
|
||||
import { readProcessStartedAt } from "../hot-restart.js";
|
||||
import { processStartsDefinitelyDiffer } from "../controller-process-identity.js";
|
||||
import { getServerProcessStartedAt } from "../../server-info.js";
|
||||
import { redactSensitiveText } from "../../redaction.js";
|
||||
import { isUniqueViolation } from "../../db-errors.js";
|
||||
@@ -349,12 +350,8 @@ function definitivelyDifferentProcessStart(
|
||||
left: Date | null,
|
||||
right: Date | null,
|
||||
): boolean {
|
||||
if (left === null || right === null) return false;
|
||||
// `ps -o lstart` has only whole-second precision on macOS and BSD. A
|
||||
// sub-second disagreement can therefore be the same process when one probe
|
||||
// fell back to a higher-precision spawn timestamp. Treat it as ambiguous and
|
||||
// fail closed instead of declaring the live PID recycled.
|
||||
return Math.abs(left.getTime() - right.getTime()) >= 1_000;
|
||||
// Shared with every other owner proof: a sub-second gap is ambiguous.
|
||||
return processStartsDefinitelyDiffer(left, right);
|
||||
}
|
||||
|
||||
export async function evaluateNativeControllerTakeover(input: {
|
||||
|
||||
@@ -296,6 +296,7 @@ import { removeNativeHarnessBackup } from "./native-harness-backup-cleanup.js";
|
||||
import { registerLiveRunnerGoalController } from "../runner-goal-control-broker.js";
|
||||
import { applyRunnerGoalPrpEvent } from "../runner-goals.js";
|
||||
import { readProcessStartedAt } from "../hot-restart.js";
|
||||
import { processExists, processStartsDefinitelyDiffer } from "../controller-process-identity.js";
|
||||
import {
|
||||
NativeRunnerOwnershipUnverifiedError,
|
||||
isNativeRunnerOwnershipHeld,
|
||||
@@ -581,21 +582,21 @@ const nativeRuntimeRequestResolutions = new Map<
|
||||
NativeRuntimeRequestResolution
|
||||
>();
|
||||
|
||||
async function verifiedRecoveryProcessIsAlive(input: {
|
||||
/**
|
||||
* True when the recorded runner still owns its PID. A start time within the
|
||||
* shared precision window is the same process: `ps -o lstart` on macOS has
|
||||
* whole-second precision, so an exact match would call a live runner gone.
|
||||
*/
|
||||
export async function verifiedRecoveryProcessIsAlive(input: {
|
||||
pid: number;
|
||||
startedAt: string;
|
||||
}): Promise<boolean> {
|
||||
try {
|
||||
process.kill(input.pid, 0);
|
||||
} catch (error) {
|
||||
if ((error as NodeJS.ErrnoException | undefined)?.code !== "EPERM")
|
||||
return false;
|
||||
}
|
||||
if (!processExists(input.pid)) return false;
|
||||
try {
|
||||
const observed = await readProcessStartedAt(input.pid);
|
||||
return (
|
||||
observed !== null &&
|
||||
new Date(observed).getTime() === new Date(input.startedAt).getTime()
|
||||
!processStartsDefinitelyDiffer(input.startedAt, observed)
|
||||
);
|
||||
} catch {
|
||||
return false;
|
||||
|
||||
Reference in new issue
Block a user