Orchestrata Ultimate › Plans › suite-runtime-research-2026-08-12

Suite runtime research — full record (2026-08-12)

Source: plans/suite-runtime-research-2026-08-12.md at 8a2cb42ad · last changed 2026-08-12 · first committed 2026-08-12 · 211 lines.

Prose pending.

Plan text

Suite runtime research — full record (2026-08-12)

Companion to plans/suite-runtime-and-graph-defects-plan.md (the plan). This file is the complete research record behind it: method, measurements, censuses, dead ends, and the adversarial-review corrections. Every number here was produced by a named artifact or a runnable command; claims the adversarial review marked WEAK are marked WEAK here too.

1. Method

Trigger: full-suite wall time 445.7s and a user goal of halving it. Process: the measure-first checklist (hook-enforced since 2026-08-12, .kimi/measure-first.json): baseline → decompose → hypothesis(+ceiling) → falsify → adversarial → signoff → implement → verify. All analysis was read-only or /tmp scratch; the only repo writes are this file and the plan.

Data sources used:

Analysis scripts (all in /tmp, rerunnable): decompose_446.py, lever3_research.py, ast_slow_review2.py, loop_census.py; findings dump /tmp/slow_review_findings.json.

2. Baseline and decomposition

Baseline: cf59d5c8, scope=full — 445.7s batch-phase wall, 32,490/0/0/0, 1,611 modules. The 445.7s is the executor phase only (gates/infra excluded).

Decomposition (decompose_446.py): the baseline window in test-durations.ndjson was identified among ~70 full-size segments by span≈446s (start 08-11 21:52, 32,238 records = 99.2% of the suite's 32,490 tests, span 442s). Per-test durations were spread over [ts−duration, ts] in 30s buckets for a true occupancy curve (a single 120s test cannot inflate one bucket beyond one lane).

• Test-call CPU 2,312s (65% of 3,566 lane-s) → floor 289s at 8 lanes (SUPPORTED)
• Fixture/teardown bucket ~793s — WEAK: junit-cache total (3,105s) − call CPU; conflates fixtures with collection/imports/teardown and absorbs the 252 missing tests' CPU (~18s at mean). The cache was refreshed by the baseline run itself, so staleness is ~4 of 1,615 entries — the boundary error, not staleness, is the issue.
• Session overhead+idle ~397s — WEAK: pure residual of the two soft numbers.
• Spawn tax: packing replayed via _prepare_batches on the real cache → 51 batches (not the ~180 assumed pre-research); ×1.26s measured empty-collect spawn = ~66s CPU (~8s wall). The "~180 spawns / 100-140s saving" premise behind the resident-worker project was wrong at the arithmetic level before any code.
• Tail idle ~26s (occupancy of the last bucket ≈1.4/8 lanes) — negligible.
• Mid-run occupancy 5.56/8 lanes; last-90s 3.87 — lanes spend ~30% of wall outside test call phases.

Resident-worker dead end (measured, reverted): long-lived pytest workers serving batches over a pipe protocol ran the full suite in 587.4s vs 445.7s baseline (+31.8%). Artifact: wt-RESIDENT-WORKERS/reports/run-tests-latest.json on branch feat/resident-workers — 1,610 modules / 32,463 passed (0.08% narrower scope than the baseline's 1,611 / 32,490). master never carried it. Do not retry this lever.

CORRECTED 2026-08-12 (second adversarial review, plan §6b-4). This paragraph previously read "590s vs 446s (+32%) with 4 solo-retry recoveries vs 0. Cause: cross-batch state accumulation that per-batch subprocesses drop at exit." The retained artifact records rerun.count = 0, solo_retry = null, failed = 0 — the recovery count is contradicted by it, and the causal story rests on that count. Both withdrawn. The lever stays closed on wall time alone, which the artifact does support. Re-opening the causal question would need a fresh instrumented run on the branch; nothing in-repo answers it.

3. Call-CPU distribution research (lever3_research.py)

No big rocks: top 10 tests = 8.4% of CPU; top 100 = 35.9%; top 250 = 53.3%; top 1,000 = 85.3%. Histogram: 3 tests in 20-60s (76.7s); 24 in 10-20s (307.4s); 48 in 5-10s (339.0s); 189 in 2-5s (538.3s); 31,191 tests <0.5s total only 316.7s. Baseline had zero >60s flags and zero acknowledged-slow.

CORRECTED 2026-08-12 (second adversarial review, plan §6b-1). This section previously read "the addressable mass is 581 tests in the 2-60s band ≈ 52% of CPU" — that fuses two different cuts and contradicts the histogram immediately above it (3+24+48+189 = 264). Re-derived from the same baseline window:

581 is the ≥1.0s cut, not the band. Sizing work off "581 tests ≈ 52%" overstates the band's population by 2.2× and understates the ≥1s cut's CPU by 18 points. The ≥1.0s cut is the better target definition: it is where 72.6% of call CPU lives.

Top modules by call CPU: test_run_tests.py 56.1s, test_gen_brief_pack.py 41.2s, test_agent_check_e2e.py 39.6s (3 tests), test_cli.py 35.2s, test_fact_extractor.py 34.1s, test_test_executor.py 32.7s, test_run_tests_main_infra.py 29.6s, test_session_stress.py 28.5s, test_workspace_perf.py 28.0s (spec'd load measurement), test_agent_check.py 27.9s. Nested-runner modules total 132s CPU. 27 tests ≥10s hold 384s. QA subprocess tooling class 67.5s across two modules.

Redesign classes (with named evidence): retry/timeout tests paying real budgets (test_execute_retries_transient_error_then_raises 13.0s vs core/graph/retry.py 8-attempt exponential to 3.2s); full-pipeline e2e repeated per test (test_agent_check_e2e, test_agent_check — real ruff/mypy/pytest + sleep(1.5) handshakes); real-index/AST-heavy queries (test_gen_brief_pack, test_orchestrata_tools 18.5s); nested runners. Proven in-repo fix patterns: retry-budget DI (test_session_graph_store 42.7→4.24s, 2026-08-11), module-scope immutable pipeline fixtures (T4, e.g. _async_multi_results_json), AST-daemon session fixture (4–6× on CLI tests, 2026-08-11).

4. Fixture-share probe (falsify experiment, survives)

3 modules run individually with junit + observer durations sinks (/tmp/fx_*.xml, /tmp/fx_*.ndjson): junit time (setup+call+teardown) vs observer call-sum — test_trace_intel 11% fixture share (3.5/31.7s), test_search 51% (10.5/20.7s), test_cli 1% (0.1/21.8s). Fixture cost is real and highly module-dependent (5× spread); adversarial note: a 3-of-1,611 sample cannot generalize a suite figure.

5. AST censuses

Pattern census (ast_slow_review2.py): 736 of 45,865 functions carry ≥1 slow-pattern signature (constant sleep, subprocess spawn, db-connect-per-call, network, retry, recompute). Weighting: measured CPU of hot test modules statically reaching each function (depth-2 BFS over static calls). Limits found during the work: runtime_calls in plans/ast-ultimate.json covers src→src only — test functions carry empty lists, so runtime-edge weighting is impossible; static reachability over-approximates and the weights are attention priority, not cost attribution.

Loop-nesting census (loop_census.py): 287 functions with true loop-depth ≥2 (if/try/with excluded) across src/. Deepest: _build_class_module_map (4, os.walk nests), code_parser.resolve_inheritance (4 — read: index-based, linear, ruled out), transitive_coupling (3 over the same node set — Warshall O(n³), latent: callers are amendment-scoped only). ToolExecutor.execute (nesting depth 19 per the toolkit's branch-based nesting command) is an if/elif dispatch with zero loops — maintainability, not runtime.

Complexity census: 77 functions cx≥15; top SemanticGraphIngester.search (29), PipelineKGMixin.sync_artifacts_to_kg (28), TaskManager.output_of (27). Weak hot-path overlap.

6. Live measurements (each independently rerun by the adversarial reviewer)

7. Adversarial review record

Agent: ~/.kimi-code/agents/adversarial-reviewer.md (created for this purpose; read-only tools; verdict protocol SUPPORTED/WEAK/WRONG/UNVERIFIABLE with independent reruns). Now a mandatory measure-first checklist item (adversarial between falsify and signoff; measure_first.py migrates armed checklists automatically).

Second review (2026-08-12) — independent re-derivation

A second adversarial pass re-derived the numbers from the artifacts without reusing the /tmp scripts: fresh gap-segmentation of test-durations.ndjson, fresh _prepare_batches replay against .cache/test_durations.json, AST-toolkit reads of every cited code site.

Reproduced exactly: call CPU 2,312.0s (window n=32,238, span 441.7s); floor 289.0s at 8 lanes (-j default confirmed 8, -b default 6 → 48 bins); 51 batches; cache mass 3,104.6s over 1,615 entries → bucket 792.6s; the 8.4/35.9/53.3/85.3% distribution; the 3/24/48/189-test histogram with 31,191 tests <0.5s = 316.7s; the module CPU table (56.1/41.2/39.6/34.1/32.7/29.6/28.5/28.0/27.9); D3's 32.7-of-34.1s attribution; the 75.75s backoff sum; and the structural premises of D1/D2/D2b/D7 at their cited lines.

Not reproduced / corrected: §3's "581 tests in the 2-60s band ≈ 52%" (§6b-1, corrected above); D7's classifier description (§6b-2); D1's index-based fix mechanism (§6b-3); the resident-worker recovery count and cause (§6b-4); the 289s floor as a constant — three consecutive 2026-08-11 full runs measured 2,312 / 2,417 / 2,862s call CPU, i.e. floors 289 / 302 / 358s, so the floor is a range (§6b-5); §4's unidentifiable "test_cli" (§6b-6); test_agent_check_e2e is 4 records, not 3 (§6b-7). Findings that were absent rather than wrong — the four production defects' near-zero suite leverage, the missing real-scale regression guards, D2's unnecessary invalidation machinery, and the impact_score name collision — are recorded as plan §8.

Verdicts on this research (first review): every hard number reproduced within noise (2,312s; 289s; 0.90s; ~11k round-trips; 0.66–0.72s; 322s extrapolated; 2.07s; 4.04s; 34.1s module; 384/132/67.5s classes; 75.75s backoff). Corrections accepted: D1 ~16s not ~8s per call; D7 ~3× worse than first stated; cache total 3,105s not 3,103s (bucket 793s not 791s). Withdrawn: the "~340-360s realistic suite outcome" projection — no per-lever savings model exists; only the endpoints (446s baseline, 289s floor) are arithmetic.

8. Gaps the review could not close (recorded, not hidden)

1. Fixture vs collection/import/teardown split of the 793s bucket — needs an instrumented run (--setup-show or phase-broken junit) over ≥20 modules spanning the duration distribution.
2. The 397s residual — needs per-lane occupancy logging inside test_executor (lane busy-in-fixture vs busy-in-test vs idle).
3. The 1.26s/batch spawn constant is a single-module measurement; batch-to-batch variance unmeasured (small stakes: ~8s wall total).
4. Full centrality run exists (340.37s) but the adversarial extrapolation (322s) used 0.5% of sources; both numbers agree the defect is real either way.
5. Per-lever savings model for the suite-side program — can only be produced by implementing a lever and re-running the suite (deferred to the verify phase).
6. 252 missing tests in the ndjson window — their CPU (~18s at mean, unbounded if slow) lands inside the WEAK fixture bucket.

Related

• Plans
• Orchestrata Ultimate — project index
• Workflow
• Tasks