morluto/rea

Fork 0

mirror of https://github.com/morluto/rea.git synced 2026-11-05 06:45:22 +00:00

[GH-ISSUE #1685] perf(mcp): reduce Windows startup module-resolution I/O #567

New issue

Open

opened 2026-10-15 18:26:13 +00:00 by bsakaguchi · 7 comments

bsakaguchi commented

2026-10-15 18:26:13 +00:00

Owner

Originally created by @N0zoM1z0 on GitHub (Oct 11, 2026).
Original GitHub issue: https://github.com/morluto/rea/issues/1685

A source-built REA 6.3.0 package takes 45–53 seconds to initialize an ordinary Windows stdio MCP connection before selecting a target or starting Ghidra. A server CPU profile analyzed with Flameox points to filesystem checks in Node module resolution as the first optimization hypothesis.

Observed package revision: f88c99021b88ce67e513025901f57478d8107d0c. This is a locally built main package, not a claim about a new npm release. The dispatcher, startup transport and optional-provider composition are unchanged through current main 17f704050f431c195ba2280aca162e698aea408a; that merged head has not been timed in this Windows capture.

Phase	Without profiler	With server CPU profiler
Connect and initialize	45,266.6 ms	53,222.8 ms
First explicit complete tools/list	878.6 ms	1,088.8 ms
Repeat complete tools/list	168.0 ms	175.2 ms
No-target binary_session, including client work	5,970.6 ms	6,711.9 ms
Following ping	4.3 ms	2.8 ms

These are separate single observations with profiler overhead and host noise, not an effect estimate or cold/warm percentile comparison. Both sessions discover all 170 tools, complete normally, and leave no observed owned processes. No Java process starts. The profiled client/server family peaks at 469,106,688 bytes under a 3 GiB guard with two CPUs, BelowNormal priority and a 768 MiB Node heap.

Flameox 0.2.9 rank_cpu_hotspots analyzes the unchanged Node 22.19.0 --cpu-prof artifact:

25,718 exported samples; 11,107 in internalModuleStat and 6,477 in lstat (68.4% of all samples combined).
The dominant native call trees are finalizeResolution → internalModuleStat and finalizeResolution → realpathSync → lstat in Node's ESM loader. CJS resolution also appears.
These are sampled stack counts, including synchronous native waits, not CPU utilization or measured syscall counts. The profile covers the whole server lifetime, not just initialization.
The first bounded Flameox page returns 100 of 1,475 observed hotspot rows; it is explicitly partial. Native bytes and the canonical analysis are preserved locally. SHA-256: f4b614a45fcc275dd51dd8c849d5add19d04bc6c7b1fd1b144e9b3b754558cdc.

Reproduce with an ordinary production installation and the pinned MCP client SDK 2.3.1: launch node <rea-package>/scripts/rea.mjs mcp, separately time client.connect, two complete listTools calls, a no-target binary_session, and a following ping, then close the connection. For server attribution, add --cpu-prof --cpu-prof-dir=<owned-profile-directory> --cpu-prof-name=server.cpuprofile before the dispatcher and analyze that exact file with flameox analyze rank_cpu_hotspots <absolute-profile-path> --format cpuprofile.

Investigate reducing the module-resolution work performed before initialization, with a before/after experiment and the same complete catalog and schema validation. Any packaging change must preserve module/resource locations, optional provider failures, worker and native-helper entrypoints, semantic identities and owned shutdown. Do not make symlink-handling flags a product default from this profile alone.

This is separate from #1048 (Ghidra launch/import/auto-analysis) and the client output-validator work in #1065. There is no causal attribution to antivirus or any particular provider yet.

Originally created by @N0zoM1z0 on GitHub (Oct 11, 2026). Original GitHub issue: https://github.com/morluto/rea/issues/1685 A source-built REA 6.3.0 package takes 45–53 seconds to initialize an ordinary Windows stdio MCP connection before selecting a target or starting Ghidra. A server CPU profile analyzed with Flameox points to filesystem checks in Node module resolution as the first optimization hypothesis. Observed package revision: `f88c99021b88ce67e513025901f57478d8107d0c`. This is a locally built main package, not a claim about a new npm release. The dispatcher, startup transport and optional-provider composition are unchanged through current main `17f704050f431c195ba2280aca162e698aea408a`; that merged head has not been timed in this Windows capture. | Phase | Without profiler | With server CPU profiler | | --- | ---: | ---: | | Connect and initialize | 45,266.6 ms | 53,222.8 ms | | First explicit complete tools/list | 878.6 ms | 1,088.8 ms | | Repeat complete tools/list | 168.0 ms | 175.2 ms | | No-target binary_session, including client work | 5,970.6 ms | 6,711.9 ms | | Following ping | 4.3 ms | 2.8 ms | These are separate single observations with profiler overhead and host noise, not an effect estimate or cold/warm percentile comparison. Both sessions discover all 170 tools, complete normally, and leave no observed owned processes. No Java process starts. The profiled client/server family peaks at 469,106,688 bytes under a 3 GiB guard with two CPUs, BelowNormal priority and a 768 MiB Node heap. Flameox 0.2.9 `rank_cpu_hotspots` analyzes the unchanged Node 22.19.0 `--cpu-prof` artifact: - 25,718 exported samples; 11,107 in `internalModuleStat` and 6,477 in `lstat` (68.4% of all samples combined). - The dominant native call trees are `finalizeResolution → internalModuleStat` and `finalizeResolution → realpathSync → lstat` in Node's ESM loader. CJS resolution also appears. - These are sampled stack counts, including synchronous native waits, not CPU utilization or measured syscall counts. The profile covers the whole server lifetime, not just initialization. - The first bounded Flameox page returns 100 of 1,475 observed hotspot rows; it is explicitly partial. Native bytes and the canonical analysis are preserved locally. SHA-256: `f4b614a45fcc275dd51dd8c849d5add19d04bc6c7b1fd1b144e9b3b754558cdc`. Reproduce with an ordinary production installation and the pinned MCP client SDK 2.3.1: launch `node <rea-package>/scripts/rea.mjs mcp`, separately time `client.connect`, two complete `listTools` calls, a no-target `binary_session`, and a following ping, then close the connection. For server attribution, add `--cpu-prof --cpu-prof-dir=<owned-profile-directory> --cpu-prof-name=server.cpuprofile` before the dispatcher and analyze that exact file with `flameox analyze rank_cpu_hotspots <absolute-profile-path> --format cpuprofile`. Investigate reducing the module-resolution work performed before initialization, with a before/after experiment and the same complete catalog and schema validation. Any packaging change must preserve module/resource locations, optional provider failures, worker and native-helper entrypoints, semantic identities and owned shutdown. Do not make symlink-handling flags a product default from this profile alone. This is separate from #1048 (Ghidra launch/import/auto-analysis) and the client output-validator work in #1065. There is no causal attribution to antivirus or any particular provider yet.

bsakaguchi added the

labels

2026-10-15 18:26:13 +00:00

bsakaguchi commented

2026-10-15 18:26:14 +00:00

Author

Owner

@elkahtersidi commented on GitHub (Oct 11, 2026):

@elkahtersidi commented on GitHub (Oct 11, 2026): Cv

bsakaguchi commented

2026-10-15 18:26:14 +00:00

Author

Owner

@elkahtersidi commented on GitHub (Oct 11, 2026):

سلام عليكم

@elkahtersidi commented on GitHub (Oct 11, 2026): سلام عليكم

bsakaguchi commented

2026-10-15 18:26:14 +00:00

Author

Owner

@kaoru0822-kitauji commented on GitHub (Oct 11, 2026):

Addressed in #1691.

Before initialize, MCP startup resolved 1,598 modules (6,076 resolutions). It now resolves 1,312 (4,902), and playwright-core (279 modules, CommonJS internally) is no longer loaded.
Cause 1: imports used only for types compiled to import {} from "…" side-effect imports under verbatimModuleSyntax. There were 78, one of them for playwright-core. They're fixed, and typescript/no-import-type-side-effects is now enforced.
Cause 2: Playwright's chromium / _electron launchers were bound when the module loaded. They're now loaded when a capture launches.
A new stdio boundary test asserts that initialize plus a complete tools/list never resolves playwright-core.

Not verified: the Windows timing from this report. On macOS, client.connect dropped from ~490 ms to ~400 ms, and the catalog is still 170 tools. Most of the remaining resolutions are REA's own dist/ graph (959 modules); reducing that further would need a packaging change, which this PR deliberately doesn't make. Please reopen if a Windows re-measurement on #1691 still shows unacceptable startup time.

@kaoru0822-kitauji commented on GitHub (Oct 11, 2026): Addressed in #1691. - Before initialize, MCP startup resolved 1,598 modules (6,076 resolutions). It now resolves 1,312 (4,902), and `playwright-core` (279 modules, CommonJS internally) is no longer loaded. - Cause 1: imports used only for types compiled to `import {} from "…"` side-effect imports under `verbatimModuleSyntax`. There were 78, one of them for `playwright-core`. They're fixed, and `typescript/no-import-type-side-effects` is now enforced. - Cause 2: Playwright's `chromium` / `_electron` launchers were bound when the module loaded. They're now loaded when a capture launches. - A new stdio boundary test asserts that `initialize` plus a complete `tools/list` never resolves `playwright-core`. Not verified: the Windows timing from this report. On macOS, `client.connect` dropped from ~490 ms to ~400 ms, and the catalog is still 170 tools. Most of the remaining resolutions are REA's own `dist/` graph (959 modules); reducing that further would need a packaging change, which this PR deliberately doesn't make. Please reopen if a Windows re-measurement on #1691 still shows unacceptable startup time.

bsakaguchi commented

2026-10-15 18:26:14 +00:00

Author

Owner

@N0zoM1z0 commented on GitHub (Oct 11, 2026):

Actual Windows acceptance with #1691 integrated passed on the source-built 6.4.0 package at 0efc3a3d (the final reviewed head of merged #1694), using the standard CLI/MCP dispatcher and matching locked production dependencies. Both MCP processes exposed all 170 tools and completed real Ghidra / snapshot recovery workflows.

Observed unprofiled connection times were 28.64 s and 26.84 s. These are two local observations, not a paired startup benchmark or a new CPU profile, so they do not quantify the module-resolution improvement. The earlier CPU profile remains evidence for the pre-fix runtime.

@N0zoM1z0 commented on GitHub (Oct 11, 2026): Actual Windows acceptance with #1691 integrated passed on the source-built 6.4.0 package at `0efc3a3d` (the final reviewed head of merged #1694), using the standard CLI/MCP dispatcher and matching locked production dependencies. Both MCP processes exposed all 170 tools and completed real Ghidra / snapshot recovery workflows. Observed unprofiled connection times were 28.64 s and 26.84 s. These are two local observations, not a paired startup benchmark or a new CPU profile, so they do not quantify the module-resolution improvement. The earlier CPU profile remains evidence for the pre-fix runtime.

bsakaguchi commented

2026-10-15 18:26:15 +00:00

Author

Owner

@N0zoM1z0 commented on GitHub (Oct 11, 2026):

Reopening after a fresh real Windows installation on pinned main 81dc64e3cd13dc8bfcac8898386717ece9721da1, which includes #1691. The production dependency versions and all 1,119 shipped runtime files were checked against the source-built archive. The native helper came from CI with an identical owning native/build/verifier source tree; this was not a fresh Windows native compilation.

Windows Node 22.19.0, SDK 2.3.1, standard REA dispatcher, two CPUs / BelowNormal priority, 768 MiB Node heap:

Unprofiled default initialization failed with REQUEST_TIMEOUT: connect took 60,213.8 ms, with the SDK's unchanged 60,000 ms initialize deadline. No Java process, catalog response, or client output-validator compilation occurred. The sampled family peak was 128 MB; the guard did not stop the run, and observed owned processes were cleaned up.
In a separate diagnostic run with server CPU profiling and only the initialize deadline extended to 120 s, connect took 72,342.6 ms. The complete 170-tool catalog then took 2,794.7 ms and retained its 1,954,693-byte payload and SHA-256 badac148871025e4ac3f4b71c8914c25b4d32d973d07a28f60ed799764906f2b.
Flameox 0.2.9 analyzed the actual server profile cropped to the initialize phase: 22,834 samples, with 11,321 internalModuleStat self hits and 6,451 lstat self hits (77.8% combined). Derived input SHA-256: e881b65ab7cf403b0545214e6f05efb65856503d659115acef7495683add4ede; original whole-server profile: 0e9178690afa9b5ea500e9c0660f7d903bf6b22da86cc3595dfdaca3c24d1bce. The crop retains the observed sample order and ancestor frames; approximately the first 356 ms of client connect precedes the server profile. The ranked output remains partial after its provider row limit, including after following the returned continuation.

These samples identify a remaining module/filesystem loading hotspot. They are not syscall counts, CPU-utilization measurements, allocation evidence, or an antivirus attribution. This is not a paired regression benchmark against the earlier 26–29 s observations. #1691's import cleanup remains useful; this measurement supports continuing the remaining startup work, as invited above.

Client output-schema compilation and Ghidra startup were recorded as separate phases and are not included in these initialization counts.

@N0zoM1z0 commented on GitHub (Oct 11, 2026): Reopening after a fresh real Windows installation on pinned main `81dc64e3cd13dc8bfcac8898386717ece9721da1`, which includes #1691. The production dependency versions and all 1,119 shipped runtime files were checked against the source-built archive. The native helper came from CI with an identical owning native/build/verifier source tree; this was not a fresh Windows native compilation. Windows Node 22.19.0, SDK 2.3.1, standard REA dispatcher, two CPUs / BelowNormal priority, 768 MiB Node heap: - **Unprofiled default initialization failed** with `REQUEST_TIMEOUT`: connect took **60,213.8 ms**, with the SDK's unchanged 60,000 ms initialize deadline. No Java process, catalog response, or client output-validator compilation occurred. The sampled family peak was 128 MB; the guard did not stop the run, and observed owned processes were cleaned up. - In a separate diagnostic run with **server CPU profiling** and only the initialize deadline extended to 120 s, connect took **72,342.6 ms**. The complete 170-tool catalog then took 2,794.7 ms and retained its 1,954,693-byte payload and SHA-256 `badac148871025e4ac3f4b71c8914c25b4d32d973d07a28f60ed799764906f2b`. - Flameox 0.2.9 analyzed the actual server profile cropped to the initialize phase: **22,834 samples**, with **11,321 `internalModuleStat` self hits** and **6,451 `lstat` self hits** (77.8% combined). Derived input SHA-256: `e881b65ab7cf403b0545214e6f05efb65856503d659115acef7495683add4ede`; original whole-server profile: `0e9178690afa9b5ea500e9c0660f7d903bf6b22da86cc3595dfdaca3c24d1bce`. The crop retains the observed sample order and ancestor frames; approximately the first 356 ms of client connect precedes the server profile. The ranked output remains partial after its provider row limit, including after following the returned continuation. These samples identify a remaining module/filesystem loading hotspot. They are not syscall counts, CPU-utilization measurements, allocation evidence, or an antivirus attribution. This is not a paired regression benchmark against the earlier 26–29 s observations. #1691's import cleanup remains useful; this measurement supports continuing the remaining startup work, as invited above. Client output-schema compilation and Ghidra startup were recorded as separate phases and are not included in these initialization counts.

bsakaguchi commented

2026-10-15 18:26:15 +00:00

Author

Owner

@Rinkia commented on GitHub (Oct 12, 2026):

A measurement that I think explains why the numbers in this thread keep moving: on this host the same build connects in 20.6 s once and ~1.1 s every time after, so the hotspot behaves like a first-run cost rather than a steady-state one.

Environment

Source-built main at 5190843 (includes #1691), Windows 11 Pro 26100 x64, Node v24.16.0, 12 logical processors, default priority, no heap or CPU restriction, Defender real-time on, no third-party AV. Plain stdio MCP connect through the standard dispatcher (node scripts/rea.mjs mcp) with client SDK 2.3.1 — no profiler, no provider configured, no Ghidra.

Three consecutive runs, same process shape

run	`client.connect`	first complete `tools/list`	repeat `tools/list`	ping	tools
1 (first after build)	20,620.7 ms	795.4 ms	180.1 ms	3.0 ms	173
2	1,315.0 ms	350.3 ms	79.0 ms	8.9 ms	173
3	1,058.1 ms	308.9 ms	66.6 ms	2.5 ms	173

Single observations, not a paired benchmark — but the ~20× step between run 1 and runs 2–3, with nothing changed in between, is larger than any variance reported here.

Where the warm second is spent

phase	warm
bare `node -e ''` spawn	74.0 ms
`import()` of the bundled MCP entry (`dist/mcp/main.js`), no handshake	948.1 ms
remainder (initialize handshake)	~100 ms

So even warm, module loading is essentially all of startup, which agrees with the internalModuleStat / lstat dominance in the profiles above. What the cold/warm split adds is the magnitude: the same resolution work costs ~20 s against a cold cache and ~0.95 s once the files are resident.

What I read into it

The reported 45–72 s figures look like cold-path measurements. @N0zoM1z0's REQUEST_TIMEOUT run was on a fresh Windows installation, which is the coldest possible state, with two CPUs and BelowNormal priority; 20.6 s here on 12 CPUs at default priority scales into that range without needing another cause. That would also explain 26.84 s / 28.64 s versus 45 s / 53 s / 60 s / 72 s across hosts and runs.
The cost tracks the number of distinct files opened, not the number of modules resolved. dist ships 1,361 .js files, dist/mcp is 66 chunks totalling 5.3 MB, and scripts/bundle-runtime.mjs keeps dependencies external by design (278 top-level node_modules entries). First run pays per file; warm runs pay almost nothing per file. That is consistent with #1691's import cleanup helping real resolution counts while barely moving a warm wall clock, and it suggests chunk/file-count reduction for the MCP entry would target the cold case specifically.
A cold-vs-warm split would make the remaining work measurable. Right now a connect time in this thread is ambiguous: comparable only to runs in the same cache state. Reporting first-run and steady-state separately, on a stated cache state, would turn these into a paired benchmark.

Limits of this data

I cannot drop the Windows page cache on demand, so "cold" here means first run after the build wrote those files. The 20× gap is consistent with cold page cache plus a first antivirus scan, and I have not isolated which of the two dominates, nor attributed any of it to Defender. These are wall-clock observations, not syscall counts, and not an effect estimate. Happy to repeat with a Defender exclusion on the tree, or to count distinct files opened at initialize, if either would help.

🤖 Posted by Claude Code

@Rinkia commented on GitHub (Oct 12, 2026): A measurement that I think explains why the numbers in this thread keep moving: on this host the same build connects in **20.6 s once and ~1.1 s every time after**, so the hotspot behaves like a first-run cost rather than a steady-state one. ### Environment Source-built `main` at `5190843` (includes #1691), Windows 11 Pro 26100 x64, Node v24.16.0, 12 logical processors, default priority, no heap or CPU restriction, Defender real-time on, no third-party AV. Plain stdio MCP connect through the standard dispatcher (`node scripts/rea.mjs mcp`) with client SDK 2.3.1 — no profiler, no provider configured, no Ghidra. ### Three consecutive runs, same process shape | run | `client.connect` | first complete `tools/list` | repeat `tools/list` | ping | tools | |---|---:|---:|---:|---:|---:| | 1 (first after build) | **20,620.7 ms** | 795.4 ms | 180.1 ms | 3.0 ms | 173 | | 2 | **1,315.0 ms** | 350.3 ms | 79.0 ms | 8.9 ms | 173 | | 3 | **1,058.1 ms** | 308.9 ms | 66.6 ms | 2.5 ms | 173 | Single observations, not a paired benchmark — but the ~20× step between run 1 and runs 2–3, with nothing changed in between, is larger than any variance reported here. ### Where the warm second is spent | phase | warm | |---:|---| | bare `node -e ''` spawn | 74.0 ms | | `import()` of the bundled MCP entry (`dist/mcp/main.js`), no handshake | **948.1 ms** | | remainder (initialize handshake) | ~100 ms | So even warm, module loading is essentially all of startup, which agrees with the `internalModuleStat` / `lstat` dominance in the profiles above. What the cold/warm split adds is the *magnitude*: the same resolution work costs ~20 s against a cold cache and ~0.95 s once the files are resident. ### What I read into it - **The reported 45–72 s figures look like cold-path measurements.** @N0zoM1z0's `REQUEST_TIMEOUT` run was on a *fresh Windows installation*, which is the coldest possible state, with two CPUs and BelowNormal priority; 20.6 s here on 12 CPUs at default priority scales into that range without needing another cause. That would also explain 26.84 s / 28.64 s versus 45 s / 53 s / 60 s / 72 s across hosts and runs. - **The cost tracks the number of distinct files opened, not the number of modules resolved.** `dist` ships 1,361 `.js` files, `dist/mcp` is 66 chunks totalling 5.3 MB, and `scripts/bundle-runtime.mjs` keeps dependencies external by design (278 top-level `node_modules` entries). First run pays per file; warm runs pay almost nothing per file. That is consistent with #1691's import cleanup helping real resolution counts while barely moving a warm wall clock, and it suggests chunk/file-count reduction for the MCP entry would target the cold case specifically. - **A cold-vs-warm split would make the remaining work measurable.** Right now a connect time in this thread is ambiguous: comparable only to runs in the same cache state. Reporting first-run and steady-state separately, on a stated cache state, would turn these into a paired benchmark. ### Limits of this data I cannot drop the Windows page cache on demand, so "cold" here means first run after the build wrote those files. The 20× gap is consistent with cold page cache plus a first antivirus scan, and I have **not** isolated which of the two dominates, nor attributed any of it to Defender. These are wall-clock observations, not syscall counts, and not an effect estimate. Happy to repeat with a Defender exclusion on the tree, or to count distinct files opened at initialize, if either would help. _🤖 Posted by [Claude Code](https://claude.com/claude-code)_

bsakaguchi commented

2026-10-15 18:26:15 +00:00

Author

Owner

@morluto commented on GitHub (Oct 14, 2026):

Measured current qualified main fffb0741936067530d1ce9777461cd53e87398c2 on GitHub's Windows 11 x64 runner (Node 24.18.0) in run 38634150930.

Five fresh source-entrypoint processes and five fresh processes from an isolated install of the exact qualified package all completed initialize, two wire-level tools/list requests, and normal shutdown. Initialize took 1.450–1.550 seconds; first listing took 0.602–0.656 seconds; refreshed listing took 0.169–0.196 seconds. All returned 207 tools, with no stderr or shutdown errors. The package came from qualification run 38629313022, SHA-256 30996ad0b3e66c263ecd06712aa7a23a9fb02391856c01fe0f651d9f951b2061.

These are current hosted-runner measurements, without a historical or cold-OS-cache baseline. They do not reproduce or explain the reported 20–72 second starts on affected desktops, so this issue remains open. The diagnostic workflow exists only on its experimental branch and was not integrated into main. Raw JSON-RPC, stderr, timing and process metrics are attached to the run's experimental-windows-mcp-startup-38634150930 artifact.

@morluto commented on GitHub (Oct 14, 2026): Measured current qualified main `fffb0741936067530d1ce9777461cd53e87398c2` on GitHub's Windows 11 x64 runner (Node 24.18.0) in [run 38634150930](https://github.com/morluto/rea/actions/runs/38634150930). Five fresh source-entrypoint processes and five fresh processes from an isolated install of the exact qualified package all completed initialize, two wire-level `tools/list` requests, and normal shutdown. Initialize took 1.450–1.550 seconds; first listing took 0.602–0.656 seconds; refreshed listing took 0.169–0.196 seconds. All returned 207 tools, with no stderr or shutdown errors. The package came from qualification run `38629313022`, SHA-256 `30996ad0b3e66c263ecd06712aa7a23a9fb02391856c01fe0f651d9f951b2061`. These are current hosted-runner measurements, without a historical or cold-OS-cache baseline. They do not reproduce or explain the reported 20–72 second starts on affected desktops, so this issue remains open. The diagnostic workflow exists only on its experimental branch and was not integrated into main. Raw JSON-RPC, stderr, timing and process metrics are attached to the run's `experimental-windows-mcp-startup-38634150930` artifact.

No milestone

No project

No assignees

1 participant

Notifications

Due date

The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set.

Reference

morluto/rea#567

No description provided.

Rows
Columns