mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-11-03 17:51:58 +01:00
## Thinking Path > - Paperclip manages agent work through shared server and database services. > - High query volume can spend main-thread time on SQL construction and result decoding. > - The existing bounded response capture counts rows and bytes, but it cannot name the operation that executed a query. > - Bundled callers can be missing, and measuring every parsed JSON value adds work to the diagnostic. > - This pull request carries a semantic execution owner into each measured query and bounds response sizing. > - Operators can rank query volume by owner before choosing a performance fix. ## Linked Issues or Issue Description Refs #17504, #17522, #17537, #17564. **What existing behavior does this improve?** The opt-in `PAPERCLIP_DB_RESPONSE_CAPTURE_WINDOW` diagnostic. **Subsystem affected** Database diagnostics and existing server execution boundaries. **Current behavior** The capture groups by table, operation, and builder caller. It cannot distinguish execution owners that reuse a prepared query. Bundled deployments need source maps for caller locations. The capture visits every returned value and serializes parsed JSON again to estimate its size. **Proposed behavior** Version 2 captures use fixed semantic owners for HTTP requests, delivery queues, execution phases, and budget work. They count completed calls, returned rows, errors, and completion wall time. They sample successful results 1, 17, 33, and so on, with fixed cell and string/byte limits. Complex values remain explicitly unmeasured. Semantic ownership works without source maps. **Reason and benefit** A short census can identify which operations issue the most queries or return the most rows. It preserves each query's execution owner through pooled connections, concurrent operations, and prepared-query reuse. It reduces diagnostic work without claiming per-query CPU attribution. **Breaking changes** Opt-in capture output moves from `entry.v1`/`summary.v1` to `entry.v2`/`summary.v2`. Sampled primitive byte lower bounds replace all-result byte estimates. Consumers must use the new fields and must not extrapolate them into a total. There is no database migration or application API change. ## What Changed - Added `withDatabaseOperation(owner, action)` to the DB package. The server owns semantic labels. Queries retain execution ownership in their completion closure. - Added fixed owners at existing HTTP, delivery, budget, and execution timing boundaries. Delivery work replaces the context of the producer that woke it. - Added complete call/row/error counters and completion wall durations within the existing bounded window. Durations include waits and are not CPU measurements. - Sampled and bounded primitive-value sizing. Complex and oversized values remain unmeasured. Known owners skip repeated stack extraction. - Preserved the deadline, group limit, paced output, query outcomes, and existing coverage exclusions. Updated the operator documentation. - Added real PostgreSQL owner-isolation and prepared-query tests, server scope tests, and plain bundled-runtime proof. - Moved projection-test and benchmark full-response sizing into an explicit test helper. Existing payload-size thresholds remain unchanged; these synthetic checks do not use the production sampler. ## Verification - Final-commit DB capture suites: 43 tests passed in 13.86 seconds against the actual PostgreSQL driver, including concurrent owners, prepared reuse, transaction failure, a dedicated client, sampling, and a query crossing the deadline. DB typecheck passed. - Server attribution and existing delivery/execution/budget suites: 53 tests passed. Final concurrent HTTP GET/JSON POST scope refinement: 5 tests passed. - Runtime bundle suite: 8 existing tests passed. The new no-source-map owner test passed after its fixture was corrected to use a driver thenable. An ordinary native Promise can bypass an overridden `.then`; the real PostgreSQL tests separately cover driver integration. - Observer-only experiment: three alternating pairs per case on Node 24.22.2, macOS arm64, 3,000 calls per run after warm-up. For an already-materialized synthetic JSON result, median capture CPU fell from 82.37 to 1.87 microseconds/call. For a 100-row primitive result, it fell from 8.10 to 4.40 microseconds/call. Every result retained identity and all calls were counted. The new diagnostic intentionally measures less byte data; these are observer costs, not database latency or a hosted application speedup. Disabled-case timings were below one microsecond/call and too small for a performance conclusion. - Final lifecycle regression: 28 unit tests and DB typecheck passed. Closing the last capture disables and replaces owner storage; overlapping captures retain it. - Final-commit full recursive typecheck passed in 38.38 seconds and full build passed in 40.81 seconds. The build stamp matches `83ed4ba9cebd68d48929c46f15ab32d5c0b9687b`. Focused server attribution tests also passed 5/5 before the test-helper-only migration. Full test acceptance will use the repository's parallel CI gates; the unsharded local command takes hours. - Verification failures retained: initial sandbox runs could not open local IPC/PostgreSQL listeners; permitted reruns exercised the real services. One old test expected JSON serialization and was updated to assert explicit unmeasured complex values. The first bundle fixture used the wrong promise boundary, as described above. A retained-callback regression also demonstrated that disabling and reusing the same AsyncLocalStorage instance could resurrect an old owner; replacing the instance after the last capture closes fixes that case. - The first CI run found older projection tests consuming the previous full-response fields. Those consumers now use the full-response test helper, preserving their byte thresholds. The two complete affected route suites plus helper tests passed 115/115 in 73.08 seconds. A temporary full-row query negative control then failed the unchanged 2,048-byte limit at 5,000,812 bytes and was restored; five other service suites passed 34/34 and the affected chat cases passed 3/3. All three previously failing CI shards passed on the corrected head. A local skill-list benchmark smoke check completed 255 captured queries with no in-flight queries or overflow; this was integration verification under concurrent test load, not a timing benchmark. - Two final-head runner jobs lost communication with GitHub before reporting a test result. One targeted retry of those jobs and their dependent aggregate passed. All 53 final-head checks passed, with 3 intentional skips; previously passing suites were preserved. - Hosted capture remains pending until the reviewed revision is deployed and a bounded window is explicitly configured. Reproduce the focused checks with Node 24 and the repository pnpm version: ```sh pnpm exec vitest run packages/db/src/response-capture.test.ts packages/db/src/response-capture-postgres.test.ts pnpm --dir server exec vitest run --config vitest.config.ts src/__tests__/database-operation-attribution.test.ts scripts/bundle-runtime.test.mjs pnpm -r typecheck pnpm build ``` ## Risks - Owner context is active while a valid future capture window is armed, up to 30 minutes before accounting starts. No-window and expired calls take the direct path. Diagnostics still add bounded work while enabled. - A nearest nested owner is reported. Broad `http.request` and unattributed groups remain visible; this does not identify every service callsite or SQL shape. - The existing census excludes tagged/raw explicit-execute/streaming paths and internal protocol commands. Its counts are not PostgreSQL transaction totals. - Completion wall time includes queue/database/network/scheduling waits. Concurrent durations overlap. Sampled bytes exclude complex values, large strings, and values beyond the sizing limits. - Activation is startup-only. Operators must choose the window after artifact preparation, allow rollout/warm-up time, and remove the expired setting afterward. ## Model Used OpenAI Codex, GPT-6 family, with code execution, repository inspection, and parallel agents. The exact deployment model ID and context-window size are not exposed in this session. ## 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 - [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 <noreply@paperclip.ing>
166 lines
10 KiB
TypeScript
166 lines
10 KiB
TypeScript
import { createHmac } from "node:crypto";
|
|
import { eq } from "drizzle-orm";
|
|
import { afterAll, afterEach, beforeAll, describe, expect, it, vi } from "vitest";
|
|
import { applyPendingMigrations, chatActions, createDb } from "@paperclipai/db";
|
|
import { createFullDatabaseResponseCapture, installDatabaseResponseCapture } from "../../../__tests__/helpers/full-database-response-capture.js";
|
|
import { getEmbeddedPostgresTestSupport, startEmbeddedPostgresTestDatabase } from "../../../__tests__/helpers/embedded-postgres.js";
|
|
import { resolveExternalTestDatabaseUrl } from "../../../__tests__/helpers/external-test-database.js";
|
|
import { cleanupIngressFixture, githubIngressFixture as createFixture } from "../../../__tests__/helpers/github-webhook-ingress.js";
|
|
import { createGitHubWebhookIngress } from "./webhook-ingress.js";
|
|
import { PROVIDER_EFFECT_STALE_MS } from "../../chat-action-work.js";
|
|
|
|
const externalUrl = resolveExternalTestDatabaseUrl("PAPERCLIP_TEST_DATABASE_URL");
|
|
const support = externalUrl ? { supported: true } : await getEmbeddedPostgresTestSupport();
|
|
describe.skipIf(!support.supported)("GitHub webhook ingress claim PostgreSQL behavior", () => {
|
|
let db: ReturnType<typeof createDb>;
|
|
const fixtureCompanyIds = new Set<string>();
|
|
async function githubIngressFixture(database: typeof db, factory = createGitHubWebhookIngress, bodyBytes?: number) {
|
|
const fixture = await createFixture(database, factory, bodyBytes);
|
|
fixtureCompanyIds.add(fixture.companyId);
|
|
return fixture;
|
|
}
|
|
let temporary: Awaited<ReturnType<typeof startEmbeddedPostgresTestDatabase>> | undefined;
|
|
beforeAll(async () => {
|
|
if (!externalUrl) temporary = await startEmbeddedPostgresTestDatabase("github-ingress-claim-");
|
|
else await applyPendingMigrations(externalUrl);
|
|
db = createDb(externalUrl ?? temporary!.connectionString);
|
|
}, 90_000);
|
|
afterEach(async () => {
|
|
vi.restoreAllMocks();
|
|
for (const companyId of fixtureCompanyIds) await cleanupIngressFixture(db, companyId);
|
|
fixtureCompanyIds.clear();
|
|
});
|
|
afterAll(async () => { await db?.$client.end({ timeout: 0 }); await temporary?.cleanup(); });
|
|
|
|
it("returns the full replay body only to a successful claimant", async () => {
|
|
const f = await githubIngressFixture(db, createGitHubWebhookIngress, 768 * 1024);
|
|
const action = await f.insertAction();
|
|
const events: Array<Record<string, unknown>> = [], now = Date.now();
|
|
const capture = createFullDatabaseResponseCapture({ start: now - 1, end: now + 59_000 }, event => events.push(event));
|
|
installDatabaseResponseCapture(db, { chatActions }, capture);
|
|
try { expect((await f.service.processGitHubWebhookIngress(action.id))?.status).toBe(202); }
|
|
finally { capture.flush(); }
|
|
const reads = events.filter(event => event.operation === "select" && event.table === "chat_actions");
|
|
expect(reads.reduce((sum, event) => sum + Number(event.responseValueBytes), 0)).toBeLessThan(1024);
|
|
expect(f.calls).toEqual([{ publicId: f.endpoint.publicId, provider: "github", body: f.payload.body, delivery: f.payload.deliveryId,
|
|
signature: `sha256=${createHmac("sha256", "fixture-secret").update(f.payload.body).digest("hex")}` }]);
|
|
expect(await f.readAction(action.id)).toMatchObject({ status: "processed", payload: { redacted: true, bodySha256: f.payload.bodySha256 }, result: { attempts: 1, httpStatus: 202, retryable: false } });
|
|
});
|
|
|
|
it.each([
|
|
{ status: "processed", result: null, accepted: true },
|
|
{ status: "cancelled", result: null, accepted: true },
|
|
{ status: "failed", result: { retryable: false }, accepted: true },
|
|
{ status: "failed", result: { retryable: true, retryAt: new Date(Date.now() + 60_000).toISOString() }, accepted: false },
|
|
{ status: "processing", result: { attempts: 1 }, accepted: false },
|
|
{ status: "delivery_unknown", result: null, accepted: false },
|
|
])("does not fetch a body or mutate an ineligible $status row ($result)", async ({ status, result, accepted }) => {
|
|
const f = await githubIngressFixture(db);
|
|
// A corrupt body must not let a nonclaimant overwrite a live or delayed claim.
|
|
const action = await f.insertAction({ status, result, payload: { ...f.payload, bodySha256: "0".repeat(64) } });
|
|
const events: Array<Record<string, unknown>> = [], now = Date.now();
|
|
const capture = createFullDatabaseResponseCapture({ start: now - 1, end: now + 59_000 }, event => events.push(event));
|
|
installDatabaseResponseCapture(db, { chatActions }, capture);
|
|
let response: Response | null;
|
|
try { response = await f.service.processGitHubWebhookIngress(action.id); }
|
|
finally { capture.flush(); }
|
|
expect(response?.status ?? null).toBe(accepted ? 202 : null);
|
|
expect(await f.readAction(action.id)).toEqual(action);
|
|
expect(f.calls).toEqual([]);
|
|
expect(events.find(event => event.event === "paperclip.test_db_response_capture.summary.v1")?.responseValueBytes).toBeLessThan(1024);
|
|
});
|
|
|
|
it.each(["received", "failed", "processing"])("settles eligible malformed %s payloads without replay", async status => {
|
|
const f = await githubIngressFixture(db);
|
|
const action = await f.insertAction({ status, payload: { ...f.payload, bodySha256: "0".repeat(64) },
|
|
result: { attempts: 2, retryable: true, retryAt: new Date(0).toISOString() }, updatedAt: new Date(0) });
|
|
expect((await f.service.processGitHubWebhookIngress(action.id))?.status).toBe(202);
|
|
expect(await f.readAction(action.id)).toMatchObject({ status: "failed", payload: {}, result: { code: "github_webhook_ingress_payload_invalid", retryable: false } });
|
|
expect(f.calls).toEqual([]);
|
|
});
|
|
|
|
it.each(["failed", "processing"])("recovers a due %s attempt after a worker restart", async status => {
|
|
const f = await githubIngressFixture(db);
|
|
const action = await f.insertAction({ status, result: { attempts: 2, retryable: true, retryAt: new Date(0).toISOString() }, updatedAt: new Date(Date.now() - PROVIDER_EFFECT_STALE_MS - 1000) });
|
|
const restarted = createGitHubWebhookIngress(db, f.options);
|
|
expect((await restarted.processGitHubWebhookIngress(action.id))?.status).toBe(202);
|
|
expect(f.calls).toHaveLength(1);
|
|
expect(await f.readAction(action.id)).toMatchObject({ status: "processed", result: { attempts: 3, httpStatus: 202 } });
|
|
});
|
|
|
|
it.each(["received", "failed", "processing"])("lets only one concurrent worker claim and replay a %s delivery", async status => {
|
|
const f = await githubIngressFixture(db);
|
|
const previousAttempts = status === "received" ? 0 : 2;
|
|
const action = await f.insertAction({ status,
|
|
result: { attempts: previousAttempts, retryable: true, retryAt: new Date(0).toISOString() },
|
|
updatedAt: new Date(0),
|
|
});
|
|
// All workers must observe the same eligible attempt before any can claim it.
|
|
let arrived = 0;
|
|
let release!: () => void;
|
|
const ready = new Promise<void>(resolve => { release = resolve; });
|
|
const transaction = db.transaction.bind(db);
|
|
vi.spyOn(db, "transaction").mockImplementation(async (callback, config) => {
|
|
if (++arrived === 12) release();
|
|
await ready;
|
|
return transaction(callback, config);
|
|
});
|
|
const responses = await Promise.all(Array.from({ length: 12 }, () => f.service.processGitHubWebhookIngress(action.id)));
|
|
expect(responses.some(response => response?.status === 202)).toBe(true);
|
|
expect(f.calls).toHaveLength(1);
|
|
expect(await f.readAction(action.id)).toMatchObject({ status: "processed", result: { attempts: previousAttempts + 1 } });
|
|
});
|
|
|
|
it("does not read the body when another worker wins between eligibility and claim", async () => {
|
|
const f = await githubIngressFixture(db);
|
|
const action = await f.insertAction();
|
|
const transaction = db.transaction.bind(db);
|
|
vi.spyOn(db, "transaction").mockImplementationOnce(async (callback, config) => {
|
|
await db.update(chatActions).set({ status: "processing", result: { attempts: 1 } }).where(eq(chatActions.id, action.id));
|
|
return transaction(callback, config);
|
|
});
|
|
expect(await f.service.processGitHubWebhookIngress(action.id)).toBeNull();
|
|
expect(f.calls).toEqual([]);
|
|
expect(await f.readAction(action.id)).toMatchObject({ status: "processing", payload: f.payload, result: { attempts: 1 } });
|
|
});
|
|
|
|
it("does not clear a malformed body after its claim is superseded", async () => {
|
|
const f = await githubIngressFixture(db);
|
|
const action = await f.insertAction({ payload: { ...f.payload, bodySha256: "0".repeat(64) } });
|
|
const transaction = db.transaction.bind(db);
|
|
vi.spyOn(db, "transaction")
|
|
.mockImplementationOnce(transaction)
|
|
.mockImplementationOnce(async (callback, config) => {
|
|
await db.update(chatActions).set({ result: { attempts: 2 } }).where(eq(chatActions.id, action.id));
|
|
return transaction(callback, config);
|
|
});
|
|
expect((await f.service.processGitHubWebhookIngress(action.id))?.status).toBe(202);
|
|
expect(await f.readAction(action.id)).toMatchObject({ status: "processing", payload: action.payload, result: { attempts: 2 } });
|
|
expect(f.calls).toEqual([]);
|
|
});
|
|
|
|
it("validates the current claimed body instead of a body replaced before the claim", async () => {
|
|
const f = await githubIngressFixture(db);
|
|
const action = await f.insertAction();
|
|
const transaction = db.transaction.bind(db);
|
|
vi.spyOn(db, "transaction").mockImplementationOnce(async (callback, config) => {
|
|
await db.update(chatActions).set({ payload: { ...f.payload, body: "corrupt replacement" } }).where(eq(chatActions.id, action.id));
|
|
return transaction(callback, config);
|
|
});
|
|
expect((await f.service.processGitHubWebhookIngress(action.id))?.status).toBe(202);
|
|
expect(f.calls).toEqual([]);
|
|
expect(await f.readAction(action.id)).toMatchObject({ status: "failed", payload: {}, result: { code: "github_webhook_ingress_payload_invalid", retryable: false } });
|
|
});
|
|
|
|
it("keeps the replay body and retry deadline after a retryable provider failure", async () => {
|
|
const f = await githubIngressFixture(db);
|
|
const action = await f.insertAction();
|
|
f.options.handleWebhook = async () => new Response("temporary", { status: 503 });
|
|
const service = createGitHubWebhookIngress(db, f.options);
|
|
expect((await service.processGitHubWebhookIngress(action.id))?.status).toBe(202);
|
|
const failed = await f.readAction(action.id);
|
|
expect(failed).toMatchObject({ status: "failed", payload: f.payload, result: { attempts: 1, httpStatus: 503, retryable: true, retryAt: expect.any(String) } });
|
|
expect(Date.parse(String(failed.result?.retryAt))).toBeGreaterThan(Date.now());
|
|
});
|
|
});
|