From 4acf36f6c8761522ec599bd0846f40815e77e051 Mon Sep 17 00:00:00 2001 From: Ray Walker Date: Sun, 1 Nov 2026 12:11:59 +0000 Subject: [PATCH 1/6] perf(ir): take pyarrow's allocator threads, purges and numpy's OS-entropy seed out of the measured process --- tests/performance/ir_budget.py | 8 ++++++++ tests/performance/ir_workload.py | 16 ++++++++++++++++ tests/unit/test_ir_budget.py | 17 +++++++++++++++++ 3 files changed, 41 insertions(+) diff --git a/tests/performance/ir_budget.py b/tests/performance/ir_budget.py index 26540769..1972f0ac 100644 --- a/tests/performance/ir_budget.py +++ b/tests/performance/ir_budget.py @@ -269,6 +269,14 @@ def measure( "PYTHONNOUSERSITE": "1", "OPENBLAS_NUM_THREADS": "1", "OMP_NUM_THREADS": "1", # pyarrow converts on a thread pool otherwise: +-0.5% per op + # pyarrow's two allocators run on real time. Its bundled jemalloc starts a background thread at + # import, and how that thread is scheduled against the main thread puts startup in one of two + # states, up to 1.2M Ir apart. With the thread off, jemalloc would check its real-time purge + # deadlines on the allocating thread instead, so it never purges. pyarrow's default pool, mimalloc, + # purges freed memory after a real-time delay that the freeing thread checks (10 clock reads per + # real-data round trip), so it never purges either. + "JE_ARROW_MALLOC_CONF": "background_thread:false,dirty_decay_ms:-1,muzzy_decay_ms:-1", + "MIMALLOC_PURGE_DELAY": "-1", # cachekit's L1 sweeper wakes every 30 s of real time. A woken thread takes the GIL at a # load-dependent moment, and the sweeper compares expiry times stamped by the pinned # main-thread clock against the real one, so it evicts live entries mid-run. A day-long diff --git a/tests/performance/ir_workload.py b/tests/performance/ir_workload.py index 0a660407..a0e40326 100644 --- a/tests/performance/ir_workload.py +++ b/tests/performance/ir_workload.py @@ -215,6 +215,21 @@ def read() -> Any: setattr(time, f"{name}_ns", pinned(getattr(time, f"{name}_ns"), int(origin * 1e9), 1000)) +def pin_os_entropy() -> None: + """Give Python code the same OS entropy in every run. + + Importing pandas imports ``numpy.random``, which seeds its global generator from 128 bits of + ``secrets.randbits``. The cost of that seeding and the sizes of what it allocates depend on the + bits drawn, and the heap layout everything after it runs in moves with them: on CPython 3.14, + 16 runs of one path spread over 57,000 instructions, and over 557 with this. ``secrets`` reads + ``random._urandom``, which is ``os.urandom`` bound at import, so both are replaced. Must run + before ``import pandas``. C code that reads OS entropy itself is not covered. + """ + import random + + random._urandom = os.urandom = random.Random(0).randbytes # pyright: ignore[reportAttributeAccessIssue] + + def run_workload(path: str, n: int, warmup: int) -> None: import gc @@ -228,6 +243,7 @@ def run_workload(path: str, n: int, warmup: int) -> None: # main thread gives up the GIL only where the code releases it itself. sys.setswitchinterval(1e6) pin_main_thread_clocks() + pin_os_entropy() _shift = [object() for _ in range(int(os.environ.get("IR_BUDGET_LAYOUT", "0")))] # noqa: F841 (held: see LAYOUTS in ir_budget.py) op = build_workload(path) for _ in range(warmup): # identical warmup at both N: first-call costs (L1 fill, lazy imports) cancel diff --git a/tests/unit/test_ir_budget.py b/tests/unit/test_ir_budget.py index f857f68c..6a60cc2d 100644 --- a/tests/unit/test_ir_budget.py +++ b/tests/unit/test_ir_budget.py @@ -511,6 +511,23 @@ def test_pinned_clocks_tick_per_read_on_the_main_thread_only(monkeypatch) -> Non assert seen[0] > 1.7e9 + 1e6 # the real clock: 2023-11 + 11 days at the very least +def test_pinned_os_entropy_starts_numpy_in_the_same_state_in_every_run() -> None: + """numpy.random seeds its global generator from OS entropy at import, which moved every path's count.""" + probe = ( + "import sys; sys.path.insert(0, sys.argv[1]); import ir_workload\n" + "if sys.argv[2] == 'pin': ir_workload.pin_os_entropy()\n" + "import numpy.random; print(numpy.random.get_state()[1][:8].tolist())" + ) + perf = str(Path(ir_workload.__file__).parent) + + def first_words(mode: str) -> str: + run = [sys.executable, "-c", probe, perf, mode] + return subprocess.run(run, capture_output=True, text=True, check=True).stdout # noqa: S603 (trusted: this test's probe) + + assert first_words("pin") == first_words("pin") + assert first_words("os") != first_words("os") # unpinned, numpy's start does come from OS entropy + + @pytest.mark.parametrize("n", [1, 4, len(PATHS) + 1]) def test_shards_split_the_paths_exactly_once(n: int) -> None: """N machines running --shard 1/N .. N/N measure every path that is not skipped, and none twice.""" From 42b25b21d4e91917b782006a6017f267932a89e0 Mon Sep 17 00:00:00 2001 From: Ray Walker Date: Sun, 1 Nov 2026 14:53:01 +0000 Subject: [PATCH 2/6] perf(ir): gate every path at 1,000 and 3,000 calls and serializer_orjson at 1% --- CONTRIBUTING.md | 2 +- Makefile | 2 +- tests/performance/ir_budget.py | 28 +++++++++------------------- tests/performance/ir_report.py | 2 +- tests/unit/test_ir_budget.py | 15 +++------------ tests/unit/test_ir_report.py | 4 +--- 6 files changed, 16 insertions(+), 37 deletions(-) diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index 1f6babb6..1be2d0a8 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -340,7 +340,7 @@ make build # Standard build ```bash make perf # Full battery: env fingerprint + timer calibration, serializer benchmarks, GIL scaling make perf-compare # Regression gate: fail on >10% median serializer regression vs baseline -make perf-ir # Instruction-count gate: fail on a >=1% per-call regression (orjson 2%; needs valgrind) +make perf-ir # Instruction-count gate: fail on a >=1% per-call regression (needs valgrind) make perf-ir-update # Ratchet the committed instruction budgets down to the measured figures make benchmark # Serializer benchmarks only + save a local baseline diff --git a/Makefile b/Makefile index 60ade960..011e4f6f 100644 --- a/Makefile +++ b/Makefile @@ -425,7 +425,7 @@ perf-compare: benchmark-compare ## Perf regression gate: fail on >10% median ser # Deterministic hot-path gate: main-thread callgrind instructions per op, fail at >=+1% vs the # budgets in tests/performance/ir_baselines.json (keyed per interpreter). Needs valgrind and the # release extension `uv sync` builds. See docs/performance.md, "Instruction budgets". -perf-ir: ## Instruction-count gate: fail on >=1% per-op regression (orjson 2%; needs valgrind) +perf-ir: ## Instruction-count gate: fail on >=1% per-op regression (needs valgrind) @uv run python tests/performance/ir_budget.py perf-ir-update: ## Ratchet instruction budgets down to the measured figures (never up) diff --git a/tests/performance/ir_budget.py b/tests/performance/ir_budget.py index 1972f0ac..563c6447 100644 --- a/tests/performance/ir_budget.py +++ b/tests/performance/ir_budget.py @@ -9,7 +9,9 @@ is not counted either: about half of the real-data Arrow round trip runs on pyarrow's threads. - Interpreter startup is ~2 billion instructions. Each path runs at two loop sizes and the per-op cost is the difference, ``(Ir[N_HI] - Ir[N_LO]) / (N_HI - N_LO)``, so startup and - warmup cancel. The real-data paths run at smaller sizes, and the cheapest paths at larger ones (``LOOPS``). + warmup cancel, as long as startup costs the same in every run: the environment keeps pyarrow's + allocators off real time (``measure``) and the OS entropy numpy draws at import is seeded + (``ir_workload.pin_os_entropy``). The real-data paths run at smaller sizes (``LOOPS``). - Code that observes its own wall-clock duration executes more instructions when it runs slower, so the measured process pins its main-thread clocks (``ir_workload.pin_main_thread_clocks``). Pinned clocks never let the metrics collector's 5 s mode check fire, so the collector stays @@ -20,8 +22,9 @@ cache is warmed first, and the heap layout is sampled (``ir_workload.run_workload``, ``measure`` and ``LAYOUTS``). -Two full runs agree within 0.08% per op (0.01% on 3.12; byte_storage_store_40b within 0.22%), against a -1% fail threshold. +Repeated runs agree within 0.04% per op (20 runs of serializer_orjson within 0.004%), against a 1% fail +threshold. The Arrow round trips and file_set keep noise from outside the measured process's control, up +to 0.25% in one layout (docs/performance.md). The measured process is ``ir_workload.py``. Its text is compiled into every measured run, so editing it moves the heap layout the budgets were recorded at; this gate is kept out of that @@ -72,13 +75,6 @@ # 3000 would take hours under callgrind. Fewer ops still cancel startup: it is a few hundred # thousand Ir of run-to-run spread against a difference of over a billion. LOOPS = dict.fromkeys(("serializer_arrow_usgs", "serializer_auto_usgs"), (5, 10, 30)) # path: (warmup, n_lo, n_hi) -# The cheapest paths run longer. Startup does not cancel exactly: importing pandas loads pyarrow's -# jemalloc, which starts a background thread, and depending on how that thread is scheduled against -# the main thread a run starts in one of two states, whose totals differ by up to about 1.2M Ir (with -# the thread turned off, by under 5,000). Over 2,000 calls of a 2,600 Ir path that is up to 13% in one -# layout, and such layouts moved byte_storage_store_40b's median by up to 8.4% in 8 of 80 gate runs. -# Over 299,000 calls its figure held within 0.22% in 40 runs. -LOOPS |= dict.fromkeys(("l1_hit", "minimal_l1_hit", "byte_storage_store_40b"), (WARMUP, N_LO, 300_000)) # Heap layout moves per-op counts: the allocators take shorter or longer paths in some heap # states. Any code change shifts the layout, even an edit to ir_workload.py's comments, so a single # run can fail an untouched path or hide a real regression. Each path runs at these layout shifts @@ -88,11 +84,6 @@ LAYOUTS = (0, 48, 80, 336, 880) FAIL_PCT = 1.0 # regression at or above this fails the gate WARN_PCT = 0.2 # above the A/A floor: report but pass -# The exception: the orjson round trip's 1 KB output buffer goes to glibc malloc, whose path length -# depends on heap state that no layout sample pins (longer warmups did not settle it). Its figure -# moves by more than the 1% threshold between unrelated changes, so it is gated at what this -# harness resolves for it. -TOLERANCE_PCT = {"serializer_orjson": (2.0, 1.0)} # path: (fail, warn) # Callgrind runs at a time by default. Each path peaks at 0.5 to 1.0 GiB per run (the L2, miss and # secure paths at the top), so the default stays small enough to share the machine with other work # rather than growing with its core count; --jobs overrides it. A workload that grows under callgrind @@ -347,12 +338,11 @@ def judge(budgets: dict[str, int], measured: dict[str, int]) -> list[dict[str, o rows.append({"path": path, "verdict": "FAIL", "ir": ir, "budget": None, "pct": None}) continue pct = (ir - budget) / budget * 100 - fail_pct, warn_pct = TOLERANCE_PCT.get(path, (FAIL_PCT, WARN_PCT)) - if pct >= fail_pct: + if pct >= FAIL_PCT: verdict = "FAIL" - elif pct >= warn_pct: + elif pct >= WARN_PCT: verdict = "WARN" - elif pct <= -fail_pct: + elif pct <= -FAIL_PCT: verdict = "LOWER" # cheaper: ratchet it down with --update if the change touched this path else: verdict = "ok" diff --git a/tests/performance/ir_report.py b/tests/performance/ir_report.py index c0cb620d..dcfe8dbe 100644 --- a/tests/performance/ir_report.py +++ b/tests/performance/ir_report.py @@ -89,7 +89,7 @@ def current(k: int) -> dict | None: out.append(f"| {verdict} | `{row['path']}` | {_figure(row.get('ir'))} | {_figure(row.get('budget'))} | {pct} |") out += [ "", - "A path fails at +1% or more against the base (+2% for `serializer_orjson`). This check is not required: " + "A path fails at +1% or more against the base. This check is not required: " "a deliberate cost increase is accepted at merge. Method: `docs/performance.md`, *Instruction budgets*.", ] return "\n".join(out) + "\n" diff --git a/tests/unit/test_ir_budget.py b/tests/unit/test_ir_budget.py index 6a60cc2d..28fe8390 100644 --- a/tests/unit/test_ir_budget.py +++ b/tests/unit/test_ir_budget.py @@ -51,18 +51,9 @@ def test_main_thread_ir_without_totals_raises(tmp_path) -> None: (99_000, "LOWER", True), ], ) -def test_compare_thresholds(measured: int, verdict: str, ok: bool) -> None: - lines, passed = compare({"l1_hit": 100_000}, {"l1_hit": measured}) - assert lines[0].split()[0] == verdict - assert passed is ok - - -@pytest.mark.parametrize( - ("measured", "verdict", "ok"), - [(100_999, "ok", True), (101_000, "WARN", True), (101_999, "WARN", True), (102_000, "FAIL", False), (98_000, "LOWER", True)], -) -def test_compare_gates_orjson_at_its_own_tolerance(measured: int, verdict: str, ok: bool) -> None: - lines, passed = compare({"serializer_orjson": 100_000}, {"serializer_orjson": measured}) +@pytest.mark.parametrize("path", ["l1_hit", "serializer_orjson"]) # orjson had a 2% exception until its noise was fixed +def test_compare_thresholds(path: str, measured: int, verdict: str, ok: bool) -> None: + lines, passed = compare({path: 100_000}, {path: measured}) assert lines[0].split()[0] == verdict assert passed is ok diff --git a/tests/unit/test_ir_report.py b/tests/unit/test_ir_report.py index 503b68e3..d5045cac 100644 --- a/tests/unit/test_ir_report.py +++ b/tests/unit/test_ir_report.py @@ -144,9 +144,7 @@ def test_a_report_ir_budget_did_not_write_is_no_report(tmp_path, text: str) -> N def test_the_footnote_states_the_gate_thresholds() -> None: body = render(_all_ok(), 4, JOBS, "aaa", "bbb", RUN) - assert f"+{ir_budget.FAIL_PCT:g}% or more" in body - assert set(ir_budget.TOLERANCE_PCT) == {"serializer_orjson"} # the footnote names no other exception - assert f"(+{ir_budget.TOLERANCE_PCT['serializer_orjson'][0]:g}% for `serializer_orjson`)" in body + assert f"+{ir_budget.FAIL_PCT:g}% or more against the base." in body # one threshold, no per-path exception def test_ci_names_the_marker_and_the_shard_jobs() -> None: From 112ee71edafcae1d6e8178e909b8af4dea79530b Mon Sep 17 00:00:00 2001 From: Ray Walker Date: Sun, 1 Nov 2026 15:24:13 +0000 Subject: [PATCH 3/6] perf(ir): re-record every budget on the reference machine under the new measured env --- docs/performance.md | 57 +++++++++++----------- tests/performance/ir_baselines.json | 74 ++++++++++++++--------------- 2 files changed, 66 insertions(+), 65 deletions(-) diff --git a/docs/performance.md b/docs/performance.md index 8ec28060..bae8ab62 100644 --- a/docs/performance.md +++ b/docs/performance.md @@ -302,13 +302,14 @@ The regression gate is the instruction budget: `make perf-ir` on your machine, a ## Instruction Budgets -`make perf-ir` counts the instructions each hot path executes per call and fails when a path costs **1% or more** above its committed budget. It warns from 0.2%. The orjson round trip fails at 2% and warns from 1% (see Limits). Instruction counts are deterministic where wall clock is not: two full runs agree within 0.08% per path (0.01% on CPython 3.12), and `byte_storage_store_40b` within 0.22% (see Method). +`make perf-ir` counts the instructions each hot path executes per call and fails when a path costs **1% or more** above its committed budget. It warns from 0.2%. Instruction counts are deterministic where wall clock is not: in repeated runs on one machine, every path but four held its figure within 0.04%, and the orjson round trip within 0.004% over 20 runs. The Arrow round trips and `file_set` keep up to 0.25% of noise in one layout's figure (see Method). **Method** (`tests/performance/ir_budget.py`; the measured process is `ir_workload.py`): - Each path runs under `valgrind --tool=callgrind --separate-threads=yes`, and only the main thread is counted. cachekit's background threads (L1 cleanup) vary by tens of percent between identical runs. -- Per-call cost is `(Ir[3000 calls] - Ir[1000 calls]) / 2000`, so interpreter startup (~2 billion instructions) and warmup cancel. Interpreter teardown is skipped. The two real-data paths cost about 60 million instructions per call, so they run 10 and 30 calls after 5 warmup calls; startup still cancels, and two runs agreed within 0.03%. The three paths that cost about 2,600 instructions per call (`l1_hit`, `minimal_l1_hit`, `byte_storage_store_40b`) run 1,000 and 300,000 calls, because startup cancels only to within about a million instructions (next item). -- Startup lands in one of two states. Every measured process imports pandas, which loads pyarrow, and pyarrow's bundled jemalloc starts a background thread. How that thread is scheduled against the main thread decides which state a run starts in, and the two states' totals differ by 0.1 to 1.2 million instructions, by a different amount at each layout and loop size. Each run is a coin flip, on an idle machine as on a loaded one. With the thread turned off (`JE_ARROW_MALLOC_CONF=background_thread:false`) there is one state: 16 runs agreed within 4,800 instructions. A layout whose two runs start in different states is off by up to 350 instructions per call over 2,000 calls. The median of five layouts hides that on most paths, but one layout of a 2,600-instruction path reads up to 13% off, and in 8 of 80 gate runs at 1,000 and 3,000 calls such layouts moved `byte_storage_store_40b`'s figure by 4.2% to 8.4% (2,434 to 2,912 overall). Over 299,000 calls the shift is a few instructions per call: in 20 gate runs each on a loaded machine, its figure stayed within 2,656 to 2,658 (0.08%) on a build with cachekit-core 0.7.2 and 2,690 to 2,696 (0.22%) with 0.7.4, and `l1_hit` and `minimal_l1_hit` did not move in 6 runs each. -- The measured process has a fixed environment (`PYTHONHASHSEED=0`, one BLAS/OpenMP thread, a one-day L1 cleanup interval, nothing inherited), seeded log sampling, and main-thread clocks that advance 1μs per read. Code that records its own duration otherwise executes more instructions when it runs slower. The cleanup sweep reads the real clock, so inside a run it would evict entries stamped with the pinned one. +- Per-call cost is `(Ir[3000 calls] - Ir[1000 calls]) / 2000`, so interpreter startup (~2 billion instructions) and warmup cancel. Interpreter teardown is skipped. The two real-data paths cost about 60 million instructions per call, so they run 10 and 30 calls after 5 warmup calls; startup still cancels. +- Startup cancels only if it costs the same in every run, and three things made it vary between identical runs. The measured process takes each out. Every run imports pandas, which loads pyarrow, and pyarrow's bundled jemalloc starts a background thread: how that thread was scheduled against the main thread put a run in one of two startup states. The environment turns the thread off (`JE_ARROW_MALLOC_CONF=background_thread:false,dirty_decay_ms:-1,muzzy_decay_ms:-1`, so that jemalloc never purges on a real-time deadline in its place). pyarrow allocates from mimalloc by default, which purges freed memory after a real-time delay that the freeing thread checks, 10 clock reads per real-data round trip; `MIMALLOC_PURGE_DELAY=-1` stops it purging. Importing pandas also imports `numpy.random`, which seeds its global generator from OS entropy, and the value drawn moves the heap layout everything after it runs in (about 57,000 instructions of spread on CPython 3.14). The workload gives Python code a seeded entropy stream before it imports pandas (`ir_workload.pin_os_entropy`). With all three, 16 runs per path at one layout agree within 3,500 instructions at each loop size, on CPython 3.12 and 3.14, where the previous setup spread the same runs by up to 5 million. That moved one layout's figure by up to 15% on a 2,600-instruction path and 3% on `object_cache_put_full`. +- Four paths keep noise this setup does not reach. The three Arrow round trips (`serializer_arrow` and the two real-data paths) run part of each call on pyarrow's thread pool, and how that work interleaves with the main thread's allocations moves the main thread's count by 0.5 to 2.8 million instructions per run, growing with the number of calls, with or without these settings: up to 0.1% of one layout's figure for `serializer_arrow` and 0.25% for the real-data paths. `file_set`'s startup still varies by up to 126,000 instructions, from a source not identified: up to 0.15% of one layout's figure. All four sit well inside the 1% threshold. +- The measured process has a fixed environment (`PYTHONHASHSEED=0`, one BLAS/OpenMP thread, a one-day L1 cleanup interval, pyarrow's allocators set as above, nothing inherited), seeded log sampling and OS entropy, and main-thread clocks that advance 1μs per read. Code that records its own duration otherwise executes more instructions when it runs slower. The cleanup sweep reads the real clock, so inside a run it would evict entries stamped with the pinned one. - Nothing that runs on real time lands in the measured loop: no background thread wakes, cyclic GC is off, and the GIL switch interval is long enough that the main thread gives up the GIL only where the code releases it. - Each path runs at five heap layouts (0 to 880 extra objects held before the workload) and its figure is the median. Any code change moves the layout, and the allocators take shorter or longer paths in some heap states: single layouts of the orjson round trip and the minimal L1 hit sat up to 2.4% from the rest. The median ignores one or two such layouts. The cheapest layout is not used, because a lucky one can sit 1% below the rest, and a budget recorded there makes every later run look like a regression. - `ir_workload.py`'s text is compiled into every measured process, so editing it moves the layout the budgets were recorded at: re-record after any change to it. The gate itself (`ir_budget.py`) is kept out of the measured process, so editing it does not move a budget. @@ -319,34 +320,34 @@ The regression gate is the instruction budget: `make perf-ir` on your machine, a | Path | What one call does | CPython 3.12 | CPython 3.14 | |------|--------------------|-------------:|-------------:| -| `l1_hit` | `@cache(backend=None)` L1 hit | 2,595 | 2,487 | -| `l1_hit_backed` | `@cache` with a backend configured, L1 hit (never reaches the in-process dict backend; decodes the verified MessagePack L1 holds after the first hit) | 83,015 | 83,882 | -| `minimal_l1_hit` | `@cache.minimal(backend=None)` L1 hit | 2,595 | 2,487 | -| `l2_hit` | `@cache`, L1 disabled, L2 hit, as one in-process single-flight trip | 172,539 | 167,686 | -| `miss` | `@cache`, L1 disabled, L2 miss, compute, L2 write, all as one in-process single-flight trip | 213,364 | 204,897 | -| `secure_l1_hit` | `@cache.secure` L1 hit (builds its key, decrypts the ciphertext L1 holds) | 134,323 | 134,972 | -| `l2_hit_async_metrics` | `l2_hit` with the metrics collector in batched mode | 171,976 | 167,728 | -| `serializer_default` | `StandardSerializer` round trip, small dict | 58,733 | 59,574 | -| `serializer_default_records` | `StandardSerializer` round trip, list of 100 six-field records (dict-heavy decode) | 1,420,388 | 1,424,292 | -| `serializer_auto` | `AutoSerializer` round trip | 65,942 | 66,628 | -| `serializer_orjson` | `OrjsonSerializer` round trip | 22,135 | 22,825 | -| `serializer_arrow` | `ArrowSerializer` round trip, 100-row DataFrame | 1,969,626 | 1,980,777 | -| `serializer_arrow_usgs` | `ArrowSerializer` round trip, real 12,535-row DataFrame (see Real data below) | 61,781,406 | 61,324,948 | -| `serializer_auto_usgs` | `AutoSerializer` round trip, same frame (it hands the frame to Arrow) | 61,793,577 | 61,344,459 | -| `serializer_encrypted` | `EncryptionWrapper` encrypt + decrypt round trip | 100,097 | 101,938 | -| `byte_storage_store_40b` | `ByteStorage.store()` alone, 40-byte compressible input (under cachekit-core's 64-byte literals-only LZ4 threshold) | 2,656 | 2,532 | -| `byte_storage_store_64k` | `ByteStorage.store()` alone, 64 KiB of address-like text | 720,631 | 720,751 | -| `file_set` | `FileBackend.set()` overwriting one key in a 1,000-entry cache (no eviction) | 76,035 | 74,112 | -| `object_cache_put_full` | `ObjectCache.put()` of a new key into a full 10,000-entry byte budget (evicts the LRU entry; nothing expired) | 165,014 | 160,608 | - -Budgets are per interpreter (minor version, build flavour, machine); an interpreter without budgets fails with `no budget`. They were recorded on CPython 3.12.12 and 3.14.3, x86_64, glibc 2.39, with the release extension that `uv sync` builds. Counts depend on that whole build, so on a different interpreter, extension or C library, record a baseline on `main` first (`--update --allow-increase`) and compare your branch against it. `l2_hit` and `l2_hit_async_metrics` now cost the same within 0.4%: a cache operation records into per-thread cells in either mode. Against the previous budgets that is 14,700 to 16,600 fewer instructions per L2 hit than the synchronous Prometheus update, and 5,400 to 7,500 fewer than queueing the record for the batching worker. +| `l1_hit` | `@cache(backend=None)` L1 hit | 2,599 | 2,487 | +| `l1_hit_backed` | `@cache` with a backend configured, L1 hit (never reaches the in-process dict backend; decodes the verified MessagePack L1 holds after the first hit) | 79,894 | 80,686 | +| `minimal_l1_hit` | `@cache.minimal(backend=None)` L1 hit | 2,597 | 2,487 | +| `l2_hit` | `@cache`, L1 disabled, L2 hit, as one in-process single-flight trip | 162,021 | 157,412 | +| `miss` | `@cache`, L1 disabled, L2 miss, compute, L2 write, all as one in-process single-flight trip | 213,413 | 204,732 | +| `secure_l1_hit` | `@cache.secure` L1 hit (builds its key, decrypts the ciphertext L1 holds) | 124,415 | 124,984 | +| `l2_hit_async_metrics` | `l2_hit` with the metrics collector in batched mode | 162,133 | 157,756 | +| `serializer_default` | `StandardSerializer` round trip, small dict | 48,690 | 49,391 | +| `serializer_default_records` | `StandardSerializer` round trip, list of 100 six-field records (dict-heavy decode) | 1,010,819 | 1,005,020 | +| `serializer_auto` | `AutoSerializer` round trip | 65,790 | 66,414 | +| `serializer_orjson` | `OrjsonSerializer` round trip | 22,020 | 22,604 | +| `serializer_arrow` | `ArrowSerializer` round trip, 100-row DataFrame | 1,968,690 | 1,980,455 | +| `serializer_arrow_usgs` | `ArrowSerializer` round trip, real 12,535-row DataFrame (see Real data below) | 61,761,752 | 61,299,396 | +| `serializer_auto_usgs` | `AutoSerializer` round trip, same frame (it hands the frame to Arrow) | 61,753,246 | 61,306,554 | +| `serializer_encrypted` | `EncryptionWrapper` encrypt + decrypt round trip | 89,945 | 91,672 | +| `byte_storage_store_40b` | `ByteStorage.store()` alone, 40-byte compressible input (under cachekit-core's 64-byte literals-only LZ4 threshold) | 2,652 | 2,526 | +| `byte_storage_store_64k` | `ByteStorage.store()` alone, 64 KiB of address-like text | 720,546 | 720,662 | +| `file_set` | `FileBackend.set()` overwriting one key in a 1,000-entry cache (no eviction) | 75,692 | 73,653 | +| `object_cache_put_full` | `ObjectCache.put()` of a new key into a full 10,000-entry byte budget (evicts the LRU entry; nothing expired) | 164,701 | 160,621 | + +Budgets are per interpreter (minor version, build flavour, machine); an interpreter without budgets fails with `no budget`. Every committed budget comes from one reference machine, where all of them were last re-recorded together: x86_64, Ubuntu 24.04, glibc 2.39, valgrind 3.22.0, CPython 3.12.12 and 3.14.3 (uv's builds), the release extension that `uv sync` builds, and the dependencies in `uv.lock`. On that machine a gate run reproduces them with no `FAIL` and no `LOWER`. Counts depend on that whole build, so on any other machine, record a baseline on `main` first (`--update --allow-increase`) and compare your branch against it. `l2_hit` and `l2_hit_async_metrics` now cost the same within 0.4%: a cache operation records into per-thread cells in either mode. Against the previous budgets that is 14,700 to 16,600 fewer instructions per L2 hit than the synchronous Prometheus update, and 5,400 to 7,500 fewer than queueing the record for the batching worker. **Sensitivity:** before the key memo, one extra BLAKE2b hash of the cache key per call raised every key-generating path by 4,700 to 4,900 instructions (`l1_hit` +6.1%, `l2_hit_async_metrics` +1.5%, `miss` +1.4%) and failed the gate, while the serializer paths, which generate no key, stayed within 0.11%. An interleaved wall-clock run agreed in sign (+286ns per L1 hit, median of 12 paired processes). -**Limits:** instruction counts do not weight cache misses or branch mispredictions. A claimed speed-up still needs an interleaved wall-clock comparison; the instruction count only guarantees the work did not grow. Paths that wait on a network backend are not covered. Cyclic-GC cost is outside the budgets; allocation and reference counting are inside. A Prometheus scrape, which sums each thread's cache-operation cells, runs outside the measured calls and is not budgeted. Part of pyarrow's work on the real-data paths is not budgeted either: about half of their instructions run on pyarrow's threads. The orjson round trip's 1 KB output buffer comes from glibc malloc, whose path length depends on heap state that no layout sample pins, so its figure moved 1.3% between unrelated changes; it is gated at 2%. Unrelated changes can still move another path's figure by up to 0.6% (a `WARN`), and a `LOWER` verdict on a path the change did not touch is a layout shift, not a saving: ratchet only the paths the change touched (`--update --path `). A change to the Rust extension moves the paths that run through it more, with no change in their work: `main`'s own source, built with and without symbol stripping, moved the `ByteStorage` round trip of `serializer_default` by 1.9%, while every function in it cost the same over 5,000 round trips, so the move is a one-time allocator event that the binary's layout puts inside one loop size. After an extension change, re-record the serializer paths that fail (`--update --allow-increase --path `) and say why in the PR. +**Limits:** instruction counts do not weight cache misses or branch mispredictions. A claimed speed-up still needs an interleaved wall-clock comparison; the instruction count only guarantees the work did not grow. Paths that wait on a network backend are not covered. Cyclic-GC cost is outside the budgets; allocation and reference counting are inside. A Prometheus scrape, which sums each thread's cache-operation cells, runs outside the measured calls and is not budgeted. Part of pyarrow's work on the real-data paths is not budgeted either: about half of their instructions run on pyarrow's threads. The orjson round trip used to be gated at 2%, because its figure moved 1.3% between unrelated changes; the startup noise in Method was the cause. It now holds within 0.004% over 20 runs, and eight copies of `ir_workload.py` that differ only in a comment's length gave it the same figure, so it is gated at 1% like every other path. Unrelated changes can still move a path's figure by up to 0.6% (a `WARN`), and a `LOWER` verdict on a path the change did not touch is a layout shift, not a saving: ratchet only the paths the change touched (`--update --path `). A change to the Rust extension moves the paths that run through it more, with no change in their work: `main`'s own source, built with and without symbol stripping, moved the `ByteStorage` round trip of `serializer_default` by 1.9%, while every function in it cost the same over 5,000 round trips, so the move is a one-time allocator event that the binary's layout puts inside one loop size. After an extension change, re-record the serializer paths that fail (`--update --allow-increase --path `) and say why in the PR. ```bash -make perf-ir # gate: fail on a >=1% per-call regression (orjson 2%; needs valgrind; 190 runs, several minutes) +make perf-ir # gate: fail on a >=1% per-call regression (needs valgrind; 190 runs, several minutes) make perf-ir-update # ratchet: write lower measured figures back as budgets, never higher ``` @@ -368,7 +369,7 @@ uv run python tests/performance/ir_budget.py --path serializer_arrow_usgs --path ### In CI -Every pull request runs the gate in the `Instruction budget (shard K/4)` jobs of `.github/workflows/ci.yml`, on GitHub-hosted `ubuntu-latest` runners with CPython 3.12. They do not compare against the committed budgets: those belong to the machine and interpreter build that recorded them, and a CPython 3.12 patch release alone read 2.0% to 3.6% over them with no code change. Instead each job builds two checkouts side by side, the pull request (its merge commit) and its base (the base branch tip), measures both on the same runner, and fails when a path costs 1% or more above the base (2% for the orjson round trip). That is `ir_budget.py --base DIR`, which never writes the committed budgets; CI adds `--report FILE`, which writes the verdict and every path's figures as JSON. +Every pull request runs the gate in the `Instruction budget (shard K/4)` jobs of `.github/workflows/ci.yml`, on GitHub-hosted `ubuntu-latest` runners with CPython 3.12. They do not compare against the committed budgets: those belong to the machine and interpreter build that recorded them, and a CPython 3.12 patch release alone read 2.0% to 3.6% over them with no code change. Instead each job builds two checkouts side by side, the pull request (its merge commit) and its base (the base branch tip), measures both on the same runner, and fails when a path costs 1% or more above the base. That is `ir_budget.py --base DIR`, which never writes the committed budgets; CI adds `--report FILE`, which writes the verdict and every path's figures as JSON. - A release-please pull request (head branch `release-please--*`) is measured against the last release instead: the tag `v`, where `` is the `"."` entry of the base's `.release-please-manifest.json`. That pull request is rebased onto `main` on every push, so against `main` it would measure nothing but a version bump. Against the tag, the comment shows each path's cumulative drift since the previous release, including the increases accepted one pull request at a time, and paths added since then show as `new`. A tag that cannot be fetched fails the job; it never falls back to `main`. The `Instruction budget base` job picks the base once per workflow run with `.github/scripts/perf-ir-base.sh`, and the shards and the comment both use its result, so a re-run shard or a tag moved mid-run cannot make the comment name a base the shards did not measure. - Both checkouts must sit at absolute paths of the same length, and the gate refuses a base that does not. The measured process's argv and import paths move its heap layout: a relative workload path against an absolute one read `l1_hit` 0.3% apart on identical source; at equal-length absolute paths the same pair agreed within 0.01%. diff --git a/tests/performance/ir_baselines.json b/tests/performance/ir_baselines.json index 3a08d4b7..a587cace 100644 --- a/tests/performance/ir_baselines.json +++ b/tests/performance/ir_baselines.json @@ -2,52 +2,52 @@ "interpreters": { "cpython-3.12-x86_64": { "budgets": { - "byte_storage_store_40b": 2656, - "byte_storage_store_64k": 720631, - "file_set": 76035, - "l1_hit": 2595, - "l1_hit_backed": 83015, - "l2_hit": 172539, - "l2_hit_async_metrics": 171976, - "minimal_l1_hit": 2595, - "miss": 213364, - "object_cache_put_full": 165014, - "secure_l1_hit": 134323, - "serializer_arrow": 1969626, - "serializer_arrow_usgs": 61781406, - "serializer_auto": 65942, - "serializer_auto_usgs": 61793577, - "serializer_default": 58733, - "serializer_default_records": 1420388, - "serializer_encrypted": 100097, - "serializer_orjson": 22135 + "byte_storage_store_40b": 2652, + "byte_storage_store_64k": 720546, + "file_set": 75692, + "l1_hit": 2599, + "l1_hit_backed": 79894, + "l2_hit": 162021, + "l2_hit_async_metrics": 162133, + "minimal_l1_hit": 2597, + "miss": 213413, + "object_cache_put_full": 164701, + "secure_l1_hit": 124415, + "serializer_arrow": 1968690, + "serializer_arrow_usgs": 61761752, + "serializer_auto": 65790, + "serializer_auto_usgs": 61753246, + "serializer_default": 48690, + "serializer_default_records": 1010819, + "serializer_encrypted": 89945, + "serializer_orjson": 22020 }, "python": "3.12.12" }, "cpython-3.14-x86_64": { "budgets": { - "byte_storage_store_40b": 2532, - "byte_storage_store_64k": 720751, - "file_set": 74112, + "byte_storage_store_40b": 2526, + "byte_storage_store_64k": 720662, + "file_set": 73653, "l1_hit": 2487, - "l1_hit_backed": 83882, - "l2_hit": 167686, - "l2_hit_async_metrics": 167728, + "l1_hit_backed": 80686, + "l2_hit": 157412, + "l2_hit_async_metrics": 157756, "minimal_l1_hit": 2487, - "miss": 204897, - "object_cache_put_full": 160608, - "secure_l1_hit": 134972, - "serializer_arrow": 1980777, - "serializer_arrow_usgs": 61324948, - "serializer_auto": 66628, - "serializer_auto_usgs": 61344459, - "serializer_default": 59574, - "serializer_default_records": 1424292, - "serializer_encrypted": 101938, - "serializer_orjson": 22825 + "miss": 204732, + "object_cache_put_full": 160621, + "secure_l1_hit": 124984, + "serializer_arrow": 1980455, + "serializer_arrow_usgs": 61299396, + "serializer_auto": 66414, + "serializer_auto_usgs": 61306554, + "serializer_default": 49391, + "serializer_default_records": 1005020, + "serializer_encrypted": 91672, + "serializer_orjson": 22604 }, "python": "3.14.3" } }, - "method": "main-thread callgrind Ir per op, (Ir[3000] - Ir[1000]) / 2000, fixed env (PYTHONHASHSEED=0, one BLAS/OMP thread), pinned clocks; written by tests/performance/ir_budget.py --update" + "method": "main-thread callgrind Ir per op, (Ir[3000] - Ir[1000]) / 2000 ((Ir[30] - Ir[10]) / 20 on the two *_usgs paths), median of five heap layouts, fixed env (PYTHONHASHSEED=0, one BLAS/OMP thread, pyarrow's jemalloc without its background thread, neither of pyarrow's allocators purging), pinned clocks and OS entropy; written by tests/performance/ir_budget.py --update" } From a3d9b15dd7edaf0c60fe8e6af0709070b7dfc043 Mon Sep 17 00:00:00 2001 From: Ray Walker Date: Sun, 1 Nov 2026 15:56:33 +0000 Subject: [PATCH 4/6] perf(ir): skip the numpy entropy test without numpy, trim the gate docs to what the gate runs --- docs/performance.md | 8 ++++---- tests/performance/README.md | 3 +-- tests/performance/ir_budget.py | 9 ++++----- tests/unit/test_ir_budget.py | 6 +++--- 4 files changed, 12 insertions(+), 14 deletions(-) diff --git a/docs/performance.md b/docs/performance.md index bae8ab62..8b428fb4 100644 --- a/docs/performance.md +++ b/docs/performance.md @@ -302,12 +302,12 @@ The regression gate is the instruction budget: `make perf-ir` on your machine, a ## Instruction Budgets -`make perf-ir` counts the instructions each hot path executes per call and fails when a path costs **1% or more** above its committed budget. It warns from 0.2%. Instruction counts are deterministic where wall clock is not: in repeated runs on one machine, every path but four held its figure within 0.04%, and the orjson round trip within 0.004% over 20 runs. The Arrow round trips and `file_set` keep up to 0.25% of noise in one layout's figure (see Method). +`make perf-ir` counts the instructions each hot path executes per call and fails when a path costs **1% or more** above its committed budget. It warns from 0.2%. Instruction counts are deterministic where wall clock is not: in repeated runs on one machine, every path but four held its figure within 0.04%; the Arrow round trips and `file_set` keep up to 0.25% of noise in one layout's figure (see Method). **Method** (`tests/performance/ir_budget.py`; the measured process is `ir_workload.py`): - Each path runs under `valgrind --tool=callgrind --separate-threads=yes`, and only the main thread is counted. cachekit's background threads (L1 cleanup) vary by tens of percent between identical runs. - Per-call cost is `(Ir[3000 calls] - Ir[1000 calls]) / 2000`, so interpreter startup (~2 billion instructions) and warmup cancel. Interpreter teardown is skipped. The two real-data paths cost about 60 million instructions per call, so they run 10 and 30 calls after 5 warmup calls; startup still cancels. -- Startup cancels only if it costs the same in every run, and three things made it vary between identical runs. The measured process takes each out. Every run imports pandas, which loads pyarrow, and pyarrow's bundled jemalloc starts a background thread: how that thread was scheduled against the main thread put a run in one of two startup states. The environment turns the thread off (`JE_ARROW_MALLOC_CONF=background_thread:false,dirty_decay_ms:-1,muzzy_decay_ms:-1`, so that jemalloc never purges on a real-time deadline in its place). pyarrow allocates from mimalloc by default, which purges freed memory after a real-time delay that the freeing thread checks, 10 clock reads per real-data round trip; `MIMALLOC_PURGE_DELAY=-1` stops it purging. Importing pandas also imports `numpy.random`, which seeds its global generator from OS entropy, and the value drawn moves the heap layout everything after it runs in (about 57,000 instructions of spread on CPython 3.14). The workload gives Python code a seeded entropy stream before it imports pandas (`ir_workload.pin_os_entropy`). With all three, 16 runs per path at one layout agree within 3,500 instructions at each loop size, on CPython 3.12 and 3.14, where the previous setup spread the same runs by up to 5 million. That moved one layout's figure by up to 15% on a 2,600-instruction path and 3% on `object_cache_put_full`. +- Startup cancels only if it costs the same in every run. Three things made it vary, and the measured process takes each out. pyarrow's bundled jemalloc starts a background thread at import, and how it was scheduled against the main thread put a run in one of two startup states: `JE_ARROW_MALLOC_CONF=background_thread:false,dirty_decay_ms:-1,muzzy_decay_ms:-1` turns it off without moving its real-time purging onto the main thread. pyarrow's default allocator, mimalloc, purges freed memory after a real-time delay that the freeing thread checks: `MIMALLOC_PURGE_DELAY=-1`. `numpy.random`, which pandas imports, seeds its global generator from OS entropy, and the value drawn moves the heap layout: `ir_workload.pin_os_entropy` seeds Python's OS entropy first. With all three, 16 runs at one layout agree within 3,500 instructions at each loop size on 15 of the 19 paths, on CPython 3.12 and 3.14. The previous setup spread the same runs by up to 5 million, which moved one layout's figure by up to 15% on a 2,600-instruction path. - Four paths keep noise this setup does not reach. The three Arrow round trips (`serializer_arrow` and the two real-data paths) run part of each call on pyarrow's thread pool, and how that work interleaves with the main thread's allocations moves the main thread's count by 0.5 to 2.8 million instructions per run, growing with the number of calls, with or without these settings: up to 0.1% of one layout's figure for `serializer_arrow` and 0.25% for the real-data paths. `file_set`'s startup still varies by up to 126,000 instructions, from a source not identified: up to 0.15% of one layout's figure. All four sit well inside the 1% threshold. - The measured process has a fixed environment (`PYTHONHASHSEED=0`, one BLAS/OpenMP thread, a one-day L1 cleanup interval, pyarrow's allocators set as above, nothing inherited), seeded log sampling and OS entropy, and main-thread clocks that advance 1μs per read. Code that records its own duration otherwise executes more instructions when it runs slower. The cleanup sweep reads the real clock, so inside a run it would evict entries stamped with the pinned one. - Nothing that runs on real time lands in the measured loop: no background thread wakes, cyclic GC is off, and the GIL switch interval is long enough that the main thread gives up the GIL only where the code releases it. @@ -340,11 +340,11 @@ The regression gate is the instruction budget: `make perf-ir` on your machine, a | `file_set` | `FileBackend.set()` overwriting one key in a 1,000-entry cache (no eviction) | 75,692 | 73,653 | | `object_cache_put_full` | `ObjectCache.put()` of a new key into a full 10,000-entry byte budget (evicts the LRU entry; nothing expired) | 164,701 | 160,621 | -Budgets are per interpreter (minor version, build flavour, machine); an interpreter without budgets fails with `no budget`. Every committed budget comes from one reference machine, where all of them were last re-recorded together: x86_64, Ubuntu 24.04, glibc 2.39, valgrind 3.22.0, CPython 3.12.12 and 3.14.3 (uv's builds), the release extension that `uv sync` builds, and the dependencies in `uv.lock`. On that machine a gate run reproduces them with no `FAIL` and no `LOWER`. Counts depend on that whole build, so on any other machine, record a baseline on `main` first (`--update --allow-increase`) and compare your branch against it. `l2_hit` and `l2_hit_async_metrics` now cost the same within 0.4%: a cache operation records into per-thread cells in either mode. Against the previous budgets that is 14,700 to 16,600 fewer instructions per L2 hit than the synchronous Prometheus update, and 5,400 to 7,500 fewer than queueing the record for the batching worker. +Budgets are per interpreter (minor version, build flavour, machine); an interpreter without budgets fails with `no budget`. Every committed budget comes from one reference machine: x86_64, Ubuntu 24.04, glibc 2.39, valgrind 3.22.0, CPython 3.12.12 and 3.14.3 (uv's builds), the release extension that `uv sync` builds, and the dependencies in `uv.lock`. Counts depend on that whole build, so on any other machine, record a baseline on `main` first (`--update --allow-increase`) and compare your branch against it. `l2_hit` and `l2_hit_async_metrics` cost the same within 0.4%: a cache operation records into per-thread cells in either mode. **Sensitivity:** before the key memo, one extra BLAKE2b hash of the cache key per call raised every key-generating path by 4,700 to 4,900 instructions (`l1_hit` +6.1%, `l2_hit_async_metrics` +1.5%, `miss` +1.4%) and failed the gate, while the serializer paths, which generate no key, stayed within 0.11%. An interleaved wall-clock run agreed in sign (+286ns per L1 hit, median of 12 paired processes). -**Limits:** instruction counts do not weight cache misses or branch mispredictions. A claimed speed-up still needs an interleaved wall-clock comparison; the instruction count only guarantees the work did not grow. Paths that wait on a network backend are not covered. Cyclic-GC cost is outside the budgets; allocation and reference counting are inside. A Prometheus scrape, which sums each thread's cache-operation cells, runs outside the measured calls and is not budgeted. Part of pyarrow's work on the real-data paths is not budgeted either: about half of their instructions run on pyarrow's threads. The orjson round trip used to be gated at 2%, because its figure moved 1.3% between unrelated changes; the startup noise in Method was the cause. It now holds within 0.004% over 20 runs, and eight copies of `ir_workload.py` that differ only in a comment's length gave it the same figure, so it is gated at 1% like every other path. Unrelated changes can still move a path's figure by up to 0.6% (a `WARN`), and a `LOWER` verdict on a path the change did not touch is a layout shift, not a saving: ratchet only the paths the change touched (`--update --path `). A change to the Rust extension moves the paths that run through it more, with no change in their work: `main`'s own source, built with and without symbol stripping, moved the `ByteStorage` round trip of `serializer_default` by 1.9%, while every function in it cost the same over 5,000 round trips, so the move is a one-time allocator event that the binary's layout puts inside one loop size. After an extension change, re-record the serializer paths that fail (`--update --allow-increase --path `) and say why in the PR. +**Limits:** instruction counts do not weight cache misses or branch mispredictions. A claimed speed-up still needs an interleaved wall-clock comparison; the instruction count only guarantees the work did not grow. Paths that wait on a network backend are not covered. Cyclic-GC cost is outside the budgets; allocation and reference counting are inside. A Prometheus scrape, which sums each thread's cache-operation cells, runs outside the measured calls and is not budgeted. Part of pyarrow's work on the real-data paths is not budgeted either: about half of their instructions run on pyarrow's threads. Unrelated changes can still move a path's figure by up to 0.6% (a `WARN`), and a `LOWER` verdict on a path the change did not touch is a layout shift, not a saving: ratchet only the paths the change touched (`--update --path `). A change to the Rust extension moves the paths that run through it more, with no change in their work: `main`'s own source, built with and without symbol stripping, moved the `ByteStorage` round trip of `serializer_default` by 1.9%, while every function in it cost the same over 5,000 round trips, so the move is a one-time allocator event that the binary's layout puts inside one loop size. After an extension change, re-record the serializer paths that fail (`--update --allow-increase --path `) and say why in the PR. ```bash make perf-ir # gate: fail on a >=1% per-call regression (needs valgrind; 190 runs, several minutes) diff --git a/tests/performance/README.md b/tests/performance/README.md index c8338c04..95bc9ab8 100644 --- a/tests/performance/README.md +++ b/tests/performance/README.md @@ -26,8 +26,7 @@ arms (manual; see [docs/free-threading.md](../../docs/free-threading.md#decorate Run the whole battery with `make perf`; gate regressions with `make perf-compare`. **Instruction budgets.** `ir_budget.py` (`make perf-ir`) is the deterministic gate: main-thread -callgrind instructions per call for each hot path, failing at +1% (the orjson round trip at +2%) -against `ir_baselines.json`. Budgets belong to the build that recorded them; on another +callgrind instructions per call for each hot path, failing at +1% against `ir_baselines.json`. Budgets belong to the build that recorded them; on another interpreter, extension or C library, record a baseline on `main` first. CI runs it on every PR with `--base`: the PR and its base are measured on the same runner and compared with each other, not with the committed budgets, and `ir_report.py` renders the shards' `--report` files as one PR diff --git a/tests/performance/ir_budget.py b/tests/performance/ir_budget.py index 563c6447..50665032 100644 --- a/tests/performance/ir_budget.py +++ b/tests/performance/ir_budget.py @@ -22,9 +22,8 @@ cache is warmed first, and the heap layout is sampled (``ir_workload.run_workload``, ``measure`` and ``LAYOUTS``). -Repeated runs agree within 0.04% per op (20 runs of serializer_orjson within 0.004%), against a 1% fail -threshold. The Arrow round trips and file_set keep noise from outside the measured process's control, up -to 0.25% in one layout (docs/performance.md). +Repeated runs agree within 0.04% per op, against a 1% fail threshold; the Arrow round trips and file_set +keep up to 0.25% in one layout (docs/performance.md). The measured process is ``ir_workload.py``. Its text is compiled into every measured run, so editing it moves the heap layout the budgets were recorded at; this gate is kept out of that @@ -72,8 +71,8 @@ N_LO, N_HI = 1000, 3000 WARMUP = 50 # The real-data paths cost about 60M main-thread Ir per op, 300 times a small path, so a run of -# 3000 would take hours under callgrind. Fewer ops still cancel startup: it is a few hundred -# thousand Ir of run-to-run spread against a difference of over a billion. +# 3000 would take hours under callgrind. Fewer ops still resolve them: pyarrow's thread pool moves a +# run by up to about 2M Ir, against a difference of over a billion. LOOPS = dict.fromkeys(("serializer_arrow_usgs", "serializer_auto_usgs"), (5, 10, 30)) # path: (warmup, n_lo, n_hi) # Heap layout moves per-op counts: the allocators take shorter or longer paths in some heap # states. Any code change shifts the layout, even an edit to ir_workload.py's comments, so a single diff --git a/tests/unit/test_ir_budget.py b/tests/unit/test_ir_budget.py index 28fe8390..ea7092e4 100644 --- a/tests/unit/test_ir_budget.py +++ b/tests/unit/test_ir_budget.py @@ -51,9 +51,8 @@ def test_main_thread_ir_without_totals_raises(tmp_path) -> None: (99_000, "LOWER", True), ], ) -@pytest.mark.parametrize("path", ["l1_hit", "serializer_orjson"]) # orjson had a 2% exception until its noise was fixed -def test_compare_thresholds(path: str, measured: int, verdict: str, ok: bool) -> None: - lines, passed = compare({path: 100_000}, {path: measured}) +def test_compare_thresholds(measured: int, verdict: str, ok: bool) -> None: + lines, passed = compare({"l1_hit": 100_000}, {"l1_hit": measured}) assert lines[0].split()[0] == verdict assert passed is ok @@ -504,6 +503,7 @@ def test_pinned_clocks_tick_per_read_on_the_main_thread_only(monkeypatch) -> Non def test_pinned_os_entropy_starts_numpy_in_the_same_state_in_every_run() -> None: """numpy.random seeds its global generator from OS entropy at import, which moved every path's count.""" + pytest.importorskip("numpy") # the free-threaded CI lanes install no numpy probe = ( "import sys; sys.path.insert(0, sys.argv[1]); import ir_workload\n" "if sys.argv[2] == 'pin': ir_workload.pin_os_entropy()\n" From 4f6472a472c4af1d1037885a3cba0c865c62dfc7 Mon Sep 17 00:00:00 2001 From: Ray Walker Date: Mon, 2 Nov 2026 00:41:41 +0000 Subject: [PATCH 5/6] perf(ir): re-record every budget on the merged tree, add l1_hit_backed_auto's residual, apply the review's wording fixes --- docs/performance.md | 48 +++++++++--------- tests/performance/README.md | 5 +- tests/performance/ir_baselines.json | 78 ++++++++++++++--------------- tests/performance/ir_budget.py | 15 +++--- 4 files changed, 74 insertions(+), 72 deletions(-) diff --git a/docs/performance.md b/docs/performance.md index a105c170..4c5fc241 100644 --- a/docs/performance.md +++ b/docs/performance.md @@ -302,13 +302,13 @@ The regression gate is the instruction budget: `make perf-ir` on your machine, a ## Instruction Budgets -`make perf-ir` counts the instructions each hot path executes per call and fails when a path costs **1% or more** above its committed budget. It warns from 0.2%. Instruction counts are deterministic where wall clock is not: in repeated runs on one machine, every path but four held its figure within 0.04%; the Arrow round trips and `file_set` keep up to 0.25% of noise in one layout's figure (see Method). +`make perf-ir` counts the instructions each hot path executes per call and fails when a path costs **1% or more** above its committed budget. It warns from 0.2%. Instruction counts are deterministic where wall clock is not: in repeated runs on one machine, every path but five held its figure within 0.04%; the Arrow round trips and `file_set` keep up to 0.25% of noise in one layout's figure, and `l1_hit_backed_auto` moved 0.16% once on CPython 3.12 (see Method). **Method** (`tests/performance/ir_budget.py`; the measured process is `ir_workload.py`): - Each path runs under `valgrind --tool=callgrind --separate-threads=yes`, and only the main thread is counted. cachekit's background threads (L1 cleanup) vary by tens of percent between identical runs. - Per-call cost is `(Ir[3000 calls] - Ir[1000 calls]) / 2000`, so interpreter startup (~2 billion instructions) and warmup cancel. Interpreter teardown is skipped. The two real-data paths cost about 60 million instructions per call, so they run 10 and 30 calls after 5 warmup calls; startup still cancels. -- Startup cancels only if it costs the same in every run. Three things made it vary, and the measured process takes each out. pyarrow's bundled jemalloc starts a background thread at import, and how it was scheduled against the main thread put a run in one of two startup states: `JE_ARROW_MALLOC_CONF=background_thread:false,dirty_decay_ms:-1,muzzy_decay_ms:-1` turns it off without moving its real-time purging onto the main thread. pyarrow's default allocator, mimalloc, purges freed memory after a real-time delay that the freeing thread checks: `MIMALLOC_PURGE_DELAY=-1`. `numpy.random`, which pandas imports, seeds its global generator from OS entropy, and the value drawn moves the heap layout: `ir_workload.pin_os_entropy` seeds Python's OS entropy first. With all three, 16 runs at one layout agree within 3,500 instructions at each loop size on 15 of the 19 paths, on CPython 3.12 and 3.14. The previous setup spread the same runs by up to 5 million, which moved one layout's figure by up to 15% on a 2,600-instruction path. -- Four paths keep noise this setup does not reach. The three Arrow round trips (`serializer_arrow` and the two real-data paths) run part of each call on pyarrow's thread pool, and how that work interleaves with the main thread's allocations moves the main thread's count by 0.5 to 2.8 million instructions per run, growing with the number of calls, with or without these settings: up to 0.1% of one layout's figure for `serializer_arrow` and 0.25% for the real-data paths. `file_set`'s startup still varies by up to 126,000 instructions, from a source not identified: up to 0.15% of one layout's figure. All four sit well inside the 1% threshold. +- Startup cancels only if it costs the same in every run. Three things made it vary, and the measured process takes each out. pyarrow's bundled jemalloc starts a background thread at import, and how it was scheduled against the main thread put a run in one of two startup states: `JE_ARROW_MALLOC_CONF=background_thread:false,dirty_decay_ms:-1,muzzy_decay_ms:-1` turns it off without moving its real-time purging onto the main thread. pyarrow's default allocator, mimalloc, purges freed memory after a real-time delay that the freeing thread checks: `MIMALLOC_PURGE_DELAY=-1`. `numpy.random`, which pandas imports, seeds its global generator from OS entropy, and the value drawn moves the heap layout: `ir_workload.pin_os_entropy` seeds Python's OS entropy first. With all three, 16 runs at one layout agree within 3,500 instructions at each loop size on 15 of the 20 paths on CPython 3.12, and on 16 of them on 3.14. +- Five paths keep noise this setup does not reach. The three Arrow round trips (`serializer_arrow` and the two real-data paths) run part of each call on pyarrow's thread pool, and how that work interleaves with the main thread's allocations moves the main thread's count by 0.5 to 2.8 million instructions per run, growing with the number of calls, with or without these settings: up to 0.1% of one layout's figure for `serializer_arrow` and 0.25% for the real-data paths. `file_set`'s startup still varies by up to 126,000 instructions, from a source not identified: up to 0.15% of one layout's figure. On CPython 3.12, `l1_hit_backed_auto`'s runs agreed within 3,900 instructions for 20 minutes at a time, but its per-call cost moved once, by 146 instructions (0.16%), between two runs that started seconds apart, and every later run kept the new cost. The move came as the machine's process IDs went from five digits to six. A process ID one digit longer makes a longer string wherever it is formatted, which can move the heap layout, but that cause is not confirmed. All five sit well inside the 1% threshold. - The measured process has a fixed environment (`PYTHONHASHSEED=0`, one BLAS/OpenMP thread, a one-day L1 cleanup interval, pyarrow's allocators set as above, nothing inherited), seeded log sampling and OS entropy, and main-thread clocks that advance 1μs per read. Code that records its own duration otherwise executes more instructions when it runs slower. The cleanup sweep reads the real clock, so inside a run it would evict entries stamped with the pinned one. - Nothing that runs on real time lands in the measured loop: no background thread wakes, cyclic GC is off, and the GIL switch interval is long enough that the main thread gives up the GIL only where the code releases it. - Each path runs at five heap layouts (0 to 880 extra objects held before the workload) and its figure is the median. Any code change moves the layout, and the allocators take shorter or longer paths in some heap states: single layouts of the orjson round trip and the minimal L1 hit sat up to 2.4% from the rest. The median ignores one or two such layouts. The cheapest layout is not used, because a lucky one can sit 1% below the rest, and a budget recorded there makes every later run look like a regression. @@ -320,26 +320,26 @@ The regression gate is the instruction budget: `make perf-ir` on your machine, a | Path | What one call does | CPython 3.12 | CPython 3.14 | |------|--------------------|-------------:|-------------:| -| `l1_hit` | `@cache(backend=None)` L1 hit | 2,595 | 2,487 | -| `l1_hit_backed` | `@cache` with a backend configured, L1 hit (never reaches the in-process dict backend; decodes the verified MessagePack L1 holds after the first hit) | 83,015 | 83,882 | -| `l1_hit_backed_auto` | `l1_hit_backed` with `serializer="auto"` (decodes the verified MessagePack the auto serializer keeps) | 91,986 | 92,950 | -| `minimal_l1_hit` | `@cache.minimal(backend=None)` L1 hit | 2,595 | 2,487 | -| `l2_hit` | `@cache`, L1 disabled, L2 hit, as one in-process single-flight trip | 172,539 | 167,686 | -| `miss` | `@cache`, L1 disabled, L2 miss, compute, L2 write, all as one in-process single-flight trip | 213,364 | 204,897 | -| `secure_l1_hit` | `@cache.secure` L1 hit (builds its key, decrypts the ciphertext L1 holds) | 134,323 | 134,972 | -| `l2_hit_async_metrics` | `l2_hit` with the metrics collector in batched mode | 171,976 | 167,728 | -| `serializer_default` | `StandardSerializer` round trip, small dict | 47,895 | 48,623 | -| `serializer_default_records` | `StandardSerializer` round trip, list of 100 six-field records (dict-heavy decode) | 1,420,388 | 1,424,292 | -| `serializer_auto` | `AutoSerializer` round trip | 64,722 | 65,653 | -| `serializer_orjson` | `OrjsonSerializer` round trip | 22,135 | 22,825 | -| `serializer_arrow` | `ArrowSerializer` round trip, 100-row DataFrame | 1,969,626 | 1,980,777 | -| `serializer_arrow_usgs` | `ArrowSerializer` round trip, real 12,535-row DataFrame (see Real data below) | 61,781,406 | 61,324,948 | -| `serializer_auto_usgs` | `AutoSerializer` round trip, same frame (it hands the frame to Arrow) | 61,793,577 | 61,344,459 | -| `serializer_encrypted` | `EncryptionWrapper` encrypt + decrypt round trip | 89,289 | 90,918 | -| `byte_storage_store_40b` | `ByteStorage.store()` alone, 40-byte compressible input (under cachekit-core's 64-byte literals-only LZ4 threshold) | 2,690 | 2,565 | -| `byte_storage_store_64k` | `ByteStorage.store()` alone, 64 KiB of address-like text | 720,631 | 720,751 | -| `file_set` | `FileBackend.set()` overwriting one key in a 1,000-entry cache (no eviction) | 76,035 | 74,112 | -| `object_cache_put_full` | `ObjectCache.put()` of a new key into a full 10,000-entry byte budget (evicts the LRU entry; nothing expired) | 165,014 | 160,608 | +| `l1_hit` | `@cache(backend=None)` L1 hit | 2,597 | 2,487 | +| `l1_hit_backed` | `@cache` with a backend configured, L1 hit (never reaches the in-process dict backend; decodes the verified MessagePack L1 holds after the first hit) | 80,291 | 80,911 | +| `l1_hit_backed_auto` | `l1_hit_backed` with `serializer="auto"` (decodes the verified MessagePack the auto serializer keeps) | 91,959 | 92,913 | +| `minimal_l1_hit` | `@cache.minimal(backend=None)` L1 hit | 2,598 | 2,487 | +| `l2_hit` | `@cache`, L1 disabled, L2 hit, as one in-process single-flight trip | 162,311 | 157,437 | +| `miss` | `@cache`, L1 disabled, L2 miss, compute, L2 write, all as one in-process single-flight trip | 212,074 | 203,600 | +| `secure_l1_hit` | `@cache.secure` L1 hit (builds its key, decrypts the ciphertext L1 holds) | 124,488 | 125,093 | +| `l2_hit_async_metrics` | `l2_hit` with the metrics collector in batched mode | 162,254 | 157,718 | +| `serializer_default` | `StandardSerializer` round trip, small dict | 47,796 | 48,501 | +| `serializer_default_records` | `StandardSerializer` round trip, list of 100 six-field records (dict-heavy decode) | 1,011,782 | 1,006,308 | +| `serializer_auto` | `AutoSerializer` round trip | 64,453 | 65,623 | +| `serializer_orjson` | `OrjsonSerializer` round trip | 22,227 | 22,519 | +| `serializer_arrow` | `ArrowSerializer` round trip, 100-row DataFrame | 1,970,058 | 1,979,439 | +| `serializer_arrow_usgs` | `ArrowSerializer` round trip, real 12,535-row DataFrame (see Real data below) | 61,805,038 | 61,327,875 | +| `serializer_auto_usgs` | `AutoSerializer` round trip, same frame (it hands the frame to Arrow) | 61,813,852 | 61,331,592 | +| `serializer_encrypted` | `EncryptionWrapper` encrypt + decrypt round trip | 89,109 | 90,790 | +| `byte_storage_store_40b` | `ByteStorage.store()` alone, 40-byte compressible input (under cachekit-core's 64-byte literals-only LZ4 threshold) | 2,685 | 2,559 | +| `byte_storage_store_64k` | `ByteStorage.store()` alone, 64 KiB of address-like text | 720,570 | 720,715 | +| `file_set` | `FileBackend.set()` overwriting one key in a 1,000-entry cache (no eviction) | 75,737 | 73,700 | +| `object_cache_put_full` | `ObjectCache.put()` of a new key into a full 10,000-entry byte budget (evicts the LRU entry; nothing expired) | 164,636 | 160,541 | Budgets are per interpreter (minor version, build flavour, machine); an interpreter without budgets fails with `no budget`. Every committed budget comes from one reference machine: x86_64, Ubuntu 24.04, glibc 2.39, valgrind 3.22.0, CPython 3.12.12 and 3.14.3 (uv's builds), the release extension that `uv sync` builds, and the dependencies in `uv.lock`. Counts depend on that whole build, so on any other machine, record a baseline on `main` first (`--update --allow-increase`) and compare your branch against it. `l2_hit` and `l2_hit_async_metrics` cost the same within 0.4%: a cache operation records into per-thread cells in either mode. @@ -348,7 +348,7 @@ Budgets are per interpreter (minor version, build flavour, machine); an interpre **Limits:** instruction counts do not weight cache misses or branch mispredictions. A claimed speed-up still needs an interleaved wall-clock comparison; the instruction count only guarantees the work did not grow. Paths that wait on a network backend are not covered. Cyclic-GC cost is outside the budgets; allocation and reference counting are inside. A Prometheus scrape, which sums each thread's cache-operation cells, runs outside the measured calls and is not budgeted. Part of pyarrow's work on the real-data paths is not budgeted either: about half of their instructions run on pyarrow's threads. Unrelated changes can still move a path's figure by up to 0.6% (a `WARN`), and a `LOWER` verdict on a path the change did not touch is a layout shift, not a saving: ratchet only the paths the change touched (`--update --path `). A change to the Rust extension moves the paths that run through it more, with no change in their work: `main`'s own source, built with and without symbol stripping, moved the `ByteStorage` round trip of `serializer_default` by 1.9%, while every function in it cost the same over 5,000 round trips, so the move is a one-time allocator event that the binary's layout puts inside one loop size. After an extension change, re-record the serializer paths that fail (`--update --allow-increase --path `) and say why in the PR. ```bash -make perf-ir # gate: fail on a >=1% per-call regression (needs valgrind; 190 runs, several minutes) +make perf-ir # gate: fail on a >=1% per-call regression (needs valgrind; 200 runs, several minutes) make perf-ir-update # ratchet: write lower measured figures back as budgets, never higher ``` diff --git a/tests/performance/README.md b/tests/performance/README.md index 95bc9ab8..4930f83a 100644 --- a/tests/performance/README.md +++ b/tests/performance/README.md @@ -26,8 +26,9 @@ arms (manual; see [docs/free-threading.md](../../docs/free-threading.md#decorate Run the whole battery with `make perf`; gate regressions with `make perf-compare`. **Instruction budgets.** `ir_budget.py` (`make perf-ir`) is the deterministic gate: main-thread -callgrind instructions per call for each hot path, failing at +1% against `ir_baselines.json`. Budgets belong to the build that recorded them; on another -interpreter, extension or C library, record a baseline on `main` first. CI runs it on every PR +callgrind instructions per call for each hot path, failing at +1% against `ir_baselines.json`. +Budgets belong to the reference machine that recorded them; on any other machine, record a +baseline on `main` first. CI runs it on every PR with `--base`: the PR and its base are measured on the same runner and compared with each other, not with the committed budgets, and `ir_report.py` renders the shards' `--report` files as one PR comment, which CI posts ([In CI](../../docs/performance.md#in-ci)). diff --git a/tests/performance/ir_baselines.json b/tests/performance/ir_baselines.json index 723d9ee7..b52522c0 100644 --- a/tests/performance/ir_baselines.json +++ b/tests/performance/ir_baselines.json @@ -2,54 +2,54 @@ "interpreters": { "cpython-3.12-x86_64": { "budgets": { - "byte_storage_store_40b": 2690, - "byte_storage_store_64k": 720631, - "file_set": 76035, - "l1_hit": 2595, - "l1_hit_backed": 83015, - "l1_hit_backed_auto": 91986, - "l2_hit": 172539, - "l2_hit_async_metrics": 171976, - "minimal_l1_hit": 2595, - "miss": 213364, - "object_cache_put_full": 165014, - "secure_l1_hit": 134323, - "serializer_arrow": 1969626, - "serializer_arrow_usgs": 61781406, - "serializer_auto": 64722, - "serializer_auto_usgs": 61793577, - "serializer_default": 47895, - "serializer_default_records": 1420388, - "serializer_encrypted": 89289, - "serializer_orjson": 22135 + "byte_storage_store_40b": 2685, + "byte_storage_store_64k": 720570, + "file_set": 75737, + "l1_hit": 2597, + "l1_hit_backed": 80291, + "l1_hit_backed_auto": 91959, + "l2_hit": 162311, + "l2_hit_async_metrics": 162254, + "minimal_l1_hit": 2598, + "miss": 212074, + "object_cache_put_full": 164636, + "secure_l1_hit": 124488, + "serializer_arrow": 1970058, + "serializer_arrow_usgs": 61805038, + "serializer_auto": 64453, + "serializer_auto_usgs": 61813852, + "serializer_default": 47796, + "serializer_default_records": 1011782, + "serializer_encrypted": 89109, + "serializer_orjson": 22227 }, "python": "3.12.12" }, "cpython-3.14-x86_64": { "budgets": { - "byte_storage_store_40b": 2565, - "byte_storage_store_64k": 720751, - "file_set": 74112, + "byte_storage_store_40b": 2559, + "byte_storage_store_64k": 720715, + "file_set": 73700, "l1_hit": 2487, - "l1_hit_backed": 83882, - "l1_hit_backed_auto": 92950, - "l2_hit": 167686, - "l2_hit_async_metrics": 167728, + "l1_hit_backed": 80911, + "l1_hit_backed_auto": 92913, + "l2_hit": 157437, + "l2_hit_async_metrics": 157718, "minimal_l1_hit": 2487, - "miss": 204897, - "object_cache_put_full": 160608, - "secure_l1_hit": 134972, - "serializer_arrow": 1980777, - "serializer_arrow_usgs": 61324948, - "serializer_auto": 65653, - "serializer_auto_usgs": 61344459, - "serializer_default": 48623, - "serializer_default_records": 1424292, - "serializer_encrypted": 90918, - "serializer_orjson": 22825 + "miss": 203600, + "object_cache_put_full": 160541, + "secure_l1_hit": 125093, + "serializer_arrow": 1979439, + "serializer_arrow_usgs": 61327875, + "serializer_auto": 65623, + "serializer_auto_usgs": 61331592, + "serializer_default": 48501, + "serializer_default_records": 1006308, + "serializer_encrypted": 90790, + "serializer_orjson": 22519 }, "python": "3.14.3" } }, - "method": "main-thread callgrind Ir per op, (Ir[3000] - Ir[1000]) / 2000 ((Ir[30] - Ir[10]) / 20 on the two *_usgs paths), median of five heap layouts, fixed env (PYTHONHASHSEED=0, one BLAS/OMP thread, pyarrow's jemalloc without its background thread, neither of pyarrow's allocators purging), pinned clocks and OS entropy; written by tests/performance/ir_budget.py --update" + "method": "main-thread callgrind Ir per op, (Ir[3000] - Ir[1000]) / 2000 ((Ir[30] - Ir[10]) / 20 on the two *_usgs paths), median of five heap layouts, fixed env (PYTHONHASHSEED=0, one BLAS/OMP thread, pyarrow's jemalloc without its background thread, neither of pyarrow's allocators purging), pinned clocks and OS entropy; budgets written by tests/performance/ir_budget.py --update" } diff --git a/tests/performance/ir_budget.py b/tests/performance/ir_budget.py index d40de694..4884d3cd 100644 --- a/tests/performance/ir_budget.py +++ b/tests/performance/ir_budget.py @@ -22,8 +22,8 @@ cache is warmed first, and the heap layout is sampled (``ir_workload.run_workload``, ``measure`` and ``LAYOUTS``). -Repeated runs agree within 0.04% per op, against a 1% fail threshold; the Arrow round trips and file_set -keep up to 0.25% in one layout (docs/performance.md). +Repeated runs agree within 0.04% per op on most paths, against a 1% fail threshold; docs/performance.md +names the paths that keep more noise, and how much. The measured process is ``ir_workload.py``. Its text is compiled into every measured run, so editing it moves the heap layout the budgets were recorded at; this gate is kept out of that @@ -72,7 +72,7 @@ WARMUP = 50 # The real-data paths cost about 60M main-thread Ir per op, 300 times a small path, so a run of # 3000 would take hours under callgrind. Fewer ops still resolve them: pyarrow's thread pool moves a -# run by up to about 2M Ir, against a difference of over a billion. +# run by up to about 2.8M Ir, against a difference of over a billion. LOOPS = dict.fromkeys(("serializer_arrow_usgs", "serializer_auto_usgs"), (5, 10, 30)) # path: (warmup, n_lo, n_hi) # Heap layout moves per-op counts: the allocators take shorter or longer paths in some heap # states. Any code change shifts the layout, even an edit to ir_workload.py's comments, so a single @@ -262,10 +262,11 @@ def measure( "OMP_NUM_THREADS": "1", # pyarrow converts on a thread pool otherwise: +-0.5% per op # pyarrow's two allocators run on real time. Its bundled jemalloc starts a background thread at # import, and how that thread is scheduled against the main thread puts startup in one of two - # states, up to 1.2M Ir apart. With the thread off, jemalloc would check its real-time purge - # deadlines on the allocating thread instead, so it never purges. pyarrow's default pool, mimalloc, - # purges freed memory after a real-time delay that the freeing thread checks (10 clock reads per - # real-data round trip), so it never purges either. + # states, up to 1.2M Ir apart: background_thread:false stops it. With the thread off, jemalloc + # would check its real-time purge deadlines on the allocating thread instead; the two decay + # settings stop it purging at all. pyarrow's default pool, mimalloc, purges freed memory after a + # real-time delay that the freeing thread checks (10 clock reads per real-data round trip); -1 + # stops it purging. "JE_ARROW_MALLOC_CONF": "background_thread:false,dirty_decay_ms:-1,muzzy_decay_ms:-1", "MIMALLOC_PURGE_DELAY": "-1", # cachekit's L1 sweeper wakes every 30 s of real time. A woken thread takes the GIL at a From 01face15c4d4d8f5060fa7092da353bedff753d3 Mon Sep 17 00:00:00 2001 From: Ray Walker Date: Mon, 2 Nov 2026 04:19:09 +0000 Subject: [PATCH 6/6] perf(ir): re-record every budget on the latest merge with main, document the measured directory's layout effect --- docs/performance.md | 48 +++++++++---------- tests/performance/ir_baselines.json | 74 ++++++++++++++--------------- 2 files changed, 61 insertions(+), 61 deletions(-) diff --git a/docs/performance.md b/docs/performance.md index 65249e3a..c016b6d4 100644 --- a/docs/performance.md +++ b/docs/performance.md @@ -302,17 +302,17 @@ The regression gate is the instruction budget: `make perf-ir` on your machine, a ## Instruction Budgets -`make perf-ir` counts the instructions each hot path executes per call and fails when a path costs **1% or more** above its committed budget. It warns from 0.2%. Instruction counts are deterministic where wall clock is not: in repeated runs on one machine, every path but five held its figure within 0.04%; the Arrow round trips and `file_set` keep up to 0.25% of noise in one layout's figure, and `l1_hit_backed_auto` moved 0.16% once on CPython 3.12 (see Method). +`make perf-ir` counts the instructions each hot path executes per call and fails when a path costs **1% or more** above its committed budget. It warns from 0.2%. Instruction counts are deterministic where wall clock is not: in repeated runs on one machine, every path but four held its figure within 0.04%; the Arrow round trips and `file_set` keep up to 0.25% of noise in one layout's figure (see Method). **Method** (`tests/performance/ir_budget.py`; the measured process is `ir_workload.py`): - Each path runs under `valgrind --tool=callgrind --separate-threads=yes`, and only the main thread is counted. cachekit's background threads (L1 cleanup) vary by tens of percent between identical runs. - Per-call cost is `(Ir[3000 calls] - Ir[1000 calls]) / 2000`, so interpreter startup (~2 billion instructions) and warmup cancel. Interpreter teardown is skipped. The two real-data paths cost about 60 million instructions per call, so they run 10 and 30 calls after 5 warmup calls; startup still cancels. -- Startup cancels only if it costs the same in every run. Three things made it vary, and the measured process takes each out. pyarrow's bundled jemalloc starts a background thread at import, and how it was scheduled against the main thread put a run in one of two startup states: `JE_ARROW_MALLOC_CONF=background_thread:false,dirty_decay_ms:-1,muzzy_decay_ms:-1` turns it off without moving its real-time purging onto the main thread. pyarrow's default allocator, mimalloc, purges freed memory after a real-time delay that the freeing thread checks: `MIMALLOC_PURGE_DELAY=-1`. `numpy.random`, which pandas imports, seeds its global generator from OS entropy, and the value drawn moves the heap layout: `ir_workload.pin_os_entropy` seeds Python's OS entropy first. With all three, 16 runs at one layout agree within 3,500 instructions at each loop size on 15 of the 20 paths on CPython 3.12, and on 16 of them on 3.14. -- Five paths keep noise this setup does not reach. The three Arrow round trips (`serializer_arrow` and the two real-data paths) run part of each call on pyarrow's thread pool, and how that work interleaves with the main thread's allocations moves the main thread's count by 0.5 to 2.8 million instructions per run, growing with the number of calls, with or without these settings: up to 0.1% of one layout's figure for `serializer_arrow` and 0.25% for the real-data paths. `file_set`'s startup still varies by up to 126,000 instructions, from a source not identified: up to 0.15% of one layout's figure. On CPython 3.12, `l1_hit_backed_auto`'s runs agreed within 3,900 instructions for 20 minutes at a time, but its per-call cost moved once, by 146 instructions (0.16%), between two runs that started seconds apart, and every later run kept the new cost. The move came as the machine's process IDs went from five digits to six. A process ID one digit longer makes a longer string wherever it is formatted, which can move the heap layout, but that cause is not confirmed. All five sit well inside the 1% threshold. +- Startup cancels only if it costs the same in every run. Three things made it vary, and the measured process takes each out. pyarrow's bundled jemalloc starts a background thread at import, and how it was scheduled against the main thread put a run in one of two startup states: `JE_ARROW_MALLOC_CONF=background_thread:false,dirty_decay_ms:-1,muzzy_decay_ms:-1` turns it off without moving its real-time purging onto the main thread. pyarrow's default allocator, mimalloc, purges freed memory after a real-time delay that the freeing thread checks: `MIMALLOC_PURGE_DELAY=-1`. `numpy.random`, which pandas imports, seeds its global generator from OS entropy, and the value drawn moves the heap layout: `ir_workload.pin_os_entropy` seeds Python's OS entropy first. With all three, 16 runs at one layout agree within 4,000 instructions at each loop size on 16 of the 20 paths, on CPython 3.12 and 3.14. +- Four paths keep noise this setup does not reach. The three Arrow round trips (`serializer_arrow` and the two real-data paths) run part of each call on pyarrow's thread pool, and how that work interleaves with the main thread's allocations moves the main thread's count by 0.5 to 2.8 million instructions per run, growing with the number of calls, with or without these settings: up to 0.1% of one layout's figure for `serializer_arrow` and 0.25% for the real-data paths. `file_set`'s startup still varies by up to 126,000 instructions, from a source not identified: up to 0.15% of one layout's figure. All four sit well inside the 1% threshold. - The measured process has a fixed environment (`PYTHONHASHSEED=0`, one BLAS/OpenMP thread, a one-day L1 cleanup interval, pyarrow's allocators set as above, nothing inherited), seeded log sampling and OS entropy, and main-thread clocks that advance 1μs per read. Code that records its own duration otherwise executes more instructions when it runs slower. The cleanup sweep reads the real clock, so inside a run it would evict entries stamped with the pinned one. - Nothing that runs on real time lands in the measured loop: no background thread wakes, cyclic GC is off, and the GIL switch interval is long enough that the main thread gives up the GIL only where the code releases it. - Each path runs at five heap layouts (0 to 880 extra objects held before the workload) and its figure is the median. Any code change moves the layout, and the allocators take shorter or longer paths in some heap states: single layouts of the orjson round trip and the minimal L1 hit sat up to 2.4% from the rest. The median ignores one or two such layouts. The cheapest layout is not used, because a lucky one can sit 1% below the rest, and a budget recorded there makes every later run look like a regression. -- `ir_workload.py`'s text is compiled into every measured process, so editing it moves the layout the budgets were recorded at: re-record after any change to it. The gate itself (`ir_budget.py`) is kept out of the measured process, so editing it does not move a budget. +- `ir_workload.py`'s text is compiled into every measured process, so editing it moves the layout the budgets were recorded at: re-record after any change to it. The gate itself (`ir_budget.py`) is kept out of the measured process, so editing it does not move a budget. The measured script's directory, `tests/performance/`, is first on the measured process's import path, so anything added there moves the layout too. A `__pycache__` there, which importing `ir_budget` or `ir_workload` without `-B` creates (pytest does), moved `serializer_orjson` on CPython 3.12 by 0.16% to 2.0%, depending on the tree. Record and gate with that directory as a fresh checkout has it, and change nothing in it while a run is measuring. - The L2 paths and the backed L1 hit use an in-process dict backend, so they cost instructions only: no sockets, retries or timeouts. - The metrics collector starts synchronous and switches to batched mode (generic metrics queue for a worker thread) when its 5 s check sees more than 100 records/s. Cache operations record into per-thread cells in either mode. Pinned clocks never reach that check, so the plain paths measure a synchronous collector, and `l2_hit_async_metrics` the batched collector a busy long-lived process runs; it checks that no cache operation queues. Every metrics path records once per call through the same method, so one batched path covers that mode. @@ -320,26 +320,26 @@ The regression gate is the instruction budget: `make perf-ir` on your machine, a | Path | What one call does | CPython 3.12 | CPython 3.14 | |------|--------------------|-------------:|-------------:| -| `l1_hit` | `@cache(backend=None)` L1 hit | 2,595 | 2,487 | -| `l1_hit_backed` | `@cache` with a backend configured, L1 hit (never reaches the in-process dict backend; decodes the verified MessagePack L1 holds after the first hit). The backend keeps an L1 hit-latency report, as a CachekitIO backend with telemetry on does, so each call pays the 1-in-256 timing draw and the timed hits' clock reads ([Telemetry](backends/cachekitio.md#telemetry)) | 80,413 | 81,213 | -| `l1_hit_backed_auto` | `@cache` with `serializer="auto"` and a backend that keeps no hit-latency report, L1 hit (decodes the verified MessagePack the auto serializer keeps) | 91,986 | 92,950 | -| `minimal_l1_hit` | `@cache.minimal(backend=None)` L1 hit | 2,595 | 2,487 | -| `l2_hit` | `@cache`, L1 disabled, L2 hit, as one in-process single-flight trip | 172,539 | 167,686 | -| `miss` | `@cache`, L1 disabled, L2 miss, compute, L2 write, all as one in-process single-flight trip | 213,364 | 204,897 | -| `secure_l1_hit` | `@cache.secure` L1 hit (builds its key, decrypts the ciphertext L1 holds) | 134,323 | 134,972 | -| `l2_hit_async_metrics` | `l2_hit` with the metrics collector in batched mode | 171,976 | 167,728 | -| `serializer_default` | `StandardSerializer` round trip, small dict | 47,895 | 48,623 | -| `serializer_default_records` | `StandardSerializer` round trip, list of 100 six-field records (dict-heavy decode) | 1,420,388 | 1,424,292 | -| `serializer_auto` | `AutoSerializer` round trip | 64,722 | 65,653 | -| `serializer_orjson` | `OrjsonSerializer` round trip | 22,135 | 22,825 | -| `serializer_arrow` | `ArrowSerializer` round trip, 100-row DataFrame | 1,969,626 | 1,980,777 | -| `serializer_arrow_usgs` | `ArrowSerializer` round trip, real 12,535-row DataFrame (see Real data below) | 61,781,406 | 61,324,948 | -| `serializer_auto_usgs` | `AutoSerializer` round trip, same frame (it hands the frame to Arrow) | 61,793,577 | 61,344,459 | -| `serializer_encrypted` | `EncryptionWrapper` encrypt + decrypt round trip | 89,289 | 90,918 | -| `byte_storage_store_40b` | `ByteStorage.store()` alone, 40-byte compressible input (under cachekit-core's 64-byte literals-only LZ4 threshold) | 2,690 | 2,565 | -| `byte_storage_store_64k` | `ByteStorage.store()` alone, 64 KiB of address-like text | 720,631 | 720,751 | -| `file_set` | `FileBackend.set()` overwriting one key in a 1,000-entry cache (no eviction) | 76,035 | 74,112 | -| `object_cache_put_full` | `ObjectCache.put()` of a new key into a full 10,000-entry byte budget (evicts the LRU entry; nothing expired) | 165,014 | 160,608 | +| `l1_hit` | `@cache(backend=None)` L1 hit | 2,597 | 2,487 | +| `l1_hit_backed` | `@cache` with a backend configured, L1 hit (never reaches the in-process dict backend; decodes the verified MessagePack L1 holds after the first hit). The backend keeps an L1 hit-latency report, as a CachekitIO backend with telemetry on does, so each call pays the 1-in-256 timing draw and the timed hits' clock reads ([Telemetry](backends/cachekitio.md#telemetry)) | 81,354 | 81,592 | +| `l1_hit_backed_auto` | `@cache` with `serializer="auto"` and a backend that keeps no hit-latency report, L1 hit (decodes the verified MessagePack the auto serializer keeps) | 92,337 | 93,325 | +| `minimal_l1_hit` | `@cache.minimal(backend=None)` L1 hit | 2,598 | 2,487 | +| `l2_hit` | `@cache`, L1 disabled, L2 hit, as one in-process single-flight trip | 163,783 | 158,141 | +| `miss` | `@cache`, L1 disabled, L2 miss, compute, L2 write, all as one in-process single-flight trip | 212,909 | 204,218 | +| `secure_l1_hit` | `@cache.secure` L1 hit (builds its key, decrypts the ciphertext L1 holds) | 125,617 | 126,238 | +| `l2_hit_async_metrics` | `l2_hit` with the metrics collector in batched mode | 163,570 | 158,590 | +| `serializer_default` | `StandardSerializer` round trip, small dict | 48,425 | 48,754 | +| `serializer_default_records` | `StandardSerializer` round trip, list of 100 six-field records (dict-heavy decode) | 1,026,419 | 1,006,373 | +| `serializer_auto` | `AutoSerializer` round trip | 64,500 | 65,557 | +| `serializer_orjson` | `OrjsonSerializer` round trip | 21,779 | 22,531 | +| `serializer_arrow` | `ArrowSerializer` round trip, 100-row DataFrame | 1,970,387 | 1,979,303 | +| `serializer_arrow_usgs` | `ArrowSerializer` round trip, real 12,535-row DataFrame (see Real data below) | 61,764,630 | 61,311,031 | +| `serializer_auto_usgs` | `AutoSerializer` round trip, same frame (it hands the frame to Arrow) | 61,759,824 | 61,345,651 | +| `serializer_encrypted` | `EncryptionWrapper` encrypt + decrypt round trip | 89,696 | 91,051 | +| `byte_storage_store_40b` | `ByteStorage.store()` alone, 40-byte compressible input (under cachekit-core's 64-byte literals-only LZ4 threshold) | 2,685 | 2,559 | +| `byte_storage_store_64k` | `ByteStorage.store()` alone, 64 KiB of address-like text | 720,567 | 720,683 | +| `file_set` | `FileBackend.set()` overwriting one key in a 1,000-entry cache (no eviction) | 75,751 | 73,691 | +| `object_cache_put_full` | `ObjectCache.put()` of a new key into a full 10,000-entry byte budget (evicts the LRU entry; nothing expired) | 164,793 | 160,601 | Budgets are per interpreter (minor version, build flavour, machine); an interpreter without budgets fails with `no budget`. Every committed budget comes from one reference machine: x86_64, Ubuntu 24.04, glibc 2.39, valgrind 3.22.0, CPython 3.12.12 and 3.14.3 (uv's builds), the release extension that `uv sync` builds, and the dependencies in `uv.lock`. Counts depend on that whole build, so on any other machine, record a baseline on `main` first (`--update --allow-increase`) and compare your branch against it. `l2_hit` and `l2_hit_async_metrics` cost the same within 0.4%: a cache operation records into per-thread cells in either mode. diff --git a/tests/performance/ir_baselines.json b/tests/performance/ir_baselines.json index 5c05003f..0a6e23d5 100644 --- a/tests/performance/ir_baselines.json +++ b/tests/performance/ir_baselines.json @@ -2,51 +2,51 @@ "interpreters": { "cpython-3.12-x86_64": { "budgets": { - "byte_storage_store_40b": 2690, - "byte_storage_store_64k": 720631, - "file_set": 76035, - "l1_hit": 2595, - "l1_hit_backed": 80413, - "l1_hit_backed_auto": 91986, - "l2_hit": 172539, - "l2_hit_async_metrics": 171976, - "minimal_l1_hit": 2595, - "miss": 213364, - "object_cache_put_full": 165014, - "secure_l1_hit": 134323, - "serializer_arrow": 1969626, - "serializer_arrow_usgs": 61781406, - "serializer_auto": 64722, - "serializer_auto_usgs": 61793577, - "serializer_default": 47895, - "serializer_default_records": 1420388, - "serializer_encrypted": 89289, - "serializer_orjson": 22135 + "byte_storage_store_40b": 2685, + "byte_storage_store_64k": 720567, + "file_set": 75751, + "l1_hit": 2597, + "l1_hit_backed": 81354, + "l1_hit_backed_auto": 92337, + "l2_hit": 163783, + "l2_hit_async_metrics": 163570, + "minimal_l1_hit": 2598, + "miss": 212909, + "object_cache_put_full": 164793, + "secure_l1_hit": 125617, + "serializer_arrow": 1970387, + "serializer_arrow_usgs": 61764630, + "serializer_auto": 64500, + "serializer_auto_usgs": 61759824, + "serializer_default": 48425, + "serializer_default_records": 1026419, + "serializer_encrypted": 89696, + "serializer_orjson": 21779 }, "python": "3.12.12" }, "cpython-3.14-x86_64": { "budgets": { "byte_storage_store_40b": 2559, - "byte_storage_store_64k": 720715, - "file_set": 73700, + "byte_storage_store_64k": 720683, + "file_set": 73691, "l1_hit": 2487, - "l1_hit_backed": 81213, - "l1_hit_backed_auto": 92950, - "l2_hit": 167686, - "l2_hit_async_metrics": 167728, + "l1_hit_backed": 81592, + "l1_hit_backed_auto": 93325, + "l2_hit": 158141, + "l2_hit_async_metrics": 158590, "minimal_l1_hit": 2487, - "miss": 203600, - "object_cache_put_full": 160541, - "secure_l1_hit": 125093, - "serializer_arrow": 1979439, - "serializer_arrow_usgs": 61327875, - "serializer_auto": 65623, - "serializer_auto_usgs": 61331592, - "serializer_default": 48501, - "serializer_default_records": 1006308, - "serializer_encrypted": 90790, - "serializer_orjson": 22519 + "miss": 204218, + "object_cache_put_full": 160601, + "secure_l1_hit": 126238, + "serializer_arrow": 1979303, + "serializer_arrow_usgs": 61311031, + "serializer_auto": 65557, + "serializer_auto_usgs": 61345651, + "serializer_default": 48754, + "serializer_default_records": 1006373, + "serializer_encrypted": 91051, + "serializer_orjson": 22531 }, "python": "3.14.3" }