test(experiment): measure queued and repeated native reads

Compare sequential and overlapping requests through both real MCP adapters
with the same preserved engine, selected instruction windows and full graph.
Retain the unexplained model-run anomaly without claiming a speed fix.

Co-authored-by: gensokyo-dev <342580529+gensokyo-dev@users.noreply.github.com>
Co-authored-by: Kaoru0822 <208281322+kaoru0822-kitauji@users.noreply.github.com>
This commit is contained in:
committed 2026-10-16 14:25:22 +00:00
1 parent 4882f6b5dc
commit 29e0472812
5 files changed
+257 -17

No files matched your search

@@ -0,0 +1,21 @@
// Read-only kernel counters for the currently bounded diagnostic payload.
import assert from "node:assert/strict";
import { readFile } from "node:fs/promises";
export async function familyCounters() {
const group = (await readFile("/proc/self/cgroup", "utf8"))
.split("\n")
.find((row) => row.startsWith("0::"))
?.slice(3);
assert.ok(group?.includes("rea-efficiency-"), "Run under resource-run.py");
const cpu = (await readFile(`/sys/fs/cgroup${group}/cpu.stat`, "utf8")).match(
/^usage_usec (\d+)$/mu,
);
assert.ok(cpu, "Missing cgroup CPU counter");
return {
cpu: Number(cpu[1]),
peak: Number(
(await readFile(`/sys/fs/cgroup${group}/memory.peak`, "utf8")).trim(),
),
};
}
@@ -0,0 +1,52 @@
# Sequential and overlapping public requests
This follows the unexplained 107.804-second source capture in the
[guided model pair](savepoint-control-study.md). The same preserved `677b9795...`
engine, target digest, VM entry and three instruction windows are used through
real stdio MCP. Each case starts a fresh lease/private native cache; cases run
serially in code/sequential, direct/overlap, direct/sequential, code/overlap order.
No model is involved and no token savings are inferred.
`verify-overlap.mjs` first requests one full VM capture and the windows, either
sequentially or with the second request starting 100 ms after the first. The
client records starts/finishes to prove request overlap; it does not assume
provider concurrency. `AtomicSession.call` serializes provider admission for
both adapters. Thus an instruction request can wait behind the snapshot. Its
API wall time is not its native command execution time.
Every full recovered graph and ordinary function field matches the complete
golden. Selected instruction items/coverage agree across all four cases. Both
snapshot and instruction reads repeat under the same retained Evidence and
handle. Target/frame/decoding selection and all limits are preserved.
| Case | Fresh task seconds | Fresh family CPU s | VM capture s | Warm task ms | Warm family CPU s |
| ------------------ | -----------------: | -----------------: | -----------: | -----------: | ----------------: |
| Code, sequential | 39.488 | 39.432 | 37.112 | 43.737 | 0.044 |
| Direct, overlap | 38.931 | 38.865 | 36.635 | 6.561 | 0.007 |
| Direct, sequential | 39.171 | 39.098 | 36.987 | 7.759 | 0.008 |
| Code, overlap | 40.616 | 40.564 | 38.262 | 32.288 | 0.033 |
CPU is a delta over each complete phase in the owned cgroup; no overlapping
per-request CPU attribution is attempted. Kernel peaks are cumulative and
include charged file cache, not RSS; the warm peak is only an upper bound.
Complete family totals/peaks and cleanup counters are in the resource receipts
under `.cache/atomic-codemode/overlap-v1-*`. One CPU, 4 GiB hard / 3 GiB early-stop,
192-task bounds apply. All four cases have verified cleanup, no abort and OOM 0.
| Case | Whole family wall s | Whole family CPU s | Kernel peak MiB |
| ------------------ | ------------------: | -----------------: | --------------: |
| Code, sequential | 41.299 | 41.026 | 623.1 |
| Direct, overlap | 40.695 | 40.427 | 616.2 |
| Direct, sequential | 40.893 | 40.660 | 617.6 |
| Code, overlap | 42.506 | 42.239 | 630.0 |
The 108-second capture does not reproduce in this matched sample. Request
queueing is confirmed by the owner and explains waiting outside native source
times; it does not explain the original long capture itself. There is no basis
to change provider concurrency or claim a native speed fix. Host contention,
OS caches and unrecorded native phases remain uncontrolled/unmeasured. This is
a four-case diagnostic, not a distribution or proof that the anomaly is fixed.
Both repeated tasks are small; Code Mode's additional guest setup is visible
here. This is not evidence against composition over a larger dependency graph,
nor a comparison with a client that lacks its own JavaScript executor.
@@ -162,3 +162,6 @@ be examined before exporting case-to-edge/target relations; a successor ordinal
is not a case value. This is a fact-export limitation, not evidence that Kuna
itself cannot recover the labels. The source-capture/concurrent-read cost
variation also needs a bounded, matched diagnostic before further speed claims.
The [subsequent four-case public MCP diagnostic](overlap-study.md) confirms
provider admission is serialized and does not reproduce the long capture;
the original cause remains unknown rather than being declared fixed.
+2 -17
View File
@@ -1,9 +1,10 @@
// A real MCP cold/warm read benchmark. No model runs in this verifier.
import assert from "node:assert/strict";
import { readFile, writeFile } from "node:fs/promises";
import { writeFile } from "node:fs/promises";
import { resolve } from "node:path";
import { Client } from "@modelcontextprotocol/client";
import { StdioClientTransport } from "@modelcontextprotocol/client/stdio";
import { familyCounters as counters } from "./family-counters.mjs";
import {
createVerifierRun,
completeVerifierRun,
@@ -11,22 +12,6 @@ import {
} from "../../scripts/lib/verifier-run.mjs";
const [binary, output, entry = "0xc1e0"] = process.argv.slice(2);
const group = (await readFile("/proc/self/cgroup", "utf8"))
.trim()
.split("\n")
.find((row) => row.startsWith("0::"))
?.slice(3);
assert.ok(group?.includes("rea-efficiency-"), "Run under resource-run.py");
const counters = async () => ({
cpu: Number(
(await readFile(`/sys/fs/cgroup${group}/cpu.stat`, "utf8")).match(
/usage_usec (\d+)/u,
)[1],
),
peak: Number(
(await readFile(`/sys/fs/cgroup${group}/memory.peak`, "utf8")).trim(),
),
});
const verifier = createVerifierRun();
const client = new Client({ name: "rea-cache-verifier", version: "0.1.0" });
const transport = new StdioClientTransport({
@@ -0,0 +1,179 @@
// Matched public MCP reads, without a model or changes to the native engine.
import assert from "node:assert/strict";
import { readFile, writeFile } from "node:fs/promises";
import { resolve, join } from "node:path";
import { setTimeout as delay } from "node:timers/promises";
import { Client } from "@modelcontextprotocol/client";
import { StdioClientTransport } from "@modelcontextprotocol/client/stdio";
import { familyCounters } from "./family-counters.mjs";
import { readNativeGraphEvidence } from "./native-ir-contract.mjs";
import {
createVerifierRun,
completeVerifierRun,
assertVerifierCleanupComplete,
} from "../../scripts/lib/verifier-run.mjs";
const [binary, output, route, ordering, goldenPath] = process.argv.slice(2);
assert.ok(["direct", "code"].includes(route));
assert.ok(["sequential", "overlap"].includes(ordering));
assert.equal(
process.versions.node,
(await readFile(resolve(".nvmrc"), "utf8")).trim(),
);
assert.ok(
process.env.REA_ATOMIC_EVIDENCE_DIR,
"Retain exact source for fidelity checks",
);
const golden = JSON.parse(await readFile(goldenPath, "utf8")).functions[0];
const windows = [
{ address: "0xf2360", count: 18 },
{ address: "0xf2410", count: 22 },
{ address: "0x288f0", count: 3 },
];
const run = createVerifierRun();
const client = new Client({ name: "rea-overlap-verifier", version: "0.1.0" });
const transport = new StdioClientTransport({
command: process.execPath,
args: [resolve("experiments/atomic-codemode/server.mjs")],
env: {
...process.env,
REA_ATOMIC_ADAPTER: route === "direct" ? "direct" : "code",
},
stderr: "pipe",
});
const failures = [],
phases = [],
requests = [];
const epoch = performance.now();
async function tool(name, input) {
const reply = await client.callTool(
{ name, arguments: input },
{ timeout: 180000 },
);
const value = JSON.parse(reply.content[0].text);
assert.equal(value.ok, true, JSON.stringify(value));
return value;
}
async function read(name, input) {
const record = { method: name, started_ms: performance.now() - epoch };
requests.push(record);
const response =
route === "direct"
? await tool(`facts_${name}`, input)
: (
await tool("execute_javascript", {
code: `return await rea.${name}(${JSON.stringify(input)});`,
})
).value;
record.finished_ms = performance.now() - epoch;
record.elapsed_ms = record.finished_ms - record.started_ms;
assert.equal(response.ok, true, JSON.stringify(response));
return response.data;
}
async function measured(phase, work) {
const before = await familyCounters(),
started = performance.now();
const value = await work();
const elapsed_ms = performance.now() - started,
after = await familyCounters();
phases.push({
phase,
elapsed_ms,
family_cpu_seconds: (after.cpu - before.cpu) / 1e6,
cumulative_family_memory_peak_bytes: after.peak,
});
return value;
}
let observations;
try {
await client.connect(transport);
const opened = await tool("open_binary", { path: binary });
assert.equal(
opened.context.artifact_sha256,
"2e6eef9a727f081f0d453b4e5e6cbd8b9ef8b6f86cbf7681cbad444d3b0b55c8",
);
const [snapshot, instructions] = await measured("fresh-lease", async () => {
if (ordering === "sequential")
return [
await read("snapshot", { entry: "0xea6d0" }),
await read("instructions", { windows }),
];
const pending = read("snapshot", { entry: "0xea6d0" });
// Deliberately overlap requests, not native processes: the session owns admission.
// Attach rejection handling immediately even if the second request fails.
const pair = Promise.all([
pending,
(async () => {
await delay(100);
return read("instructions", { windows });
})(),
]);
return pair;
});
assert.equal(snapshot.facets.recovered_ir.availability, "available");
assert.equal(snapshot.coverage.operations, 21349);
assert.equal(snapshot.coverage.omitted_definition_count, 0);
assert.equal(instructions.results.length, windows.length);
for (const item of instructions.results) assert.equal(item.ok, true);
const warm = await measured("same-lease-reuse", async () => [
await read("snapshot", { entry: "0xea6d0" }),
await read("instructions", { windows }),
]);
assert.deepEqual(warm, [snapshot, instructions]);
const source = await readFile(
join(
process.env.REA_ATOMIC_EVIDENCE_DIR,
`${snapshot.source.evidence_id}.txt`,
),
"utf8",
);
const { atomic_facts: _archive, ...ordinary } =
JSON.parse(source).functions[0];
const { atomic_facts: expectedGraph, ...expectedOrdinary } = golden;
assert.deepEqual(
JSON.parse(readNativeGraphEvidence(source).text),
expectedGraph,
);
assert.deepEqual(ordinary, expectedOrdinary);
const first = requests[0],
second = requests[1];
assert.equal(second.started_ms < first.finished_ms, ordering === "overlap");
observations = {
snapshot,
instructions,
source_fidelity: "full-graph-and-ordinary-fields-match-golden",
};
await tool("close_binary", {});
} catch (error) {
failures.push(error.stack ?? String(error));
} finally {
try {
await client.close();
} catch (error) {
failures.push(String(error));
}
try {
await transport.close();
} catch (error) {
failures.push(String(error));
}
}
const lifecycle = await completeVerifierRun(run);
assertVerifierCleanupComplete(lifecycle.process_lineage);
await writeFile(
output,
JSON.stringify({
route,
ordering,
phases,
requests,
observations,
failures,
lifecycle,
scope:
"Real MCP, same pinned engine and fresh lease/cache per run; no model/token measurement. Request overlap is observed at the client; AtomicSession serializes provider admission. Source elapsed includes command supervision/retention, not isolated native execution. CPU deltas cover each whole phase, not overlapping per-request attribution. Peak includes file cache and is cumulative; warm peak is an upper bound. OS caches and host contention are uncontrolled.",
}),
{ flag: "wx" },
);
console.log(JSON.stringify({ output, route, ordering, phases, failures }));
if (failures.length) process.exitCode = 1;