Files
PaperClipAI/server/src/services/skill-version-cache-lock.test.ts
T
Devin FoleyandClaude Opus 5.5 72d80944a9 fix(skills): keep the skill cache lock transaction active (#18996)
Replaces #17907. That branch conflicted with `master` after #17918 added
preparation timing to the same function. This branch applies the same
fix on current `master` and keeps that timing.

## Thinking Path

> - Paperclip is the open source app people use to manage AI agents for
work.
> - Before a run starts, the server prepares the agent's skills while
holding a per-company skill cache lock.
> - The lock is a Postgres advisory transaction lock on a dedicated
connection. The preparation work runs on the ordinary pool, so the lock
transaction sits idle.
> - Hosted Postgres (Neon) sets `idle_in_transaction_session_timeout`.
If preparation runs longer than that timeout, Postgres ends the lock
session.
> - The lock is then released early, and the commit fails with `write
CONNECTION_CLOSED`. The run fails during setup and the preparation work
is lost.
> - #16340 and #16956 fixed the same problem for the workspace source
lock and the lifecycle lock with `withWorkspaceLockKeepalive`.
> - This pull request applies that keepalive to the skill cache lock.
> - With it, slow skill preparation keeps its lock and the run no longer
fails.

## Linked Issues or Issue Description

Refs #16340
Refs #16956
Supersedes #17907

**What happened?**

A hosted staging run failed during setup with `write CONNECTION_CLOSED
<neon-pooler-host>:5432`. The run trace shows `skills.prepare` running
for 322 seconds before it failed. That is longer than Neon's 5-minute
`idle_in_transaction_session_timeout`. The stack ends in
`postgres/src/connection.js` (`TLSSocket.closed`).

**Expected behavior**

Skill preparation holds the skill cache lock until it finishes, and no
other preparation for the same company can enter the locked section
during that time. The run then continues to execution.

**Steps to reproduce**

1. Set `idle_in_transaction_session_timeout` on the database role to
`1s`.
2. Call `withSkillVersionCacheLock` with an action that waits longer
than 1 second.
3. Without this change, a second `tryOnly` call for the same company
gets the lock while the first call still holds it. The first call then
fails with `write CONNECTION_CLOSED` instead of returning its own result
or error.

## What Changed

- After `withSkillVersionCacheLock` gets the lock and records the
`skills.cache.acquire` phase, it reads
`idle_in_transaction_session_timeout`. It then runs the action inside
the existing `withWorkspaceLockKeepalive` helper. The helper sends
`select 1` on the lock transaction every third of the timeout, and at
least every 30 seconds. When the timeout is 0 (disabled), the helper
does nothing.
- The `.catch` from `master` that ends the timing phase on failure is
kept.
- Added `skill-version-cache-lock.test.ts`. It runs against real
embedded Postgres with a 1-second idle timeout, following the same
pattern as `isolated-remote-workspace-source-lock.test.ts`.
- The edited file no longer has an extra blank line at the end. This is
whitespace only.

## Verification

All checks below ran on this branch's tree, which is `master` at
afbc5a88 plus this change.

- **Red on current `master`:** both new tests fail against the unpatched
`master` source. The overlap test gets the lock a second time (`promise
resolved "'overlap'" instead of rejecting`). The failure test gets
`write CONNECTION_CLOSED 127.0.0.1:<port>` instead of the original
error, which is the same error as in production.
- **Green with the fix:** `skill-version-cache-lock.test.ts` and
`native-workspace-lock-keepalive.test.ts` pass (8 tests).
- **Related suites pass:** 13 files and 245 tests, covering
`execution-preparation-timing`, `isolated-remote-workspace-source-lock`,
`company-skills` (service, runtime concurrency and runtime selection),
every `skill-version-*` suite and `heartbeat-execution-configuration`.
- **Other checks:** `node scripts/check-module-boundaries.mjs` and `git
diff --check` pass.
- **Not run locally:** the full server `tsc`, because the sandbox has an
8 GB memory limit. CI has to confirm it.
- **Not done:** a live run on hosted staging. That will show after the
normal rollout.

On #17907, CI failed in `environment-cleanup-work.test.ts` (an
off-by-one call count) and `chat-channels.integration.test.ts` (reply
ordering). Neither test touches the skill cache lock. This branch runs
CI again on current `master`.

## Risks

- Low risk. The change runs only inside the existing lock transaction.
The work still uses the ordinary pool, so a one-slot pool cannot
deadlock.
- Each lock adds one `pg_settings` read. A long lock adds one `select 1`
at least every 30 seconds.
- If a keepalive query fails, the helper ignores the failure, and the
work's own result or error is unchanged. The other locks behave the same
way.
- This change does not explain why preparation took more than 5 minutes.
That is a separate performance question.

## Model Used

Anthropic Claude Opus 5.5 (`claude-opus-5-5`), with tool use and code
execution in a Paperclip agent sandbox.

## 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
- [x] 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 <noreply@anthropic.com>
2026-11-04 14:36:01 -08:00

76 lines
3.4 KiB
TypeScript

import { randomUUID } from "node:crypto";
import { setTimeout as delay } from "node:timers/promises";
import { sql } from "drizzle-orm";
import { afterAll, beforeAll, describe, expect, it } from "vitest";
import { createDb } from "@paperclipai/db";
import { getEmbeddedPostgresTestSupport, startEmbeddedPostgresTestDatabase } from "../__tests__/helpers/embedded-postgres.js";
import { SkillCacheBusy, withSkillVersionCacheLock } from "./skill-version-cache.js";
const support = await getEmbeddedPostgresTestSupport();
const describePostgres = support.supported ? describe : describe.skip;
if (!support.supported) console.warn(`Skill version cache lock tests require Postgres: ${support.reason}`);
describePostgres("skill version cache lock during slow preparation", () => {
let database: Awaited<ReturnType<typeof startEmbeddedPostgresTestDatabase>>;
let db: ReturnType<typeof createDb>;
beforeAll(async () => {
database = await startEmbeddedPostgresTestDatabase("skill-version-cache-lock-");
db = createDb(database.connectionString, { maxConnections: 1 });
const rows = await db.execute(sql`select current_user as name`);
const role = String(rows[0].name);
await db.execute(sql`alter role ${sql.identifier(role)} set idle_in_transaction_session_timeout = '1s'`);
});
afterAll(async () => {
try {
await db?.$client.end({ timeout: 1 });
} finally {
await database?.cleanup();
}
});
it("keeps the lock beyond the idle timeout while preparation uses the ordinary pool", async () => {
const companyId = randomUUID();
let entered!: () => void, release!: () => void;
const started = new Promise<void>(resolve => { entered = resolve; });
const pending = new Promise<void>(resolve => { release = resolve; });
const preparation = withSkillVersionCacheLock(db, companyId, async () => {
await db.execute(sql`select 1`);
entered();
await pending;
return "prepared";
}).then(value => ({ value }), error => ({ error }));
try {
// Surface a preparation that settles before entering instead of timing out.
let hasEntered = false;
await Promise.race([started.then(() => { hasEntered = true; }), preparation.then(result => {
if (hasEntered) return;
throw "error" in result ? result.error : new Error("Preparation finished before entering the lock");
})]);
await delay(1400);
await expect(db.execute(sql`select 1 as usable`)).resolves.toMatchObject([{ usable: 1 }]);
await expect(withSkillVersionCacheLock(db, companyId, async () => "overlap", true))
.rejects.toBeInstanceOf(SkillCacheBusy);
await expect(withSkillVersionCacheLock(db, randomUUID(), async () => "independent", true))
.resolves.toBe("independent");
} finally {
release();
await preparation;
}
expect(await preparation).toEqual({ value: "prepared" });
await expect(withSkillVersionCacheLock(db, companyId, async () => "next", true)).resolves.toBe("next");
});
it("releases a failed preparation and preserves the original failure", async () => {
const companyId = randomUUID();
const failure = new Error("skill preparation failed");
await expect(withSkillVersionCacheLock(db, companyId, async () => {
await delay(1400);
throw failure;
})).rejects.toBe(failure);
await expect(withSkillVersionCacheLock(db, companyId, async () => "recovered", true)).resolves.toBe("recovered");
});
});