diff --git a/tests/runner-e2e/README.md b/tests/runner-e2e/README.md index 4980f35edc3..524e03bc3ca 100644 --- a/tests/runner-e2e/README.md +++ b/tests/runner-e2e/README.md @@ -1354,11 +1354,16 @@ snapshot provisioning, with the fixture’s existing 42-second installation and teardown reserve subtracted before admission. It does not impose a separate 20-second lease deadline or extend the case budget. Every poll rechecks task/run ownership and run status, and requires exactly one -unambiguous active lease for that run and task. A stopped run fails immediately, even if another endpoint fails. Missing reads +unambiguous active lease for that run and task. A stopped run fails as soon as its read completes, even if another endpoint +fails or remains pending. At most three reads are outstanding, each with a +transport timeout bounded by admission and 30 seconds. Late responses cannot +change saved evidence or start another poll. Missing reads cannot admit a lease; successful ownership/status reads are retained. Admission and observer setup failures save bounded, allowlisted read status, -run-stage and lease-count evidence; -this evidence does not infer a provider-side cause or change the machine grade. +run-stage, lease-count and classified read-failure evidence; +this evidence does not infer a provider-side cause. Persistent API failures retain +their real cause and infrastructure classification. A recovered API failure does +not reclassify a later successfully observed state timeout. The initial provider's instruction-file read window remains 20 seconds after provider startup, and no action is published before the observer is armed. diff --git a/tests/runner-e2e/api.test.ts b/tests/runner-e2e/api.test.ts index c82eddfd94e..0214d30c812 100644 --- a/tests/runner-e2e/api.test.ts +++ b/tests/runner-e2e/api.test.ts @@ -32,3 +32,12 @@ describe("fixture instruction revision fence", () => { expect(fixture.request.put).toHaveBeenCalledTimes(1); }); }); + + +it("passes a bounded GET timeout to the request transport without changing its response", async () => { + vi.stubEnv("PAPERCLIP_RUNNER_E2E_PORT", "3100"); + const get = vi.fn(async () => response(200, { status: "running" })); + const api = new RunnerApi({ get } as unknown as APIRequestContext); + await expect(api.get("/api/heartbeat-runs/run", { timeout: 1234 })).resolves.toEqual({ status: "running" }); + expect(get).toHaveBeenCalledExactlyOnceWith("/api/heartbeat-runs/run", { timeout: 1234 }); +}); diff --git a/tests/runner-e2e/api.ts b/tests/runner-e2e/api.ts index c5631f406dd..921c5b8ba10 100644 --- a/tests/runner-e2e/api.ts +++ b/tests/runner-e2e/api.ts @@ -18,8 +18,8 @@ export class RunnerApi { this.baseURL = `http://127.0.0.1:${port}`; } - async get(path: string): Promise { - const response = await this.request.get(path); + async get(path: string, options?: { timeout: number }): Promise { + const response = await (options ? this.request.get(path, options) : this.request.get(path)); if (!response.ok()) throw new Error(await failureMessage(response, "GET")); return response.json() as Promise; } diff --git a/tests/runner-e2e/remote-native-bootstrap.test.ts b/tests/runner-e2e/remote-native-bootstrap.test.ts index 9a8b59acab0..21f8515be37 100644 --- a/tests/runner-e2e/remote-native-bootstrap.test.ts +++ b/tests/runner-e2e/remote-native-bootstrap.test.ts @@ -1,4 +1,6 @@ import { afterEach, expect, it, vi } from "vitest"; +import { classifyFailure } from "./failure-classifier.js"; +import { ObservedStateTimeout } from "./api.js"; import { createRemoteNativeBootstrap } from "./remote-native-bootstrap.js"; import type { RemoteFixtureApi, RemoteNativeFixture } from "./remote-native-fixtures.js"; @@ -181,7 +183,7 @@ it.each(["terminal", "run-owner", "issue-owner"])("does not lose a successful %s }); await expect(h.bootstrap.bindAndRelease(h.request)).rejects.toThrow(variant === "terminal" ? "stopped before observer setup" : "ownership is unproven"); expect(Date.now()).toBe(0); expect(h.bind).not.toHaveBeenCalled(); - expect(h.input.evidence.mock.calls[0]![1]).toMatchObject({ leasesRead: "rejected", admissionDeadlineReached: false }); + expect(h.input.evidence.mock.calls[0]![1]).toMatchObject({ admissionDeadlineReached: false }); expect(JSON.stringify(h.input.evidence.mock.calls)).not.toContain("PRIVATE"); }); @@ -190,7 +192,7 @@ it.each(["/api/issues/issue", "/api/heartbeat-runs/run", "/api/environments/env/ const h = harness(43_000); h.bootstrap.prompt("missing-read"); const original = h.api.get.getMockImplementation()!; h.api.get.mockImplementation(async path => { if (path === failedPath) throw new Error("PRIVATE API ERROR"); return original(path); }); - const delivery = expect(h.bootstrap.bindAndRelease(h.request)).rejects.toThrow("Timed out waiting"); + const delivery = expect(h.bootstrap.bindAndRelease(h.request)).rejects.toThrow("PRIVATE API ERROR"); await vi.advanceTimersByTimeAsync(1000); await delivery; expect(h.bind).not.toHaveBeenCalled(); expect(h.fixture.publishAction).not.toHaveBeenCalled(); expect(JSON.stringify(h.input.evidence.mock.calls)).not.toContain("PRIVATE"); @@ -217,7 +219,8 @@ it("rejects a lease read completing inside the final setup reserve and saves sta const delivery = expect(h.bootstrap.bindAndRelease(h.request)).rejects.toThrow("Timed out waiting"); await vi.advanceTimersByTimeAsync(1200); await delivery; expect(h.bind).not.toHaveBeenCalled(); expect(h.fixture.publishAction).not.toHaveBeenCalled(); - expect(h.input.evidence.mock.calls[0]![1]).toMatchObject({ phase: "lease_admission", activeOwnedLeaseCount: 1, admissionDeadlineReached: true, deadlineReached: false }); + expect(h.input.evidence.mock.calls[0]![1]).toMatchObject({ phase: "lease_admission", leasesRead: "rejected", admissionDeadlineReached: true, deadlineReached: false }); + expect(h.input.evidence.mock.calls[0]![1]).not.toHaveProperty("activeOwnedLeaseCount"); }); it("captures binder failure after admission without publishing or repeating setup", async () => { @@ -227,3 +230,73 @@ it("captures binder failure after admission without publishing or repeating setu expect(h.input.evidence.mock.calls[0]![1]).toMatchObject({ phase: "observer_setup", activeOwnedLeaseCount: 1 }); expect(h.bind).toHaveBeenCalledTimes(1); expect(h.fixture.publishAction).not.toHaveBeenCalled(); }); + + +it.each(["terminal", "run-owner", "issue-owner"])("rejects %s immediately with another failed read and a pending lease, and consumes its late rejection", async variant => { + vi.useFakeTimers(); vi.setSystemTime(0); + const h = harness(); h.bootstrap.prompt("slow-lease"); + if (variant === "terminal") h.run.status = "failed"; + if (variant === "run-owner") h.run.companyId = "foreign"; + if (variant === "issue-owner") h.issue.companyId = "foreign"; + let rejectLease!: (error: Error) => void; + const leaseRead = new Promise((_resolve, reject) => { rejectLease = reject; }); + const original = h.api.get.getMockImplementation()!; + h.api.get.mockImplementation(async path => { + if (path.endsWith("/leases")) return leaseRead; + if (path === (variant === "issue-owner" ? "/api/heartbeat-runs/run" : "/api/issues/issue")) throw new Error("503 PRIVATE"); + return original(path); + }); + await expect(h.bootstrap.bindAndRelease(h.request)).rejects.toThrow(variant === "terminal" ? "stopped before observer setup" : "ownership is unproven"); + expect(Date.now()).toBe(0); expect(h.api.get).toHaveBeenCalledTimes(3); + expect(h.api.get).toHaveBeenCalledWith("/api/environments/env/leases", { timeout: 18_000 }); + const saved = JSON.stringify(h.input.evidence.mock.calls); + expect(saved).toContain('"leasesRead":"pending"'); expect(saved).not.toContain("PRIVATE"); + rejectLease(new Error("late private rejection")); + await vi.advanceTimersByTimeAsync(60_000); + expect(JSON.stringify(h.input.evidence.mock.calls)).toBe(saved); + expect(h.api.get).toHaveBeenCalledTimes(3); expect(h.bind).not.toHaveBeenCalled(); +}); + +it("retains permanent 503 reads as a typed infrastructure timeout with the real cause", async () => { + vi.useFakeTimers(); vi.setSystemTime(0); + const h = harness(43_000); h.bootstrap.prompt("503"); + const cause = new Error("GET /api/environments/env/leases returned 503: PRIVATE BODY"); + const original = h.api.get.getMockImplementation()!; + h.api.get.mockImplementation(async path => { if (path.endsWith("/leases")) throw cause; return original(path); }); + const delivery = h.bootstrap.bindAndRelease(h.request).catch(error => error); + await vi.advanceTimersByTimeAsync(1000); const error = await delivery; + expect(error).toBeInstanceOf(ObservedStateTimeout); expect(error.cause).toBe(cause); + expect(classifyFailure(error)).toBe("transient_infrastructure"); + expect(error.message).not.toContain("PRIVATE"); + expect(h.input.evidence.mock.calls[0]![1]).toMatchObject({ readFailureClass: "transient_infrastructure" }); + expect(JSON.stringify(h.input.evidence.mock.calls)).not.toContain("PRIVATE"); + expect(h.bind).not.toHaveBeenCalled(); +}); + +it.each([true, false])("clears a recovered 503 cause before %s admission or observed-state timeout", async admits => { + vi.useFakeTimers(); vi.setSystemTime(0); + const h = harness(43_000); h.bootstrap.prompt("503-recovery"); + const original = h.api.get.getMockImplementation()!; let failed = false; + h.api.get.mockImplementation(async path => { + if (path.endsWith("/leases")) { + if (!failed) { failed = true; throw new Error("503 PRIVATE BODY"); } + if (!admits) return []; + } + return original(path); + }); + const delivery = h.bootstrap.bindAndRelease(h.request).catch(error => error); + await vi.advanceTimersByTimeAsync(1000); const result = await delivery; + if (admits) expect(result).toBe(h.fixture); + else { expect(classifyFailure(result)).toBe("candidate_failure"); expect(result.cause).toBeUndefined(); } +}); + +it("bounds an unresponsive read at admission without launching replacement reads", async () => { + vi.useFakeTimers(); vi.setSystemTime(0); + const h = harness(43_000); h.bootstrap.prompt("hung"); + const original = h.api.get.getMockImplementation()!; + h.api.get.mockImplementation(async path => path.endsWith("/leases") ? new Promise(() => {}) : original(path)); + const delivery = h.bootstrap.bindAndRelease(h.request).catch(error => error); + await vi.advanceTimersByTimeAsync(1100); const error = await delivery; + expect(classifyFailure(error)).toBe("transient_infrastructure"); + expect(h.api.get).toHaveBeenCalledTimes(3); expect(h.bind).not.toHaveBeenCalled(); +}); diff --git a/tests/runner-e2e/remote-native-bootstrap.ts b/tests/runner-e2e/remote-native-bootstrap.ts index b214d2e500f..2d0e9528887 100644 --- a/tests/runner-e2e/remote-native-bootstrap.ts +++ b/tests/runner-e2e/remote-native-bootstrap.ts @@ -3,7 +3,8 @@ import { readFile } from "node:fs/promises"; import { createRequire } from "node:module"; import { dirname, join } from "node:path"; import { pathToFileURL } from "node:url"; -import { pollUntil } from "./api.js"; +import { ObservedStateTimeout, pollUntil } from "./api.js"; +import { classifyFailure } from "./failure-classifier.js"; import { REMOTE_FIXTURE_MIN_SETUP_BUDGET_MS, bindRemoteNativeFixture, type RemoteFixtureApi, type RemoteFixtureDaytona, type RemoteNativeFixture } from "./remote-native-fixtures.js"; export interface RemoteNativeBootstrap { @@ -66,41 +67,85 @@ export function createRemoteNativeBootstrap(input: { let lastState: Record = { observed: false }; const admissionDeadlineAt = input.deadlineAt - REMOTE_FIXTURE_MIN_SETUP_BUDGET_MS; let fixture: RemoteNativeFixture; + let lastReadError: unknown; try { const ready = await pollUntil({ label: "owned native qualification lease", deadlineAt: admissionDeadlineAt, intervalMs: 100, load: async () => { - const [issueRead, runRead, leasesRead] = await Promise.allSettled([ - input.api.get>(`/api/issues/${request.issueId}`), - input.api.get>(`/api/heartbeat-runs/${request.runId}`), - input.api.get>>(`/api/environments/${input.environmentId}/leases`), - ]); - const issue = issueRead.status === "fulfilled" ? issueRead.value : undefined; - const run = runRead.status === "fulfilled" ? runRead.value : undefined; - const rows = leasesRead.status === "fulfilled" ? leasesRead.value : undefined; - const issueOwned = issue?.id === request.issueId && issue.companyId === input.companyId - && issue.assigneeAgentId === input.agentId; - const runOwned = run?.companyId === input.companyId && run.agentId === input.agentId && run.id === request.runId; - const owned = issueOwned && runOwned; - const runLeases = rows?.filter(row => row.heartbeatRunId === request.runId); - const active = runLeases?.filter(row => row.issueId === request.issueId && row.status === "active" && row.providerLeaseId); - // A failed endpoint cannot discard a successful read proving that - // ownership changed or the run stopped. Missing reads never admit. - const rejection = (issueRead.status === "fulfilled" && !issueOwned) || (runRead.status === "fulfilled" && !runOwned) - ? "Remote bootstrap task/run ownership is unproven" - : runRead.status === "fulfilled" && !["queued", "running"].includes(run?.status) ? "Native qualification run stopped before observer setup" - : runLeases && runLeases.length > 1 ? "Ambiguous native qualification lease" : undefined; - // Fixed keys and allowlisted enum values only: no provider IDs, - // errors, prompts or arbitrary API strings enter startup evidence. - lastState = { - observed: true, owned, phase: "lease_admission", - issueRead: issueRead.status, runRead: runRead.status, leasesRead: leasesRead.status, - runStatus: ["queued", "running", "succeeded", "failed", "cancelled", "timed_out"].includes(run?.status) ? run!.status : "unknown", - executionStage: ["queued", "preparing", "executing", "finalizing"].includes(run?.executionStage) ? run!.executionStage : "unknown", - ...(runLeases ? { runLeaseCount: runLeases.length, activeOwnedLeaseCount: active!.length } : {}), - deadlineReached: Date.now() >= input.deadlineAt, + type Read = PromiseSettledResult | { status: "pending" }; + let issueRead: Read> = { status: "pending" }; + let runRead: Read> = { status: "pending" }; + let leasesRead: Read>> = { status: "pending" }; + const snapshot = () => { + const issue = issueRead.status === "fulfilled" ? issueRead.value : undefined; + const run = runRead.status === "fulfilled" ? runRead.value : undefined; + const rows = leasesRead.status === "fulfilled" ? leasesRead.value : undefined; + const issueOwned = issue?.id === request.issueId && issue.companyId === input.companyId + && issue.assigneeAgentId === input.agentId; + const runOwned = run?.companyId === input.companyId && run.agentId === input.agentId && run.id === request.runId; + const owned = issueOwned && runOwned; + const runLeases = Array.isArray(rows) ? rows.filter(row => row?.heartbeatRunId === request.runId) : undefined; + const active = runLeases?.filter(row => row.issueId === request.issueId && row.status === "active" && row.providerLeaseId); + // A failed endpoint cannot discard a successful read proving that + // ownership changed or the run stopped. Missing reads never admit. + const rejection = (issueRead.status === "fulfilled" && !issueOwned) || (runRead.status === "fulfilled" && !runOwned) + ? "Remote bootstrap task/run ownership is unproven" + : runRead.status === "fulfilled" && !["queued", "running"].includes(run?.status) ? "Native qualification run stopped before observer setup" + : runLeases && runLeases.length > 1 ? "Ambiguous native qualification lease" : undefined; + // Fixed keys and allowlisted enum values only: no provider IDs, + // errors, prompts or arbitrary API strings enter startup evidence. + const readError = [issueRead, runRead, leasesRead].find(read => read.status === "rejected"); + const evidence = { + observed: true, owned, phase: "lease_admission", + issueRead: issueRead.status, runRead: runRead.status, leasesRead: leasesRead.status, + runStatus: ["queued", "running", "succeeded", "failed", "cancelled", "timed_out"].includes(run?.status) ? run!.status : "unknown", + executionStage: ["queued", "preparing", "executing", "finalizing"].includes(run?.executionStage) ? run!.executionStage : "unknown", + ...(runLeases ? { runLeaseCount: runLeases.length, activeOwnedLeaseCount: active!.length } : {}), + ...(readError?.status === "rejected" ? { readFailureClass: classifyFailure(readError.reason) } : {}), + deadlineReached: Date.now() >= input.deadlineAt, + }; + return { run, owned, lease: active?.[0], rejection, evidence, + readError: readError?.status === "rejected" ? readError.reason : undefined }; }; - return { run, owned, lease: active?.[0], rejection }; + // At most three in-flight reads. Each has a transport deadline no + // later than admission; terminal/ownership proof need not await it. + const remainingMs = Math.max(1, admissionDeadlineAt - Date.now()); + const timeout = Math.min(30_000, remainingMs); + const state = await new Promise>(resolve => { + let finished = false; + const finish = (state: ReturnType) => { + if (finished) return; + finished = true; clearTimeout(timer); resolve(state); + }; + const timer = setTimeout(() => { + const failure = { status: "rejected" as const, reason: new Error("API connection timed out during remote admission") }; + if (issueRead.status === "pending") issueRead = failure; + if (runRead.status === "pending") runRead = failure; + if (leasesRead.status === "pending") leasesRead = failure; + finish(snapshot()); + }, remainingMs); + function read(path: string, save: (result: Read) => void) { + // Both handlers are installed before dispatch. Late completion + // is consumed but cannot mutate saved evidence or start a poll. + void Promise.resolve().then(() => input.api.get(path, { timeout })).then( + value => settled({ status: "fulfilled", value }), + reason => settled({ status: "rejected", reason }), + ); + function settled(result: Read) { + if (finished) return; + save(result); + const state = snapshot(); + if (state.rejection || [issueRead, runRead, leasesRead].every(read => read.status !== "pending")) finish(state); + } + } + read>(`/api/issues/${request.issueId}`, result => { issueRead = result; }); + read>(`/api/heartbeat-runs/${request.runId}`, result => { runRead = result; }); + read>>(`/api/environments/${input.environmentId}/leases`, result => { leasesRead = result; }); + }); + lastState = state.evidence; + lastReadError = state.rejection ? undefined : state.readError; + if (lastReadError !== undefined) throw lastReadError; + return state; }, accept: state => !state.rejection && state.owned && state.run?.status === "running" && Boolean(state.lease) && Date.now() < admissionDeadlineAt, @@ -114,6 +159,13 @@ export function createRemoteNativeBootstrap(input: { targets: [...request.targets], crossRoot: request.crossRoot, actionFile: setup.path, deadlineAt: input.deadlineAt, }); } catch (error) { + if (lastReadError !== undefined && lastState.phase === "lease_admission") { + if (classifyFailure(lastReadError) === "transient_infrastructure") { + const timeout = new ObservedStateTimeout("owned native qualification lease", "transient_infrastructure", JSON.stringify(lastState)); + timeout.cause = lastReadError; + error = timeout; + } else error = lastReadError; + } try { await input.evidence(`remote-native-bootstrap-startup-${request.runId}.json`, { ...lastState, deadlineReached: Date.now() >= input.deadlineAt, diff --git a/tests/runner-e2e/remote-native-fixtures.ts b/tests/runner-e2e/remote-native-fixtures.ts index 5b558bdf4ad..150cee5baeb 100644 --- a/tests/runner-e2e/remote-native-fixtures.ts +++ b/tests/runner-e2e/remote-native-fixtures.ts @@ -51,7 +51,7 @@ export interface RemoteFixtureDaytona { executeCommand(command: string, cwd?: string, env?: Record, timeout?: number): Promise<{ exitCode: number; result: string }>; } }>; } -export interface RemoteFixtureApi { get(path: string): Promise } +export interface RemoteFixtureApi { get(path: string, options?: { timeout: number }): Promise } /** Linux /proc identity uses boot ID + start ticks, never PID alone. */ export function parseRemoteProcStat(pid: number, stat: string, bootId: string): RemoteProcessIdentity & { group: number; state: string } {