fix(logging): redact raw cache keys on all log paths (LAB-304)

SECURITY.md

@@ -187,6 +187,10 @@ When using `@cache.io` (CachekitIOBackend), the SDK includes built-in Server-Sid
 
 See [SSRF Protection](docs/features/ssrf-protection.md) for full details, including custom host configuration for development environments.
 
+### Cache Key Redaction in Logs (CWE-532)
+
+Cache keys can embed caller-supplied tenant/user identifiers, so they never reach logs verbatim ([CWE-532][cwe-532]). Every log path — decorator error handling (structured and backwards-compat), cache-operation logs, and SWR/TTL-refresh debug logs — replaces the key with a fixed-length blake2b digest (`<redacted:…>`), keeping log lines correlatable without leaking the key. Error paths are covered centrally at the shared error sink (`FeatureOrchestrator.handle_cache_error` / `log_cache_operation`), so new call sites are redacted by construction. `BackendError` redacts its `key` at construction, so `str(e)` is safe at any log sink; backend error *messages* carry no raw key either — wrapped third-party exception text of unknown provenance (e.g. pymemcache illegal-input errors, which echo the key) is reduced to the exception type name, with the original exception preserved on `original_exception` for programmatic access.
+
 ### Lock Token Transport (CWE-532)
 
 The distributed-lock capability token (`lock_id`) is sent in the `X-CacheKit-Lock-Id` request header when releasing a lock (`DELETE /v1/cache/{key}/lock`), **never** in the URL query string. Query strings are routinely captured by access logs, proxy/CDN logs, and OpenTelemetry `http.url` spans ([CWE-532][cwe-532]); a leaked token could be replayed to release a lock within its short TTL. The CacheKit SaaS backend dual-reads the header and the legacy `?lock_id=` query during migration, preferring the header (removed in protocol 2.0).

pyproject.toml

@@ -247,10 +247,11 @@ constraint-dependencies = [
     "urllib3>=2.7.0",
     "fonttools>=4.60.2",
     "werkzeug>=3.1.4",
-    # pip is a dev-only transitive dep (pip-audit -> pip-api -> pip). 26.1.2 fixes
-    # PYSEC-2026-196 (entry-point path traversal), GHSA-58qw-9mgm-455v (tar/zip
-    # confusion) and GHSA-jp4c-xjxw-mgf9 (self-update import ordering).
-    "pip>=26.1.2",
+    # pip is a dev-only transitive dep (pip-audit -> pip-api -> pip). 26.2 fixes
+    # PYSEC-2026-3721; 26.1.2 fixed PYSEC-2026-196 (entry-point path traversal),
+    # GHSA-58qw-9mgm-455v (tar/zip confusion) and GHSA-jp4c-xjxw-mgf9 (self-update
+    # import ordering).
+    "pip>=26.2",
     # h2 is a transitive dep (httpx[http2] -> h2). 4.4.1 fixes
     # GHSA-6hr6-w5qg-qmwg (duplicate Host headers forwarded on HTTP/2 ->
     # HTTP/1.1 downgrade — request smuggling primitive).

src/cachekit/backends/errors.py

@@ -10,6 +10,8 @@
 from enum import Enum
 from typing import Optional
 
+from ..hash_utils import redact_cache_key
+
 
 class BackendErrorType(str, Enum):
     """Error classification for circuit breaker and retry decisions.
@@ -52,7 +54,9 @@ class BackendError(Exception):
         error_type: Error classification (see BackendErrorType)
         original_exception: The original exception that caused this error (if any)
         operation: The operation that failed (get, set, delete, exists)
-        key: The cache key involved in the operation (optional, for debugging)
+        key: The cache key involved in the operation (optional, for debugging).
+            Kept raw on the attribute for programmatic access; the formatted
+            exception text carries only its redacted digest (CWE-532).
 
     Example:
         >>> from redis import ConnectionError as RedisConnectionError
@@ -99,9 +103,11 @@ def _format_message(self) -> str:
         if self.operation:
             parts.append(f"operation={self.operation}")
         if self.key:
-            # Truncate key for security/readability
-            key_display = self.key[:50] + "..." if len(self.key) > 50 else self.key
-            parts.append(f"key={key_display}")
+            # Redact, don't truncate: str(e) reaches log interpolation at every
+            # error sink, and cache keys embed caller-supplied tenant/user
+            # identifiers (CWE-532, LAB-304). The fixed-length digest keeps the
+            # message correlatable with the sinks' own redact_cache_key() output.
+            parts.append(f"key={redact_cache_key(self.key)}")
         if self.error_type:
             parts.append(f"type={self.error_type.value}")
         return " | ".join(parts)

src/cachekit/backends/memcached/backend.py

@@ -127,7 +127,10 @@ def set(self, key: str, value: bytes, ttl: Optional[int] = None) -> None:
         if max_size and len(value) > max_size:
             raise BackendError(
                 message=(
-                    f"Value for key {key!r} is {len(value)} bytes, which exceeds the Memcached "
+                    # No raw key in the message — it reaches log sinks via str(e)
+                    # (CWE-532); the key= segment _format_message appends carries
+                    # the redacted digest for correlation.
+                    f"Value is {len(value)} bytes, which exceeds the Memcached "
                     f"max item size of {max_size} bytes. Memcached cannot store it. Enable "
                     f"compression, use a larger-payload backend (Redis/SaaS/File), or raise both "
                     f"the server's -I limit and CACHEKIT_MEMCACHED_MAX_ITEM_SIZE_BYTES."

src/cachekit/backends/memcached/error_handler.py

@@ -68,19 +68,24 @@ def classify_memcached_error(
             key=key,
         )
 
-    # Permanent — illegal input, client errors (don't retry)
+    # Permanent — illegal input, client errors (don't retry).
+    # Only the exception TYPE goes in the message: pymemcache embeds the raw
+    # cache key in illegal-input error text ("Key is too long: %r"), and the
+    # message reaches log sinks via str(e) (CWE-532). Full details stay on
+    # original_exception for programmatic access.
     if isinstance(exc, (MemcacheIllegalInputError, MemcacheClientError)):
         return BackendError(
-            message=f"Memcached permanent error during {operation}: {exc}",
+            message=f"Memcached permanent error during {operation}: {type(exc).__name__}",
             error_type=BackendErrorType.PERMANENT,
             original_exception=exc,
             operation=operation,
             key=key,
         )
 
-    # Unknown — safe default
+    # Unknown — safe default. Arbitrary exception text has unknown provenance
+    # and may embed the key, so only the type name goes in the message (CWE-532).
     return BackendError(
-        message=f"Memcached unknown error during {operation}: {exc}",
+        message=f"Memcached unknown error during {operation}: {type(exc).__name__}",
         error_type=BackendErrorType.UNKNOWN,
         original_exception=exc,
         operation=operation,

src/cachekit/backends/provider.py

@@ -9,6 +9,8 @@
 
 from typing import TYPE_CHECKING, Optional
 
+from cachekit.hash_utils import redact_key_for_log
+
 if TYPE_CHECKING:
     import redis
     import redis.asyncio as redis_async
@@ -59,21 +61,21 @@ def error(self, message: str):
         self._logger.error(message)
 
     def cache_hit(self, key: str, source: str = "Redis"):
-        """Log cache hits."""
-        self._logger.debug(f"{source} cache hit for key: {key}")
+        """Log cache hits. Keys are redacted — they embed caller identifiers (CWE-532)."""
+        self._logger.debug(f"{source} cache hit for key: {redact_key_for_log(key)}")
 
     def cache_miss(self, key: str):
-        """Log cache misses."""
-        self._logger.debug(f"Cache miss for key: {key}")
+        """Log cache misses. Keys are redacted — they embed caller identifiers (CWE-532)."""
+        self._logger.debug(f"Cache miss for key: {redact_key_for_log(key)}")
 
     def cache_stored(self, key: str, ttl=None):
-        """Log cache storage operations."""
+        """Log cache storage operations. Keys are redacted — they embed caller identifiers (CWE-532)."""
         ttl_info = f" with TTL {ttl}" if ttl else ""
-        self._logger.debug(f"Cached result for key: {key}{ttl_info}")
+        self._logger.debug(f"Cached result for key: {redact_key_for_log(key)}{ttl_info}")
 
     def cache_invalidated(self, key: str, source: str = "Redis"):
-        """Log cache invalidation."""
-        self._logger.debug(f"Invalidated {source} cache for key: {key}")
+        """Log cache invalidation. Keys are redacted — they embed caller identifiers (CWE-532)."""
+        self._logger.debug(f"Invalidated {source} cache for key: {redact_key_for_log(key)}")
 
 
 class DefaultLoggerProvider(LoggerProvider):

src/cachekit/cache_handler.py

@@ -7,7 +7,6 @@
 from __future__ import annotations
 
 import asyncio
-import hashlib
 import threading
 import warnings
 from collections.abc import Callable
@@ -29,6 +28,10 @@
 )
 from cachekit.config import ConfigurationError, get_settings
 from cachekit.di import DIContainer
+
+# Re-exported for backwards compatibility — redact_cache_key moved to the hash_utils
+# leaf module so backend/L1 modules can redact without importing this module (cycle).
+from cachekit.hash_utils import redact_cache_key
 from cachekit.interop import InteropError
 from cachekit.key_generator import CacheKeyGenerator
 from cachekit.serializers.base import (
@@ -76,16 +79,6 @@ def get_backend_provider():
     return container.get(BackendProviderInterface)
 
 
-def redact_cache_key(cache_key: object) -> str:
-    """Redact a cache key for log/error messages.
-
-    Cache keys can embed caller-supplied tenant/user identifiers, so they must never reach
-    logs verbatim (issue #163). A fixed-length blake2b digest keeps messages correlatable
-    across the sync and async cache-set failure paths without leaking the key itself.
-    """
-    return f"<redacted:{hashlib.blake2b(str(cache_key).encode('utf-8'), digest_size=8).hexdigest()}>"
-
-
 # Lazy logger initialization to avoid import-time container access
 _logger = None
 
@@ -1256,7 +1249,7 @@ def _notify_deserialize_error(self, error: Exception, cache_key: str) -> None:
         try:
             self.on_deserialize_error(error, cache_key)
         except Exception as hook_err:  # observability must never break the miss path
-            get_logger().warning(f"on_deserialize_error hook failed for {cache_key}: {hook_err}")
+            get_logger().warning(f"on_deserialize_error hook failed for {redact_cache_key(cache_key)}: {hook_err}")
 
     def get_cache_key(
         self,
@@ -1382,7 +1375,7 @@ def get_cached_value(self, cache_key: str, refresh_ttl: Optional[int] = None) ->
             self._handle_l2_read_error(e, cache_key)  # raises when fail-closed (LAB-108)
             return None
         except Exception as e:
-            get_logger().warning(f"Backend operation failed for get on {cache_key}: {e}")
+            get_logger().warning(f"Backend operation failed for get on {redact_cache_key(cache_key)}: {e}")
             return None
 
     def get_cached_value_with_freshness(self, cache_key: str) -> Optional[tuple[tuple[bool, Any], bool]]:
@@ -1502,7 +1495,7 @@ async def get_cached_value_async(self, cache_key: str, refresh_ttl: Optional[int
             await self._handle_l2_read_error_async(e, cache_key)  # raises when fail-closed (LAB-108)
             return None
         except Exception as e:
-            get_logger().warning(f"Backend operation failed for get on {cache_key}: {e}")
+            get_logger().warning(f"Backend operation failed for get on {redact_cache_key(cache_key)}: {e}")
             return None
 
     def store_result(
@@ -1714,9 +1707,9 @@ def invalidate_cache(
             self._backend.delete(cache_key)
             get_logger().cache_invalidated(cache_key, "Backend")
         except BackendError as e:
-            get_logger().error(f"Backend operation failed for invalidation on {cache_key}: {e}")
+            get_logger().error(f"Backend operation failed for invalidation on {redact_cache_key(cache_key)}: {e}")
         except Exception as e:
-            get_logger().error(f"Unexpected error invalidating {cache_key}: {e}")
+            get_logger().error(f"Unexpected error invalidating {redact_cache_key(cache_key)}: {e}")
 
     async def invalidate_cache_async(
         self,
@@ -1746,9 +1739,9 @@ async def invalidate_cache_async(
             self._backend.delete(cache_key)
             get_logger().cache_invalidated(cache_key, "Backend")
         except BackendError as e:
-            get_logger().error(f"Backend operation failed for invalidation on {cache_key}: {e}")
+            get_logger().error(f"Backend operation failed for invalidation on {redact_cache_key(cache_key)}: {e}")
         except Exception as e:
-            get_logger().error(f"Unexpected error invalidating {cache_key}: {e}")
+            get_logger().error(f"Unexpected error invalidating {redact_cache_key(cache_key)}: {e}")
 
 
 @runtime_checkable
@@ -1915,12 +1908,12 @@ async def _maybe_refresh_ttl(self, key: str, refresh_ttl: int) -> None:
             if remaining_ttl is not None and remaining_ttl < refresh_ttl * self.ttl_refresh_threshold:
                 await self.backend.refresh_ttl(key, refresh_ttl)
                 get_logger().debug(
-                    f"Refreshed TTL for {key}: {refresh_ttl}s "
+                    f"Refreshed TTL for {redact_cache_key(key)}: {refresh_ttl}s "
                     f"(remaining: {remaining_ttl}s, threshold: {self.ttl_refresh_threshold})"
                 )
         except Exception as e:
             # Log but don't fail the cache operation
-            get_logger().debug(f"Failed to refresh TTL for {key}: {e}")
+            get_logger().debug(f"Failed to refresh TTL for {redact_cache_key(key)}: {e}")
 
     def get(self, key: str, refresh_ttl: Optional[int] = None) -> Optional[bytes]:
         """Get value from cache using backend.
@@ -1941,10 +1934,10 @@ def get(self, key: str, refresh_ttl: Optional[int] = None) -> Optional[bytes]:
 
             return value
         except BackendError as e:
-            get_logger().error(f"Backend error getting key {key}: {e}")
+            get_logger().error(f"Backend error getting key {redact_cache_key(key)}: {e}")
             return None
         except Exception as e:
-            get_logger().error(f"Unexpected error getting key {key}: {e}")
+            get_logger().error(f"Unexpected error getting key {redact_cache_key(key)}: {e}")
             return None
 
     def get_buffer(self, key: str) -> Optional[BufferHandle]:
@@ -1958,10 +1951,10 @@ def get_buffer(self, key: str) -> Optional[BufferHandle]:
         try:
             return self._with_backpressure_and_timeout(self.backend.get_buffer, key)
         except BackendError as e:
-            get_logger().error(f"Backend error mmapping key {key}: {e}")
+            get_logger().error(f"Backend error mmapping key {redact_cache_key(key)}: {e}")
             return None
         except Exception as e:
-            get_logger().error(f"Unexpected error mmapping key {key}: {e}")
+            get_logger().error(f"Unexpected error mmapping key {redact_cache_key(key)}: {e}")
             return None
 
     def get_with_freshness(self, key: str) -> Optional[tuple[bytes, bool]]:
@@ -2024,10 +2017,10 @@ def set(
                 self._with_backpressure_and_timeout(self.backend.set, key, value, ttl)
             return True
         except BackendError as e:
-            get_logger().error(f"Backend error setting key {key}: {e}")
+            get_logger().error(f"Backend error setting key {redact_cache_key(key)}: {e}")
             return False
         except Exception as e:
-            get_logger().error(f"Unexpected error setting key {key}: {e}")
+            get_logger().error(f"Unexpected error setting key {redact_cache_key(key)}: {e}")
             return False
 
     def set_streaming(self, key: str, write_payload: Callable[[BinaryIO], None], ttl: Optional[int] = None) -> Optional[bool]:
@@ -2083,10 +2076,10 @@ def delete(self, key: str) -> bool:
         try:
             return self._with_backpressure_and_timeout(self.backend.delete, key)
         except BackendError as e:
-            get_logger().error(f"Backend error deleting key {key}: {e}")
+            get_logger().error(f"Backend error deleting key {redact_cache_key(key)}: {e}")
             return False
         except Exception as e:
-            get_logger().error(f"Unexpected error deleting key {key}: {e}")
+            get_logger().error(f"Unexpected error deleting key {redact_cache_key(key)}: {e}")
             return False
 
     async def _with_backpressure_and_timeout_async(self, operation, *args, **kwargs):
@@ -2120,10 +2113,10 @@ async def get_async(self, key: str, refresh_ttl: Optional[int] = None) -> Option
 
             return value
         except BackendError as e:
-            get_logger().error(f"Backend error getting key {key}: {e}")
+            get_logger().error(f"Backend error getting key {redact_cache_key(key)}: {e}")
             return None
         except Exception as e:
-            get_logger().error(f"Unexpected error getting key {key}: {e}")
+            get_logger().error(f"Unexpected error getting key {redact_cache_key(key)}: {e}")
             return None
 
     async def set_async(
@@ -2147,10 +2140,10 @@ async def set_async(
                 await self._with_backpressure_and_timeout_async(self.backend.set, key, value, ttl)
             return True
         except BackendError as e:
-            get_logger().error(f"Backend error setting key {key}: {e}")
+            get_logger().error(f"Backend error setting key {redact_cache_key(key)}: {e}")
             return False
         except Exception as e:
-            get_logger().error(f"Unexpected error setting key {key}: {e}")
+            get_logger().error(f"Unexpected error setting key {redact_cache_key(key)}: {e}")
             return False
 
     async def delete_async(self, key: str) -> bool:
@@ -2162,8 +2155,8 @@ async def delete_async(self, key: str) -> bool:
             # Run sync backend operation in thread pool
             return await self._with_backpressure_and_timeout_async(self.backend.delete, key)
         except BackendError as e:
-            get_logger().error(f"Backend error deleting key {key}: {e}")
+            get_logger().error(f"Backend error deleting key {redact_cache_key(key)}: {e}")
             return False
         except Exception as e:
-            get_logger().error(f"Unexpected error deleting key {key}: {e}")
+            get_logger().error(f"Unexpected error deleting key {redact_cache_key(key)}: {e}")
             return False