morluto/rea

Fork 0

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

[GH-ISSUE #3813] perf: CLI startup and doctor catalog digests make clientProfileLifecycle time out on CI #1475

New issue

Open

opened 2026-10-16 21:05:53 +00:00 by bsakaguchi · 4 comments

bsakaguchi commented

2026-10-16 21:05:53 +00:00

Owner

Originally created by @kaoru0822-kitauji on GitHub (Oct 15, 2026).
Original GitHub issue: https://github.com/morluto/rea/issues/3813

Summary: tests/boundary/cli/clientProfileLifecycle.test.ts > selected client profiles lifecycle follows the selected roots times out at 30,000 ms on CI. I've seen it in Test shard (3/5) / Portable tests on three unrelated PRs (#3788 run 38665633527, #3809 run 38671733565). It passes locally in about 7.8 s, so the cost is per-process CLI startup multiplied by sequential spawns.

What the test spawns: six clients, each with a setup --dry-run and a doctor --client … --skill run. On top of that come one extra doctor (grok_build), setup --yes, a repeated setup and uninstall, for about 16 sequential CLI processes.

Measured on macOS arm64, Node 26.5, built main:

command	wall time
`rea --version`	~325 ms
`rea setup --client codex --dry-run --json`	~435 ms
`rea doctor --client codex --skill --json`	~620 ms

6 × 0.435 + 7 × 0.62 + ~2 s ≈ 8.7 s locally. A shared CI runner 3–4× slower crosses 30 s.

CPU profile of doctor --client codex --skill --json (≈680–800 ms CPU):

~130–150 ms: catalog digests. catalogIdentity builds every tool's advertised JSON Schema (zod toJSONSchema, ~85 ms), then canonicalizes it (~55 ms) to compute CATALOG_IDENTITY.digests. That is a deterministic function of the build, recomputed in every doctor and MCP server process. createServerIdentity reports it and compares it with the registration's expected digest.
~90 ms: import-time zod schema construction, which every command pays (--version included).
~90 ms of ESM compile, ~80 ms of file reads, and a further ~21 ms of canonical JSON (emitCanonical).

Possible directions (not implemented):

Precompute the default (full output profile, no compact presentation) catalog digests at build time. Keep a test asserting the constant equals createCatalogDigests(), so a stale constant fails CI. This removes ~130–150 ms from every doctor and server start. It needs a decision on generated-file ownership.
Reduce the test's sequential spawns by using one multi-client setup --dry-run and one multi-client doctor, if per-client invocations aren't the property under test.
Lazily import command-specific schema modules so --version/help don't build every schema.

I haven't changed anything here, because options 1 and 3 touch build and generated-file ownership and option 2 changes what the test exercises.

Originally created by @kaoru0822-kitauji on GitHub (Oct 15, 2026). Original GitHub issue: https://github.com/morluto/rea/issues/3813 **Summary:** `tests/boundary/cli/clientProfileLifecycle.test.ts > selected client profiles lifecycle follows the selected roots` times out at 30,000 ms on CI. I've seen it in Test shard (3/5) / Portable tests on three unrelated PRs (#3788 run 38665633527, #3809 run 38671733565). It passes locally in about 7.8 s, so the cost is per-process CLI startup multiplied by sequential spawns. **What the test spawns:** six clients, each with a `setup --dry-run` and a `doctor --client … --skill` run. On top of that come one extra `doctor` (grok_build), `setup --yes`, a repeated `setup` and `uninstall`, for about 16 sequential CLI processes. **Measured on macOS arm64, Node 26.5, built `main`:** | command | wall time | |---|---:| | `rea --version` | ~325 ms | | `rea setup --client codex --dry-run --json` | ~435 ms | | `rea doctor --client codex --skill --json` | ~620 ms | 6 × 0.435 + 7 × 0.62 + ~2 s ≈ 8.7 s locally. A shared CI runner 3–4× slower crosses 30 s. **CPU profile of `doctor --client codex --skill --json`** (≈680–800 ms CPU): - **~130–150 ms: catalog digests.** `catalogIdentity` builds every tool's advertised JSON Schema (`zod` `toJSONSchema`, ~85 ms), then `canonicalize`s it (~55 ms) to compute `CATALOG_IDENTITY.digests`. That is a deterministic function of the build, recomputed in every `doctor` and MCP server process. `createServerIdentity` reports it and compares it with the registration's expected digest. - **~90 ms: import-time `zod` schema construction**, which every command pays (`--version` included). - ~90 ms of ESM compile, ~80 ms of file reads, and a further ~21 ms of canonical JSON (`emitCanonical`). **Possible directions (not implemented):** 1. Precompute the default (`full` output profile, no compact presentation) catalog digests at build time. Keep a test asserting the constant equals `createCatalogDigests()`, so a stale constant fails CI. This removes ~130–150 ms from every `doctor` and server start. It needs a decision on generated-file ownership. 2. Reduce the test's sequential spawns by using one multi-client `setup --dry-run` and one multi-client `doctor`, if per-client invocations aren't the property under test. 3. Lazily import command-specific schema modules so `--version`/`help` don't build every schema. I haven't changed anything here, because options 1 and 3 touch build and generated-file ownership and option 2 changes what the test exercises.

bsakaguchi commented

2026-10-16 21:05:54 +00:00

Author

Owner

@Hahaa909 commented on GitHub (Oct 15, 2026):

I reviewed the reproduction and the three possible directions. The repeated catalog digest work looks like the narrowest first target: the default full-profile/no-compact digest is deterministic, and a build-time generated value plus a test comparing it with createCatalogDigests() could remove the ~130–150 ms digest cost per doctor/MCP startup while failing closed if the generated value becomes stale.

Before preparing a PR, could a maintainer confirm the preferred direction?

Precompute the default digest: focused change, but needs guidance on generated-file ownership and the build/check hook.
Batch the lifecycle test spawns: smaller test runtime change, but may weaken the per-client lifecycle coverage.
Lazy-load schema modules: broader startup improvement, but larger module-boundary and regression surface.

I would start with the precomputed default digest if that matches the repository's generated-artifact conventions. I have not changed the test semantics or build outputs without that direction.

@Hahaa909 commented on GitHub (Oct 15, 2026): I reviewed the reproduction and the three possible directions. The repeated catalog digest work looks like the narrowest first target: the default full-profile/no-compact digest is deterministic, and a build-time generated value plus a test comparing it with `createCatalogDigests()` could remove the ~130–150 ms digest cost per `doctor`/MCP startup while failing closed if the generated value becomes stale. Before preparing a PR, could a maintainer confirm the preferred direction? - **Precompute the default digest**: focused change, but needs guidance on generated-file ownership and the build/check hook. - **Batch the lifecycle test spawns**: smaller test runtime change, but may weaken the per-client lifecycle coverage. - **Lazy-load schema modules**: broader startup improvement, but larger module-boundary and regression surface. I would start with the precomputed default digest if that matches the repository's generated-artifact conventions. I have not changed the test semantics or build outputs without that direction.

bsakaguchi commented

2026-10-16 21:05:54 +00:00

Author

Owner

@XinwangTao commented on GitHub (Oct 15, 2026):

Nice breakdown — recomputing deterministic catalog digests on every doctor/MCP server start is clearly wasted work, and the numbers (~150 ms per process, ~16 processes) explain the CI flake well. Option 1 (precomputed constant + a guard test that recomputes and compares) is the most robust and removes the cost everywhere, not just in this test. I would pair it with option 3 for --version/help paths: even if digests are precomputed, the ~90 ms of import-time zod schema construction still penalises every command. Option 2 can then be judged separately if the test remains flaky.

@XinwangTao commented on GitHub (Oct 15, 2026): Nice breakdown — recomputing deterministic catalog digests on every doctor/MCP server start is clearly wasted work, and the numbers (~150 ms per process, ~16 processes) explain the CI flake well. Option 1 (precomputed constant + a guard test that recomputes and compares) is the most robust and removes the cost everywhere, not just in this test. I would pair it with option 3 for --version/help paths: even if digests are precomputed, the ~90 ms of import-time zod schema construction still penalises every command. Option 2 can then be judged separately if the test remains flaky.

bsakaguchi referenced this issue

2026-10-17 21:11:45 +00:00

[PR #1475] [MERGED] feat(website): add a Blog and Touhou reconstruction essay #2912

bsakaguchi commented

2026-11-04 00:49:08 +00:00

Author

Owner

@CassieFox23 commented on GitHub (Nov 3, 2026):

TL;DR: On main c3647ade1 (#8824), the slow test passed all 3 times in my VM, in about 20 s against its 30 s limit. Direction 1 (digests recorded at build) landed in c61c108b5 (#4041). Direction 2 (fewer spawns) landed in part in 85788452d, and direction 3 (lazy imports) is not in main, where PR #4083 is open.

What is settled

Direction 1. compile runs scripts/record-catalog-digests.mjs (package.json:327). It writes dist/recordedCatalogDigests.js from the compiled contracts. src/catalogIdentity.ts:219 reads those digests for the default catalogs. src/recordedCatalogDigests.ts:8-10 stays undefined, so source runs still compute on first use. Later commits widened it, from c23e161629 (#5415) on. Main now records six profiles. After npm run build:cached in my VM, dist/recordedCatalogDigests.js holds six digest entries, and so does the bundled dist/cli-runtime/catalogIdentity-DAa0_Lm0.js.
Stale guard. No committed constant can go stale, so the issue's guard test took another shape. tests/boundary/mcp/mcpDoctor.test.ts:259-300 starts the production server from dist. It compares the reported digest with one computed from src. I read that test; I did not run it.
Direction 2. The commit 85788452d has no PR. It turned the per-client setup --dry-run loop into one run (test lines 357-377). The per-client doctor loop stayed (lines 396-433), plus one extra doctor for grok_build (line 428). The test now covers 7 clients, so it spawns 12 CLI processes: 1 dry run, 1 setup --yes, 7 doctor, 1 more doctor, 1 repeat setup, 1 uninstall. The issue counted about 16 for six clients. Each spawn has a 20,000 ms limit (line 355), and vitest allows 30,000 ms per test (60,000 ms with coverage), at vitest.config.ts:148.

What is left

Direction 2. The doctor calls are still one process per client. I did not try a multi-client doctor.
Direction 3. On main, a formatted --version returns before the command runtime loads (scripts/rea.mjs:149-150, src/cliOutput.ts:388-396). Plain --version falls through to the full CLI import (scripts/rea.mjs:152). tests/boundary/cli/cliStartupImports.test.ts:220-227 shows heavy command packages already load lazily for --help. I found nothing on main that makes plain --version skip the command schemas, and I did not trace what that import builds. PR #4083, "perf(cli): skip command schemas for standalone version queries" by Hahaa909, is open. I did not build or review it.
Direction 1. Nothing left that I found.

Timings

Five runs each, one at a time, empty HOME and XDG_CONFIG_HOME, and I set no compile-cache variable. One setup --client codex --yes ran between the dry runs and the doctor runs, so doctor sees a registration. All exit codes were 0.

command	my VM: median (min to max)	issue: macOS arm64, Node 26.5 (secondhand)
`rea --version`	1,495 ms (1,395 to 1,510)	~325 ms
`rea setup --client codex --dry-run --json`	1,913 ms (1,788 to 2,068)	~435 ms
`rea doctor --client codex --skill --json`	1,829 ms (1,787 to 1,915)	~620 ms

`test:focused` run	selected client profiles test (limit 30,000 ms)	whole file, 7 tests
1: 7 passed	19,976 ms	45,548 ms
2: 7 passed	19,483 ms	46,780 ms
3: 7 passed	19,666 ms	46,975 ms

The issue's 7.8 s is secondhand and from other hardware. The 30,000 ms limit is per test, so the whole-file time is not compared with it. My VM has 4 vCPUs and 8 GB and is not CI. I did not measure doctor with the recorded digests removed, so I cannot say how much of any gap is digests. My direct runs set no compile cache, but the test's spawns do (tests/support/cli/cliFixture.ts:251-254), so the two tables are not the same kind of number.

CI sample (secondhand, and only a sample)

The 20 newest runs of all workflows on main were all from 2026-11-03, 22:06Z to 23:34Z, and none had failed. So I listed the CI workflow instead: 20 runs on main, 2026-11-03 10:27Z to 23:27Z, 11 success, 8 failure, 1 cancelled. I opened the failed-job logs of the 5 newest failures (2026-11-03 15:25Z, 15:27Z, 15:48Z, 16:27Z, 18:27Z). The test file name is absent from three of them. In run 41664168009 and run 41674389884 it appears only as a pass line: 7 tests, 41,941 ms and 40,170 ms for the whole file. No timeout of this test turned up. I did not look into why those five runs failed. Pull request runs are not in the sample.

Not run

The revert check (recorded digests made undefined in a scratch dist, then doctor timed): out of time. The bundled catalogIdentity-DAa0_Lm0.js carries its own copy of the digests, so the edit would need to reach that file too.
mcpDoctor.test.ts and the rest of the suite.
A run on real CI, with coverage (60,000 ms limit), on macOS or Windows, or on Node 22 or 26.
A multi-client doctor, and PR #4083.

Test setup

Box: Fedora 44 VM (4 vCPUs, 8 GB) on my Nobara 44 machine, guest kernel 7.2.11-200.fc44.x86_64
Node: 24.22.1
Head: c3647ade1 (#8824)
Other: vitest 5.0.3, turbo 2.11.7; npm ci --offline added 739 packages; tree built with npm run test:prepare (23 s) then npm run build:cached

Commands

npm --prefix ~/i3813-main/src ci --offline                          # exit 0
npm --prefix ~/i3813-main/src run test:prepare                      # exit 0
npm --prefix ~/i3813-main/src run build:cached                      # exit 0
# each direct run: env HOME=~/i3813-home/home XDG_CONFIG_HOME=~/i3813-home/xdg node ~/i3813-main/src/scripts/rea.mjs <args>
--version                                  # x5, exit 0
setup --client codex --dry-run --json      # x5, exit 0
setup --client codex --yes --json          # x1, exit 0
doctor --client codex --skill --json       # x5, exit 0
npm --prefix ~/i3813-main/src run test:focused -- tests/boundary/cli/clientProfileLifecycle.test.ts   # x3, exit 0 each

🤖 Written and tested with Claude Code (Sonnet 5.5, verified by Opus 5.5), posted with my OK 🦊

@CassieFox23 commented on GitHub (Nov 3, 2026): **TL;DR:** On main c3647ade1 (#8824), the slow test passed all 3 times in my VM, in about 20 s against its 30 s limit. Direction 1 (digests recorded at build) landed in c61c108b5 (#4041). Direction 2 (fewer spawns) landed in part in 85788452d, and direction 3 (lazy imports) is not in main, where PR #4083 is open. ### What is settled - **Direction 1.** `compile` runs `scripts/record-catalog-digests.mjs` (package.json:327). It writes `dist/recordedCatalogDigests.js` from the compiled contracts. `src/catalogIdentity.ts:219` reads those digests for the default catalogs. `src/recordedCatalogDigests.ts:8-10` stays `undefined`, so source runs still compute on first use. Later commits widened it, from c23e161629 (#5415) on. Main now records six profiles. After `npm run build:cached` in my VM, `dist/recordedCatalogDigests.js` holds six digest entries, and so does the bundled `dist/cli-runtime/catalogIdentity-DAa0_Lm0.js`. - **Stale guard.** No committed constant can go stale, so the issue's guard test took another shape. `tests/boundary/mcp/mcpDoctor.test.ts:259-300` starts the production server from `dist`. It compares the reported digest with one computed from `src`. I read that test; I did not run it. - **Direction 2.** The commit 85788452d has no PR. It turned the per-client `setup --dry-run` loop into one run (test lines 357-377). The per-client `doctor` loop stayed (lines 396-433), plus one extra `doctor` for grok_build (line 428). The test now covers 7 clients, so it spawns 12 CLI processes: 1 dry run, 1 `setup --yes`, 7 `doctor`, 1 more `doctor`, 1 repeat `setup`, 1 `uninstall`. The issue counted about 16 for six clients. Each spawn has a 20,000 ms limit (line 355), and vitest allows 30,000 ms per test (60,000 ms with coverage), at `vitest.config.ts:148`. ### What is left - **Direction 2.** The `doctor` calls are still one process per client. I did not try a multi-client `doctor`. - **Direction 3.** On main, a formatted `--version` returns before the command runtime loads (`scripts/rea.mjs:149-150`, `src/cliOutput.ts:388-396`). Plain `--version` falls through to the full CLI import (`scripts/rea.mjs:152`). `tests/boundary/cli/cliStartupImports.test.ts:220-227` shows heavy command packages already load lazily for `--help`. I found nothing on main that makes plain `--version` skip the command schemas, and I did not trace what that import builds. PR #4083, "perf(cli): skip command schemas for standalone version queries" by Hahaa909, is open. I did not build or review it. - **Direction 1.** Nothing left that I found. ### Timings Five runs each, one at a time, empty `HOME` and `XDG_CONFIG_HOME`, and I set no compile-cache variable. One `setup --client codex --yes` ran between the dry runs and the `doctor` runs, so `doctor` sees a registration. All exit codes were 0. | command | my VM: median (min to max) | issue: macOS arm64, Node 26.5 (secondhand) | |---|---:|---:| | `rea --version` | 1,495 ms (1,395 to 1,510) | ~325 ms | | `rea setup --client codex --dry-run --json` | 1,913 ms (1,788 to 2,068) | ~435 ms | | `rea doctor --client codex --skill --json` | 1,829 ms (1,787 to 1,915) | ~620 ms | | `test:focused` run | selected client profiles test (limit 30,000 ms) | whole file, 7 tests | |---|---:|---:| | 1: 7 passed | 19,976 ms | 45,548 ms | | 2: 7 passed | 19,483 ms | 46,780 ms | | 3: 7 passed | 19,666 ms | 46,975 ms | The issue's 7.8 s is secondhand and from other hardware. The 30,000 ms limit is per test, so the whole-file time is not compared with it. My VM has 4 vCPUs and 8 GB and is not CI. I did not measure `doctor` with the recorded digests removed, so I cannot say how much of any gap is digests. My direct runs set no compile cache, but the test's spawns do (`tests/support/cli/cliFixture.ts:251-254`), so the two tables are not the same kind of number. ### CI sample (secondhand, and only a sample) The 20 newest runs of all workflows on main were all from 2026-11-03, 22:06Z to 23:34Z, and none had failed. So I listed the `CI` workflow instead: 20 runs on main, 2026-11-03 10:27Z to 23:27Z, 11 success, 8 failure, 1 cancelled. I opened the failed-job logs of the 5 newest failures (2026-11-03 15:25Z, 15:27Z, 15:48Z, 16:27Z, 18:27Z). The test file name is absent from three of them. In [run 41664168009](https://github.com/morluto/rea/actions/runs/41664168009) and [run 41674389884](https://github.com/morluto/rea/actions/runs/41674389884) it appears only as a pass line: 7 tests, 41,941 ms and 40,170 ms for the whole file. No timeout of this test turned up. I did not look into why those five runs failed. Pull request runs are not in the sample. ### Not run - The revert check (recorded digests made undefined in a scratch `dist`, then `doctor` timed): out of time. The bundled `catalogIdentity-DAa0_Lm0.js` carries its own copy of the digests, so the edit would need to reach that file too. - `mcpDoctor.test.ts` and the rest of the suite. - A run on real CI, with coverage (60,000 ms limit), on macOS or Windows, or on Node 22 or 26. - A multi-client `doctor`, and PR #4083. <details> <summary>Test setup</summary> - Box: Fedora 44 VM (4 vCPUs, 8 GB) on my Nobara 44 machine, guest kernel 7.2.11-200.fc44.x86_64 - Node: 24.22.1 - Head: c3647ade1 (#8824) - Other: vitest 5.0.3, turbo 2.11.7; `npm ci --offline` added 739 packages; tree built with `npm run test:prepare` (23 s) then `npm run build:cached` </details> <details> <summary>Commands</summary> ``` npm --prefix ~/i3813-main/src ci --offline # exit 0 npm --prefix ~/i3813-main/src run test:prepare # exit 0 npm --prefix ~/i3813-main/src run build:cached # exit 0 # each direct run: env HOME=~/i3813-home/home XDG_CONFIG_HOME=~/i3813-home/xdg node ~/i3813-main/src/scripts/rea.mjs <args> --version # x5, exit 0 setup --client codex --dry-run --json # x5, exit 0 setup --client codex --yes --json # x1, exit 0 doctor --client codex --skill --json # x5, exit 0 npm --prefix ~/i3813-main/src run test:focused -- tests/boundary/cli/clientProfileLifecycle.test.ts # x3, exit 0 each ``` </details> 🤖 Written and tested with Claude Code (Sonnet 5.5, verified by Opus 5.5), posted with my OK 🦊

bsakaguchi commented

2026-11-04 04:56:15 +00:00

Author

Owner

@XinwangTao commented on GitHub (Nov 4, 2026):

Thanks for the careful verification — 3/3 passes at ~20 s against the 30 s limit is solid evidence that the build-time digests closed most of the gap. Since direction 1 and the dry-run batching are now in main, I'd treat #4083 (skip command schemas for standalone version queries) as the next high-value item: it removes the ~90 ms import-time schema cost from every plain --version/help call without changing test semantics. Happy to review it once it's ready.

@XinwangTao commented on GitHub (Nov 4, 2026): Thanks for the careful verification — 3/3 passes at ~20 s against the 30 s limit is solid evidence that the build-time digests closed most of the gap. Since direction 1 and the dry-run batching are now in main, I'd treat #4083 (skip command schemas for standalone version queries) as the next high-value item: it removes the ~90 ms import-time schema cost from every plain --version/help call without changing test semantics. Happy to review it once it's ready.

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#1475

No description provided.

Rows
Columns