Cut the cli_run E2E wall-clock: unshare the serialized demo-project fixture store #250

Closed
opened 2026-07-13 11:35:26 +02:00 by claude · 3 comments
Collaborator

Problem

One integration-test binary dominates the whole workspace suite. A full cargo test --workspace run captured 2026-07-13 finishes in ~247 s, of which crates/aura-cli/tests/cli_run.rs (140 #[test]s) accounts for 211 s:

running 139 tests    (tests/cli_run.rs)
test result: ok. 139 passed; 0 failed; ... finished in 211.01s

Every other test binary and unit-test suite in the workspace finishes in under 35 s combined (largest other entries: 73 tests in 21.1 s, 2 tests in 4.3 s; the library unit tests are all in the millisecond range). So this single binary is ~85 % of suite wall-clock.

The cost multiplies in practice: recent working sessions re-ran the full suite six to eight times per change (test-first red run, green run, each fix-and-re-verify round, final verification), i.e. 20+ minutes of suite wait per change from this one binary alone.

Cause

Three compounding properties:

  1. Serialized execution. The binary's tests share the git-tracked tests/fixtures/demo-project fixture and mutate its runs/ store, so they take the project_lock() mutex (crates/aura-cli/tests/common/mod.rs:49, shared via the #223 extraction — #223, now closed, deduplicated built_project/project_lock into tests/common). The lock defeats the test harness's default thread-parallelism: 139 tests run strictly one after another (~1.5 s average each). cli_run.rs's fresh_project() (around line 41) exists to enforce exactly this serialization.
  2. Every test spawns processes. Each test launches the real aura binary (CARGO_BIN_EXE_aura) at least once, many several times, plus git invocations for provenance-sensitive scaffold tests.
  3. Some tests compute real workloads twice. The *_reproduces_bit_identically family runs a sweep / walkforward / Monte-Carlo and then re-derives it for a bit-identical comparison; the *_real_* family additionally reads actual market data.

The test count also grows structurally — E2E fixtures accumulate in this binary a few at a time with each shipped change (140 and counting), so the wall-clock trend is monotonically up.

Direction

Two independent levers, both compatible:

  • Unshare the mutable store, drop the lock. The shared object the lock protects is only the fixture's runs/ store (common/mod.rs:45-48: tests "remove/re-seed <fixture>/runs"). Options: point each test at its own store location if the store path can be injected (flag or env var — to be checked), or copy the built fixture into a per-test tempdir (built_project() builds once per process; cargo build on the fixture is idempotent, and a directory copy is cheap next to the current 1.5 s/test serial cost). Either way the harness's default parallelism returns.
  • Gate the expensive real-data reproduction tests. Make the *_real_* / bit-identical-reproduce family opt-in (#[ignore] or a cargo feature) so the default per-change suite stays fast, with the full set still run as a final verification step before a change is considered done.

Note on cargo-nextest as a shortcut: it would make things worse, not better, while the shared store exists — one process per test bypasses the in-process mutex entirely. The common/mod.rs module header (lines 6-14) documents this exact boundary ("Process-local serialization only ... a process-parallel test runner ... still race[s] on the shared tests/fixtures/demo-project/runs store"), and cross-binary collisions on the shared store were already observed 2026-07-12 as three spurious --workspace test failures that passed on isolated re-run. Unsharing the store has to land first; parallelism then comes back safely at both levels.

## Problem One integration-test binary dominates the whole workspace suite. A full `cargo test --workspace` run captured 2026-07-13 finishes in ~247 s, of which `crates/aura-cli/tests/cli_run.rs` (140 `#[test]`s) accounts for 211 s: ``` running 139 tests (tests/cli_run.rs) test result: ok. 139 passed; 0 failed; ... finished in 211.01s ``` Every other test binary and unit-test suite in the workspace finishes in under 35 s **combined** (largest other entries: 73 tests in 21.1 s, 2 tests in 4.3 s; the library unit tests are all in the millisecond range). So this single binary is ~85 % of suite wall-clock. The cost multiplies in practice: recent working sessions re-ran the full suite six to eight times per change (test-first red run, green run, each fix-and-re-verify round, final verification), i.e. 20+ minutes of suite wait per change from this one binary alone. ## Cause Three compounding properties: 1. **Serialized execution.** The binary's tests share the git-tracked `tests/fixtures/demo-project` fixture and mutate its `runs/` store, so they take the `project_lock()` mutex (`crates/aura-cli/tests/common/mod.rs:49`, shared via the #223 extraction — #223, now closed, deduplicated `built_project`/`project_lock` into `tests/common`). The lock defeats the test harness's default thread-parallelism: 139 tests run strictly one after another (~1.5 s average each). `cli_run.rs`'s `fresh_project()` (around line 41) exists to enforce exactly this serialization. 2. **Every test spawns processes.** Each test launches the real `aura` binary (`CARGO_BIN_EXE_aura`) at least once, many several times, plus `git` invocations for provenance-sensitive scaffold tests. 3. **Some tests compute real workloads twice.** The `*_reproduces_bit_identically` family runs a sweep / walkforward / Monte-Carlo and then re-derives it for a bit-identical comparison; the `*_real_*` family additionally reads actual market data. The test count also grows structurally — E2E fixtures accumulate in this binary a few at a time with each shipped change (140 and counting), so the wall-clock trend is monotonically up. ## Direction Two independent levers, both compatible: - **Unshare the mutable store, drop the lock.** The shared object the lock protects is only the fixture's `runs/` store (`common/mod.rs:45-48`: tests "remove/re-seed `<fixture>/runs`"). Options: point each test at its own store location if the store path can be injected (flag or env var — to be checked), or copy the built fixture into a per-test tempdir (`built_project()` builds once per process; `cargo build` on the fixture is idempotent, and a directory copy is cheap next to the current 1.5 s/test serial cost). Either way the harness's default parallelism returns. - **Gate the expensive real-data reproduction tests.** Make the `*_real_*` / bit-identical-reproduce family opt-in (`#[ignore]` or a cargo feature) so the default per-change suite stays fast, with the full set still run as a final verification step before a change is considered done. Note on `cargo-nextest` as a shortcut: it would make things worse, not better, while the shared store exists — one process per test bypasses the in-process mutex entirely. The `common/mod.rs` module header (lines 6-14) documents this exact boundary ("Process-local serialization only ... a process-parallel test runner ... still race[s] on the shared `tests/fixtures/demo-project/runs` store"), and cross-binary collisions on the shared store were already observed 2026-07-12 as three spurious `--workspace` test failures that passed on isolated re-run. Unsharing the store has to land first; parallelism then comes back safely at both levels.
Owner

Measured breakdown (2026-07-13, read-only analysis session — prebuilt debug binary 3016bd6, fixture copy + real archive, repo untouched). The Cause section needs two corrections, and the Direction section is missing the biggest lever.

Correction 1: it is not 139-wide serialization

Only 37 of 140 tests take the lock (all via fresh_project(), cli_run.rs:40-46; zero direct project_lock() calls). The other ~103 use temp_cwd() or no cwd and already run 24-wide. The 211 s is the serial chain of the 37 fixture tests (~5.5 s average), and that average is an artifact of an extremely skewed distribution — the median test is ≪100 ms.

Correction 2: the chain's weight is compute, not lock overhead

Measured with the prebuilt debug binary against a tempdir fixture copy (data host, /mnt/tickdata/Pepperstone present):

invocation wall
aura --help (spawn floor) 2 ms
synthetic run examples/r_sma.json 3 ms
same, cwd inside the crate-project fixture +124 ms fixed (see below)
month-bounded run --real GER40 (Sept-2024) ~0.2 s
month-bounded 2-cell sweep --real ~0.35 s
no-window 1-cell sweep --real GER40 (full 2014→2026 archive) 14.5 s (~13.8 µs/bar, linear)
no-window walkforward --real GER40 (142 windows) 19.6 s — two such tests (cli_run.rs:2875, :2973)
year-2025 walkforward pin (9 windows) 4.4 s — ~6 such tests
no-window generalize GER40,USDJPY 34.9 s (cli_run.rs:3493)
the AAPL∩GER40 intersection test (2 full-archive probes + generalize, cli_run.rs:3542) ≈ 55 s total — the single longest test

The ~8–10 full-archive / full-year tests account for ≈150–185 s of the 211 s. It is not death-by-process-spawn, and there is no engine hot-path regression: Harness::run is allocation-free per tick and untouched since 2026-06-29 (d5602ec); per-bar cost scales linearly month→year→12 years. No [profile] overrides exist, so everything (engine, zip inflate, sha2, serde) runs at opt-level 0.

Product-level waste found on the way

  1. probe_window drains the entire close column (main.rs:616-634) just to learn first/last timestamp, and the campaign path always probes — even with explicit --from/--to (main.rs:3249-3263). An O(1) bound derivation from the monthly file index would remove a full archive pass from every no-window invocation.
  2. The walkforward pre-flight executes the complete first-IS-window sweep and discards it (main.rs:2130-2141, landed 6a775f7): blueprint_sweep_over runs every grid member end-to-end purely to validate axes; the walk_forward closure then recomputes the same window. Every real walkforward pays ~one extra IS window.
  3. Per-invocation provenance cost inside a crate project: ~107 ms debug-profile SHA-256 of the 4.7 MB fixture dylib (project.rs:534) + ~12 ms cargo metadata + 2 git spawns, where git status --porcelain walks the whole aura work tree because the fixture has no .git (project.rs:320-340). ~5 s across the suite — real but minor.

Revised direction, ranked by measured gain

  1. Window the five no-window whales (−115…135 s). The two walkforward_dissolved_* tests assert only exit 0 — the full span is not load-bearing; the 135-day window from reproduce_real_walkforward_family_does_not_panic (cli_run.rs:1935) preserves the property. For the generalize/intersection/roller tests the no-window resolution IS the property — point them at a tiny committed archive (2 symbols × a few months, deliberately different spans) via the existing paths.data override instead.
  2. Unshare without any engine change (restores 24-wide parallelism): replace fresh_project() with a per-test tempdir containing a 2-line Aura.toml whose [nodes] crates = ["<absolute path to the fixture>"] shares the already-built cdylib read-only (absolute pointers pass through, project.rs:42-44/:497; store root follows the project root, project.rs:167-175). project_lock() and the runs/ wipe become deletable. Caveats: provenance commit is None in a non-git tempdir (no fresh_project test asserts it; init_and_commit exists at project_new.rs:34 if one ever does). A full fixture copy is the wrong lever — 72 MB of target/ and a relative aura-core path-dep that breaks outside the tree.
  3. Shrink the ~6 full-2025 pins to one quarter and re-pin once (−20 s serial; optional — 4.4 s each is tolerable once parallel).
  4. [profile.dev.package."*"] opt-level = 2 — multiplicative on inflate/parse/sha2/sim with zero test edits; verify the float pins stay byte-identical once (expected: yes, Rust has no fast-math).
  5. Product fixes from the waste list above (O(1) probe, pre-flight without member execution, provenance caching/gating).

With 1+2 the binary lands at ~10–20 s wall on 24 cores; #[ignore]-gating the real family becomes unnecessary. The nextest note in the issue stands unchanged: unsafe until the store is unshared.

**Measured breakdown (2026-07-13, read-only analysis session — prebuilt debug binary `3016bd6`, fixture copy + real archive, repo untouched).** The Cause section needs two corrections, and the Direction section is missing the biggest lever. ## Correction 1: it is not 139-wide serialization Only **37 of 140 tests** take the lock (all via `fresh_project()`, cli_run.rs:40-46; zero direct `project_lock()` calls). The other ~103 use `temp_cwd()` or no cwd and already run 24-wide. The 211 s is the serial chain of the 37 fixture tests (~5.5 s average), and that average is an artifact of an extremely skewed distribution — the median test is ≪100 ms. ## Correction 2: the chain's weight is compute, not lock overhead Measured with the prebuilt debug binary against a tempdir fixture copy (data host, `/mnt/tickdata/Pepperstone` present): | invocation | wall | |---|---| | `aura --help` (spawn floor) | 2 ms | | synthetic `run examples/r_sma.json` | 3 ms | | same, cwd inside the crate-project fixture | +124 ms fixed (see below) | | month-bounded `run --real GER40` (Sept-2024) | ~0.2 s | | month-bounded 2-cell `sweep --real` | ~0.35 s | | **no-window 1-cell `sweep --real GER40`** (full 2014→2026 archive) | **14.5 s** (~13.8 µs/bar, linear) | | **no-window `walkforward --real GER40`** (142 windows) | **19.6 s** — two such tests (cli_run.rs:2875, :2973) | | year-2025 `walkforward` pin (9 windows) | 4.4 s — ~6 such tests | | **no-window `generalize GER40,USDJPY`** | **34.9 s** (cli_run.rs:3493) | | **the AAPL∩GER40 intersection test** (2 full-archive probes + generalize, cli_run.rs:3542) | **≈ 55 s total — the single longest test** | The ~8–10 full-archive / full-year tests account for **≈150–185 s of the 211 s**. It is not death-by-process-spawn, and there is **no engine hot-path regression**: `Harness::run` is allocation-free per tick and untouched since 2026-06-29 (`d5602ec`); per-bar cost scales linearly month→year→12 years. No `[profile]` overrides exist, so everything (engine, zip inflate, sha2, serde) runs at opt-level 0. ## Product-level waste found on the way 1. **`probe_window` drains the entire close column** (main.rs:616-634) just to learn first/last timestamp, and the campaign path always probes — even with explicit `--from/--to` (main.rs:3249-3263). An O(1) bound derivation from the monthly file index would remove a full archive pass from every no-window invocation. 2. **The walkforward pre-flight executes the complete first-IS-window sweep and discards it** (main.rs:2130-2141, landed `6a775f7`): `blueprint_sweep_over` runs every grid member end-to-end purely to validate axes; the `walk_forward` closure then recomputes the same window. Every real walkforward pays ~one extra IS window. 3. **Per-invocation provenance cost inside a crate project**: ~107 ms debug-profile SHA-256 of the 4.7 MB fixture dylib (project.rs:534) + ~12 ms `cargo metadata` + 2 git spawns, where `git status --porcelain` walks the whole aura work tree because the fixture has no `.git` (project.rs:320-340). ~5 s across the suite — real but minor. ## Revised direction, ranked by measured gain 1. **Window the five no-window whales** (−115…135 s). The two `walkforward_dissolved_*` tests assert only exit 0 — the full span is not load-bearing; the 135-day window from `reproduce_real_walkforward_family_does_not_panic` (cli_run.rs:1935) preserves the property. For the generalize/intersection/roller tests the no-window *resolution* IS the property — point them at a tiny committed archive (2 symbols × a few months, deliberately different spans) via the existing `paths.data` override instead. 2. **Unshare without any engine change** (restores 24-wide parallelism): replace `fresh_project()` with a per-test tempdir containing a 2-line `Aura.toml` whose `[nodes] crates = ["<absolute path to the fixture>"]` shares the already-built cdylib read-only (absolute pointers pass through, project.rs:42-44/:497; store root follows the project root, project.rs:167-175). `project_lock()` and the runs/ wipe become deletable. Caveats: provenance `commit` is `None` in a non-git tempdir (no fresh_project test asserts it; `init_and_commit` exists at project_new.rs:34 if one ever does). A full fixture *copy* is the wrong lever — 72 MB of `target/` and a relative `aura-core` path-dep that breaks outside the tree. 3. **Shrink the ~6 full-2025 pins to one quarter** and re-pin once (−20 s serial; optional — 4.4 s each is tolerable once parallel). 4. **`[profile.dev.package."*"] opt-level = 2`** — multiplicative on inflate/parse/sha2/sim with zero test edits; verify the float pins stay byte-identical once (expected: yes, Rust has no fast-math). 5. **Product fixes** from the waste list above (O(1) probe, pre-flight without member execution, provenance caching/gating). With 1+2 the binary lands at ~10–20 s wall on 24 cores; `#[ignore]`-gating the real family becomes unnecessary. The nextest note in the issue stands unchanged: unsafe until the store is unshared.
Author
Collaborator

Shipped on branch worktree-250-test-wallclock — PR #255 (closes this issue on merge). Measured end state on the data-full host, full cargo test --workspace: 247 s → 45.7 s wall; cli_run 211 s → 25.0 s (140 tests, all green), research_docs 21.1 s → 1.9 s, every exact-float pin byte-identical.

The four levers, one commit each:

  1. 052cb46 — the three whale tests whose properties are window-independent get bounded windows (two no-window walkforwards, the mc roller-fit probe): 19.6/19.6/14.5 s → 1.1–1.9 s each.
  2. bc6c8fe[profile.dev.package."*"] opt-level = 2: dependency code (zip inflate, sha2, serde) optimized, workspace crates stay opt 0; −17 % on a full-archive sweep.
  3. bd174d1 — per-test tempdir projects via an absolute [nodes] pointer at the once-built fixture; project_lock() retired. The serialized chain is gone and the #223 cross-process race window with it (no shared mutable store remains) — cargo-nextest is now safe to consider.
  4. 7abe89c — the two no-window generalize tests generate a deterministic two-symbol synthetic M1 archive per test (paths.data) and drop their data gates: ~35 s and ~50 s → 0.74 s and 1.14 s, hostless.

The issue's original Cause section is corrected in the measured breakdown: only 37 of 140 tests serialized, and their weight was real full-archive compute, not lock overhead — which is why unsharing alone (step 3) only got the binary to 55 s and the workload levers (1, 4) were needed for the rest. Product-side residue is filed as #252 (O(1) archive-bounds probe), #253 (walkforward pre-flight without member execution), #254 (relative paths.data resolves against the invoking cwd).

Shipped on branch `worktree-250-test-wallclock` — PR #255 (closes this issue on merge). Measured end state on the data-full host, full `cargo test --workspace`: **247 s → 45.7 s wall**; `cli_run` **211 s → 25.0 s** (140 tests, all green), `research_docs` 21.1 s → 1.9 s, every exact-float pin byte-identical. The four levers, one commit each: 1. `052cb46` — the three whale tests whose properties are window-independent get bounded windows (two no-window walkforwards, the mc roller-fit probe): 19.6/19.6/14.5 s → 1.1–1.9 s each. 2. `bc6c8fe` — `[profile.dev.package."*"] opt-level = 2`: dependency code (zip inflate, sha2, serde) optimized, workspace crates stay opt 0; −17 % on a full-archive sweep. 3. `bd174d1` — per-test tempdir projects via an absolute `[nodes]` pointer at the once-built fixture; `project_lock()` retired. The serialized chain is gone and the #223 cross-process race window with it (no shared mutable store remains) — `cargo-nextest` is now safe to consider. 4. `7abe89c` — the two no-window generalize tests generate a deterministic two-symbol synthetic M1 archive per test (`paths.data`) and drop their data gates: ~35 s and ~50 s → 0.74 s and 1.14 s, hostless. The issue's original Cause section is corrected in [the measured breakdown](issues/250#issuecomment-3433): only 37 of 140 tests serialized, and their weight was real full-archive compute, not lock overhead — which is why unsharing alone (step 3) only got the binary to 55 s and the workload levers (1, 4) were needed for the rest. Product-side residue is filed as #252 (O(1) archive-bounds probe), #253 (walkforward pre-flight without member execution), #254 (relative `paths.data` resolves against the invoking cwd).
Author
Collaborator

Second round on the same branch (PR #255 updated): the product-side residue landed too — #254 (relative paths.data now root-anchored, RED-first), #253 (synthetic wf pre-flight validates without executing members; attribution corrected on the issue, the --real-trunk fork is #256), #252 (probe_window drain retired: probe 366 ms → 13 ms via boundary-month extent derivation; end-to-end ~2-3 % since the sim dominates), plus bonus bug #257 (the knob-lab scaffold leaked ~66 MB per test run into /tmp — 159 dirs filled the 16 GB tmpfs; now fixed-name under CARGO_TARGET_TMPDIR).

Final state on the branch: full workspace suite 39.8 s (was ~247 s), cli_run 142 tests ~25 s, all green, clippy clean, float pins byte-identical. Remaining open: #256 (design fork) and #251 (idea).

Second round on the same branch (PR #255 updated): the product-side residue landed too — #254 (relative `paths.data` now root-anchored, RED-first), #253 (synthetic wf pre-flight validates without executing members; attribution corrected on the issue, the `--real`-trunk fork is #256), #252 (`probe_window` drain retired: probe 366 ms → 13 ms via boundary-month extent derivation; end-to-end ~2-3 % since the sim dominates), plus bonus bug #257 (the knob-lab scaffold leaked ~66 MB per test run into /tmp — 159 dirs filled the 16 GB tmpfs; now fixed-name under `CARGO_TARGET_TMPDIR`). Final state on the branch: full workspace suite **39.8 s** (was ~247 s), cli_run 142 tests ~25 s, all green, clippy clean, float pins byte-identical. Remaining open: #256 (design fork) and #251 (idea).
Sign in to join this conversation.
2 Participants
Notifications
Due Date
No due date set.
Dependencies

No dependencies set.

Reference: Brummel/Aura#250