[GH-ISSUE #2453] test: full inventory check times out after unrelated SDK schema compilation #817

New issue

Closed

opened 2026-10-15 18:28:44 +00:00 by bsakaguchi · 0 comments

bsakaguchi commented

2026-10-15 18:28:44 +00:00

Owner

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

Originally assigned to: @N0zoM1z0 on GitHub.

The session inventory correctness case in tests/boundary/mcp/serverWorkflowMcp.test.ts has a historical 10_000 ms override. It bypasses the repository's existing bounded test budget: 30 seconds normally and 60 seconds with coverage. Two complete local coverage runs have now failed on this exact timeout, while the latest hosted six-shard CI and isolated covered runs pass the unchanged functional assertions.

Confirmed reproduction

Latest-main audit baseline: 4773c152bc5f299fa682575bb8d1efea7587c7bc (updated main at start; source frozen throughout the run).
Linux, pinned Node 24.18.0 / npm 11.16.0, fresh dependencies, configured two workers, retries disabled, existing preparation artifacts reused. MCP SDK 2.3.1.
Full command: npm run test:coverage -- --coverage.reportOnFailure --coverage.reporter=json-summary --coverage.reporter=text-summary --coverage.reportsDirectory=/tmp/rea-ci-tests-review2-local-coverage --reporter=default --reporter=json --outputFile.json=/tmp/rea-ci-tests-review2-local-results.json.
Complete result: 1,004 files; 10,223 passed, 95 skipped, one failed out of 10,319 cases. The sole failure is advertises the complete currently available inventory with a session: Error: Test timed out in 10000ms, reported case duration 14,954.839 ms.
A previous complete local coverage run also failed this same case at the same explicit deadline. Its separate cleanup-injection failure was corrected in #2430; the five cleanup cases pass in this current full run.
Latest hosted CI on ca2d15b3 passes this inventory case in 3,753.794 ms: https://github.com/morluto/rea/actions/runs/38333585208 . Full hosted result: 10,227 passed, 92 skipped, no failures. The three additional local skips are the real-Chrome SVG/XHTML cases, not this inventory case.
The override originated in 513d9b1555 (test: overhaul deterministic suite architecture, July 29). No separate 10-second inventory performance SLO was found; the case asserts catalog completeness, metadata/schema availability and unavailable-tool remediation.

Impact and limits of the finding

A late failure wastes a completed full validation cycle and encourages reruns: this run consumed 2,181.370 monotonic seconds (~36m21s), with 4,546.395 user + 1,039.005 system CPU seconds in the waited process family. Sampled combined RSS/PSS peaked at 4,181,204 / 3,962,504 KiB. No sampled surviving descendant generation remained at completion. Three-second sampling can miss processes/peaks; RSS includes shared pages; CPU accounting is limited to waited descendants; host load is uncontrolled. These are resource observations, not comparative speed claims.

The run failed despite reaching all configured coverage thresholds (lines 89.59%, statements 88.01%, functions 91.31%, branches 79.91%). A green isolated rerun does not make this original full run green. The earlier Windows web-module subprocess timeout is a different case and is not attributed to this finding.

Measured cause and bounded correction

The dominant isolated covered phase is binary_session, not listing: listTools() takes about 0.55 s; the first call takes about 7.37 s. A temporary delegate around the unchanged default SDK validator observes 187 getValidator calls totaling 6.77 s (including cheap cache hits). The SDK's ClientResponseCache.outputValidator() derives the entire name-to-validator index on the first cached call: it loops over the listed tools. A per-tool compile failure is stored and thrown only if that tool is called; compiling unrelated schemas does not itself assert catalog validity.

The installed SDK also supports callTool(params, {toolDefinition}). The candidate passes the exact current binary_session definition returned by the same listTools() call. This preserves real SDK validation of the requested reply while avoiding unrelated output-validator initialization. Every existing inventory, availability, remediation, metadata and schema-presence assertion remains; afterEach cleanup, the original 10-second deadline, worker limits, retries and coverage thresholds remain. Production code and SDK dependencies are unchanged. The candidate adds an explicit missing-definition failure.

This supersedes the initially considered timeout-budget adjustment: the final candidate does not change the deadline.

Reproduction and performance counterchecks

All six fresh-runner covered samples complete the same two cases and every assertion, in original/selected/selected/original/original/selected order on frozen f254f5ac2. Prepared artifacts and OS/file caches are warm; SDK/client objects are fresh. Both temporary benchmark variants use the same 60-second cap to prevent deadline censoring; the final candidate retains 10 seconds. Focused coverage commands still exit nonzero for the unchanged full-repository thresholds, so these are diagnostic measurements, not a complete green gate.

Measure	Original path (3 samples)	Reuse current definition (3 samples)
Inventory case	8.058–9.347 s	1.303–1.385 s
Entire focused covered runner	21.02–22.82 s	13.45–14.40 s
Waited process-family CPU	28.35–30.44 s	19.61–20.81 s
Sampled combined RSS peak	1,089–1,133 MiB	926–947 MiB
Sampled combined PSS peak	1,082–1,134 MiB	887–897 MiB

One-second sampling can miss peaks/short-lived descendants; RSS/PSS are collected at slightly different instants and shared pages differ. CPU is limited to waited descendants and shared host load is uncontrolled. No surviving observed process generation remains in any sample. No model-token measure applies to these offline SDK checks. This establishes a local case/file benefit, not a large whole-CI improvement.

Three temporary drift/fault mutants are rejected under the candidate's original 10-second cap, on genuine assertions/SDK errors:

Remove an unrelated advertised tool: the complete catalog Set equality fails.
Change the advertised binary_session title: exact metadata equality fails.
Supply an incompatible advertised output schema requiring an absent property: the real SDK rejects the actual structured reply with ProtocolError.

All temporary timing, validator delegates and fault code have been removed. Final complete latest-main coverage, static checks and remote PR CI remain required before merge. The source/benchmark/negative-check evidence is recorded in /tmp/rea-ci-tests-review2-20261013.md and task-owned JSON/log artifacts.

Follow-up ownership

Assigned to N0zoM1z0. Review and verification notes: /tmp/rea-ci-tests-review2-20261013.md; raw local results, coverage and process-family costs remain in task-owned temporary artifacts. Latest main subsequently advanced to f254f5ac2; its Android package summary changes and new Python resource-receipt tests will be included in final verification. No runtime optimization is proposed here.

Completed local verification and ready PR

PR #2469 is ready for review: https://github.com/morluto/rea/pull/2469 . Full local coverage at f254f5ac2 + 2db5ee5d6 completed successfully: 1,005 files, 10,230 passed / 92 skipped / zero failures; all thresholds passed. Inventory completed in 1,315.830 ms with the original 10-second cap. No observed surviving process generation remained. Full elapsed remains approximately 36 minutes, so no whole-suite acceleration is claimed.

Main then advanced to bb154d1067; it was merged without conflicts into the final PR head 41139ddc9382d7d0e60ade1dffd4990e8ab1b9f0. The PR diff is still only the inventory test. Latest combined-source static/type/architecture, website and docs checks pass; discovery verifies 1,010 files. All 16 changed/related capture/view/schema/inventory files pass (210 cases and two expected capability skips), including inventory in approximately 1.04 seconds. Complete combined-source coverage is pending PR CI 38342163586 and is required before merge.

Final result

PR #2469 merged as a6efa4fcefeffcf5ff5310b8154988b4be30c349 after full CI on final latest-main combination fd54f00395315a05cdeaa0e01365c7018aabd610: https://github.com/morluto/rea/actions/runs/38343539084 . All 16 selected jobs pass; 18 lanes are intentionally skipped by unchanged selection. Full report: 1,013 files, 10,291 passed / 94 skipped / zero failures; all coverage thresholds pass. Inventory completes in 1,042.557 ms with its original 10-second cap. Latest parent main CI also passes Windows/native Apple/macOS lanes. Merged main tree was checked equal to the tested PR tree. The issue is closed completed. No larger whole-suite speedup is claimed.

Originally created by @N0zoM1z0 on GitHub (Oct 13, 2026). Original GitHub issue: https://github.com/morluto/rea/issues/2453 Originally assigned to: @N0zoM1z0 on GitHub. The session inventory correctness case in `tests/boundary/mcp/serverWorkflowMcp.test.ts` has a historical `10_000` ms override. It bypasses the repository's existing bounded test budget: 30 seconds normally and 60 seconds with coverage. Two complete local coverage runs have now failed on this exact timeout, while the latest hosted six-shard CI and isolated covered runs pass the unchanged functional assertions. ## Confirmed reproduction - Latest-main audit baseline: `4773c152bc5f299fa682575bb8d1efea7587c7bc` (updated main at start; source frozen throughout the run). - Linux, pinned Node 24.18.0 / npm 11.16.0, fresh dependencies, configured two workers, retries disabled, existing preparation artifacts reused. MCP SDK 2.3.1. - Full command: `npm run test:coverage -- --coverage.reportOnFailure --coverage.reporter=json-summary --coverage.reporter=text-summary --coverage.reportsDirectory=/tmp/rea-ci-tests-review2-local-coverage --reporter=default --reporter=json --outputFile.json=/tmp/rea-ci-tests-review2-local-results.json`. - Complete result: 1,004 files; 10,223 passed, 95 skipped, one failed out of 10,319 cases. The sole failure is `advertises the complete currently available inventory with a session`: `Error: Test timed out in 10000ms`, reported case duration 14,954.839 ms. - A previous complete local coverage run also failed this same case at the same explicit deadline. Its separate cleanup-injection failure was corrected in #2430; the five cleanup cases pass in this current full run. - Latest hosted CI on `ca2d15b3` passes this inventory case in 3,753.794 ms: https://github.com/morluto/rea/actions/runs/38333585208 . Full hosted result: 10,227 passed, 92 skipped, no failures. The three additional local skips are the real-Chrome SVG/XHTML cases, not this inventory case. - The override originated in `513d9b1555` (`test: overhaul deterministic suite architecture`, July 29). No separate 10-second inventory performance SLO was found; the case asserts catalog completeness, metadata/schema availability and unavailable-tool remediation. ## Impact and limits of the finding A late failure wastes a completed full validation cycle and encourages reruns: this run consumed 2,181.370 monotonic seconds (~36m21s), with 4,546.395 user + 1,039.005 system CPU seconds in the waited process family. Sampled combined RSS/PSS peaked at 4,181,204 / 3,962,504 KiB. No sampled surviving descendant generation remained at completion. Three-second sampling can miss processes/peaks; RSS includes shared pages; CPU accounting is limited to waited descendants; host load is uncontrolled. These are resource observations, not comparative speed claims. The run failed despite reaching all configured coverage thresholds (lines 89.59%, statements 88.01%, functions 91.31%, branches 79.91%). A green isolated rerun does not make this original full run green. The earlier Windows web-module subprocess timeout is a different case and is not attributed to this finding. ## Measured cause and bounded correction The dominant isolated covered phase is `binary_session`, not listing: `listTools()` takes about 0.55 s; the first call takes about 7.37 s. A temporary delegate around the **unchanged default** SDK validator observes 187 `getValidator` calls totaling 6.77 s (including cheap cache hits). The SDK's `ClientResponseCache.outputValidator()` derives the entire name-to-validator index on the first cached call: it loops over the listed tools. A per-tool compile failure is stored and thrown only if that tool is called; compiling unrelated schemas does not itself assert catalog validity. The installed SDK also supports `callTool(params, {toolDefinition})`. The candidate passes the exact current `binary_session` definition returned by the same `listTools()` call. This preserves real SDK validation of the requested reply while avoiding unrelated output-validator initialization. Every existing inventory, availability, remediation, metadata and schema-presence assertion remains; afterEach cleanup, the **original 10-second deadline**, worker limits, retries and coverage thresholds remain. Production code and SDK dependencies are unchanged. The candidate adds an explicit missing-definition failure. This supersedes the initially considered timeout-budget adjustment: the final candidate does not change the deadline. ## Reproduction and performance counterchecks All six fresh-runner covered samples complete the same two cases and every assertion, in original/selected/selected/original/original/selected order on frozen `f254f5ac2`. Prepared artifacts and OS/file caches are warm; SDK/client objects are fresh. Both temporary benchmark variants use the same 60-second cap to prevent deadline censoring; the final candidate retains 10 seconds. Focused coverage commands still exit nonzero for the unchanged full-repository thresholds, so these are diagnostic measurements, not a complete green gate. | Measure | Original path (3 samples) | Reuse current definition (3 samples) | | --- | --- | --- | | Inventory case | 8.058–9.347 s | 1.303–1.385 s | | Entire focused covered runner | 21.02–22.82 s | 13.45–14.40 s | | Waited process-family CPU | 28.35–30.44 s | 19.61–20.81 s | | Sampled combined RSS peak | 1,089–1,133 MiB | 926–947 MiB | | Sampled combined PSS peak | 1,082–1,134 MiB | 887–897 MiB | One-second sampling can miss peaks/short-lived descendants; RSS/PSS are collected at slightly different instants and shared pages differ. CPU is limited to waited descendants and shared host load is uncontrolled. No surviving observed process generation remains in any sample. No model-token measure applies to these offline SDK checks. This establishes a local case/file benefit, not a large whole-CI improvement. Three temporary drift/fault mutants are rejected under the candidate's original 10-second cap, on genuine assertions/SDK errors: 1. Remove an unrelated advertised tool: the complete catalog Set equality fails. 2. Change the advertised `binary_session` title: exact metadata equality fails. 3. Supply an incompatible advertised output schema requiring an absent property: the real SDK rejects the actual structured reply with `ProtocolError`. All temporary timing, validator delegates and fault code have been removed. Final complete latest-main coverage, static checks and remote PR CI remain required before merge. The source/benchmark/negative-check evidence is recorded in `/tmp/rea-ci-tests-review2-20261013.md` and task-owned JSON/log artifacts. ## Follow-up ownership Assigned to N0zoM1z0. Review and verification notes: `/tmp/rea-ci-tests-review2-20261013.md`; raw local results, coverage and process-family costs remain in task-owned temporary artifacts. Latest main subsequently advanced to `f254f5ac2`; its Android package summary changes and new Python resource-receipt tests will be included in final verification. No runtime optimization is proposed here. ## Completed local verification and ready PR PR #2469 is ready for review: https://github.com/morluto/rea/pull/2469 . Full local coverage at `f254f5ac2 + 2db5ee5d6` completed successfully: 1,005 files, 10,230 passed / 92 skipped / zero failures; all thresholds passed. Inventory completed in 1,315.830 ms with the original 10-second cap. No observed surviving process generation remained. Full elapsed remains approximately 36 minutes, so no whole-suite acceleration is claimed. Main then advanced to `bb154d1067`; it was merged without conflicts into the final PR head `41139ddc9382d7d0e60ade1dffd4990e8ab1b9f0`. The PR diff is still only the inventory test. Latest combined-source static/type/architecture, website and docs checks pass; discovery verifies 1,010 files. All 16 changed/related capture/view/schema/inventory files pass (210 cases and two expected capability skips), including inventory in approximately 1.04 seconds. Complete combined-source coverage is pending PR CI 38342163586 and is required before merge. ## Final result PR #2469 merged as `a6efa4fcefeffcf5ff5310b8154988b4be30c349` after full CI on final latest-main combination `fd54f00395315a05cdeaa0e01365c7018aabd610`: https://github.com/morluto/rea/actions/runs/38343539084 . All 16 selected jobs pass; 18 lanes are intentionally skipped by unchanged selection. Full report: 1,013 files, 10,291 passed / 94 skipped / zero failures; all coverage thresholds pass. Inventory completes in 1,042.557 ms with its original 10-second cap. Latest parent main CI also passes Windows/native Apple/macOS lanes. Merged main tree was checked equal to the tested PR tree. The issue is closed completed. No larger whole-suite speedup is claimed.

bsakaguchi

2026-10-15 18:28:44 +00:00