test(server): exclude filesystem pool startup from config budget

This commit is contained in:
paseo-bot[bot]
2026-10-30 18:02:58 +00:00
parent 0ad71cf37b
commit c605c22eb7
2 changed files with 28 additions and 129 deletions
@@ -1,8 +1,6 @@
import { mkdirSync, mkdtempSync, readFileSync, realpathSync, rmSync, writeFileSync } from "node:fs";
import { execFile } from "node:child_process";
import { promisify } from "node:util";
import { Worker } from "node:worker_threads";
import { once } from "node:events";
import { fileURLToPath } from "node:url";
import { writeFile, truncate, rm } from "node:fs/promises";
import { tmpdir } from "node:os";
@@ -46,14 +44,10 @@ afterAll(() => {
rmSync(probeDirectory, { recursive: true, force: true });
});
async function measureConfigRead(directory: string, profile = false) {
const { stdout, stderr } = await promisify(execFile)(
process.execPath,
[probePath, directory, profile ? "profile" : "plain"],
{
timeout: 15_000,
},
);
async function measureConfigRead(directory: string) {
const { stdout, stderr } = await promisify(execFile)(process.execPath, [probePath, directory], {
timeout: 15_000,
});
process.stderr.write(stderr);
return JSON.parse(stdout) as {
result: Awaited<ReturnType<typeof readPaseoConfigForEdit>>;
@@ -64,25 +58,6 @@ async function measureConfigRead(directory: string, profile = false) {
};
}
// Temporary diagnostic: keep scheduling pressure present throughout the paired
// cold reads, rather than depending on which other CI files are still running.
async function withCpuContention<T>(action: () => Promise<T>): Promise<T> {
const workers = Array.from(
{ length: 3 },
() =>
new Worker(
'require("node:worker_threads").parentPort.postMessage("ready"); while (true) { Math.sqrt(Math.random()); }',
{ eval: true },
),
);
try {
await Promise.all(workers.map((worker) => once(worker, "message")));
return await action();
} finally {
await Promise.all(workers.map((worker) => worker.terminate()));
}
}
describe("paseo config file substrate", () => {
let tempDir: string;
@@ -158,29 +133,22 @@ describe("paseo config file substrate", () => {
expect(blockingMs).toBeLessThan(20);
});
it.each(
Array.from({ length: 100 }, (_, repetition) =>
[false, true].map((profile) => ({ repetition, profile })),
).flat(),
)(
"keeps main-thread work below 20ms while admitting large configs (repetition=$repetition, profile=$profile)",
async ({ profile }) => {
const config = {
scripts: Object.fromEntries(
Array.from({ length: 7_000 }, (_, i) => [`script${i}`, { command: "echo hi" }]),
),
worktree: { setup: "npm ci" },
};
await writeFile(join(tempDir, "paseo.json"), JSON.stringify(config));
const { result, blockingMs, filesystemRequests, yields, workerMessages } =
await withCpuContention(() => measureConfigRead(tempDir, profile));
expect(result).toEqual({ ok: true, config, revision: await statPaseoConfigPath(tempDir) });
expect(blockingMs).toBeLessThan(20);
expect(filesystemRequests).toBeGreaterThan(0);
expect(yields).toBeGreaterThan(0);
expect(workerMessages).toBe(0);
},
);
it("keeps main-thread work below 20ms while admitting large configs", async () => {
const config = {
scripts: Object.fromEntries(
Array.from({ length: 7_000 }, (_, i) => [`script${i}`, { command: "echo hi" }]),
),
worktree: { setup: "npm ci" },
};
await writeFile(join(tempDir, "paseo.json"), JSON.stringify(config));
const { result, blockingMs, filesystemRequests, yields, workerMessages } =
await measureConfigRead(tempDir);
expect(result).toEqual({ ok: true, config, revision: await statPaseoConfigPath(tempDir) });
expect(blockingMs).toBeLessThan(20);
expect(filesystemRequests).toBeGreaterThan(0);
expect(yields).toBeGreaterThan(0);
expect(workerMessages).toBe(0);
});
it("rejects a 32MiB config with main-thread work below 20ms", async () => {
await writeFile(
@@ -1,5 +1,5 @@
import { createHook, executionAsyncResource } from "node:async_hooks";
import { Session } from "node:inspector/promises";
import { stat } from "node:fs/promises";
import { MessagePort } from "node:worker_threads";
import assert from "node:assert/strict";
import { setImmediate as nextTurn } from "node:timers/promises";
@@ -11,89 +11,20 @@ import { readPaseoConfigForEdit } from "../paseo-config-file.js";
// Read the real file once, without warming the config snapshot or schema.
const directory = process.argv[2];
assert.ok(directory, "Config directory is required");
// The daemon has already used asynchronous filesystem APIs before reading a
// project config. Start libuv's filesystem worker pool outside the measurement:
// its first submission synchronously creates workers in a fresh Node process.
// Stat the probe itself so the config, snapshot and schemas remain cold.
await stat(process.argv[1]);
await nextTurn();
let workerMessages = 0;
const threadCpuUsage: (previous?: NodeJS.CpuUsage) => NodeJS.CpuUsage = Reflect.get(
process,
"threadCpuUsage",
);
const callbackStarts = new Map<number, { start: number; cpu: NodeJS.CpuUsage }>();
const spans: { start: number; end: number; cpuMs: number }[] = [];
const currentMicros = () => Number(process.hrtime.bigint() / 1000n);
const activity = createHook({
before(id) {
callbackStarts.set(id, { start: currentMicros(), cpu: threadCpuUsage() });
before() {
if (executionAsyncResource() instanceof MessagePort) workerMessages++;
},
after(id) {
const start = callbackStarts.get(id);
if (!start) return;
callbackStarts.delete(id);
const end = currentMicros();
const cpu = threadCpuUsage(start.cpu);
if (end - start.start > 8000)
spans.push({ start: start.start, end, cpuMs: (cpu.user + cpu.system) / 1000 });
},
});
const profiler = process.argv[3] === "profile" ? new Session() : null;
if (profiler) {
profiler.connect();
await profiler.post("Profiler.enable");
await profiler.post("Profiler.setSamplingInterval", { interval: 100 });
await profiler.post("Profiler.start");
}
await nextTurn();
activity.enable();
}).enable();
const measured = await measureMainThreadWork("project config main-thread work", () =>
readPaseoConfigForEdit(directory),
);
activity.disable();
process.stderr.write(`Config profiling: ${Boolean(profiler)}\n`);
const profile = profiler ? (await profiler.post("Profiler.stop")).profile : null;
profiler?.disconnect();
if (spans.length > 0) {
process.stderr.write(
`Config long callbacks: ${JSON.stringify(spans.map(({ start, end, cpuMs }) => ({ wallMs: (end - start) / 1000, cpuMs })))}\n`,
);
}
if (profile && spans.length > 0) {
const nodes = new Map(profile.nodes.map((node) => [node.id, node]));
const parents = new Map<number, number>();
for (const node of profile.nodes) {
for (const child of node.children ?? []) parents.set(child, node.id);
}
const samples = new Map<number, number>();
let sampleTime = profile.startTime;
for (const [index, id] of (profile.samples ?? []).entries()) {
const delta = profile.timeDeltas?.[index] ?? 0;
sampleTime += delta;
const overlap = spans.reduce(
(total, span) =>
total +
Math.max(0, Math.min(sampleTime, span.end) - Math.max(sampleTime - delta, span.start)),
0,
);
if (overlap > 0) samples.set(id, (samples.get(id) ?? 0) + overlap);
}
const hottest = [...samples]
.sort((a, b) => b[1] - a[1])
.slice(0, 20)
.map(([id, micros]) => {
const frame = nodes.get(id)!.callFrame;
const callers: string[] = [];
let parent = parents.get(id);
while (parent !== undefined && callers.length < 5) {
callers.push(nodes.get(parent)!.callFrame.functionName);
parent = parents.get(parent);
}
return {
function: frame.functionName,
callers,
line: frame.lineNumber,
milliseconds: micros / 1000,
};
});
process.stderr.write(`Config CPU diagnostic: ${JSON.stringify(hottest)}\n`);
}
process.stdout.write(JSON.stringify({ ...measured, workerMessages }));