mirror of
https://github.com/paperclipai/paperclip.git
synced 2026-11-11 05:11:49 +01:00
Record local journal bottleneck and retain diagnostic evidence
This commit is contained in:
Dotta committed
1 parent
e9b909015a
commit
75dbd64974
23 files changed
+1625
-4
No files matched your search
@@ -0,0 +1,42 @@
|
||||
# Local journal diagnostic (2026-11-03)
|
||||
|
||||
The original local-process, 100-run browser fixture could not qualify its baseline. All 100 providers became ready and emitted all 51,200 measured deltas, but only 7 of the foreground run's 512 markers became visible within the 120-second streaming budget. The experiment failed; later database counts do not establish delivery within that budget. No candidate result or throughput gain is claimed for this workload.
|
||||
|
||||
The fixture used baseline `83b5f7d486e70e484acd9a41bc957054f4e10175` and driver `f5c560d80d9d4ee089297d3b3f300c052db17c9e`. A separate instrumented baseline replay investigated the limiting stage. Its profiles are **diagnostic only** and excluded from acceptance measurements.
|
||||
|
||||
## What the profiles establish
|
||||
|
||||
The early 31.063-second profile was 84.33% idle by weighted samples. A diagnostic flush accounted for 4.40%, making observer overhead material. This window does not establish a CPU bottleneck throughout the experiment.
|
||||
|
||||
A separate 30.847-second profile captured the hot queue after the browser fixture had already failed. Synchronous `fsync` occupied 45.38% of weighted self samples; the parent-directory sync frame occupied 48.09% inclusively, and `withStagedPrivateWrite` occupied 67.43% inclusively. These inclusive percentages overlap and must not be added. They identify costly work in the existing local raw journal, outside the event-ingestion transaction.
|
||||
|
||||
The serialization wrapper occupied 21.26% of weighted self samples, but the probe also counts bytes there. That figure is **not** pure production JSON-encoding CPU. Async file-sync elapsed time also overlaps across operations and includes callback scheduling; it is not main-thread blocked time. The retained PostgreSQL observations distinguish idle client waits from idle transactions.
|
||||
|
||||
V8 weighted stack samples include idle and native blocking time. They are not a measure of process CPU utilization. The two windows describe different phases, and the latter cannot be substituted for an unprofiled successful run.
|
||||
|
||||
## Scope of the subsequent experiment
|
||||
|
||||
The supported remote-controller path already avoids full local file-journal rewrites for ordinary externally checkpointed output. The revised browser fixture uses that normal path for streaming and keeps a separate local Stop case. It changes neither transport recovery policy nor the ingestion code to bypass persistence. All compared application revisions receive the same fixture, and its baseline must qualify before candidate measurements begin.
|
||||
|
||||
Any later remote-streaming improvement is scoped to that tested configuration. It does not establish that the original local-process, 100-run workload passes. Ordinary raw transport ACKs still do not universally guarantee database durability. Database receipts and consequential side effects retain their commit barriers.
|
||||
|
||||
## Inspect the evidence
|
||||
|
||||
The [manifest](native-event-ingestion-2026-11-03/local-journal-diagnostic/manifest.json) records exact original hashes and compressed sizes. Inspect the [failed browser report](native-event-ingestion-2026-11-03/local-journal-diagnostic/native-ingestion-evidence.json.gz), [post-failure database counts](native-event-ingestion-2026-11-03/local-journal-diagnostic/measured-delta-counts.json.gz), [owned-process cleanup](native-event-ingestion-2026-11-03/local-journal-diagnostic/external-cleanup-receipt.json.gz), and [read-only forensics](native-event-ingestion-2026-11-03/local-journal-diagnostic/forensic-receipt.json.gz) alongside the two raw profiles and [PostgreSQL observations](native-event-ingestion-2026-11-03/local-journal-diagnostic/pg-live.ndjson.gz). The [weighted summary](native-event-ingestion-2026-11-03/local-journal-diagnostic/weighted-cpu-summary.json) can be reproduced with:
|
||||
|
||||
```sh
|
||||
python3 scripts/native-ingestion/inspect-cpu-profile.py \
|
||||
doc/benchmarks/native-event-ingestion-2026-11-03/local-journal-diagnostic/focused-100-run-app.cpuprofile.gz \
|
||||
doc/benchmarks/native-event-ingestion-2026-11-03/local-journal-diagnostic/postfailure-hotqueue-app.cpuprofile.gz
|
||||
```
|
||||
|
||||
The separate replay's [app counters](native-event-ingestion-2026-11-03/local-journal-diagnostic/app-46347.ndjson.gz) contain 2,105 samples over 596.787 seconds. The observed upstream normalized queue reaches 22,992 events and sampled RSS reaches 3,234,127,872 bytes. The final sample records 36,552 full snapshots encoding 13,740,085,068 bytes, with 50.971 seconds of serialization elapsed and 149.033 seconds of synchronous directory-sync elapsed. Those are cumulative diagnostic observations, not accepted throughput or user-latency measurements. The normalized queue is upstream of the bounded collector, so the collector's limit alone cannot bound it.
|
||||
|
||||
The [counter summary](native-event-ingestion-2026-11-03/local-journal-diagnostic/app-counter-summary.json), [diagnostic command](native-event-ingestion-2026-11-03/local-journal-diagnostic/diagnostic-command.json), same-directory original instrumentation sources and [quiet return](native-event-ingestion-2026-11-03/local-journal-diagnostic/diagnostic-quiet-returned.json) make the observer and cleanup inspectable. Reproduce the counter summary with:
|
||||
|
||||
```sh
|
||||
python3 scripts/native-ingestion/inspect-app-metrics.py \
|
||||
doc/benchmarks/native-event-ingestion-2026-11-03/local-journal-diagnostic/app-46347.ndjson.gz
|
||||
```
|
||||
|
||||
This diagnostic is not a production improvement or deployment-qualification claim.
|
||||
@@ -30,7 +30,7 @@
|
||||
},
|
||||
"workloadSha256": "7c8abf644080c5e75f07ed7c1925e8d40a0c573a7160cbf0b5c99c06135b321a",
|
||||
"units": {
|
||||
"ordinaryTimedSample": "512 append attempts:16 consecutive groups of32; replay attempts create0new events",
|
||||
"ordinaryTimedSample": "512 append attempts:16 consecutive groups of32; mixed replay samples create256new events and reuse256duplicate receipts",
|
||||
"lateGapTimedSample": "one gap-closing append, structural-only latency gate",
|
||||
"ownerCpu": "benchmark process only",
|
||||
"databaseCpu": "PostgreSQL backend process,10msclockresolution",
|
||||
|
||||
@@ -1,12 +1,12 @@
|
||||
# Native event ingestion measurements (2026-11-03)
|
||||
|
||||
Cursor service acceptance has passed. Application and batching acceptance remain in progress. These measurements use the actual append service and real PostgreSQL on a dedicated quiet host. They establish a local service improvement.
|
||||
Historical cursor service acceptance passed at B0 `83b5f7d` and B1 `7922802f`. The current common-base revisions require fresh qualification; their first A/A run failed the frozen noise gates, so no candidate comparison has started. Application and batching acceptance remain in progress. These measurements use the actual append service and real PostgreSQL on a dedicated quiet host. They establish a local service improvement.
|
||||
|
||||
The long-history cursor/range operations are bounded; replay still performs its required indexed event identity lookup. At 100k seeded events, the separately recorded baseline plans examine about 100,000 source entries; the candidate performs a one-row identity lookup and bounded projection work. The raw reports retain the SQL and plans.
|
||||
|
||||
## Cursor comparison
|
||||
|
||||
Each ordinary sample contains **512 append attempts** (16 groups of 32). Five baseline/candidate pairs alternate order; two warmups, seeding, rebuild preparation and verification are excluded. Replay attempts reuse receipts and create no new events. The table reports median wall time per 512 attempts, not individual event latency.
|
||||
Each ordinary sample contains **512 append attempts** (16 groups of 32). Five baseline/candidate pairs alternate order; two warmups, seeding, rebuild preparation and verification are excluded. The mixed replay case contains 256 new events and 256 exact duplicates; duplicate attempts reuse receipts and allocate nothing. The table reports median wall time per 512 attempts, not individual event latency.
|
||||
|
||||
| Seeded history / case | B0 ms/512 | B1 ms/512 | Change | Pairs beating noise | A/A noise | SQL calls/attempt B0 → B1 |
|
||||
| --- | ---: | ---: | ---: | ---: | ---: | ---: |
|
||||
@@ -35,6 +35,6 @@ See [experiment commands](../../scripts/native-ingestion/README.md) and the [imp
|
||||
| [service-aa-b0.json.gz](native-event-ingestion-2026-11-03/service-aa-b0.json.gz) | `92ae98cd5bb22b4bf1b6425150b2615d280d046c3d24ca341358847eede28fe5` |
|
||||
| [service-b0-b1.json.gz](native-event-ingestion-2026-11-03/service-b0-b1.json.gz) | `11d7f4c5fcfbeab39d9b38224aa151a3cf6430bb103c4d45b847789e72cb2899` |
|
||||
|
||||
Use `gzip -dc <report.json.gz>` to inspect the complete original JSON. Its byte-for-byte SHA256 is recorded above and in the summary. No p99 is inferred from five service samples. The initial noisy calibration and failed browser qualifications remain excluded; the final report will record their failure ledger alongside the application comparisons.
|
||||
Use `gzip -dc <report.json.gz>` to inspect the complete original JSON. Its byte-for-byte SHA256 is recorded above and in the summary. No p99 is inferred from five service samples. The initial noisy calibration and failed browser qualifications remain excluded; the final report will record their failure ledger alongside the application comparisons. The [local-journal diagnostic](2026-11-03-native-event-ingestion-local-journal.md) records a separate baseline bottleneck and its measurement limits.
|
||||
|
||||
Application streaming, control responsiveness, batching, profile-only backlog/resource diagnostics, final delivery revisions and current-head CI remain pending. The live-provider functional journey has passed separately. This report makes no deployed production or 10,000-agent qualification claim.
|
||||
+10
@@ -0,0 +1,10 @@
|
||||
{
|
||||
"diagnosticOnly": true,
|
||||
"role": "app",
|
||||
"pid": 46347,
|
||||
"parentPid": 46338,
|
||||
"startedAtMs": 1793741799526,
|
||||
"cwd": "/home/ubuntu/native-ingestion/baseline",
|
||||
"configPath": "/tmp/paperclip-e2e-home-4gIRB7/instances/playwright-e2e/config.json",
|
||||
"disclosure": "Profile-only instrumentation; never use these timings for unprofiled acceptance"
|
||||
}
|
||||
BIN
Binary file not shown.
+107
@@ -0,0 +1,107 @@
|
||||
{
|
||||
"scope": "Instrumented failed historical local-process baseline replay; no acceptance comparison",
|
||||
"sampleCount": 2105,
|
||||
"firstAtMs": 1793741807203,
|
||||
"lastAtMs": 1793742403990,
|
||||
"sampleSpanMs": 596787,
|
||||
"maxObservedNormalizedQueueDepth": 22992,
|
||||
"maxObservedRssBytes": 3234127872,
|
||||
"lastSample": {
|
||||
"atMs": 1793742403990,
|
||||
"kind": "app-sample",
|
||||
"intervalMs": 396.07483800000045,
|
||||
"cpuMicros": 126479,
|
||||
"rssBytes": 1705947136,
|
||||
"heapUsedBytes": 1085192912,
|
||||
"externalBytes": 93966649,
|
||||
"eventLoopUtilization": 1,
|
||||
"eventLoopDelayCount": 3,
|
||||
"eventLoopDelayMaxMs": 63.143935,
|
||||
"eventLoopDelayP95Ms": 63.143935,
|
||||
"actualNormalizedQueueDepth": 22992,
|
||||
"liveQueueObjects": 112,
|
||||
"queuePeakSinceSample": 22992,
|
||||
"counters": {
|
||||
"normalizedEvents": 34720,
|
||||
"committedEvents": 9197,
|
||||
"duplicateReceipts": 0,
|
||||
"committedMarkers": 7869,
|
||||
"sqlCalls": 232476,
|
||||
"begins": 17190,
|
||||
"commits": 17183,
|
||||
"rollbacks": 0,
|
||||
"savepoints": 10172,
|
||||
"releases": 0,
|
||||
"queueHighWater": 22992
|
||||
},
|
||||
"filesystem": {
|
||||
"fullSnapshotSerialization": {
|
||||
"calls": 36552,
|
||||
"successes": 36552,
|
||||
"errors": 0,
|
||||
"millis": 50971.382787009425,
|
||||
"bytesAttempted": 13740085068
|
||||
},
|
||||
"atomicWrite": {
|
||||
"calls": 3216,
|
||||
"successes": 3216,
|
||||
"errors": 0,
|
||||
"millis": 1035.6515519998793,
|
||||
"bytesAttempted": 515122207
|
||||
},
|
||||
"atomicFileFsync": {
|
||||
"calls": 3216,
|
||||
"successes": 3216,
|
||||
"errors": 0,
|
||||
"millis": 16744.279251000335,
|
||||
"bytesAttempted": 0
|
||||
},
|
||||
"directoryFsync": {
|
||||
"calls": 36720,
|
||||
"successes": 36720,
|
||||
"errors": 0,
|
||||
"millis": 149033.220497999,
|
||||
"bytesAttempted": 0
|
||||
},
|
||||
"stagedWrite": {
|
||||
"calls": 33537,
|
||||
"successes": 33536,
|
||||
"errors": 0,
|
||||
"millis": 2727536.487238994,
|
||||
"bytesAttempted": 13208582362
|
||||
},
|
||||
"stagedFileFsync": {
|
||||
"calls": 33536,
|
||||
"successes": 33532,
|
||||
"errors": 0,
|
||||
"millis": 3608792.627418981,
|
||||
"bytesAttempted": 0
|
||||
}
|
||||
},
|
||||
"sqlVerbs": {
|
||||
"select": 150235,
|
||||
"create": 1314,
|
||||
"begin": 17190,
|
||||
"alter": 1090,
|
||||
"insert": 12608,
|
||||
"commit": 17183,
|
||||
"other": 97,
|
||||
"drop": 77,
|
||||
"do": 624,
|
||||
"update": 16324,
|
||||
"with": 5319,
|
||||
"delete": 238,
|
||||
"analyze": 2,
|
||||
"savepoint": 10172,
|
||||
"set": 3
|
||||
},
|
||||
"fatalDiagnosticErrors": 0
|
||||
},
|
||||
"limits": [
|
||||
"Queue counts the normalized upstream queue, excluding collector/pending-read/in-flight/transport queues",
|
||||
"Observed peaks are sample based",
|
||||
"Cumulative filesystem elapsed times overlap across async operations and include scheduling; do not sum or interpret async sync elapsed as blocked CPU",
|
||||
"Serialization elapsed ends before byte-counting probe; sampled wrapper residence includes byte counting",
|
||||
"Diagnostic instrumentation and its observer work are excluded from acceptance"
|
||||
]
|
||||
}
|
||||
+21
@@ -0,0 +1,21 @@
|
||||
{
|
||||
"diagnosticOnly": true,
|
||||
"tree": "B0",
|
||||
"sourceRevision": "83b5f7d486e70e484acd9a41bc957054f4e10175",
|
||||
"childPid": 46312,
|
||||
"startedAtMs": 1793741797774,
|
||||
"env": {
|
||||
"PAPERCLIP_E2E_PORT": "46821",
|
||||
"PAPERCLIP_INGESTION_SMOKE": "0",
|
||||
"PAPERCLIP_INGESTION_VARIANT": "PROFILE-ONLY-B0",
|
||||
"PAPERCLIP_INGESTION_APP_ROOT": "/home/ubuntu/native-ingestion/baseline",
|
||||
"PAPERCLIP_INGESTION_EVIDENCE_DIR": "/tmp/native-ingestion-local-journal-profile-f5",
|
||||
"PAPERCLIP_NATIVE_INGESTION_DIAGNOSTIC_DIR": "/tmp/native-ingestion-local-journal-profile-f5/profile",
|
||||
"PAPERCLIP_NATIVE_INGESTION_DIAGNOSTIC_CODEX_COMMAND": "/tmp/native-ingestion-local-journal-profile-f5/profile/codex-profile-only",
|
||||
"PAPERCLIP_NATIVE_INGESTION_DIAGNOSTIC_FS": "1",
|
||||
"PAPERCLIP_NATIVE_INGESTION_DIAGNOSTIC_INSPECTOR": "1",
|
||||
"PAPERCLIP_INGESTION_DRIVER_DEPENDENCIES": "Driver-only tooling links to frozen B1 locked dependencies; each app owns independent installs",
|
||||
"PAPERCLIP_INGESTION_SERVER_COMMAND": "node --import ./server/node_modules/tsx/dist/loader.mjs '/home/ubuntu/native-ingestion/harness/tests/e2e/fixtures/native-ingestion-bootstrap.mjs' && node --cpu-prof --cpu-prof-dir='/tmp/native-ingestion-local-journal-profile-f5/profile/cpu' --import '/home/ubuntu/native-ingestion/helpers/native-ingestion-diagnostic-preload.mjs' --import ./server/node_modules/tsx/dist/loader.mjs server/dist/index.js"
|
||||
},
|
||||
"preloadSha256": "98bf2eb6994f13d6957535f5799b5994dda8920af97c2965c1d8baab925d3386"
|
||||
}
|
||||
+12
@@ -0,0 +1,12 @@
|
||||
{
|
||||
"at": "2026-11-03T21:51:30.093116+00:00",
|
||||
"dataDirectory": "/tmp/paperclip-e2e-home-4gIRB7/instances/playwright-e2e/db",
|
||||
"postgresStop": "already-stopped",
|
||||
"remainingOwnedRelevantProcesses": [],
|
||||
"ports": {
|
||||
"54329": "closed",
|
||||
"46821": "closed"
|
||||
},
|
||||
"cleanupComplete": true,
|
||||
"syncComplete": true
|
||||
}
|
||||
BIN
Binary file not shown.
BIN
Binary file not shown.
BIN
Binary file not shown.
+217
@@ -0,0 +1,217 @@
|
||||
import assert from 'node:assert/strict';
|
||||
import { createHash } from 'node:crypto';
|
||||
import { appendFileSync, mkdirSync, readFileSync, writeFileSync } from 'node:fs';
|
||||
import { registerHooks } from 'node:module';
|
||||
import path from 'node:path';
|
||||
import { fileURLToPath } from 'node:url';
|
||||
import { monitorEventLoopDelay, performance } from 'node:perf_hooks';
|
||||
import inspector from 'node:inspector';
|
||||
|
||||
const directory = process.env.PAPERCLIP_NATIVE_INGESTION_DIAGNOSTIC_DIR;
|
||||
assert.equal(process.env.NODE_ENV, 'test', 'Diagnostic instrumentation is test-only');
|
||||
assert.ok(directory?.startsWith('/private/tmp/') || directory?.startsWith('/tmp/'), 'Use an owned private temporary diagnostic directory');
|
||||
mkdirSync(directory, { recursive: true });
|
||||
const role = process.argv.includes('--ingestion-stream-fixture') ? 'provider'
|
||||
: process.argv.some(value => /\/server\/dist\/index\.js$/.test(value)) ? 'app' : 'other';
|
||||
const file = path.join(directory, `${role}-${process.pid}.ndjson`);
|
||||
const metadata = { diagnosticOnly: true, role, pid: process.pid, parentPid: process.ppid, startedAtMs: Date.now(),
|
||||
cwd: process.cwd(), configPath: role === 'app' ? process.env.PAPERCLIP_CONFIG : undefined,
|
||||
disclosure: 'Profile-only instrumentation; never use these timings for unprofiled acceptance' };
|
||||
writeFileSync(path.join(directory, `${role}-${process.pid}.metadata.json`), JSON.stringify(metadata, null, 2));
|
||||
const queue = [];
|
||||
const record = value => queue.push({ atMs: Date.now(), ...value });
|
||||
function flush() { if (queue.length) appendFileSync(file, queue.splice(0).map(value => JSON.stringify(value)).join('\n') + '\n'); }
|
||||
const markerPattern = /INGEST_([a-z0-9]+)_(\d+)_(\d+)_(\d+)/g;
|
||||
const markers = text => {
|
||||
if (typeof text !== 'string') return [];
|
||||
const compact = [...text.matchAll(/\[([a-z0-9]{2})([a-z0-9]{1,3})\]/g)].map(match => ({ markerCode: match[1], index: Number.parseInt(match[2], 36) }));
|
||||
if (compact.length) return compact;
|
||||
return [...text.matchAll(markerPattern)].map(match => ({ nonce: match[1], index: Number(match[2]), intendedMs: Number(match[3]), emittedMs: Number(match[4]) }));
|
||||
};
|
||||
process.once('exit', flush);
|
||||
setInterval(flush, 250).unref();
|
||||
|
||||
if (role === 'provider') {
|
||||
for (const signal of ['SIGINT', 'SIGTERM']) {
|
||||
const finish = () => {
|
||||
flush();
|
||||
process.removeListener(signal, finish);
|
||||
if (process.listenerCount(signal) === 0) process.kill(process.pid, signal);
|
||||
};
|
||||
process.once(signal, finish);
|
||||
}
|
||||
const original = process.stdout.write;
|
||||
let pending = '';
|
||||
process.stdout.write = function (chunk, ...args) {
|
||||
const result = original.call(this, chunk, ...args);
|
||||
pending += Buffer.isBuffer(chunk) ? chunk.toString('utf8') : String(chunk);
|
||||
for (;;) {
|
||||
const end = pending.indexOf('\n'); if (end < 0) break;
|
||||
const line = pending.slice(0, end); pending = pending.slice(end + 1);
|
||||
let message; try { message = JSON.parse(line); } catch { continue; }
|
||||
if (message.method === 'item/agentMessage/delta') {
|
||||
for (const marker of markers(message.params?.delta)) record({ kind: 'provider-emission', ...marker });
|
||||
} else if (message.method === 'turn/completed') {
|
||||
record({ kind: 'provider-terminal' });
|
||||
flush(); // Provider teardown can precede the periodic diagnostic flush.
|
||||
}
|
||||
}
|
||||
return result;
|
||||
};
|
||||
} else if (role === 'app') {
|
||||
// The production provider environment sanitizer intentionally strips loader
|
||||
// options. A separate test-only command wrapper explicitly starts the
|
||||
// diagnostic observer; production environment policy stays untouched.
|
||||
const providerCommand = process.env.PAPERCLIP_NATIVE_INGESTION_DIAGNOSTIC_CODEX_COMMAND;
|
||||
assert.ok(providerCommand?.startsWith(directory + '/'), 'An owned profile-only provider wrapper is required');
|
||||
const key = Symbol.for('paperclip.native-ingestion.diagnostic');
|
||||
const queues = new Set();
|
||||
const committed = new Set();
|
||||
const fatalErrors = [];
|
||||
const filesystem = {};
|
||||
const fsObservation = process.env.PAPERCLIP_NATIVE_INGESTION_DIAGNOSTIC_FS === '1';
|
||||
const counters = { normalizedEvents: 0, committedEvents: 0, duplicateReceipts: 0, committedMarkers: 0,
|
||||
sqlCalls: 0, begins: 0, commits: 0, rollbacks: 0, savepoints: 0, releases: 0, queueHighWater: 0 };
|
||||
const sqlVerbs = {};
|
||||
let queuePeakSinceSample = 0;
|
||||
function queueDepth() {
|
||||
let depth = 0, active = 0;
|
||||
for (const reference of queues) {
|
||||
const value = reference.deref();
|
||||
if (!value) { queues.delete(reference); continue; }
|
||||
depth += value.__nativeIngestionDiagnosticDepth(); active++;
|
||||
}
|
||||
return { depth, active };
|
||||
}
|
||||
globalThis[key] = {
|
||||
serialize(candidate) {
|
||||
const row = filesystem.fullSnapshotSerialization ??= { calls: 0, successes: 0, errors: 0, millis: 0, bytesAttempted: 0 };
|
||||
row.calls++; const started = performance.now(); let value;
|
||||
try { value = JSON.stringify(candidate); row.successes++; }
|
||||
catch (error) { row.errors++; throw error; }
|
||||
finally { row.millis += performance.now() - started; }
|
||||
row.bytesAttempted += typeof value === 'string' ? Buffer.byteLength(value) : 0;
|
||||
return value;
|
||||
},
|
||||
syncWork(name, work, bytes = 0) {
|
||||
const row = filesystem[name] ??= { calls: 0, successes: 0, errors: 0, millis: 0, bytesAttempted: 0 };
|
||||
row.calls++; row.bytesAttempted += bytes; const began = performance.now();
|
||||
try { const value = work(); row.successes++; return value; } catch (error) { row.errors++; throw error; }
|
||||
finally { row.millis += performance.now() - began; }
|
||||
},
|
||||
async asyncWork(name, work, bytes = 0) {
|
||||
const row = filesystem[name] ??= { calls: 0, successes: 0, errors: 0, millis: 0, bytesAttempted: 0 };
|
||||
row.calls++; row.bytesAttempted += bytes; const began = performance.now();
|
||||
try { const value = await work(); row.successes++; return value; } catch (error) { row.errors++; throw error; }
|
||||
finally { row.millis += performance.now() - began; }
|
||||
},
|
||||
registerQueue(value) { queues.add(new WeakRef(value)); },
|
||||
observeQueue() {
|
||||
const { depth } = queueDepth();
|
||||
queuePeakSinceSample = Math.max(queuePeakSinceSample, depth);
|
||||
counters.queueHighWater = Math.max(counters.queueHighWater, depth);
|
||||
},
|
||||
normalized(event) { counters.normalizedEvents++; },
|
||||
postCommit(event, disposition) { try {
|
||||
if (disposition === 'duplicate') { counters.duplicateReceipts++; return; }
|
||||
assert.equal(disposition, 'committed');
|
||||
const identity = `${event.runId}:${event.sourceInstanceId}:${event.sourceEventId}`;
|
||||
assert.equal(committed.has(identity), false, 'A committed source identity was observed twice');
|
||||
committed.add(identity); counters.committedEvents++;
|
||||
if (event.eventType !== 'item.delta') return;
|
||||
for (const marker of markers(event.payload?.text)) {
|
||||
counters.committedMarkers++; record({ kind: 'postcommit-marker', runId: event.runId, sourceSeq: event.sourceSeq,
|
||||
identitySha256: createHash('sha256').update(identity).digest('hex'), ...marker });
|
||||
}
|
||||
} catch (error) {
|
||||
// The existing persistence observer has a deliberately non-consequential
|
||||
// catch. Persist an explicit fatal flag instead of trusting propagation.
|
||||
const message = String(error.message ?? error);
|
||||
fatalErrors.push(message); record({ kind: 'diagnostic-fatal', message });
|
||||
}
|
||||
},
|
||||
sql(statement) {
|
||||
counters.sqlCalls++;
|
||||
const verb = statement.trim().match(/^[a-z]+/i)?.[0].toLowerCase() ?? 'other';
|
||||
sqlVerbs[verb] = (sqlVerbs[verb] ?? 0) + 1;
|
||||
if (verb === 'begin') counters.begins++;
|
||||
else if (verb === 'commit') counters.commits++;
|
||||
else if (verb === 'rollback') counters.rollbacks++;
|
||||
else if (verb === 'savepoint') counters.savepoints++;
|
||||
else if (verb === 'release') counters.releases++;
|
||||
},
|
||||
};
|
||||
const call = `globalThis[Symbol.for('paperclip.native-ingestion.diagnostic')]`;
|
||||
const allowed = {
|
||||
queue: new Set(['f8cb9fd06a567831cff886251c79eb73810a83d1384fb2b61851587a30832869']),
|
||||
port: new Set(['49a971a961d831dc4dbea39c715abb371609464797bbfcc58ac911792d8b945c', 'd3cf1203feb7f0b74c6799a289799990b932a837475e857732c7340876fd4f66']),
|
||||
postgres: new Set(['b57261592f135d127b8e7267c78981eb2c5f4751259641b782ba621b89d939d1']),
|
||||
resolver: new Set(['92031b6800bfb2356812d6fdc28af89143e1ffea37d2060879515d04667c5f3c']),
|
||||
core: new Set(['15bffae6e51d1e07f3635d37ce3fa2e8af18783b93331b477deeb82908aab212']),
|
||||
staged: new Set(['cd3a3f09c0890e26d57ca18def4890874f985f7a8c571ad4b92d4ed2578c0554']),
|
||||
};
|
||||
function replaceExactly(source, anchor, replacement) {
|
||||
assert.equal(source.split(anchor).length - 1, 1, `Diagnostic anchor must occur exactly once: ${anchor}`);
|
||||
return source.replace(anchor, replacement);
|
||||
}
|
||||
registerHooks({ load(url, context, nextLoad) {
|
||||
let type;
|
||||
if (/\/server\/dist\/vendor\/paperclip-runner\/drivers\/codex\/codex-session-state\.js$/.test(url)) type = 'queue';
|
||||
else if (/\/server\/dist\/services\/native-runtime\/paperclip-control-plane-port\.js$/.test(url)) type = 'port';
|
||||
else if (/\/postgres\/src\/connection\.js$/.test(url)) type = 'postgres';
|
||||
else if (/\/server\/dist\/vendor\/paperclip-runner\/drivers\/codex\/codex-command\.js$/.test(url)) type = 'resolver';
|
||||
else if (fsObservation && /\/server\/dist\/vendor\/paperclip-runner\/control-plane\/durable-prp-control-plane\.js$/.test(url)) type = 'core';
|
||||
else if (fsObservation && /\/server\/dist\/vendor\/paperclip-runner\/control-plane\/staged-private-write\.js$/.test(url)) type = 'staged';
|
||||
if (!type) return nextLoad(url, context);
|
||||
const original = readFileSync(fileURLToPath(url), 'utf8');
|
||||
const sha256 = createHash('sha256').update(original).digest('hex');
|
||||
assert.ok(allowed[type].has(sha256), `Unknown compiled ${type} artifact: ${sha256}`);
|
||||
let source = original;
|
||||
if (type === 'queue') {
|
||||
source = replaceExactly(source, 'class AsyncQueue {', `class AsyncQueue {\nconstructor() { ${call}.registerQueue(this); }\n__nativeIngestionDiagnosticDepth() { return this.#values.length; }`);
|
||||
source = replaceExactly(source, 'const waiter = this.#waiters.shift();', `${call}.normalized(value);\nconst waiter = this.#waiters.shift();`);
|
||||
source = replaceExactly(source, 'this.#values.push(value);', `{ this.#values.push(value); ${call}.observeQueue(); }`);
|
||||
} else if (type === 'port') {
|
||||
source = replaceExactly(source, 'await this.#onEventPersistence?.(', `${call}.postCommit(event, persisted.disposition);\nawait this.#onEventPersistence?.(`);
|
||||
} else if (type === 'postgres') {
|
||||
source = replaceExactly(source, "typeof options.debug === 'function' && options.debug(id, string, parameters, types)", `${call}.sql(string)\n typeof options.debug === 'function' && options.debug(id, string, parameters, types)`);
|
||||
} else if (type === 'core') {
|
||||
assert.equal(source.split('JSON.stringify(candidate)').length - 1, 3, 'All three full-candidate serialization sites must match');
|
||||
source = source.replaceAll('JSON.stringify(candidate)', `${call}.serialize(candidate)`);
|
||||
source = replaceExactly(source, ' fsyncSync(descriptor);\n }\n finally {', ` ${call}.syncWork('directoryFsync', () => fsyncSync(descriptor));\n }\n finally {`);
|
||||
source = replaceExactly(source, ' fsyncSync(descriptor);', ` ${call}.syncWork('atomicFileFsync', () => fsyncSync(descriptor));`);
|
||||
source = replaceExactly(source, ' writeFileSync(descriptor, contents, "utf8");', ` ${call}.syncWork('atomicWrite', () => writeFileSync(descriptor, contents, "utf8"), Buffer.byteLength(contents));`);
|
||||
} else if (type === 'staged') {
|
||||
source = replaceExactly(source, ' await file.writeFile(contents, "utf8");', ` await ${call}.asyncWork('stagedWrite', () => file.writeFile(contents, "utf8"), Buffer.byteLength(contents));`);
|
||||
source = replaceExactly(source, ' await file.sync();', ` await ${call}.asyncWork('stagedFileFsync', () => file.sync());`);
|
||||
} else {
|
||||
source = `export const resolveCodexCommand = () => ${JSON.stringify(providerCommand)}; export const resolvePinnedCodexCommand = resolveCodexCommand;`;
|
||||
}
|
||||
record({ kind: 'instrumented-module', type, sha256, file: fileURLToPath(url) });
|
||||
return { format: 'module', shortCircuit: true, source };
|
||||
} });
|
||||
const delay = monitorEventLoopDelay({ resolution: 20 }); delay.enable();
|
||||
let previousCpu = process.cpuUsage(), previousTime = performance.now(), previousElu = performance.eventLoopUtilization();
|
||||
const sample = () => {
|
||||
const now = performance.now(), currentCpu = process.cpuUsage(), currentElu = performance.eventLoopUtilization();
|
||||
const memory = process.memoryUsage(), actualQueue = queueDepth();
|
||||
record({ kind: 'app-sample', intervalMs: now - previousTime, cpuMicros: currentCpu.user + currentCpu.system - previousCpu.user - previousCpu.system,
|
||||
rssBytes: memory.rss, heapUsedBytes: memory.heapUsed, externalBytes: memory.external,
|
||||
eventLoopUtilization: performance.eventLoopUtilization(currentElu, previousElu).utilization,
|
||||
eventLoopDelayCount: delay.count, eventLoopDelayMaxMs: delay.count ? delay.max / 1e6 : null,
|
||||
eventLoopDelayP95Ms: delay.count ? delay.percentile(95) / 1e6 : null,
|
||||
actualNormalizedQueueDepth: actualQueue.depth, liveQueueObjects: actualQueue.active, queuePeakSinceSample,
|
||||
counters: { ...counters }, filesystem: structuredClone(filesystem), sqlVerbs: { ...sqlVerbs }, fatalDiagnosticErrors: fatalErrors.length });
|
||||
queuePeakSinceSample = 0; previousCpu = currentCpu; previousTime = now; previousElu = currentElu; delay.reset();
|
||||
};
|
||||
setInterval(sample, 250).unref();
|
||||
process.once('exit', () => { sample(); flush(); });
|
||||
if (process.env.PAPERCLIP_NATIVE_INGESTION_DIAGNOSTIC_INSPECTOR === '1') {
|
||||
inspector.open(0, '127.0.0.1');
|
||||
writeFileSync(path.join(directory, `app-${process.pid}.inspector.json`), JSON.stringify({ diagnosticOnly: true, pid: process.pid, url: inspector.url() }));
|
||||
}
|
||||
record({ kind: 'diagnostic-disclosure', queue: 'Actual private normalized AsyncQueue buffered values; excludes runtime collector, iterator pending read, in-flight append and transport queue',
|
||||
sql: 'All PostgreSQL protocol query-build attempts, transaction and savepoint commands included; parameters and SQL text are never logged',
|
||||
commit: 'Existing port persistence-observation callsite after outer database transaction resolves; callback timestamp is an upper bound on commit time',
|
||||
overhead: 'Queue observation scans weak references after every buffered push; diagnostic overhead is intentionally excluded from acceptance measurements' });
|
||||
}
|
||||
+224
@@ -0,0 +1,224 @@
|
||||
import assert from 'node:assert/strict';
|
||||
import { spawn, execFileSync } from 'node:child_process';
|
||||
import { createHash } from 'node:crypto';
|
||||
import { readdir, readFile, writeFile, mkdir, open } from 'node:fs/promises';
|
||||
import net from 'node:net';
|
||||
import path from 'node:path';
|
||||
|
||||
const arg = name => process.argv.find(value => value.startsWith(`--${name}=`))?.slice(name.length + 3);
|
||||
const root = arg('root') ?? process.cwd();
|
||||
const harnessRoot = arg('harness-root') ?? root;
|
||||
const trees = { B0: arg('b0-root') ?? '/private/tmp/paperclip-native-event-baseline', B1: root,
|
||||
B2: arg('b2-root') ?? '/private/tmp/paperclip-native-event-batching' };
|
||||
const tree = arg('tree'), smoke = process.argv.includes('--smoke');
|
||||
const out = arg('output');
|
||||
if (!process.argv.includes('--execute')) {
|
||||
console.log('PROFILE ONLY; no load launched. After quiet-window release: node /private/tmp/native-ingestion-diagnostic-run.mjs --execute --tree=B0|B1|B2 --output=/private/tmp/<new-directory> [--smoke]');
|
||||
process.exit(0);
|
||||
}
|
||||
assert.ok(trees[tree], 'Choose B0, B1 or B2'); assert.ok(out?.startsWith('/private/tmp/') || out?.startsWith('/tmp/'));
|
||||
await mkdir(out, { recursive: false });
|
||||
const profiles = path.join(out, 'profile'); await mkdir(profiles);
|
||||
const cpuProfileDirectory = path.join(profiles, 'cpu');
|
||||
if (!smoke) await mkdir(cpuProfileDirectory);
|
||||
const getJson = async file => JSON.parse(await readFile(file, 'utf8'));
|
||||
const saveJson = async (file, value) => writeFile(file, JSON.stringify(value, null, 2) + '\n');
|
||||
const readNdjson = async file => (await readFile(file, 'utf8')).split('\n').filter(Boolean).map(value => JSON.parse(value));
|
||||
const quote = value => `'${value.replaceAll("'", "'\\''")}'`;
|
||||
const portServer = net.createServer();
|
||||
await new Promise((resolve, reject) => { portServer.once('error', reject); portServer.listen(0, '127.0.0.1', resolve); });
|
||||
const port = portServer.address().port; await new Promise(resolve => portServer.close(resolve));
|
||||
const bootstrap = path.join(harnessRoot, 'tests/e2e/fixtures/native-ingestion-bootstrap.mjs');
|
||||
const preload = path.join(import.meta.dirname, 'native-ingestion-diagnostic-preload.mjs');
|
||||
const providerCommand = path.join(profiles, 'codex-profile-only');
|
||||
await writeFile(providerCommand, `#!/bin/sh\nexec env NODE_ENV=test PAPERCLIP_NATIVE_INGESTION_DIAGNOSTIC_DIR=${quote(profiles)} ${quote(process.execPath)} --import ${quote(preload)} ${quote(path.join(harnessRoot, 'tests/e2e/fixtures/in-feed-codex.mjs'))} --ingestion-stream-fixture "$@"\n`, { mode: 0o755 });
|
||||
const cpuProfileFlags = smoke ? '' : ` --cpu-prof --cpu-prof-dir=${quote(cpuProfileDirectory)}`;
|
||||
const command = `node --import ./server/node_modules/tsx/dist/loader.mjs ${quote(bootstrap)} && node${cpuProfileFlags} --import ${quote(preload)} --import ./server/node_modules/tsx/dist/loader.mjs server/dist/index.js`;
|
||||
const env = { PAPERCLIP_E2E_PORT: String(port), PAPERCLIP_INGESTION_SMOKE: smoke ? '1' : '0',
|
||||
PAPERCLIP_INGESTION_VARIANT: `PROFILE-ONLY-${tree}`, PAPERCLIP_INGESTION_APP_ROOT: trees[tree],
|
||||
PAPERCLIP_INGESTION_EVIDENCE_DIR: out, PAPERCLIP_NATIVE_INGESTION_DIAGNOSTIC_DIR: profiles,
|
||||
PAPERCLIP_NATIVE_INGESTION_DIAGNOSTIC_CODEX_COMMAND: providerCommand,
|
||||
PAPERCLIP_NATIVE_INGESTION_DIAGNOSTIC_FS: process.env.PAPERCLIP_NATIVE_INGESTION_DIAGNOSTIC_FS ?? '0',
|
||||
PAPERCLIP_NATIVE_INGESTION_DIAGNOSTIC_INSPECTOR: process.env.PAPERCLIP_NATIVE_INGESTION_DIAGNOSTIC_INSPECTOR ?? '0',
|
||||
PAPERCLIP_INGESTION_DRIVER_DEPENDENCIES: 'Driver-only tooling links to frozen B1 locked dependencies; each app owns independent installs',
|
||||
PAPERCLIP_INGESTION_SERVER_COMMAND: command };
|
||||
const logHandle = await open(path.join(out, 'playwright.log'), 'wx'), log = logHandle.createWriteStream();
|
||||
const child = spawn(process.execPath, ['node_modules/@playwright/test/cli.js', 'test', '--config', 'tests/e2e/playwright-native-ingestion.config.ts'],
|
||||
{ cwd: harnessRoot, env: { ...process.env, ...env }, stdio: ['ignore', 'pipe', 'pipe'] });
|
||||
child.stdout.pipe(log, { end: false }); child.stderr.pipe(log, { end: false });
|
||||
const startedAtMs = Date.now();
|
||||
await saveJson(path.join(out, 'command.json'), { diagnosticOnly: true, tree, sourceRevision: execFileSync('git', ['rev-parse', 'HEAD'], { cwd: trees[tree], encoding: 'utf8' }).trim(),
|
||||
childPid: child.pid, startedAtMs, env, preloadSha256: createHash('sha256').update(await readFile(preload)).digest('hex') });
|
||||
let metadata, clusterPid;
|
||||
const processSamples = [];
|
||||
const cpuMillis = value => value.split(':').map(Number).reduce((total, part) => total * 60 + part, 0) * 1000;
|
||||
const clockTicks = process.platform === 'linux' ? Number(execFileSync('getconf', ['CLK_TCK'], { encoding: 'utf8' }).trim()) : null;
|
||||
const sample = async () => {
|
||||
if (!metadata) {
|
||||
const names = (await readdir(profiles)).filter(name => /^app-\d+\.metadata\.json$/.test(name));
|
||||
if (!names.length) return; assert.equal(names.length, 1); metadata = await getJson(path.join(profiles, names[0]));
|
||||
}
|
||||
if (!clusterPid) {
|
||||
try {
|
||||
const config = await getJson(metadata.configPath), directory = config.database.embeddedPostgresDataDir;
|
||||
assert.ok(directory.includes('/paperclip-e2e-home-'), 'Sampler may only inspect this disposable fixture database');
|
||||
clusterPid = Number((await readFile(path.join(directory, 'postmaster.pid'), 'utf8')).split('\n')[0]);
|
||||
assert.ok(Number.isSafeInteger(clusterPid) && clusterPid > 1);
|
||||
} catch (error) { if (error.code !== 'ENOENT') throw error; }
|
||||
}
|
||||
const output = execFileSync('ps', ['-axo', 'pid=,ppid=,time=,rss=,comm='], { encoding: 'utf8' });
|
||||
const processes = output.split('\n').flatMap(line => {
|
||||
const match = line.match(/^\s*(\d+)\s+(\d+)\s+([\d:.]+)\s+(\d+)\s+(.+)$/);
|
||||
return match ? [{ pid: Number(match[1]), parentPid: Number(match[2]), cpuMillis: cpuMillis(match[3]), rssBytes: Number(match[4]) * 1024, executable: path.basename(match[5]) }] : [];
|
||||
});
|
||||
const ownedPg = new Set(clusterPid ? [clusterPid] : []);
|
||||
for (let pass = 0; pass < 4; pass++) for (const proc of processes) if (ownedPg.has(proc.parentPid) && /^postgres/.test(proc.executable)) ownedPg.add(proc.pid);
|
||||
const pg = processes.filter(proc => ownedPg.has(proc.pid) && /^postgres/.test(proc.executable));
|
||||
if (clockTicks) for (const proc of pg) {
|
||||
try {
|
||||
const stat = await readFile(`/proc/${proc.pid}/stat`, 'utf8');
|
||||
const fields = stat.slice(stat.lastIndexOf(')') + 2).trim().split(/\s+/);
|
||||
proc.cpuMillis = (Number(fields[11]) + Number(fields[12])) / clockTicks * 1000;
|
||||
} catch (error) { if (error.code !== 'ENOENT' && error.code !== 'ESRCH') throw error; }
|
||||
}
|
||||
const app = processes.find(proc => proc.pid === metadata.pid);
|
||||
processSamples.push({ atMs: Date.now(), app, postgres: pg });
|
||||
};
|
||||
let sampling = false, samplingError;
|
||||
const timer = setInterval(() => {
|
||||
if (sampling) return; sampling = true;
|
||||
sample().catch(error => { samplingError = String(error.stack ?? error); child.kill('SIGTERM'); }).finally(() => { sampling = false; });
|
||||
}, 1000);
|
||||
const terminate = signal => child.kill(signal);
|
||||
const sigint = () => terminate('SIGINT'), sigterm = () => terminate('SIGTERM');
|
||||
process.once('SIGINT', sigint); process.once('SIGTERM', sigterm);
|
||||
const watchdog = setTimeout(() => { samplingError = '20-minute diagnostic resource watchdog expired'; child.kill('SIGTERM'); }, 20 * 60_000);
|
||||
const exit = await new Promise((resolve, reject) => { child.once('error', reject); child.once('close', (code, signal) => resolve({ code, signal })); });
|
||||
clearInterval(timer); clearTimeout(watchdog); process.off('SIGINT', sigint); process.off('SIGTERM', sigterm);
|
||||
while (sampling) await new Promise(resolve => setTimeout(resolve, 20));
|
||||
await new Promise(resolve => log.end(resolve));
|
||||
await saveJson(path.join(out, 'process-samples.json'), { diagnosticOnly: true, intervalMs: 1000, childExit: exit, samplingError,
|
||||
cpuResolutionMillis: clockTicks ? 1000 / clockTicks : 10,
|
||||
cpuSource: clockTicks ? 'Owned PostgreSQL /proc/PID/stat utime+stime ticks' : 'ps process CPU time, 10ms on this macOS host',
|
||||
boundary: 'Task-owned app PID and embedded cluster PID plus PostgreSQL descendants; PID/PPID/CPU/RSS/comm only, no argv or credentials',
|
||||
limitation: '1-second polling can miss short-lived backends and CPU accrued after their final observation; PostgreSQL CPU is sampled process CPU, not exact accounting', samples: processSamples });
|
||||
assert.equal(samplingError, undefined, 'Diagnostic process sampler failed; preserve process-samples.json');
|
||||
assert.equal(exit.code, 0, `Diagnostic fixture failed: ${JSON.stringify(exit)}; preserve log`);
|
||||
const browser = await getJson(path.join(out, 'playwright.json'));
|
||||
const attachments = [];
|
||||
function visit(value) {
|
||||
if (Array.isArray(value)) for (const child of value) visit(child);
|
||||
else if (value && typeof value === 'object') {
|
||||
if (value.attachments) attachments.push(...value.attachments.filter(item => item.name === 'native-ingestion-evidence'));
|
||||
for (const [key, child] of Object.entries(value)) if (key !== 'attachments') visit(child);
|
||||
}
|
||||
}
|
||||
visit(browser); assert.equal(attachments.length, 1);
|
||||
const attachment = attachments[0];
|
||||
const evidence = attachment.body ? JSON.parse(Buffer.from(attachment.body, 'base64').toString()) : await getJson(attachment.path);
|
||||
assert.equal(evidence.complete, true);
|
||||
assert.equal(evidence.diagnosticOnly, true, 'The raw fixture attachment must identify profiling before extraction');
|
||||
assert.equal(evidence.performanceAcceptanceEligible, false);
|
||||
await saveJson(path.join(out, 'PROFILE-ONLY-browser-evidence.json'), evidence);
|
||||
const files = await readdir(profiles);
|
||||
const rows = (await Promise.all(files.filter(file => file.endsWith('.ndjson')).map(file => readNdjson(path.join(profiles, file))))).flat();
|
||||
const moduleTypes = new Set(rows.filter(row => row.kind === 'instrumented-module').map(row => row.type));
|
||||
const expectedModuleTypes = ['port', 'postgres', 'queue', 'resolver', ...(process.env.PAPERCLIP_NATIVE_INGESTION_DIAGNOSTIC_FS === '1' ? ['core', 'staged'] : [])];
|
||||
assert.deepEqual([...moduleTypes].sort(), expectedModuleTypes.sort(), 'All diagnostic anchors must actually be exercised');
|
||||
assert.equal(rows.filter(row => row.kind === 'diagnostic-fatal').length, 0, 'A diagnostic assertion failed inside the non-consequential observer');
|
||||
const emissions = rows.filter(row => row.kind === 'provider-emission'), commits = rows.filter(row => row.kind === 'postcommit-marker');
|
||||
const samples = rows.filter(row => row.kind === 'app-sample').sort((a, b) => a.atMs - b.atMs);
|
||||
const cases = await Promise.all(evidence.cases.map(async item => {
|
||||
const codes = new Set(item.durable.map(proof => proof.markerCode));
|
||||
const offered = emissions.filter(row => codes.has(row.markerCode)), persisted = commits.filter(row => codes.has(row.markerCode));
|
||||
const key = row => `${row.markerCode}:${row.index}`;
|
||||
const originalClocks = item.clockEvidence.flatMap(stream => stream.emissions);
|
||||
const originalByMarker = new Map(originalClocks.map(row => [key(row), row]));
|
||||
assert.equal(originalByMarker.size, originalClocks.length, 'Duplicate original source-clock marker');
|
||||
const durableByMarker = new Map(item.durable.flatMap(proof => Array.from({ length: proof.individualDeltas }, (_, index) =>
|
||||
[`${proof.markerCode}:${index}`, { runId: proof.runId, nonce: proof.token, markerCode: proof.markerCode, index }])));
|
||||
const rawMarkersWithoutOriginalClock = offered.filter(row => !originalByMarker.has(key(row))).map(key);
|
||||
if (!item.stop) assert.equal(rawMarkersWithoutOriginalClock.length, 0, 'Every normally emitted marker needs an original clock');
|
||||
assert.equal(new Set(offered.map(key)).size, offered.length, 'Duplicate provider emission marker');
|
||||
assert.equal(new Set(persisted.map(key)).size, persisted.length, 'Duplicate committed marker');
|
||||
const offeredKeys = new Set(offered.map(key)), persistedKeys = new Set(persisted.map(key));
|
||||
const markerCoverage = {
|
||||
expectedDurableMarkers: durableByMarker.size,
|
||||
missingPostcommitObservation: [...durableByMarker.keys()].filter(value => !persistedKeys.has(value)),
|
||||
postcommitAbsentFromDurablePrefix: persisted.filter(row => !durableByMarker.has(key(row))).map(key),
|
||||
postcommitWithoutProviderObservation: persisted.filter(row => !offeredKeys.has(key(row))).map(key),
|
||||
postcommitWithoutOriginalClock: persisted.filter(row => !originalByMarker.has(key(row))).map(key),
|
||||
mismatchedRunOrNonce: persisted.filter(row => {
|
||||
const durable = durableByMarker.get(key(row)), original = originalByMarker.get(key(row));
|
||||
return durable && original && (row.runId !== durable.runId || original.nonce !== durable.nonce);
|
||||
}).map(key),
|
||||
};
|
||||
markerCoverage.complete = Object.entries(markerCoverage).every(([name, value]) => name === 'expectedDurableMarkers' || value.length === 0);
|
||||
// Incomplete observation is distinct from a correctly observed, cancelled raw
|
||||
// tail. Preserve the mismatch even if teardown killed a diagnostic observer.
|
||||
await saveJson(path.join(out, `${item.name}-marker-coverage.json`), markerCoverage);
|
||||
assert.equal(markerCoverage.complete, true, 'Incomplete diagnostic observer coverage; do not interpret its backlog as all durable commits');
|
||||
if (!item.stop) {
|
||||
assert.equal(offered.length, item.runs * item.events); assert.equal(persisted.length, offered.length);
|
||||
assert.deepEqual([...new Set(persisted.map(key))].sort(), [...new Set(offered.map(key))].sort());
|
||||
}
|
||||
assert.ok(offered.length > 0 && persisted.length > 0);
|
||||
const begin = Math.min(...originalClocks.map(row => row.intendedMs)), end = begin + item.drainThroughTerminalMs;
|
||||
const during = samples.filter(row => row.atMs >= begin && row.atMs <= end);
|
||||
assert.ok(during.length > 0, 'No app resource samples in measured diagnostic interval');
|
||||
const preceding = [...samples].reverse().find(row => row.atMs < begin), following = samples.find(row => row.atMs > end);
|
||||
assert.ok(preceding && following, 'Resource counter boundaries were not captured');
|
||||
const deltas = Object.fromEntries(['sqlCalls', 'begins', 'commits', 'rollbacks', 'savepoints', 'releases', 'committedEvents'].map(name => [name, following.counters[name] - preceding.counters[name]]));
|
||||
const changes = [...offered.map(row => ({ atMs: row.atMs, delta: 1 })), ...persisted.map(row => ({ atMs: row.atMs, delta: -1 }))].sort((a, b) => a.atMs - b.atMs || b.delta - a.delta);
|
||||
let backlog = 0, peakBacklog = 0;
|
||||
for (const change of changes) { backlog += change.delta; peakBacklog = Math.max(peakBacklog, backlog); }
|
||||
const bracketed = samples.filter(row => row.atMs > preceding.atMs && row.atMs <= following.atMs);
|
||||
const appCpuMicros = bracketed.reduce((total, row) => total + row.cpuMicros, 0);
|
||||
const pgBefore = [...processSamples].reverse().find(row => row.atMs <= begin), pgAfter = processSamples.find(row => row.atMs >= end);
|
||||
assert.ok(pgBefore && pgAfter, 'PG CPU needs an explicit before/after boundary');
|
||||
const pg = processSamples.filter(row => row.atMs > pgBefore.atMs && row.atMs <= pgAfter.atMs);
|
||||
const previousByPid = new Map(pgBefore.postgres.map(proc => [proc.pid, proc.cpuMillis])); let pgCpuMillis = 0;
|
||||
for (const row of pg) for (const proc of row.postgres) {
|
||||
const previous = previousByPid.get(proc.pid);
|
||||
pgCpuMillis += previous === undefined || proc.cpuMillis < previous ? proc.cpuMillis : proc.cpuMillis - previous;
|
||||
previousByPid.set(proc.pid, proc.cpuMillis);
|
||||
}
|
||||
return { name: item.name, interval: { begin, end }, providerMarkers: offered.length, postcommitMarkers: persisted.length,
|
||||
emittedToCommittedBacklogPeak: peakBacklog, finalUncommittedMarkers: backlog, originalClockCount: originalClocks.length, rawMarkersWithoutOriginalClock, markerCoverage,
|
||||
finalBacklogInterpretation: item.stop ? 'Cancellation may intentionally leave raw unacknowledged output uncommitted under the preserved transport policy' : 'Must be zero after full terminal drainage',
|
||||
actualNormalizedQueuePeakInBracketedWindow: Math.max(...bracketed.map(row => row.queuePeakSinceSample)),
|
||||
actualNormalizedQueueDepthAtLastPreterminalSample: during.at(-1).actualNormalizedQueueDepth,
|
||||
actualNormalizedQueueDepthAtPostterminalBoundary: following.actualNormalizedQueueDepth,
|
||||
appCpuWindow: { begin: preceding.atMs, end: following.atMs }, pgCpuWindow: { begin: pgBefore.atMs, end: pgAfter.atMs },
|
||||
appCpuMicros, appCpuMicrosPerMarker: appCpuMicros / persisted.length, sampledPgCpuMillis: pgCpuMillis,
|
||||
appCpuMicrosPerCommittedNormalizedEvent: appCpuMicros / deltas.committedEvents,
|
||||
sampledPgCpuMillisPerMarker: pgCpuMillis / persisted.length, appRssPeakBytes: Math.max(...during.map(row => row.rssBytes)),
|
||||
appHeapPeakBytes: Math.max(...during.map(row => row.heapUsedBytes)),
|
||||
eventLoopDelayPeakMs: Math.max(...during.map(row => row.eventLoopDelayMaxMs ?? 0)),
|
||||
eventLoopUtilizationMedian: during.map(row => row.eventLoopUtilization).sort((a, b) => a - b)[Math.floor(during.length / 2)],
|
||||
databaseCounterDeltas: deltas, sqlCallsPerMarker: deltas.sqlCalls / persisted.length,
|
||||
sqlCallsPerCommittedNormalizedEvent: deltas.sqlCalls / deltas.committedEvents,
|
||||
transactionsBegunPerMarker: deltas.begins / persisted.length,
|
||||
transactionsBegunPerCommittedNormalizedEvent: deltas.begins / deltas.committedEvents,
|
||||
counterBoundaryOvershootMs: { before: begin - preceding.atMs, after: following.atMs - end }, resourceSampleCount: during.length };
|
||||
}));
|
||||
const cpuProfiles = smoke ? [] : await Promise.all((await readdir(cpuProfileDirectory)).filter(file => file.endsWith('.cpuprofile')).map(async file => ({
|
||||
file: path.join(cpuProfileDirectory, file), sha256: createHash('sha256').update(await readFile(path.join(cpuProfileDirectory, file))).digest('hex'),
|
||||
})));
|
||||
if (!smoke) assert.ok(cpuProfiles.length > 0, 'Full profile must capture the app-only Node CPU profile');
|
||||
const summary = { diagnosticOnly: true, performanceAcceptanceEligible: false, tree, sourceRevision: evidence.sourceRevision,
|
||||
complete: true, cases, cpuProfiles, processScope: { appCpuAndMemory: 'Server Node process only; excludes Rust Runner/providers and the external load driver', postgresMemory: 'Per-process RSS; summing it double-counts shared pages' }, disclosures: ['CPU/RSS/heap describe the server Node process, not the Rust Runner, provider or whole host fleet',
|
||||
'PostgreSQL memory is per-process RSS; a sum would double-count shared pages and is not unique physical memory',
|
||||
'Actual normalized queue excludes iterator/collector/in-flight append and raw transport buffers',
|
||||
'Raw provider-observer emission-minus-postcommit is a full-path backlog proxy, distinct from the actual normalized queue',
|
||||
'Original intended/emitted clocks come from the separate streamed HTTP source channel in browser evidence; no clocks are synthesized for cancelled unmatched raw tail',
|
||||
'Resource samples use 250ms app / 1s process polling. CPU/SQL phase boundaries are approximate, with overshoot reported',
|
||||
'SQL counts are query-build attempts across the whole app including API reads, lifecycle work, COMMIT and savepoints; no parameters or SQL text are logged',
|
||||
'Bracketed whole-app CPU/SQL windows can include postterminal verification reads; per-marker ratios are diagnostic whole-app costs, not append-only costs',
|
||||
'Postcommit observation happens after the durable outer transaction, so its timestamp is an upper bound',
|
||||
'Full diagnostics also run app-only Node --cpu-prof; CPU sampling and observer overhead are excluded from acceptance timing claims'] };
|
||||
if (process.env.PAPERCLIP_NATIVE_INGESTION_DIAGNOSTIC_FS === '1') summary.disclosures.push(
|
||||
'Full-snapshot UTF-8 byte counting adds a scan and filesystem timing adds Promise wrappers; diagnostics do not remove or bypass any durable operation',
|
||||
'Asynchronous staged write/fsync milliseconds sum overlapping waits across runs and are not blocked-main-thread time; directory fsync is synchronous main-thread elapsed time');
|
||||
await saveJson(path.join(out, 'PROFILE-ONLY-summary.json'), summary);
|
||||
console.log(JSON.stringify(summary, null, 2));
|
||||
+47
@@ -0,0 +1,47 @@
|
||||
import fs from 'node:fs/promises';
|
||||
import path from 'node:path';
|
||||
import postgres from '/home/ubuntu/native-ingestion/paperclip/packages/db/node_modules/postgres/src/index.js';
|
||||
const out=process.argv[2], exitFile=process.argv[3];
|
||||
if(!out?.startsWith('/tmp/'))throw Error('Owned diagnostic output required');
|
||||
const dir=path.join(out,'profile'), end=Date.now()+16*60_000;
|
||||
await fs.mkdir(out,{recursive:true});
|
||||
const save=(name,v)=>fs.writeFile(path.join(out,name),JSON.stringify(v,null,2)+'\n');
|
||||
const append=(name,v)=>fs.appendFile(path.join(out,name),JSON.stringify(v)+'\n');
|
||||
let client, metadata, dataDirectory, inspection, socket, seq=0, focusedStartedAt, focusedStopped=false;
|
||||
const requests=new Map();
|
||||
async function rpc(method,params={}){
|
||||
const id=++seq;let timer;
|
||||
try{return await Promise.race([new Promise((resolve,reject)=>{requests.set(id,{resolve,reject});socket.send(JSON.stringify({id,method,params}));}),new Promise((_,reject)=>{timer=setTimeout(()=>reject(Error(method+' timed out')),5000);})]);}
|
||||
finally{clearTimeout(timer);requests.delete(id);}
|
||||
}
|
||||
let nextPg=0, nextMarker=0;
|
||||
const receipt={diagnosticOnly:true,performanceAcceptanceEligible:false,startedAt:new Date().toISOString(),focusedCpuSeconds:30,sql:'Read-only external connection, activity/locks/count snapshots, 3-second statement limits; no query parameters/credentials logged',overhead:'Additional PG diagnostics and an app-only focused CPU profiler; excluded from acceptance'};
|
||||
try{
|
||||
while(Date.now()<end){
|
||||
try{await fs.access(exitFile);break;}catch{}
|
||||
let files=[];try{files=await fs.readdir(dir);}catch{}
|
||||
if(!metadata){const file=files.find(x=>/^app-\d+\.metadata\.json$/.test(x));if(file)metadata=JSON.parse(await fs.readFile(path.join(dir,file),'utf8'));}
|
||||
if(metadata&&!client&&Date.now()>=nextPg){
|
||||
try{const config=JSON.parse(await fs.readFile(metadata.configPath,'utf8'));dataDirectory=config.database.embeddedPostgresDataDir;if(!dataDirectory.includes('/paperclip-e2e-home-'))throw Error('Wrong fixture directory');await fs.access(path.join(dataDirectory,'postmaster.pid'));client=postgres({host:'127.0.0.1',port:config.database.embeddedPostgresPort??54329,user:'paperclip',password:'paperclip',database:'paperclip',max:1,connect_timeout:3,idle_timeout:30,connection:{application_name:'native_ingestion_diagnostic_only_observer',default_transaction_read_only:'on',statement_timeout:'3000'}});const cluster=await client.unsafe("select current_setting('data_directory') as directory,current_setting('transaction_read_only') as read_only");if(cluster[0].directory!==dataDirectory||cluster[0].read_only!=='on')throw Error('Wrong/readwrite fixture');receipt.cluster={directory:dataDirectory,readOnly:true};}
|
||||
catch(error){await append('pg-live.ndjson',{at:Date.now(),connectError:String(error)});if(client){await client.end({timeout:1});client=undefined;}nextPg=Date.now()+10000;}
|
||||
}
|
||||
if(client&&Date.now()>=nextPg){
|
||||
const sample={at:Date.now(),diagnosticOnly:true};
|
||||
try{sample.activity=await client.unsafe("select pid,application_name,state,wait_event_type,wait_event,extract(epoch from clock_timestamp()-xact_start) as transaction_age_seconds,left(query,1000) as query from pg_stat_activity where datname=current_database() and pid<>pg_backend_pid()");sample.locks=await client.unsafe("select pid,locktype,relation::regclass::text as relation,mode,granted,pg_blocking_pids(pid) as blockers from pg_locks where pid<>pg_backend_pid()");sample.counts=await client.unsafe("select run_id,event_type,payload->'prpEvent'->>'eventType' as prp_event_type,count(*)::int as rows,max(source_seq) as maximum_source_seq from heartbeat_run_events group by run_id,event_type,payload->'prpEvent'->>'eventType'");}
|
||||
catch(error){sample.error=String(error);}
|
||||
await append('pg-live.ndjson',sample);nextPg=Date.now()+10000;
|
||||
}
|
||||
if(metadata&&!socket&&!focusedStopped){
|
||||
const file=files.find(x=>/^app-\d+\.inspector\.json$/.test(x));
|
||||
if(file){inspection=JSON.parse(await fs.readFile(path.join(dir,file),'utf8'));if(inspection.pid!==metadata.pid||!/^ws:\/\/127\.0\.0\.1:\d+\//.test(inspection.url))throw Error('Wrong inspector');socket=new WebSocket(inspection.url);await new Promise((resolve,reject)=>{const timer=setTimeout(()=>reject(Error('Inspector open timed out')),5000);socket.addEventListener('open',()=>{clearTimeout(timer);resolve();},{once:true});socket.addEventListener('error',reject,{once:true});});socket.addEventListener('message',e=>{const v=JSON.parse(e.data);const req=requests.get(v.id);if(req)v.error?req.reject(Error(JSON.stringify(v.error))):req.resolve(v.result);});await rpc('Profiler.enable');receipt.inspectorPid=inspection.pid;}
|
||||
}
|
||||
if(socket&&!focusedStartedAt&&!focusedStopped&&Date.now()>=nextMarker){
|
||||
for(const file of files.filter(x=>/^provider-\d+\.ndjson$/.test(x))){const handle=await fs.open(path.join(dir,file),'r');let buffer=Buffer.alloc(4096);let read;try{read=await handle.read(buffer,0,buffer.length,0);}finally{await handle.close();}const text=buffer.subarray(0,read.bytesRead).toString();if(text.includes('"markerCode":"0c"')){await rpc('Profiler.start');focusedStartedAt=Date.now();receipt.focusedStartedAtMs=focusedStartedAt;receipt.trigger='First provider-observer markerCode0c, the fixed100-run case foreground';await save('independent-observer-receipt.json',receipt);break;}}
|
||||
nextMarker=Date.now()+1000;
|
||||
}
|
||||
if(socket&&focusedStartedAt&&!focusedStopped&&Date.now()-focusedStartedAt>=30000){const result=await rpc('Profiler.stop');await fs.mkdir(path.join(dir,'cpu'),{recursive:true});await save('profile/cpu/focused-100-run-app.cpuprofile',result.profile);receipt.focusedStoppedAtMs=Date.now();receipt.focusedProfileComplete=true;focusedStopped=true;socket.close();socket=undefined;await save('independent-observer-receipt.json',receipt);}
|
||||
await new Promise(r=>setTimeout(r,1000));
|
||||
}
|
||||
}catch(error){receipt.error=String(error);}
|
||||
finally{if(client)await client.end({timeout:1});if(socket)socket.close();receipt.finishedAt=new Date().toISOString();await save('independent-observer-receipt.json',receipt);}
|
||||
console.log(JSON.stringify(receipt));
|
||||
+108
@@ -0,0 +1,108 @@
|
||||
{
|
||||
"scope": "Historical baseline diagnostic only; not an acceptance measurement or current-head result",
|
||||
"revision": "83b5f7d486e70e484acd9a41bc957054f4e10175",
|
||||
"driverRevision": "f5c560d80d9d4ee089297d3b3f300c052db17c9e",
|
||||
"files": [
|
||||
{
|
||||
"file": "focused-100-run-app.cpuprofile.gz",
|
||||
"decompressedSha256": "c53b3fb457c6df5bcbba0d2cf3265df45d6dfb7e7a58b83a0cb286e53cc3a2c8",
|
||||
"decompressedBytes": 1818639,
|
||||
"gzipSha256": "8997313d74c22f00035f9f412632ba318f277cf3094b8b4fd5df42f23bfe0c65",
|
||||
"gzipBytes": 105696
|
||||
},
|
||||
{
|
||||
"file": "postfailure-hotqueue-app.cpuprofile.gz",
|
||||
"decompressedSha256": "4b9a0ef0a04e863d076160af1151ef51baead05feaf0231aa45776e51caebf3d",
|
||||
"decompressedBytes": 537091,
|
||||
"gzipSha256": "59b3a71614aa5235206172f7a61ee2da92381d5c9f8426051be204d4202d3ef9",
|
||||
"gzipBytes": 69617
|
||||
},
|
||||
{
|
||||
"file": "pg-live.ndjson.gz",
|
||||
"decompressedSha256": "c827f92db6efe93256cd0445e26233313a7832cf419696517bdd581fcaf99040",
|
||||
"decompressedBytes": 16600029,
|
||||
"gzipSha256": "a8bef8f260fdcd43d523fd28f09e9437aeb577a4e8f2228b5e569356e8580842",
|
||||
"gzipBytes": 987192
|
||||
},
|
||||
{
|
||||
"file": "weighted-cpu-summary.json",
|
||||
"sha256": "4a5b4c48c4ad848291515568b4e45b5ff135b82a62c438a8cad7a4f6f1721976",
|
||||
"bytes": 31558
|
||||
},
|
||||
{
|
||||
"file": "postfailure-hotqueue-profile-receipt.json",
|
||||
"sha256": "1754f09164bb1325d852f43b823f781b1ff2a14c34bb756188a4c7ee8a464d17",
|
||||
"bytes": 182
|
||||
},
|
||||
{
|
||||
"file": "native-ingestion-evidence.json.gz",
|
||||
"decompressedSha256": "35e7babc19bfd29a50e3f428b03b1e99cd9bc2c20df9f66145b99532c85d6ce4",
|
||||
"decompressedBytes": 14830386,
|
||||
"gzipSha256": "a5554fcc7b705b69bde5afd1514fd6a95a8bf26e555bec456addc1cb3b492fab",
|
||||
"gzipBytes": 218190
|
||||
},
|
||||
{
|
||||
"file": "measured-delta-counts.json.gz",
|
||||
"decompressedSha256": "9a9c1f98844161fd0aaaaef1b4b98df9f14f1409a7eacaf693bdae9b6ea4691b",
|
||||
"decompressedBytes": 134067,
|
||||
"gzipSha256": "3e3918b4252808543e892bc7620ee22d9eda09ae32e9f07242147d69a937d07c",
|
||||
"gzipBytes": 6720
|
||||
},
|
||||
{
|
||||
"file": "external-cleanup-receipt.json.gz",
|
||||
"decompressedSha256": "17ce9e81ed9a5d05bb757d1f2105713419ed0e3753a753e6abae418c0d4e7dfb",
|
||||
"decompressedBytes": 84489,
|
||||
"gzipSha256": "05fe48458e3e478c50ae14fd4588a947e451ad55934347ac8aa57a56f735b502",
|
||||
"gzipBytes": 5934
|
||||
},
|
||||
{
|
||||
"file": "forensic-receipt.json.gz",
|
||||
"decompressedSha256": "57f104658c3505b3ce4c0adbe194bf721c819ba5c1f2f389f167300ffc4b0c56",
|
||||
"decompressedBytes": 90658,
|
||||
"gzipSha256": "881a95cf93992d50265be49c8f420a909745e12938fb9efe1f06af002fa026f8",
|
||||
"gzipBytes": 7192
|
||||
},
|
||||
{
|
||||
"file": "app-46347.ndjson.gz",
|
||||
"decompressedSha256": "f2ee482283b97c6b29602e70c0b8b121e649b38bf7aaaeaedf80da0bbdba8665",
|
||||
"decompressedBytes": 4918482,
|
||||
"gzipSha256": "278b5133c714eeb7bd94dd6b91f0efcaac4ee6f8ad83eeeaac5e8b37b6dc3a19",
|
||||
"gzipBytes": 860079
|
||||
},
|
||||
{
|
||||
"file": "app-46347.metadata.json",
|
||||
"sha256": "77486d6c3e87f6f2fc8d0a9bd3fea5585659878a7fca5e0cfd652a27a01e23e1",
|
||||
"bytes": 352
|
||||
},
|
||||
{
|
||||
"file": "diagnostic-command.json",
|
||||
"sha256": "58540aa8bf3c4845419a3fb923a4dd45da742241d3e7ffcdc7b78bbf9cb7d198",
|
||||
"bytes": 1507
|
||||
},
|
||||
{
|
||||
"file": "diagnostic-quiet-returned.json",
|
||||
"sha256": "aad920ab5333e59cf082c46e653e7460cd53e70600d5f5394948674884bab88e",
|
||||
"bytes": 320
|
||||
},
|
||||
{
|
||||
"file": "instrumentation-native-ingestion-diagnostic-preload.mjs",
|
||||
"sha256": "98bf2eb6994f13d6957535f5799b5994dda8920af97c2965c1d8baab925d3386",
|
||||
"bytes": 14742
|
||||
},
|
||||
{
|
||||
"file": "instrumentation-native-ingestion-diagnostic-run.mjs",
|
||||
"sha256": "35a9b220aef9005ceb8110d538231e12fdab901c56f25cf020631b1d27648f50",
|
||||
"bytes": 20010
|
||||
},
|
||||
{
|
||||
"file": "instrumentation-native-ingestion-failure-replay-observer.mjs",
|
||||
"sha256": "5536dec1b0b39c3777eeda7b11822e6b5ef6bc902985d654a5128ee8eb20291f",
|
||||
"bytes": 6097
|
||||
},
|
||||
{
|
||||
"file": "app-counter-summary.json",
|
||||
"sha256": "4bad67a1e4553204d907f20c1da62298623961ef0946897a51dd536b28b27ed5",
|
||||
"bytes": 3078
|
||||
}
|
||||
]
|
||||
}
|
||||
BIN
Binary file not shown.
BIN
Binary file not shown.
BIN
Binary file not shown.
BIN
Binary file not shown.
+8
@@ -0,0 +1,8 @@
|
||||
{
|
||||
"diagnosticOnly": true,
|
||||
"postFailureHotQueue": true,
|
||||
"pid": 46347,
|
||||
"startedAt": "2026-11-03T21:44:19.092Z",
|
||||
"complete": true,
|
||||
"finishedAt": "2026-11-03T21:44:49.985Z"
|
||||
}
|
||||
+732
@@ -0,0 +1,732 @@
|
||||
{
|
||||
"scope": "Diagnostic only; no performance acceptance claim",
|
||||
"method": "Weight each sampled frame by its corresponding V8 timeDelta; inclusive frames deduplicate recursion",
|
||||
"limits": [
|
||||
"Includes idle and native blocking time; this is not process CPU usage",
|
||||
"Inclusive frames overlap and must not be summed",
|
||||
"Instrumented wrapper residence can include byte counting or other probe work",
|
||||
"Instrumentation and failed-run phases must remain identified"
|
||||
],
|
||||
"profiles": [
|
||||
{
|
||||
"file": "focused-100-run-app.cpuprofile",
|
||||
"decompressedSha256": "c53b3fb457c6df5bcbba0d2cf3265df45d6dfb7e7a58b83a0cb286e53cc3a2c8",
|
||||
"samples": 25045,
|
||||
"weightedMillis": 31062.924,
|
||||
"self": [
|
||||
{
|
||||
"function": "(idle)",
|
||||
"url": "",
|
||||
"line": 0,
|
||||
"weightedMillis": 26194.861,
|
||||
"sampledSharePercent": 84.32838132044492
|
||||
},
|
||||
{
|
||||
"function": "writeFileUtf8",
|
||||
"url": "",
|
||||
"line": 0,
|
||||
"weightedMillis": 1366.912,
|
||||
"sampledSharePercent": 4.400461463318778
|
||||
},
|
||||
{
|
||||
"function": "(program)",
|
||||
"url": "",
|
||||
"line": 0,
|
||||
"weightedMillis": 1008.754,
|
||||
"sampledSharePercent": 3.247453459307308
|
||||
},
|
||||
{
|
||||
"function": "(garbage collector)",
|
||||
"url": "",
|
||||
"line": 0,
|
||||
"weightedMillis": 297.565,
|
||||
"sampledSharePercent": 0.9579426585855214
|
||||
},
|
||||
{
|
||||
"function": "#pumpEvents",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/live/runnerd-codex-transport.js",
|
||||
"line": 5328,
|
||||
"weightedMillis": 262.525,
|
||||
"sampledSharePercent": 0.8451393693652278
|
||||
},
|
||||
{
|
||||
"function": "is",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/drizzle-orm@0.45.2_@opentelemetry+api@1.9.1_kysely@0.29.5_pg@8.18.0_postgres@3.4.9_patch_hash_4ringkigkncd6jisnfxlswcv6m/node_modules/drizzle-orm/entity.js",
|
||||
"line": 3,
|
||||
"weightedMillis": 179.036,
|
||||
"sampledSharePercent": 0.576365573311772
|
||||
},
|
||||
{
|
||||
"function": "recoveryIdentityMatches",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/live/runnerd-codex-transport.js",
|
||||
"line": 115,
|
||||
"weightedMillis": 159.983,
|
||||
"sampledSharePercent": 0.5150287847982373
|
||||
},
|
||||
{
|
||||
"function": "<anonymous>",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/live/runnerd-codex-transport.js",
|
||||
"line": 4157,
|
||||
"weightedMillis": 121.288,
|
||||
"sampledSharePercent": 0.39045905659106656
|
||||
},
|
||||
{
|
||||
"function": "writeBuffer",
|
||||
"url": "",
|
||||
"line": 0,
|
||||
"weightedMillis": 115.834,
|
||||
"sampledSharePercent": 0.372901147361401
|
||||
},
|
||||
{
|
||||
"function": "listOnTimeout",
|
||||
"url": "node:internal/timers",
|
||||
"line": 546,
|
||||
"weightedMillis": 92.142,
|
||||
"sampledSharePercent": 0.29663015625959743
|
||||
},
|
||||
{
|
||||
"function": "<anonymous>",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/live/runnerd-codex-transport.js",
|
||||
"line": 5344,
|
||||
"weightedMillis": 81.664,
|
||||
"sampledSharePercent": 0.26289862473989895
|
||||
},
|
||||
{
|
||||
"function": "match",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/path-to-regexp@8.3.0/node_modules/path-to-regexp/dist/index.js",
|
||||
"line": 245,
|
||||
"weightedMillis": 65.137,
|
||||
"sampledSharePercent": 0.20969371717871763
|
||||
},
|
||||
{
|
||||
"function": "readFileUtf8",
|
||||
"url": "",
|
||||
"line": 0,
|
||||
"weightedMillis": 65.043,
|
||||
"sampledSharePercent": 0.20939110561517002
|
||||
},
|
||||
{
|
||||
"function": "runMicrotasks",
|
||||
"url": "",
|
||||
"line": 0,
|
||||
"weightedMillis": 38.792,
|
||||
"sampledSharePercent": 0.1248819975865762
|
||||
},
|
||||
{
|
||||
"function": "#pumpEventsSafely",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/live/runnerd-codex-transport.js",
|
||||
"line": 5790,
|
||||
"weightedMillis": 37.647,
|
||||
"sampledSharePercent": 0.12119593120081033
|
||||
},
|
||||
{
|
||||
"function": "parse",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/postgres@3.4.9_patch_hash=6q4cic6qawywsyeo2spgnjamda/node_modules/postgres/src/types.js",
|
||||
"line": 20,
|
||||
"weightedMillis": 34.626,
|
||||
"sampledSharePercent": 0.11147051063190316
|
||||
},
|
||||
{
|
||||
"function": "<anonymous>",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/drizzle-orm@0.45.2_@opentelemetry+api@1.9.1_kysely@0.29.5_pg@8.18.0_postgres@3.4.9_patch_hash_4ringkigkncd6jisnfxlswcv6m/node_modules/drizzle-orm/sql/sql.js",
|
||||
"line": 83,
|
||||
"weightedMillis": 34.617,
|
||||
"sampledSharePercent": 0.11144153718432946
|
||||
},
|
||||
{
|
||||
"function": "buildQueryFromSourceParams",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/drizzle-orm@0.45.2_@opentelemetry+api@1.9.1_kysely@0.29.5_pg@8.18.0_postgres@3.4.9_patch_hash_4ringkigkncd6jisnfxlswcv6m/node_modules/drizzle-orm/sql/sql.js",
|
||||
"line": 70,
|
||||
"weightedMillis": 23.75,
|
||||
"sampledSharePercent": 0.07645770887505632
|
||||
},
|
||||
{
|
||||
"function": "match",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/router@2.2.0/node_modules/router/lib/layer.js",
|
||||
"line": 178,
|
||||
"weightedMillis": 22.833,
|
||||
"sampledSharePercent": 0.07350563649449099
|
||||
},
|
||||
{
|
||||
"function": "readLinuxProcessGroupActivity",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/services/local-service-supervisor.js",
|
||||
"line": 208,
|
||||
"weightedMillis": 20.191,
|
||||
"sampledSharePercent": 0.06500031999563209
|
||||
}
|
||||
],
|
||||
"inclusiveFileFrames": [
|
||||
{
|
||||
"function": "flush",
|
||||
"url": "file:///home/ubuntu/native-ingestion/helpers/native-ingestion-diagnostic-preload.mjs",
|
||||
"line": 23,
|
||||
"weightedMillis": 1371.1,
|
||||
"sampledSharePercent": 4.413943774256409
|
||||
},
|
||||
{
|
||||
"function": "#pumpEventsSafely",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/live/runnerd-codex-transport.js",
|
||||
"line": 5790,
|
||||
"weightedMillis": 564.661,
|
||||
"sampledSharePercent": 1.817797320046239
|
||||
},
|
||||
{
|
||||
"function": "#pumpEvents",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/live/runnerd-codex-transport.js",
|
||||
"line": 5328,
|
||||
"weightedMillis": 527.014,
|
||||
"sampledSharePercent": 1.6966013888454288
|
||||
},
|
||||
{
|
||||
"function": "startActiveSpan",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/drizzle-orm@0.45.2_@opentelemetry+api@1.9.1_kysely@0.29.5_pg@8.18.0_postgres@3.4.9_patch_hash_4ringkigkncd6jisnfxlswcv6m/node_modules/drizzle-orm/tracing.js",
|
||||
"line": 6,
|
||||
"weightedMillis": 358.223,
|
||||
"sampledSharePercent": 1.1532172566883916
|
||||
},
|
||||
{
|
||||
"function": "then",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/drizzle-orm@0.45.2_@opentelemetry+api@1.9.1_kysely@0.29.5_pg@8.18.0_postgres@3.4.9_patch_hash_4ringkigkncd6jisnfxlswcv6m/node_modules/drizzle-orm/query-promise.js",
|
||||
"line": 20,
|
||||
"weightedMillis": 328.862,
|
||||
"sampledSharePercent": 1.0586962128871062
|
||||
},
|
||||
{
|
||||
"function": "execute",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/drizzle-orm@0.45.2_@opentelemetry+api@1.9.1_kysely@0.29.5_pg@8.18.0_postgres@3.4.9_patch_hash_4ringkigkncd6jisnfxlswcv6m/node_modules/drizzle-orm/pg-core/query-builders/select.js",
|
||||
"line": 795,
|
||||
"weightedMillis": 324.707,
|
||||
"sampledSharePercent": 1.045320137923912
|
||||
},
|
||||
{
|
||||
"function": "_prepare",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/drizzle-orm@0.45.2_@opentelemetry+api@1.9.1_kysely@0.29.5_pg@8.18.0_postgres@3.4.9_patch_hash_4ringkigkncd6jisnfxlswcv6m/node_modules/drizzle-orm/pg-core/query-builders/select.js",
|
||||
"line": 763,
|
||||
"weightedMillis": 314.452,
|
||||
"sampledSharePercent": 1.012306504049651
|
||||
},
|
||||
{
|
||||
"function": "handleRequest",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/router@2.2.0/node_modules/router/lib/layer.js",
|
||||
"line": 142,
|
||||
"weightedMillis": 196.007,
|
||||
"sampledSharePercent": 0.6309998376199227
|
||||
},
|
||||
{
|
||||
"function": "handle",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/router@2.2.0/node_modules/router/index.js",
|
||||
"line": 149,
|
||||
"weightedMillis": 182.942,
|
||||
"sampledSharePercent": 0.5889400495587601
|
||||
},
|
||||
{
|
||||
"function": "next",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/router@2.2.0/node_modules/router/index.js",
|
||||
"line": 188,
|
||||
"weightedMillis": 182.932,
|
||||
"sampledSharePercent": 0.5889078568392339
|
||||
},
|
||||
{
|
||||
"function": "processParams",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/router@2.2.0/node_modules/router/index.js",
|
||||
"line": 576,
|
||||
"weightedMillis": 182.932,
|
||||
"sampledSharePercent": 0.5889078568392339
|
||||
},
|
||||
{
|
||||
"function": "trimPrefix",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/router@2.2.0/node_modules/router/index.js",
|
||||
"line": 304,
|
||||
"weightedMillis": 181.87,
|
||||
"sampledSharePercent": 0.5854889900255366
|
||||
},
|
||||
{
|
||||
"function": "is",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/drizzle-orm@0.45.2_@opentelemetry+api@1.9.1_kysely@0.29.5_pg@8.18.0_postgres@3.4.9_patch_hash_4ringkigkncd6jisnfxlswcv6m/node_modules/drizzle-orm/entity.js",
|
||||
"line": 3,
|
||||
"weightedMillis": 179.036,
|
||||
"sampledSharePercent": 0.576365573311772
|
||||
},
|
||||
{
|
||||
"function": "toQuery",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/drizzle-orm@0.45.2_@opentelemetry+api@1.9.1_kysely@0.29.5_pg@8.18.0_postgres@3.4.9_patch_hash_4ringkigkncd6jisnfxlswcv6m/node_modules/drizzle-orm/sql/sql.js",
|
||||
"line": 60,
|
||||
"weightedMillis": 163.084,
|
||||
"sampledSharePercent": 0.5250117471233552
|
||||
},
|
||||
{
|
||||
"function": "sqlToQuery",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/drizzle-orm@0.45.2_@opentelemetry+api@1.9.1_kysely@0.29.5_pg@8.18.0_postgres@3.4.9_patch_hash_4ringkigkncd6jisnfxlswcv6m/node_modules/drizzle-orm/pg-core/dialect.js",
|
||||
"line": 428,
|
||||
"weightedMillis": 163.084,
|
||||
"sampledSharePercent": 0.5250117471233552
|
||||
},
|
||||
{
|
||||
"function": "buildQueryFromSourceParams",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/drizzle-orm@0.45.2_@opentelemetry+api@1.9.1_kysely@0.29.5_pg@8.18.0_postgres@3.4.9_patch_hash_4ringkigkncd6jisnfxlswcv6m/node_modules/drizzle-orm/sql/sql.js",
|
||||
"line": 70,
|
||||
"weightedMillis": 160.083,
|
||||
"sampledSharePercent": 0.5153507119935007
|
||||
},
|
||||
{
|
||||
"function": "recoveryIdentityMatches",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/live/runnerd-codex-transport.js",
|
||||
"line": 115,
|
||||
"weightedMillis": 159.983,
|
||||
"sampledSharePercent": 0.5150287847982373
|
||||
},
|
||||
{
|
||||
"function": "invoke",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/middleware/idle-admission.js",
|
||||
"line": 118,
|
||||
"weightedMillis": 159.227,
|
||||
"sampledSharePercent": 0.512595015202046
|
||||
},
|
||||
{
|
||||
"function": "layer.handle",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/middleware/idle-admission.js",
|
||||
"line": 156,
|
||||
"weightedMillis": 159.227,
|
||||
"sampledSharePercent": 0.512595015202046
|
||||
},
|
||||
{
|
||||
"function": "router",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/router@2.2.0/node_modules/router/index.js",
|
||||
"line": 59,
|
||||
"weightedMillis": 155.053,
|
||||
"sampledSharePercent": 0.4991577740717519
|
||||
},
|
||||
{
|
||||
"function": "data",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/postgres@3.4.9_patch_hash=6q4cic6qawywsyeo2spgnjamda/node_modules/postgres/src/connection.js",
|
||||
"line": 302,
|
||||
"weightedMillis": 149.056,
|
||||
"sampledSharePercent": 0.4798518001718061
|
||||
},
|
||||
{
|
||||
"function": "getSQL",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/drizzle-orm@0.45.2_@opentelemetry+api@1.9.1_kysely@0.29.5_pg@8.18.0_postgres@3.4.9_patch_hash_4ringkigkncd6jisnfxlswcv6m/node_modules/drizzle-orm/pg-core/query-builders/select.js",
|
||||
"line": 727,
|
||||
"weightedMillis": 140.294,
|
||||
"sampledSharePercent": 0.45164453932282744
|
||||
},
|
||||
{
|
||||
"function": "handle",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/postgres@3.4.9_patch_hash=6q4cic6qawywsyeo2spgnjamda/node_modules/postgres/src/connection.js",
|
||||
"line": 466,
|
||||
"weightedMillis": 138.418,
|
||||
"sampledSharePercent": 0.44560518513968617
|
||||
},
|
||||
{
|
||||
"function": "buildSelectQuery",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/drizzle-orm@0.45.2_@opentelemetry+api@1.9.1_kysely@0.29.5_pg@8.18.0_postgres@3.4.9_patch_hash_4ringkigkncd6jisnfxlswcv6m/node_modules/drizzle-orm/pg-core/dialect.js",
|
||||
"line": 240,
|
||||
"weightedMillis": 134.883,
|
||||
"sampledSharePercent": 0.43422505878712514
|
||||
},
|
||||
{
|
||||
"function": "args.<computed>",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/middleware/idle-admission.js",
|
||||
"line": 133,
|
||||
"weightedMillis": 131.239,
|
||||
"sampledSharePercent": 0.422494031791727
|
||||
},
|
||||
{
|
||||
"function": "nextWrite",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/postgres@3.4.9_patch_hash=6q4cic6qawywsyeo2spgnjamda/node_modules/postgres/src/connection.js",
|
||||
"line": 255,
|
||||
"weightedMillis": 124.865,
|
||||
"sampledSharePercent": 0.4019743923656382
|
||||
},
|
||||
{
|
||||
"function": "recoverActiveExecutions",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/services/heartbeat/recovery.js",
|
||||
"line": 1645,
|
||||
"weightedMillis": 103.554,
|
||||
"sampledSharePercent": 0.3333684877830561
|
||||
},
|
||||
{
|
||||
"function": "readLinuxProcessGroupActivity",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/services/local-service-supervisor.js",
|
||||
"line": 208,
|
||||
"weightedMillis": 94.908,
|
||||
"sampledSharePercent": 0.305534662480583
|
||||
},
|
||||
{
|
||||
"function": "isProcessGroupAlive",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/services/local-service-supervisor.js",
|
||||
"line": 190,
|
||||
"weightedMillis": 94.908,
|
||||
"sampledSharePercent": 0.305534662480583
|
||||
},
|
||||
{
|
||||
"function": "matchLayer",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/router@2.2.0/node_modules/router/index.js",
|
||||
"line": 517,
|
||||
"weightedMillis": 94.37,
|
||||
"sampledSharePercent": 0.3038026941700659
|
||||
}
|
||||
]
|
||||
},
|
||||
{
|
||||
"file": "postfailure-hotqueue-app.cpuprofile",
|
||||
"decompressedSha256": "4b9a0ef0a04e863d076160af1151ef51baead05feaf0231aa45776e51caebf3d",
|
||||
"samples": 19496,
|
||||
"weightedMillis": 30846.88,
|
||||
"self": [
|
||||
{
|
||||
"function": "fsync",
|
||||
"url": "",
|
||||
"line": 0,
|
||||
"weightedMillis": 13998.407,
|
||||
"sampledSharePercent": 45.38030102234002
|
||||
},
|
||||
{
|
||||
"function": "serialize",
|
||||
"url": "file:///home/ubuntu/native-ingestion/helpers/native-ingestion-diagnostic-preload.mjs",
|
||||
"line": 87,
|
||||
"weightedMillis": 6558.807,
|
||||
"sampledSharePercent": 21.26246479384625
|
||||
},
|
||||
{
|
||||
"function": "utf8Write",
|
||||
"url": "node:internal/buffer",
|
||||
"line": 982,
|
||||
"weightedMillis": 2287.385,
|
||||
"sampledSharePercent": 7.415288029129688
|
||||
},
|
||||
{
|
||||
"function": "<anonymous>",
|
||||
"url": "",
|
||||
"line": 0,
|
||||
"weightedMillis": 2106.694,
|
||||
"sampledSharePercent": 6.829520522010654
|
||||
},
|
||||
{
|
||||
"function": "rename",
|
||||
"url": "",
|
||||
"line": 0,
|
||||
"weightedMillis": 1179.849,
|
||||
"sampledSharePercent": 3.8248568412753574
|
||||
},
|
||||
{
|
||||
"function": "(garbage collector)",
|
||||
"url": "",
|
||||
"line": 0,
|
||||
"weightedMillis": 1069.057,
|
||||
"sampledSharePercent": 3.465689236642409
|
||||
},
|
||||
{
|
||||
"function": "<anonymous>",
|
||||
"url": "node:internal/validators",
|
||||
"line": 547,
|
||||
"weightedMillis": 844.865,
|
||||
"sampledSharePercent": 2.7388993635661047
|
||||
},
|
||||
{
|
||||
"function": "<anonymous>",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/live/runnerd-codex-transport.js",
|
||||
"line": 5344,
|
||||
"weightedMillis": 338.32,
|
||||
"sampledSharePercent": 1.0967721857121369
|
||||
},
|
||||
{
|
||||
"function": "writeBuffer",
|
||||
"url": "",
|
||||
"line": 0,
|
||||
"weightedMillis": 118.827,
|
||||
"sampledSharePercent": 0.385215619861717
|
||||
},
|
||||
{
|
||||
"function": "(program)",
|
||||
"url": "",
|
||||
"line": 0,
|
||||
"weightedMillis": 118.335,
|
||||
"sampledSharePercent": 0.38362064494042836
|
||||
},
|
||||
{
|
||||
"function": "getKeyObjectSlots",
|
||||
"url": "node:internal/crypto/keys",
|
||||
"line": 219,
|
||||
"weightedMillis": 103.851,
|
||||
"sampledSharePercent": 0.3366661393307848
|
||||
},
|
||||
{
|
||||
"function": "fchmod",
|
||||
"url": "",
|
||||
"line": 0,
|
||||
"weightedMillis": 91.41,
|
||||
"sampledSharePercent": 0.296334669827224
|
||||
},
|
||||
{
|
||||
"function": "fstat",
|
||||
"url": "",
|
||||
"line": 0,
|
||||
"weightedMillis": 87.082,
|
||||
"sampledSharePercent": 0.28230407743019714
|
||||
},
|
||||
{
|
||||
"function": "<anonymous>",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/control-plane/durable-prp-control-plane.js",
|
||||
"line": 3019,
|
||||
"weightedMillis": 83.088,
|
||||
"sampledSharePercent": 0.26935625256103696
|
||||
},
|
||||
{
|
||||
"function": "decryptSecureJson",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/control-plane/durable-prp-control-plane.js",
|
||||
"line": 893,
|
||||
"weightedMillis": 80.018,
|
||||
"sampledSharePercent": 0.2594038683977115
|
||||
},
|
||||
{
|
||||
"function": "(idle)",
|
||||
"url": "",
|
||||
"line": 0,
|
||||
"weightedMillis": 79.126,
|
||||
"sampledSharePercent": 0.25651216589813947
|
||||
},
|
||||
{
|
||||
"function": "#pumpEvents",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/live/runnerd-codex-transport.js",
|
||||
"line": 5328,
|
||||
"weightedMillis": 79.033,
|
||||
"sampledSharePercent": 0.2562106767361886
|
||||
},
|
||||
{
|
||||
"function": "getSlots",
|
||||
"url": "node:internal/crypto/keys",
|
||||
"line": 1108,
|
||||
"weightedMillis": 70.972,
|
||||
"sampledSharePercent": 0.23007837421483146
|
||||
},
|
||||
{
|
||||
"function": "PgDatabase",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/drizzle-orm@0.45.2_@opentelemetry+api@1.9.1_kysely@0.29.5_pg@8.18.0_postgres@3.4.9_patch_hash_4ringkigkncd6jisnfxlswcv6m/node_modules/drizzle-orm/pg-core/db.js",
|
||||
"line": 17,
|
||||
"weightedMillis": 66.396,
|
||||
"sampledSharePercent": 0.21524381071926885
|
||||
},
|
||||
{
|
||||
"function": "close",
|
||||
"url": "",
|
||||
"line": 0,
|
||||
"weightedMillis": 56.314,
|
||||
"sampledSharePercent": 0.18255979210863466
|
||||
}
|
||||
],
|
||||
"inclusiveFileFrames": [
|
||||
{
|
||||
"function": "withStagedPrivateWrite",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/control-plane/staged-private-write.js",
|
||||
"line": 7,
|
||||
"weightedMillis": 20800.069,
|
||||
"sampledSharePercent": 67.43005775624634
|
||||
},
|
||||
{
|
||||
"function": "syncParentDirectory",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/control-plane/durable-prp-control-plane.js",
|
||||
"line": 982,
|
||||
"weightedMillis": 14832.746,
|
||||
"sampledSharePercent": 48.0850769996836
|
||||
},
|
||||
{
|
||||
"function": "syncWork",
|
||||
"url": "file:///home/ubuntu/native-ingestion/helpers/native-ingestion-diagnostic-preload.mjs",
|
||||
"line": 96,
|
||||
"weightedMillis": 14820.52,
|
||||
"sampledSharePercent": 48.045442521253364
|
||||
},
|
||||
{
|
||||
"function": "#event",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/control-plane/durable-prp-control-plane.js",
|
||||
"line": 2957,
|
||||
"weightedMillis": 7375.811,
|
||||
"sampledSharePercent": 23.911043839765966
|
||||
},
|
||||
{
|
||||
"function": "commitEvent",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/control-plane/durable-prp-control-plane.js",
|
||||
"line": 1118,
|
||||
"weightedMillis": 6876.781,
|
||||
"sampledSharePercent": 22.293278931289
|
||||
},
|
||||
{
|
||||
"function": "serialize",
|
||||
"url": "file:///home/ubuntu/native-ingestion/helpers/native-ingestion-diagnostic-preload.mjs",
|
||||
"line": 87,
|
||||
"weightedMillis": 6674.31,
|
||||
"sampledSharePercent": 21.636904607532433
|
||||
},
|
||||
{
|
||||
"function": "asyncWork",
|
||||
"url": "file:///home/ubuntu/native-ingestion/helpers/native-ingestion-diagnostic-preload.mjs",
|
||||
"line": 102,
|
||||
"weightedMillis": 2476.23,
|
||||
"sampledSharePercent": 8.027489327932031
|
||||
},
|
||||
{
|
||||
"function": "#pumpEventsSafely",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/live/runnerd-codex-transport.js",
|
||||
"line": 5790,
|
||||
"weightedMillis": 454.703,
|
||||
"sampledSharePercent": 1.474064800070542
|
||||
},
|
||||
{
|
||||
"function": "#pumpEvents",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/live/runnerd-codex-transport.js",
|
||||
"line": 5328,
|
||||
"weightedMillis": 452.498,
|
||||
"sampledSharePercent": 1.4669165892952545
|
||||
},
|
||||
{
|
||||
"function": "#handleJson",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/control-plane/durable-prp-control-plane.js",
|
||||
"line": 2126,
|
||||
"weightedMillis": 392.106,
|
||||
"sampledSharePercent": 1.27113665952602
|
||||
},
|
||||
{
|
||||
"function": "sendJson",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/control-plane/durable-prp-control-plane.js",
|
||||
"line": 1349,
|
||||
"weightedMillis": 346.178,
|
||||
"sampledSharePercent": 1.122246398987515
|
||||
},
|
||||
{
|
||||
"function": "#sendJson",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/control-plane/durable-prp-control-plane.js",
|
||||
"line": 1539,
|
||||
"weightedMillis": 346.178,
|
||||
"sampledSharePercent": 1.122246398987515
|
||||
},
|
||||
{
|
||||
"function": "encryptSecureJson",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/control-plane/durable-prp-control-plane.js",
|
||||
"line": 877,
|
||||
"weightedMillis": 243.404,
|
||||
"sampledSharePercent": 0.7890716986612585
|
||||
},
|
||||
{
|
||||
"function": "decryptSecureJson",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/control-plane/durable-prp-control-plane.js",
|
||||
"line": 893,
|
||||
"weightedMillis": 204.594,
|
||||
"sampledSharePercent": 0.6632567053783073
|
||||
},
|
||||
{
|
||||
"function": "pumpNotifications",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/drivers/codex/codex-session-notifications.js",
|
||||
"line": 15,
|
||||
"weightedMillis": 118.523,
|
||||
"sampledSharePercent": 0.38423010690222154
|
||||
},
|
||||
{
|
||||
"function": "mapNotification",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/drivers/codex/codex-session-notifications.js",
|
||||
"line": 34,
|
||||
"weightedMillis": 118.296,
|
||||
"sampledSharePercent": 0.3834942140015457
|
||||
},
|
||||
{
|
||||
"function": "mapNotificationBody",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/drivers/codex/codex-session-notifications.js",
|
||||
"line": 76,
|
||||
"weightedMillis": 116.174,
|
||||
"sampledSharePercent": 0.376615074198752
|
||||
},
|
||||
{
|
||||
"function": "startActiveSpan",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/drizzle-orm@0.45.2_@opentelemetry+api@1.9.1_kysely@0.29.5_pg@8.18.0_postgres@3.4.9_patch_hash_4ringkigkncd6jisnfxlswcv6m/node_modules/drizzle-orm/tracing.js",
|
||||
"line": 6,
|
||||
"weightedMillis": 113.346,
|
||||
"sampledSharePercent": 0.3674472102202881
|
||||
},
|
||||
{
|
||||
"function": "then",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/drizzle-orm@0.45.2_@opentelemetry+api@1.9.1_kysely@0.29.5_pg@8.18.0_postgres@3.4.9_patch_hash_4ringkigkncd6jisnfxlswcv6m/node_modules/drizzle-orm/query-promise.js",
|
||||
"line": 20,
|
||||
"weightedMillis": 105.065,
|
||||
"sampledSharePercent": 0.3406017075308751
|
||||
},
|
||||
{
|
||||
"function": "sendJson",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/control-plane/durable-prp-control-plane.js",
|
||||
"line": 1224,
|
||||
"weightedMillis": 100.048,
|
||||
"sampledSharePercent": 0.324337501880255
|
||||
},
|
||||
{
|
||||
"function": "scope",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/postgres@3.4.9_patch_hash=6q4cic6qawywsyeo2spgnjamda/node_modules/postgres/src/index.js",
|
||||
"line": 270,
|
||||
"weightedMillis": 94.549,
|
||||
"sampledSharePercent": 0.30651073949780333
|
||||
},
|
||||
{
|
||||
"function": "sendText",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/control-plane/durable-prp-control-plane.js",
|
||||
"line": 1227,
|
||||
"weightedMillis": 91.045,
|
||||
"sampledSharePercent": 0.29515140591204037
|
||||
},
|
||||
{
|
||||
"function": "result",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/postgres@3.4.9_patch_hash=6q4cic6qawywsyeo2spgnjamda/node_modules/postgres/src/index.js",
|
||||
"line": 279,
|
||||
"weightedMillis": 90.314,
|
||||
"sampledSharePercent": 0.2927816362627274
|
||||
},
|
||||
{
|
||||
"function": "buildCandidate",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/control-plane/durable-prp-control-plane.js",
|
||||
"line": 3081,
|
||||
"weightedMillis": 84.653,
|
||||
"sampledSharePercent": 0.27442969921107097
|
||||
},
|
||||
{
|
||||
"function": "emit",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/server/dist/vendor/paperclip-runner/drivers/codex/codex-session-state.js",
|
||||
"line": 322,
|
||||
"weightedMillis": 73.384,
|
||||
"sampledSharePercent": 0.23789764151188061
|
||||
},
|
||||
{
|
||||
"function": "PgTransaction",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/drizzle-orm@0.45.2_@opentelemetry+api@1.9.1_kysely@0.29.5_pg@8.18.0_postgres@3.4.9_patch_hash_4ringkigkncd6jisnfxlswcv6m/node_modules/drizzle-orm/pg-core/session.js",
|
||||
"line": 138,
|
||||
"weightedMillis": 71.739,
|
||||
"sampledSharePercent": 0.23256484934618996
|
||||
},
|
||||
{
|
||||
"function": "PostgresJsTransaction",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/drizzle-orm@0.45.2_@opentelemetry+api@1.9.1_kysely@0.29.5_pg@8.18.0_postgres@3.4.9_patch_hash_4ringkigkncd6jisnfxlswcv6m/node_modules/drizzle-orm/postgres-js/session.js",
|
||||
"line": 125,
|
||||
"weightedMillis": 71.739,
|
||||
"sampledSharePercent": 0.23256484934618996
|
||||
},
|
||||
{
|
||||
"function": "PgDatabase",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/drizzle-orm@0.45.2_@opentelemetry+api@1.9.1_kysely@0.29.5_pg@8.18.0_postgres@3.4.9_patch_hash_4ringkigkncd6jisnfxlswcv6m/node_modules/drizzle-orm/pg-core/db.js",
|
||||
"line": 17,
|
||||
"weightedMillis": 70.663,
|
||||
"sampledSharePercent": 0.2290766521606075
|
||||
},
|
||||
{
|
||||
"function": "toQuery",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/drizzle-orm@0.45.2_@opentelemetry+api@1.9.1_kysely@0.29.5_pg@8.18.0_postgres@3.4.9_patch_hash_4ringkigkncd6jisnfxlswcv6m/node_modules/drizzle-orm/sql/sql.js",
|
||||
"line": 60,
|
||||
"weightedMillis": 57.216,
|
||||
"sampledSharePercent": 0.18548391279766382
|
||||
},
|
||||
{
|
||||
"function": "sqlToQuery",
|
||||
"url": "file:///home/ubuntu/native-ingestion/baseline/node_modules/.pnpm/drizzle-orm@0.45.2_@opentelemetry+api@1.9.1_kysely@0.29.5_pg@8.18.0_postgres@3.4.9_patch_hash_4ringkigkncd6jisnfxlswcv6m/node_modules/drizzle-orm/pg-core/dialect.js",
|
||||
"line": 428,
|
||||
"weightedMillis": 57.216,
|
||||
"sampledSharePercent": 0.18548391279766382
|
||||
}
|
||||
]
|
||||
}
|
||||
]
|
||||
}
|
||||
@@ -0,0 +1,32 @@
|
||||
#!/usr/bin/env python3
|
||||
"""Summarize diagnostic app samples, excluding them from performance acceptance."""
|
||||
import gzip
|
||||
import json
|
||||
import pathlib
|
||||
import sys
|
||||
|
||||
if len(sys.argv) != 2:
|
||||
raise SystemExit("Pass one .ndjson or .ndjson.gz diagnostic app metrics file")
|
||||
path = pathlib.Path(sys.argv[1])
|
||||
raw = gzip.decompress(path.read_bytes()) if path.suffix == ".gz" else path.read_bytes()
|
||||
rows = [json.loads(line) for line in raw.splitlines() if line.strip()]
|
||||
samples = [row for row in rows if row.get("kind") == "app-sample"]
|
||||
if not samples:
|
||||
raise SystemExit("No app samples found")
|
||||
print(json.dumps({
|
||||
"scope": "Instrumented failed historical local-process baseline replay; no acceptance comparison",
|
||||
"sampleCount": len(samples),
|
||||
"firstAtMs": samples[0]["atMs"],
|
||||
"lastAtMs": samples[-1]["atMs"],
|
||||
"sampleSpanMs": samples[-1]["atMs"] - samples[0]["atMs"],
|
||||
"maxObservedNormalizedQueueDepth": max(row["actualNormalizedQueueDepth"] for row in samples),
|
||||
"maxObservedRssBytes": max(row["rssBytes"] for row in samples),
|
||||
"lastSample": samples[-1],
|
||||
"limits": [
|
||||
"Queue counts the normalized upstream queue, excluding collector/pending-read/in-flight/transport queues",
|
||||
"Observed peaks are sample based",
|
||||
"Cumulative filesystem elapsed times overlap across async operations and include scheduling; do not sum or interpret async sync elapsed as blocked CPU",
|
||||
"Serialization elapsed ends before byte-counting probe; sampled wrapper residence includes byte counting",
|
||||
"Diagnostic instrumentation and its observer work are excluded from acceptance",
|
||||
],
|
||||
}, indent=2))
|
||||
@@ -0,0 +1,61 @@
|
||||
#!/usr/bin/env python3
|
||||
"""Describe sealed V8 profiles; sampled stack time is not process CPU usage."""
|
||||
import collections
|
||||
import gzip
|
||||
import hashlib
|
||||
import json
|
||||
import pathlib
|
||||
import sys
|
||||
|
||||
if len(sys.argv) < 2:
|
||||
raise SystemExit("Pass one or more .cpuprofile or .cpuprofile.gz paths")
|
||||
|
||||
reports = []
|
||||
for argument in sys.argv[1:]:
|
||||
path = pathlib.Path(argument)
|
||||
raw = path.read_bytes()
|
||||
if path.suffix == ".gz":
|
||||
raw = gzip.decompress(raw)
|
||||
profile = json.loads(raw)
|
||||
nodes = {node["id"]: node for node in profile["nodes"]}
|
||||
parents = {child: node["id"] for node in nodes.values() for child in node.get("children", [])}
|
||||
assert len(profile["samples"]) == len(profile["timeDeltas"])
|
||||
own, inclusive = collections.Counter(), collections.Counter()
|
||||
|
||||
def frame(node_id):
|
||||
value = nodes[node_id]["callFrame"]
|
||||
return (value["functionName"] or "<anonymous>", value["url"], value["lineNumber"] + 1)
|
||||
|
||||
for node_id, duration in zip(profile["samples"], profile["timeDeltas"]):
|
||||
assert duration >= 0
|
||||
own[frame(node_id)] += duration
|
||||
seen = set()
|
||||
while node_id in nodes:
|
||||
key = frame(node_id)
|
||||
if key not in seen:
|
||||
inclusive[key] += duration
|
||||
seen.add(key)
|
||||
if node_id not in parents:
|
||||
break
|
||||
node_id = parents[node_id]
|
||||
total = sum(profile["timeDeltas"])
|
||||
assert total > 0
|
||||
|
||||
def ranked(counter, limit):
|
||||
return [{"function": key[0], "url": key[1], "line": key[2],
|
||||
"weightedMillis": duration / 1000, "sampledSharePercent": duration * 100 / total}
|
||||
for key, duration in counter.most_common(limit)]
|
||||
|
||||
application = collections.Counter({key: value for key, value in inclusive.items()
|
||||
if key[1].startswith("file:") and key[0] != "<anonymous>"})
|
||||
reports.append({"file": path.name.removesuffix(".gz"), "decompressedSha256": hashlib.sha256(raw).hexdigest(),
|
||||
"samples": len(profile["samples"]), "weightedMillis": total / 1000,
|
||||
"self": ranked(own, 20), "inclusiveFileFrames": ranked(application, 30)})
|
||||
|
||||
print(json.dumps({"scope": "Diagnostic only; no performance acceptance claim",
|
||||
"method": "Weight each sampled frame by its corresponding V8 timeDelta; inclusive frames deduplicate recursion",
|
||||
"limits": ["Includes idle and native blocking time; this is not process CPU usage",
|
||||
"Inclusive frames overlap and must not be summed",
|
||||
"Instrumented wrapper residence can include byte counting or other probe work",
|
||||
"Instrumentation and failed-run phases must remain identified"],
|
||||
"profiles": reports}, indent=2))
|
||||
Reference in new issue
Block a user