diff --git a/doc/observability.md b/doc/observability.md index 6af36505f4..0be094bccd 100644 --- a/doc/observability.md +++ b/doc/observability.md @@ -457,13 +457,31 @@ The shared reporter also attaches bounded diagnostic contexts for both legacy and native runs: - `run_execution`: runtime mode, execution stage/native phase, driver and version, - duration, failure phase, stop reason, error family, and timeout settings when available. + duration, ACP activity, failure phase, stop reason, error family, + and timeout settings when available. - `adapter_failure`: selected adapter error fields such as phase, category, protocol code, retryability, cause message, stack preview, HTTP status, and request ID. - `provider_failure`: the saved provider failure category, title, and details. - `run_exception_0` through `run_exception_3`: exception names, codes, HTTP statuses, and request IDs for a caught exception and up to three causes. +ACP turns record `acpLastEventAgeMs`, `acpObservedEventCount`, +`acpPendingToolCount`, and `acpToolInventoryComplete` at finalization, before +usage reads, error logging, and cleanup. The age measures time since the last +runtime event and is omitted if no event was observed or the clock is invalid. +Timeout and cleanup log messages do not reset this age. The pending count uses +known tool statuses; an incomplete inventory cannot establish that no work is +pending. Recent events do not prove useful progress. These fields contain only +numbers and a boolean, never tool names, IDs, arguments, or event content, and +do not change the execution timeout, cancellation, or recovery policy. + +When settlement records a workspace restore failure, `run_execution` also +includes `workspaceRestoreFailure` with one of the shared, path-free codes: +`restore_permission_denied`, `restore_lock_timeout`, `restore_unsafe_archive`, +or `restore_failed`. Unknown values are omitted. Workspace paths and arbitrary +pre-restore result data are not included. A later successful run does not, by +itself, establish that an earlier failed restore recovered the workspace files. + The execution and setup catch paths pass the original exception to the reporter. It snapshots and rebuilds only these selected fields and the original message and stack. Sentry receives the sanitized cause chain rather than a stack created at diff --git a/packages/adapter-utils/src/acpx-engine/execute.test.ts b/packages/adapter-utils/src/acpx-engine/execute.test.ts index a26f980fc9..07d6070d40 100644 --- a/packages/adapter-utils/src/acpx-engine/execute.test.ts +++ b/packages/adapter-utils/src/acpx-engine/execute.test.ts @@ -3030,9 +3030,69 @@ describe("gemini ACP flag selection", () => { expect(result.errorCode).toBe("acpx_timeout"); expect(result.errorMessage).toBe(expectedMessage); expect(cancelReasons).toContain(expectedMessage); + expect(result.resultJson).toMatchObject({ acpObservedEventCount: 0, acpPendingToolCount: 0, acpToolInventoryComplete: true }); + expect(result.resultJson).not.toHaveProperty("acpLastEventAgeMs"); }, 15_000); }); +describe("ACP activity diagnostics", () => { + it.each(["terminal", "relay_error", "no_events"])( + "snapshots %s activity before usage reads, failure logging, and cleanup", async (outcome) => { + const root = await makeTempRoot(); + const cwd = path.join(root, "worktree"); + await fs.mkdir(cwd, { recursive: true }); + let currentNow = 1000; + let statusReads = 0; + const execute = createAcpxEngineExecutor({ + now: () => currentNow, + createRuntime: () => ({ + ...buildRuntime(), + getStatus: async () => { + if (++statusReads > 1) currentNow += 100_000; + return null; + }, + startTurn: () => ({ + events: (async function* () { + if (outcome !== "no_events") { + yield { type: "tool_call", toolCallId: "private-pending-id", title: "private command", kind: "execute", status: "in_progress" }; + yield { type: "tool_call", toolCallId: "private-done-id", title: "private read", kind: "read", status: "in_progress" }; + yield { type: "tool_call", toolCallId: "private-done-id", status: "completed" }; + yield { type: "tool_call", toolCallId: "private-cancelled-id", status: "cancelled" }; + yield { type: "tool_call", toolCallId: "private-failed-id", status: "failed" }; + yield { type: "status", text: "terminal/create private receipt" }; + } + currentNow = 10_000; + if (outcome === "relay_error") throw new Error("relay failed"); + })(), + result: Promise.resolve({ status: "failed", error: new Error("turn failed") }), + cancel: async () => {}, + }), + close: async () => { currentNow += 100_000; }, + }) as never, + }); + const result = await execute({ + runId: "activity-run", agent: { id: "agent-1", companyId: "company-1" }, runtime: {}, + config: { agent: "custom", agentCommand: "node ./fake-acp.js", stateDir: path.join(root, "state"), cwd }, + context: {}, onMeta: async () => {}, + onLog: async (_stream: string, text: string) => { + if (text.includes('"type":"acpx.error"')) currentNow += 100_000; + }, + } as never); + expect(result.exitCode).toBe(1); + expect(result.resultJson).toMatchObject({ + acpObservedEventCount: outcome === "no_events" ? 0 : 6, + acpPendingToolCount: outcome === "no_events" ? 0 : 1, + acpToolInventoryComplete: outcome === "no_events", + }); + if (outcome === "no_events") expect(result.resultJson).not.toHaveProperty("acpLastEventAgeMs"); + else expect(result.resultJson?.acpLastEventAgeMs).toBe(9000); + const diagnostics = Object.fromEntries(Object.entries(result.resultJson ?? {}).filter(([key]) => key.startsWith("acp"))); + expect(JSON.stringify(diagnostics)).not.toContain("private"); + expect(currentNow).toBeGreaterThan(10_000); + }, + ); +}); + describe("summarizeAcpxTurnUsage", () => { it("uses the post-turn amount alone when the cumulative cost counter reset", () => { const summary = summarizeAcpxTurnUsage({ diff --git a/packages/adapter-utils/src/acpx-engine/execute.ts b/packages/adapter-utils/src/acpx-engine/execute.ts index b1dc569985..b47667cd63 100644 --- a/packages/adapter-utils/src/acpx-engine/execute.ts +++ b/packages/adapter-utils/src/acpx-engine/execute.ts @@ -4691,6 +4691,8 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { }; let eventBreakdown: AcpRuntimeUsageBreakdown | null = null; let eventCostUsd: number | null = null; + let lastRuntimeEventAt: number | null = null; + let observedRuntimeEvents = 0; // The turn-local state the sequence steps share. `promptBuild` sets the // prompt, `preTurnUsage` sets the pre-turn status, `turnStart` sets the // active turn, and `turnFinalize` reads all three. `activeTurn` is the run- @@ -4861,6 +4863,8 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { const toolTitles = new Map(); const drainEvents = (async (): Promise => { for await (const event of turn.events) { + lastRuntimeEventAt = now(); + observedRuntimeEvents += 1; // ACPX currently flattens client-side filesystem/terminal receipts // into status text. They cannot establish complete action outcomes. if (event.type === "status" && /^(fs|terminal)\//.test(event.text)) incompleteToolInventory = true; @@ -4918,6 +4922,18 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { const stepTurnFinalize = async ( input: TurnFinalizeInput, ): Promise => { + // Capture runtime activity before usage reads, error logs, or cleanup + // make an otherwise silent turn look active at its execution deadline. + const lastEventAgeMs = lastRuntimeEventAt === null ? undefined : now() - lastRuntimeEventAt; + const activityDiagnostics = { + acpObservedEventCount: observedRuntimeEvents, + ...(lastEventAgeMs !== undefined && Number.isSafeInteger(lastEventAgeMs) && lastEventAgeMs >= 0 + ? { acpLastEventAgeMs: lastEventAgeMs } : {}), + acpPendingToolCount: [...interruptionTools.values()].filter( + (tool) => tool.status !== "completed" && tool.status !== "failed" && tool.status !== "cancelled", + ).length, + acpToolInventoryComplete: !incompleteToolInventory, + }; if (input.kind === "terminal") { const terminal = input.terminal; const timedOut = input.timedOut; @@ -5047,6 +5063,7 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { costUsd: turnUsage.costUsd, resultJson: { status: channelLost ? "failed" : terminal.status, + ...activityDiagnostics, ...(failureDiagnostic ? { terminalSessionFailure: failureDiagnostic } : {}), ...(classifiedFailure?.errorFamily ? { errorFamily: classifiedFailure.errorFamily } : {}), ...(classifiedFailure?.retryNotBefore @@ -5181,7 +5198,7 @@ export function createAcpxEngineExecutor(deps: AcpxEngineExecutorOptions = {}) { ...referencedProjectStagingFailuresField, model: prepared.requestedModel || null, clearSession: clearSession || timedOut, - resultJson: { phase }, + resultJson: { phase, ...activityDiagnostics }, summary: message, }; // Return a typed failed completion so the coordinator settles for a cause diff --git a/server/src/services/__tests__/run-failure-diagnostics.test.ts b/server/src/services/__tests__/run-failure-diagnostics.test.ts index 838d63f8d0..37494eec92 100644 --- a/server/src/services/__tests__/run-failure-diagnostics.test.ts +++ b/server/src/services/__tests__/run-failure-diagnostics.test.ts @@ -7,6 +7,47 @@ const run = (overrides: Partial = {}) => ({ resultJson: null, ...overrides const collect = (error: unknown) => collectRunFailureDiagnostics(run(), { error }); describe("run failure diagnostics", () => { + it.each(["restore_permission_denied", "restore_lock_timeout", "restore_unsafe_archive", "restore_failed"])( + "includes the saved %s classification without copying workspace paths or results", (code) => { + const result = sanitizeRunFailureDiagnostics(collectRunFailureDiagnostics(run({ resultJson: { + workspaceRestoreFailure: code, workspaceRestorePath: "/private/workspace", + executionBeforeRestore: { errorMessage: "private provider response" }, + } }), {})); + expect(result.execution).toEqual({ workspaceRestoreFailure: code }); + expect(JSON.stringify(result)).not.toContain("private"); + }, + ); + + it.each([null, false, 1, "private arbitrary code", { error: "private" }])( + "omits unknown workspace restore classifications (%j)", (value) => { + const result = collectRunFailureDiagnostics(run({ resultJson: { workspaceRestoreFailure: value } }), {}); + expect(result.execution).not.toHaveProperty("workspaceRestoreFailure"); + expect(JSON.stringify(result)).not.toContain("private"); + }, + ); + + it("includes only bounded ACP activity fields, not tool names, identities, or output", () => { + const result = sanitizeRunFailureDiagnostics(collectRunFailureDiagnostics(run({ resultJson: { + acpLastEventAgeMs: 14_000_000, acpObservedEventCount: 9, acpPendingToolCount: 2, + acpToolInventoryComplete: false, acpToolNames: ["private command"], lastEvent: "private output", + } }), {})); + expect(result.execution).toEqual({ + acpLastEventAgeMs: 14_000_000, acpObservedEventCount: 9, acpPendingToolCount: 2, + acpToolInventoryComplete: false, + }); + expect(JSON.stringify(result)).not.toContain("private"); + }); + + it.each([null, -1, Infinity, NaN, 1.5, Number.MAX_SAFE_INTEGER + 1, "private", {}])( + "omits invalid ACP activity fields (%j)", (value) => { + const result = collectRunFailureDiagnostics(run({ resultJson: { + acpLastEventAgeMs: value, acpObservedEventCount: value, acpPendingToolCount: value, + acpToolInventoryComplete: value, + } }), {}); + expect(result.execution).toEqual({}); + }, + ); + it("selects declared environment secrets under opaque names and common credential keys", () => { expect(collectRunFailureSecretValues({ CUSTOM_BINDING: "bound-opaque-value", ACCESS_TOKEN: "plain-opaque-value", REGION: "us-east-1", EMPTY_KEY: "", diff --git a/server/src/services/run-failure-diagnostics.ts b/server/src/services/run-failure-diagnostics.ts index 86197fc1a1..091b682c68 100644 --- a/server/src/services/run-failure-diagnostics.ts +++ b/server/src/services/run-failure-diagnostics.ts @@ -1,4 +1,5 @@ import type { heartbeatRuns } from "@paperclipai/db"; +import { WORKSPACE_RESTORE_FAILURE_CODES } from "@paperclipai/shared"; import { redactDiagnosticText } from "@paperclipai/adapter-utils/command-redaction"; import { redactCurrentUserText } from "../log-redaction.js"; import { redactSensitiveText, REDACTED_EVENT_VALUE } from "../redaction.js"; @@ -146,6 +147,15 @@ export function collectRunFailureDiagnostics(run: Run, options: RunFailureReport "mode", "stopReason", "timeoutFired", "timeoutSource", "timeoutConfigured", "effectiveTimeoutSec", "errorFamily", ])); + for (const field of ["acpLastEventAgeMs", "acpObservedEventCount", "acpPendingToolCount"]) { + const value = read(result, field); + if (typeof value === "number" && Number.isSafeInteger(value) && value >= 0) execution[field] = value; + } + const toolInventoryComplete = read(result, "acpToolInventoryComplete"); + if (typeof toolInventoryComplete === "boolean") execution.acpToolInventoryComplete = toolInventoryComplete; + const restoreFailure = read(result, "workspaceRestoreFailure"); + const restoreCode = WORKSPACE_RESTORE_FAILURE_CODES.find((code) => code === restoreFailure); + if (restoreCode) execution.workspaceRestoreFailure = restoreCode; const adapter = scalars(options.adapterErrorMeta, [ "category", "phase", "errorName", "acpCode", "causeMessage", "retryable", "stackPreview", "status", "statusCode", "requestId",