diff --git a/server/src/services/__tests__/run-failure-report-reviewed-chat.test.ts b/server/src/services/__tests__/run-failure-report-reviewed-chat.test.ts new file mode 100644 index 00000000000..7956c8ac9d4 --- /dev/null +++ b/server/src/services/__tests__/run-failure-report-reviewed-chat.test.ts @@ -0,0 +1,123 @@ +import { randomUUID } from "node:crypto"; +import { afterAll, afterEach, beforeAll, beforeEach, describe, expect, it, vi } from "vitest"; +import { agents, applyPendingMigrations, closeRegisteredClients, companies, createDb, heartbeatRuns } from "@paperclipai/db"; +import { + getEmbeddedPostgresTestSupport, + startEmbeddedPostgresTestDatabase, +} from "../../__tests__/helpers/embedded-postgres.js"; + +const mockCaptureRunFailure = vi.hoisted(() => vi.fn()); + +vi.mock("../../sentry.js", () => ({ + captureRunFailure: mockCaptureRunFailure, +})); + +import { reportRunFailure } from "../run-failure-report.js"; +import { REVIEWED_CHAT_BINDING_NOT_READY } from "../reviewed-chat-binding-diagnostics.js"; + +const testDatabaseUrl = process.env.PAPERCLIP_TEST_DATABASE_URL; +const embeddedPostgresSupport = testDatabaseUrl ? { supported: true } : await getEmbeddedPostgresTestSupport(); +const describeEmbeddedPostgres = embeddedPostgresSupport.supported ? describe : describe.skip; + +describeEmbeddedPostgres("reportRunFailure reviewed chat setup waits", () => { + let db!: ReturnType; + let tempDb: Awaited> | null = null; + let companyId!: string; + let agentId!: string; + let inheritedEnv: NodeJS.ProcessEnv; + + beforeAll(async () => { + if (testDatabaseUrl) { + await applyPendingMigrations(testDatabaseUrl); + db = createDb(testDatabaseUrl); + } else { + tempDb = await startEmbeddedPostgresTestDatabase("paperclip-run-failure-reviewed-chat-"); + db = createDb(tempDb.connectionString); + } + }, 20_000); + + beforeEach(async () => { + inheritedEnv = process.env; + process.env = Object.fromEntries( + ["PATH", "HOME", "USER", "USERNAME", "LOGNAME", "USERPROFILE", "TMPDIR", "TEMP", "TMP"] + .flatMap((key) => inheritedEnv[key] === undefined ? [] : [[key, inheritedEnv[key]]]), + ); + process.env.PAPERCLIP_SENTRY_RUN_FAILURES = "unexpected"; + companyId = randomUUID(); + agentId = randomUUID(); + await db.insert(companies).values({ + id: companyId, + name: "Paperclip", + issuePrefix: `T${companyId.replace(/-/g, "").slice(0, 6).toUpperCase()}`, + requireBoardApprovalForNewAgents: false, + defaultResponsibleUserId: "responsible-user", + }); + await db.insert(agents).values({ + id: agentId, + companyId, + name: "ReviewBot", + role: "engineer", + status: "active", + adapterType: "paperclip_runner", + adapterConfig: {}, + runtimeConfig: {}, + permissions: {}, + }); + }); + + afterEach(async () => { + vi.clearAllMocks(); + vi.unstubAllEnvs(); + process.env = inheritedEnv; + await db.delete(heartbeatRuns); + await db.delete(agents); + await db.delete(companies); + }); + + afterAll(async () => { + if (testDatabaseUrl) await closeRegisteredClients(testDatabaseUrl); + await tempDb?.cleanup(); + }); + + function reviewedChatWaitRun( + overrides: Partial = {}, + ): typeof heartbeatRuns.$inferSelect { + return { + id: randomUUID(), + companyId, + agentId, + status: "failed", + error: REVIEWED_CHAT_BINDING_NOT_READY, + errorCode: REVIEWED_CHAT_BINDING_NOT_READY, + runtimeMode: "legacy", + executionStage: "preparing", + nativeIssueId: null, + contextSnapshot: null, + resultJson: { executionRecovery: { kind: "bootstrap", providerWorkStarted: false } }, + ...overrides, + } as unknown as typeof heartbeatRuns.$inferSelect; + } + + it("keeps a wait local until its retry decision, and after a scheduled retry", async () => { + const run = reviewedChatWaitRun(); + await reportRunFailure(db, run, { phase: "setup", reviewedChatRetry: "pending" }); + await reportRunFailure(db, run, { phase: "setup", reviewedChatRetry: "scheduled" }); + // The setup path reports once more with its decision, so a pending write stays local in every mode. + vi.stubEnv("PAPERCLIP_SENTRY_RUN_FAILURES", "all"); + await reportRunFailure(db, run, { phase: "setup", reviewedChatRetry: "pending" }); + expect(mockCaptureRunFailure).not.toHaveBeenCalled(); + }); + + it.each([ + ["no retry was scheduled", {}, "not_scheduled", "unexpected"], + ["the decision is unknown", {}, undefined, "unexpected"], + ["every run failure is reported", {}, "scheduled", "all"], + ["the run failed for another reason", { errorCode: "setup_failed" }, "scheduled", "unexpected"], + ] as const)("reports a reviewed chat setup failure when %s", async (_label, overrides, reviewedChatRetry, mode) => { + vi.stubEnv("PAPERCLIP_SENTRY_RUN_FAILURES", mode); + const run = reviewedChatWaitRun(overrides); + await reportRunFailure(db, run, { phase: "setup", ...(reviewedChatRetry ? { reviewedChatRetry } : {}) }); + expect(mockCaptureRunFailure).toHaveBeenCalledOnce(); + expect(mockCaptureRunFailure.mock.calls[0]![0]).toMatchObject({ errorCode: run.errorCode, runStatus: "failed" }); + }); +}); diff --git a/server/src/services/heartbeat/run-completion-reviewed-chat-report.test.ts b/server/src/services/heartbeat/run-completion-reviewed-chat-report.test.ts new file mode 100644 index 00000000000..2d049495938 --- /dev/null +++ b/server/src/services/heartbeat/run-completion-reviewed-chat-report.test.ts @@ -0,0 +1,129 @@ +import { agents, agentWakeupRequests, companies, createDb, EMBEDDED_POSTGRES_TEST_TIMEOUT_MS, heartbeatRuns, type Db } from "@paperclipai/db"; +import { eq, sql } from "drizzle-orm"; +import { afterAll, beforeAll, beforeEach, describe, expect, it, vi } from "vitest"; +import { getEmbeddedPostgresTestSupport, startEmbeddedPostgresTestDatabase } from "../../__tests__/helpers/embedded-postgres.js"; +import { createAgentIdentityRedactor } from "../agent-identity-redaction.js"; +import { ReviewedChatBindingNotReadyError } from "../reviewed-chat-binding-diagnostics.js"; +import { reportRunFailure } from "../run-failure-report.js"; +import { createHeartbeatLifecycle, type HeartbeatLifecycleDependencies } from "./run-lifecycle.js"; +import { createHeartbeatRunPreparation } from "./run-preparation.js"; +import { createHeartbeatRunState } from "./run-state.js"; +import { createHeartbeatRunCompletion, type HeartbeatRunCompletionDependencies } from "./run-completion.js"; + +vi.mock("../live-events.js", () => ({ publishLiveEvent: vi.fn() })); +// The Sentry report is an outbound boundary; the tests observe the decision handed to it. +vi.mock("../run-failure-report.js", async importOriginal => { + const actual = await importOriginal(); + return { ...actual, reportRunFailure: vi.fn(async () => undefined) }; +}); + +type Dependencies = HeartbeatRunCompletionDependencies; +function callbacks(db: Db) { + const state = createHeartbeatRunState(db); + const lifecycleDeps = { + ...state, ...createHeartbeatRunPreparation(db), + issuesSvc: { addComment: vi.fn(), listReviewAttention: vi.fn() }, + recovery: { escalateStrandedAssignedIssue: vi.fn() }, + companySkills: { completeTestRunForIssue: vi.fn() }, + budgets: { getInvocationBlock: vi.fn(async () => null) }, + treeControlSvc: { getActivePauseHoldGate: vi.fn(async () => null) }, + enqueueWakeup: vi.fn(), + getCurrentUserRedactionOptions: vi.fn(async () => ({ enabled: false })), + getAgentInvokability: vi.fn(async () => ({ invokable: true })), + emitTerminalAgentTaskRun: vi.fn(), budgetHooks: {}, + } satisfies HeartbeatLifecycleDependencies; + const lifecycle = createHeartbeatLifecycle(db, lifecycleDeps); + return { + ...state, ...lifecycle, + setRunStatusIfRunning: vi.fn(lifecycle.setRunStatusIfRunning), + setWakeupStatus: vi.fn(lifecycle.setWakeupStatus), + upsertTaskSession: vi.fn(state.upsertTaskSession), + clearTaskSessions: vi.fn(state.clearTaskSessions), + classifyAndPersistRunLiveness: vi.fn(async run => run), + completeSkillTestRunForHeartbeatOutcome: vi.fn(async () => null), + refreshContinuationSummaryForRun: vi.fn(async () => null), + findRunIssueComment: vi.fn(async () => null), + findLatestCompletedFinalAgentMessage: vi.fn(async () => null), + finalizeIssueCommentPolicy: vi.fn(async () => ({ outcome: "not_applicable", queuedRun: null })), + handleIssueReviewPathDisposition: vi.fn(async () => undefined), + handleRunLivenessContinuation: vi.fn(), + handleSuccessfulRunHandoff: vi.fn(), + updateRuntimeState: vi.fn(), + scheduleBoundedRetryForRun: vi.fn(), + scheduleInteractionContinuationInfrastructureRetryIfEligible: vi.fn(async () => null), + timerClaimWasFirstHeartbeat: vi.fn(() => undefined), + releaseIssueExecutionAndPromote: vi.fn(async () => undefined), + finalizeAgentStatus: vi.fn(async () => undefined), + enqueueWakeup: vi.fn(), + issuesSvc: { addComment: vi.fn() }, + recovery: { reconcileLegacyContinuation: vi.fn(), reconcileResolvedDependencyWakeBackstop: vi.fn() }, + getCurrentUserRedactionOptions: lifecycleDeps.getCurrentUserRedactionOptions, + budgetHooks: {}, + runLogStore: { finalize: vi.fn(async () => ({ bytes: 123, sha256: "log-hash", compressed: true })) }, + traceStore: { finalize: vi.fn() }, + processRunCancellationSettlements: new Map; failed: boolean }>(), + failedProcessRunCancellations: new Map; failed: boolean }>(), + } satisfies Dependencies; +} + +const support = await getEmbeddedPostgresTestSupport(); +describe.skipIf(!support.supported && !process.env.PAPERCLIP_TEST_DATABASE_URL)("reviewed chat setup wait reporting", () => { + let database: Awaited> | undefined; + let db: Db; + beforeAll(async () => { + const external = process.env.PAPERCLIP_TEST_DATABASE_URL; + if (external) db = createDb(external); + else { + database = await startEmbeddedPostgresTestDatabase("paperclip-reviewed-chat-report"); + db = createDb(database.connectionString); + } + await db.execute(sql`set client_min_messages = warning`); + }, EMBEDDED_POSTGRES_TEST_TIMEOUT_MS); + afterAll(async () => { await db?.$client.end(); await database?.cleanup(); vi.restoreAllMocks(); }); + beforeEach(async () => { + await db.execute(sql`truncate table companies restart identity cascade`); + vi.mocked(reportRunFailure).mockClear(); + }); + + async function fixture(patch: Partial = {}) { + const [company] = await db.insert(companies).values({ name: "Completion", issuePrefix: "CMP" }).returning(); + const [agent] = await db.insert(agents).values({ companyId: company.id, name: "Chat agent", adapterType: "process" }).returning(); + const [wake] = await db.insert(agentWakeupRequests).values({ companyId: company.id, agentId: agent.id, source: "on_demand", status: "claimed" }).returning(); + const [run] = await db.insert(heartbeatRuns).values({ companyId: company.id, agentId: agent.id, wakeupRequestId: wake.id, status: "running", runtimeMode: "legacy", ...patch }).returning(); + const deps = callbacks(db); + const completion = createHeartbeatRunCompletion(db, deps); + const setup = (outerErr: unknown) => ({ run, runId: run.id, outerErr, signal: new AbortController().signal, providerDispatchStarted: false, + identityRedactor: createAgentIdentityRedactor(), readFailureReportSecrets: () => [] }); + return { run, deps, completion, setup }; + } + const read = (id: string) => db.select().from(heartbeatRuns).where(eq(heartbeatRuns.id, id)).then(rows => rows[0]!); + + it.each(["scheduled", "not_scheduled", "scheduler_failed", "interaction_scheduled", "interaction_not_scheduled", "untrusted"] as const)( + "reports the wait only after its retry decision: %s", async scenario => { + const f = await fixture(scenario.startsWith("interaction_") ? { contextSnapshot: { source: "issue.interaction.respond", externalChatContinuation: true, + interactionId: "interaction-1", interactionStatus: "answered", interactionKind: "ask_user_questions", + mutation: "interaction", wakeReason: "issue_commented" } } : {}); + const scheduled = { outcome: "scheduled" } as never; + if (scenario === "scheduler_failed") f.deps.scheduleBoundedRetryForRun.mockRejectedValueOnce(new Error("fixture scheduler failure")); + else if (scenario === "interaction_scheduled") f.deps.scheduleInteractionContinuationInfrastructureRetryIfEligible.mockResolvedValueOnce(scheduled); + else f.deps.scheduleBoundedRetryForRun.mockResolvedValueOnce(scenario === "not_scheduled" + ? { outcome: "not_scheduled", reason: "Fixture scheduler boundary", issueId: null } : scheduled); + const error = scenario === "untrusted" ? new Error("reviewed_chat_execution_binding_not_ready") : new ReviewedChatBindingNotReadyError(); + await f.completion.failRunSetup(f.setup(error)); + const write = f.deps.setRunStatusIfRunning.mock.calls.find(call => call[1] === "failed"); + if (scenario === "untrusted") { + // An ordinary setup failure keeps its report on the failed-status write. + expect(await read(f.run.id)).toMatchObject({ status: "failed", errorCode: "setup_failed" }); + expect(write?.[3]).toEqual(expect.not.objectContaining({ reviewedChatRetry: expect.anything() })); + expect(reportRunFailure).not.toHaveBeenCalled(); + return; + } + expect(await read(f.run.id)).toMatchObject({ status: "failed", errorCode: "reviewed_chat_execution_binding_not_ready" }); + expect(write?.[3]).toMatchObject({ phase: "setup", reviewedChatRetry: "pending" }); + expect(reportRunFailure).toHaveBeenCalledOnce(); + expect(reportRunFailure).toHaveBeenCalledWith(db, + expect.objectContaining({ id: f.run.id, status: "failed", errorCode: "reviewed_chat_execution_binding_not_ready" }), + expect.objectContaining({ phase: "setup", error, + reviewedChatRetry: scenario === "scheduled" || scenario === "interaction_scheduled" ? "scheduled" : "not_scheduled" })); + }); +}); diff --git a/server/src/services/heartbeat/run-completion.ts b/server/src/services/heartbeat/run-completion.ts index fccf30ccc9e..ebad344fe03 100644 --- a/server/src/services/heartbeat/run-completion.ts +++ b/server/src/services/heartbeat/run-completion.ts @@ -27,6 +27,7 @@ import { preserveWorkspaceRestoreRecoveryMetadataSql } from "../legacy-workspace import { cancellationResultJson, controllerLeaseLossCancellation, readRunCancellation } from "../run-cancellation.js"; import { CONTROLLER_LEASE_LOST_FAILURE_CODE, LegacyControllerLeaseLostError } from "../legacy-controller-lease.js"; import { REVIEWED_CHAT_BINDING_NOT_READY, ReviewedChatBindingNotReadyError, reviewedChatBindingDenialResultJson } from "../reviewed-chat-binding-diagnostics.js"; +import { reportRunFailure } from "../run-failure-report.js"; import { accountRunCost } from "../run-cost-accounting.js"; import { isConversation, settleConversationTurn } from "../agent-conversations.js"; import { legacyExecutionNeedsReconciliationWithEvidence } from "../legacy-execution-recovery.js"; @@ -1528,7 +1529,11 @@ export function createHeartbeatRunCompletion(db: Db, dependencies: HeartbeatRunC : setupFailureResultJson ? { resultJson: setupFailureResultJson } : {}), - }, { error: outerErr, phase: "setup", secretValues: readFailureReportSecrets() }, { setupFailure: true }).catch(() => ({ run: null, updated: false as const })); + }, { error: outerErr, phase: "setup", secretValues: readFailureReportSecrets(), + // The Sentry report waits for the bounded retry decision below. + ...(reviewedChatBindingNotReady ? { reviewedChatRetry: "pending" as const } : {}), + }, { setupFailure: true }).catch(() => ({ run: null, updated: false as const })); + let reviewedChatRetryScheduled = false; if (!setupFailureWrite.updated) { logger.info( { @@ -1614,7 +1619,7 @@ export function createHeartbeatRunCompletion(db: Db, dependencies: HeartbeatRunC || livenessRun.errorCode === REPOSITORY_CATALOG_UNAVAILABLE_CODE || livenessRun.errorCode === REVIEWED_CHAT_BINDING_NOT_READY) && isResolvedInteractionContinuationWakeContext(livenessRun.contextSnapshot); - await (isTransientWorkspacePreparationCode(livenessRun.errorCode) && !interactionOwnsRetry + const retry = await (isTransientWorkspacePreparationCode(livenessRun.errorCode) && !interactionOwnsRetry ? livenessRun.errorCode === RUNNER_REVISION_MISMATCH_CODE ? scheduleBoundedRetryForRun(livenessRun, failedAgent, RUNNER_REVISION_MISMATCH_RETRY) : scheduleBoundedRetryForRun(livenessRun, failedAgent) @@ -1624,7 +1629,9 @@ export function createHeartbeatRunCompletion(db: Db, dependencies: HeartbeatRunC { err: retryError, runId: livenessRun.id }, "failed to schedule interaction continuation retry after setup failure", ); + return null; }); + reviewedChatRetryScheduled = retry?.outcome === "scheduled"; } } await releaseIssueExecutionAndPromote(livenessRun, { @@ -1650,6 +1657,13 @@ export function createHeartbeatRunCompletion(db: Db, dependencies: HeartbeatRunC }, ); } + // This path owned the failed-status write, which deferred the report. + const reviewedChatReportRun = reviewedChatBindingNotReady && setupFailureWrite.updated + ? failedRun ?? setupFailureWrite.run : null; + if (reviewedChatReportRun) { + void reportRunFailure(db, reviewedChatReportRun, { error: outerErr, phase: "setup", secretValues: readFailureReportSecrets(), + reviewedChatRetry: reviewedChatRetryScheduled ? "scheduled" : "not_scheduled" }); + } // Ensure the agent is not left stuck in "running" if the setup-failure // path owned the terminal transition. If another path already finalized // the run, keep that terminal outcome authoritative. diff --git a/server/src/services/run-failure-diagnostics.ts b/server/src/services/run-failure-diagnostics.ts index 0ec8fc1170e..5cbe30cc0f6 100644 --- a/server/src/services/run-failure-diagnostics.ts +++ b/server/src/services/run-failure-diagnostics.ts @@ -40,6 +40,12 @@ export interface RunFailureReportOptions { * read, as closed labels and counts; its message and stack are never copied. */ nativeCloseFailure?: unknown; + /** + * The bounded retry decision for a reviewed chat setup wait. The setup path + * writes the failed status while `pending`, then reports again with the + * decision; a scheduled retry owns recovery and reports its own outcome. + */ + reviewedChatRetry?: "pending" | "scheduled" | "not_scheduled"; } export interface RunFailureException { diff --git a/server/src/services/run-failure-report.ts b/server/src/services/run-failure-report.ts index b993d08a740..1e0ceb7d4cc 100644 --- a/server/src/services/run-failure-report.ts +++ b/server/src/services/run-failure-report.ts @@ -20,6 +20,7 @@ import { RESTRICTED_WORKSPACE_SOURCE_REASON } from "./workspace-source-restricti import { PLUGIN_RUNNER_AI_CONNECTION_REQUIRED } from "./plugin-runner-ai-connection.js"; import { NATIVE_PROVIDER_OVERLOADED_CODE } from "./native-runtime/native-provider-failure.js"; import { PROJECT_ACCESS_DENIED } from "./project-access-denial.js"; +import { REVIEWED_CHAT_BINDING_NOT_READY } from "./reviewed-chat-binding-diagnostics.js"; type HeartbeatRun = typeof heartbeatRuns.$inferSelect; @@ -289,6 +290,16 @@ async function isScheduledNativeCapacityRetry(db: Db, run: HeartbeatRun, options return retry !== undefined; } +/** + * A reviewed chat attestation exhausted its short lock or delivery wait before + * provider dispatch, and the setup path scheduled the bounded retry. The retry + * owns recovery; an exhausted or unscheduled wait stays reportable. + */ +function isScheduledReviewedChatRetry(run: HeartbeatRun, options: RunFailureReportOptions): boolean { + return run.status === "failed" && run.errorCode === REVIEWED_CHAT_BINDING_NOT_READY && + options.reviewedChatRetry === "scheduled"; +} + const providerAuthErrorCodes = new Set(["claude_auth_required", "acpx_auth_required"]); /** @@ -342,6 +353,8 @@ export function reportRunFailure(db: Db, run: HeartbeatRun, options: RunFailureR if (run.status === "cancelled" && !isUnexpectedRunCancellation(run)) return Promise.resolve(); // The terminal write that ends the retry reports instead (`isNewTerminalRunFailure`). if (isPendingNativeRetry(run)) return Promise.resolve(); + // The setup path reports this run again once it has decided the retry. + if (options.reviewedChatRetry === "pending") return Promise.resolve(); if (mode === "unexpected" && ( isMissingSecretConfigurationBlocker(run, options) || isAiConnectionSelectionBlocker(run, options) || @@ -353,6 +366,7 @@ export function reportRunFailure(db: Db, run: HeartbeatRun, options: RunFailureR isProviderQuotaFailure(run, options) || isCodexAcpModelCapacityFailure(run, options) || isAcpProviderAccessFailure(run, options) || + isScheduledReviewedChatRetry(run, options) || isRestartInterruptedSetup(run) )) return Promise.resolve(); const runStatus = run.status;