Skip to content

fix(tests): keep a gen2 pause out of two sub-second perf gates - #102

Merged
ethan-scitix merged 2 commits into
mainfrom
fix/perf-gate-gen2-pause
Aug 14, 2026
Merged

fix(tests): keep a gen2 pause out of two sub-second perf gates#102
ethan-scitix merged 2 commits into
mainfrom
fix/perf-gate-gen2-pause

Conversation

@ethan-scitix

@ethan-scitix ethan-scitix commented Aug 14, 2026

Copy link
Copy Markdown
Collaborator

Type

  • fix — bug fix or alignment correction

Summary

Two perf tests fail intermittently in full-suite runs and pass in isolation, with no change to the code they measure. Both were dismissed as "flaky under load"; neither is — the machine was at load average 3.54 on 128 cores while they reproduced.

Neither is a CI gate, which is worth stating precisely: CI runs tests/unit tests/integration tests/acceptance, and both of these live under tests/performance/, which is not in that path list. What they gate is a bare local pytest — where a developer actually meets them, and where a red line on unrelated work costs an investigation.

  • test_throughput_vs_concurrency loses a single gen2 collection into a sub-second window. After tests/unit alone the process holds 833,021 tracked objects and one gen2 pass costs 286 ms — longer than the 0.20 s window the test measures at concurrency 16. Its timed section now runs under gc.freeze().
  • test_pipeline_memory_scaling divided by a number that was mostly one-time process growth. delta for n=2000 measured 122.7 MB in a fresh process against 20 MB of actual payload, and 62.3 MB for the identical run once the suite had already grown the process. The published ratio ranged 1.2x → 6.7x for unchanged code against a 4x bar. Replaced by a marginal figure, which cancels that term.

The shape is what rules out contention. In the failing run, concurrency 1 and 4 came in 0.043 s and 0.053 s slower than isolated while concurrency 16 took 0.457 s longer — one discrete pause landing in the shortest window, not everything degrading together. That 0.457 s sits on the measured pause-vs-heap curve (305k objects → 14.6 ms, 1M → 94 ms, 2M → 258 ms, 4M → 535 ms synthetic; the real heap is dearer per object, 286 ms at 833k).

gc.freeze(), not gc.disable(). These gates measure framework scheduling efficiency, and GC pressure the pipeline itself creates is part of that. Freeze takes only the heap it did not allocate out of the scan; objects allocated inside the window are still collected and still charged to it. test_serialization's _gc_paused disables outright, which is right there — a tight serialization loop where any collection is pure noise — and is left alone.

Hypotheses tested and discarded, recorded so they are not re-tried. Allocator reuse does not explain the memory gate: 1 MB blocks go through mmap and are returned on free, so the same 100 MB allocation measured 96.7 MB on a small heap and 99.8 MB after an 800 MB peak had been freed.

Related Issues

Follow-up to #96, which diagnosed this mechanism and fixed test_orjson_vs_serialize_breakdown. Its docstring reasoned that "the absolute bounds elsewhere have the headroom to absorb a collection" — true for the absolute bounds, not for these two.

Test Plan

Automated

  • Lint/format clean (ruff check && ruff format --check)
  • Type check clean (ty check)
  • Unit tests pass (pdm run pytest) — two consecutive full-suite runs, and in both, test_throughput_vs_concurrency and test_pipeline_memory_scaling pass. They failed in the two full-suite runs before this change.
  • Both also still pass in isolation, so the change did not simply loosen them.

Manual

  • Which gates need this was computed, not assumed. Each timed gate was checked against one 286 ms pause landing in its worst window: iteration_overhead goes 2.98x → 4.15x against a 5.0x bar, record_each_stage 46% → 151% against 200%, dep_loading times ~18 ms but takes the best of five so a pause must hit every run. Those keep their headroom and are untouched.
  • The marginal memory figure is stable where the ratio was not. Across four process states (isolated, after tests/unit/core, after acceptance+performance, after the full suite) the ratio-of-deltas read 1.2x / 1.3x / 1.6x / 2.8x while the marginal peak read 51.7 / 65.6 / 57.8 / 48.0 KB per sample — and, more to the point, is no longer ordered by how much of the suite ran first; the heaviest state is now the lowest reading. The bound is 10x the payload (100 KB against 10 KB), matching what TestContextMemoryFootprint allows a single context. Both bounds are verified live by mutation: a 4x bar fails at 49.3, an 8x floor fails at 61.8.
  • The first version of this metric was still contaminated. It differenced two absolute RSS peaks, and peak_mb is a high-water mark, so the difference still carried baseline[10000] - baseline[2000] — 257.1 MB of residue, 32.9 of the 84.6 KB/sample it reported, 39% of the figure — which kept the reading climbing with process weight (80.7 → 106.6). Each run's peak is now taken over its own baseline, which cancels it.

Not fixed here, and why

TestBenchmarkSummary::test_benchmark_scenarios still fails in a full-suite run (high_concurrency 63.5% against its 65% bar, against 79.2% in a fresh process — reproducible, tests/unit alone is enough to cause it). It is @pytest.mark.benchmark, which CI deselects (-m "not stress and not benchmark"), and tests/README.md already documents that marker as "calibrated on a dedicated box… treat a failure as 're-run idle' before calling it a regression".

That marker does not mean it gates nothing — saying so gets it backwards. /sieval-release runs pytest -m benchmark and stops the release if it fails, so it is the only one of the three sitting behind an automated gate. What makes it safe to defer is different: the release runs -m benchmark alone, in a fresh process whose heap is small, so the 286 ms mechanism does not reach it there — reproducing the failure takes a bare full-suite pytest. Moving its threshold is still a calibration decision rather than a bug fix.

Its window is wrapped anyway, since it is the same exposure and costs nothing — but that is not what makes the residual gap, and the cause there is still open. Ruled out by experiment: memory footprint (1.2 GB of GC-untracked bytes → 78.3%, still passing), tracked-object population (856k tracked dicts → 78.5%, still passing), leaked loguru sinks (1 handler after tests/unit), and leaked threads (4 alive). Only actually running the suite reproduces it.

Checklist

Required (all PRs)

  • PR title follows conventional format (type(scope): description)
  • No internal paths, credentials, or personal info in committed files
  • AI-generated code has AI-Generated Code - <model> (<provider>) in module docstring — tests only, no new modules
  • No new upper-layer dependencies added to core/
  • Deleted code verified — the delta ratio survives as a printed diagnostic; only its assertion is replaced

ethan-scitix and others added 2 commits August 14, 2026 15:33
`test_throughput_vs_concurrency` and `test_pipeline_memory_scaling` fail in
full-suite runs and pass in isolation with no change to the code they measure.
Neither is load: the machine sat at load average 3.54 on 128 cores while both
reproduced.

A gen2 collection costs in proportion to the whole live heap. After
`tests/unit` alone this process holds 833,021 tracked objects and one gen2 pass
takes 286 ms -- longer than the 0.20 s window the concurrency gate measures at
concurrency 16. One collection landing there is the whole difference between
61.7% and 18.9% efficiency. The shape rules out contention on its own: in the
failing run concurrency 1 and 4 came in 0.043 s and 0.053 s slower while
concurrency 16 took 0.457 s longer, which is one discrete pause and not
everything degrading together.

`gc.freeze()` rather than `gc.disable()`: these gates measure scheduling
efficiency, so GC pressure the pipeline itself creates has to stay charged to
the window. Only the heap it did not allocate stops being rescanned.
`test_serialization`'s `_gc_paused` disables outright, which is correct for a
tight serialization loop, and is left alone. Which gates need the guard was
computed against a single pause rather than assumed: `iteration_overhead`
(2.98x -> 4.15x against 5.0x), `record_each_stage` (46% -> 151% against 200%)
and `dep_loading` (best of five) keep their headroom and are untouched.

The memory gate had a different defect: it divided by a quantity that is mostly
one-time process growth. `delta` at n=2000 measured 122.7 MB in a fresh process
against 20 MB of real payload, and 62.3 MB for the identical run once the suite
had grown the process, so the ratio published 1.2x to 6.7x for unchanged code
against a 4x bar. Subtracting two measurements cancels the term: the marginal
peak held at 80.7 / 82.7 / 82.8 / 106.6 KB per sample across those same four
process states. The delta ratio stays as a printed diagnostic.

Not allocator reuse, which was the first guess: 1 MB blocks go through `mmap`
and are returned on free, so the same 100 MB allocation measured 96.7 MB on a
small heap and 99.8 MB after an 800 MB peak had been freed.

Verified over two consecutive full-suite runs; both gates pass in each, and
both still pass in isolation.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
The marginal figure that replaced the ratio is built from two *absolute* RSS
peaks, and `peak_mb` is a high-water mark, so `peaks[10000] - peaks[2000]`
still carries `baseline[10000] - baseline[2000]`: the RSS this process retained
across the n=2000 and n=5000 iterations. Instrumented here that residue was
257.1 MB -- 32.9 of the 84.6 KB/sample it reported, 39% of the figure -- and it
kept the reading ordered by process weight, 80.7 to 106.6 across four states.
That is the same contamination the ratio was dropped for, an order of magnitude
smaller.

Each run's peak is now taken over its own baseline, which does cancel it. Across
the same four states (isolated, after `tests/unit/core`, after `tests/unit`, and
in a full-suite run) the corrected figure reads 45-66 KB per sample and is no
longer ordered by how much ran first -- the heaviest state reads lowest. That
ordering going away, not the spread, is the evidence the term is gone. The bar is
10x the payload, the same budget `TestContextMemoryFootprint` allows one context,
~1.5x over the worst reading. Both bounds were verified live by mutation rather
than assumed: a 4x bar fails at 49.3 KB, an 8x floor fails at 61.8 KB.

The assertion is also two-sided again. `results[2000] > 0` was the guard that a
measurement had happened at all; dropping it left a one-sided bound that passes
any degenerate reading at or below zero -- a stalled sampler, or RSS fully
reused -- as silently as a healthy one.

`suite_heap_excluded()` is made safe under nesting. `gc.unfreeze()` is
all-or-nothing, so a nested exit dropped the outer guard while the outer window
was still being timed, and it failed silently rather than loudly. A nested enter
is now a no-op: the outer freeze already covers everything the inner window
inherited, and anything allocated since belongs to the code under test, which
has to stay charged. `_run_scenario` is a shared helper, so a second caller
wrapping it would have hit exactly this; the sibling `_gc_paused` already
restores prior state on purpose.

Docstring corrections. The gate enumeration read as exhaustive while naming
three gates, omitting `dataset_iteration_overhead`, `multi_task_runner` and
`composite_limiter`. All three survive a pause, but the first is worth recording
because the arithmetic misleads: fresh it reads 443.7x against a 600x bar and
the leftover ratio is only 37 ms of numerator, yet its denominator is a
plain-list loop that slows 4x on locality alone under 1.03M live objects, so the
ratio drops to 104x and headroom rises to ~460 ms against a 206 ms pass in that
same process. Headroom outgrows the pause. Separately, "the two wrapped here"
did not match what is wrapped -- the memory gate is fixed by measurement, not by
wrapping -- and `tests/README.md` said a frozen heap stops a pass landing in the
window, when what it stops is the pass rescanning the rest of the suite.

Also drops a function-local `import gc as _gc` that the new module-level import
made redundant, and the stale "scales sub-linearly" line left in the module
docstring.

Verified with a full `tests/unit tests/integration tests/acceptance
tests/performance` run: 5363 passed, 6 deselected.

Co-Authored-By: Claude Opus 5 (1M context) <noreply@anthropic.com>
@ethan-scitix
ethan-scitix force-pushed the fix/perf-gate-gen2-pause branch from 89dcaac to f38e7da Compare August 14, 2026 08:15
@ethan-scitix
ethan-scitix merged commit 154bf45 into main Aug 14, 2026
9 checks passed
@ethan-scitix
ethan-scitix deleted the fix/perf-gate-gen2-pause branch August 14, 2026 08:33
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant