From 4b9a6000f75332a7e9a672a2af3ceecce8be00b2 Mon Sep 17 00:00:00 2001 From: Devin Foley Date: Wed, 30 Sep 2026 18:35:12 -0700 Subject: [PATCH] Add bounded evidence for directory lock timeouts (#14787) ## Thinking Path > - Paperclip is the open source app people use to manage AI agents for work. > - Agent files use directory locks during collection and cleanup. > - A lock timeout can fail finalization after the model turn completes. > - The timeout currently identifies no owner state or waiting operation. > - This pull request adds bounded evidence to the existing run failure report. > - Operators can distinguish a known local holder from a possible old lock without changing lock safety. ## Linked Issues or Issue Description **What happened?** A directory lock timeout does not distinguish active local work from an owner record left by an earlier process. The stored execution stage can also precede the cleanup operation that failed. **Expected behavior** The failure report should identify the waiting operation and expose bounded ownership clues. It must preserve the timeout and keep unknown ownership protected. **Steps to reproduce** Hold a directory merge lock while a second caller reaches its acquisition deadline. The regression tests exercise a live holder and an older owner record with a live PID. Related: #9667 proposes stale-lock recovery under a single-server assumption. This change only adds evidence and does not adopt that assumption. #14575 and #14665 add other run failure diagnostics. ## What Changed - Record lock owner state, capped age and wait duration, same-process and process-age comparisons, and whether this module holds the lock. - Label agent-directory release, collection, checkpoint, and warm handoff timeouts with a fixed operation code. - Validate each field before the existing event-local Sentry report accepts it. Exclude owner records, PIDs, paths, and absolute timestamps. - Limit the extra diagnostic owner read to 100 ms with best-effort abort; malformed JSON is `invalid` and unreadable owner records remain `unknown`. - Document the diagnostic limits and verify that contenders never reclaim protected locks. ## Verification - Focused lock, diagnostic, real Sentry SDK, and database-backed agent-directory tests: 126 passed, including stalled-read and malformed/missing/unreadable-owner regression coverage. - Final revision `0691613dcc`: all 54 reported checks successful, with two intentionally skipped Storybook checks. Greptile: 5/5, zero unresolved review threads; no merge conflicts. - `pnpm -r typecheck`: passed. - `pnpm build`: passed. - `pnpm test:run`: complete suite coverage ran with the existing repository shard flags: four general-server shards, four serialized shards, two general-workspaces-a shards, and general-workspaces-b. The full run is not green because of the base failures below. - The broad run found 13 failures in the unchanged macOS skill-cache tests. All 13 reproduce on the clean base revision. Open PR #14290 covers that existing failure. - Two unchanged CLI archive tests hit their five-second limits during the broad run; all 17 tests in that file pass on recheck. A CLI auth socket error also cleared on recheck (19 tests), and its full serialized shard passed on rerun. ## Risks This is a diagnostic change, not a stale-lock fix. Owner observations can race with release. Wall-clock shifts can affect the age comparison. A local-holder flag covers only this module instance. None of these fields authorizes reclamation or proves a file save. Lock acquisition, release, retries, task status, and recovery guards retain their current behavior. No schema change or deployment action is required. ## Model Used OpenAI Codex, based on GPT-6, with code execution and repository tools. The exact model build and context window were not exposed to this agent. ## 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 - [ ] I have run tests locally and they pass (focused checks pass; existing base failures are documented above) - [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 - [x] All Paperclip CI gates are green - [x] Greptile is 5/5 with no open P2s, recommendations, or follow-ups - [x] I will address all Greptile and reviewer comments before requesting merge --------- Co-authored-by: Paperclip --- doc/observability.md | 16 ++ .../src/workspace-restore-merge.test.ts | 139 ++++++++++++++++++ .../src/workspace-restore-merge.ts | 80 +++++++++- .../run-failure-sentry-real-sdk.test.ts | 9 +- .../__tests__/run-failure-diagnostics.test.ts | 29 ++++ .../agent-directory-working-copies.ts | 14 +- .../src/services/run-failure-diagnostics.ts | 21 +++ 7 files changed, 296 insertions(+), 12 deletions(-) diff --git a/doc/observability.md b/doc/observability.md index 0be094bccd5..470d0413ef6 100644 --- a/doc/observability.md +++ b/doc/observability.md @@ -482,6 +482,22 @@ 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. +A caught directory-merge lock timeout also records `restoreLockOwnerState` +(`alive`, `dead`, `unknown`, `missing`, or `invalid`), `restoreLockKnownLocalHolder`, +and, when available, `restoreLockOwnerSameProcess`, `restoreLockOwnerPredatesProcess`, +`restoreLockOwnerAgeMs`, and `restoreLockWaitMs` in `run_execution`. Ages are capped +at seven days. These fields omit paths, PIDs, owner records, and absolute timestamps. +The local-holder flag covers this module's active acquisitions only. Process-age +comparison uses the wall clock and a one-second margin; it is a clue to PID reuse, +not proof of ownership or permission to remove a lock. Diagnostic reads can race +with release. The extra diagnostic owner read has a 100 ms budget; a stalled or +unreadable read leaves the owner state `unknown`, while malformed JSON is `invalid`. +These fields do not change lock acquisition, reclamation, or retries. +Agent-directory callers also supply `restoreLockOperation`: `agent_directory_release`, +`agent_directory_collect`, `agent_directory_checkpoint`, or `agent_directory_handoff`. +This identifies the operation waiting for the lock, including cleanup after a +completed adapter turn when the recorded execution stage has not advanced. + 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/workspace-restore-merge.test.ts b/packages/adapter-utils/src/workspace-restore-merge.test.ts index 914d99ac751..aaacd5d7dac 100644 --- a/packages/adapter-utils/src/workspace-restore-merge.test.ts +++ b/packages/adapter-utils/src/workspace-restore-merge.test.ts @@ -444,6 +444,145 @@ describe("workspace restore merge", () => { // have produced this result. expect(caughtError?.message).not.toContain("restore_lock_timeout"); expect(classifyWorkspaceRestoreFailure(caughtError)).toBe("restore_lock_timeout"); + expect(caughtError).toMatchObject({ workspaceRestoreLock: { + ownerState: "alive", ownerSameProcess: true, knownLocalHolder: false, + } }); + }); + + it("reports a known live holder without releasing it when a contender times out", async () => { + const rootDir = await mkdtemp(path.join(os.tmpdir(), "paperclip-lock-holder-")); + cleanupDirs.push(rootDir); + useTempPaperclipHome(path.join(rootDir, "home"), "test-instance"); + const targetDir = path.join(rootDir, "target"); + await mkdir(targetDir); + const lockRoot = path.join(rootDir, "home", "instances", "test-instance", "locks", "directory-merge"); + const contender = vi.fn(); + await withDirectoryMergeLock(targetDir, async () => { + const now = Date.now(); + const clock = vi.spyOn(Date, "now").mockReturnValue(now) + .mockReturnValueOnce(now).mockReturnValueOnce(now + 30_001); + try { + await expect(withDirectoryMergeLock(targetDir, contender, process.env, "agent_directory_release")).rejects.toMatchObject({ + code: WORKSPACE_RESTORE_LOCK_TIMEOUT_CODE, + workspaceRestoreLock: { ownerState: "alive", ownerSameProcess: true, + knownLocalHolder: true, ownerPredatesProcess: false, operation: "agent_directory_release" }, + }); + } finally { clock.mockRestore(); } + expect(contender).not.toHaveBeenCalled(); + expect(await readdir(lockRoot)).toHaveLength(1); + }); + expect(await readdir(lockRoot)).toHaveLength(0); + }); + + it("delivers the timeout when the diagnostic owner read stalls and ignores its late rejection", async () => { + const rootDir = await mkdtemp(path.join(os.tmpdir(), "paperclip-lock-read-stall-")); + cleanupDirs.push(rootDir); + useTempPaperclipHome(path.join(rootDir, "home"), "test-instance"); + const targetDir = path.join(rootDir, "target"); + await mkdir(targetDir); + const contender = vi.fn(); + await withDirectoryMergeLock(targetDir, async () => { + const now = Date.now(); + vi.useFakeTimers({ toFake: ["setTimeout", "clearTimeout"] }); + const clock = vi.spyOn(Date, "now").mockReturnValue(now) + .mockReturnValueOnce(now).mockReturnValueOnce(now + 30_001); + let markReadStarted!: (signal: AbortSignal) => void; + const readStarted = new Promise((resolve) => { markReadStarted = resolve; }); + let rejectStalledRead!: (error: Error) => void; + const stalledRead = new Promise((_resolve, reject) => { rejectStalledRead = reject; }); + const realReadFile = fsPromises.readFile; + const readSpy = vi.spyOn(fsPromises, "readFile") + .mockImplementation((file, options) => { + if (!options || typeof options !== "object" || !options.signal) return realReadFile(file, options); + markReadStarted(options.signal); + return stalledRead; + }); + try { + const pending = withDirectoryMergeLock(targetDir, contender, process.env, "agent_directory_release") + .catch((error: unknown) => error); + const signal = await readStarted; + await vi.advanceTimersByTimeAsync(100); + const error = await pending; + expect(error).toMatchObject({ + code: WORKSPACE_RESTORE_LOCK_TIMEOUT_CODE, + workspaceRestoreLock: { ownerState: "unknown", knownLocalHolder: true, + operation: "agent_directory_release" }, + }); + expect(signal.aborted).toBe(true); + expect(vi.getTimerCount()).toBe(0); + rejectStalledRead(new Error("late filesystem failure")); + await Promise.resolve(); + expect(contender).not.toHaveBeenCalled(); + expect(error).toMatchObject({ workspaceRestoreLock: { ownerState: "unknown" } }); + } finally { + vi.useRealTimers(); + readSpy.mockRestore(); + clock.mockRestore(); + } + }); + }); + + it.each([ + { label: "malformed JSON", raw: "{invalid-json", code: undefined, ownerState: "invalid" }, + { label: "a missing file", raw: undefined, code: "ENOENT", ownerState: "missing" }, + { label: "an unreadable file", raw: undefined, code: "EACCES", ownerState: "unknown" }, + ])("distinguishes $label in the diagnostic read", async ({ raw, code, ownerState }) => { + const rootDir = await mkdtemp(path.join(os.tmpdir(), "paperclip-lock-read-state-")); + cleanupDirs.push(rootDir); + useTempPaperclipHome(path.join(rootDir, "home"), "test-instance"); + const targetDir = path.join(rootDir, "target"); + await mkdir(targetDir); + const contender = vi.fn(); + await withDirectoryMergeLock(targetDir, async () => { + const now = Date.now(); + const clock = vi.spyOn(Date, "now").mockReturnValue(now) + .mockReturnValueOnce(now).mockReturnValueOnce(now + 30_001); + const realReadFile = fsPromises.readFile; + const readSpy = vi.spyOn(fsPromises, "readFile") + .mockImplementation(async (file, options) => { + if (!options || typeof options !== "object" || !options.signal) return realReadFile(file, options); + if (code) throw Object.assign(new Error("owner read failed"), { code }); + return raw!; + }); + try { + await expect(withDirectoryMergeLock(targetDir, contender)).rejects.toMatchObject({ + code: WORKSPACE_RESTORE_LOCK_TIMEOUT_CODE, + workspaceRestoreLock: { ownerState, knownLocalHolder: true }, + }); + expect(contender).not.toHaveBeenCalled(); + } finally { + readSpy.mockRestore(); + clock.mockRestore(); + } + }); + }); + + it("reports an owner older than this process without reclaiming a live PID", async () => { + const rootDir = await mkdtemp(path.join(os.tmpdir(), "paperclip-lock-older-owner-")); + cleanupDirs.push(rootDir); + useTempPaperclipHome(path.join(rootDir, "home"), "test-instance"); + const targetDir = path.join(rootDir, "target"); + await mkdir(targetDir); + const lockKey = createHash("sha256").update(await realpath(targetDir)).digest("hex"); + const lockDir = path.join(rootDir, "home", "instances", "test-instance", "locks", "directory-merge", `${lockKey}.lock`); + await mkdir(lockDir, { recursive: true }); + const now = Date.now(); + const owner = JSON.stringify({ pid: process.pid, createdAt: new Date(now - process.uptime() * 1000 - 10_000).toISOString(), private: "private owner payload" }); + await writeFile(path.join(lockDir, "owner.json"), owner); + const clock = vi.spyOn(Date, "now").mockReturnValue(now) + .mockReturnValueOnce(now).mockReturnValueOnce(now + 30_001); + let caught: unknown; + try { await withDirectoryMergeLock(targetDir, async () => { throw new Error("must not acquire"); }); } + catch (error) { caught = error; } + finally { clock.mockRestore(); } + expect(caught).toMatchObject({ code: WORKSPACE_RESTORE_LOCK_TIMEOUT_CODE, + workspaceRestoreLock: { ownerState: "alive", ownerSameProcess: true, + knownLocalHolder: false, ownerPredatesProcess: true } }); + const diagnostic = (caught as { workspaceRestoreLock: Record }).workspaceRestoreLock; + expect(Object.keys(diagnostic).sort()).toEqual(["knownLocalHolder", "ownerAgeMs", "ownerPredatesProcess", "ownerSameProcess", "ownerState", "waitMs"]); + expect(JSON.stringify(diagnostic)).not.toContain("private"); + expect(JSON.stringify(diagnostic)).not.toContain(lockDir); + expect(await readFile(path.join(lockDir, "owner.json"), "utf8")).toBe(owner); }); it.skipIf(process.platform === "win32")( diff --git a/packages/adapter-utils/src/workspace-restore-merge.ts b/packages/adapter-utils/src/workspace-restore-merge.ts index fafba8dabd4..755bce9be40 100644 --- a/packages/adapter-utils/src/workspace-restore-merge.ts +++ b/packages/adapter-utils/src/workspace-restore-merge.ts @@ -201,6 +201,68 @@ function entriesMatch(left: SnapshotEntry | null | undefined, right: SnapshotEnt } const LOCK_STALE_MS = 30_000; +const LOCK_DIAGNOSTIC_READ_TIMEOUT_MS = 100; +const activeDirectoryMergeLocks = new Set(); +const MAX_LOCK_DIAGNOSTIC_AGE_MS = 7 * 24 * 60 * 60 * 1000; +export type DirectoryMergeLockOperation = + | "agent_directory_release" + | "agent_directory_collect" + | "agent_directory_checkpoint" + | "agent_directory_handoff"; + +/** Evidence only: neither process age nor this module's holder set can prove + * that a lock in another process or PID namespace is safe to reclaim. */ +async function directoryMergeLockDiagnostics(lockDir: string, waitMs: number): Promise> { + const diagnostics: Record = { + ownerState: "unknown", + knownLocalHolder: activeDirectoryMergeLocks.has(lockDir), + waitMs: Math.min(MAX_LOCK_DIAGNOSTIC_AGE_MS, Math.max(0, Math.floor(waitMs))), + }; + const controller = new AbortController(); + let timeout: ReturnType | undefined; + try { + // Abort is best effort: race the read as well so a stalled filesystem + // cannot keep the original lock timeout from reaching its caller. + const raw = await Promise.race([ + fs.readFile(path.join(lockDir, "owner.json"), { encoding: "utf8", signal: controller.signal }), + new Promise((resolve) => { + timeout = setTimeout(() => resolve(undefined), LOCK_DIAGNOSTIC_READ_TIMEOUT_MS); + }), + ]); + if (raw === undefined) return diagnostics; + let owner: { pid?: unknown; createdAt?: unknown } | null; + try { + owner = JSON.parse(raw) as typeof owner; + } catch { + diagnostics.ownerState = "invalid"; + return diagnostics; + } + if (!owner || !Number.isSafeInteger(owner.pid) || (owner.pid as number) <= 0) { + diagnostics.ownerState = "invalid"; + return diagnostics; + } + const pid = owner.pid as number; + diagnostics.ownerSameProcess = pid === process.pid; + try { + process.kill(pid, 0); + diagnostics.ownerState = "alive"; + } catch (error) { + diagnostics.ownerState = (error as NodeJS.ErrnoException).code === "ESRCH" ? "dead" : "unknown"; + } + const createdAt = typeof owner.createdAt === "string" ? Date.parse(owner.createdAt) : NaN; + const ageMs = Date.now() - createdAt; + if (Number.isFinite(ageMs) && ageMs >= 0) { + diagnostics.ownerAgeMs = Math.min(MAX_LOCK_DIAGNOSTIC_AGE_MS, Math.floor(ageMs)); + if (pid === process.pid) diagnostics.ownerPredatesProcess = ageMs > process.uptime() * 1000 + 1000; + } + } catch (error) { + diagnostics.ownerState = (error as NodeJS.ErrnoException).code === "ENOENT" ? "missing" : "unknown"; + } finally { + clearTimeout(timeout); + controller.abort(); + } + return diagnostics; +} /** * The stable `code` a lock-timeout error carries, so a caller can identify it @@ -305,7 +367,8 @@ async function isLockStale(lockDir: string): Promise { } } -async function acquireDirectoryMergeLock(lockDir: string): Promise<() => Promise> { +async function acquireDirectoryMergeLock(lockDir: string, operation?: DirectoryMergeLockOperation): Promise<() => Promise> { + const startedAt = performance.now(); const deadline = Date.now() + LOCK_STALE_MS; while (true) { try { @@ -315,8 +378,13 @@ async function acquireDirectoryMergeLock(lockDir: string): Promise<() => Promise `${JSON.stringify({ pid: process.pid, createdAt: new Date().toISOString() })}\n`, "utf8", ); + activeDirectoryMergeLocks.add(lockDir); return async () => { - await fs.rm(lockDir, { recursive: true, force: true }).catch(() => undefined); + try { + await fs.rm(lockDir, { recursive: true, force: true }).catch(() => undefined); + } finally { + activeDirectoryMergeLocks.delete(lockDir); + } }; } catch (error) { const code = error && typeof error === "object" ? (error as { code?: unknown }).code : null; @@ -329,10 +397,13 @@ async function acquireDirectoryMergeLock(lockDir: string): Promise<() => Promise continue; } if (Date.now() >= deadline) { - const timeoutError: NodeJS.ErrnoException = new Error( + const timeoutError: NodeJS.ErrnoException & { workspaceRestoreLock?: Record } = new Error( `Timed out waiting for workspace restore lock at ${lockDir}`, ); timeoutError.code = WORKSPACE_RESTORE_LOCK_TIMEOUT_CODE; + // Keep the original timeout if the diagnostic read itself fails. + timeoutError.workspaceRestoreLock = await directoryMergeLockDiagnostics(lockDir, performance.now() - startedAt).catch(() => undefined); + if (operation && timeoutError.workspaceRestoreLock) timeoutError.workspaceRestoreLock.operation = operation; throw timeoutError; } await new Promise((resolve) => setTimeout(resolve, 50)); @@ -411,13 +482,14 @@ export async function withDirectoryMergeLock( targetDir: string, fn: (canonicalTargetDir: string) => Promise, env: NodeJS.ProcessEnv = process.env, + diagnosticOperation?: DirectoryMergeLockOperation, ): Promise { // Canonicalize before we hash or lock: a retargeted symlink must not let the // lock protect one directory while the caller mutates another. const canonicalTargetDir = await fs.realpath(targetDir); const lockRoot = await resolveDirectoryMergeLockRoot(env); const lockKey = createHash("sha256").update(canonicalTargetDir).digest("hex"); - const releaseLock = await acquireDirectoryMergeLock(path.join(lockRoot, `${lockKey}.lock`)); + const releaseLock = await acquireDirectoryMergeLock(path.join(lockRoot, `${lockKey}.lock`), diagnosticOperation); try { return await fn(canonicalTargetDir); } finally { diff --git a/server/src/__tests__/run-failure-sentry-real-sdk.test.ts b/server/src/__tests__/run-failure-sentry-real-sdk.test.ts index a3f26b22edd..583b827f3bc 100644 --- a/server/src/__tests__/run-failure-sentry-real-sdk.test.ts +++ b/server/src/__tests__/run-failure-sentry-real-sdk.test.ts @@ -129,7 +129,11 @@ describe.skipIf(!sentryPackage)("run failure context with the real Sentry SDK", code: "ECONNRESET", requestId: "request-123", status: 503, stack: "Error: upstream connection reset\n at socketRead (/app/provider.js:19:7)", response: { body: "private-response" }, - }) }), { stack: "Error: first run failed\n at originalAdapter (/app/adapter.js:42:7)", request: { headers: "private-headers" } }); + }) }), { stack: "Error: first run failed\n at originalAdapter (/app/adapter.js:42:7)", request: { headers: "private-headers" }, + code: "ERR_WORKSPACE_RESTORE_LOCK_TIMEOUT", workspaceRestoreLock: { + operation: "agent_directory_release", ownerState: "alive", ownerSameProcess: true, ownerPredatesProcess: true, + knownLocalHolder: false, ownerAgeMs: 120_000, waitMs: 30_001, path: "/private-lock-path", + } }); const diagnostics = sanitizeRunFailureDiagnostics(collectRunFailureDiagnostics({ runtimeMode: "legacy", resultJson: { terminalSessionFailure: { category: "service", title: "Provider failed", details: "d".repeat(9000), @@ -175,6 +179,9 @@ describe.skipIf(!sentryPackage)("run failure context with the real Sentry SDK", expect(JSON.stringify(exceptions)).not.toContain("captureRunFailure"); expect(JSON.stringify(captured(second.errorMessage)?.exception)).not.toContain("captureRunFailure"); expect(firstCapture).toMatchObject({ contexts: { + run_execution: { restoreLockOperation: "agent_directory_release", restoreLockOwnerState: "alive", restoreLockOwnerSameProcess: true, + restoreLockOwnerPredatesProcess: true, restoreLockKnownLocalHolder: false, + restoreLockOwnerAgeMs: 120_000, restoreLockWaitMs: 30_001 }, provider_failure: { category: "service", details: "d".repeat(9000) }, run_exception_1: { code: "ECONNRESET", requestId: "request-123", status: 503 }, } }); diff --git a/server/src/services/__tests__/run-failure-diagnostics.test.ts b/server/src/services/__tests__/run-failure-diagnostics.test.ts index 37494eec920..4e1fe15a841 100644 --- a/server/src/services/__tests__/run-failure-diagnostics.test.ts +++ b/server/src/services/__tests__/run-failure-diagnostics.test.ts @@ -7,6 +7,35 @@ const run = (overrides: Partial = {}) => ({ resultJson: null, ...overrides const collect = (error: unknown) => collectRunFailureDiagnostics(run(), { error }); describe("run failure diagnostics", () => { + it("selects bounded lock-owner evidence from a caught timeout cause", () => { + const error = new Error("outer", { cause: Object.assign(new Error("lock timeout"), { + code: "ERR_WORKSPACE_RESTORE_LOCK_TIMEOUT", + workspaceRestoreLock: { operation: "agent_directory_release", ownerState: "alive", ownerSameProcess: true, + ownerPredatesProcess: true, knownLocalHolder: false, ownerAgeMs: 120_000, waitMs: 30_001, + ownerPid: 123, path: "/sentinel-lock-path", owner: { payload: "sentinel-owner-payload" } }, + }) }); + const result = sanitizeRunFailureDiagnostics(collect(error)); + expect(result.execution).toEqual({ restoreLockOperation: "agent_directory_release", restoreLockOwnerState: "alive", restoreLockOwnerSameProcess: true, + restoreLockOwnerPredatesProcess: true, restoreLockKnownLocalHolder: false, + restoreLockOwnerAgeMs: 120_000, restoreLockWaitMs: 30_001 }); + expect(JSON.stringify(result)).not.toContain("sentinel-"); + expect(result.execution).not.toHaveProperty("ownerPid"); + }); + + it.each([null, -1, Infinity, NaN, 1.5, 604_800_001, "private", {}])("omits invalid lock diagnostic values (%j)", value => { + const error = Object.assign(new Error("lock timeout"), { code: "ERR_WORKSPACE_RESTORE_LOCK_TIMEOUT", + workspaceRestoreLock: { operation: value, ownerState: value, ownerAgeMs: value, waitMs: value, + ownerSameProcess: value, ownerPredatesProcess: value, knownLocalHolder: value } }); + expect(collect(error).execution).toEqual({}); + }); + + it("does not attach lock evidence to unrelated errors or invoke hostile getters", () => { + expect(collect({ code: "OTHER", workspaceRestoreLock: { ownerState: "alive" } }).execution).toEqual({}); + const error = { code: "ERR_WORKSPACE_RESTORE_LOCK_TIMEOUT", + workspaceRestoreLock: Object.defineProperty({}, "ownerState", { get() { throw new Error("private"); } }) }; + expect(collect(error).execution).toEqual({}); + }); + 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: { diff --git a/server/src/services/agent-directory-working-copies.ts b/server/src/services/agent-directory-working-copies.ts index 33faf661243..b76f212ff51 100644 --- a/server/src/services/agent-directory-working-copies.ts +++ b/server/src/services/agent-directory-working-copies.ts @@ -4,7 +4,7 @@ import { and, eq } from "drizzle-orm"; import { agents, environmentLeases, environments, agentInstructionWorkingCopies as copies, type Db } from "@paperclipai/db"; import { syncDirectoryToSsh, restoreWorkspaceFromSshExecution } from "@paperclipai/adapter-utils/ssh"; import { prepareAdapterExecutionTargetRuntime, runAdapterExecutionTargetShellCommand, type AdapterExecutionTarget, type PreparedAdapterExecutionTargetRuntime } from "@paperclipai/adapter-utils/execution-target"; -import { withDirectoryMergeLock, directorySnapshotSha256, parseDirectorySnapshot, serializeDirectorySnapshot } from "@paperclipai/adapter-utils/workspace-restore-merge"; +import { withDirectoryMergeLock, directorySnapshotSha256, parseDirectorySnapshot, serializeDirectorySnapshot, type DirectoryMergeLockOperation } from "@paperclipai/adapter-utils/workspace-restore-merge"; import { AGENT_FILES_CONTRACT, AgentFileLimitError, agentFileStore, agentStorageWarning, inspectAgentDirectory } from "./agent-file-store.js"; import { agentInstructionsBundleMode, deriveBundleState, resolveManagedInstructionsRoot } from "./agent-instructions.js"; import { instructionGitExcludeProgram } from "./agent-instruction-files.js"; @@ -108,7 +108,7 @@ export function agentDirectoryWorkingCopyService(db: Db, get: (companyId: string if (!handedOff) await db.delete(copies).where(and(eq(copies.companyId, input.companyId), eq(copies.runId, input.runId))); throw error; } - }); + }, "agent_directory_handoff"); } const localRoot = path.join(path.dirname(root), "file-sync", "runs", input.runId, "live"); // Local copies live outside the task cwd. Remote copies use the reserved, @@ -343,18 +343,18 @@ export function agentDirectoryWorkingCopyService(db: Db, get: (companyId: string cwd: remoteCwd, env: {}, timeoutMs: 15_000, bypassSession: true }); return result.exitCode === 0 && !result.timedOut; } - async function serial(row: Copy, fn: (current: Copy) => Promise): Promise { + async function serial(row: Copy, fn: (current: Copy) => Promise, operation: DirectoryMergeLockOperation): Promise { // Duplicate stop callbacks and restart recovery must not race while moving // the stopped working copy. This lock is outside the writable tree. return withDirectoryMergeLock(path.resolve(row.localRoot, "../../.."), async () => { const current = await get(row.companyId, row.runId); if (!current) throw notFound("Agent directory copy not found"); return fn(current); - }); + }, process.env, operation); } return { prepare, hasChanges, canReuse, - checkpointWarm: (row: Copy, target?: AdapterExecutionTarget | null) => serial(row, current => current.receipt?.warm === true ? checkpoint(current, target) : Promise.resolve(current)), - collectStopped: (row: Copy, target?: AdapterExecutionTarget | null) => serial(row, current => collectStopped(current, target)), - release: (row: Copy) => serial(row, release), + checkpointWarm: (row: Copy, target?: AdapterExecutionTarget | null) => serial(row, current => current.receipt?.warm === true ? checkpoint(current, target) : Promise.resolve(current), "agent_directory_checkpoint"), + collectStopped: (row: Copy, target?: AdapterExecutionTarget | null) => serial(row, current => collectStopped(current, target), "agent_directory_collect"), + release: (row: Copy) => serial(row, release, "agent_directory_release"), }; } diff --git a/server/src/services/run-failure-diagnostics.ts b/server/src/services/run-failure-diagnostics.ts index 091b682c68a..27ccc1f7191 100644 --- a/server/src/services/run-failure-diagnostics.ts +++ b/server/src/services/run-failure-diagnostics.ts @@ -183,6 +183,27 @@ export function collectRunFailureDiagnostics(run: Run, options: RunFailureReport break; } if (typeof error !== "object") break; + if (execution.restoreLockOwnerState === undefined && read(error, "code") === "ERR_WORKSPACE_RESTORE_LOCK_TIMEOUT") { + const lock = read(error, "workspaceRestoreLock"); + const operation = read(lock, "operation"); + if (["agent_directory_release", "agent_directory_collect", "agent_directory_checkpoint", "agent_directory_handoff"].some(value => value === operation)) { + execution.restoreLockOperation = operation as string; + } + const ownerState = read(lock, "ownerState"); + if (["alive", "dead", "unknown", "missing", "invalid"].some(value => value === ownerState)) { + execution.restoreLockOwnerState = ownerState as string; + } + for (const field of ["knownLocalHolder", "ownerSameProcess", "ownerPredatesProcess"]) { + const value = read(lock, field); + if (typeof value === "boolean") execution[`restoreLock${field[0]!.toUpperCase()}${field.slice(1)}`] = value; + } + for (const field of ["ownerAgeMs", "waitMs"]) { + const value = read(lock, field); + if (typeof value === "number" && Number.isSafeInteger(value) && value >= 0 && value <= 7 * 24 * 60 * 60 * 1000) { + execution[`restoreLock${field[0]!.toUpperCase()}${field.slice(1)}`] = value; + } + } + } const entry: RunFailureException = {}; for (const field of ["name", "message", "stack", "code"] as const) { const value = read(error, field);