test(server): compare profiled and plain config reads on Windows

packages/server/src/utils/paseo-config-file.test.ts

@@ -44,10 +44,14 @@ afterAll(() => {
   rmSync(probeDirectory, { recursive: true, force: true });
 });
 
-async function measureConfigRead(directory: string) {
-  const { stdout, stderr } = await promisify(execFile)(process.execPath, [probePath, directory], {
-    timeout: 15_000,
-  });
+async function measureConfigRead(directory: string, profile = false) {
+  const { stdout, stderr } = await promisify(execFile)(
+    process.execPath,
+    [probePath, directory, profile ? "profile" : "plain"],
+    {
+      timeout: 15_000,
+    },
+  );
   process.stderr.write(stderr);
   return JSON.parse(stdout) as {
     result: Awaited<ReturnType<typeof readPaseoConfigForEdit>>;
@@ -133,22 +137,29 @@ describe("paseo config file substrate", () => {
     expect(blockingMs).toBeLessThan(20);
   });
 
-  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.each(
+    Array.from({ length: 150 }, (_, 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 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("rejects a 32MiB config with main-thread work below 20ms", async () => {
     await writeFile(

packages/server/src/utils/test-fixtures/config-responsiveness.ts

@@ -1,4 +1,5 @@
 import { createHook, executionAsyncResource } from "node:async_hooks";
+import { Session } from "node:inspector/promises";
 import { MessagePort } from "node:worker_threads";
 import assert from "node:assert/strict";
 import { setImmediate as nextTurn } from "node:timers/promises";
@@ -17,8 +18,48 @@ const activity = createHook({
     if (executionAsyncResource() instanceof MessagePort) workerMessages++;
   },
 }).enable();
+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");
+}
 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 (profile && measured.blockingMs >= 20) {
+  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>();
+  for (const [index, id] of (profile.samples ?? []).entries()) {
+    samples.set(id, (samples.get(id) ?? 0) + (profile.timeDeltas?.[index] ?? 0));
+  }
+  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 }));