From 2384384eeec4f32d073242ebf597b81df2df1ccb Mon Sep 17 00:00:00 2001 From: Dotta Date: Sun, 25 Oct 2026 14:26:21 -0500 Subject: [PATCH] fix(server): wake retry notices after source lease settlement Co-Authored-By: Paperclip --- ...2026-10-24-recurring-server-sleep-stack.md | 12 ++ ...-10-25-failed-retry-notices-sleep-audit.md | 98 +++++++++++++++- .../chat-channels.integration.test.ts | 106 +++++++++++++++++- .../src/__tests__/environment-service.test.ts | 18 ++- server/src/services/environments.ts | 30 +++-- 5 files changed, 247 insertions(+), 17 deletions(-) diff --git a/doc/plans/2026-10-24-recurring-server-sleep-stack.md b/doc/plans/2026-10-24-recurring-server-sleep-stack.md index b4e1807b321..0167296b6f9 100644 --- a/doc/plans/2026-10-24-recurring-server-sleep-stack.md +++ b/doc/plans/2026-10-24-recurring-server-sleep-stack.md @@ -1787,3 +1787,15 @@ cases pass. Workspace typecheck and build pass. See the retry audit for retained failures, exact commands/logs, and native source-cleanup qualification still open. This is a draft checkpoint, not a merge-ready claim. Older parent gates and every remaining original recurring-server duty stay in scope. No merge occurred. + + +## Slice 31 native producer repairs + +Draft [#17649](https://github.com/paperclipai/paperclip/pull/17649) now covers +source lease cleanup and reusable-lease retirement, each with a reproduced +missing notice and real writer transaction tests. All 36 selected native/notice +cases pass. The owning audit distinguishes notice authority from the stronger +filesystem execution proof, and retains the fake-clock connection failure and +Runner CI receipt timeout. Existing lease acceptance, updated full acceptance, +remote gates, older parent findings, and every remaining original duty are still +required. No stack PR has been merged. diff --git a/doc/plans/2026-10-25-failed-retry-notices-sleep-audit.md b/doc/plans/2026-10-25-failed-retry-notices-sleep-audit.md index 82fe5cbe584..7af02ca8485 100644 --- a/doc/plans/2026-10-25-failed-retry-notices-sleep-audit.md +++ b/doc/plans/2026-10-25-failed-retry-notices-sleep-audit.md @@ -6,7 +6,7 @@ Parent: [#17647](https://github.com/paperclipai/paperclip/pull/17647), This is slice 31 of the recurring-server-work stack. The branch now registers a scoped worker and removes retry notices from periodic publication maintenance. Producer audit and full acceptance remain in progress; this is not merge-ready. -No PR has been opened for this slice yet. +Draft PR: [#17649](https://github.com/paperclipai/paperclip/pull/17649). ## Obligation and boundary @@ -231,3 +231,99 @@ are covered by the general milestone fanout merely because run finalizers use it All older stack failures and original recurring-server duties remain required. No merge, expanded Cloud wake coverage, or deployed host sleep is claimed. + + +## Native lease producer qualification + +Two real producer gaps are now repaired without changing retry authority: + +- `environmentService.releaseLease` can settle a source lease after a notice + pass was denied. It now locks the exact matching row and registers the + existing scoped notice intent before changing eligibility fields. The + pending-cleanup attempt predicate remains on both selection and update; + stale claims cannot release the resource or create a notice wake. Unchanged + release repeats do not notify this worker. The existing environment-cleanup + transaction remains the owner, including caller-owned outer transactions. +- `environmentService.acquireLease` can retire a retained predecessor when + transferring a reusable sandbox to a new run. It registers a company-scoped + intent in that existing transaction before retirement. The predecessor can + belong to another issue in the same execution workspace, so the new issue is + not a sufficient scope. The original company/environment/resource/ownership + predicates and rollback on failed handoff remain unchanged. The notice worker + still bounds candidate authorization per pass. + +Both regressions start with an admitted retry receipt, make its native source +ineligible through a lease, settle the denied worker, then use the actual service +writer. They cover stale claims, outer rollback and commit, repeat writes, one +publication, and 120 seconds of logical idle with no root SQL or transactions. +The retained before-fix logs are `/tmp/sleep31-native-cleanup-before.log` and +`/tmp/sleep31-replacement-before.log`. Atomic release passed 35 selected cases +in `/tmp/sleep31-native-cleanup-atomic.log`. Both producers and the other notice +lifecycle cases pass 36 tests in `/tmp/sleep31-native-lease-producers-fixed.log`. + +The intermediate combined run `/tmp/sleep31-native-lease-producers.log` passed +the new producer cases but failed the disabled-admission case with a recorded +PostgreSQL `CONNECT_TIMEOUT`. Its fake clock advanced 1,000ms on each wait while +real TCP connection work was pending. Those waits now advance 10ms; the same +strict error assertions and 120,000ms settled-quiet assertion pass. This supplies +a concrete cause for this failure, not proof that the earlier unprinted error +had the same cause. Keep that earlier observation in the acceptance record. + +### Native cleanup boundary disposition + +The notice projection calls `authorizeFailedChatRunRetry(publication: true)`. +For a non-task Retry this reaches `failedNativeRetryCoordinator`, which reads +saved native ownership, recovery and environment lease state. It does not call +`assertFailedNativeRetryState` or its filesystem activation/checkpoint verifier. +The stronger filesystem check remains on initial preparation and admission. +Task Retry uses its saved intent authority and intentionally bypasses the +non-task coordinator check for status publications; it does not gain execution +permission from the notice worker. Therefore filesystem activation completion +is not itself a new notice-eligibility producer. + +For the retired-owner recovery path, initial non-task retry preparation already +requires settled native maintenance and the physical checkpoint proof. The +maintenance service refuses another ordinary pass over a nonempty canonical +root with existing maintenance history; its interrupted-copy path requires +exactly the earlier incomplete history and cannot recreate a settled generation. +The first successful cleanup precedes creation of that non-task retry action. +Do not add a pre-activation notification to filesystem cleanup on the assumption +that all execution predicates are also notice predicates. Existing source +finalization writers use the milestone notification boundary; source lease +release and reuse were the actual missing producers found here. + +`releaseLeasesForRun` has no production caller in the inspected repository; +only its definition and environment-service test call it. `extendLease` changes +expiry/last-used metadata, which these notice authorization predicates do not +read. Same-run reacquisition makes a lease active (revokes eligibility); its +later settlement uses the covered release writer. Current publication authority +is still rechecked before sending. Future producers must use the same committed +notification contract rather than relying on this audit as a blanket exemption. + +### Remote and local gate record + +At `cbfaab918a`, Greptile reports 5/5 with no inline findings, explicitly leaving +the native audit unresolved. CI run 40224785432 has a Runner failure in +`local-runner.test.ts`: duplicate command receipt `command_happy_path_3` timed +out. Evidence: `/tmp/sleep31-ci-runner-failure.log`, job 121263785884. +The first local attempt was invalid because debug Rust binaries were missing +(`/tmp/sleep31-runner-receipt-check.log`). After the prescribed `build:rust`, +all 10 cases pass in `/tmp/sleep31-runner-receipt-built.log`. This does not alone +clear remote CI. No unchanged-job retry has been used for this PR. + +Server typecheck passed with the two lease producers in +`/tmp/sleep31-native-lease-types.log`. The environment-service suite now accepts +an explicitly named isolated external test database ending in `_test`, retaining +embedded startup by default and closing the external client afterward. This +allows verification of the existing lease contracts on this host. Its result, +full updated acceptance, latest-head review and CI still need recording. + + +Existing environment-service acceptance passes all 51 cases on fresh migrated +`paperclip_sleep31_environment_20261025_test` in +`/tmp/sleep31-environment-service.log`. Server typecheck and build pass at this +lease-repair checkpoint (`/tmp/sleep31-native-final-types.log` and +`/tmp/sleep31-native-final-build.log`). Updated full chat acceptance and remote +checks remain required. Initial remote head `cbfaab918a` finished with only the +Runner receipt timeout and dependent `ci / verify` failing; all other 51 checks +passed. The forthcoming source-change push must earn its own checks and review. diff --git a/server/src/__tests__/chat-channels.integration.test.ts b/server/src/__tests__/chat-channels.integration.test.ts index d73c1016a25..e9adaddc0ab 100644 --- a/server/src/__tests__/chat-channels.integration.test.ts +++ b/server/src/__tests__/chat-channels.integration.test.ts @@ -1,3 +1,4 @@ +import { environmentService } from "../services/environments.js"; import { createAdmissionTransactionScope, createWakeAdmissionWriter } from "../modules/wake-queue/adapters/postgres.js"; import { chatFailedRetryNoticeWork } from "../services/chat-failed-retry-notice-work.js"; import { issueTreeControlService } from "../services/issue-tree-control.js"; @@ -129,6 +130,7 @@ import { nativeRunResults, nativeRunFinalizations, environmentLeases, + environments, principalPermissionGrants, projects, projectWorkspaces, @@ -61868,6 +61870,8 @@ describeEmbeddedPostgres("chat channel control-plane integration", () => { "integrity", "cleanup", "active_environment", + "notice_cleanup", + "notice_replacement", "live_pid", "missing_input", "late_provider_event", @@ -61901,6 +61905,9 @@ describeEmbeddedPostgres("chat channel control-plane integration", () => { : providerAccount; const previousStateDirectory = process.env.PAPERCLIP_RUNNER_STATE_DIR; let stateDirectory: string | null = null; + let noticeCoordinator: ReturnType | undefined; + let noticeActionId: string | undefined; + let noticeEnvironmentId: string | undefined; try { const nativeSessionId = randomUUID(); const runnerInstanceId = randomUUID(); @@ -62109,7 +62116,7 @@ describeEmbeddedPostgres("chat channel control-plane integration", () => { ); // A null account without existing provider-session evidence remains // conservatively ineligible for the exhausted-run recovery lane. - if (["bootstrap", "checkpoint", "distinct_account"].includes(kind)) { + if (["bootstrap", "checkpoint", "distinct_account", "notice_cleanup", "notice_replacement"].includes(kind)) { const staged = await attempt; await expect( context.service.processFailedChatRunRetry(staged.actionId), @@ -62119,12 +62126,101 @@ describeEmbeddedPostgres("chat channel control-plane integration", () => { retryOfRunId: context.runId, wakeCommentIds: [context.action.payload.commentId], }); + if (kind === "notice_cleanup" || kind === "notice_replacement") { + noticeActionId = staged.actionId; + await db.update(agentWakeupRequests).set({ status: "deferred_issue_execution" }) + .where(eq(agentWakeupRequests.id, staged.actionId)); + const cleanupAttemptId = randomUUID(); + if (kind === "notice_replacement") { + const [environment] = await db.insert(environments).values({ name: randomUUID(), driver: "ssh" }).returning(); + noticeEnvironmentId = environment.id; + } + const [lease] = await db.insert(environmentLeases).values({ + companyId: context.fixture.companyId, issueId: context.issue.id, + heartbeatRunId: context.runId, status: "pending_cleanup", cleanupStatus: "failed", + metadata: { pendingCleanupAttemptId: cleanupAttemptId, agentId: context.fixture.assignedAgentId }, + ...(kind === "notice_replacement" ? { environmentId: noticeEnvironmentId, + status: "retained", leasePolicy: "reuse_by_environment", providerLeaseId: randomUUID() } : {}), + }).returning(); + const errors: unknown[] = []; + noticeCoordinator = createDeliveryWorkCoordinator({ owner: db, canRun: () => true, + canReconcile: () => true, onError: error => errors.push(error) }); + vi.useFakeTimers({ toFake: ["Date", "setTimeout", "clearTimeout"], shouldAdvanceTime: true }); + await chatFailedRetryNoticeWork(context.service).register(noticeCoordinator, () => true).ready; + await vi.waitFor(async () => { await vi.advanceTimersByTimeAsync(1000); + expect(noticeCoordinator!.nextWakeAt()).toBeNull(); expect(idleWorkSnapshot().active).toBe(0); }); + expect(await readChatPublicationsByEndpointId(context.endpoint.id)).toHaveLength(0); + const replace = (owner: Db, replacesReusableLeaseId = lease.id) => environmentService(owner).acquireLease({ + companyId: context.fixture.companyId, environmentId: noticeEnvironmentId!, issueId: context.issue.id, + leasePolicy: "reuse_by_environment", providerLeaseId: lease.providerLeaseId, + metadata: { agentId: context.fixture.assignedAgentId }, replacesReusableLeaseId, + }); + if (kind === "notice_replacement") { + await expect(replace(db, randomUUID())).rejects.toThrow("ownership changed"); + const rollback = new Error("rollback reusable lease handoff"); + await expect(db.transaction(async tx => { + await replace(tx as unknown as Db); + throw rollback; + })).rejects.toBe(rollback); + await vi.waitFor(async () => { await vi.advanceTimersByTimeAsync(1000); + expect(noticeCoordinator!.nextWakeAt()).toBeNull(); expect(idleWorkSnapshot().active).toBe(0); }); + expect(await readChatPublicationsByEndpointId(context.endpoint.id)).toHaveLength(0); + await db.transaction(tx => replace(tx as unknown as Db)); + } else { + expect(await environmentService(db).releaseLease(lease.id, "released", { + cleanupStatus: "success", expectedPendingCleanupAttemptId: randomUUID(), + })).toBeNull(); + const rollback = new Error("rollback native lease settlement"); + await expect(db.transaction(async tx => { + await environmentService(tx as unknown as Db).releaseLease(lease.id, "released", { + cleanupStatus: "success", expectedPendingCleanupAttemptId: cleanupAttemptId, + }); + throw rollback; + })).rejects.toBe(rollback); + await vi.waitFor(async () => { await vi.advanceTimersByTimeAsync(1000); + expect(noticeCoordinator!.nextWakeAt()).toBeNull(); expect(idleWorkSnapshot().active).toBe(0); }); + expect(await readChatPublicationsByEndpointId(context.endpoint.id)).toHaveLength(0); + await db.transaction(async tx => { + await environmentService(tx as unknown as Db).releaseLease(lease.id, "released", { + cleanupStatus: "success", expectedPendingCleanupAttemptId: cleanupAttemptId, + }); + }); + } + await vi.waitFor(async () => { + await vi.advanceTimersByTimeAsync(1000); + expect(await readChatPublicationsByEndpointId(context.endpoint.id)).toHaveLength(1); + expect(noticeCoordinator!.nextWakeAt()).toBeNull(); expect(idleWorkSnapshot().active).toBe(0); + }, { timeout: 5000 }); + const selection = vi.spyOn(context.service, "loadFailedRetryNoticeScopes"); + try { + if (kind === "notice_replacement") await expect(replace(db)).rejects.toThrow("ownership changed"); + else await environmentService(db).releaseLease(lease.id, "released", { cleanupStatus: "success" }); + await vi.advanceTimersByTimeAsync(1000); + expect(selection).not.toHaveBeenCalled(); + } finally { selection.mockRestore(); } + const select = vi.spyOn(db, "select"), transaction = vi.spyOn(db, "transaction"); + try { + await vi.advanceTimersByTimeAsync(120_000); + expect(select).not.toHaveBeenCalled(); expect(transaction).not.toHaveBeenCalled(); + } finally { select.mockRestore(); transaction.mockRestore(); } + expect(errors).toEqual([]); + } } else await expect(attempt).rejects.toMatchObject({ details: { code: "chat_failed_run_retry_not_authorized" }, }); } finally { + await noticeCoordinator?.stop(); + if (kind === "notice_cleanup" || kind === "notice_replacement") vi.useRealTimers(); await context.service.shutdown(); + if (noticeEnvironmentId) { + await db.delete(environmentLeases).where(eq(environmentLeases.environmentId, noticeEnvironmentId)); + await db.delete(environments).where(eq(environments.id, noticeEnvironmentId)); + } + if (noticeActionId) { + await db.delete(agentWakeupRequests).where(eq(agentWakeupRequests.id, noticeActionId)); + await db.delete(chatActions).where(eq(chatActions.id, noticeActionId)); + } if (stateDirectory) { if (previousStateDirectory === undefined) delete process.env.PAPERCLIP_RUNNER_STATE_DIR; @@ -62657,7 +62753,7 @@ describeEmbeddedPostgres("chat channel control-plane integration", () => { const selection = vi.spyOn(context.service, "loadFailedRetryNoticeScopes"); vi.useFakeTimers({ toFake: ["Date", "setTimeout", "clearTimeout"], shouldAdvanceTime: true }); const settle = async () => vi.waitFor(async () => { - await vi.advanceTimersByTimeAsync(1000); + await vi.advanceTimersByTimeAsync(10); expect(idleWorkSnapshot().active).toBe(0); expect(coordinator.nextWakeAt()).toBeNull(); }, { timeout: 10_000 }); const quiet = async () => { @@ -62675,7 +62771,7 @@ describeEmbeddedPostgres("chat channel control-plane integration", () => { if (mode === "failed selection") selection.mockRejectedValueOnce(new Error("temporary retry selection failure")); expect(await context.admit()).toMatchObject({ status: mode === "disabled" ? "failed" : "deferred" }); if (mode === "failed selection") { - await vi.waitFor(async () => { await vi.advanceTimersByTimeAsync(1000); expect(errors).toHaveLength(1); }); + await vi.waitFor(async () => { await vi.advanceTimersByTimeAsync(10); expect(errors).toHaveLength(1); }); canRun = false; } if (["drain", "failed selection", "stopped"].includes(mode)) { @@ -62753,7 +62849,7 @@ describeEmbeddedPostgres("chat channel control-plane integration", () => { if (mode === "bounded pass") await vi.waitFor(() => expect(held).toBe(true), { timeout: 10_000 }); else { await ready; - await vi.waitFor(async () => { await vi.advanceTimersByTimeAsync(1000); + await vi.waitFor(async () => { await vi.advanceTimersByTimeAsync(10); expect(coordinator.nextWakeAt()).toBeNull(); expect(idleWorkSnapshot().active).toBe(0); }); const select = vi.spyOn(db, "select"), transaction = vi.spyOn(db, "transaction"); try { @@ -62775,7 +62871,7 @@ describeEmbeddedPostgres("chat channel control-plane integration", () => { } else await issueService(db).update(context.issue.id, { visibility: "open" }); release(); await ready; await vi.waitFor(async () => { - await vi.advanceTimersByTimeAsync(1000); + await vi.advanceTimersByTimeAsync(10); expect(await readChatPublicationsByEndpointId(context.endpoint.id)).toHaveLength(1); expect(coordinator.nextWakeAt()).toBeNull(); expect(idleWorkSnapshot().active).toBe(0); }, { timeout: 10_000 }); diff --git a/server/src/__tests__/environment-service.test.ts b/server/src/__tests__/environment-service.test.ts index 59774e35ec5..f1a1c98f05c 100644 --- a/server/src/__tests__/environment-service.test.ts +++ b/server/src/__tests__/environment-service.test.ts @@ -11,6 +11,7 @@ import { companySecretBindings, companySecrets, createDb, + closeRegisteredClients, environmentCustomImageSetupSessions, environmentLeases, environments, @@ -26,7 +27,11 @@ import { } from "./helpers/embedded-postgres.js"; import { environmentService } from "../services/environments.ts"; -const embeddedPostgresSupport = await getEmbeddedPostgresTestSupport(); +const externalTestDatabaseUrl = process.env.PAPERCLIP_TEST_DATABASE_URL; +if (externalTestDatabaseUrl && !new URL(externalTestDatabaseUrl).pathname.endsWith("_test")) { + throw new Error("Environment service tests require an isolated database ending in _test"); +} +const embeddedPostgresSupport = externalTestDatabaseUrl ? { supported: true } : await getEmbeddedPostgresTestSupport(); const describeEmbeddedPostgres = embeddedPostgresSupport.supported ? describe : describe.skip; if (!embeddedPostgresSupport.supported) { @@ -41,9 +46,14 @@ describeEmbeddedPostgres("environmentService leases", () => { let svc!: ReturnType; beforeAll(async () => { - const started = await startEmbeddedPostgresTestDatabase("environment-service"); - stopDb = started.stop; - db = createDb(started.connectionString); + if (externalTestDatabaseUrl) { + db = createDb(externalTestDatabaseUrl); + stopDb = () => closeRegisteredClients(externalTestDatabaseUrl); + } else { + const started = await startEmbeddedPostgresTestDatabase("environment-service"); + stopDb = started.stop; + db = createDb(started.connectionString); + } svc = environmentService(db); }); diff --git a/server/src/services/environments.ts b/server/src/services/environments.ts index ec5abac4cae..91a6153d5f3 100644 --- a/server/src/services/environments.ts +++ b/server/src/services/environments.ts @@ -1,3 +1,4 @@ +import { notifyChatInboundWakeNotices } from "./chat-inbound-wake-notice-notifications.js"; import { writeEnvironmentCleanup, notifyEnvironmentCleanup } from "./environment-cleanup-notifications.js"; import { withoutCleanupVerification } from "./cleanup-verification-proof.js"; import { randomUUID } from "node:crypto"; @@ -1549,6 +1550,7 @@ export function environmentService(db: Db) { } } if (input.replacesReusableLeaseId) { + await notifyChatInboundWakeNotices(tx, { companyId: input.companyId }); const retired = await tx .update(environmentLeases) .set({ @@ -1671,8 +1673,24 @@ export function environmentService(db: Db) { : sql`${environmentLeases.metadata} - 'remoteExecutionTermination'`; const cleanupSettled = options?.expectedPendingCleanupAttemptId && options.cleanupStatus === "success" && status !== "pending_cleanup"; - const row = await writeEnvironmentCleanup(db, tx => tx - .update(environmentLeases) + const row = await writeEnvironmentCleanup(db, async tx => { + const condition = and(eq(environmentLeases.id, id), options?.expectedPendingCleanupAttemptId + ? and(eq(environmentLeases.status, "pending_cleanup"), + sql`${environmentLeases.metadata}->>'pendingCleanupAttemptId' = ${options.expectedPendingCleanupAttemptId}`) + : undefined); + const [previous] = await tx.select({ companyId: environmentLeases.companyId, issueId: environmentLeases.issueId, + heartbeatRunId: environmentLeases.heartbeatRunId, status: environmentLeases.status, + cleanupStatus: environmentLeases.cleanupStatus, releasedAt: environmentLeases.releasedAt, + }).from(environmentLeases).where(condition).for("update"); + if (!previous) return null; + if (previous.heartbeatRunId && (previous.status !== status || + (options?.cleanupStatus !== undefined && previous.cleanupStatus !== options.cleanupStatus) || + (status !== "retained" && !previous.releasedAt))) { + await notifyChatInboundWakeNotices(tx, { + companyId: previous.companyId, issueId: previous.issueId ?? undefined, + }); + } + return tx.update(environmentLeases) .set({ status, releasedAt: status === "retained" ? null : now, @@ -1686,12 +1704,10 @@ export function environmentService(db: Db) { ? sql`coalesce(${releaseMetadata}, '{}'::jsonb) || '{"pendingCleanupInFlight":false,"pendingCleanupLeaseExpiresAtMs":0}'::jsonb` : releaseMetadata, }) - .where(and(eq(environmentLeases.id, id), options?.expectedPendingCleanupAttemptId - ? and(eq(environmentLeases.status, "pending_cleanup"), - sql`${environmentLeases.metadata}->>'pendingCleanupAttemptId' = ${options.expectedPendingCleanupAttemptId}`) - : undefined)) + .where(condition) .returning() - .then((rows) => rows[0] ?? null)); + .then((rows) => rows[0] ?? null); + }); return row ? toEnvironmentLease(row) : null; },