mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-11-13 15:55:46 +01:00
## Thinking Path > - Paperclip is the open source app people use to manage AI agents for work > - After a restart, a remote run resumes on the same heartbeat run under a restart claim: a lease on its native coordinator row, 60 s for a remote claim (`REMOTE_CONTROLLER_LEASE_MS`) > - Preparation then runs before the native executor takes its own lease renewal. It includes the run-log begin and the workspace restore, which can each wait out a storage outage for minutes (#20299) > - Preparation renewed the claim only for `reattach_remote_runner`. A `bootstrap_incomplete` or resume claim kept its 60 s lease with nothing renewing it > - So a preparation wait longer than a minute let the lease lapse. The run failed at its next writer-authority check (`run_log_writer_authority_lost`) the moment storage came back > - This PR renews every remote restart claim during preparation. When the same owner's executor claims at the next attempt, it takes over that renewal > - The benefit is that a resumed remote run survives a long storage outage during preparation instead of failing as soon as storage returns ## Linked Issues or Issue Description **What happened?** In restart-chaos waves on Daytona R1 with `--storage s3 --storage-faults ST1` and K2 at +110 s, a resumed `bootstrap_incomplete` run's `heartbeat.prepare.run_output` ended `failed` right after the outage ended: - `w-20261110T101517-s11936` t01, run `9d39550a`. The claim was at 10:19:55 and the outage ended at 10:22:18.15. `run_output` failed at 10:22:18.17, after 141 s. - `w-20261110T081647-s11936` t02, run `9da10424`. The claim was at 08:21:29 and the outage ended at 08:23:30. During the outage the journal claim fails on its head `GET` before it checks authority. The first attempt after the outage reaches `claimFrom`'s `assertAuthority` (`run-log-authority.ts`), which requires a live coordinator lease. That lease expired 60 s after the claim. **Why not just widen the condition?** For a `bootstrap_incomplete` claim, the executor's own claim moves the coordinator attempt to N+1 (`nextNativeProviderAttempt`). `startNativeSessionExecutionLeaseRenewal` shares one renewal per lease owner and threw `native_session_renewal_binding_changed` when the attempt differed. That is presumably why preparation renewal was limited to reattach claims. **Related:** #20460 (live status while a run waits out a storage outage). #20514 settles a failure that this lapse used to leave silent. ## What Changed - `heartbeat/recovery.ts`: start the preparation lease renewal for every remote restart claim (`scope.remote`), not only `reattach_remote_runner`. - `native-runtime/native-execution-lease.ts`: - When the same owner's executor starts its renewal at a higher attempt, it takes over the shared renewal, rebinding the attempt and `onLost`. A lower attempt or any other binding change still throws. - A renewal that failed under the old binding is not counted as a loss. - A failed renewal is not a loss when the coordinator shows the same owner already at a higher attempt (the executor's claim committed while the renewal was in flight). The renewal deadline still ends ownership if no executor takes over. - Tests: one recovery case and three lease-renewal cases (below). ## Verification - `cd server && npx vitest run src/services/native-runtime/native-execution-lease.test.ts src/services/heartbeat/recovery.test.ts src/services/native-runtime/native-execution-lease-reacquire.test.ts src/services/native-runtime/native-runner-restart-lease-renewal.integration.test.ts src/services/native-runtime/native-runner-restart-preparation.integration.test.ts`: 143 pass. `npx tsc --noEmit`: pass. - Red/green, recovery test "keeps a remote bootstrap restart claim through preparation longer than its first lease, then hands it to the next attempt": the claim's first lease ends 4 s in. Preparation runs past it and the run-log writer authority still passes. Then the executor claims attempt 2 and its renewal keeps extending the lease with no detach. - Red with master's `recovery.ts`: the lease is never extended. - Red with only the `recovery.ts` change: `native_session_renewal_binding_changed`. - Green with both. - Red/green, lease unit tests: handover to the next attempt (and refusal of a lower one); a failure under the old binding is not a loss; a failure while the coordinator shows the same owner at a higher attempt is not a loss. All three fail on master. - Live wave: results in a comment below. ## Risks - Medium-low. - The preparation renewal now runs for remote `bootstrap_incomplete` and `resume_dead_runner` claims too. It renews the same coordinator row under the same CAS conditions reattach claims already use. - If preparation truly loses the lease (another owner takes it), its `onLost` still runs (`detachNativeSessionsForRestart`) and authority checks still fence writes. - The new non-loss case applies only when the coordinator names this exact owner at a higher attempt. The renewal deadline still bounds it. - Previous-release state: this persists nothing new. A claim saved by the previous release resumes unchanged; its preparation is simply renewed now. ## Model Used Claude Opus 5.5 (`claude-opus-5-5`), Anthropic, 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 🤖 Generated with [Claude Code](https://claude.com/claude-code) --------- Co-authored-by: Claude Opus 5.5 <noreply@anthropic.com>
205 lines
11 KiB
TypeScript
205 lines
11 KiB
TypeScript
import { afterEach, describe, expect, it, vi } from "vitest";
|
|
import type { Db } from "@paperclipai/db";
|
|
import { startNativeSessionExecutionLeaseRenewal } from "./native-execution-lease.js";
|
|
|
|
function fixture() {
|
|
const returning = vi.fn(async () => [{ runId: "run" }]);
|
|
const coordinator = vi.fn(async (): Promise<Array<{ attempt: number; leaseOwner: string }>> => []);
|
|
const renewed = vi.fn((_values: unknown) => undefined);
|
|
const update = vi.fn(() => ({ set: (values: unknown) => { renewed(values); return { where: (condition: unknown) => { renewed(condition); return { returning }; } }; } }));
|
|
const select = () => ({ from: () => ({ where: () => ({ limit: coordinator }) }) });
|
|
const transaction = vi.fn(async (run: (tx: unknown) => Promise<unknown>) => run({ update, select, execute: vi.fn() }));
|
|
const db = { update, transaction };
|
|
return { update, returning, transaction, coordinator, input: { db: db as unknown as Db, runId: "run", companyId: "company", issueId: "issue",
|
|
leaseOwner: "owner", attempt: 1, controller: { bootId: "boot", pid: 1, processStartedAt: new Date() }, remote: true,
|
|
onLost: vi.fn(async () => undefined) } };
|
|
}
|
|
afterEach(() => vi.useRealTimers());
|
|
describe("native execution renewal ownership", () => {
|
|
it("reports only the remaining confirmed ownership budget", async () => {
|
|
vi.useFakeTimers();
|
|
const { input, returning } = fixture();
|
|
let complete!: (value: { runId: string }[]) => void;
|
|
returning.mockImplementationOnce(() => new Promise(resolve => { complete = resolve; }));
|
|
const guard = startNativeSessionExecutionLeaseRenewal({ ...input, confirmedDeadline: performance.now() + 45_000 });
|
|
expect(guard.remainingMs()).toBe(45_000);
|
|
await vi.advanceTimersByTimeAsync(40_000);
|
|
expect(guard.remainingMs()).toBe(5_000);
|
|
complete([{ runId: "run" }]);
|
|
await vi.advanceTimersByTimeAsync(0);
|
|
expect(guard.remainingMs()).toBe(40_000);
|
|
await guard.stop();
|
|
});
|
|
it("keeps a successfully renewed lease through repeated slow connection acquisition", async () => {
|
|
vi.useFakeTimers();
|
|
const { input, update, transaction } = fixture();
|
|
const connected = transaction.getMockImplementation()!;
|
|
transaction.mockImplementation(async run => {
|
|
await new Promise(resolve => setTimeout(resolve, 30_000));
|
|
return connected(run);
|
|
});
|
|
const guard = startNativeSessionExecutionLeaseRenewal(input);
|
|
try {
|
|
// Renewals start at 20s/60s and extend the database lease at 50s/90s.
|
|
// Connection waits must not shorten the successfully extended ownership.
|
|
await vi.advanceTimersByTimeAsync(95_000);
|
|
expect(update).toHaveBeenCalledTimes(2);
|
|
expect(input.onLost).not.toHaveBeenCalled();
|
|
} finally { await guard.stop().catch(() => undefined); }
|
|
expect(vi.getTimerCount()).toBe(0);
|
|
});
|
|
it("shares one timer across preparation and execution and stops idle SQL after both release", async () => {
|
|
vi.useFakeTimers();
|
|
const { input, update } = fixture();
|
|
const preparation = startNativeSessionExecutionLeaseRenewal(input);
|
|
const execution = startNativeSessionExecutionLeaseRenewal(input);
|
|
expect(update).not.toHaveBeenCalled();
|
|
await vi.advanceTimersByTimeAsync(40_000);
|
|
expect(update).toHaveBeenCalledTimes(2);
|
|
await preparation.stop();
|
|
await preparation.stop();
|
|
await vi.advanceTimersByTimeAsync(20_000);
|
|
expect(update).toHaveBeenCalledTimes(3);
|
|
await execution.stop();
|
|
await vi.advanceTimersByTimeAsync(120_000);
|
|
expect(update).toHaveBeenCalledTimes(3);
|
|
expect(vi.getTimerCount()).toBe(0);
|
|
});
|
|
it("retries cancelled SQL within the original deadline without losing healthy ownership", async () => {
|
|
vi.useFakeTimers();
|
|
const { input, returning } = fixture();
|
|
returning.mockRejectedValueOnce(Object.assign(new Error("statement timeout"), { code: "57014" }));
|
|
const guard = startNativeSessionExecutionLeaseRenewal(input);
|
|
await vi.advanceTimersByTimeAsync(60_000);
|
|
expect(returning).toHaveBeenCalledTimes(3);
|
|
expect(input.onLost).not.toHaveBeenCalled();
|
|
await guard.stop();
|
|
expect(vi.getTimerCount()).toBe(0);
|
|
});
|
|
it("detaches at the deadline while a database response is missing and cannot regain authority from a late response", async () => {
|
|
vi.useFakeTimers();
|
|
const { input, returning } = fixture();
|
|
let complete!: (value: { runId: string }[]) => void;
|
|
returning.mockImplementationOnce(() => new Promise(resolve => { complete = resolve; }));
|
|
const guard = startNativeSessionExecutionLeaseRenewal(input);
|
|
await vi.advanceTimersByTimeAsync(60_000);
|
|
expect(returning).toHaveBeenCalledTimes(1);
|
|
expect(input.onLost).toHaveBeenCalledTimes(1);
|
|
complete([{ runId: "run" }]);
|
|
await expect(guard.stop()).rejects.toThrow("native_session_lease_renewal_deadline");
|
|
await vi.advanceTimersByTimeAsync(120_000);
|
|
expect(returning).toHaveBeenCalledTimes(1);
|
|
expect(vi.getTimerCount()).toBe(0);
|
|
});
|
|
it("hands preparation renewal to the same owner's executor at the next attempt", async () => {
|
|
vi.useFakeTimers();
|
|
const { input, returning } = fixture();
|
|
const preparation = startNativeSessionExecutionLeaseRenewal(input);
|
|
expect(() => startNativeSessionExecutionLeaseRenewal({ ...input, attempt: 0 })).toThrow("native_session_renewal_binding_changed");
|
|
const executorLost = vi.fn(async () => undefined);
|
|
const execution = startNativeSessionExecutionLeaseRenewal({ ...input, attempt: 2, onLost: executorLost });
|
|
await preparation.stop();
|
|
await vi.advanceTimersByTimeAsync(20_000);
|
|
expect(returning).toHaveBeenCalledTimes(1);
|
|
returning.mockResolvedValueOnce([]);
|
|
await vi.advanceTimersByTimeAsync(20_000);
|
|
expect(executorLost).toHaveBeenCalledTimes(1);
|
|
expect(input.onLost).not.toHaveBeenCalled();
|
|
await expect(execution.stop()).rejects.toThrow("native_session_lease_lost");
|
|
});
|
|
it("gives the executor that takes over at the next attempt its own later deadline", async () => {
|
|
vi.useFakeTimers();
|
|
const { input, returning } = fixture();
|
|
let complete!: (value: { runId: string }[]) => void;
|
|
const preparation = startNativeSessionExecutionLeaseRenewal({ ...input, confirmedDeadline: performance.now() + 25_000 });
|
|
returning.mockImplementationOnce(() => new Promise(resolve => { complete = resolve; }));
|
|
await vi.advanceTimersByTimeAsync(20_000);
|
|
const executorLost = vi.fn(async () => undefined);
|
|
const execution = startNativeSessionExecutionLeaseRenewal({ ...input, attempt: 2, onLost: executorLost,
|
|
confirmedDeadline: performance.now() + 60_000 });
|
|
expect(execution.remainingMs()).toBe(60_000);
|
|
const released = preparation.stop().catch(() => undefined);
|
|
await vi.advanceTimersByTimeAsync(30_000);
|
|
expect(executorLost).not.toHaveBeenCalled();
|
|
complete([{ runId: "run" }]);
|
|
await vi.advanceTimersByTimeAsync(0);
|
|
expect(execution.remainingMs()).toBeGreaterThanOrEqual(30_000);
|
|
await released;
|
|
await execution.stop();
|
|
});
|
|
it("reacquires a lapsed local lease with the generation of the attempt that took over", async () => {
|
|
vi.useFakeTimers();
|
|
const { input, update, returning } = fixture();
|
|
const conditions: unknown[] = [];
|
|
update.mockImplementation(() => ({ set: () => ({ where: (condition: unknown) => { conditions.push(condition); return { returning }; } }) }));
|
|
const local = { ...input, remote: false, controllerGeneration: 3 };
|
|
const preparation = startNativeSessionExecutionLeaseRenewal(local);
|
|
const execution = startNativeSessionExecutionLeaseRenewal({ ...local, attempt: 2, controllerGeneration: 4 });
|
|
await preparation.stop();
|
|
await vi.advanceTimersByTimeAsync(5 * 60_000);
|
|
const values = (root: unknown) => {
|
|
const found = new Set<unknown>(), seen = new WeakSet<object>();
|
|
const walk = (node: unknown) => {
|
|
if (node === null || typeof node !== "object") { found.add(node); return; }
|
|
if (seen.has(node)) return; seen.add(node);
|
|
for (const child of Object.values(node)) walk(child);
|
|
};
|
|
walk(root);
|
|
return found;
|
|
};
|
|
expect(conditions.length).toBeGreaterThan(0);
|
|
expect(values(conditions.at(-1)).has(4)).toBe(true);
|
|
expect(values(conditions.at(-1)).has(3)).toBe(false);
|
|
await execution.stop();
|
|
});
|
|
it("does not count a renewal that failed because the owner's executor advanced the attempt", async () => {
|
|
vi.useFakeTimers();
|
|
const { input, returning } = fixture();
|
|
let complete!: (value: { runId: string }[]) => void;
|
|
returning.mockImplementationOnce(() => new Promise(resolve => { complete = resolve; }));
|
|
const preparation = startNativeSessionExecutionLeaseRenewal(input);
|
|
await vi.advanceTimersByTimeAsync(20_000);
|
|
expect(returning).toHaveBeenCalledTimes(1);
|
|
const execution = startNativeSessionExecutionLeaseRenewal({ ...input, attempt: 2 });
|
|
complete([]);
|
|
await vi.advanceTimersByTimeAsync(20_000);
|
|
expect(returning).toHaveBeenCalledTimes(2);
|
|
expect(input.onLost).not.toHaveBeenCalled();
|
|
await preparation.stop();
|
|
await execution.stop();
|
|
expect(vi.getTimerCount()).toBe(0);
|
|
});
|
|
it("keeps renewing when the coordinator shows its own owner already claimed the next attempt", async () => {
|
|
vi.useFakeTimers();
|
|
const { input, returning, coordinator } = fixture();
|
|
coordinator.mockResolvedValue([{ attempt: 2, leaseOwner: "owner" }]);
|
|
returning.mockResolvedValueOnce([]);
|
|
const preparation = startNativeSessionExecutionLeaseRenewal(input);
|
|
await vi.advanceTimersByTimeAsync(20_000);
|
|
expect(coordinator).toHaveBeenCalledTimes(1);
|
|
expect(input.onLost).not.toHaveBeenCalled();
|
|
const execution = startNativeSessionExecutionLeaseRenewal({ ...input, attempt: 2 });
|
|
await preparation.stop();
|
|
await vi.advanceTimersByTimeAsync(20_000);
|
|
expect(returning).toHaveBeenCalledTimes(2);
|
|
expect(input.onLost).not.toHaveBeenCalled();
|
|
await execution.stop();
|
|
});
|
|
it("does not queue SQL behind a slow renewal and fences a lost owner", async () => {
|
|
vi.useFakeTimers();
|
|
const { input, update, returning } = fixture();
|
|
let complete!: (value: { runId: string }[]) => void;
|
|
returning.mockImplementationOnce(() => new Promise(resolve => { complete = resolve; }));
|
|
const guard = startNativeSessionExecutionLeaseRenewal(input);
|
|
await vi.advanceTimersByTimeAsync(50_000);
|
|
expect(update).toHaveBeenCalledTimes(1);
|
|
complete([]);
|
|
await vi.advanceTimersByTimeAsync(100_000);
|
|
expect(update).toHaveBeenCalledTimes(1);
|
|
expect(input.onLost).toHaveBeenCalledTimes(1);
|
|
expect(() => startNativeSessionExecutionLeaseRenewal(input)).toThrow("native_session_lease_lost");
|
|
await expect(guard.stop()).rejects.toThrow("native_session_lease_lost");
|
|
expect(vi.getTimerCount()).toBe(0);
|
|
});
|
|
});
|