Skip to content

Commit 98d616e

Browse files
authored
refactor(logging)!: remove dead compat surface and Redis branding from StructuredLogger (LAB-4621) (#316)
`StructuredLogger` kept a compatibility surface that no production code reached, and a log-writer thread still named after Redis even though LAB-4617 made the class backend-agnostic. ## Removed Each verified zero-caller in `src/`: | Symbol | Why it is dead | | --- | --- | | `serialization_fallback` | no caller anywhere | | `create_span`, `SimpleSpan` | `features.create_span(...)` in `decorators/wrapper.py` binds to `FeatureOrchestrator.create_span`, which is untouched | | `redis_operation_failed`, `cache_hit`, `cache_miss`, `cache_stored` | the whole `# Compatibility methods for tests` block | The `cache_hit` / `cache_miss` / `cache_stored` that `cache_handler.get_logger()` calls belong to `backends.provider.SimpleLogger` — a different class, reached through the DI container. Those call sites pass `source` and `ttl` **positionally**, which `StructuredLogger`'s `(key, **kwargs)` signature would reject with a `TypeError`; that signature mismatch is the proof the binding goes elsewhere. `SimpleLogger` is unchanged and keeps its own redaction tests. Thread name `RedisCache-LogWriter` → `cachekit-LogWriter`, so `grep -rni redis src/cachekit/logging.py` is now empty. ## The deleted tests lose no coverage `test_redis_operation_failed_override` pinned a CWE-532 guarantee: an exception object passed as `error=` must render key-free. That guarantee is already pinned — better — by `TestErrorKwargSanitisedAtSink::test_logging_sink`, which drives `cache_operation` through a live `caplog` sink instead of a mocked `Logger.log`, asserts over the whole payload instead of one field, and uses an exception whose message embeds the raw key instead of an inert literal. Verified by mutation rather than by reading: replacing the sink's `redact_error_for_log` with `str()` makes that test fail on both exception shapes, then reverted. The surviving docstring is corrected — it named `redis_operation_failed` as one of three in-tree `error=` callers; two remain, and the raw-exception case stays as defence in depth because `cache_operation` takes `**kwargs`. ## Breaking `cachekit.logging.SimpleSpan` was a top-level importable name in v0.18.0 and importing it now raises `ImportError`; the six removed methods now raise `AttributeError`. No deprecation aliases — same removal shape as the PII-masking knobs (LAB-3797) and `L1CacheConfig.namespace_index` in v0.18.0. Callers wanting these events should call `cache_operation` directly. ## Verification - `uv run ruff check src/ tests/`, `uv run ruff format --check src/ tests/` — clean - `uv run pytest tests/unit tests/critical -q -m "not slow"` — 2600 passed, 23 skipped - `tests/unit/test_log_redaction_architecture.py` still passes - Docs: no public doc surface named any removed symbol (`docs/`, `README.md`, `llms.txt`, `SECURITY.md`, `CONTRIBUTING.md` all grep clean), so no docs change was needed Closes LAB-4621
1 parent 2f7c979 commit 98d616e

3 files changed

Lines changed: 10 additions & 123 deletions

File tree

‎src/cachekit/logging.py‎

Lines changed: 1 addition & 59 deletions
Original file line numberDiff line numberDiff line change
@@ -113,7 +113,7 @@ class AsyncLogWriter(threading.Thread):
113113
"""Background thread for async log writing."""
114114

115115
def __init__(self, buffer: LockFreeRingBuffer):
116-
super().__init__(daemon=True, name="RedisCache-LogWriter")
116+
super().__init__(daemon=True, name="cachekit-LogWriter")
117117
self.buffer = buffer
118118
self.running = True
119119
self._stop_event = threading.Event()
@@ -414,70 +414,12 @@ def _get_context(self) -> dict[str, Any]:
414414
context["correlation_id"] = self._context.correlation_id
415415
return context
416416

417-
# Compatibility methods for tests
418-
def redis_operation_failed(self, operation: str, key: str, error: Exception, **kwargs):
419-
"""Log Redis operation failure. ``cache_operation`` renders the error key-free (CWE-532)."""
420-
self.cache_operation(operation, key, error=error, error_type=type(error).__name__, **kwargs)
421-
422-
def cache_hit(self, key: str, **kwargs):
423-
"""Log cache hit."""
424-
self.cache_operation("get", key, hit=True, **kwargs)
425-
426-
def cache_miss(self, key: str, **kwargs):
427-
"""Log cache miss."""
428-
self.cache_operation("get", key, hit=False, **kwargs)
429-
430-
def cache_stored(self, key: str, **kwargs):
431-
"""Log cache store operation."""
432-
self.cache_operation("set", key, **kwargs)
433-
434-
def serialization_fallback(self, from_serializer: str, to_serializer: str, reason: str, **kwargs):
435-
"""Log serialization fallback event."""
436-
437-
# Log the fallback
438-
self.warning(
439-
f"Serialization fallback: {from_serializer} -> {to_serializer}",
440-
from_serializer=from_serializer,
441-
to_serializer=to_serializer,
442-
reason=reason,
443-
**kwargs,
444-
)
445-
446-
def create_span(self, name: str, **kwargs):
447-
"""Create a simple tracing span context manager."""
448-
return SimpleSpan(self, name, **kwargs)
449-
450417
def __del__(self):
451418
"""Cleanup on deletion."""
452419
if hasattr(self, "writer"):
453420
self.writer.stop()
454421

455422

456-
class SimpleSpan:
457-
"""Simple span implementation for tracing integration."""
458-
459-
def __init__(self, logger: StructuredLogger, name: str, **kwargs):
460-
self.logger = logger
461-
self.name = name
462-
self.kwargs = kwargs
463-
self.start_time = None
464-
465-
def __enter__(self):
466-
"""Start the span."""
467-
self.start_time = time.time()
468-
# Generate a simple trace ID if not set
469-
if not hasattr(self.logger._context, "trace_id") or not self.logger._context.trace_id:
470-
trace_id = f"span-{int(time.time() * 1000000)}"
471-
self.logger.set_trace_id(trace_id)
472-
return self
473-
474-
def __exit__(self, exc_type, exc_val, exc_tb):
475-
"""End the span."""
476-
if self.start_time:
477-
duration = time.time() - self.start_time
478-
self.logger.debug(f"Span completed: {self.name}", span_name=self.name, duration_ms=duration * 1000, **self.kwargs)
479-
480-
481423
# Global logger instances cache
482424
_logger_instances: dict[str, StructuredLogger] = {}
483425
_logger_lock = threading.Lock()

‎tests/unit/test_error_path_key_redaction.py‎

Lines changed: 9 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -285,10 +285,9 @@ async def test_async_get_failure_redacts_key_in_exception_text(self, caplog: pyt
285285

286286

287287
class TestStructuredLoggerCacheOperationRedaction:
288-
"""``StructuredLogger.cache_operation`` is a direct sink.
288+
"""``StructuredLogger.cache_operation`` is the only structured sink on the class.
289289
290-
``cache_hit``/``cache_miss``/``cache_stored`` all funnel through it, so this
291-
one method is the whole surface. It must apply the *same* pass-through policy
290+
It must apply the *same* pass-through policy
292291
as the orchestrator sink: a value that arrives already redacted, or is a known
293292
sentinel, is emitted verbatim. Hashing it a second time would mint a different
294293
digest for the same key and break correlation between the two sinks
@@ -409,11 +408,13 @@ def test_arbitrary_exception_reduced_to_type_name(self) -> None:
409408
class TestErrorKwargSanitisedAtSink:
410409
"""An ``error`` kwarg is sanitised once, at each structured sink (CWE-532, defence in depth).
411410
412-
Three in-tree callers, three shapes: ``handle_cache_error`` pre-renders to a str,
413-
``redis_operation_failed`` passes the exception object, and the circuit-breaker path
414-
in ``wrapper.py`` passes a str literal. The sink must emit all three key-free, and a
415-
str must pass through untouched (re-sanitising one would emit the literal ``"str"``).
416-
The assertion runs over the whole payload, not the ``error`` field alone.
411+
Two in-tree callers, both str: ``handle_cache_error`` pre-renders via
412+
``redact_error_for_log``, and the circuit-breaker path in ``wrapper.py`` passes a str
413+
literal. The raw-exception shape is kept as defence in depth — ``cache_operation``
414+
takes ``**kwargs``, so nothing stops a future caller handing it an exception object,
415+
and the sink must render that key-free too. A str must pass through untouched
416+
(re-sanitising one would emit the literal ``"str"``). The assertion runs over the
417+
whole payload, not the ``error`` field alone.
417418
"""
418419

419420
@pytest.mark.parametrize(("error", "rendered"), ERROR_KWARGS)

‎tests/unit/test_structured_logging.py‎

Lines changed: 0 additions & 56 deletions
Original file line numberDiff line numberDiff line change
@@ -8,7 +8,6 @@
88

99
import pytest
1010

11-
from cachekit.backends.errors import BackendError, BackendErrorType
1211
from cachekit.logging import (
1312
JsonFormatter,
1413
StructuredLogger,
@@ -116,61 +115,6 @@ def test_cache_operation_error_logging(self, mock_log, logger):
116115
assert extra["error"] == "Connection timeout"
117116
assert extra["error_type"] == "TimeoutError"
118117

119-
@pytest.mark.parametrize(
120-
("error", "rendered", "error_type"),
121-
[
122-
(ValueError("Test error"), "ValueError", "ValueError"),
123-
(BackendError("Redis timeout", error_type=BackendErrorType.TIMEOUT), "BackendError(timeout)", "BackendError"),
124-
],
125-
ids=["provider_exception", "backend_error"],
126-
)
127-
@patch("cachekit.logging.logging.Logger.log")
128-
def test_redis_operation_failed_override(self, mock_log, logger, error, rendered, error_type):
129-
"""redis_operation_failed emits a key-free error representation (CWE-532).
130-
131-
A non-BackendError's str() has unknown provenance and may echo the raw cache
132-
key, so only its type name reaches the log; a BackendError renders as
133-
``TypeName(error_type)``. error_type still carries the Python type.
134-
"""
135-
logger.redis_operation_failed("get", "test_key", error)
136-
137-
mock_log.assert_called_once()
138-
extra = mock_log.call_args[1]["extra"]["structured"]
139-
assert extra["operation"] == "get"
140-
assert extra["error"] == rendered # never the raw message
141-
assert extra["error_type"] == error_type
142-
143-
@patch("cachekit.logging.logging.Logger.log")
144-
def test_cache_hit_override(self, mock_log, logger):
145-
"""Test cache_hit override."""
146-
logger.cache_hit("test_key", source="memory")
147-
148-
mock_log.assert_called_once()
149-
extra = mock_log.call_args[1]["extra"]["structured"]
150-
assert extra["operation"] == "get"
151-
assert extra["hit"] is True
152-
assert extra["source"] == "memory"
153-
154-
@patch("cachekit.logging.logging.Logger.log")
155-
def test_cache_miss_override(self, mock_log, logger):
156-
"""Test cache_miss override."""
157-
logger.cache_miss("test_key")
158-
159-
mock_log.assert_called_once()
160-
extra = mock_log.call_args[1]["extra"]["structured"]
161-
assert extra["operation"] == "get"
162-
assert extra["hit"] is False
163-
164-
@patch("cachekit.logging.logging.Logger.log")
165-
def test_cache_stored_override(self, mock_log, logger):
166-
"""Test cache_stored override."""
167-
logger.cache_stored("test_key", ttl=300)
168-
169-
mock_log.assert_called_once()
170-
extra = mock_log.call_args[1]["extra"]["structured"]
171-
assert extra["operation"] == "set"
172-
assert extra["ttl"] == 300
173-
174118
def test_thread_safety(self, logger):
175119
"""Test thread-local context isolation."""
176120
results = {}

0 commit comments

Comments
 (0)