From 57f1afdf19f3fe2d55729b79a6e83b59ce739184 Mon Sep 17 00:00:00 2001 From: Dotta <34892728+cryppadotta@users.noreply.github.com> Date: Wed, 11 Nov 2026 10:04:17 -0600 Subject: [PATCH] fix(daytona): retry a sandbox create that timed out before any agent work (#20828) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit ## Thinking Path > - Paperclip is the open source app people use to manage AI agents for work > - On a Daytona sandbox environment, every new task run first creates a fresh sandbox > - When one Daytona create did not start, the plugin waited the full 300 s acquisition budget > - The run then failed `setup_failed` with `lease_acquire_failed`. No agent work had started, but nothing retried it > - On staging this hit two agents in 15 minutes. Each attempt used about 5 minutes, and the task stopped until a person pressed Retry. The manual Retry then got a sandbox in 28 s > - This pull request ends a stuck create early, adopts a create that started late, and routes the timeout to the bounded bootstrap retry that already exists for transient provider refusals > - The benefit is that a stuck create costs about 90 s and recovers by itself. The task shows Retry only after the bounded attempts are used up ## Linked Issues or Issue Description Refs #20626 (bounded resume of a reusable sandbox), Refs #20212 (wait out a Daytona state change), Refs #20609 (force a stuck stop). **What happened?** A run on a Daytona sandbox environment failed after 307 s with `Failed to acquire lease for environment "Paperclip Sandbox" (sandbox): Daytona lease acquisition timed out; allocation cleanup is pending`. The run recorded `errorCode: setup_failed`, `failureCause: lease_acquire_failed`, and `executionRecovery: { kind: "bootstrap", providerWorkStarted: false }`. The task became blocked with Retry. No automatic retry was scheduled. **Steps to reproduce** 1. Use a Daytona sandbox environment with the default `timeoutMs` (300,000). 2. Start a run while Daytona keeps the new sandbox in `creating`. 3. See that the run waits 300 s, fails `setup_failed`, and is not retried. **Expected behavior** A create that has not started before provider work must not cost 5 minutes. The run must retry by itself within bounds. A late sandbox that has started must be used. A sandbox that was abandoned must be removed. **Root cause** - `packages/plugins/sandbox-providers/daytona/src/plugin.ts` (`onEnvironmentAcquireLease`): the only bound on the create step was the whole acquisition budget (`timeoutMs`, default 300 s). - `server/src/services/environment-provider-unavailable-error.ts` (`readTransientEnvironmentProviderFailure`): only an HTTP status or errno on the create call counted as transient. The timeout envelope carries neither, so the run fell through to generic `setup_failed`, which `isTransientWorkspacePreparationCode` does not retry. ## What Changed - Daytona: one fresh acquisition is now capped at 180 s. A create that has not returned after 90 s is looked up once by its creation name. A sandbox in `started` is adopted, and setup continues. A sandbox in `pending_build`, `building_snapshot`, or `pulling_snapshot` keeps waiting inside the cap. Any other state ends the attempt with the existing cleanup envelope and an acquisition diagnostic whose elapsed time reached the expired budget. - Daytona: a late SDK failure no longer runs the compensating delete for a sandbox that was adopted. - Host: `readTransientEnvironmentProviderFailure` reads the validated acquisition diagnostic. An acquisition whose first failure was its own deadline is transient. The run fails with `environment_provider_unavailable`, category `timeout`, and uses the bounded bootstrap retry (30 s, then 60 s). An earlier setup failure stays `setup_failed`. Message text is never parsed. - Host: the task reason for this case is plain: "The sandbox for ... did not finish starting in time. No agent work had started. Paperclip retries automatically ...". - Docs: `doc/execution-semantics.md` and `doc/plugins/SANDBOX_PROVIDER_CAPABILITIES.md`. ## Verification Red before the fix, green after: - `server/src/services/heartbeat/run-completion.test.ts` "routes a fresh sandbox create that timed out through bounded bootstrap recovery" uses the staging error shape through the orchestrator. Red: `errorCode` was `setup_failed`. Green: `environment_provider_unavailable`, category `timeout`, bounded retry scheduled. The `started` and `early_failure` cases stay `setup_failed` with no retry. - `server/src/services/environment-provider-unavailable-error.test.ts`: deadline diagnostic is transient (red, then green). An early failure is not. The task message is plain. - `packages/plugins/sandbox-providers/daytona/src/plugin.test.ts`: "ends a create still pending at 90 seconds" (red: still pending at 90 s; green) and "adopts a create that started by 90 seconds" (red; green, and a late SDK rejection does not delete it). "keeps waiting for a create that is still preparing its snapshot" is a safety case. - Existing tests that encoded the 300 s acquisition budget now use the 180 s cap. Commands run locally: - `npx vitest run src/plugin.test.ts` (Daytona): 414 passed. - `npx vitest run src/services/heartbeat/run-completion.test.ts src/services/environment-provider-unavailable-error.test.ts src/__tests__/environment-acquisition-diagnostics.test.ts src/__tests__/task-interruption-query.test.ts`: 229 tests passed. The run-completion file reports an `afterAll` embedded-Postgres teardown timeout. The same timeout occurs on unchanged `origin/master`, so it is a local platform fault. - Daytona plugin `pnpm typecheck` and server `pnpm typecheck`: pass. - `pnpm verify`: asked for broader CI coverage, because `doc/execution-semantics.md` is a global CI input. Required CI supplies that coverage. Upgrade safety: nothing new is persisted. A task already blocked by this failure keeps `canRetry: true`. Its Retry starts a new run with a new creation record, and that run uses the new path. On staging, the manual Retry of the affected task got a fresh lease in 28 s. The creation record of the earlier attempt stays with the creation reconciler. Not verified: a live Daytona create that stays in `creating`. That cannot be forced on demand. ## Risks - A legitimately slow create that stays in `creating` or `starting` for more than 90 s now ends the attempt and retries. Snapshot preparation states still wait inside the 180 s cap. Staging creates normally take about 20 to 30 s. - An abandoned create is removed by the creation reconciler. It can stay alive until that reconciler settles the record (the existing settle window). This PR does not change that window. - Other sandbox providers get the host classification only when they send the same acquisition diagnostic. ## Model Used Claude Opus 5.5 (claude-opus-5-5), Anthropic, used through Claude Code with tool use (shell, file edits, browser for read-only staging API reads). ## 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 - [ ] 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 --- doc/execution-semantics.md | 12 +- doc/plugins/SANDBOX_PROVIDER_CAPABILITIES.md | 20 ++- .../daytona/src/plugin.test.ts | 119 ++++++++++++++++-- .../sandbox-providers/daytona/src/plugin.ts | 79 ++++++++++-- ...ronment-provider-unavailable-error.test.ts | 27 ++++ .../environment-provider-unavailable-error.ts | 24 ++-- .../services/heartbeat/run-completion.test.ts | 27 ++++ 7 files changed, 268 insertions(+), 40 deletions(-) diff --git a/doc/execution-semantics.md b/doc/execution-semantics.md index bd85a0b0f72..e84dd070334 100644 --- a/doc/execution-semantics.md +++ b/doc/execution-semantics.md @@ -1440,11 +1440,13 @@ status, errno-style code), never by provider text. On exhaustion, the task gets specific recovery notice, and generic recovery does not grant another budget. An environment provider that refuses a new lease with a transient status (HTTP -408, 425, 429, 500, 502, 503 or 504, or a closed connection errno) before provider -dispatch uses the same bounded bootstrap budget (`environment_provider_unavailable`). -The status comes only from structured fields: the worker's validated acquisition -envelope or the in-process error's status; message text is never parsed, and -other statuses stay `setup_failed`. Each retry is a new creation attempt with its +408, 425, 429, 500, 502, 503 or 504, or a closed connection errno), or whose +acquisition reached its own deadline, before provider dispatch uses the same +bounded bootstrap budget (`environment_provider_unavailable`). The status comes +only from structured fields: the worker's validated acquisition envelope, its +acquisition diagnostic (a first failure at or after the expired budget), or the +in-process error's status; message text is never parsed, and other statuses and +earlier setup failures stay `setup_failed`. Each retry is a new creation attempt with its own durable creation record and provider name. A provisional allocation whose cleanup could not be confirmed stays owned by its own record, which the creation reconciler settles; a retry neither reuses nor abandons it. The task shows the diff --git a/doc/plugins/SANDBOX_PROVIDER_CAPABILITIES.md b/doc/plugins/SANDBOX_PROVIDER_CAPABILITIES.md index 796b487ebbd..ce7e6bdf0eb 100644 --- a/doc/plugins/SANDBOX_PROVIDER_CAPABILITIES.md +++ b/doc/plugins/SANDBOX_PROVIDER_CAPABILITIES.md @@ -18,12 +18,20 @@ resolved config has no positive finite numeric `timeoutMs`. A positive numeric `bridgeRequestTimeoutMs` can extend that budget. The host adds 30 seconds for RPC overhead. This applies to both sandbox providers and generic plugin drivers. -Daytona declares 300,000 milliseconds for the entire fresh acquisition. Creation, -workspace setup, shell detection, expiry setup, and inline failure cleanup share -that budget. Its host RPC can therefore wait 330 seconds instead of the worker's -normal 30 seconds. On timeout the provider returns the attempt's scoped cleanup -record for durable host reconciliation. Late SDK results cannot admit the lease -or start the next setup phase. +Daytona declares 300,000 milliseconds, and its host RPC can therefore wait 330 +seconds instead of the worker's normal 30 seconds. The worker itself caps one +fresh acquisition at 180 seconds. Creation, workspace setup, shell detection, +expiry setup, and inline failure cleanup share that cap. A create that has not +returned after 90 seconds is looked up once by its creation name: a sandbox that +has started is adopted and setup continues, one still preparing its snapshot +keeps waiting within the cap, and any other state ends the attempt. On timeout +the provider returns the attempt's scoped cleanup record and an acquisition +diagnostic whose elapsed time has reached the expired budget. The host treats +that diagnostic as a transient provider failure (`environment_provider_unavailable`), +so the run is retried with the bounded bootstrap budget while the creation +reconciler removes the abandoned allocation. Late SDK results cannot admit the +lease or start the next setup phase, and a late SDK failure never deletes an +adopted sandbox. Drivers that omit the declaration keep the existing fallback. The host does not infer this budget from config-schema defaults: a field named `timeoutMs` can describe sandbox lifetime instead of the time needed to acquire it. diff --git a/packages/plugins/sandbox-providers/daytona/src/plugin.test.ts b/packages/plugins/sandbox-providers/daytona/src/plugin.test.ts index 1ecd185ea8a..1bde131bbac 100644 --- a/packages/plugins/sandbox-providers/daytona/src/plugin.test.ts +++ b/packages/plugins/sandbox-providers/daytona/src/plugin.test.ts @@ -1350,11 +1350,11 @@ describe("Daytona sandbox provider plugin", () => { mockGet.mockImplementation(() => new Promise(() => {})); let settled = false; const pending = plugin.definition.onEnvironmentAcquireLease!(params).catch(error => { settled = true; return error; }); - await vi.advanceTimersByTimeAsync(304_999); + await vi.advanceTimersByTimeAsync(94_999); expect(settled).toBe(false); await vi.advanceTimersByTimeAsync(1); const error = await pending; - expect(readEnvironmentAcquisitionDiagnostic(error)).toEqual({ phase: "create", elapsedMs: 300_000, budgetMs: 300_000, providerState: "unavailable" }); + expect(readEnvironmentAcquisitionDiagnostic(error)).toEqual({ phase: "create", elapsedMs: 90_000, budgetMs: 90_000, providerState: "unavailable" }); expect(error.message).toBe("Daytona lease acquisition timed out; allocation cleanup is pending"); }); @@ -1406,22 +1406,125 @@ describe("Daytona sandbox provider plugin", () => { expect(await plugin.definition.onEnvironmentAcquireLease!(params)).not.toHaveProperty("acquisitionDiagnostic"); }); + it("ends a create still pending at 90 seconds instead of waiting out five minutes", async () => { + mockCreate.mockImplementation(() => new Promise(() => {})); + let found: ReturnType | undefined; + mockGet.mockImplementation(async () => (found = ownedCreation("creating"))); + let settled = false; + const pending = plugin.definition.onEnvironmentAcquireLease!(params).catch(error => { settled = true; return error; }); + await vi.advanceTimersByTimeAsync(89_999); + expect(settled).toBe(false); + await vi.advanceTimersByTimeAsync(1); + const error = await pending; + expect(error.message).toBe("Daytona lease acquisition timed out; allocation cleanup is pending"); + expect(readEnvironmentAcquisitionDiagnostic(error)).toEqual({ phase: "create", elapsedMs: 90_000, budgetMs: 90_000, providerState: "creating" }); + expect(readEnvironmentCreationCleanupError(error)?.providerLeaseId).toBe(mockCreate.mock.calls[0][0].name); + expect(found!.getWorkDir).not.toHaveBeenCalled(); + }); + + it("adopts a create that started by 90 seconds although its SDK wait is still pending", async () => { + let rejectCreate!: (error: Error) => void; + mockCreate.mockImplementation(() => new Promise((_resolve, reject) => { rejectCreate = reject; })); + let found: ReturnType | undefined; + mockGet.mockImplementation(async () => (found ??= ownedCreation("started"))); + const pending = plugin.definition.onEnvironmentAcquireLease!(params); + await vi.advanceTimersByTimeAsync(90_000); + const lease = await pending; + expect(lease).toMatchObject({ providerLeaseId: found!.id }); + expect(found!.getWorkDir).toHaveBeenCalled(); + rejectCreate(new MockDaytonaTimeoutError("late SDK wait")); + await vi.advanceTimersByTimeAsync(30_000); + expect(found!.delete).not.toHaveBeenCalled(); + }); + + it("uses a create that succeeds while its 90 second lookup is still pending", async () => { + const sandbox = createMockSandbox(); + mockCreate.mockImplementation(() => new Promise(resolve => setTimeout(() => resolve(sandbox), 91_000))); + mockGet.mockImplementation(() => new Promise(() => {})); + const pending = plugin.definition.onEnvironmentAcquireLease!(params).catch(error => error); + await vi.advanceTimersByTimeAsync(96_000); + expect(await pending).toMatchObject({ providerLeaseId: sandbox.id }); + expect(sandbox.getWorkDir).toHaveBeenCalled(); + expect(sandbox.delete).not.toHaveBeenCalled(); + }); + + it("never adopts a sandbox whose failed create already started its cleanup", async () => { + const createError = new MockDaytonaTimeoutError("SDK wait ended"); + mockCreate.mockImplementation(() => new Promise((_resolve, reject) => setTimeout(() => reject(createError), 91_000))); + let found: ReturnType | undefined; + mockGet.mockImplementationOnce(() => new Promise(resolve => setTimeout(() => resolve(found ??= ownedCreation("started")), 3_000))) + .mockImplementation(async () => (found ??= ownedCreation("started"))); + let settled = false; + const pending = plugin.definition.onEnvironmentAcquireLease!(params).then( + lease => { settled = true; return lease; }, error => { settled = true; return error; }); + await vi.advanceTimersByTimeAsync(95_000); + expect(settled).toBe(true); + expect(await pending).toBe(createError); + expect(found!.delete).toHaveBeenCalledOnce(); + expect(found!.getWorkDir).not.toHaveBeenCalled(); + }); + + it.each([ + ["missing", () => undefined], + ["expired", () => new Date(Date.now() - 1_000).toISOString()], + ["too distant", () => new Date(Date.now() + 120 * 60_000).toISOString()], + ])("rejects and deletes an adopted sandbox whose creation TTL is %s", async (_label, autoDestroyAt) => { + mockCreate.mockImplementation(() => new Promise(() => {})); + let found: ReturnType | undefined; + mockGet.mockImplementation(async () => { + if (!found) { found = ownedCreation("started"); found.autoDestroyAt = autoDestroyAt(); } + return found; + }); + const pending = plugin.definition.onEnvironmentAcquireLease!({ ...params, config: { ...params.config, ttlMinutes: 30 } }) + .catch(error => error); + await vi.advanceTimersByTimeAsync(91_000); + const error = await pending; + expect(error.message).toBe("Daytona did not confirm the configured creation TTL."); + expect(found!.refreshData).toHaveBeenCalled(); + expect(found!.getWorkDir).not.toHaveBeenCalled(); + expect(found!.delete).toHaveBeenCalledOnce(); + }); + + it("admits an adopted sandbox whose creation TTL is confirmed", async () => { + mockCreate.mockImplementation(() => new Promise(() => {})); + let found: ReturnType | undefined; + mockGet.mockImplementation(async () => { + if (!found) { found = ownedCreation("started"); found.autoDestroyAt = new Date(Date.now() + 20 * 60_000).toISOString(); } + return found; + }); + const pending = plugin.definition.onEnvironmentAcquireLease!({ ...params, config: { ...params.config, ttlMinutes: 30 } }); + await vi.advanceTimersByTimeAsync(91_000); + expect(await pending).toMatchObject({ providerLeaseId: found!.id }); + expect(found!.delete).not.toHaveBeenCalled(); + }); + + it("keeps waiting for a create that is still preparing its snapshot at 90 seconds", async () => { + const sandbox = createMockSandbox(); + mockCreate.mockImplementation(() => new Promise(resolve => setTimeout(() => resolve(sandbox), 120_000))); + mockGet.mockImplementation(async () => ownedCreation("pulling_snapshot")); + const pending = plugin.definition.onEnvironmentAcquireLease!(params); + await vi.advanceTimersByTimeAsync(121_000); + expect(await pending).toMatchObject({ providerLeaseId: sandbox.id }); + }); + 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))); + mockCreate.mockImplementation(() => new Promise(resolve => setTimeout(() => resolve(sandbox), 160_000))); + mockGet.mockImplementation(async () => ownedCreation("pulling_snapshot")); sandbox.process.executeCommand.mockImplementation(() => new Promise(resolve => setTimeout(() => resolve({ result: "bash" }), 15_000))); const pending = plugin.definition.onEnvironmentAcquireLease!(params); - await vi.advanceTimersByTimeAsync(295_000); + await vi.advanceTimersByTimeAsync(175_000); expect(await pending).toMatchObject({ providerLeaseId: sandbox.id }); expect(vi.getTimerCount()).toBe(0); }); it("journals ownership before the host deadline when setup outlasts creation", async () => { const sandbox = createMockSandbox(); - mockCreate.mockImplementation(() => new Promise(resolve => setTimeout(() => resolve(sandbox), 280_000))); + mockCreate.mockImplementation(() => new Promise(resolve => setTimeout(() => resolve(sandbox), 160_000))); + mockGet.mockImplementation(async () => ownedCreation("pulling_snapshot")); sandbox.process.executeCommand.mockImplementation(() => new Promise(resolve => setTimeout(() => resolve({ result: "bash" }), 55_000))); const pending = plugin.definition.onEnvironmentAcquireLease!(params).catch(error => error); - await vi.advanceTimersByTimeAsync(300_000); + await vi.advanceTimersByTimeAsync(180_000); const cleanup = readEnvironmentCreationCleanupError(await pending); expect(cleanup).toMatchObject({ companyId: params.companyId, environmentId: params.environmentId, runId: params.runId, observedProviderLeaseId: sandbox.id, providerLeaseId: mockCreate.mock.calls[0][0].name }); @@ -1470,7 +1573,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 }); + expect(readEnvironmentAcquisitionDiagnostic(error)).toEqual({ phase: "workspace", elapsedMs: 0, budgetMs: 180_000 }); }); }); @@ -1804,7 +1907,7 @@ describe("Daytona sandbox provider plugin", () => { expect(sandbox.fs.uploadFile).toHaveBeenCalledWith( expect.any(Buffer), "/home/daytona/paperclip-workspace/.paperclip-runtime/reusable-sandbox-lease.json", - 300, + 180, ); }); diff --git a/packages/plugins/sandbox-providers/daytona/src/plugin.ts b/packages/plugins/sandbox-providers/daytona/src/plugin.ts index b6df53f97c7..69031f0970b 100644 --- a/packages/plugins/sandbox-providers/daytona/src/plugin.ts +++ b/packages/plugins/sandbox-providers/daytona/src/plugin.ts @@ -1221,6 +1221,7 @@ async function createSandbox( onCreateAttempt?: (cleanup: PluginEnvironmentCreationCleanup) => void; onCreateFailure?: () => PluginEnvironmentAcquisitionDiagnostic; onSnapshotIdentity?: (identity: SnapshotIdentity) => void; + claimCleanup?: () => boolean; } = {}, ): Promise { const resourceRequestError = validateCreationTtl(config) ?? validateRuntimeResourceRequest(config); @@ -1275,15 +1276,11 @@ async function createSandbox( idleActivity.observe(allocation, providerActivityKey(params, config, sandbox.id)); if (config.ttlMinutes != null) { cleanup.observedProviderLeaseId = sandbox.id; - await withLivenessTimeout("sandbox.refreshData", config.livenessTimeoutMs, () => sandbox.refreshData()); - const expiry = Date.parse(sandbox.autoDestroyAt ?? ""); - const nowMs = Date.now(); - if (!Number.isFinite(expiry) || expiry <= nowMs || expiry > nowMs + config.ttlMinutes * 60_000) { - throw new Error("Daytona did not confirm the configured creation TTL."); - } + await confirmCreationTtl(sandbox, config); } return sandbox; } catch (createError) { + if (options.claimCleanup && !options.claimCleanup()) throw createError; // Observe the create failure before compensating deletion can stall or fail. const diagnostic = options.onCreateFailure?.(); try { @@ -1300,6 +1297,16 @@ async function createSandbox( } } +async function confirmCreationTtl(sandbox: Sandbox, config: DaytonaDriverConfig): Promise { + if (config.ttlMinutes == null) return; + await withLivenessTimeout("sandbox.refreshData", config.livenessTimeoutMs, () => sandbox.refreshData()); + const expiry = Date.parse(sandbox.autoDestroyAt ?? ""); + const nowMs = Date.now(); + if (!Number.isFinite(expiry) || expiry <= nowMs || expiry > nowMs + config.ttlMinutes * 60_000) { + throw new Error("Daytona did not confirm the configured creation TTL."); + } +} + // Resolve by the immutable creation name, not through the admitted-lease cache: // the SDK's returned sandbox ID differs from this provisional name. Persist a // verified provider ID before host-driven deletion. Its later absence is then @@ -1364,20 +1371,32 @@ const REPORTED_CREATE_STATES = new Set([ // One read-only lookup of the provisional creation name, so a create deadline // records where the provider left the allocation. It neither deletes nor // records an observed ID: the host-owned cleanup envelope is unchanged. -async function observeCreateState( +async function lookupCreation( config: DaytonaDriverConfig, cleanup: PluginEnvironmentCreationCleanup, -): Promise { +): Promise<{ state: PluginEnvironmentAcquisitionProviderState; sandbox?: Sandbox }> { try { const sandbox = await withLivenessTimeout("sandbox.createStateLookup", 5_000, () => createDaytonaClient(config).get(cleanup.providerLeaseId)); if (!sandbox || sandbox.name !== cleanup.providerLeaseId || typeof sandbox.state !== "string" || - Object.entries(cleanup.labels).some(([key, value]) => sandbox.labels?.[key] !== value)) return "unavailable"; - return REPORTED_CREATE_STATES.has(sandbox.state) ? sandbox.state as PluginEnvironmentAcquisitionProviderState : "other"; + Object.entries(cleanup.labels).some(([key, value]) => sandbox.labels?.[key] !== value)) return { state: "unavailable" }; + return { state: REPORTED_CREATE_STATES.has(sandbox.state) ? sandbox.state as PluginEnvironmentAcquisitionProviderState : "other", sandbox }; } catch (error) { - return error instanceof DaytonaNotFoundError ? "absent" : "unavailable"; + return { state: error instanceof DaytonaNotFoundError ? "absent" : "unavailable" }; } } +async function observeCreateState( + config: DaytonaDriverConfig, cleanup: PluginEnvironmentCreationCleanup, +): Promise { + return (await lookupCreation(config, cleanup)).state; +} + +const DAYTONA_CREATE_ATTEMPT_MS = 90_000; +const DAYTONA_ACQUIRE_ATTEMPT_BUDGET_MS = 180_000; +const SNAPSHOT_PREPARATION_STATES = new Set([ + "pending_build", "building_snapshot", "pulling_snapshot", +]); + // ─── Per-lease started-sandbox handle cache ────────────────────────────────── // Memoize the started Daytona `Sandbox` handle so repeated exec/sync/resume/ // teardown calls on one lease skip the per-call `client.get(sandboxId)` REST @@ -2960,7 +2979,10 @@ const plugin = definePlugin(trackDaytonaHooks({ let snapshotIdentity: SnapshotIdentity | undefined; // 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 budgetMs = Math.min(config.timeoutMs > 0 ? config.timeoutMs : DEFAULT_DAYTONA_OPERATION_TIMEOUT_MS, + DAYTONA_ACQUIRE_ATTEMPT_BUDGET_MS); + const createCapMs = Math.min(DAYTONA_CREATE_ATTEMPT_MS, budgetMs); + let allocationClaim: "adopted" | "cleanup" | undefined; const startedAt = Date.now(); const deadline = startedAt + budgetMs; let expired = false; @@ -2999,13 +3021,44 @@ const plugin = definePlugin(trackDaytonaHooks({ if (createPending) diagnostic.providerState = await observeCreateState(config, createPending); return timeoutFailure(); }; + const createWithinCap = async (creating: Promise): Promise => { + let createdBeforeDecision = false; + creating.then(() => { createdBeforeDecision = true; }, () => undefined); + let capTimer: ReturnType | undefined; + const capReached = await Promise.race([ + creating.then(() => false, () => false), + new Promise(resolve => { capTimer = setTimeout(() => resolve(true), Math.max(0, startedAt + createCapMs - Date.now())); }), + ]).finally(() => clearTimeout(capTimer)); + if (!capReached || !cleanup || expired || phase !== "create" || firstFailure) return creating; + const elapsedMs = Math.max(createCapMs, Date.now() - startedAt); + const observed = await lookupCreation(config, cleanup); + if (expired || createdBeforeDecision || allocationClaim === "cleanup" || firstFailure) return creating; + if (observed.state === "started" && observed.sandbox) { + allocationClaim = "adopted"; + cleanup.observedProviderLeaseId = observed.sandbox.id; + idleActivity.observe(idleActivity.resource(providerActivityKey(params, config, cleanup.providerLeaseId), true), + providerActivityKey(params, config, observed.sandbox.id)); + return observed.sandbox; + } + if (SNAPSHOT_PREPARATION_STATES.has(observed.state)) return creating; + firstFailure = { phase: "create", elapsedMs, budgetMs: createCapMs, providerState: observed.state }; + expired = true; + throw timeoutFailure(); + }; const acquire = async (): Promise => { - const sandbox = await traceLeaseStep("lease.create", () => createSandbox(params, config, { + const creating = traceLeaseStep("lease.create", () => createSandbox(params, config, { onCreateAttempt: (attempt) => { assertActive(); cleanup = attempt; }, onCreateFailure: observeFailure, onSnapshotIdentity: identity => { snapshotIdentity = identity; }, + claimCleanup: () => { + if (allocationClaim === "adopted") return false; + allocationClaim = "cleanup"; + return true; + }, })); + const sandbox = createCapMs < budgetMs ? await createWithinCap(creating) : await creating; try { + if (allocationClaim === "adopted") await confirmCreationTtl(sandbox, config); assertActive(); if (cleanup) cleanup.observedProviderLeaseId = sandbox.id; phase = "workspace"; diff --git a/server/src/services/environment-provider-unavailable-error.test.ts b/server/src/services/environment-provider-unavailable-error.test.ts index 8c42fdd31c7..319647827a3 100644 --- a/server/src/services/environment-provider-unavailable-error.test.ts +++ b/server/src/services/environment-provider-unavailable-error.test.ts @@ -49,6 +49,24 @@ describe("readTransientEnvironmentProviderFailure", () => { expect(readTransientEnvironmentProviderFailure(rpcError)).toEqual({ httpStatus: 429 }); }); + const stagingLeaseTimeout = (diagnostic: { phase: string; elapsedMs: number; budgetMs: number; providerState?: string }) => + Object.assign(new Error("Daytona lease acquisition timed out; allocation cleanup is pending"), { + data: { schema: "paperclip/environment-creation-cleanup/v1", + cleanup: { providerLeaseId: "paperclip-create-05f81d77", companyId: "company", environmentId: "environment", + runId: "f41857b6", attemptId: "05f81d77", accountFingerprint: "a".repeat(64), + labels: { "paperclip-provider": "daytona", "paperclip-create-attempt": "05f81d77" } }, + acquisitionDiagnostic: diagnostic }, + }); + + it("treats an acquisition that reached its deadline as transient", () => { + const timeout = stagingLeaseTimeout({ phase: "create", elapsedMs: 300_004, budgetMs: 300_000, providerState: "creating" }); + expect(readTransientEnvironmentProviderFailure(new Error("outer", { cause: timeout }))).toEqual({ acquisitionTimedOut: true }); + }); + + it("does not retry an acquisition whose first failure came before its deadline", () => { + expect(readTransientEnvironmentProviderFailure(stagingLeaseTimeout({ phase: "workspace", elapsedMs: 100, budgetMs: 300_000 }))).toBeNull(); + }); + it("never parses message text", () => { expect(readTransientEnvironmentProviderFailure(new Error("HTTP 502 Bad Gateway ECONNRESET"))).toBeNull(); }); @@ -70,6 +88,15 @@ describe("EnvironmentProviderUnavailableError", () => { expect(error.providerFailure.retryability).toBe("transient"); }); + it("names an acquisition timeout in plain words", () => { + const error = new EnvironmentProviderUnavailableError({ + environmentName: "Paperclip Sandbox", driver: "sandbox", evidence: { acquisitionTimedOut: true }, cause: null, + }); + expect(error.providerFailure).toMatchObject({ category: "timeout", retryability: "transient", phase: "startup" }); + expect(error.providerFailure.message).toContain("did not finish starting"); + expect(error.providerFailure.message).not.toMatch(/ETIMEDOUT|undefined/); + }); + it("falls back to a generic provider label for an unsafe driver key", () => { const error = new EnvironmentProviderUnavailableError({ environmentName: "env", driver: "bad driver ", evidence: { httpStatus: 502 }, cause: null, diff --git a/server/src/services/environment-provider-unavailable-error.ts b/server/src/services/environment-provider-unavailable-error.ts index f6f0357db9b..488a57bda00 100644 --- a/server/src/services/environment-provider-unavailable-error.ts +++ b/server/src/services/environment-provider-unavailable-error.ts @@ -1,10 +1,11 @@ -import { readEnvironmentAcquireErrorDiagnostic } from "@paperclipai/plugin-sdk"; +import { readEnvironmentAcquireErrorDiagnostic, readEnvironmentAcquisitionDiagnostic } from "@paperclipai/plugin-sdk"; import type { ProviderFailure } from "@paperclipai/shared"; /** * Setup failure code for a lease acquisition that the environment provider * refused with a transient status (HTTP 408/425/429/5xx or a connection-level - * errno) before any agent work started. The run is retried with the bounded + * errno), or that reached its own acquisition deadline, before any agent work + * started. The run is retried with the bounded * bootstrap budget. A provisional allocation whose cleanup could not be * confirmed stays owned by its own creation record, which the cleanup * reconciler settles independently; every retry is a new creation attempt @@ -20,7 +21,7 @@ const TRANSIENT_ERROR_CODES = new Set([ "UND_ERR_CONNECT_TIMEOUT", "UND_ERR_SOCKET", ]); -type TransientProviderEvidence = { httpStatus?: number; errorCode?: string }; +type TransientProviderEvidence = { httpStatus?: number; errorCode?: string; acquisitionTimedOut?: true }; function own(value: unknown, key: string): unknown { try { @@ -31,10 +32,13 @@ function own(value: unknown, key: string): unknown { /** * Read transient provider evidence from structured fields only: the validated * plugin RPC envelope, or the status/errno an in-process provider attached to - * its error. Message text is never parsed. + * its error. An acquisition whose first failure was its own deadline is + * transient too. Message text is never parsed. */ export function readTransientEnvironmentProviderFailure(error: unknown): TransientProviderEvidence | null { for (let cause = error, depth = 0; cause && depth < 5; cause = own(cause, "cause"), depth++) { + const acquisition = readEnvironmentAcquisitionDiagnostic(cause); + if (acquisition && acquisition.elapsedMs >= acquisition.budgetMs) return { acquisitionTimedOut: true }; const envelope = readEnvironmentAcquireErrorDiagnostic(cause); const statusValue = envelope?.httpStatus ?? [own(cause, "status"), own(cause, "statusCode")] .find(value => Number.isInteger(value)); @@ -52,7 +56,7 @@ export function readTransientEnvironmentProviderFailure(error: unknown): Transie function category(evidence: TransientProviderEvidence): ProviderFailure["category"] { if (evidence.httpStatus === 429) return "rate_limit"; - if (evidence.httpStatus === 408 || evidence.httpStatus === 504 + if (evidence.acquisitionTimedOut || evidence.httpStatus === 408 || evidence.httpStatus === 504 || evidence.errorCode === "ETIMEDOUT" || evidence.errorCode === "UND_ERR_CONNECT_TIMEOUT") return "timeout"; return "overloaded"; } @@ -66,8 +70,10 @@ export class EnvironmentProviderUnavailableError extends Error { readonly providerFailure: ProviderFailure; constructor(input: { environmentName: string; driver: string; evidence: TransientProviderEvidence; cause: unknown }) { - const status = input.evidence.httpStatus !== undefined ? `HTTP ${input.evidence.httpStatus}` : input.evidence.errorCode!; - super(`Environment provider for "${input.environmentName}" was temporarily unavailable (${status}).`, { cause: input.cause }); + const status = input.evidence.httpStatus !== undefined ? `HTTP ${input.evidence.httpStatus}` : input.evidence.errorCode; + super(status + ? `Environment provider for "${input.environmentName}" was temporarily unavailable (${status}).` + : `Environment provider for "${input.environmentName}" did not finish starting the sandbox in time.`, { cause: input.cause }); this.name = "EnvironmentProviderUnavailableError"; this.httpStatus = input.evidence.httpStatus ?? null; this.errorCode = input.evidence.errorCode ?? null; @@ -76,7 +82,9 @@ export class EnvironmentProviderUnavailableError extends Error { provider: /^[a-zA-Z0-9_.:/-]{1,80}$/.test(input.driver) ? input.driver : "environment", phase: "startup", category: category(input.evidence), - message: `The provider for "${input.environmentName}" was temporarily unavailable while Paperclip was starting it (${status}). ` + message: (status + ? `The provider for "${input.environmentName}" was temporarily unavailable while Paperclip was starting it (${status}). ` + : `The sandbox for "${input.environmentName}" did not finish starting in time. `) + "No agent work had started. Paperclip retries automatically; if those retries are used up, use Retry once the provider is available.", ...(input.evidence.httpStatus !== undefined ? { httpStatus: input.evidence.httpStatus } : {}), ...(input.evidence.errorCode !== undefined ? { providerCode: input.evidence.errorCode } : {}), diff --git a/server/src/services/heartbeat/run-completion.test.ts b/server/src/services/heartbeat/run-completion.test.ts index c0962b38469..6fc5dcfc863 100644 --- a/server/src/services/heartbeat/run-completion.test.ts +++ b/server/src/services/heartbeat/run-completion.test.ts @@ -1403,6 +1403,33 @@ describe.skipIf(!support.supported && !process.env.PAPERCLIP_TEST_DATABASE_URL)( } else expect(f.deps.scheduleBoundedRetryForRun).not.toHaveBeenCalled(); }); + // Staging run f41857b6: the Daytona create was still pending at the + // acquisition deadline, so the worker returned the cleanup envelope with a + // create-phase diagnostic and no provider status. + const daytonaLeaseTimeout = (elapsedMs: number) => new JsonRpcCallError({ code: -32000, + message: "Daytona lease acquisition timed out; allocation cleanup is pending", + data: { schema: "paperclip/environment-creation-cleanup/v1", + cleanup: { providerLeaseId: "paperclip-create-05f81d77", companyId: "company", environmentId: "environment", + runId: "f41857b6", attemptId: "05f81d77", accountFingerprint: "a".repeat(64), + labels: { "paperclip-provider": "daytona", "paperclip-create-attempt": "05f81d77" } }, + acquisitionDiagnostic: { phase: "create", elapsedMs, budgetMs: 300_000, providerState: "creating" } } }); + + it.each(["fresh", "started", "early_failure"] as const)("routes a %s sandbox create that timed out through bounded bootstrap recovery", async scenario => { + const f = await fixture(); + const error = await acquireThroughOrchestrator(daytonaLeaseTimeout(scenario === "early_failure" ? 100 : 300_004)); + f.deps.scheduleBoundedRetryForRun.mockResolvedValueOnce({ outcome: "not_scheduled", reason: "Fixture scheduler boundary", issueId: null }); + await f.completion.failRunSetup(f.setup(error, scenario === "started")); + const failed = await read(f.run.id); + const retried = scenario === "fresh"; + expect(failed).toMatchObject({ status: "failed", errorCode: retried ? "environment_provider_unavailable" : "setup_failed" }); + expect(failed.error).toContain("Daytona lease acquisition timed out"); + if (retried) { + expect(failed.resultJson).toMatchObject({ executionRecovery: { kind: "bootstrap", providerWorkStarted: false }, + providerFailure: { provider: "sandbox", phase: "startup", category: "timeout", retryability: "transient" } }); + expect(f.deps.scheduleBoundedRetryForRun).toHaveBeenCalledWith(expect.objectContaining({ id: f.run.id }), f.agent); + } else expect(f.deps.scheduleBoundedRetryForRun).not.toHaveBeenCalled(); + }); + it.each(["fresh", "started", "untrusted", "denied", "retained", "session", "runner"] as const)("bounds only an owned pre-dispatch chat binding wait: %s", async scenario => { const f = await fixture({ runtimeMode: scenario === "retained" ? "native" : "legacy", ...(scenario === "session" ? { nativeSessionId: randomUUID() } : {}),