diff --git a/src/cachekit/cache_handler.py b/src/cachekit/cache_handler.py index 0f47dfcd..0a924ec9 100644 --- a/src/cachekit/cache_handler.py +++ b/src/cachekit/cache_handler.py @@ -1354,7 +1354,7 @@ async def _handle_l2_read_error_async(self, e: SerializationError, cache_key: st get_logger().warning(f"Failed to evict poisoned L2 entry {redact_cache_key(cache_key)}: {del_err}") self._notify_deserialize_error(e, cache_key) - def get_cached_value(self, cache_key: str, refresh_ttl: Optional[int] = None) -> Optional[Any]: + def get_cached_value(self, cache_key: str, refresh_ttl: Optional[int] = None) -> Optional[tuple[bool, Any, int]]: """Get value from cache if it exists. Args: @@ -1362,7 +1362,11 @@ def get_cached_value(self, cache_key: str, refresh_ttl: Optional[int] = None) -> refresh_ttl: Optional TTL to refresh on hit Returns: - Tuple (True, value) if cache hit, None if cache miss or error + Tuple (True, value, size_bytes) if cache hit, None if cache miss or error. + size_bytes is the length of the L2 envelope actually served, the same quantity + the L1 hit site records via len(l1_bytes) (LAB-3768). It is a length rather than + the envelope itself: the sync path does no L1 backfill (#164) and the mmap fast + path's view dangles once its handle closes (#171). Note: Requires cache_handler to be set via set_cache_handler() before calling. @@ -1381,7 +1385,9 @@ def get_cached_value(self, cache_key: str, refresh_ttl: Optional[int] = None) -> if handle is not None: try: get_logger().cache_hit(cache_key, "Backend(mmap)") - return (True, self.serialization_handler.deserialize_data(handle.view, cache_key)) + value = self.serialization_handler.deserialize_data(handle.view, cache_key) + # Size is read before close(); the view itself must never leave this frame (#171). + return (True, value, handle.view.nbytes) finally: handle.close() @@ -1390,8 +1396,8 @@ def get_cached_value(self, cache_key: str, refresh_ttl: Optional[int] = None) -> get_logger().cache_hit(cache_key, "Backend") # Pass cache_key for AAD verification (required for encrypted data) deserialized = self.serialization_handler.deserialize_data(cached_data, cache_key) - # Return a tuple (True, value) to distinguish from "no cache entry" - return (True, deserialized) + # Tuple distinguishes a hit from "no cache entry"; the served envelope size rides along + return (True, deserialized, len(cached_data)) return None except KeyringConfigurationError: # LOCAL keyring config fault (bad tenant_id, bad keyring entry index) — @@ -1410,11 +1416,11 @@ def get_cached_value(self, cache_key: str, refresh_ttl: Optional[int] = None) -> get_logger().warning(f"Backend operation failed for get on {cache_key}: {e}") return None - def get_cached_value_with_freshness(self, cache_key: str) -> Optional[tuple[tuple[bool, Any], bool, Optional[int]]]: + def get_cached_value_with_freshness(self, cache_key: str) -> Optional[tuple[tuple[bool, Any, int], bool, Optional[int]]]: """SWR variant of :meth:`get_cached_value` (LAB-381/LAB-557): also reports staleness and the server's remaining freshness in seconds. - Returns ``((True, value), is_stale, fresh_for)`` on a hit, None on + Returns ``((True, value, size_bytes), is_stale, fresh_for)`` on a hit, None on miss/error. fresh_for is None when no signal exists (pre-signal server, non-SWR backend) — the caller applies legacy L1 TTL behavior. The mmap fast path is skipped — SWR is CachekitIO-only, which is not buffer-readable. @@ -1436,7 +1442,7 @@ def get_cached_value_with_freshness(self, cache_key: str) -> Optional[tuple[tupl cached_data, is_stale, fresh_for = hit get_logger().cache_hit(cache_key, "Backend(stale)" if is_stale else "Backend") deserialized = self.serialization_handler.deserialize_data(cached_data, cache_key) - return ((True, deserialized), is_stale, fresh_for) + return ((True, deserialized, len(cached_data)), is_stale, fresh_for) except KeyringConfigurationError: # LOCAL keyring config fault (bad tenant_id, bad keyring entry index) — # never a legitimate miss, and not tamper. Re-raised past the broad diff --git a/src/cachekit/decorators/wrapper.py b/src/cachekit/decorators/wrapper.py index 08b2209b..c3c8af0f 100644 --- a/src/cachekit/decorators/wrapper.py +++ b/src/cachekit/decorators/wrapper.py @@ -1322,7 +1322,8 @@ def sync_wrapper(*args: Any, **kwargs: Any) -> Any: # noqa: PLR0912 duration = time.time() - start_time if cached_result is not None: - # Cached result is a tuple (True, actual_value) + # (True, value, size_bytes): served L2 envelope length, see get_cached_value. + _found, result, size_bytes = cached_result features.set_operation_context("get", duration_ms=duration * 1000) features.record_success() @@ -1337,7 +1338,6 @@ def sync_wrapper(*args: Any, **kwargs: Any) -> Any: # noqa: PLR0912 ) # Record cache hit with structured logging - size_bytes = len(str(cached_result[1]).encode("utf-8")) if cached_result[1] is not None else 0 features.log_cache_operation( operation="get", key=cache_key, @@ -1350,7 +1350,6 @@ def sync_wrapper(*args: Any, **kwargs: Any) -> Any: # noqa: PLR0912 # Also record statistics if enabled if features.collect_stats: - size_bytes = len(str(cached_result[1]).encode("utf-8")) if cached_result[1] is not None else 0 features.record_cache_operation( operation="get", namespace=namespace or "default", @@ -1374,7 +1373,7 @@ def sync_wrapper(*args: Any, **kwargs: Any) -> Any: # noqa: PLR0912 # WHY: L2 cache hit returns from try block that lacks finally cleanup # (only inner try at line ~567, not the outer try-finally at ~645-720) reset_current_function_stats(token) - return cached_result[1] + return result except DecryptionAuthenticationError: # Fail-closed tamper failure propagated from get_cached_value — it only # raises when encryption.fail_closed=True (the metric and error log were diff --git a/tests/unit/test_decrypt_fail_policy.py b/tests/unit/test_decrypt_fail_policy.py index 3961708d..c913443d 100644 --- a/tests/unit/test_decrypt_fail_policy.py +++ b/tests/unit/test_decrypt_fail_policy.py @@ -332,7 +332,7 @@ def test_fail_open_valid_entry_roundtrips(self): """Regression: the happy path is untouched by the policy plumbing.""" handler, strategy, serialization = _make_operation_handler(fail_closed=True) strategy.store["key:a"] = serialization.serialize_data({"v": 7}, cache_key="key:a") - assert handler.get_cached_value("key:a") == (True, {"v": 7}) + assert handler.get_cached_value("key:a") == (True, {"v": 7}, len(strategy.store["key:a"])) class TestConfigDriftRead: diff --git a/tests/unit/test_mmap_read_path.py b/tests/unit/test_mmap_read_path.py index 8f08731d..c01e941e 100644 --- a/tests/unit/test_mmap_read_path.py +++ b/tests/unit/test_mmap_read_path.py @@ -99,12 +99,13 @@ def test_eligible_reads_via_mmap_and_confines_the_handle(self) -> None: sh.supports_mmap_read.return_value = True sh.deserialize_data.return_value = sentinel handle = MagicMock() + handle.view = memoryview(b"payload") ch = MagicMock() ch.get_buffer.return_value = handle result = self._handler(sh, ch).get_cached_value("k") - assert result == (True, sentinel) + assert result == (True, sentinel, len(b"payload")) # size is the mapped payload, read before close ch.get_buffer.assert_called_once_with("k") ch.get.assert_not_called() # normal read path NOT used on the mmap hit sh.deserialize_data.assert_called_once_with(handle.view, "k") @@ -133,7 +134,7 @@ def test_get_buffer_none_falls_through_to_normal_read(self) -> None: ch.get_buffer.assert_called_once() ch.get.assert_called_once() # fell through - assert result == (True, "val") + assert result == (True, "val", len(b"frame")) @pytest.mark.unit @@ -156,7 +157,8 @@ def test_arrow_dataframe_roundtrips_through_real_mmap(self, tmp_path) -> None: oh = CacheOperationHandler(sh, CacheKeyGenerator(), cache_handler=ch) df = pd.DataFrame({"a": range(2000), "b": [float(i) / 3 for i in range(2000)]}) - ch.set("k", sh.serialize_data(df, cache_key="k"), 300) + envelope = sh.serialize_data(df, cache_key="k") + ch.set("k", envelope, 300) with ( patch.object(backend, "get", wraps=backend.get) as g, @@ -165,8 +167,9 @@ def test_arrow_dataframe_roundtrips_through_real_mmap(self, tmp_path) -> None: hit = oh.get_cached_value("k") assert hit is not None - found, value = hit + found, value, size_bytes = hit assert found is True pd.testing.assert_frame_equal(value, df) + assert size_bytes == len(envelope) # the mmap hit reports the served envelope, not a repr estimate (LAB-3768) gb.assert_called_once() # the real mmap path was taken g.assert_not_called() # not the os.read fallback diff --git a/tests/unit/test_swr_decorator.py b/tests/unit/test_swr_decorator.py index ffe6dc36..a93ce8ba 100644 --- a/tests/unit/test_swr_decorator.py +++ b/tests/unit/test_swr_decorator.py @@ -528,7 +528,7 @@ def test_legacy_two_tuple_handler_degrades_to_no_bound(self) -> None: cache_handler = mock.MagicMock() cache_handler.get_with_freshness.return_value = (b"bytes", False) # 0.5.x 2-tuple op.set_cache_handler(cache_handler) - assert op.get_cached_value_with_freshness("k") == ((True, {"v": 1}), False, None) + assert op.get_cached_value_with_freshness("k") == ((True, {"v": 1}, len(b"bytes")), False, None) def test_backend_error_reads_as_miss(self) -> None: op, cache_handler = self._make_op() diff --git a/tests/unit/test_sync_l2_hit_size_bytes.py b/tests/unit/test_sync_l2_hit_size_bytes.py new file mode 100644 index 00000000..b80a7be0 --- /dev/null +++ b/tests/unit/test_sync_l2_hit_size_bytes.py @@ -0,0 +1,62 @@ +"""Sync L2-hit ``size_bytes`` measures the served envelope (LAB-3768). + +The sync L1 hit site records ``len(l1_bytes)``; the sync L2 site recorded +``len(str(value).encode())``, a repr estimate of the deserialized value, because the sync +handler returned no envelope. A secure cache (ciphertext envelope vs plaintext repr) got a +bimodal histogram on one series. +""" + +from __future__ import annotations + +from typing import Any + +import pytest + +from cachekit import cache +from cachekit.decorators.orchestrator import FeatureOrchestrator + + +class _ByteStore: + """Plain in-memory byte store standing in for L2.""" + + def __init__(self) -> None: + self.store: dict[str, bytes] = {} + + def get(self, key: str) -> bytes | None: + return self.store.get(key) + + def set(self, key: str, value: bytes, ttl: int | None = None) -> None: + self.store[key] = value + + def delete(self, key: str) -> bool: + return self.store.pop(key, None) is not None + + def exists(self, key: str) -> bool: + return key in self.store + + def health_check(self) -> tuple[bool, dict[str, Any]]: + return True, {} + + +@pytest.mark.unit +def test_sync_l2_hit_records_envelope_size(monkeypatch: pytest.MonkeyPatch) -> None: + # Patched at the orchestrator, not the collector: record_success() also forwards an + # operation-context record to the collector, which would shadow the value under test. + recorded: list[dict[str, Any]] = [] + monkeypatch.setattr(FeatureOrchestrator, "record_cache_operation", lambda self, **kw: recorded.append(kw)) + backend = _ByteStore() + + @cache(backend=backend, l1_enabled=False, ttl=60, namespace="sync-l2-size") + def compute() -> dict[str, int]: + return {"answer": 42} + + assert compute() == {"answer": 42} # miss: primes L2 + (envelope,) = backend.store.values() + recorded.clear() + + assert compute() == {"answer": 42} + + gets = [c for c in recorded if c["operation"] == "get"] + assert len(gets) == 1 + assert gets[0]["size_bytes"] == len(envelope) + assert len(envelope) != len(str({"answer": 42}).encode()) # non-vacuous: the old repr estimate differs