diff --git a/doc/DATABASE.md b/doc/DATABASE.md index 04698b00f19..9fcab3a9737 100644 --- a/doc/DATABASE.md +++ b/doc/DATABASE.md @@ -565,11 +565,26 @@ finish writing the bounded output. Wait for the summary before collecting it. It never logs SQL, parameters, result values, connection strings, or query errors. In-flight queries continue normally. -Semantic owners work in a bundled server without source maps. For queries -without an explicit owner, keep the linked source maps and enable Node's -`--enable-source-maps` option to resolve public caller locations. Restore prior -Node options after capture. Known semantic owners avoid repeated stack capture. -Queries without an available owner/caller still contribute to the totals. +Semantic owners work in a bundled server without source maps. Specific owners +avoid stack capture. The generic `http.request` owner keeps its exact name but, +like an unowned query, also captures a bounded caller location during the window. +For wrapped query builders, a map-free hosted bundle retains one static generated +construction-site anchor (`dist-runtime/server.mjs`, `index.mjs`, or +`chunk-.mjs`, with line and column). Correlate it with the exact serving +revision and bundle; it is not a TypeScript location or an execution-time CPU +owner. Capture wrapper frames are excluded before reading the stack, and deeper +frames in the same bundle are omitted. + +Unscoped driver calls, including relational queries, do not accept generated +anchors: a bundled ORM helper could otherwise be mistaken for an application +caller. They can still retain existing public source/dist locations; linked +source maps and Node's `--enable-source-maps` may help resolve those locations. +Restore prior Node options after capture. Missing callers remain unknown and +still contribute to totals. Disabled, future and expired windows do not capture +stacks; wrappers installed for an armed window remain after expiry. Active census +stack capture, grouping and bounded sizing add measurement overhead. More caller +groups still share the existing group, page and output-rate caps. This diagnostic +is not a production performance improvement. Look for `paperclip.db_response_capture.entry.v2` and `paperclip.db_response_capture.summary.v2` in the process logs. Version 2 uses diff --git a/doc/performance/2026-11-03-db-capture-hosted-callers.md b/doc/performance/2026-11-03-db-capture-hosted-callers.md new file mode 100644 index 00000000000..3d0bd748b56 --- /dev/null +++ b/doc/performance/2026-11-03-db-capture-hosted-callers.md @@ -0,0 +1,81 @@ +# Hosted database capture construction sites + +The bounded database response census could not distinguish map-free hosted +query builders. The `http.request` semantic owner suppressed stack capture; +unowned generated runtime paths failed the public caller allowlist. The control +bundles the actual capture module and real Drizzle into one file, rather than +assigning an application filename to an isolated mock function. + +The change preserves exact semantic owners. Generic HTTP and unowned builders +retain one safe generated construction-site anchor. A local V8 stack boundary +removes capture wrappers before reading the stack. Deeper shared-chunk frames +are omitted. Specific semantic owners stay stack-free. The public stack parser rejects generated +anchors by default; only the trusted builder wrapper explicitly enables them. Unscoped driver and +relational paths deliberately remain unknown in map-free bundles: their first +frame can belong to the ORM. Prepared builders retain construction provenance, +not the later consumer location. Resolve each anchor against the exact serving +revision and generated bundle. No TypeScript or CPU ownership is inferred. + +The fixture checks exact generated application lines for select, prepare and +execute, including repeated parameters, transactions and nested savepoints. +It checks unknown raw/relational calls and zero stack captures for disabled, +future, expired and specific-owner cases. Existing real PostgreSQL tests retain +query/error identity, prepared execution, transaction propagation, primitive +sizing and expiry behavior. Existing cap tests retain 2,048 groups, 128-entry +pages and 64 output events per second. More callers can reach these caps sooner. + +## Local diagnostic overhead + +Baseline: `09162fe893b464dd2ccdafd14bd3ef1611202a86`. +Five alternating rounds per mode, 1,000 serial queries per sample, after 500 +warmup queries for each variant/mode. There are 40 measured samples. Both variants +use the same real bundled ORM and fake postgres-js thenable. Capture creation, +output flushing, printing and validation occur outside timing. Samples include +ORM compilation, census metadata, stack formatting and async bookkeeping. Empty +results exclude meaningful result-sizing work. Node v24.22.2 ran on a shared +18-logical-CPU host; load averages were 7.13/6.66/6.12. No other owned benchmark +ran, but the host was not idle. CPU is process CPU, including JIT/GC. + +Microseconds per query, median [minimum–maximum]: + +| Mode | Variant | Process CPU | Wall | +| --- | --- | --- | --- | +| disabled | current | 11.767 [7.687–25.037] | 8.543 [7.637–8.917] | +| disabled | candidate | 9.934 [8.294–31.978] | 8.260 [7.897–8.665] | +| unowned | current | 21.675 [14.754–32.634] | 15.841 [14.633–16.434] | +| unowned | candidate | 21.865 [14.563–33.807] | 15.642 [14.370–16.377] | +| http.request | current | 15.461 [9.734–17.897] | 10.528 [9.531–10.910] | +| http.request | candidate | 17.662 [15.080–20.058] | 15.169 [14.589–15.986] | +| response.presentation | current | 10.704 [9.656–11.078] | 9.870 [9.544–10.500] | +| response.presentation | candidate | 12.323 [9.884–16.804] | 10.758 [9.683–10.810] | +For both unowned and generic HTTP queries, the control yields no caller for +1,000 queries. The candidate yields two distinct exact application anchors, +covering all 1,000 queries. Both variants keep the same specific semantic owner +without caller locations. Disabled mode has no capture groups. + +This is an attribution improvement with active measurement cost, not a product +speedup. Ranges overlap and are noisy. The HTTP median wall delta is about 4.6 +microseconds per query in this fixture. Do not treat this as exact hosted overhead: +there is no database/network latency, Sentry/OTel stack formatting or deployed +traffic mix. Wrappers remain installed after expiry; they do not capture stacks. +Samples precede a review correction that made the standalone public parser reject +generated anchors by default. The measured private builder path still opts in +explicitly and has the same behavior. No timing is attributed to that default-only +contract correction. All original samples and the expanded proof are in +[the evidence file](fixtures/db-capture-hosted-callers-overhead.json). Only the +machine-specific executable path is redacted in that public copy. + +## Reproduce + +Use Node 24 and the frozen repository dependencies. From the repository root: + +```sh +pnpm exec vitest run packages/db/src/response-capture.test.ts packages/db/src/response-capture-bundle.test.ts packages/db/src/response-capture-postgres.test.ts +node packages/db/src/__tests__/response-capture-overhead.mjs 09162fe893b464dd2ccdafd14bd3ef1611202a86 1000 > capture-overhead.jsonl +``` + +The helper reads the pinned baseline with `git show` into an esbuild loader. +It does not retain a cloned implementation or change production files. It +removes its temporary bundles in `finally`. No source maps, network services, +SQL parameters or real company data are required. The PostgreSQL test needs +local embedded PostgreSQL support. Preserve failures if that setup is unavailable. diff --git a/doc/performance/fixtures/db-capture-hosted-callers-overhead.json b/doc/performance/fixtures/db-capture-hosted-callers-overhead.json new file mode 100644 index 00000000000..15b507ea079 --- /dev/null +++ b/doc/performance/fixtures/db-capture-hosted-callers-overhead.json @@ -0,0 +1,1305 @@ +[ + { + "kind": "host", + "node": "v24.22.2", + "execPath": "", + "base": "09162fe893b464dd2ccdafd14bd3ef1611202a86", + "logicalCpus": 18, + "loadavg": [ + 7.125, + 6.66455078125, + 6.1240234375 + ], + "count": 1000, + "boundary": "serial instrumented fake-driver process; real bundled Drizzle/capture; no network, database, output flush or assertions in timing", + "candidateCaptureSha256": "bdc3fceee77bf5cf6dcc2784de6cdf9631c3446e300f1c3b194312c203eba1dd" + }, + { + "kind": "sample", + "round": 0, + "variant": "current", + "mode": "disabled", + "count": 1000, + "cpuUsPerQuery": 11.767, + "wallUsPerQuery": 8.897500000000008, + "calls": 1000, + "entries": [] + }, + { + "kind": "sample", + "round": 0, + "variant": "candidate", + "mode": "disabled", + "count": 1000, + "cpuUsPerQuery": 12.59, + "wallUsPerQuery": 8.665041000000002, + "calls": 1000, + "entries": [] + }, + { + "kind": "sample", + "round": 0, + "variant": "current", + "mode": "unowned", + "count": 1000, + "cpuUsPerQuery": 21.548, + "wallUsPerQuery": 16.43412499999999, + "calls": 1000, + "entries": [ + { + "owner": "unattributed", + "calls": 1000, + "callers": [] + } + ] + }, + { + "kind": "sample", + "round": 0, + "variant": "candidate", + "mode": "unowned", + "count": 1000, + "cpuUsPerQuery": 24.97, + "wallUsPerQuery": 16.37704099999999, + "calls": 1000, + "entries": [ + { + "owner": "unattributed", + "calls": 500, + "callers": [ + "dist-runtime/server.mjs:9471:13" + ] + }, + { + "owner": "unattributed", + "calls": 500, + "callers": [ + "dist-runtime/server.mjs:9468:13" + ] + } + ] + }, + { + "kind": "sample", + "round": 0, + "variant": "current", + "mode": "http.request", + "count": 1000, + "cpuUsPerQuery": 15.461, + "wallUsPerQuery": 10.909791999999982, + "calls": 1000, + "entries": [ + { + "owner": "http.request", + "calls": 1000, + "callers": [] + } + ] + }, + { + "kind": "sample", + "round": 0, + "variant": "candidate", + "mode": "http.request", + "count": 1000, + "cpuUsPerQuery": 20.058, + "wallUsPerQuery": 15.985584000000017, + "calls": 1000, + "entries": [ + { + "owner": "http.request", + "calls": 500, + "callers": [ + "dist-runtime/server.mjs:9471:13" + ] + }, + { + "owner": "http.request", + "calls": 500, + "callers": [ + "dist-runtime/server.mjs:9468:13" + ] + } + ] + }, + { + "kind": "sample", + "round": 0, + "variant": "current", + "mode": "response.presentation", + "count": 1000, + "cpuUsPerQuery": 11.039, + "wallUsPerQuery": 10.400749999999988, + "calls": 1000, + "entries": [ + { + "owner": "response.presentation", + "calls": 1000, + "callers": [] + } + ] + }, + { + "kind": "sample", + "round": 0, + "variant": "candidate", + "mode": "response.presentation", + "count": 1000, + "cpuUsPerQuery": 12.913, + "wallUsPerQuery": 10.773500000000013, + "calls": 1000, + "entries": [ + { + "owner": "response.presentation", + "calls": 1000, + "callers": [] + } + ] + }, + { + "kind": "sample", + "round": 1, + "variant": "candidate", + "mode": "disabled", + "count": 1000, + "cpuUsPerQuery": 9.934, + "wallUsPerQuery": 8.25970799999999, + "calls": 1000, + "entries": [] + }, + { + "kind": "sample", + "round": 1, + "variant": "current", + "mode": "disabled", + "count": 1000, + "cpuUsPerQuery": 16.865, + "wallUsPerQuery": 8.917332999999983, + "calls": 1000, + "entries": [] + }, + { + "kind": "sample", + "round": 1, + "variant": "candidate", + "mode": "unowned", + "count": 1000, + "cpuUsPerQuery": 16.868, + "wallUsPerQuery": 15.450959000000012, + "calls": 1000, + "entries": [ + { + "owner": "unattributed", + "calls": 500, + "callers": [ + "dist-runtime/server.mjs:9471:13" + ] + }, + { + "owner": "unattributed", + "calls": 500, + "callers": [ + "dist-runtime/server.mjs:9468:13" + ] + } + ] + }, + { + "kind": "sample", + "round": 1, + "variant": "current", + "mode": "unowned", + "count": 1000, + "cpuUsPerQuery": 21.675, + "wallUsPerQuery": 16.195375000000013, + "calls": 1000, + "entries": [ + { + "owner": "unattributed", + "calls": 1000, + "callers": [] + } + ] + }, + { + "kind": "sample", + "round": 1, + "variant": "candidate", + "mode": "http.request", + "count": 1000, + "cpuUsPerQuery": 19.058, + "wallUsPerQuery": 15.357625000000041, + "calls": 1000, + "entries": [ + { + "owner": "http.request", + "calls": 500, + "callers": [ + "dist-runtime/server.mjs:9471:13" + ] + }, + { + "owner": "http.request", + "calls": 500, + "callers": [ + "dist-runtime/server.mjs:9468:13" + ] + } + ] + }, + { + "kind": "sample", + "round": 1, + "variant": "current", + "mode": "http.request", + "count": 1000, + "cpuUsPerQuery": 15.661, + "wallUsPerQuery": 10.571124999999995, + "calls": 1000, + "entries": [ + { + "owner": "http.request", + "calls": 1000, + "callers": [] + } + ] + }, + { + "kind": "sample", + "round": 1, + "variant": "candidate", + "mode": "response.presentation", + "count": 1000, + "cpuUsPerQuery": 16.804, + "wallUsPerQuery": 10.809834000000025, + "calls": 1000, + "entries": [ + { + "owner": "response.presentation", + "calls": 1000, + "callers": [] + } + ] + }, + { + "kind": "sample", + "round": 1, + "variant": "current", + "mode": "response.presentation", + "count": 1000, + "cpuUsPerQuery": 10.704, + "wallUsPerQuery": 10.500125000000025, + "calls": 1000, + "entries": [ + { + "owner": "response.presentation", + "calls": 1000, + "callers": [] + } + ] + }, + { + "kind": "sample", + "round": 2, + "variant": "current", + "mode": "disabled", + "count": 1000, + "cpuUsPerQuery": 25.037, + "wallUsPerQuery": 8.543166999999983, + "calls": 1000, + "entries": [] + }, + { + "kind": "sample", + "round": 2, + "variant": "candidate", + "mode": "disabled", + "count": 1000, + "cpuUsPerQuery": 31.978, + "wallUsPerQuery": 8.642375000000014, + "calls": 1000, + "entries": [] + }, + { + "kind": "sample", + "round": 2, + "variant": "current", + "mode": "unowned", + "count": 1000, + "cpuUsPerQuery": 28.522, + "wallUsPerQuery": 15.685416000000032, + "calls": 1000, + "entries": [ + { + "owner": "unattributed", + "calls": 1000, + "callers": [] + } + ] + }, + { + "kind": "sample", + "round": 2, + "variant": "candidate", + "mode": "unowned", + "count": 1000, + "cpuUsPerQuery": 21.865, + "wallUsPerQuery": 16.07820799999996, + "calls": 1000, + "entries": [ + { + "owner": "unattributed", + "calls": 500, + "callers": [ + "dist-runtime/server.mjs:9471:13" + ] + }, + { + "owner": "unattributed", + "calls": 500, + "callers": [ + "dist-runtime/server.mjs:9468:13" + ] + } + ] + }, + { + "kind": "sample", + "round": 2, + "variant": "current", + "mode": "http.request", + "count": 1000, + "cpuUsPerQuery": 17.897, + "wallUsPerQuery": 10.527792000000034, + "calls": 1000, + "entries": [ + { + "owner": "http.request", + "calls": 1000, + "callers": [] + } + ] + }, + { + "kind": "sample", + "round": 2, + "variant": "candidate", + "mode": "http.request", + "count": 1000, + "cpuUsPerQuery": 17.662, + "wallUsPerQuery": 15.169457999999961, + "calls": 1000, + "entries": [ + { + "owner": "http.request", + "calls": 500, + "callers": [ + "dist-runtime/server.mjs:9471:13" + ] + }, + { + "owner": "http.request", + "calls": 500, + "callers": [ + "dist-runtime/server.mjs:9468:13" + ] + } + ] + }, + { + "kind": "sample", + "round": 2, + "variant": "current", + "mode": "response.presentation", + "count": 1000, + "cpuUsPerQuery": 10.148, + "wallUsPerQuery": 9.870416999999977, + "calls": 1000, + "entries": [ + { + "owner": "response.presentation", + "calls": 1000, + "callers": [] + } + ] + }, + { + "kind": "sample", + "round": 2, + "variant": "candidate", + "mode": "response.presentation", + "count": 1000, + "cpuUsPerQuery": 10.126, + "wallUsPerQuery": 9.869708000000003, + "calls": 1000, + "entries": [ + { + "owner": "response.presentation", + "calls": 1000, + "callers": [] + } + ] + }, + { + "kind": "sample", + "round": 3, + "variant": "candidate", + "mode": "disabled", + "count": 1000, + "cpuUsPerQuery": 8.294, + "wallUsPerQuery": 8.219832999999996, + "calls": 1000, + "entries": [] + }, + { + "kind": "sample", + "round": 3, + "variant": "current", + "mode": "disabled", + "count": 1000, + "cpuUsPerQuery": 7.687, + "wallUsPerQuery": 7.63733400000001, + "calls": 1000, + "entries": [] + }, + { + "kind": "sample", + "round": 3, + "variant": "candidate", + "mode": "unowned", + "count": 1000, + "cpuUsPerQuery": 33.807, + "wallUsPerQuery": 15.641625000000033, + "calls": 1000, + "entries": [ + { + "owner": "unattributed", + "calls": 500, + "callers": [ + "dist-runtime/server.mjs:9471:13" + ] + }, + { + "owner": "unattributed", + "calls": 500, + "callers": [ + "dist-runtime/server.mjs:9468:13" + ] + } + ] + }, + { + "kind": "sample", + "round": 3, + "variant": "current", + "mode": "unowned", + "count": 1000, + "cpuUsPerQuery": 32.634, + "wallUsPerQuery": 15.841042000000016, + "calls": 1000, + "entries": [ + { + "owner": "unattributed", + "calls": 1000, + "callers": [] + } + ] + }, + { + "kind": "sample", + "round": 3, + "variant": "candidate", + "mode": "http.request", + "count": 1000, + "cpuUsPerQuery": 15.08, + "wallUsPerQuery": 14.588625000000036, + "calls": 1000, + "entries": [ + { + "owner": "http.request", + "calls": 500, + "callers": [ + "dist-runtime/server.mjs:9471:13" + ] + }, + { + "owner": "http.request", + "calls": 500, + "callers": [ + "dist-runtime/server.mjs:9468:13" + ] + } + ] + }, + { + "kind": "sample", + "round": 3, + "variant": "current", + "mode": "http.request", + "count": 1000, + "cpuUsPerQuery": 10.075, + "wallUsPerQuery": 9.658459000000109, + "calls": 1000, + "entries": [ + { + "owner": "http.request", + "calls": 1000, + "callers": [] + } + ] + }, + { + "kind": "sample", + "round": 3, + "variant": "candidate", + "mode": "response.presentation", + "count": 1000, + "cpuUsPerQuery": 9.884, + "wallUsPerQuery": 9.682833999999957, + "calls": 1000, + "entries": [ + { + "owner": "response.presentation", + "calls": 1000, + "callers": [] + } + ] + }, + { + "kind": "sample", + "round": 3, + "variant": "current", + "mode": "response.presentation", + "count": 1000, + "cpuUsPerQuery": 9.656, + "wallUsPerQuery": 9.543583000000014, + "calls": 1000, + "entries": [ + { + "owner": "response.presentation", + "calls": 1000, + "callers": [] + } + ] + }, + { + "kind": "sample", + "round": 4, + "variant": "current", + "mode": "disabled", + "count": 1000, + "cpuUsPerQuery": 10.043, + "wallUsPerQuery": 7.930874999999901, + "calls": 1000, + "entries": [] + }, + { + "kind": "sample", + "round": 4, + "variant": "candidate", + "mode": "disabled", + "count": 1000, + "cpuUsPerQuery": 9.838, + "wallUsPerQuery": 7.896916000000033, + "calls": 1000, + "entries": [] + }, + { + "kind": "sample", + "round": 4, + "variant": "current", + "mode": "unowned", + "count": 1000, + "cpuUsPerQuery": 14.754, + "wallUsPerQuery": 14.633041999999932, + "calls": 1000, + "entries": [ + { + "owner": "unattributed", + "calls": 1000, + "callers": [] + } + ] + }, + { + "kind": "sample", + "round": 4, + "variant": "candidate", + "mode": "unowned", + "count": 1000, + "cpuUsPerQuery": 14.563, + "wallUsPerQuery": 14.370415999999977, + "calls": 1000, + "entries": [ + { + "owner": "unattributed", + "calls": 500, + "callers": [ + "dist-runtime/server.mjs:9471:13" + ] + }, + { + "owner": "unattributed", + "calls": 500, + "callers": [ + "dist-runtime/server.mjs:9468:13" + ] + } + ] + }, + { + "kind": "sample", + "round": 4, + "variant": "current", + "mode": "http.request", + "count": 1000, + "cpuUsPerQuery": 9.734, + "wallUsPerQuery": 9.531333000000016, + "calls": 1000, + "entries": [ + { + "owner": "http.request", + "calls": 1000, + "callers": [] + } + ] + }, + { + "kind": "sample", + "round": 4, + "variant": "candidate", + "mode": "http.request", + "count": 1000, + "cpuUsPerQuery": 15.634, + "wallUsPerQuery": 14.889666000000034, + "calls": 1000, + "entries": [ + { + "owner": "http.request", + "calls": 500, + "callers": [ + "dist-runtime/server.mjs:9471:13" + ] + }, + { + "owner": "http.request", + "calls": 500, + "callers": [ + "dist-runtime/server.mjs:9468:13" + ] + } + ] + }, + { + "kind": "sample", + "round": 4, + "variant": "current", + "mode": "response.presentation", + "count": 1000, + "cpuUsPerQuery": 11.078, + "wallUsPerQuery": 9.57454199999995, + "calls": 1000, + "entries": [ + { + "owner": "response.presentation", + "calls": 1000, + "callers": [] + } + ] + }, + { + "kind": "sample", + "round": 4, + "variant": "candidate", + "mode": "response.presentation", + "count": 1000, + "cpuUsPerQuery": 12.323, + "wallUsPerQuery": 10.757791999999993, + "calls": 1000, + "entries": [ + { + "owner": "response.presentation", + "calls": 1000, + "callers": [] + } + ] + }, + { + "kind": "proof", + "node": "v24.22.2", + "cases": [ + { + "mode": "disabled", + "driverCalls": 9, + "stacks": 0, + "events": [] + }, + { + "mode": "future", + "driverCalls": 9, + "stacks": 0, + "events": [ + { + "event": "paperclip.db_response_capture.summary.v2", + "captureId": "43e805c3-8e65-4795-921a-8c9decf686e9", + "windowStart": "1970-01-01T00:00:00.999Z", + "windowEnd": "1970-01-01T00:00:02.000Z", + "closedAt": "1970-01-01T00:00:00.998Z", + "startedQueries": 0, + "completedQueries": 0, + "inFlightAtEnd": 0, + "groups": 0, + "groupPageSize": 128, + "groupPages": 0, + "overflowCalls": 0, + "rows": 0, + "sampledResults": 0, + "sampledValueBytes": 0, + "sizingWallMs": 0, + "sampleEvery": 16, + "sampling": "first-and-every-16th-successful-result-per-group", + "maxSampleCells": 256, + "maxSampleStringLength": 16384, + "maxSampleStringUnits": 65536, + "maxSampleBytes": 65536, + "rowValuesLogged": false, + "sqlOrParametersLogged": false, + "wireBytesMeasured": false, + "measurementBoundary": "postgres-js results before Drizzle column decoding", + "wallTimeBoundary": "first query consumption to driver result; includes queue, database, network and event-loop waits; not CPU", + "byteMeasurement": "sampled primitive values only; complex/oversized/budget-exceeding values unmeasured; no extrapolation", + "relationalQueriesMeasured": true, + "unsafeDriverQueriesMeasured": true, + "taggedDriverQueriesMeasured": false, + "streamingQueriesMeasured": false + } + ] + }, + { + "mode": "expired", + "driverCalls": 9, + "stacks": 0, + "events": [ + { + "event": "paperclip.db_response_capture.summary.v2", + "captureId": "37b60d6c-60d7-4470-951f-5c816d03ac85", + "windowStart": "1970-01-01T00:00:00.999Z", + "windowEnd": "1970-01-01T00:00:02.000Z", + "closedAt": "1970-01-01T00:00:02.000Z", + "startedQueries": 0, + "completedQueries": 0, + "inFlightAtEnd": 0, + "groups": 0, + "groupPageSize": 128, + "groupPages": 0, + "overflowCalls": 0, + "rows": 0, + "sampledResults": 0, + "sampledValueBytes": 0, + "sizingWallMs": 0, + "sampleEvery": 16, + "sampling": "first-and-every-16th-successful-result-per-group", + "maxSampleCells": 256, + "maxSampleStringLength": 16384, + "maxSampleStringUnits": 65536, + "maxSampleBytes": 65536, + "rowValuesLogged": false, + "sqlOrParametersLogged": false, + "wireBytesMeasured": false, + "measurementBoundary": "postgres-js results before Drizzle column decoding", + "wallTimeBoundary": "first query consumption to driver result; includes queue, database, network and event-loop waits; not CPU", + "byteMeasurement": "sampled primitive values only; complex/oversized/budget-exceeding values unmeasured; no extrapolation", + "relationalQueriesMeasured": true, + "unsafeDriverQueriesMeasured": true, + "taggedDriverQueriesMeasured": false, + "streamingQueriesMeasured": false + } + ] + }, + { + "mode": "unowned", + "driverCalls": 9, + "stacks": 9, + "events": [ + { + "event": "paperclip.db_response_capture.entry.v2", + "captureId": "d44c771a-f15b-4371-9106-83b83676c077", + "groupIndex": 0, + "groupPage": 0, + "operation": "select", + "table": "diagnostic_fixture", + "callers": [ + "dist-runtime/server.mjs:9468:13" + ], + "owner": "unattributed", + "calls": 3, + "rows": 0, + "queryErrors": 0, + "totalWallMs": 0.006083000000103311, + "maxWallMs": 0.003958000000011452, + "sampledResults": 1, + "sampledRows": 0, + "sampledValueBytes": 0, + "maxSampledValueBytes": 0, + "measuredValues": 0, + "unmeasuredValues": 0, + "incompleteSamples": 0, + "sizingWallMs": 0.00037500000007639755 + }, + { + "event": "paperclip.db_response_capture.entry.v2", + "captureId": "d44c771a-f15b-4371-9106-83b83676c077", + "groupIndex": 1, + "groupPage": 0, + "operation": "select", + "table": "diagnostic_fixture", + "callers": [ + "dist-runtime/server.mjs:9471:13" + ], + "owner": "unattributed", + "calls": 2, + "rows": 0, + "queryErrors": 0, + "totalWallMs": 0.001958000000058746, + "maxWallMs": 0.001082999999994172, + "sampledResults": 1, + "sampledRows": 0, + "sampledValueBytes": 0, + "maxSampledValueBytes": 0, + "measuredValues": 0, + "unmeasuredValues": 0, + "incompleteSamples": 0, + "sizingWallMs": 0.00012500000002546585 + }, + { + "event": "paperclip.db_response_capture.entry.v2", + "captureId": "d44c771a-f15b-4371-9106-83b83676c077", + "groupIndex": 2, + "groupPage": 0, + "operation": "select", + "table": "diagnostic_fixture", + "callers": [ + "dist-runtime/server.mjs:9474:13" + ], + "owner": "unattributed", + "calls": 1, + "rows": 0, + "queryErrors": 0, + "totalWallMs": 0.0009159999999610591, + "maxWallMs": 0.0009159999999610591, + "sampledResults": 1, + "sampledRows": 0, + "sampledValueBytes": 0, + "maxSampledValueBytes": 0, + "measuredValues": 0, + "unmeasuredValues": 0, + "incompleteSamples": 0, + "sizingWallMs": 8.300000001781882e-05 + }, + { + "event": "paperclip.db_response_capture.entry.v2", + "captureId": "d44c771a-f15b-4371-9106-83b83676c077", + "groupIndex": 3, + "groupPage": 0, + "operation": "execute", + "table": "other", + "callers": [ + "dist-runtime/server.mjs:9477:13" + ], + "owner": "unattributed", + "calls": 1, + "rows": 0, + "queryErrors": 0, + "totalWallMs": 0.001040999999986525, + "maxWallMs": 0.001040999999986525, + "sampledResults": 1, + "sampledRows": 0, + "sampledValueBytes": 0, + "maxSampledValueBytes": 0, + "measuredValues": 0, + "unmeasuredValues": 0, + "incompleteSamples": 0, + "sizingWallMs": 4.100000001017179e-05 + }, + { + "event": "paperclip.db_response_capture.entry.v2", + "captureId": "d44c771a-f15b-4371-9106-83b83676c077", + "groupIndex": 4, + "groupPage": 0, + "operation": "select", + "table": "other", + "callers": [], + "owner": "unattributed", + "calls": 1, + "rows": 0, + "queryErrors": 0, + "totalWallMs": 0.0012500000000272848, + "maxWallMs": 0.0012500000000272848, + "sampledResults": 1, + "sampledRows": 0, + "sampledValueBytes": 0, + "maxSampledValueBytes": 0, + "measuredValues": 0, + "unmeasuredValues": 0, + "incompleteSamples": 0, + "sizingWallMs": 4.099999989648495e-05 + }, + { + "event": "paperclip.db_response_capture.entry.v2", + "captureId": "d44c771a-f15b-4371-9106-83b83676c077", + "groupIndex": 5, + "groupPage": 0, + "operation": "select", + "table": "diagnostic_fixture", + "callers": [], + "owner": "unattributed", + "calls": 1, + "rows": 0, + "queryErrors": 0, + "totalWallMs": 0.0011660000000119908, + "maxWallMs": 0.0011660000000119908, + "sampledResults": 1, + "sampledRows": 0, + "sampledValueBytes": 0, + "maxSampledValueBytes": 0, + "measuredValues": 0, + "unmeasuredValues": 0, + "incompleteSamples": 0, + "sizingWallMs": 8.300000001781882e-05 + }, + { + "event": "paperclip.db_response_capture.summary.v2", + "captureId": "d44c771a-f15b-4371-9106-83b83676c077", + "windowStart": "1970-01-01T00:00:00.999Z", + "windowEnd": "1970-01-01T00:00:02.000Z", + "closedAt": "1970-01-01T00:00:01.000Z", + "startedQueries": 9, + "completedQueries": 9, + "inFlightAtEnd": 0, + "groups": 6, + "groupPageSize": 128, + "groupPages": 1, + "overflowCalls": 0, + "rows": 0, + "sampledResults": 6, + "sampledValueBytes": 0, + "sizingWallMs": 0.0007480000000441578, + "sampleEvery": 16, + "sampling": "first-and-every-16th-successful-result-per-group", + "maxSampleCells": 256, + "maxSampleStringLength": 16384, + "maxSampleStringUnits": 65536, + "maxSampleBytes": 65536, + "rowValuesLogged": false, + "sqlOrParametersLogged": false, + "wireBytesMeasured": false, + "measurementBoundary": "postgres-js results before Drizzle column decoding", + "wallTimeBoundary": "first query consumption to driver result; includes queue, database, network and event-loop waits; not CPU", + "byteMeasurement": "sampled primitive values only; complex/oversized/budget-exceeding values unmeasured; no extrapolation", + "relationalQueriesMeasured": true, + "unsafeDriverQueriesMeasured": true, + "taggedDriverQueriesMeasured": false, + "streamingQueriesMeasured": false + } + ] + }, + { + "mode": "http.request", + "driverCalls": 9, + "stacks": 9, + "events": [ + { + "event": "paperclip.db_response_capture.entry.v2", + "captureId": "8881cd9d-06cc-4817-a71c-cc14bdbe74c6", + "groupIndex": 0, + "groupPage": 0, + "operation": "select", + "table": "diagnostic_fixture", + "callers": [ + "dist-runtime/server.mjs:9468:13" + ], + "owner": "http.request", + "calls": 3, + "rows": 0, + "queryErrors": 0, + "totalWallMs": 0.0028340000000071086, + "maxWallMs": 0.0010419999999840002, + "sampledResults": 1, + "sampledRows": 0, + "sampledValueBytes": 0, + "maxSampledValueBytes": 0, + "measuredValues": 0, + "unmeasuredValues": 0, + "incompleteSamples": 0, + "sizingWallMs": 4.200000000764703e-05 + }, + { + "event": "paperclip.db_response_capture.entry.v2", + "captureId": "8881cd9d-06cc-4817-a71c-cc14bdbe74c6", + "groupIndex": 1, + "groupPage": 0, + "operation": "select", + "table": "diagnostic_fixture", + "callers": [ + "dist-runtime/server.mjs:9471:13" + ], + "owner": "http.request", + "calls": 2, + "rows": 0, + "queryErrors": 0, + "totalWallMs": 0.0017080000000078144, + "maxWallMs": 0.0008750000000645741, + "sampledResults": 1, + "sampledRows": 0, + "sampledValueBytes": 0, + "maxSampledValueBytes": 0, + "measuredValues": 0, + "unmeasuredValues": 0, + "incompleteSamples": 0, + "sizingWallMs": 4.200000000764703e-05 + }, + { + "event": "paperclip.db_response_capture.entry.v2", + "captureId": "8881cd9d-06cc-4817-a71c-cc14bdbe74c6", + "groupIndex": 2, + "groupPage": 0, + "operation": "select", + "table": "diagnostic_fixture", + "callers": [ + "dist-runtime/server.mjs:9474:13" + ], + "owner": "http.request", + "calls": 1, + "rows": 0, + "queryErrors": 0, + "totalWallMs": 0.0008749999999508873, + "maxWallMs": 0.0008749999999508873, + "sampledResults": 1, + "sampledRows": 0, + "sampledValueBytes": 0, + "maxSampledValueBytes": 0, + "measuredValues": 0, + "unmeasuredValues": 0, + "incompleteSamples": 0, + "sizingWallMs": 4.200000000764703e-05 + }, + { + "event": "paperclip.db_response_capture.entry.v2", + "captureId": "8881cd9d-06cc-4817-a71c-cc14bdbe74c6", + "groupIndex": 3, + "groupPage": 0, + "operation": "execute", + "table": "other", + "callers": [ + "dist-runtime/server.mjs:9477:13" + ], + "owner": "http.request", + "calls": 1, + "rows": 0, + "queryErrors": 0, + "totalWallMs": 0.001082999999994172, + "maxWallMs": 0.001082999999994172, + "sampledResults": 1, + "sampledRows": 0, + "sampledValueBytes": 0, + "maxSampledValueBytes": 0, + "measuredValues": 0, + "unmeasuredValues": 0, + "incompleteSamples": 0, + "sizingWallMs": 4.200000000764703e-05 + }, + { + "event": "paperclip.db_response_capture.entry.v2", + "captureId": "8881cd9d-06cc-4817-a71c-cc14bdbe74c6", + "groupIndex": 4, + "groupPage": 0, + "operation": "select", + "table": "other", + "callers": [], + "owner": "http.request", + "calls": 1, + "rows": 0, + "queryErrors": 0, + "totalWallMs": 0.0009579999999687061, + "maxWallMs": 0.0009579999999687061, + "sampledResults": 1, + "sampledRows": 0, + "sampledValueBytes": 0, + "maxSampledValueBytes": 0, + "measuredValues": 0, + "unmeasuredValues": 0, + "incompleteSamples": 0, + "sizingWallMs": 4.100000001017179e-05 + }, + { + "event": "paperclip.db_response_capture.entry.v2", + "captureId": "8881cd9d-06cc-4817-a71c-cc14bdbe74c6", + "groupIndex": 5, + "groupPage": 0, + "operation": "select", + "table": "diagnostic_fixture", + "callers": [], + "owner": "http.request", + "calls": 1, + "rows": 0, + "queryErrors": 0, + "totalWallMs": 0.0009580000000823929, + "maxWallMs": 0.0009580000000823929, + "sampledResults": 1, + "sampledRows": 0, + "sampledValueBytes": 0, + "maxSampledValueBytes": 0, + "measuredValues": 0, + "unmeasuredValues": 0, + "incompleteSamples": 0, + "sizingWallMs": 4.200000000764703e-05 + }, + { + "event": "paperclip.db_response_capture.summary.v2", + "captureId": "8881cd9d-06cc-4817-a71c-cc14bdbe74c6", + "windowStart": "1970-01-01T00:00:00.999Z", + "windowEnd": "1970-01-01T00:00:02.000Z", + "closedAt": "1970-01-01T00:00:01.000Z", + "startedQueries": 9, + "completedQueries": 9, + "inFlightAtEnd": 0, + "groups": 6, + "groupPageSize": 128, + "groupPages": 1, + "overflowCalls": 0, + "rows": 0, + "sampledResults": 6, + "sampledValueBytes": 0, + "sizingWallMs": 0.00025100000004840695, + "sampleEvery": 16, + "sampling": "first-and-every-16th-successful-result-per-group", + "maxSampleCells": 256, + "maxSampleStringLength": 16384, + "maxSampleStringUnits": 65536, + "maxSampleBytes": 65536, + "rowValuesLogged": false, + "sqlOrParametersLogged": false, + "wireBytesMeasured": false, + "measurementBoundary": "postgres-js results before Drizzle column decoding", + "wallTimeBoundary": "first query consumption to driver result; includes queue, database, network and event-loop waits; not CPU", + "byteMeasurement": "sampled primitive values only; complex/oversized/budget-exceeding values unmeasured; no extrapolation", + "relationalQueriesMeasured": true, + "unsafeDriverQueriesMeasured": true, + "taggedDriverQueriesMeasured": false, + "streamingQueriesMeasured": false + } + ] + }, + { + "mode": "response.presentation", + "driverCalls": 9, + "stacks": 0, + "events": [ + { + "event": "paperclip.db_response_capture.entry.v2", + "captureId": "0c37a43d-ab5c-4321-85e3-66ebab9938f0", + "groupIndex": 0, + "groupPage": 0, + "operation": "select", + "table": "diagnostic_fixture", + "callers": [], + "owner": "response.presentation", + "calls": 7, + "rows": 0, + "queryErrors": 0, + "totalWallMs": 0.00462599999991653, + "maxWallMs": 0.0008329999999432403, + "sampledResults": 1, + "sampledRows": 0, + "sampledValueBytes": 0, + "maxSampledValueBytes": 0, + "measuredValues": 0, + "unmeasuredValues": 0, + "incompleteSamples": 0, + "sizingWallMs": 8.300000001781882e-05 + }, + { + "event": "paperclip.db_response_capture.entry.v2", + "captureId": "0c37a43d-ab5c-4321-85e3-66ebab9938f0", + "groupIndex": 1, + "groupPage": 0, + "operation": "execute", + "table": "other", + "callers": [], + "owner": "response.presentation", + "calls": 1, + "rows": 0, + "queryErrors": 0, + "totalWallMs": 0.0006250000000136424, + "maxWallMs": 0.0006250000000136424, + "sampledResults": 1, + "sampledRows": 0, + "sampledValueBytes": 0, + "maxSampledValueBytes": 0, + "measuredValues": 0, + "unmeasuredValues": 0, + "incompleteSamples": 0, + "sizingWallMs": 8.300000001781882e-05 + }, + { + "event": "paperclip.db_response_capture.entry.v2", + "captureId": "0c37a43d-ab5c-4321-85e3-66ebab9938f0", + "groupIndex": 2, + "groupPage": 0, + "operation": "select", + "table": "other", + "callers": [], + "owner": "response.presentation", + "calls": 1, + "rows": 0, + "queryErrors": 0, + "totalWallMs": 0.0005830000000059954, + "maxWallMs": 0.0005830000000059954, + "sampledResults": 1, + "sampledRows": 0, + "sampledValueBytes": 0, + "maxSampledValueBytes": 0, + "measuredValues": 0, + "unmeasuredValues": 0, + "incompleteSamples": 0, + "sizingWallMs": 8.299999990413198e-05 + }, + { + "event": "paperclip.db_response_capture.summary.v2", + "captureId": "0c37a43d-ab5c-4321-85e3-66ebab9938f0", + "windowStart": "1970-01-01T00:00:00.999Z", + "windowEnd": "1970-01-01T00:00:02.000Z", + "closedAt": "1970-01-01T00:00:01.000Z", + "startedQueries": 9, + "completedQueries": 9, + "inFlightAtEnd": 0, + "groups": 3, + "groupPageSize": 128, + "groupPages": 1, + "overflowCalls": 0, + "rows": 0, + "sampledResults": 3, + "sampledValueBytes": 0, + "sizingWallMs": 0.0002489999999397696, + "sampleEvery": 16, + "sampling": "first-and-every-16th-successful-result-per-group", + "maxSampleCells": 256, + "maxSampleStringLength": 16384, + "maxSampleStringUnits": 65536, + "maxSampleBytes": 65536, + "rowValuesLogged": false, + "sqlOrParametersLogged": false, + "wireBytesMeasured": false, + "measurementBoundary": "postgres-js results before Drizzle column decoding", + "wallTimeBoundary": "first query consumption to driver result; includes queue, database, network and event-loop waits; not CPU", + "byteMeasurement": "sampled primitive values only; complex/oversized/budget-exceeding values unmeasured; no extrapolation", + "relationalQueriesMeasured": true, + "unsafeDriverQueriesMeasured": true, + "taggedDriverQueriesMeasured": false, + "streamingQueriesMeasured": false + } + ] + } + ] + } +] diff --git a/packages/db/src/__tests__/response-capture-bundle-fixture.ts b/packages/db/src/__tests__/response-capture-bundle-fixture.ts new file mode 100644 index 00000000000..57e97a6d894 --- /dev/null +++ b/packages/db/src/__tests__/response-capture-bundle-fixture.ts @@ -0,0 +1,96 @@ +import { eq, sql } from "drizzle-orm"; +import { pgTable, uuid } from "drizzle-orm/pg-core"; +import { drizzle } from "drizzle-orm/postgres-js"; +import type { Sql } from "postgres"; +import { createDatabaseResponseCapture, installDatabaseResponseCapture, withDatabaseOperation } from "../response-capture.js"; + +const table = pgTable("diagnostic_fixture", { id: uuid("id") }); +const privateParameter = "00000000-0000-4000-8000-000000000001"; +function firstApplicationCaller(db: Pick, "select">, id: string) { + return db.select({ id: table.id }).from(table).where(eq(table.id, id)).execute(); +} +function secondApplicationCaller(db: Pick, "select">, id: string) { + return db.select({ id: table.id }).from(table).where(eq(table.id, id)).execute(); +} +function prepareApplicationCaller(db: Pick, "select">) { + return db.select({ id: table.id }).from(table).where(eq(table.id, sql.placeholder("id"))).prepare("fixture"); +} +function executeApplicationCaller(db: ReturnType) { + return db.execute(sql`select 1`); +} +export async function runBundleProof() { + const cases = []; + for (const mode of ["disabled", "future", "expired", "unowned", "http.request", "response.presentation"]) { + let clock = mode === "future" ? 998 : 1000, driverCalls = 0, stacks = 0; + const events: Array> = []; + const capture = mode === "disabled" ? undefined : createDatabaseResponseCapture( + { start: 999, end: 2000 }, event => events.push(event), () => clock); + const client = { + options: { parsers: {}, serializers: {} }, + unsafe() { + driverCalls += 1; + return { values() { return this; }, then(ok: (value: unknown) => unknown, bad: (error: unknown) => unknown) { + return Promise.resolve(Object.assign([], { columns: [{ name: "id" }] })).then(ok, bad); + } }; + }, + begin(callback: (value: unknown) => unknown) { return callback(client); }, + savepoint(callback: (value: unknown) => unknown) { return callback(client); }, + }; + const db = drizzle(client as unknown as Sql, { logger: false, schema: { table } }); + installDatabaseResponseCapture(db, { table }, capture); + if (mode === "expired") clock = 2000; + const original = Error.captureStackTrace; + Error.captureStackTrace = (target, boundary) => { stacks += 1; original(target, boundary); }; + try { + const action = async () => { + await firstApplicationCaller(db, privateParameter); + await firstApplicationCaller(db, "00000000-0000-4000-8000-000000000002"); + await secondApplicationCaller(db, privateParameter); + const prepared = prepareApplicationCaller(db); + await prepared.execute({ id: privateParameter }); + await executeApplicationCaller(db); + await db.transaction(async tx => { + await secondApplicationCaller(tx, privateParameter); + await tx.transaction(async nested => { await firstApplicationCaller(nested, privateParameter); }); + }); + // These have no trusted builder boundary. Do not label bundled ORM + // internals (or their driver bridge) as an application caller. + await db.$client.unsafe("select 1"); + await db.query.table.findMany(); + }; + await (mode.includes(".") ? withDatabaseOperation(mode, action) : action()); + } finally { Error.captureStackTrace = original; capture?.flush(); } + cases.push({ mode, driverCalls, stacks, events }); + } + return { node: process.version, cases }; +} + +// Serial, finite fake-driver measurement: includes real ORM compilation and +// active census costs, but no database/network latency or result sizing work. +export async function measureBundleCapture(mode: string, count: number) { + const events: Array> = []; + const now = Date.now(); + const capture = mode === "disabled" ? undefined : createDatabaseResponseCapture( + { start: now - 1, end: now + 59_000 }, event => events.push(event)); + let calls = 0; + const client = { options: { parsers: {}, serializers: {} }, unsafe() { + calls += 1; + return { values() { return this; }, then(ok: (value: unknown) => unknown, bad: (error: unknown) => unknown) { + return Promise.resolve(Object.assign([], { columns: [{ name: "id" }] })).then(ok, bad); + } }; + } }; + const db = drizzle(client as unknown as Sql, { logger: false }); + installDatabaseResponseCapture(db, { table }, capture); + const action = async () => { + for (let index = 0; index < count; index += 1) { + await (index % 2 ? firstApplicationCaller(db, privateParameter) : secondApplicationCaller(db, privateParameter)); + } + }; + const cpu = process.cpuUsage(), wall = performance.now(); + await (mode === "unowned" || mode === "disabled" ? action() : withDatabaseOperation(mode, action)); + const wallUs = (performance.now() - wall) * 1000, used = process.cpuUsage(cpu); + capture?.flush(); + if (calls !== count) throw new Error("Incomplete measurement"); + return { mode, count, cpuUsPerQuery: (used.user + used.system) / count, wallUsPerQuery: wallUs / count, + calls, entries: events.filter(event => Array.isArray(event.callers)).map(event => ({ owner: event.owner, calls: event.calls, callers: event.callers })) }; +} diff --git a/packages/db/src/__tests__/response-capture-overhead.mjs b/packages/db/src/__tests__/response-capture-overhead.mjs new file mode 100644 index 00000000000..fc8ec78ea68 --- /dev/null +++ b/packages/db/src/__tests__/response-capture-overhead.mjs @@ -0,0 +1,39 @@ +// Run from the repository root with Node 24. A pinned git source is materialized +// only in memory; no baseline production clone or runtime patch is retained. +import { execFileSync } from "node:child_process"; +import { mkdtemp, mkdir, rm } from "node:fs/promises"; +import { tmpdir, loadavg, cpus } from "node:os"; +import { join, resolve } from "node:path"; +import { pathToFileURL } from "node:url"; +import { build } from "esbuild"; + +const root = process.cwd(), base = process.argv[2], count = Number(process.argv[3] ?? 1000); +if (!base || !/^[a-f0-9]{40}$/.test(base) || !Number.isInteger(count) || count < 1 || count > 10000) + throw new Error("Usage: node packages/db/src/__tests__/response-capture-overhead.mjs BASELINE_SHA [queries<=10000]"); +const baseline = execFileSync("git", ["show", `${base}:packages/db/src/response-capture.ts`], { encoding: "utf8" }); +const directory = await mkdtemp(join(tmpdir(), "capture-overhead-")); +try { + const bundles = {}; + for (const variant of ["current", "candidate"]) { + const output = join(directory, variant, "server/dist-runtime/server.mjs"); + await mkdir(join(directory, variant, "server/dist-runtime"), { recursive: true }); + await build({ entryPoints: [resolve(root, "packages/db/src/__tests__/response-capture-bundle-fixture.ts")], + outfile: output, bundle: true, platform: "node", format: "esm", target: "node24", sourcemap: false, + plugins: variant === "current" ? [{ name: "pinned-baseline", setup(builder) { + builder.onLoad({ filter: /[/\\]response-capture\.ts$/ }, () => ({ contents: baseline, loader: "ts", resolveDir: resolve(root, "packages/db/src") })); + } }] : [] }); + bundles[variant] = await import(pathToFileURL(output).href); + } + console.log(JSON.stringify({ kind: "host", node: process.version, execPath: process.execPath, base, logicalCpus: cpus().length, loadavg: loadavg(), count, + boundary: "serial instrumented fake-driver process; real bundled Drizzle/capture; no network, database, output flush or assertions in timing" })); + for (const variant of ["current", "candidate"]) for (const mode of ["disabled", "unowned", "http.request", "response.presentation"]) + await bundles[variant].measureBundleCapture(mode, Math.min(count, 500)); + for (let round = 0; round < 5; round++) { + for (const mode of ["disabled", "unowned", "http.request", "response.presentation"]) { + for (const variant of round % 2 ? ["candidate", "current"] : ["current", "candidate"]) + console.log(JSON.stringify({ kind: "sample", round, variant, ...await bundles[variant].measureBundleCapture(mode, count) })); + } + } + const proof = await bundles.candidate.runBundleProof(); + console.log(JSON.stringify({ kind: "proof", ...proof })); +} finally { await rm(directory, { recursive: true, force: true }); } diff --git a/packages/db/src/response-capture-bundle.test.ts b/packages/db/src/response-capture-bundle.test.ts new file mode 100644 index 00000000000..6e93890b838 --- /dev/null +++ b/packages/db/src/response-capture-bundle.test.ts @@ -0,0 +1,51 @@ +import { mkdtemp, mkdir, readFile, readdir, rm } from "node:fs/promises"; +import { tmpdir } from "node:os"; +import { join } from "node:path"; +import { fileURLToPath, pathToFileURL } from "node:url"; +import { build } from "esbuild"; +import { expect, it } from "vitest"; + +it("keeps real application call sites when capture and Drizzle share a map-free runtime bundle", async () => { + const directory = await mkdtemp(join(tmpdir(), "capture-bundle-")); + try { + const output = join(directory, "server/dist-runtime/chunk-ABCDEFGH.mjs"); + await mkdir(join(directory, "server/dist-runtime"), { recursive: true }); + await build({ entryPoints: [fileURLToPath(new URL("./__tests__/response-capture-bundle-fixture.ts", import.meta.url))], + outfile: output, bundle: true, platform: "node", format: "esm", target: "node24", sourcemap: false }); + expect(await readdir(join(directory, "server/dist-runtime"))).toEqual(["chunk-ABCDEFGH.mjs"]); + const source = await readFile(output, "utf8"); + expect(source).toContain("function installDatabaseResponseCapture"); + expect(source).toContain("PgDialect = class"); + const lines = source.split("\n"); + const expectedLines = lines.flatMap((line, index) => (line.includes("return db.select(") || line.includes("return db.execute(")) ? [index + 1] : []); + expect(expectedLines).toHaveLength(4); + const result = await (await import(/* @vite-ignore */ pathToFileURL(output).href)).runBundleProof(); + for (const item of result.cases) { + expect(item.driverCalls).toBe(9); + const entries = item.events.filter((event: Record) => Array.isArray(event.callers)); + if (["disabled", "future", "expired"].includes(item.mode)) { + expect(item.stacks).toBe(0); + expect(entries).toEqual([]); + } else if (item.mode === "response.presentation") { + expect(item.stacks).toBe(0); + expect(entries.reduce((sum: number, entry: { calls: number }) => sum + entry.calls, 0)).toBe(9); + expect(entries.every((entry: { owner: string; callers: string[] }) => entry.owner === item.mode && entry.callers.length === 0)).toBe(true); + } else { + expect(item.stacks).toBe(9); + const located = entries.filter((entry: { callers: string[] }) => entry.callers.length > 0); + expect(entries.filter((entry: { callers: string[] }) => entry.callers.length === 0).reduce((sum: number, entry: { calls: number }) => sum + entry.calls, 0)).toBe(2); + expect(located.map((entry: { callers: string[] }) => Number(entry.callers[0]!.split(":")[1])).sort((a: number, b: number) => a - b)) + .toEqual(expectedLines); + expect(located.map((entry: { calls: number }) => entry.calls).sort()).toEqual([1, 1, 2, 3]); + for (const entry of located) { + expect(entry.callers).toHaveLength(1); + expect(entry.callers[0]).toMatch(/^dist-runtime\/chunk-ABCDEFGH\.mjs:\d+:\d+$/); + expect(entry.owner).toBe(item.mode === "unowned" ? "unattributed" : item.mode); + } + } + } + const serialized = JSON.stringify(result); + for (const privateValue of [directory, "00000000-0000", "firstApplicationCaller", "select ", "where ", "node_modules", "response-capture.ts"]) + expect(serialized).not.toContain(privateValue); + } finally { await rm(directory, { recursive: true, force: true }); } +}); diff --git a/packages/db/src/response-capture.test.ts b/packages/db/src/response-capture.test.ts index f22a5021c17..3ad00b55e31 100644 --- a/packages/db/src/response-capture.test.ts +++ b/packages/db/src/response-capture.test.ts @@ -87,6 +87,14 @@ describe("bounded database response capture", () => { "at f (/private/fixture/customer-file.js:7:9)", "at f (/app/server/src/services/../../customer-file.ts:8:1)"].join("\n"); expect(publicDatabaseCallers(stack)).toEqual(["services/example.ts:4:2", "routes/example.js:5:3"]); }); + it("keeps one static bundled anchor and rejects dynamic paths or untrusted driver anchors", () => { + expect(publicDatabaseCallers("at privateName (/app/server/dist-runtime/chunk-ABCDEFGH.mjs:12:34)\nat helper (/app/server/dist-runtime/server.mjs:56:78)", true)) + .toEqual(["dist-runtime/chunk-ABCDEFGH.mjs:12:34"]); + for (const path of ["customer-name.mjs", "chunk-ABCDEFGH.mjs?private=1", "chunk-ABCDEFGH.mjs#private", "../server.mjs", "nested/server.mjs", "server.mjs:0:1", "server.mjs:9999999999:1"]) { + expect(publicDatabaseCallers(`at privateName (/app/server/dist-runtime/${path}:12:34)`, true)).toEqual([]); + } + expect(publicDatabaseCallers("at f (/app/server/dist-runtime/server.mjs:12:34)")).toEqual([]); + }); it("leaves methods and identity unchanged when disabled", () => { vi.stubEnv("PAPERCLIP_DB_RESPONSE_CAPTURE_WINDOW", undefined); const db = { select: vi.fn(), transaction: vi.fn() }, select = db.select, transaction = db.transaction; diff --git a/packages/db/src/response-capture.ts b/packages/db/src/response-capture.ts index 64e1bcf2448..8f55c8e3010 100644 --- a/packages/db/src/response-capture.ts +++ b/packages/db/src/response-capture.ts @@ -34,11 +34,18 @@ export function responseCaptureWindow(value: string | undefined, now = Date.now( return { start, end }; } -export function publicDatabaseCallers(stack: string | undefined): string[] { +export function publicDatabaseCallers(stack: string | undefined, bundled = false): string[] { const callers: string[] = []; for (const line of (stack ?? "").split("\n")) { const match = line.match(/[/\\]server[/\\](?:src|dist)[/\\]((?:services|routes|modules|middleware)[/\\][A-Za-z0-9_./\\-]+\.[cm]?[jt]s):(\d+):(\d+)/); - if (!match) continue; + if (!match) { + const bundledMatch = line.match(/[/\\]server[/\\]dist-runtime[/\\]((?:server|index|chunk-[A-Z0-9]{8})\.mjs):([1-9]\d{0,8}):([1-9]\d{0,8})\)?$/); + // The wrapper boundary makes the first generated frame the application + // call site. Deeper frames may be capture/transaction helpers in this same + // chunk, so retain only this build-specific anchor without source maps. + if (bundledMatch && bundled) { callers.push(`dist-runtime/${bundledMatch[1]}:${bundledMatch[2]}:${bundledMatch[3]}`); break; } + continue; + } const relative = match[1]!.replaceAll("\\", "/"); if (relative.split("/").includes("..")) continue; const caller = `${relative}:${match[2]}:${match[3]}`; @@ -283,7 +290,15 @@ export function installDatabaseResponseCapture(db: T, schema: }); } } - function sqlMetadata(value: unknown): Metadata { + function callers(boundary: Function, bundled: boolean): string[] { + if (!capture!.active()) return []; + const owner = operationScope.getStore(); + if (owner && owner !== "http.request") return []; + const error: { stack?: string } = {}; + Error.captureStackTrace(error, boundary); + return publicDatabaseCallers(error.stack, bundled); + } + function sqlMetadata(value: unknown, boundary: Function): Metadata { const scoped = capture!.scope.getStore(); const text = typeof value === "string" ? value : ""; let table = "other"; @@ -292,15 +307,17 @@ export function installDatabaseResponseCapture(db: T, schema: } return scoped ? { ...scoped, table: scoped.table === "other" ? table : scoped.table } : { operation: text.match(/^\s*(select|insert|update|delete)\b/i)?.[1]?.toLowerCase() ?? "execute", - table, callers: capture!.active() && !operationScope.getStore() ? publicDatabaseCallers(new Error().stack) : [] }; + // Unscoped driver calls can come through bundled ORM helpers. Their + // generated locations are not trustworthy application construction sites. + table, callers: callers(boundary, false) }; } function client(value: unknown) { if ((!object(value) && typeof value !== "function") || capture!.clients.has(value)) return; capture!.clients.add(value); const target = value as Record; - replace(target, "unsafe", original => function (this: unknown, ...args: unknown[]) { + replace(target, "unsafe", original => function capturedUnsafe(this: unknown, ...args: unknown[]) { const result = Reflect.apply(original, this, args); - if (!capture!.expired()) { try { driverQuery(result, sqlMetadata(args[0])); } catch {} } + if (!capture!.expired()) { try { driverQuery(result, sqlMetadata(args[0], capturedUnsafe)); } catch {} } return result; }); for (const method of ["begin", "savepoint"]) { @@ -323,14 +340,14 @@ export function installDatabaseResponseCapture(db: T, schema: if (!object(value) || capture!.roots.has(value)) return; capture!.roots.add(value); for (const method of ["select", "selectDistinct", "selectDistinctOn", "insert", "update", "delete", "execute", "with"] as const) { - replace(value, method, original => function (this: unknown, ...args: unknown[]) { + replace(value, method, original => function capturedRoot(this: unknown, ...args: unknown[]) { const result = Reflect.apply(original, this, args); if (capture!.expired()) return result; try { if (method === "with") { root(result); return result; } const operation = method.startsWith("select") ? "select" : method; const metadata = { operation, table: operation === "select" || method === "execute" ? "other" : tableName(args[0]), - callers: capture!.active() && !operationScope.getStore() ? publicDatabaseCallers(new Error().stack) : [] }; + callers: callers(capturedRoot, true) }; if (operation === "select") factory(result, "from", metadata, true); else if (method === "insert") factory(result, "values", metadata); else if (method === "update") factory(result, "set", metadata);