fix(caching): keep the sync Redis read and the top-level cache wrapper quiet when the breaker is open

The sync RedisCache.get_cache ran outside the breaker and logged with a stray positional
argument, so every failure printed a logging-module stack dump. Cache.add_cache and its
async twins logged a full traceback for the expected open-breaker fast fail

Co-Authored-By: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com>
This commit is contained in:
mateo 2026-09-10 21:45:46 +00:00
parent ad78a8f8d0
commit df8a9c72ab
6 changed files with 75 additions and 3 deletions

View file

@ -32,7 +32,7 @@ from .dual_cache import DualCache # noqa: F401
from .gcs_cache import GCSCache
from .in_memory_cache import InMemoryCache
from .qdrant_semantic_cache import QdrantSemanticCache
from .redis_cache import RedisCache
from .redis_cache import RedisCache, RedisCircuitBreakerOpenError
from .redis_cluster_cache import RedisClusterCache
from .redis_semantic_cache import RedisSemanticCache
from .s3_cache import S3Cache
@ -677,6 +677,8 @@ class Cache:
return
cache_key, cached_data, kwargs = self._add_cache_logic(result=result, **kwargs)
self.cache.set_cache(cache_key, cached_data, **kwargs)
except RedisCircuitBreakerOpenError as e:
verbose_logger.debug("LiteLLM Cache: skipped add_cache: %s", e)
except Exception as e:
verbose_logger.exception("LiteLLM Cache: Excepton add_cache: %s", e)
@ -696,6 +698,8 @@ class Cache:
await dynamic_cache_object.async_set_cache(cache_key, cached_data, **kwargs)
else:
await self.cache.async_set_cache(cache_key, cached_data, **kwargs)
except RedisCircuitBreakerOpenError as e:
verbose_logger.debug("LiteLLM Cache: skipped add_cache: %s", e)
except Exception as e:
verbose_logger.exception("LiteLLM Cache: Excepton add_cache: %s", e)
@ -875,6 +879,8 @@ class Cache:
await dynamic_cache_object.async_set_cache_pipeline(cache_list=cache_list, **kwargs)
else:
await self.cache.async_set_cache_pipeline(cache_list=cache_list, **kwargs)
except RedisCircuitBreakerOpenError as e:
verbose_logger.debug("LiteLLM Cache: skipped add_cache: %s", e)
except Exception as e:
verbose_logger.exception("LiteLLM Cache: Excepton add_cache: %s", e)

View file

@ -177,6 +177,8 @@ class DualCache(BaseCache):
print_verbose(f"get cache: cache result: {result}")
return result
except RedisCircuitBreakerOpenError:
return None
except Exception:
verbose_logger.error(traceback.format_exc())

View file

@ -1364,6 +1364,7 @@ class RedisCache(BaseCache):
except Exception:
return ast.literal_eval(decoded)
@_redis_circuit_breaker_guard_sync
def get_cache(self, key, parent_otel_span: Span | None = None, **kwargs):
try:
key = self.check_and_fix_namespace(key=key)
@ -1384,7 +1385,8 @@ class RedisCache(BaseCache):
return self._get_cache_logic(cached_response=cached_response)
except Exception as e:
# NON blocking - notify users Redis is throwing an exception
verbose_logger.error("litellm.caching.caching: get() - Got exception from REDIS: ", e)
verbose_logger.error("litellm.caching.caching: get() - Got exception from REDIS: %s", e)
_record_swallowed_redis_failure(self._circuit_breaker, e)
def _run_redis_mget_operation(self, keys: list[str]) -> Sequence[bytes | str | None]:
"""

View file

@ -252,3 +252,29 @@ def test_exact_cache_key_includes_anthropic_messages_params(anthropic_param):
assert baseline != cache.get_cache_key(
model="claude-sonnet-4-5", messages=messages, **anthropic_param
)
@pytest.mark.asyncio
async def test_async_add_cache_treats_an_open_breaker_as_a_quiet_skip(caplog):
"""The top-level write wrapper logs a full ERROR traceback for any failure. An open Redis
breaker fails every write instantly, so under load that wrapper alone was hundreds of
stack formats per second per replica. Unexpected failures must still get the traceback.
"""
from unittest.mock import AsyncMock
from litellm.caching.redis_cache import RedisCircuitBreakerOpenError
caplog.set_level(logging.DEBUG, logger="LiteLLM")
cache = Cache(type=LiteLLMCacheType.LOCAL)
cache.cache.async_set_cache = AsyncMock(side_effect=RedisCircuitBreakerOpenError("open"))
await cache.async_add_cache("result", model="gpt-5.4-nano", messages=[{"role": "user", "content": "hi"}])
assert [r.levelno for r in caplog.records if "add_cache" in r.getMessage()] == [logging.DEBUG]
cache.cache.async_set_cache.assert_awaited_once()
cache.cache.async_set_cache = AsyncMock(side_effect=OSError("disk full"))
await cache.async_add_cache("result", model="gpt-5.4-nano", messages=[{"role": "user", "content": "hi"}])
errors = [r for r in caplog.records if r.levelno == logging.ERROR]
assert len(errors) == 1 and errors[0].exc_info is not None

View file

@ -638,3 +638,18 @@ async def test_open_breaker_is_a_quiet_cache_miss(dual_cache_with_open_breaker,
noisy = [r for r in caplog.records if r.levelno > logging.DEBUG]
assert noisy == [], f"an open breaker must be silent per call, got {[r.getMessage() for r in noisy]}"
def test_open_breaker_is_a_quiet_cache_miss_on_the_sync_read_path(dual_cache_with_open_breaker, caplog):
"""The sync read runs in the request thread pool for /v1/messages and /v1/responses, so it
must short-circuit on an open breaker like the async path instead of dialing Redis per call.
"""
caplog.set_level(logging.DEBUG, logger="LiteLLM")
redis_client = dual_cache_with_open_breaker.redis_cache.redis_client
redis_client.get.side_effect = AssertionError("an open breaker must not touch Redis")
for _ in range(50):
assert dual_cache_with_open_breaker.get_cache("lit7468") is None
noisy = [r for r in caplog.records if r.levelno > logging.DEBUG]
assert noisy == [], f"an open breaker must be silent per call, got {[r.getMessage() for r in noisy]}"

View file

@ -1,4 +1,5 @@
import asyncio
import logging
from collections.abc import Iterator
from unittest.mock import AsyncMock, MagicMock, patch
@ -646,7 +647,6 @@ def test_sync_batch_get_cache_survives_a_service_callback_that_raises(
from concurrent.futures import ThreadPoolExecutor
import litellm
from litellm.constants import REDIS_CIRCUIT_BREAKER_FAILURE_THRESHOLD
cache, service_logger = sync_batch_cache_with_service_logger
@ -1141,3 +1141,24 @@ async def test_recovery_probe_still_closes_the_breaker():
await asyncio.sleep(0.06)
assert await _run_under_circuit_breaker(breaker, "probe", recovered) == "ok"
assert breaker.is_open() is False
def test_sync_get_cache_failure_feeds_the_breaker_and_logs_a_well_formed_record(sync_batch_redis_cache, caplog):
"""The sync read used to log with a stray positional arg, so every Redis failure produced a
`--- Logging error ---` stack dump on stderr, and it sat outside the breaker so it kept dialing
Redis on every request even after the async paths had opened it.
"""
from redis.exceptions import ConnectionError as RedisConnectionError
from litellm.constants import REDIS_CIRCUIT_BREAKER_FAILURE_THRESHOLD
caplog.set_level(logging.ERROR, logger="LiteLLM")
sync_batch_redis_cache.redis_client.get.side_effect = RedisConnectionError("refused")
for _ in range(REDIS_CIRCUIT_BREAKER_FAILURE_THRESHOLD):
assert sync_batch_redis_cache.get_cache("lit7468") is None
assert sync_batch_redis_cache._circuit_breaker.is_open() is True
assert sync_batch_redis_cache.redis_client.get.call_count == REDIS_CIRCUIT_BREAKER_FAILURE_THRESHOLD
assert all("refused" in record.getMessage() for record in caplog.records)
assert len(caplog.records) == REDIS_CIRCUIT_BREAKER_FAILURE_THRESHOLD