mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-10-29 04:25:52 +01:00
## Thinking Path > - Paperclip is the open source app people use to manage AI agents for work. > - Each native run prepares its workspace and skills, then starts its provider. > - A long preparation span does not show whether inventory refresh, a cache lock, repository reads, or file checks caused the delay. > - One hosted run spent 81 seconds in this phase. The same deployed service and pinned files took 2.55 seconds in a separate diagnostic process. > - Another hosted turn spent 69 seconds before its first output. A matched public-workspace local model replay took 7.64 seconds. > - We need skill preparation and provider-internal measurements before choosing another fix. > - This pull request adds skill spans, a real-service benchmark, and opt-in filtered provider timing. > - The benefit is a faster and more precise diagnosis loop. ## Linked Issues or Issue Description Refs #17620. That PR owns the batched read optimization. This PR adds diagnostics and does not change its read policy. Refs #17907. That PR protects long cache lock transactions from the database idle timeout. **What happened?** Native skill configuration can take much longer than matched standalone resolution. Provider execution also has long gaps with no internal timings. Existing spans cannot separate inventory refresh, cache acquisition, repository reads, context loading, Git snapshots, or model streaming. **Expected behavior** An operator-configured trace shows these phases under the existing run context. Without an OTLP endpoint, the new spans stay off. A local benchmark can reproduce the service path with real PostgreSQL, files, an agent actor, and a responsible user. **Steps to reproduce** 1. Run `pnpm --filter @paperclipai/server exec tsx scripts/benchmark-native-skill-preparation.ts --actor=agent --staging-shape=true`. 2. Inspect cold and warm phase timings, SQL counts, and file verification results. 3. Set the existing operator OTLP configuration and add `--export-otlp=true` to inspect the same hierarchy in the collector. ## What Changed - Add bounded skill inventory, refresh wait, cache acquisition, row, version, repository, file check, and consumer spans. - Keep the existing endpoint gate, attribute allowlist, cache locks, authorization, file validation, and durable pin boundary. - Add a standalone benchmark with a full repository fixture, immutable snapshot input, calibrated local transport delay, and optional OTLP export. - Verify every delivered file and executable bit outside the timed section. Create its fixture agent through the lifecycle API. - Add an opt-in authenticated loopback sink for OpenCode. Discard raw attributes, logs and content. Retain only closed phase names and timestamps. - Carry one bounded diagnostic batch through the real proxy, Rust normalization, durable journal and server trace projection. Group provider phases under their execution parent. - Freeze the Date clock in an existing delegated Slack rate-limit test. This fixes a CI failure when consecutive requests cross a rate-window boundary. It does not change rate-limit behavior. - Document phase boundaries and the difference between SDK startup and confirmed ingestion. ## Verification - Skill service, runtime selection, concurrency, cache and timing suites: 122 tests passed with real PostgreSQL and migrations. Enabled-span integration tests also passed. They verify parent relationships and a real advisory-lock timeout. - A captured 208-file repository produced 209 verified runtime files. The benchmark uses real agent and responsible-user authorization. The lifecycle fixture correction passed with the staging-shaped inventory. - Affected OpenCode driver, collector and transport tests: 72 passed. The tests cover authentication, content removal, size/count bounds, disabled behavior and the rebuilt native Runner boundary. One Rust projection test and 18 server trace tests also passed. A held run-log sink proves that a full 128-span diagnostic batch adds no duplicate database writes before terminal consumption. - The two CI-failing delegated Slack rate-limit cases passed against real PostgreSQL with only the Date clock frozen. - Runner TypeScript and server TypeScript checks passed. Rust formatting and module-boundary checks passed. - Real Honeycomb readback confirmed the 14-span skill waterfall and a 40-span provider waterfall. Provider phases have the correct execution parent. The provider export uses synthetic model replies and is instrumentation proof only. - Earlier full local checks failed on missing package-local executables, then on the default Node heap and a missing generated service worker. The dependency links were repaired. The server check passed with a larger heap. The full local test attempt could not start embedded PostgreSQL on this host and was stopped after retaining its failures; real database coverage uses an isolated database on an existing local server. These attempts do not count as a full local pass. - CI on the prior revision passed typecheck, build, Runner and all E2E shards. It failed the benchmark lifecycle boundary and one existing rate-window test. Those fixes passed CI. A later Runner assertion exposed the Copilot source identity pin on the shared transport file. The diagnostic flag now uses the existing configured-environment projection, preserving that file byte-for-byte. All 66 selected installation and native transport tests passed. New-head CI and review remain required. - The under-15-second hosted response target remains unmet. This PR adds diagnostics and does not claim a hosted latency fix. ## Risks - Skill spans and Honeycomb export retain the operator endpoint gate. OpenCode phase collection requires a separate explicit diagnostic flag. Without an endpoint, its closed measurements stay in the instance run log. - Raw OpenCode OTLP can contain prompts and authorization attributes. The new sink rejects unauthenticated requests and discards all attributes before any measurement reaches PRP or the operator collector. Request, event and per-phase limits bound memory and journal growth. - Collection does not wait for a provider flush. Late or oversized exports can be absent; these measurements are not a complete profiling guarantee. - The benchmark's inventory contents and transport delay are explicit fixtures. They do not reproduce server contention or prove hosted response time. - The one durable diagnostic batch remains the local evidence. Its child span export does not add per-phase run-log rows. - No database migration, authorization policy, model selection or inference transport changes. The Rust Runner and OpenCode proxy must be shipped together for the new opt-in diagnostic. ## Model Used OpenAI GPT-6 through Codex, with repository inspection, shell execution, browser tools, and Honeycomb queries. The session does not expose a verifiable backend deployment ID or context-window size. ## 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 --------- Co-authored-by: Paperclip <noreply@paperclip.ing> Co-authored-by: Paperclip <paperclip@paperclip.ing>
201 lines
11 KiB
TypeScript
201 lines
11 KiB
TypeScript
import { AsyncLocalStorage } from "node:async_hooks";
|
|
import { randomUUID } from "node:crypto";
|
|
import { constants, promises as fs } from "node:fs";
|
|
import path from "node:path";
|
|
import { and, eq, sql } from "drizzle-orm";
|
|
import { companySkillVersions, companySkillRepositorySnapshots, heartbeatRuns,
|
|
nativeRunFinalizations, environmentLeases, withDedicatedDbConnection, type Db } from "@paperclipai/db";
|
|
import { resolvePaperclipInstanceRoot } from "../home-paths.js";
|
|
import { assertSkillSnapshotPath } from "./skill-snapshot.js";
|
|
import { repositorySkillFrontmatter } from "./skill-repository-package.js";
|
|
import type { CompanySkillVersionFileInventoryEntry } from "@paperclipai/shared";
|
|
import { parseNativeExecutionInput } from "../vendor/paperclip-runner/index.js";
|
|
import { beginRunPhase } from "./execution-preparation-timing.js";
|
|
|
|
export const SKILL_VERSION_CACHE_IDLE_MS = 60 * 60 * 1000;
|
|
const locks = new AsyncLocalStorage<Array<{ db: Db; companyId: string }>>();
|
|
const uuid = /^[a-f0-9]{8}-[a-f0-9]{4}-[a-f0-9]{4}-[a-f0-9]{4}-[a-f0-9]{12}$/i;
|
|
export class SkillCacheBusy extends Error {}
|
|
// Repository snapshots are immutable and referenced with restrictive foreign
|
|
// keys. Cache only validated entrypoint names, never large file contents, so an
|
|
// hourly sweep does not transfer the same repository for each skill/version.
|
|
const verifiedSnapshots = new WeakMap<Db, Map<string, ReadonlySet<string>>>();
|
|
|
|
/** Hold through publication AND durable run pinning, not just file creation. */
|
|
export async function withSkillVersionCacheLock<T>(db: Db, companyId: string, action: () => Promise<T>, tryOnly = false): Promise<T> {
|
|
const held = locks.getStore() ?? [];
|
|
if (held.some(lock => lock.db === db && lock.companyId === companyId)) return action();
|
|
// Preparation uses the ordinary pool for version/pin writes. Borrowing a pool
|
|
// connection for this lock would deadlock installations with a one-slot pool.
|
|
const acquired = beginRunPhase("skills.cache.acquire");
|
|
return withDedicatedDbConnection(db, connection => connection.transaction(async tx => {
|
|
const key = `skill_version_cache:${companyId}`;
|
|
if (tryOnly) {
|
|
const rows = await tx.execute<{ acquired: boolean }>(sql`select pg_try_advisory_xact_lock(hashtextextended(${key}, 0)) as acquired`);
|
|
if (!rows[0]?.acquired) throw new SkillCacheBusy();
|
|
} else await tx.execute(sql`select pg_advisory_xact_lock(hashtextextended(${key}, 0))`);
|
|
acquired();
|
|
return locks.run([...held, { db, companyId }], action);
|
|
})).catch(error => {
|
|
acquired(true);
|
|
throw error;
|
|
});
|
|
}
|
|
|
|
export function skillVersionCachePaths(companyId: string, skillId: string, versionId: string) {
|
|
if (![companyId, skillId, versionId].every(value => uuid.test(value))) throw new Error("Invalid skill cache identity");
|
|
const root = path.join(resolvePaperclipInstanceRoot(), "skills", companyId);
|
|
return {
|
|
root,
|
|
directory: path.join(root, "__versions__", skillId, versionId),
|
|
access: path.join(root, "__version_access__", skillId, `${versionId}.json`),
|
|
};
|
|
}
|
|
|
|
/** Never traverse a symlink below the configured instance root. */
|
|
export async function ensureSkillCacheDirectory(directory: string, create = false) {
|
|
const root = path.resolve(resolvePaperclipInstanceRoot());
|
|
const relative = path.relative(root, directory);
|
|
if (!relative || relative.startsWith("..") || path.isAbsolute(relative)) throw new Error("Skill cache escaped instance root");
|
|
if (create) await fs.mkdir(root, { recursive: true });
|
|
let cursor = root;
|
|
for (const part of relative.split(path.sep)) {
|
|
cursor = path.join(cursor, part);
|
|
if (create) await fs.mkdir(cursor).catch((error: NodeJS.ErrnoException) => {
|
|
if (error.code !== "EEXIST") throw error;
|
|
});
|
|
const stat = await fs.lstat(cursor);
|
|
if (!stat.isDirectory() || stat.isSymbolicLink()) throw new Error("Unsafe skill cache directory");
|
|
}
|
|
}
|
|
|
|
export async function touchSkillVersionCache(companyId: string, skillId: string, versionId: string, now = Date.now()) {
|
|
const { access } = skillVersionCachePaths(companyId, skillId, versionId);
|
|
await ensureSkillCacheDirectory(path.dirname(access), true);
|
|
const temporary = `${access}.${randomUUID()}.tmp`;
|
|
try {
|
|
await fs.writeFile(temporary, JSON.stringify({ version: 1, lastUsedAt: now }), { flag: "wx", mode: 0o600 });
|
|
await fs.rename(temporary, access);
|
|
} finally { await fs.rm(temporary, { force: true }); }
|
|
}
|
|
|
|
export async function lastUsedAt(filename: string): Promise<number | null> {
|
|
try {
|
|
await ensureSkillCacheDirectory(path.dirname(filename));
|
|
const file = await fs.open(filename, constants.O_RDONLY | constants.O_NOFOLLOW);
|
|
try {
|
|
const stat = await file.stat();
|
|
if (!stat.isFile() || stat.size > 256) return null;
|
|
const value = JSON.parse(await file.readFile("utf8"));
|
|
return value.version === 1 && Number.isSafeInteger(value.lastUsedAt) && value.lastUsedAt > 0 ? value.lastUsedAt : null;
|
|
} finally { await file.close(); }
|
|
} catch (error) {
|
|
if (error instanceof SyntaxError || ["ENOENT", "ELOOP"].includes((error as NodeJS.ErrnoException).code ?? "")) return null;
|
|
throw error;
|
|
}
|
|
}
|
|
|
|
// A terminal run can still own provider execution or recovery. Only fully settled
|
|
// runs release their pins; resume preparation reacquires the same cache lock.
|
|
export async function protectedVersions(db: Db, companyId: string): Promise<Set<string> | null> {
|
|
const rows = await db.select({
|
|
id: heartbeatRuns.id, agentId: heartbeatRuns.agentId, nativeIssueId: heartbeatRuns.nativeIssueId,
|
|
pins: sql<unknown>`${heartbeatRuns.contextSnapshot}->'skillVersions'`,
|
|
// Avoid loading large execution inputs for runs with the modern pin map.
|
|
legacyInput: sql<unknown>`case when ${heartbeatRuns.runtimeMode} = 'native'
|
|
and not coalesce(${heartbeatRuns.contextSnapshot} ? 'skillVersions', false)
|
|
then ${heartbeatRuns.runnerProfileJson}->'nativeExecutionInput' end`,
|
|
})
|
|
.from(heartbeatRuns).where(and(eq(heartbeatRuns.companyId, companyId), sql`(
|
|
${heartbeatRuns.status} not in ('succeeded', 'failed', 'timed_out', 'cancelled', 'interrupted')
|
|
or ${heartbeatRuns.finishedAt} is null
|
|
or ${heartbeatRuns.controllerLeaseExpiresAt} > now()
|
|
or exists (select 1 from ${nativeRunFinalizations} f
|
|
where f.company_id = ${heartbeatRuns.companyId} and f.run_id = ${heartbeatRuns.id}
|
|
and (f.phase <> 'committed' or f.lease_owner is not null or f.recovery_state is not null))
|
|
or exists (select 1 from ${environmentLeases} l
|
|
where l.company_id = ${heartbeatRuns.companyId} and l.heartbeat_run_id = ${heartbeatRuns.id}
|
|
and (l.status = 'pending_cleanup' or l.cleanup_status = 'failed'
|
|
or l.metadata ? 'nativeWorkspaceExportResume'
|
|
or (l.released_at is null and not coalesce(l.status = 'retained'
|
|
and l.lease_policy = 'reuse_by_environment' and l.cleanup_status = 'success', false))))
|
|
)`));
|
|
const versions = new Set<string>();
|
|
for (const { pins, legacyInput, id, agentId, nativeIssueId } of rows) {
|
|
if (legacyInput != null) {
|
|
// Older native runs captured the complete selection in their immutable
|
|
// execution input before contextSnapshot.skillVersions was introduced.
|
|
// Use the recovery parser (including digest validation) and the exact run
|
|
// binding. Never repair a malformed modern pin map with a different source.
|
|
try {
|
|
const input = parseNativeExecutionInput(legacyInput);
|
|
if (!("runtimeContext" in input) || input.binding.companyId !== companyId
|
|
|| input.binding.runId !== id || input.binding.agentId !== agentId
|
|
|| input.binding.issueId !== nativeIssueId) return null;
|
|
for (const skill of input.runtimeContext.skills) {
|
|
// Unversioned skills have their own captured asset bundle; they do
|
|
// not reference a directory under __versions__.
|
|
if (skill.versionId === null) continue;
|
|
if (!uuid.test(skill.versionId)) return null;
|
|
versions.add(skill.versionId);
|
|
}
|
|
continue;
|
|
} catch { return null; }
|
|
}
|
|
// Legacy/incomplete preparation is not proof that no skill is in use.
|
|
if (!pins || typeof pins !== "object" || Array.isArray(pins)) return null;
|
|
for (const version of Object.values(pins)) {
|
|
if (typeof version !== "string" || !uuid.test(version)) return null;
|
|
versions.add(version);
|
|
}
|
|
}
|
|
return versions;
|
|
}
|
|
|
|
function validateInventory(inventory: CompanySkillVersionFileInventoryEntry[]) {
|
|
const seen = new Set<string>();
|
|
for (const file of inventory) {
|
|
assertSkillSnapshotPath(file.path);
|
|
if (seen.has(file.path) || typeof file.content !== "string") return false;
|
|
seen.add(file.path);
|
|
}
|
|
return true;
|
|
}
|
|
|
|
export async function hasRestorableSnapshot(db: Db, companyId: string, versionId: string) {
|
|
const [version] = await db.select().from(companySkillVersions).where(and(
|
|
eq(companySkillVersions.companyId, companyId), eq(companySkillVersions.id, versionId)));
|
|
if (!version) return false;
|
|
if (version.repositorySnapshotId) {
|
|
if (!version.repositorySkillPath) return false;
|
|
let cache = verifiedSnapshots.get(db);
|
|
if (!cache) { cache = new Map(); verifiedSnapshots.set(db, cache); }
|
|
const key = `${companyId}:${version.repositorySnapshotId}`;
|
|
const verified = cache.get(key);
|
|
if (verified) return verified.has(version.repositorySkillPath);
|
|
const [snapshot] = await db.select({ inventory: companySkillRepositorySnapshots.fileInventory })
|
|
.from(companySkillRepositorySnapshots).where(and(eq(companySkillRepositorySnapshots.companyId, companyId),
|
|
eq(companySkillRepositorySnapshots.id, version.repositorySnapshotId)));
|
|
if (!snapshot || !validateInventory(snapshot.inventory)) return false;
|
|
const entrypoints = new Set(snapshot.inventory.filter(file => file.encoding !== "base64"
|
|
&& repositorySkillFrontmatter(file.content)).map(file => file.path));
|
|
if (cache.size >= 128) cache.delete(cache.keys().next().value!);
|
|
cache.set(key, entrypoints);
|
|
return entrypoints.has(version.repositorySkillPath);
|
|
}
|
|
return validateInventory(version.fileInventory) && version.fileInventory.some(file => file.path === "SKILL.md");
|
|
}
|
|
|
|
// Counts allocated bytes without following links, matching what df can reclaim.
|
|
export async function allocatedBytes(directory: string, shouldContinue: () => boolean = () => true): Promise<number> {
|
|
if (!shouldContinue()) throw new Error("Skill cache scan stopped");
|
|
const stat = await fs.lstat(directory);
|
|
if (stat.isSymbolicLink() || (!stat.isDirectory() && !stat.isFile())) throw new Error("Unsafe skill cache entry");
|
|
let bytes = stat.blocks * 512;
|
|
if (stat.isDirectory()) {
|
|
for (const entry of await fs.readdir(directory)) bytes += await allocatedBytes(path.join(directory, entry), shouldContinue);
|
|
}
|
|
return bytes;
|
|
}
|
|
|