From 942a46ffd7793ca1c535bf73ae1c8f3366976617 Mon Sep 17 00:00:00 2001 From: "devin-ai-integration[bot]" <158243242+devin-ai-integration[bot]@users.noreply.github.com> Date: Thu, 3 Sep 2026 22:18:20 +0000 Subject: [PATCH] fix(caching): don't trip redis circuit breaker on short timeout bursts (#38999) * fix(caching): don't trip redis circuit breaker on short timeout bursts Co-Authored-By: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com> * fix(caching): scope timeout duration gate to timeout failures and count breaker states per label Co-Authored-By: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com> * fix(caching): reset the timeout streak on hard failures so stale timeouts cannot pre-age the duration gate Co-Authored-By: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com> --------- Co-authored-by: yassin Co-authored-by: Devin AI <158243242+devin-ai-integration[bot]@users.noreply.github.com> --- litellm/caching/redis_cache.py | 142 +++++++++++++++-- litellm/constants.py | 3 + .../test_litellm/caching/test_redis_cache.py | 150 +++++++++++++++++- 3 files changed, 284 insertions(+), 11 deletions(-) diff --git a/litellm/caching/redis_cache.py b/litellm/caching/redis_cache.py index 58733b384b9..aaee7188d86 100644 --- a/litellm/caching/redis_cache.py +++ b/litellm/caching/redis_cache.py @@ -27,6 +27,7 @@ from litellm.constants import ( REDIS_CIRCUIT_BREAKER_ENABLED, REDIS_CIRCUIT_BREAKER_FAILURE_THRESHOLD, REDIS_CIRCUIT_BREAKER_RECOVERY_TIMEOUT, + REDIS_CIRCUIT_BREAKER_TIMEOUT_MIN_DURATION, ) from litellm.litellm_core_utils.core_helpers import _get_parent_otel_span_from_kwargs from litellm.litellm_core_utils.coroutine_checker import coroutine_checker @@ -41,6 +42,8 @@ from .base_cache import BaseCache if TYPE_CHECKING: from opentelemetry.trace import Span as _Span + from prometheus_client import Counter as _PromCounter + from prometheus_client import Gauge as _PromGauge from redis.asyncio import Redis, RedisCluster from redis.asyncio.client import Pipeline from redis.asyncio.cluster import ClusterPipeline @@ -135,10 +138,20 @@ class RedisCircuitBreaker: HALF_OPEN - recovery probe: allow one request through Transitions: - CLOSED -> OPEN after failure_threshold consecutive failures + CLOSED -> OPEN after failure_threshold consecutive hard connectivity + failures, or after an unbroken run of timeout failures + (no success or hard failure in between) that reaches + failure_threshold and spans timeout_min_duration seconds OPEN -> HALF_OPEN after recovery_timeout seconds HALF_OPEN -> CLOSED on success HALF_OPEN -> OPEN on failure (resets timer) + + Timeouts are accounted separately from hard connectivity failures because the async + Redis timeout includes time waiting for the worker event loop to resume: one loop + stall makes every in-flight operation time out together, which satisfies a purely + consecutive threshold instantly even though Redis is healthy. Requiring a + timeout-only streak to also span timeout_min_duration filters such bursts while a + real outage that surfaces as timeouts still opens the breaker after that duration. """ CLOSED = "closed" @@ -150,13 +163,19 @@ class RedisCircuitBreaker: failure_threshold: int, recovery_timeout: int, enabled: bool = True, + timeout_min_duration: float = REDIS_CIRCUIT_BREAKER_TIMEOUT_MIN_DURATION, ) -> None: self.failure_threshold = failure_threshold self.recovery_timeout = recovery_timeout self.enabled = enabled + self.timeout_min_duration = timeout_min_duration self._failure_count = 0 + self._hard_failure_count = 0 + self._timeout_count = 0 + self._timeout_streak_started_at: float | None = None self._opened_at: float | None = None self._state = self.CLOSED + _breaker_metrics().record_state_change(None, self._state) def is_open(self) -> bool: """Returns True if Redis calls should be skipped.""" @@ -169,24 +188,45 @@ class RedisCircuitBreaker: return True if self._state == self.OPEN: if time.time() - (self._opened_at or 0) > self.recovery_timeout: - self._state = self.HALF_OPEN + self._set_state(self.HALF_OPEN) return False # this caller is the designated probe return True return False - def record_failure(self) -> None: + def _should_open(self, now: float) -> bool: + if self._state == self.HALF_OPEN: + return True + if self._hard_failure_count >= self.failure_threshold: + return True + if self._timeout_count < self.failure_threshold: + return False + return now - (self._timeout_streak_started_at or now) >= self.timeout_min_duration + + def record_failure(self, is_timeout: bool = False) -> None: if not self.enabled: return + now: Final = time.time() self._failure_count += 1 - self._opened_at = time.time() - if self._failure_count >= self.failure_threshold: + if is_timeout: + self._timeout_count += 1 + if self._timeout_streak_started_at is None: + self._timeout_streak_started_at = now + else: + self._hard_failure_count += 1 + self._timeout_count = 0 + self._timeout_streak_started_at = None + self._opened_at = now + _breaker_metrics().record_failure("timeout" if is_timeout else "connectivity") + if self._should_open(now): if self._state != self.OPEN: verbose_logger.warning( - "Redis circuit breaker OPENED after %d consecutive failures — fast-failing Redis calls for %ds", + "Redis circuit breaker OPENED after %d consecutive failures" + " (%d hard connectivity) — fast-failing Redis calls for %ds", self._failure_count, + self._hard_failure_count, self.recovery_timeout, ) - self._state = self.OPEN + self._set_state(self.OPEN) def record_success(self) -> None: if not self.enabled: @@ -194,7 +234,17 @@ class RedisCircuitBreaker: if self._state == self.HALF_OPEN: verbose_logger.info("Redis circuit breaker CLOSED — Redis recovered") self._failure_count = 0 - self._state = self.CLOSED + self._hard_failure_count = 0 + self._timeout_count = 0 + self._timeout_streak_started_at = None + self._set_state(self.CLOSED) + + def _set_state(self, state: str) -> None: + if state == self._state: + return + _breaker_metrics().record_transition(state) + _breaker_metrics().record_state_change(self._state, state) + self._state = state _RedisCallResult = TypeVar("_RedisCallResult") @@ -234,6 +284,78 @@ def _is_redis_health_failure(exc: BaseException) -> bool: return True +@functools.lru_cache(maxsize=1) +def _redis_timeout_error_types() -> tuple[type, ...]: + """Health failures that are timeouts rather than unambiguous connectivity errors. + + ``builtins.TimeoutError`` covers ``asyncio.TimeoutError`` and ``socket.timeout`` + (aliases since py3.11 / py3.10). ``redis.exceptions.TimeoutError`` does not subclass + either, so it is listed explicitly. + """ + try: + from redis.exceptions import TimeoutError as RedisTimeoutError + except ImportError: + return (TimeoutError,) + return (RedisTimeoutError, TimeoutError) + + +def _is_redis_timeout_failure(exc: BaseException) -> bool: + return isinstance(exc, _redis_timeout_error_types()) + + +class _BreakerMetrics: + """Prometheus metrics for the Redis circuit breaker; no-ops when the client is absent. + + Registered lazily on the default registry (which /metrics serves) via the module-level + ``_breaker_metrics`` singleton so repeated RedisCache construction never re-registers. + """ + + def __init__(self) -> None: + self._state_gauge: _PromGauge | None = None + self._transitions: _PromCounter | None = None + self._failures: _PromCounter | None = None + try: + from prometheus_client import Counter as PromCounter + from prometheus_client import Gauge + except ImportError: + return + self._state_gauge = Gauge( + "litellm_redis_circuit_breaker_state", + "Number of Redis circuit breakers currently in each state", + labelnames=("state",), + ) + self._transitions = PromCounter( + "litellm_redis_circuit_breaker_transitions", + "Redis circuit breaker state transitions", + labelnames=("state",), + ) + self._failures = PromCounter( + "litellm_redis_circuit_breaker_failures", + "Redis health failures counted by the circuit breaker", + labelnames=("failure_class",), + ) + + def record_state_change(self, old_state: str | None, new_state: str) -> None: + if self._state_gauge is None: + return + if old_state is not None: + self._state_gauge.labels(old_state).dec() + self._state_gauge.labels(new_state).inc() + + def record_transition(self, state: str) -> None: + if self._transitions is not None: + self._transitions.labels(state).inc() + + def record_failure(self, failure_class: str) -> None: + if self._failures is not None: + self._failures.labels(failure_class).inc() + + +@functools.lru_cache(maxsize=1) +def _breaker_metrics() -> _BreakerMetrics: + return _BreakerMetrics() + + def _record_swallowed_redis_failure(breaker: RedisCircuitBreaker, exc: BaseException) -> None: """Record a Redis failure that the calling method is about to swallow. @@ -245,7 +367,7 @@ def _record_swallowed_redis_failure(breaker: RedisCircuitBreaker, exc: BaseExcep """ if not _is_redis_health_failure(exc): return - breaker.record_failure() + breaker.record_failure(is_timeout=_is_redis_timeout_failure(exc)) _swallowed_redis_failures.set(_swallowed_redis_failures.get() + 1) @@ -281,7 +403,7 @@ async def _run_under_circuit_breaker( result: Final = await call() except Exception as e: if _is_redis_health_failure(e): - breaker.record_failure() + breaker.record_failure(is_timeout=_is_redis_timeout_failure(e)) raise _exit_circuit_breaker(breaker, swallowed_before) return result diff --git a/litellm/constants.py b/litellm/constants.py index f5acadc32ab..cd72adc3db5 100644 --- a/litellm/constants.py +++ b/litellm/constants.py @@ -432,6 +432,9 @@ REDIS_CONNECTION_POOL_TIMEOUT: Final = int(os.getenv("REDIS_CONNECTION_POOL_TIME REDIS_CIRCUIT_BREAKER_FAILURE_THRESHOLD: Final = int(os.getenv("REDIS_CIRCUIT_BREAKER_FAILURE_THRESHOLD", 5)) REDIS_CIRCUIT_BREAKER_RECOVERY_TIMEOUT: Final = int(os.getenv("REDIS_CIRCUIT_BREAKER_RECOVERY_TIMEOUT", 60)) REDIS_CIRCUIT_BREAKER_ENABLED: Final = os.getenv("REDIS_CIRCUIT_BREAKER_ENABLED", "true").lower() == "true" +# minimum seconds a timeout-only failure streak must span before it can open the breaker, +# so one event-loop stall timing out many queued calls at once does not trip it +REDIS_CIRCUIT_BREAKER_TIMEOUT_MIN_DURATION: Final = float(os.getenv("REDIS_CIRCUIT_BREAKER_TIMEOUT_MIN_DURATION", 5.0)) # Seconds of idle before a Redis cluster connection is validated with a PING and # reconnected if dead, so a connection silently dropped by a cluster restart # (e.g. ElastiCache Serverless maintenance) is not reused while broken diff --git a/tests/test_litellm/caching/test_redis_cache.py b/tests/test_litellm/caching/test_redis_cache.py index 71be8730df1..e4724ff8705 100644 --- a/tests/test_litellm/caching/test_redis_cache.py +++ b/tests/test_litellm/caching/test_redis_cache.py @@ -779,7 +779,7 @@ async def test_concurrent_success_is_not_cancelled_by_another_calls_failure(): "error, opens_breaker", [ pytest.param("ConnectionError", True, id="connection_refused_is_unhealthy"), - pytest.param("TimeoutError", True, id="timeout_is_unhealthy"), + pytest.param("TimeoutError", False, id="timeout_burst_is_ambiguous"), pytest.param("BusyLoadingError", True, id="loading_is_unhealthy"), pytest.param("ResponseError", False, id="wrong_type_command_is_not"), pytest.param("DataError", False, id="bad_data_is_not"), @@ -791,6 +791,10 @@ async def test_only_connectivity_failures_open_the_breaker(error, opens_breaker) They say nothing about connectivity, and a caller able to provoke them (an INCR against a non-numeric value, say) could otherwise trip the shared breaker on demand and drop rate limiting to per-process counters, which spreading traffic across replicas outruns. + + A rapid burst of timeouts is ambiguous too: the async timeout includes event-loop + scheduling delay, so a loop stall times out every queued call at once against a + healthy Redis. It must not open the breaker until the streak spans a minimum duration. """ import redis.exceptions @@ -810,3 +814,147 @@ async def test_only_connectivity_failures_open_the_breaker(error, opens_breaker) await _run_under_circuit_breaker(breaker, "op", failing_call) assert breaker.is_open() is opens_breaker + + +@pytest.mark.asyncio +async def test_event_loop_stall_timeout_burst_keeps_breaker_closed(): + """One blocking stall of the worker event loop must not trip the breaker. + + Every operation already waiting on the loop times out together when the loop resumes, + so a purely consecutive threshold is satisfied instantly even though the Redis on the + other end (here an in-process fake that answers immediately) is healthy. + """ + import time as time_mod + + from litellm.caching.redis_cache import RedisCircuitBreaker, _run_under_circuit_breaker + + breaker = RedisCircuitBreaker(failure_threshold=3, recovery_timeout=60, timeout_min_duration=5.0) + + async def healthy_redis_call_with_client_timeout(): + return await asyncio.wait_for(asyncio.sleep(0.001, result="ok"), timeout=0.05) + + async def stall_the_loop(): + await asyncio.sleep(0) + time_mod.sleep(0.2) + + results = await asyncio.gather( + *(_run_under_circuit_breaker(breaker, "op", healthy_redis_call_with_client_timeout) for _ in range(8)), + stall_the_loop(), + return_exceptions=True, + ) + timeouts = [r for r in results if isinstance(r, asyncio.TimeoutError)] + assert len(timeouts) >= breaker.failure_threshold, "the stall must time out a full burst" + + assert breaker.is_open() is False, "a healthy Redis behind one loop stall must stay in the pool" + assert await _run_under_circuit_breaker(breaker, "op", healthy_redis_call_with_client_timeout) == "ok" + + +@pytest.mark.asyncio +async def test_persistent_timeouts_still_open_the_breaker(): + """A real outage that surfaces only as timeouts must still open the breaker. + + Once the timeout-only streak spans the minimum duration with no success in between, + Redis is genuinely unusable from this worker and protection has to kick in. + """ + from redis.exceptions import TimeoutError as RedisTimeoutError + + from litellm.caching.redis_cache import RedisCircuitBreaker, _run_under_circuit_breaker + + breaker = RedisCircuitBreaker(failure_threshold=3, recovery_timeout=60, timeout_min_duration=0.1) + + async def timing_out_call(): + raise RedisTimeoutError("read timed out") + + for _ in range(breaker.failure_threshold): + with pytest.raises(RedisTimeoutError): + await _run_under_circuit_breaker(breaker, "op", timing_out_call) + assert breaker.is_open() is False, "the burst has not spanned the minimum duration yet" + + await asyncio.sleep(0.12) + with pytest.raises(RedisTimeoutError): + await _run_under_circuit_breaker(breaker, "op", timing_out_call) + + assert breaker.is_open() is True + + +@pytest.mark.asyncio +async def test_stale_timeout_does_not_let_sub_threshold_hard_failures_open_the_breaker(): + """Hard connectivity failures below the threshold must not open the breaker just + because an old timeout already started the streak and the duration has elapsed. + + Each class has to earn the open on its own terms: hard failures by reaching the + threshold, timeouts by reaching the threshold and spanning the minimum duration. + """ + from redis.exceptions import ConnectionError as RedisConnectionError + from redis.exceptions import TimeoutError as RedisTimeoutError + + from litellm.caching.redis_cache import RedisCircuitBreaker, _is_redis_timeout_failure + + breaker = RedisCircuitBreaker(failure_threshold=3, recovery_timeout=60, timeout_min_duration=0.05) + + breaker.record_failure(is_timeout=_is_redis_timeout_failure(RedisTimeoutError("read timed out"))) + await asyncio.sleep(0.06) + for _ in range(breaker.failure_threshold - 1): + breaker.record_failure(is_timeout=_is_redis_timeout_failure(RedisConnectionError("refused"))) + assert breaker.is_open() is False, "2 hard failures and 1 stale timeout are below both thresholds" + + breaker.record_failure(is_timeout=_is_redis_timeout_failure(RedisConnectionError("refused"))) + assert breaker.is_open() is True, "the threshold-th hard failure must still open it" + + +@pytest.mark.asyncio +async def test_hard_failure_resets_timeout_streak_so_a_later_burst_must_earn_its_own_duration(): + """A stale timeout followed by hard failures must not pre-age the duration gate: + a later short timeout burst has to span timeout_min_duration on its own. + """ + from redis.exceptions import ConnectionError as RedisConnectionError + from redis.exceptions import TimeoutError as RedisTimeoutError + + from litellm.caching.redis_cache import RedisCircuitBreaker, _is_redis_timeout_failure + + breaker = RedisCircuitBreaker(failure_threshold=3, recovery_timeout=60, timeout_min_duration=0.05) + + breaker.record_failure(is_timeout=_is_redis_timeout_failure(RedisTimeoutError("read timed out"))) + breaker.record_failure(is_timeout=_is_redis_timeout_failure(RedisConnectionError("refused"))) + await asyncio.sleep(0.06) + for _ in range(breaker.failure_threshold): + breaker.record_failure(is_timeout=_is_redis_timeout_failure(RedisTimeoutError("read timed out"))) + assert breaker.is_open() is False, "the burst is instantaneous, so the duration gate must hold it closed" + + await asyncio.sleep(0.06) + breaker.record_failure(is_timeout=_is_redis_timeout_failure(RedisTimeoutError("read timed out"))) + assert breaker.is_open() is True, "the same run of timeouts persisting past the duration must open it" + + +@pytest.mark.asyncio +async def test_breaker_metrics_track_state_and_failure_class(): + """Breaker accounting must be observable: failure class, transitions, and state.""" + from prometheus_client import REGISTRY + from redis.exceptions import ConnectionError as RedisConnectionError + from redis.exceptions import TimeoutError as RedisTimeoutError + + from litellm.caching.redis_cache import RedisCircuitBreaker, _is_redis_timeout_failure + + def sample(name, labels=None): + return REGISTRY.get_sample_value(name, labels) or 0.0 + + timeout_before = sample("litellm_redis_circuit_breaker_failures_total", {"failure_class": "timeout"}) + hard_before = sample("litellm_redis_circuit_breaker_failures_total", {"failure_class": "connectivity"}) + opened_before = sample("litellm_redis_circuit_breaker_transitions_total", {"state": "open"}) + open_gauge_before = sample("litellm_redis_circuit_breaker_state", {"state": "open"}) + closed_gauge_before = sample("litellm_redis_circuit_breaker_state", {"state": "closed"}) + + breaker = RedisCircuitBreaker(failure_threshold=2, recovery_timeout=60, timeout_min_duration=5.0) + breaker.record_failure(is_timeout=_is_redis_timeout_failure(RedisTimeoutError("t"))) + breaker.record_failure(is_timeout=_is_redis_timeout_failure(RedisConnectionError("refused"))) + breaker.record_failure(is_timeout=_is_redis_timeout_failure(RedisConnectionError("refused"))) + + assert sample("litellm_redis_circuit_breaker_failures_total", {"failure_class": "timeout"}) == timeout_before + 1 + assert sample("litellm_redis_circuit_breaker_failures_total", {"failure_class": "connectivity"}) == hard_before + 2 + assert sample("litellm_redis_circuit_breaker_transitions_total", {"state": "open"}) == opened_before + 1 + assert sample("litellm_redis_circuit_breaker_state", {"state": "open"}) == open_gauge_before + 1 + assert sample("litellm_redis_circuit_breaker_state", {"state": "closed"}) == closed_gauge_before + + breaker.record_success() + assert sample("litellm_redis_circuit_breaker_state", {"state": "open"}) == open_gauge_before + assert sample("litellm_redis_circuit_breaker_state", {"state": "closed"}) == closed_gauge_before + 1