diff --git a/doc/observability.md b/doc/observability.md index 9e7433cd6c5..56c550161bc 100644 --- a/doc/observability.md +++ b/doc/observability.md @@ -583,6 +583,27 @@ and native runs: - `run_exception_0` through `run_exception_3`: exception names, codes, HTTP statuses, and request IDs for a caught exception and up to three causes. +When a Daytona acquisition fails with pending allocation cleanup, the immediate +setup-failure report can include `environmentAcquisitionPhase`, +`environmentAcquisitionElapsedMs`, and `environmentAcquisitionBudgetMs` in +`run_execution`. The phase is one of `create`, `workspace`, `shell`, `expiry`, +or `sentinel`. It records the first acquisition failure observation, before +inline cleanup, not the cause of the failure. Elapsed time measures acquisition +start to that observation; if cleanup later consumes the deadline, this time +still describes the earlier failure. The overall error message is unchanged. +Elapsed time is bounded to seven days, and the budget to one day. Unknown or +malformed optional values are omitted without invalidating cleanup ownership. + +These fields cross the existing creation-cleanup RPC envelope only for lease +acquisition. The host accepts them only from an actual RPC error with matching +company, environment, and run ownership. A private receipt binds the report to +that run; arbitrary error fields and saved result JSON do not supply evidence. +Raw provider causes, output, paths, URLs, and cleanup ownership identifiers are +not copied into these diagnostic fields. This does not change timeout budgets, +commands, cleanup, retries, task status, or Sentry filtering. The receipt is +process-local: post-restart reports without the original error cannot recover +these observations. Existing saved runs and leases are not backfilled. + The orphan reaper records a bounded `processLossDiagnostic` before status writes or cleanup. For `process_lost` failures, `run_execution` includes `processLossPidRecorded`, `processLossGroupRecorded`, and `processLossLocalCheck` diff --git a/packages/plugins/sandbox-providers/daytona/src/plugin.test.ts b/packages/plugins/sandbox-providers/daytona/src/plugin.test.ts index 79eb85bd0a5..6daa71792a7 100644 --- a/packages/plugins/sandbox-providers/daytona/src/plugin.test.ts +++ b/packages/plugins/sandbox-providers/daytona/src/plugin.test.ts @@ -36,7 +36,7 @@ import plugin, { __setDaytonaPluginContextForTest, } from "./plugin.js"; import type { PluginContext } from "@paperclipai/plugin-sdk"; -import { environmentSyncErrorData, readEnvironmentSyncErrorDiagnostic, withEnvironmentSyncErrorCapture, environmentCreationCleanupErrorData, readEnvironmentCreationCleanupError } from "@paperclipai/plugin-sdk"; +import { environmentSyncErrorData, readEnvironmentSyncErrorDiagnostic, withEnvironmentSyncErrorCapture, environmentCreationCleanupErrorData, readEnvironmentCreationCleanupError, readEnvironmentAcquisitionDiagnostic } from "@paperclipai/plugin-sdk"; import manifest from "./manifest.js"; import { parseTarVerboseListingLine, splitLinkEntryOnce } from "./file-sync.js"; @@ -553,6 +553,57 @@ describe("Daytona sandbox provider plugin", () => { }); afterEach(() => { vi.useRealTimers(); }); + it.each(["create", "workspace", "shell", "expiry", "sentinel"] as const)("records the %s acquisition deadline without advancing late setup", async phase => { + const sandbox = createMockSandbox(); + const never = () => new Promise(() => {}); + mockCreate.mockResolvedValue(sandbox); + if (phase === "create") mockCreate.mockImplementation(never); + if (phase === "workspace") sandbox.getWorkDir.mockImplementation(never); + if (phase === "shell") sandbox.process.executeCommand.mockImplementation(never); + if (phase === "expiry") sandbox.setTtl.mockImplementation(never); + if (phase === "sentinel") sandbox.fs.uploadFile.mockImplementation(never); + const pending = plugin.definition.onEnvironmentAcquireLease!({ ...params, + config: { ...params.config, timeoutMs: 2_000 }, + ...(phase === "sentinel" ? { agentId: "agent-fixture", issueId: "issue-fixture" } : {}), + ...(phase === "expiry" ? { requestedExpiresAt: new Date(Date.now() + 60_000).toISOString() } : {}), + }).catch(error => error); + await vi.advanceTimersByTimeAsync(2_000); + const error = await pending; + expect(readEnvironmentAcquisitionDiagnostic(error)).toEqual({ phase, elapsedMs: 2_000, budgetMs: 2_000 }); + expect(error.message).toBe("Daytona lease acquisition timed out; allocation cleanup is pending"); + expect(sandbox.delete).not.toHaveBeenCalled(); + }); + + it.each(["create", "workspace"] as const)("keeps the original %s observation when cleanup consumes the remaining deadline", async phase => { + const sandbox = createMockSandbox(); + mockCreate.mockResolvedValue(sandbox); + const fail = () => new Promise((_resolve, reject) => setTimeout(() => reject(new Error("private-provider-failure")), 100)); + if (phase === "create") { mockCreate.mockImplementation(fail); mockGet.mockImplementation(() => new Promise(() => {})); } + else { sandbox.getWorkDir.mockImplementation(fail); sandbox.delete.mockImplementation(() => new Promise(() => {})); } + const pending = plugin.definition.onEnvironmentAcquireLease!({ ...params, config: { ...params.config, timeoutMs: 2_000 } }).catch(error => error); + await vi.advanceTimersByTimeAsync(2_000); + const error = await pending; + expect(readEnvironmentAcquisitionDiagnostic(error)).toEqual({ phase, elapsedMs: 100, budgetMs: 2_000 }); + expect(error.message).toBe("Daytona lease acquisition timed out; allocation cleanup is pending"); + expect(JSON.stringify(environmentCreationCleanupErrorData(error, true))).not.toContain("private-"); + await vi.advanceTimersByTimeAsync(20_000); + expect(readEnvironmentAcquisitionDiagnostic(error)?.elapsedMs).toBe(100); + }); + + it("isolates overlapping acquisition observations and does not annotate successful leases", async () => { + const sandbox = createMockSandbox(); + mockCreate.mockImplementationOnce(() => new Promise(() => {})).mockResolvedValueOnce(sandbox); + sandbox.getWorkDir.mockImplementation(() => new Promise(() => {})); + const first = plugin.definition.onEnvironmentAcquireLease!({ ...params, config: { ...params.config, timeoutMs: 2_000 } }).catch(error => error); + await vi.advanceTimersByTimeAsync(100); + const second = plugin.definition.onEnvironmentAcquireLease!({ ...params, config: { ...params.config, timeoutMs: 3_000 } }).catch(error => error); + await vi.advanceTimersByTimeAsync(3_000); + expect(readEnvironmentAcquisitionDiagnostic(await first)).toEqual({ phase: "create", elapsedMs: 2_000, budgetMs: 2_000 }); + expect(readEnvironmentAcquisitionDiagnostic(await second)).toEqual({ phase: "workspace", elapsedMs: 3_000, budgetMs: 3_000 }); + mockCreate.mockResolvedValue(createMockSandbox()); + expect(await plugin.definition.onEnvironmentAcquireLease!(params)).not.toHaveProperty("acquisitionDiagnostic"); + }); + it("allows a slow create and setup that finish inside the total budget", async () => { const sandbox = createMockSandbox(); mockCreate.mockImplementation(() => new Promise(resolve => setTimeout(() => resolve(sandbox), 280_000))); @@ -617,6 +668,7 @@ describe("Daytona sandbox provider plugin", () => { observedProviderLeaseId: sandbox.id, companyId: params.companyId, runId: params.runId, }); expect(vi.getTimerCount()).toBe(0); + expect(readEnvironmentAcquisitionDiagnostic(error)).toEqual({ phase: "workspace", elapsedMs: 0, budgetMs: 300_000 }); }); }); diff --git a/packages/plugins/sandbox-providers/daytona/src/plugin.ts b/packages/plugins/sandbox-providers/daytona/src/plugin.ts index bbfa70a049d..1f9ddd10189 100644 --- a/packages/plugins/sandbox-providers/daytona/src/plugin.ts +++ b/packages/plugins/sandbox-providers/daytona/src/plugin.ts @@ -13,6 +13,7 @@ import { decodeChannelBytes, definePlugin, NOOP_PLUGIN_TRACER, PluginEnvironment import type { PluginContext, PluginEnvironmentCreationCleanup, + PluginEnvironmentAcquisitionDiagnostic, PluginTracer, PluginEnvironmentAcquireLeaseParams, PluginEnvironmentCancelInteractiveSetupParams, @@ -953,6 +954,7 @@ async function createSandbox( options: { purpose?: string; onCreateAttempt?: (cleanup: PluginEnvironmentCreationCleanup) => void; + onCreateFailure?: () => PluginEnvironmentAcquisitionDiagnostic; } = {}, ): Promise { const resourceRequestError = validateRuntimeResourceRequest(config); @@ -986,6 +988,8 @@ async function createSandbox( timeout: toTimeoutSeconds(config.timeoutMs), }); } catch (createError) { + // Observe the create failure before compensating deletion can stall or fail. + const diagnostic = options.onCreateFailure?.(); try { // A not-found lookup after an uncertain create is not a deletion receipt: // the provider may still materialize the request. Keep the name in the @@ -993,7 +997,7 @@ async function createSandbox( await destroyFailedCreation(config, cleanup); } catch (cleanupError) { throw new PluginEnvironmentCreationCleanupError([createError, cleanupError], - `Daytona sandbox creation failed; cleanup could not be confirmed for ${name}`, cleanup); + `Daytona sandbox creation failed; cleanup could not be confirmed for ${name}`, cleanup, diagnostic); } throw createError; } @@ -2406,17 +2410,30 @@ const plugin = definePlugin({ // One budget covers creation, setup, and inline cleanup. The host leaves // 30 seconds beyond this deadline to receive/journal the cleanup record. const budgetMs = config.timeoutMs > 0 ? config.timeoutMs : DEFAULT_DAYTONA_OPERATION_TIMEOUT_MS; - const deadline = Date.now() + budgetMs; + const startedAt = Date.now(); + const deadline = startedAt + budgetMs; let expired = false; - let phase = "create"; + let phase: PluginEnvironmentAcquisitionDiagnostic["phase"] = "create"; + let cleanupInProgress = false; + let firstFailure: PluginEnvironmentAcquisitionDiagnostic | undefined; + const observeFailure = (): PluginEnvironmentAcquisitionDiagnostic => { + // Cleanup may consume the rest of the budget. Keep the original failed + // step and time, rather than attributing that failure to its cleanup. + return firstFailure ??= { + phase, + elapsedMs: Math.max(0, Math.min(604_800_000, Date.now() - startedAt)), + budgetMs, + }; + }; let cleanup: PluginEnvironmentCreationCleanup | undefined; const timeoutFailure = () => { + const diagnostic = observeFailure(); expired = true; - const cause = new Error(`Daytona lease acquisition exceeded ${budgetMs} ms during ${phase}`); + const cause = new Error(`Daytona lease acquisition exceeded ${budgetMs} ms during ${cleanupInProgress ? "cleanup" : phase}`); return cleanup ? new PluginEnvironmentCreationCleanupError([cause], "Daytona lease acquisition timed out; allocation cleanup is pending", - { ...cleanup, labels: { ...cleanup.labels } }) + { ...cleanup, labels: { ...cleanup.labels } }, diagnostic) : cause; }; const assertActive = () => { @@ -2425,6 +2442,7 @@ const plugin = definePlugin({ const acquire = async (): Promise => { const sandbox = await createSandbox(params, config, { onCreateAttempt: (attempt) => { cleanup = attempt; }, + onCreateFailure: observeFailure, }); try { assertActive(); @@ -2487,17 +2505,18 @@ const plugin = definePlugin({ }), }; } catch (error) { + const diagnostic = observeFailure(); // After timeout the host owns the durable cleanup record. A late SDK // completion must not admit this lease or start another setup phase. if (!expired) { - phase = "cleanup"; + cleanupInProgress = true; try { await sandbox.delete(toTimeoutSeconds(Math.max(1, deadline - Date.now()))); } catch (cleanupError) { if (cleanup) { throw new PluginEnvironmentCreationCleanupError([error, cleanupError], "Daytona lease setup failed; allocation cleanup is pending", - { ...cleanup, labels: { ...cleanup.labels } }); + { ...cleanup, labels: { ...cleanup.labels } }, diagnostic); } throw error; } diff --git a/packages/plugins/sdk/src/environment-creation-cleanup.ts b/packages/plugins/sdk/src/environment-creation-cleanup.ts index 8dcdc1f768f..6328b9ee42f 100644 --- a/packages/plugins/sdk/src/environment-creation-cleanup.ts +++ b/packages/plugins/sdk/src/environment-creation-cleanup.ts @@ -13,24 +13,55 @@ export interface PluginEnvironmentCreationCleanup { const SCHEMA = "paperclip/environment-creation-cleanup/v1"; +/** The step observed at the first acquisition failure, not its upstream cause. */ +export interface PluginEnvironmentAcquisitionDiagnostic { + phase: "create" | "workspace" | "shell" | "expiry" | "sentinel"; + /** Milliseconds from acquisition start to the first failure, before cleanup. */ + elapsedMs: number; + budgetMs: number; +} + +export function readEnvironmentAcquisitionDiagnostic(error: unknown): PluginEnvironmentAcquisitionDiagnostic | null { + try { + // Diagnostics never make an invalid ownership envelope usable for cleanup. + if (!readEnvironmentCreationCleanupError(error)) return null; + const container = error instanceof PluginEnvironmentCreationCleanupError + ? error : (error as { data?: object }).data; + const value = container && Object.getOwnPropertyDescriptor(container, "acquisitionDiagnostic")?.value; + if (!value || typeof value !== "object" || Array.isArray(value)) return null; + const fields = Object.getOwnPropertyDescriptors(value); + const phase = fields.phase?.value; + const elapsedMs = fields.elapsedMs?.value; + const budgetMs = fields.budgetMs?.value; + if (!["create", "workspace", "shell", "expiry", "sentinel"].includes(phase as string) || + typeof elapsedMs !== "number" || !Number.isSafeInteger(elapsedMs) || elapsedMs < 0 || elapsedMs > 604_800_000 || + typeof budgetMs !== "number" || !Number.isSafeInteger(budgetMs) || budgetMs < 1 || budgetMs > 86_400_000) return null; + return { phase: phase as PluginEnvironmentAcquisitionDiagnostic["phase"], elapsedMs, budgetMs }; + } catch { return null; } +} + /** * Never serialize the provider exceptions: they may contain credentials. * The host persists only this explicit ownership envelope, then retries teardown. */ export class PluginEnvironmentCreationCleanupError extends AggregateError { readonly cleanup: PluginEnvironmentCreationCleanup; + readonly acquisitionDiagnostic?: PluginEnvironmentAcquisitionDiagnostic; - constructor(errors: unknown[], message: string, cleanup: PluginEnvironmentCreationCleanup) { + constructor(errors: unknown[], message: string, cleanup: PluginEnvironmentCreationCleanup, + acquisitionDiagnostic?: PluginEnvironmentAcquisitionDiagnostic) { super(errors, message); this.name = "PluginEnvironmentCreationCleanupError"; this.cleanup = cleanup; + this.acquisitionDiagnostic = acquisitionDiagnostic; } } -export function environmentCreationCleanupErrorData(error: unknown): unknown { +export function environmentCreationCleanupErrorData(error: unknown, includeAcquisitionDiagnostic = false): unknown { if (!(error instanceof PluginEnvironmentCreationCleanupError)) return undefined; const cleanup = readEnvironmentCreationCleanupError(error); - return cleanup ? { schema: SCHEMA, cleanup } : undefined; + const acquisitionDiagnostic = includeAcquisitionDiagnostic ? readEnvironmentAcquisitionDiagnostic(error) : null; + return cleanup ? { schema: SCHEMA, cleanup, ...(acquisitionDiagnostic ? { acquisitionDiagnostic } : {}) } : undefined; } export function readEnvironmentCreationCleanupError(error: unknown): PluginEnvironmentCreationCleanup | null { diff --git a/packages/plugins/sdk/src/index.ts b/packages/plugins/sdk/src/index.ts index 7c2c944b63c..f361b5c4353 100644 --- a/packages/plugins/sdk/src/index.ts +++ b/packages/plugins/sdk/src/index.ts @@ -450,8 +450,8 @@ export { PRINCIPAL_TYPES, } from "@paperclipai/shared"; -export { PluginEnvironmentCreationCleanupError, environmentCreationCleanupErrorData, readEnvironmentCreationCleanupError } from "./environment-creation-cleanup.js"; -export type { PluginEnvironmentCreationCleanup } from "./environment-creation-cleanup.js"; +export { PluginEnvironmentCreationCleanupError, environmentCreationCleanupErrorData, readEnvironmentCreationCleanupError, readEnvironmentAcquisitionDiagnostic } from "./environment-creation-cleanup.js"; +export type { PluginEnvironmentCreationCleanup, PluginEnvironmentAcquisitionDiagnostic } from "./environment-creation-cleanup.js"; export { preserveEnvironmentSyncErrorDiagnostic, environmentSyncErrorData, readEnvironmentSyncErrorDiagnostic, withEnvironmentSyncErrorCapture, withEnvironmentSyncTransferStep, recordEnvironmentSyncError } from "./environment-sync-error.js"; export type { PluginEnvironmentSyncErrorDiagnostic } from "./environment-sync-error.js"; diff --git a/packages/plugins/sdk/src/worker-rpc-host.ts b/packages/plugins/sdk/src/worker-rpc-host.ts index ef8de899f63..5b1492106be 100644 --- a/packages/plugins/sdk/src/worker-rpc-host.ts +++ b/packages/plugins/sdk/src/worker-rpc-host.ts @@ -1601,7 +1601,7 @@ export function startWorkerRpcHost(options: WorkerRpcHostOptions): WorkerRpcHost sendMessage(createErrorResponse(id, errorCode, errorMessage, method === "environmentAcquireLease" || method === "environmentDestroyLease" - ? environmentCreationCleanupErrorData(err) + ? environmentCreationCleanupErrorData(err, method === "environmentAcquireLease") : method === "environmentSyncOut" ? environmentSyncErrorData(err) : undefined)); } finally { done?.(); diff --git a/packages/plugins/sdk/tests/environment-creation-cleanup.test.ts b/packages/plugins/sdk/tests/environment-creation-cleanup.test.ts index e75f7877ee0..64fa237f43a 100644 --- a/packages/plugins/sdk/tests/environment-creation-cleanup.test.ts +++ b/packages/plugins/sdk/tests/environment-creation-cleanup.test.ts @@ -2,7 +2,7 @@ import { createInterface } from "node:readline"; import { PassThrough } from "node:stream"; import { describe, expect, it } from "vitest"; import { definePlugin } from "../src/define-plugin.js"; -import { PluginEnvironmentCreationCleanupError, environmentCreationCleanupErrorData, readEnvironmentCreationCleanupError } from "../src/environment-creation-cleanup.js"; +import { PluginEnvironmentCreationCleanupError, environmentCreationCleanupErrorData, readEnvironmentCreationCleanupError, readEnvironmentAcquisitionDiagnostic } from "../src/environment-creation-cleanup.js"; import { createRequest, isJsonRpcResponse, JsonRpcCallError, parseMessage, serializeMessage, type JsonRpcResponse } from "../src/protocol.js"; import { startWorkerRpcHost } from "../src/worker-rpc-host.js"; @@ -73,3 +73,72 @@ describe("failed environment creation ownership", () => { expect(readEnvironmentCreationCleanupError(value)).toBeNull(); }); }); + + +describe("acquisition failure observations", () => { + const diagnostic = { phase: "shell", elapsedMs: 300_000, budgetMs: 300_000 } as const; + + it("crosses the real acquire RPC without provider causes or ownership in the diagnostic", async () => { + const input = { ...diagnostic, url: "private-url", command: "private-command", token: "private-token" }; + const response = await invoke("environmentAcquireLease", new PluginEnvironmentCreationCleanupError( + [new Error("private-provider-cause")], "Cleanup required", ownership, input, + )); + if (!("error" in response) || !response.error) throw new Error("Expected RPC error"); + expect(response.error.data).toEqual({ schema, cleanup: ownership, acquisitionDiagnostic: diagnostic }); + expect(readEnvironmentAcquisitionDiagnostic(new JsonRpcCallError(response.error))).toEqual(diagnostic); + expect(JSON.stringify(response)).not.toContain("private-"); + // The old ownership reader and envelope version remain valid. + expect(readEnvironmentCreationCleanupError(new JsonRpcCallError(response.error))).toEqual(ownership); + expect(readEnvironmentAcquisitionDiagnostic({ data: { schema, cleanup: ownership } })).toBeNull(); + }); + + it.each(["environmentDestroyLease", "environmentProbe"])("omits acquisition diagnostics from %s", async method => { + const response = await invoke(method, new PluginEnvironmentCreationCleanupError([], "Cleanup required", ownership, diagnostic)); + expect("error" in response && response.error).not.toHaveProperty("data.acquisitionDiagnostic"); + if (method === "environmentDestroyLease") expect("error" in response && response.error?.data).toEqual({ schema, cleanup: ownership }); + }); + + it.each([ + null, [], {}, { ...diagnostic, phase: "cleanup" }, { ...diagnostic, phase: "private-command" }, + { ...diagnostic, elapsedMs: -1 }, { ...diagnostic, elapsedMs: NaN }, { ...diagnostic, elapsedMs: Infinity }, + { ...diagnostic, elapsedMs: 604_800_001 }, { ...diagnostic, elapsedMs: 0.5 }, { ...diagnostic, elapsedMs: "300000" }, + { ...diagnostic, budgetMs: 0 }, { ...diagnostic, budgetMs: 86_400_001 }, { ...diagnostic, budgetMs: Infinity }, + { ...diagnostic, budgetMs: "private-token" }, Object.create(diagnostic), + ])("omits malformed optional diagnostics without rejecting cleanup (%j)", invalid => { + const error = new PluginEnvironmentCreationCleanupError([], "Cleanup required", ownership, invalid as typeof diagnostic); + expect(readEnvironmentAcquisitionDiagnostic(error)).toBeNull(); + expect(environmentCreationCleanupErrorData(error, true)).toEqual({ schema, cleanup: ownership }); + }); + + it("omits accessor diagnostics without invoking their getters", () => { + let reads = 0; + const invalid = Object.defineProperty({ ...diagnostic }, "phase", { get() { reads++; throw new Error("private-getter"); } }); + const error = new PluginEnvironmentCreationCleanupError([], "Cleanup required", ownership, invalid); + expect(environmentCreationCleanupErrorData(error, true)).toEqual({ schema, cleanup: ownership }); + expect(reads).toBe(0); + }); + + it("does not read an inherited or accessor acquisitionDiagnostic envelope field", () => { + let reads = 0; + const accessor = Object.defineProperty({ schema, cleanup: ownership }, "acquisitionDiagnostic", { + get() { reads++; throw new Error("private-getter"); }, + }); + const inherited = Object.assign(Object.create({ acquisitionDiagnostic: diagnostic }), { schema, cleanup: ownership }); + for (const data of [accessor, inherited]) { + expect(readEnvironmentAcquisitionDiagnostic({ data })).toBeNull(); + expect(readEnvironmentCreationCleanupError({ data })).toEqual(ownership); + } + const typed = new PluginEnvironmentCreationCleanupError([], "Cleanup required", ownership); + Object.defineProperty(typed, "acquisitionDiagnostic", { get() { reads++; throw new Error("private-getter"); } }); + expect(environmentCreationCleanupErrorData(typed, true)).toEqual({ schema, cleanup: ownership }); + expect(reads).toBe(0); + }); + + it("does not serialize forged error properties or accept invalid ownership with valid diagnostics", async () => { + const forged = Object.assign(new Error("Cleanup required"), { acquisitionDiagnostic: diagnostic, + data: { schema, cleanup: ownership, acquisitionDiagnostic: diagnostic } }); + const response = await invoke("environmentAcquireLease", forged); + expect("error" in response && response.error).not.toHaveProperty("data"); + expect(readEnvironmentAcquisitionDiagnostic({ data: { schema, cleanup: { ...ownership, runId: "private/path" }, acquisitionDiagnostic: diagnostic } })).toBeNull(); + }); +}); diff --git a/server/src/__tests__/environment-acquisition-diagnostics.test.ts b/server/src/__tests__/environment-acquisition-diagnostics.test.ts new file mode 100644 index 00000000000..4990aca7c87 --- /dev/null +++ b/server/src/__tests__/environment-acquisition-diagnostics.test.ts @@ -0,0 +1,56 @@ +import { createRequire } from "node:module"; +import { fileURLToPath } from "node:url"; +import { describe, expect, it } from "vitest"; +import { JsonRpcCallError, readEnvironmentAcquisitionDiagnostic, readEnvironmentCreationCleanupError } from "@paperclipai/plugin-sdk"; +import type { heartbeatRuns } from "@paperclipai/db"; +import { createPluginWorkerHandle } from "../services/plugin-worker-manager.js"; +import { captureEnvironmentAcquisitionDiagnostic } from "../services/environment-acquisition-diagnostics.js"; +import { collectRunFailureDiagnostics } from "../services/run-failure-diagnostics.js"; + +describe("acquisition diagnostics through the built worker and real host client", () => { + it("keeps concurrent RPC errors isolated through wrapping and failure projection", async () => { + const handle = createPluginWorkerHandle("test.acquisition", { + entrypointPath: fileURLToPath(new URL("./fixtures/plugin-worker-acquisition-diagnostic.mjs", import.meta.url)), + manifest: { id: "test.acquisition", apiVersion: 1, version: "1.0.0", displayName: "Acquisition fixture", + description: "Acquisition fixture", author: "Paperclip", categories: ["automation"], capabilities: [], + entrypoints: { worker: "fixture.mjs" } }, + config: {}, instanceInfo: { instanceId: "instance-fixture", hostVersion: "1.0.0" }, apiVersion: 1, + hostHandlers: {}, rpcTimeoutMs: 5_000, + execArgv: ["--import", createRequire(import.meta.url).resolve("tsx")], + }); + try { + await handle.start(); + const first = { driverKey: "daytona", companyId: "company-fixture", environmentId: "environment-fixture", + runId: "run-first", config: { phase: "create" } }; + const second = { ...first, runId: "run-second", config: { phase: "shell" } }; + const [a, b] = await Promise.all([first, second].map(params => handle.call("environmentAcquireLease", params).catch(error => error))); + expect(a).toBeInstanceOf(JsonRpcCallError); + expect(b).toBeInstanceOf(JsonRpcCallError); + expect(a).not.toBe(b); + for (const [error, params] of [[a, first], [b, second]] as const) { + expect(error.code).toBe(-32002); + expect(readEnvironmentCreationCleanupError(error)?.runId).toBe(params.runId); + expect(error.message).toBe("Daytona lease acquisition timed out; allocation cleanup is pending"); + expect(JSON.stringify(error)).not.toContain("private-provider-"); + const diagnostic = readEnvironmentAcquisitionDiagnostic(error); + expect(diagnostic).toEqual({ phase: params.config.phase, elapsedMs: 2_000, budgetMs: 2_000 }); + const properties = Object.getOwnPropertyDescriptors(error); + Object.freeze(error); + captureEnvironmentAcquisitionDiagnostic(error, params, diagnostic); + const run = { id: params.runId, companyId: params.companyId, errorCode: "setup_failed", resultJson: null } as typeof heartbeatRuns.$inferSelect; + const diagnostics = collectRunFailureDiagnostics(run, { error: new Error("Cleanup confirmed", { cause: error }), phase: "setup" }); + expect(diagnostics.execution).toMatchObject({ environmentAcquisitionPhase: params.config.phase, + environmentAcquisitionElapsedMs: 2_000, environmentAcquisitionBudgetMs: 2_000 }); + expect(JSON.stringify(diagnostics)).not.toContain("private-provider-"); + // Object.freeze changes descriptor flags but no error values or identity. + for (const [key, descriptor] of Object.entries(properties)) expect(Object.getOwnPropertyDescriptor(error, key)?.value).toBe(descriptor.value); + expect(collectRunFailureDiagnostics({ ...run, id: "another-run" }, { error, phase: "setup" }).execution) + .not.toHaveProperty("environmentAcquisitionPhase"); + } + const destroyed = await handle.call("environmentDestroyLease", { ...first, providerLeaseId: "fixture" }).catch(error => error); + expect(destroyed).toBeInstanceOf(JsonRpcCallError); + expect(readEnvironmentCreationCleanupError(destroyed)).not.toBeNull(); + expect(readEnvironmentAcquisitionDiagnostic(destroyed)).toBeNull(); + } finally { await handle.stop(); } + }); +}); diff --git a/server/src/__tests__/environment-runtime.test.ts b/server/src/__tests__/environment-runtime.test.ts index 0d3a2a76ddc..9c456d8e83a 100644 --- a/server/src/__tests__/environment-runtime.test.ts +++ b/server/src/__tests__/environment-runtime.test.ts @@ -1,3 +1,5 @@ +import { JsonRpcCallError } from "@paperclipai/plugin-sdk"; +import { collectRunFailureDiagnostics } from "../services/run-failure-diagnostics.js"; import { idleWorkSnapshot } from "../services/task-admission.js"; import { createHash, randomUUID } from "node:crypto"; import { mkdir, mkdtemp, readdir, rm, writeFile } from "node:fs/promises"; @@ -769,7 +771,7 @@ describeEmbeddedPostgres("environmentRuntimeService", () => { expect(call.mock.calls.filter((entry) => entry[1] === "environmentResumeLease")).toHaveLength(shouldResume ? 1 : 0); }); - it.each(["pending", "inline", "foreign scope", "foreign environment", "foreign run", "malformed", "deleted environment"])("retains uncertain plugin creation for durable cleanup: %s", async (mode) => { + it.each(["pending", "inline", "foreign scope", "foreign environment", "foreign run", "malformed", "deleted environment", "forged error", "invalid diagnostic", "old worker"])("retains uncertain plugin creation for durable cleanup: %s", async (mode) => { const seeded = await seedReusablePluginSandboxLease(); await environmentService(db).releaseLease(seeded.reusableLease.id, "expired"); const attemptId = randomUUID(); @@ -780,9 +782,14 @@ describeEmbeddedPostgres("environmentRuntimeService", () => { runId: mode === "foreign run" ? randomUUID() : seeded.runId, accountFingerprint: mode === "malformed" ? "invalid" : "a".repeat(64), labels: { "paperclip-provider": "fake-plugin" }, }; - const failure = Object.assign(new Error("Provider creation cleanup required"), { - data: { schema: "paperclip/environment-creation-cleanup/v1", cleanup }, - }); + const acquisitionDiagnostic = { phase: "shell", elapsedMs: 300_000, budgetMs: 300_000 }; + const data = { schema: "paperclip/environment-creation-cleanup/v1", cleanup, + ...(mode === "old worker" ? {} : { acquisitionDiagnostic: mode === "invalid diagnostic" + ? { ...acquisitionDiagnostic, phase: "private-command" } : acquisitionDiagnostic }), + }; + const failure = mode === "forged error" + ? Object.assign(new Error("Provider creation cleanup required"), { data }) + : new JsonRpcCallError({ code: -32002, message: "Provider creation cleanup required", data }); let available = mode === "inline"; const call = vi.fn(async (_id: string, method: string, params: Record) => { if (method === "environmentAcquireLease") throw failure; @@ -800,6 +807,14 @@ describeEmbeddedPostgres("environmentRuntimeService", () => { const candidate = environmentRuntimeService(db, { pluginWorkerManager: worker }); const acquisition = candidate.acquireRunLease({ companyId: seeded.companyId, environment: seeded.environment, issueId: null, heartbeatRunId: seeded.runId, persistedExecutionWorkspace: null }); + const caught = await acquisition.catch(error => error); + const execution = collectRunFailureDiagnostics({ id: seeded.runId, companyId: seeded.companyId, + errorCode: "setup_failed", resultJson: null, + } as typeof heartbeatRuns.$inferSelect, { error: caught, phase: "setup" }).execution; + if (["pending", "inline", "deleted environment"].includes(mode)) { + expect(execution).toMatchObject({ environmentAcquisitionPhase: "shell", + environmentAcquisitionElapsedMs: 300_000, environmentAcquisitionBudgetMs: 300_000 }); + } else expect(execution).not.toHaveProperty("environmentAcquisitionPhase"); if (mode === "inline") { await expect(acquisition).rejects.toMatchObject({ message: "Sandbox creation failed; allocated sandbox cleanup was confirmed.", cause: failure, diff --git a/server/src/__tests__/fixtures/plugin-worker-acquisition-diagnostic.mjs b/server/src/__tests__/fixtures/plugin-worker-acquisition-diagnostic.mjs new file mode 100644 index 00000000000..092dfe77b0e --- /dev/null +++ b/server/src/__tests__/fixtures/plugin-worker-acquisition-diagnostic.mjs @@ -0,0 +1,19 @@ +import { definePlugin, PluginEnvironmentCreationCleanupError, runWorker } from "@paperclipai/plugin-sdk"; + +function failure(params) { + const cleanup = { + providerLeaseId: "paperclip-create-fixture", attemptId: "fixture", companyId: params.companyId, + environmentId: params.environmentId, runId: params.runId, accountFingerprint: "a".repeat(64), + labels: { "paperclip-provider": "daytona" }, + }; + const diagnostic = { phase: params.config.phase ?? "create", elapsedMs: 2_000, budgetMs: 2_000, + output: "private-provider-output", command: "private-provider-command", url: "private-provider-url" }; + return new PluginEnvironmentCreationCleanupError([new Error("private-provider-cause")], + "Daytona lease acquisition timed out; allocation cleanup is pending", cleanup, diagnostic); +} + +runWorker(definePlugin({ + async setup() {}, + async onEnvironmentAcquireLease(params) { throw failure(params); }, + async onEnvironmentDestroyLease(params) { throw failure(params); }, +}), import.meta.url); diff --git a/server/src/__tests__/run-failure-sentry-real-sdk.test.ts b/server/src/__tests__/run-failure-sentry-real-sdk.test.ts index 53b6c7caea6..2c879205080 100644 --- a/server/src/__tests__/run-failure-sentry-real-sdk.test.ts +++ b/server/src/__tests__/run-failure-sentry-real-sdk.test.ts @@ -1,3 +1,4 @@ +import { captureEnvironmentAcquisitionDiagnostic } from "../services/environment-acquisition-diagnostics.js"; import { createRequire } from "node:module"; import { afterEach, describe, expect, it, vi } from "vitest"; import { collectRunFailureDiagnostics, sanitizeRunFailureDiagnostics } from "../services/run-failure-diagnostics.js"; @@ -42,6 +43,47 @@ afterEach(async () => { }); describe.skipIf(!sentryPackage)("run failure context with the real Sentry SDK", () => { + it("sends only owned acquisition observations and isolates unrelated captures", async () => { + const Sentry = sentryPackage!; + const events: Array> = []; + vi.stubEnv("SENTRY_DSN_BACKEND", "https://public@example.invalid/1"); + vi.doMock("../peer-version-check.js", () => ({ checkExactPeerVersions: () => ({ ok: true }) })); + vi.doMock("@sentry/node", () => ({ ...Sentry, + init: (options: Record) => Sentry.init({ ...options, + transport: () => ({ send: async (envelope: [unknown, Array<[{ type: string }, Record]>]) => { + for (const [header, payload] of envelope[1]) if (header.type === "event") events.push(payload); + return {}; + }, flush: async () => true }), + }), + })); + vi.resetModules(); + const { sentryReady, captureRunFailure, captureException } = await import("../sentry.js"); + await sentryReady; + const scope = { companyId: "company-fixture", environmentId: "environment-fixture", + runId: "22222222-2222-4222-8222-222222222222" }; + // The acquire boundary and real worker wire are covered separately. This + // narrow SDK job imports only the dependency-free private-marker projection. + const error = Object.freeze(Object.assign(new Error("Acquisition failed"), { + data: { raw: "private-acquire-payload" }, path: "private-acquire-path", response: { token: "private-acquire-token" }, + })); + captureEnvironmentAcquisitionDiagnostic(error, scope, { phase: "workspace", elapsedMs: 100, budgetMs: 2_000 }); + const diagnostics = sanitizeRunFailureDiagnostics(collectRunFailureDiagnostics({ + id: scope.runId, companyId: scope.companyId, errorCode: "setup_failed", resultJson: null, + } as typeof heartbeatRuns.$inferSelect, { error: new Error("Cleanup confirmed", { cause: error }), phase: "setup" })); + captureRunFailure({ taskId: "11111111-1111-4111-8111-111111111111", runId: scope.runId, + errorMessage: "Acquisition failed", errorCode: "setup_failed", agentAdapter: "fixture-adapter", + runStatus: "failed", exitCode: null, signal: null, diagnostics }); + captureException(new Error("Unrelated acquisition fixture")); + await Sentry.flush(2000); + expect(events).toHaveLength(2); + const event = events.find(entry => (entry.tags as Record)?.error_code === "setup_failed"); + expect(event).toMatchObject({ contexts: { run_execution: { + environmentAcquisitionPhase: "workspace", environmentAcquisitionElapsedMs: 100, environmentAcquisitionBudgetMs: 2_000, + } } }); + expect(JSON.stringify(events)).not.toContain("private-acquire-"); + expect(events.find(entry => entry !== event)).not.toHaveProperty("contexts.run_execution"); + }); + it("sends base-ref observations through the real scrubber and transport without private payloads", async () => { const Sentry = sentryPackage!; const events: Array> = []; diff --git a/server/src/services/__tests__/run-failure-diagnostics.test.ts b/server/src/services/__tests__/run-failure-diagnostics.test.ts index 0a6708766c2..4a7384c5db6 100644 --- a/server/src/services/__tests__/run-failure-diagnostics.test.ts +++ b/server/src/services/__tests__/run-failure-diagnostics.test.ts @@ -1,3 +1,4 @@ +import { captureEnvironmentAcquisitionDiagnostic } from "../environment-acquisition-diagnostics.js"; import { describe, expect, it } from "vitest"; import type { heartbeatRuns } from "@paperclipai/db"; import { collectRunFailureDiagnostics, collectRunFailureSecretValues, redactRunFailureSecretValues, sanitizeRunFailureDiagnostics, sanitizeRunFailureText } from "../run-failure-diagnostics.js"; @@ -7,6 +8,36 @@ const run = (overrides: Partial = {}) => ({ resultJson: null, ...overrides const collect = (error: unknown) => collectRunFailureDiagnostics(run(), { error }); describe("run failure diagnostics", () => { + it("reports only private acquisition observations for the exact failed setup run", () => { + const scope = { companyId: "company-fixture", environmentId: "environment-fixture", runId: "run-fixture" }; + const diagnostic = { phase: "workspace", elapsedMs: 100, budgetMs: 2_000 } as const; + const error = Object.freeze(new Error("Acquisition failed")); + const properties = Object.getOwnPropertyDescriptors(error); + captureEnvironmentAcquisitionDiagnostic(error, scope, diagnostic); + const fixture = run({ id: scope.runId, companyId: scope.companyId, errorCode: "setup_failed" }); + const collectSetup = (failure: unknown, record = fixture) => collectRunFailureDiagnostics(record, { error: failure, phase: "setup" }).execution; + expect(collectSetup(new Error("Cleanup confirmed", { cause: error }))).toMatchObject({ + environmentAcquisitionPhase: "workspace", environmentAcquisitionElapsedMs: 100, environmentAcquisitionBudgetMs: 2_000, + }); + expect(collectSetup(error, run({ ...fixture, id: "another-run" }))).not.toHaveProperty("environmentAcquisitionPhase"); + expect(collectSetup(error, run({ ...fixture, companyId: "another-company" }))).not.toHaveProperty("environmentAcquisitionPhase"); + expect(collectSetup(error, run({ ...fixture, errorCode: "adapter_failed" }))).not.toHaveProperty("environmentAcquisitionPhase"); + expect(collectRunFailureDiagnostics(fixture, { error, phase: "execute" }).execution).not.toHaveProperty("environmentAcquisitionPhase"); + expect(Object.getOwnPropertyDescriptors(error)).toEqual(properties); + captureEnvironmentAcquisitionDiagnostic(error, scope, null); + expect(collectSetup(error)).not.toHaveProperty("environmentAcquisitionPhase"); + }); + + it("ignores forged acquisition fields and persisted JSON without private producer evidence", () => { + const acquisitionDiagnostic = { phase: "shell", elapsedMs: 2_000, budgetMs: 2_000 }; + const error = Object.assign(new Error("Acquisition failed"), { acquisitionDiagnostic, + data: { schema: "paperclip/environment-creation-cleanup/v1", acquisitionDiagnostic }, + }); + expect(collectRunFailureDiagnostics(run({ errorCode: "setup_failed", resultJson: { acquisitionDiagnostic, + environmentAcquisitionPhase: "shell", environmentAcquisitionElapsedMs: 2_000, + } }), { error, phase: "setup" }).execution).toEqual({ failurePhase: "setup" }); + }); + it("exports only bounded workspace base-ref observations without treating them as proof", () => { const resultJson = { configurationIncomplete: { reason: "workspace_base_ref_unresolved", requestedRef: "private-ref", fetchError: "private-stderr", baseRefDiagnostic: { diff --git a/server/src/services/environment-acquisition-diagnostics.ts b/server/src/services/environment-acquisition-diagnostics.ts new file mode 100644 index 00000000000..613e19ed565 --- /dev/null +++ b/server/src/services/environment-acquisition-diagnostics.ts @@ -0,0 +1,23 @@ +import type { PluginEnvironmentAcquisitionDiagnostic } from "@paperclipai/plugin-sdk"; + +type Scope = { companyId: string; environmentId: string; runId: string }; +const evidence = new WeakMap(); + +/** The acquire RPC boundary validates the error class, ownership and diagnostic. */ +export function captureEnvironmentAcquisitionDiagnostic( + error: unknown, scope: Scope, diagnostic: PluginEnvironmentAcquisitionDiagnostic | null, +): void { + if (!error || typeof error !== "object") return; + // A reused error cannot carry an earlier receipt into a later invalid call. + evidence.delete(error); + if (diagnostic) evidence.set(error, { scope: { ...scope }, diagnostic: { ...diagnostic } }); +} + +/** Only the run that acquired this private receipt may report it. */ +export function getEnvironmentAcquisitionDiagnostic( + error: unknown, run: { id: string; companyId: string }, +): PluginEnvironmentAcquisitionDiagnostic | null { + const receipt = error && typeof error === "object" ? evidence.get(error) : undefined; + return receipt && receipt.scope.runId === run.id && receipt.scope.companyId === run.companyId + ? { ...receipt.diagnostic } : null; +} diff --git a/server/src/services/environment-runtime.ts b/server/src/services/environment-runtime.ts index 06816cbd2c9..de0a695142d 100644 --- a/server/src/services/environment-runtime.ts +++ b/server/src/services/environment-runtime.ts @@ -1,7 +1,8 @@ import { beginIdleTrackedWork } from "./task-admission.js"; import { hasStopOnlyCleanup, prepareSandboxStopAndRetain, readStopOnlyCleanup, settleStopOnlyCleanup, stopOnlyCleanupKey } from "./sandbox-stop-and-retain.js"; -import { readEnvironmentCreationCleanupError } from "@paperclipai/plugin-sdk"; +import { JsonRpcCallError, readEnvironmentAcquisitionDiagnostic, readEnvironmentCreationCleanupError } from "@paperclipai/plugin-sdk"; import { preserveEnvironmentSyncOutErrorDiagnostic } from "./environment-sync-out-error.js"; +import { captureEnvironmentAcquisitionDiagnostic } from "./environment-acquisition-diagnostics.js"; import { remoteTerminationReceipt } from "./remote-execution-termination.js"; import { hasNativeWorkspaceExportResume, releaseCompletedNativeWorkspaceExportRetention } from "./native-runtime/native-workspace-export-resume.js"; import { createHash, randomUUID } from "node:crypto"; @@ -2126,11 +2127,17 @@ function createSandboxEnvironmentDriver( ), ); } catch (error) { + captureEnvironmentAcquisitionDiagnostic(error, { + companyId: input.companyId, environmentId: input.environment.id, runId: acquisitionRunId, + }, null); const cleanup = readEnvironmentCreationCleanupError(error); // The authenticated worker may identify its uncertain allocation, // but cannot redirect cleanup to another company, environment, or run. if (cleanup && cleanup.companyId === input.companyId && cleanup.environmentId === input.environment.id && cleanup.runId === acquisitionRunId) { + if (error instanceof JsonRpcCallError) captureEnvironmentAcquisitionDiagnostic(error, { + companyId: input.companyId, environmentId: input.environment.id, runId: acquisitionRunId, + }, readEnvironmentAcquisitionDiagnostic(error)); const cleanupMetadata = { ...sandboxConfigForLeaseMetadata(storedConfig), failedCreateCleanup: cleanup, diff --git a/server/src/services/run-failure-diagnostics.ts b/server/src/services/run-failure-diagnostics.ts index a1d7a2a6a32..9d2f7662692 100644 --- a/server/src/services/run-failure-diagnostics.ts +++ b/server/src/services/run-failure-diagnostics.ts @@ -1,4 +1,5 @@ import { readWorkspaceBaseRefDiagnostic } from "./workspace-base-ref-diagnostics.js"; +import { getEnvironmentAcquisitionDiagnostic } from "./environment-acquisition-diagnostics.js"; import type { heartbeatRuns } from "@paperclipai/db"; import { readRunCancellation } from "./run-cancellation.js"; import { readProcessLossDiagnostic } from "./process-loss-diagnostics.js"; @@ -249,6 +250,13 @@ export function collectRunFailureDiagnostics(run: Run, options: RunFailureReport break; } if (typeof error !== "object") break; + const acquisition = options.phase === "setup" && run.errorCode === "setup_failed" + ? getEnvironmentAcquisitionDiagnostic(error, run) : null; + if (acquisition && execution.environmentAcquisitionPhase === undefined) { + execution.environmentAcquisitionPhase = acquisition.phase; + execution.environmentAcquisitionElapsedMs = acquisition.elapsedMs; + execution.environmentAcquisitionBudgetMs = acquisition.budgetMs; + } if (execution.restoreLockOwnerState === undefined && read(error, "code") === "ERR_WORKSPACE_RESTORE_LOCK_TIMEOUT") { const lock = read(error, "workspaceRestoreLock"); const operation = read(lock, "operation");