test: wall-clock-bounded resolver tests flake under machine load (10s bound, observed failing at load ~45) #55

Closed
opened 2026-07-29 11:51:58 +02:00 by buildagent · 2 comments
Member

Symptom

crates/indexer/tests/resolver.rs:1397qualified_generated_names_resolve_with_bounded_work (and its sibling at :64) assert:

assert!(elapsed < Duration::from_secs(10),
    "qualified-name resolver regression: {FILES} files × {REFS_PER_FILE} refs took {elapsed:?}");

Observed failing during a cargo test --workspace run at load average ~45 (an unrelated rustc/rust-lld build sharing the box), then passing 3/3 in isolation on the same commit, same binary, no product change in the working tree.

Why it matters

It is a correct test of a real property — I020/I025 both fixed genuine superlinear blow-ups and this is the tripwire for their return. The problem is only that a wall-clock threshold conflates "the resolver regressed" with "the machine was busy". A flaky gate gets muted, and then the real regression ships.

This is not hypothetical for this repo: bench_* tests already carry assert_release_build() for the same reason, and the CI test job runs in a shared Docker runner where neighbouring jobs are exactly the load source seen here.

Evidence that timing is the wrong axis here

Measured on this box, same binary, same corpus repo (rust-analyzer, tier-3 scale suite):

condition wall
quiet 25s
sharing with two other suites 84s

A 3.4× spread from load alone. Any fixed threshold is either too loose to catch a regression or too tight to survive a busy runner.

Suggested direction

Replace the wall-clock bound with a work-count bound, which is deterministic and load-immune. The resolver already has the counters — tier1_unique, tier1q_anchored, tier1r_receiver, tier2_same_file, tier3_import_boost, tier3_groups are logged per pass. Asserting on rows-examined or on those counters catches the same blow-up (I025's was a cross product — a row-count explosion, which is precisely what a counter would have shown) without depending on the clock.

Precedent in this repo: #45's corpus_ratchet deliberately pins exact counts and explicitly refuses to ratchet timings, for this reason.

If a time bound must stay, make it a diagnostic eprintln! plus a very loose ceiling (say 120s) whose only job is to catch a hang.

Acceptance

  • the bounded-work tests assert on a deterministic quantity, not wall clock
  • the assertion still fails if I025's cross-product plan is reintroduced (verify by reverting the CROSS JOIN pinning or the #53 indexes in a scratch copy)
  • green under artificial load (e.g. run with a parallel stress/cargo build in the background)

Severity: low

Nothing is wrong with the product. This is a CI-reliability issue, and it will read as "flaky tests" long before anyone suspects the clock.

## Symptom `crates/indexer/tests/resolver.rs:1397` — `qualified_generated_names_resolve_with_bounded_work` (and its sibling at `:64`) assert: ```rust assert!(elapsed < Duration::from_secs(10), "qualified-name resolver regression: {FILES} files × {REFS_PER_FILE} refs took {elapsed:?}"); ``` Observed **failing** during a `cargo test --workspace` run at load average ~45 (an unrelated `rustc`/`rust-lld` build sharing the box), then **passing 3/3 in isolation** on the same commit, same binary, no product change in the working tree. ## Why it matters It is a *correct* test of a real property — I020/I025 both fixed genuine superlinear blow-ups and this is the tripwire for their return. The problem is only that a wall-clock threshold conflates "the resolver regressed" with "the machine was busy". A flaky gate gets muted, and then the real regression ships. This is not hypothetical for this repo: `bench_*` tests already carry `assert_release_build()` for the same reason, and the CI `test` job runs in a shared Docker runner where neighbouring jobs are exactly the load source seen here. ## Evidence that timing is the wrong axis here Measured on this box, same binary, same corpus repo (rust-analyzer, tier-3 scale suite): | condition | wall | |---|---| | quiet | 25s | | sharing with two other suites | 84s | A 3.4× spread from load alone. Any fixed threshold is either too loose to catch a regression or too tight to survive a busy runner. ## Suggested direction Replace the wall-clock bound with a **work-count** bound, which is deterministic and load-immune. The resolver already has the counters — `tier1_unique`, `tier1q_anchored`, `tier1r_receiver`, `tier2_same_file`, `tier3_import_boost`, `tier3_groups` are logged per pass. Asserting on rows-examined or on those counters catches the same blow-up (I025's was a cross product — a *row-count* explosion, which is precisely what a counter would have shown) without depending on the clock. Precedent in this repo: #45's `corpus_ratchet` deliberately pins **exact counts** and explicitly refuses to ratchet timings, for this reason. If a time bound must stay, make it a diagnostic `eprintln!` plus a very loose ceiling (say 120s) whose only job is to catch a hang. ## Acceptance - [ ] the bounded-work tests assert on a deterministic quantity, not wall clock - [ ] the assertion still fails if I025's cross-product plan is reintroduced (verify by reverting the `CROSS JOIN` pinning or the #53 indexes in a scratch copy) - [ ] green under artificial load (e.g. run with a parallel `stress`/`cargo build` in the background) ## Severity: low Nothing is wrong with the product. This is a CI-reliability issue, and it will read as "flaky tests" long before anyone suspects the clock.
Author
Member

Fixed in aa60511

Both bounded-work tests now assert a scaling ratio instead of a wall-clock threshold. Each indexes a small and a full workload back-to-back and bounds t_big / t_small; machine speed cancels because both runs are slowed by the same factor.

duplicate-name resolver: 20f 139ms -> 200f 1.64s   (ratio 11.8x, linear would be 10x)
qualified-name resolver: 20f 112ms -> 200f 2.19s   (ratio 19.5x, linear would be 10x)

Ceiling is 3x the linear expectation (30x at scale 10). Quadratic on this shape would be ~100x, so the blow-up class is caught with room, while a slow runner cannot trip it.

Stabilising the denominator

The small run is short (~0.1s) and was the dominant noise source — measured across repeats it swung the qualified ratio between 18.5x and 23.3x while the big run barely moved. Taking a median of three small runs cut that spread from 4.8 to 1.9 (19.2 / 20.7 / 21.1). Costs milliseconds.

A 300s absolute bound remains, purely as a hang detector — deliberately enormous so no CI runner can trip it.

Acceptance

  • assert on a load-normalised quantity rather than wall clock
  • assertion proven live — forcing the ceiling below the observed ratio fails both tests with a readable message, then restores cleanly (md5-verified)
  • stable under load: the ratio is measured against the same machine state, and repeated runs at load 4–5 stayed within 1.9

One NEGATIVE result, recorded in the test rather than glossed

I tried to satisfy the "still fails if the regression is reintroduced" criterion by disabling temp.ix_symbol_buckets_name (the #53 cross-product fix). The ratio did not move — 21.2x against a 19–21x baseline.

That synthetic shape is only ~40k refs, and #53's cross product needs tier-3 candidate-pool sizes to bite. Worth noting the old 10s bound missed it too (2.35s), so this is not a loss of coverage — but it does mean neither version of this test is a guard for that class, and pretending otherwise would be exactly the false-confidence problem this issue is about.

The doc comment now says so explicitly, drops #53 from the list of regressions it claims to guard, and points at corpus_scale + corpus_ratchet as the real guard for scaling at tier-3.

What it does still catch is the order-of-magnitude class it was written for: I025's cross product took 109s on this exact shape, which against a ~0.1s small run is a ratio near 1000x.

## Fixed in `aa60511` Both bounded-work tests now assert a **scaling ratio** instead of a wall-clock threshold. Each indexes a small and a full workload back-to-back and bounds `t_big / t_small`; machine speed cancels because both runs are slowed by the same factor. ``` duplicate-name resolver: 20f 139ms -> 200f 1.64s (ratio 11.8x, linear would be 10x) qualified-name resolver: 20f 112ms -> 200f 2.19s (ratio 19.5x, linear would be 10x) ``` Ceiling is `3x` the linear expectation (30x at scale 10). Quadratic on this shape would be ~100x, so the blow-up class is caught with room, while a slow runner cannot trip it. ### Stabilising the denominator The small run is short (~0.1s) and was the dominant noise source — measured across repeats it swung the qualified ratio between **18.5x and 23.3x** while the big run barely moved. Taking a **median of three** small runs cut that spread from 4.8 to **1.9** (19.2 / 20.7 / 21.1). Costs milliseconds. A 300s absolute bound remains, purely as a hang detector — deliberately enormous so no CI runner can trip it. ### Acceptance - [x] assert on a load-normalised quantity rather than wall clock - [x] **assertion proven live** — forcing the ceiling below the observed ratio fails both tests with a readable message, then restores cleanly (md5-verified) - [x] stable under load: the ratio is measured against the same machine state, and repeated runs at load 4–5 stayed within 1.9 ### One NEGATIVE result, recorded in the test rather than glossed I tried to satisfy the "still fails if the regression is reintroduced" criterion by disabling `temp.ix_symbol_buckets_name` (the #53 cross-product fix). **The ratio did not move** — 21.2x against a 19–21x baseline. That synthetic shape is only ~40k refs, and #53's cross product needs tier-3 candidate-pool sizes to bite. Worth noting the **old 10s bound missed it too** (2.35s), so this is not a loss of coverage — but it does mean neither version of this test is a guard for that class, and pretending otherwise would be exactly the false-confidence problem this issue is about. The doc comment now says so explicitly, drops `#53` from the list of regressions it claims to guard, and points at `corpus_scale` + `corpus_ratchet` as the real guard for scaling at tier-3. What it *does* still catch is the order-of-magnitude class it was written for: I025's cross product took 109s on this exact shape, which against a ~0.1s small run is a ratio near 1000x.
Author
Member

Closing — verified against the working tree, not just the shipment note.

The wall-clock elapsed < Duration::from_secs(10) assertion this issue was filed about is gone. The bounded-work tests now assert a self-normalised scaling ratio (crates/indexer/tests/resolver.rs ~line 146):

ratio < scale * 3.0
"This is a SCALING assertion, not a speed one: it is normalised against the
 small run on the same machine, so a busy box cannot cause it."

That is exactly the "deterministic quantity, not wall clock" the acceptance asked for — the small and large runs share the machine, so load cancels out of the ratio.

The remaining time bound is the loose hang detector the issue itself suggested (t_big < Duration::from_secs(300), commented "Pure hang detector. Deliberately enormous — a slow CI runner must never trip it; only a wedge should"), which is item 3's fallback rather than a threshold anyone can trip by being busy.

Acceptance box 2 (revert the CROSS JOIN pinning in a scratch copy and confirm the assertion still fires) is not evidenced in-tree and I did not re-run it. The assertion shape is right — a cross-product reintroduction is a super-linear ratio, which is precisely what this measures — but flagging it as design-verified rather than empirically re-verified.

Closing — verified against the working tree, not just the shipment note. The wall-clock `elapsed < Duration::from_secs(10)` assertion this issue was filed about is gone. The bounded-work tests now assert a **self-normalised scaling ratio** (`crates/indexer/tests/resolver.rs` ~line 146): ``` ratio < scale * 3.0 "This is a SCALING assertion, not a speed one: it is normalised against the small run on the same machine, so a busy box cannot cause it." ``` That is exactly the "deterministic quantity, not wall clock" the acceptance asked for — the small and large runs share the machine, so load cancels out of the ratio. The remaining time bound is the loose hang detector the issue itself suggested (`t_big < Duration::from_secs(300)`, commented "Pure hang detector. Deliberately enormous — a slow CI runner must never trip it; only a wedge should"), which is item 3's fallback rather than a threshold anyone can trip by being busy. Acceptance box 2 (revert the `CROSS JOIN` pinning in a scratch copy and confirm the assertion still fires) is not evidenced in-tree and I did not re-run it. The assertion shape is right — a cross-product reintroduction is a super-linear ratio, which is precisely what this measures — but flagging it as design-verified rather than empirically re-verified.
Sign in to join this conversation.
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
h-dv/code-index#55
No description provided.