diff --git a/docs/features/zero-knowledge-encryption.md b/docs/features/zero-knowledge-encryption.md index b7a7885a..6752b665 100644 --- a/docs/features/zero-knowledge-encryption.md +++ b/docs/features/zero-knowledge-encryption.md @@ -772,7 +772,7 @@ didn't recently disable encryption for that function, investigate. ### Encryption Overhead -An encrypted cache encrypts every value it stores and decrypts every hit. Through the decorator, the hosted benchmark could not separate that cost from run-to-run noise: in the Performance Guide's [GitHub-Hosted Runner](../performance.md#github-hosted-runner) table, the difference between the plaintext and encrypted arms of an L1 hit with a backend configured sits inside its own Welch band (see [Not Measured Here](../performance.md#not-measured-here)). The deterministic costs are the `secure_l1_hit` and `serializer_encrypted` rows of the guide's [Instruction Budgets](../performance.md#instruction-budgets). +An encrypted cache encrypts every value it stores and decrypts every hit. Through the decorator, the hosted benchmark could not separate that cost from run-to-run noise: in the Performance Guide's [GitHub-Hosted Runner](../performance.md#github-hosted-runner) table, the difference between the plaintext and encrypted arms of an L1 hit with a backend configured sits inside its own Welch band (see [Not Measured Here](../performance.md#not-measured-here)). The deterministic costs are the `secure_l1_hit` and `serializer_encrypted` rows of the guide's [Instruction Budgets](../performance.md#instruction-budgets), beside `l1_hit_backed`, the same value's L1 hit through plaintext `@cache` with a backend (the two presets differ in more than encryption). To time encryption per serializer on your own machine: `pytest tests/performance/test_encryption_overhead.py -v -s` diff --git a/docs/performance.md b/docs/performance.md index 04aa348b..54ea5ed6 100644 --- a/docs/performance.md +++ b/docs/performance.md @@ -73,7 +73,7 @@ With `backend=None`, cachekit keeps the returned object itself in memory and han With an L2 backend configured, L1 holds the serialized bytes instead, and a hit deserializes them, so that hit costs more as the payload grows. For the 100-user dict it took 284 ± 2μs on the same runner, measured before the walk skip described below, about 910 times an L1-only hit of the same dict. Nearly all of the difference is deserializing 23.5KB of MessagePack back into about 400 nested dicts. It is still about half of a Redis L2 hit there (539 ± 3μs), which deserializes the same bytes after the round trip. -For a plaintext cache with the default serializer and integrity checking on, an entry's first L1 hit decodes it as every read does, under the structure walk that bounds untrusted MessagePack, and then L1 holds the entry marked as walked: its verified MessagePack when that is no longer than the envelope, which is true of small values and incompressible ones, and otherwise the envelope itself. Later hits skip the walk, because the bytes it passed cannot change. They also skip the decoder's object hook when none of the strings `__datetime__`, `__date__` or `__time__` (or any text starting `__date`) appears anywhere in the MessagePack, because the hook would then hand back every map unchanged, and a hit on held MessagePack skips the envelope's LZ4 decompress and xxHash3-64 checksum as well. Bytes read from L2 are walked on every read. The 100-user dict compresses to a 3,171-byte envelope from 23.5KB of MessagePack, so L1 keeps its envelope, and its hits skip the walk and the hook: on CPython 3.14.3 the hit fell from 2,731,277 to 2,192,392 instructions (−19.7%, callgrind with the [Instruction Budgets](#instruction-budgets) method; no budget gates this path yet), and an interleaved wall-clock run on a shared x86_64 Linux host put it 20.9% faster (median of 12 paired processes; the base against itself, −1.2%). The same dict with datetimes in it keeps the hook and fell 5.6%. The hosted figures above were measured before this change. Encrypted caches always keep the ciphertext envelope, and every hit on one still decrypts, walks and runs the hook. +For a plaintext cache with the default serializer and integrity checking on, an entry's first L1 hit decodes it as every read does, under the structure walk that bounds untrusted MessagePack, and then L1 holds the entry marked as walked: its verified MessagePack when that is no longer than the envelope, which is true of small values and incompressible ones, and otherwise the envelope itself. Later hits skip the walk, because the bytes it passed cannot change. They also skip the decoder's object hook when none of the strings `__datetime__`, `__date__` or `__time__` (or any text starting `__date`) appears anywhere in the MessagePack, because the hook would then hand back every map unchanged, and a hit on held MessagePack skips the envelope's LZ4 decompress and xxHash3-64 checksum as well. Bytes read from L2 are walked on every read. The 100-user dict compresses to a 3,171-byte envelope from 23.5KB of MessagePack, so L1 keeps its envelope, and its hits skip the walk and the hook: on CPython 3.14.3 the hit fell from 2,731,277 to 2,192,392 instructions (−19.7%, callgrind with the [Instruction Budgets](#instruction-budgets) method; no budget gates this large-value hit, and `l1_hit_backed` gates the small-value hit on held MessagePack), and an interleaved wall-clock run on a shared x86_64 Linux host put it 20.9% faster (median of 12 paired processes; the base against itself, −1.2%). The same dict with datetimes in it keeps the hook and fell 5.6%. The hosted figures above were measured before this change. Encrypted caches always keep the ciphertext envelope, and every hit on one still decrypts, walks and runs the hook. ### Decorator + L1 Hit (Hot Path) @@ -126,7 +126,7 @@ uv run python tests/performance/terrain_canary.py --redis redis://localhost:6379 ## Not Measured Here These have no figure from the run-level harness that supports a claim: -- **Encryption overhead through the decorator**: `test_encryption_overhead` interleaves its plaintext and encrypted runs and prints both results. On the 100-user dict, the difference between the arms' run medians stayed inside its own band in every pass on a shared host and on the hosted runner until the 2026-10-31 hosted run, which put it at 9.3 ± 1.0μs ([GitHub-Hosted Runner](#github-hosted-runner)). One run that resolves it, after runs that did not, does not pin the cost down. The deterministic costs are the `secure_l1_hit` and `serializer_encrypted` rows of [Instruction Budgets](#instruction-budgets); see [Zero-Knowledge Encryption](features/zero-knowledge-encryption.md) for how encryption works +- **Encryption overhead through the decorator**: `test_encryption_overhead` interleaves its plaintext and encrypted runs and prints both results. On the 100-user dict, the difference between the arms' run medians stayed inside its own band in every pass on a shared host and on the hosted runner until the 2026-10-31 hosted run, which put it at 9.3 ± 1.0μs ([GitHub-Hosted Runner](#github-hosted-runner)). One run that resolves it, after runs that did not, does not pin the cost down. The deterministic costs are the `secure_l1_hit` and `serializer_encrypted` rows of [Instruction Budgets](#instruction-budgets), beside `l1_hit_backed`, the same value's L1 hit through plaintext `@cache` with a backend (the two presets differ in more than encryption); see [Zero-Knowledge Encryption](features/zero-knowledge-encryption.md) for how encryption works - **Request latency under contention**: the 10-thread guard times each call after its thread is scheduled (see [Decorator + L1 Hit](#decorator--l1-hit-hot-path)) - **The async decorator, serializer comparisons and a Redis on another machine** @@ -291,31 +291,32 @@ The regression gate is the instruction budget: `make perf-ir` on your machine, a - 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. -- The L2 paths use an in-process dict backend, so they cost instructions only: no sockets, retries or timeouts. +- 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. **Budgets** (instructions per call, `tests/performance/ir_baselines.json`): | Path | What one call does | CPython 3.12 | CPython 3.14 | |------|--------------------|-------------:|-------------:| -| `l1_hit` | `@cache(backend=None)` L1 hit | 2,594 | 2,482 | -| `minimal_l1_hit` | `@cache.minimal(backend=None)` L1 hit | 2,594 | 2,479 | -| `l2_hit` | `@cache`, L1 disabled, L2 hit, as one in-process single-flight trip | 171,988 | 167,408 | -| `miss` | `@cache`, L1 disabled, L2 miss, compute, L2 write, all as one in-process single-flight trip | 211,434 | 203,521 | -| `secure_l1_hit` | `@cache.secure` L1 hit (builds its key, decrypts the ciphertext L1 holds) | 139,943 | 140,926 | -| `l2_hit_async_metrics` | `l2_hit` with the metrics collector in batched mode | 171,370 | 167,447 | -| `serializer_default` | `StandardSerializer` round trip, small dict | 58,661 | 59,595 | -| `serializer_default_records` | `StandardSerializer` round trip, list of 100 six-field records (dict-heavy decode) | 1,422,079 | 1,422,120 | -| `serializer_auto` | `AutoSerializer` round trip | 65,971 | 66,624 | -| `serializer_orjson` | `OrjsonSerializer` round trip | 22,085 | 22,677 | -| `serializer_arrow` | `ArrowSerializer` round trip, 100-row DataFrame | 1,972,713 | 1,982,226 | -| `serializer_arrow_usgs` | `ArrowSerializer` round trip, real 12,535-row DataFrame (see Real data below) | 61,750,733 | 61,321,806 | -| `serializer_auto_usgs` | `AutoSerializer` round trip, same frame (it hands the frame to Arrow) | 61,806,031 | 61,327,994 | -| `serializer_encrypted` | `EncryptionWrapper` encrypt + decrypt round trip | 100,164 | 101,927 | -| `byte_storage_store_40b` | `ByteStorage.store()` alone, 40-byte compressible input (under cachekit-core's 64-byte literals-only LZ4 threshold) | 2,658 | 2,530 | -| `byte_storage_store_64k` | `ByteStorage.store()` alone, 64 KiB of address-like text | 720,667 | 720,663 | -| `file_set` | `FileBackend.set()` overwriting one key in a 1,000-entry cache (no eviction) | 75,887 | 74,132 | -| `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,514 | 160,511 | +| `l1_hit` | `@cache(backend=None)` L1 hit | 2,596 | 2,482 | +| `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) | 89,226 | 90,146 | +| `minimal_l1_hit` | `@cache.minimal(backend=None)` L1 hit | 2,596 | 2,488 | +| `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) | 140,428 | 141,391 | +| `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,658 | 2,540 | +| `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. @@ -324,7 +325,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. 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. ```bash -make perf-ir # gate: fail on a >=1% per-call regression (orjson 2%; needs valgrind; 170 runs, several minutes) +make perf-ir # gate: fail on a >=1% per-call regression (orjson 2%; needs valgrind; 190 runs, several minutes) make perf-ir-update # ratchet: write lower measured figures back as budgets, never higher ``` diff --git a/tests/performance/ir_baselines.json b/tests/performance/ir_baselines.json index 18a191f0..7d8ce9a1 100644 --- a/tests/performance/ir_baselines.json +++ b/tests/performance/ir_baselines.json @@ -3,46 +3,48 @@ "cpython-3.12-x86_64": { "budgets": { "byte_storage_store_40b": 2658, - "byte_storage_store_64k": 720667, - "file_set": 75887, - "l1_hit": 2594, - "l2_hit": 171988, - "l2_hit_async_metrics": 171370, - "minimal_l1_hit": 2594, - "miss": 211434, - "object_cache_put_full": 164514, - "secure_l1_hit": 139943, - "serializer_arrow": 1972713, - "serializer_arrow_usgs": 61750733, - "serializer_auto": 65971, - "serializer_auto_usgs": 61806031, - "serializer_default": 58661, - "serializer_default_records": 1422079, - "serializer_encrypted": 100164, - "serializer_orjson": 22085 + "byte_storage_store_64k": 720631, + "file_set": 76035, + "l1_hit": 2596, + "l1_hit_backed": 89226, + "l2_hit": 172539, + "l2_hit_async_metrics": 171976, + "minimal_l1_hit": 2596, + "miss": 213364, + "object_cache_put_full": 165014, + "secure_l1_hit": 140428, + "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 }, "python": "3.12.12" }, "cpython-3.14-x86_64": { "budgets": { - "byte_storage_store_40b": 2530, - "byte_storage_store_64k": 720663, - "file_set": 74132, + "byte_storage_store_40b": 2540, + "byte_storage_store_64k": 720751, + "file_set": 74112, "l1_hit": 2482, - "l2_hit": 167408, - "l2_hit_async_metrics": 167447, - "minimal_l1_hit": 2479, - "miss": 203521, - "object_cache_put_full": 160511, - "secure_l1_hit": 140926, - "serializer_arrow": 1982226, - "serializer_arrow_usgs": 61321806, - "serializer_auto": 66624, - "serializer_auto_usgs": 61327994, - "serializer_default": 59595, - "serializer_default_records": 1422120, - "serializer_encrypted": 101927, - "serializer_orjson": 22677 + "l1_hit_backed": 90146, + "l2_hit": 167686, + "l2_hit_async_metrics": 167728, + "minimal_l1_hit": 2488, + "miss": 204897, + "object_cache_put_full": 160608, + "secure_l1_hit": 141391, + "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 }, "python": "3.14.3" } diff --git a/tests/performance/ir_budget.py b/tests/performance/ir_budget.py index 95857967..cea06df1 100644 --- a/tests/performance/ir_budget.py +++ b/tests/performance/ir_budget.py @@ -96,6 +96,7 @@ WORKLOAD = Path(__file__).with_name("ir_workload.py") # the measured process PATHS = ( "l1_hit", + "l1_hit_backed", "minimal_l1_hit", "l2_hit", "miss", diff --git a/tests/performance/ir_workload.py b/tests/performance/ir_workload.py index 80e4bd1c..0a660407 100644 --- a/tests/performance/ir_workload.py +++ b/tests/performance/ir_workload.py @@ -113,8 +113,11 @@ def __init__(self, **kwargs: Any) -> None: l2 = lambda: cache(backend=DictBackend(), l1_enabled=False, ttl=300)(body) # noqa: E731 # Every metrics path records through the same AsyncMetricsCollector.record_cache_operation, once # per call, so one batched-mode variant covers that mode; the L1-only hits record no metric. + # With a backend, L1 holds serialized bytes and every hit decodes them, where an L1-only hit returns + # the stored object: after its first hit, this small value's entry is held as its verified MessagePack. decorated: dict[str, Callable[[], Callable[..., dict]]] = { "l1_hit": lambda: cache(backend=None, ttl=300)(body), + "l1_hit_backed": lambda: cache(backend=DictBackend(), ttl=300)(body), "minimal_l1_hit": lambda: cache.minimal(backend=None, ttl=300)(body), "l2_hit": l2, "miss": lambda: cache(backend=MissBackend(), l1_enabled=False, ttl=300)(body), diff --git a/tests/unit/test_ir_budget.py b/tests/unit/test_ir_budget.py index 92468bb5..f857f68c 100644 --- a/tests/unit/test_ir_budget.py +++ b/tests/unit/test_ir_budget.py @@ -446,6 +446,51 @@ def tracking_init(self, *args, **kwargs): assert direct == {} +def test_backed_l1_hit_path_is_a_plaintext_l1_hit_on_held_msgpack(monkeypatch) -> None: + """``l1_hit_backed`` budgets an L1 hit with a backend: after warmup, every call finds its key in L1, holding + the verified MessagePack, so it never reaches L2.""" + pytest.importorskip("pandas") # the workload builder makes the Arrow path's DataFrame too + import cachekit + from cachekit.l1_cache import L1Cache + from cachekit.serializers.standard_serializer import VerifiedMsgpack + + entries: list[object] = [] + real_get = L1Cache.get + + def tracking_get(self, key): + found, entry = real_get(self, key) + entries.append(entry if found else None) + return found, entry + + # build_workload imports cache at call time, so this wrapper sees the backend the path is built with. + backend_reads: list[str] = [] + real_cache = cachekit.cache + + def counting_cache(*args, backend, **kwargs): + real_backend_get = backend.get + + def counting_get(key): + backend_reads.append(key) + return real_backend_get(key) + + backend.get = counting_get + return real_cache(*args, backend=backend, **kwargs) + + monkeypatch.setattr(L1Cache, "get", tracking_get) + monkeypatch.setattr(cachekit, "cache", counting_cache) + op = ir_workload.build_workload("l1_hit_backed") + for _ in range(3): # warmup: the miss stores the envelope, the first hit swaps in the MessagePack + op() + assert backend_reads, "the warmup miss reads the backend, so the count reaches it" + entries.clear() + backend_reads.clear() + for _ in range(20): + assert op() == {"id": 42, "name": "Ada Lovelace", "roles": ["admin", "ops"], "score": 97.5, "tags": list(range(16))} + assert len(entries) == 20 + assert all(type(entry) is VerifiedMsgpack for entry in entries) + assert backend_reads == [] + + def test_pinned_clocks_tick_per_read_on_the_main_thread_only(monkeypatch) -> None: for name in ("time", "monotonic", "perf_counter"): monkeypatch.setattr(time, name, getattr(time, name))