Skip to content

fix(redis): count pool wait timeouts as breaker timeouts - #40672

Closed
mateo-berri wants to merge 4 commits into
litellm_internal_stagingfrom
litellm_redis_pool_timeout_counts_as_timeout
Closed

mateo-berri wants to merge 4 commits into
litellm_internal_stagingfrom
litellm_redis_pool_timeout_counts_as_timeout

Conversation

@mateo-berri

@mateo-berri mateo-berri commented Sep 11, 2026 •

Copy link
Copy Markdown
Contributor

TLDR

Problem this solves:

  • A busy Redis pool opened the circuit breaker at once
  • Redis was healthy, yet caching went dark for 60 s
  • The pool wait error is a ConnectionError raised from a timeout

How it solves it:

  • Timeout classification now follows the exception's explicit cause chain
  • Pool waits count as timeouts, gated on the minimum duration
  • A refused or reset connection still opens the breaker at once
  • asyncio.TimeoutError is listed as a timeout explicitly, since on Python 3.10 it is not yet an alias of TimeoutError

User Flow

Before: an operator running two proxy instances with Redis caching sees caching go dark for a minute the moment a burst fills the Redis connection pool, even though Redis is healthy

  1. The operator runs two proxy instances, two workers each, with cache: true, cache_params.type: redis, max_connections: 2, and a 1 s pool wait timeout, both pointed at one Redis reached over a slow link
  2. Their clients send a burst of 300 POST https://litellm-domain/v1/chat/completions requests for haiku at 40-way concurrency, alternating between the two instances, and every one returns 200 with a fresh chatcmpl-... id
  3. Within a few seconds the proxy log on every worker prints the Redis circuit breaker OPENED after 5 consecutive failures (5 hard connectivity) warning and fast-fails Redis calls for 60 s, while redis-cli PING against that Redis keeps answering PONG
  4. Right after the burst they send the same prompt to instance A and then to instance B: both come back 200 with different chatcmpl-... ids and no x-litellm-cache-key header, so nothing is cached on any worker for the next 60 s

After: the same burst leaves the breaker closed, and a response cached through one instance is served by the other

  1. The operator runs two proxy instances, two workers each, with cache: true, cache_params.type: redis, max_connections: 2, and a 1 s pool wait timeout, both pointed at one Redis reached over a slow link
  2. Their clients send a burst of 300 POST https://litellm-domain/v1/chat/completions requests for haiku at 40-way concurrency, alternating between the two instances, and every one returns 200 with a fresh chatcmpl-... id
  3. The proxy log on every worker stays free of any Redis circuit breaker OPENED line, while redis-cli PING against that Redis keeps answering PONG
  4. Right after the burst they send the same prompt to instance A and then to instance B: A answers 200 with a fresh chatcmpl-... id, and B answers 200 with that same id plus an x-litellm-cache-key header, so the response cached through A came back from B

Relevant issues

None, tracked in Linear only

Linear ticket

Resolves LIT-7542

Pre-Submission checklist

Please complete all items before asking a LiteLLM maintainer to review your PR

  • I have added meaningful tests
  • The handful of test files covering my change pass locally, e.g. uv run pytest tests/test_litellm/<your_test_file>.py -v. Leave the suites (make test-unit-*, make test-unit) to CI: it finishes in ~15 minutes where a laptop takes an hour or more
  • My PR passes all required CI/CD checks (e.g., lint, schema.d.ts sync check, etc.)
  • My PR's scope is as isolated as possible; it only solves 1 specific problem
  • I have received a Greptile Confidence Score of at least 4/5 before requesting a maintainer review (Greptile reviews automatically once the PR is opened; only comment @greptileai to re-request a review after pushing changes)

Delays in PR merge?

If you're seeing a delay in your PR being merged, ping the LiteLLM Team on Slack (#pr-review).

Screenshots / Proof of Fix

Rig shared by both legs: a real local redis-server behind a small TCP relay that adds 0.3 s of delay per direction, so every Redis round trip takes about 0.75 s (time redis-cli -p 24775 PING reports 0.76 s), a cache pool capped at 2 connections, and a 1 s pool wait timeout. That is the ticket's shape: a healthy but slow Redis whose pool runs dry under a burst. Both legs boot two proxy instances, each with --num_workers 2, sharing that Redis, and every request alternates between the two instances. Real Anthropic spend on claude-haiku-4-5 (x-litellm-response-cost: 3.6e-05 per uncached call)

redis-server --port 55086 --bind 127.0.0.1 --save '' --appendonly no
echo 0.3 > delay.txt
python relay.py 24775 55086 delay.txt
relay.py
import asyncio, sys, pathlib
LISTEN, TARGET, CTRL = int(sys.argv[1]), int(sys.argv[2]), pathlib.Path(sys.argv[3])
def delay() -> float:
    try:
        return float(CTRL.read_text().strip() or 0)
    except Exception:
        return 0.0
async def pump(r, w):
    try:
        while True:
            data = await r.read(65536)
            if not data:
                break
            d = delay()
            if d:
                await asyncio.sleep(d)
            w.write(data)
            await w.drain()
    except Exception:
        pass
    finally:
        try:
            w.close()
        except Exception:
            pass
async def handle(cr, cw):
    try:
        sr, sw = await asyncio.open_connection("127.0.0.1", TARGET)
    except Exception:
        cw.close(); return
    await asyncio.gather(pump(cr, sw), pump(sr, cw))
async def main():
    srv = await asyncio.start_server(handle, "127.0.0.1", LISTEN)
    async with srv:
        await srv.serve_forever()
asyncio.run(main())

config.yaml:

model_list:
  - model_name: haiku
    litellm_params:
      model: anthropic/claude-haiku-4-5
      api_key: os.environ/ANTHROPIC_API_KEY

litellm_settings:
  cache: true
  cache_params:
    type: redis
    host: 127.0.0.1
    port: 24775
    max_connections: 2

general_settings:
  master_key: sk-lit7542

Two proxy instances per leg, A and B, each started as (ports are random and named per leg below):

LITELLM_LOG=WARNING REDIS_CONNECTION_POOL_TIMEOUT=1 REDIS_CIRCUIT_BREAKER_FAILURE_THRESHOLD=5 \
REDIS_CIRCUIT_BREAKER_RECOVERY_TIMEOUT=60 REDIS_CIRCUIT_BREAKER_TIMEOUT_MIN_DURATION=5.0 \
python litellm/proxy/proxy_cli.py --config config.yaml --host 127.0.0.1 --port $PORT --num_workers 2 2>&1 | tee proxy-$NAME.log

The burst: 300 chat completions at 40-way concurrency, odd requests to A and even to B (req.sh is the curl below, printing status, latency, and port). The Redis sampler runs alongside it, once a second

# req.sh PORTA PORTB N
if (( N % 2 == 1 )); then PORT=$PORTA; else PORT=$PORTB; fi
curl -s -o /dev/null -w "%{http_code} %{time_total} $PORT\n" "http://127.0.0.1:$PORT/v1/chat/completions" \
  -H 'Authorization: Bearer sk-lit7542' -H 'Content-Type: application/json' \
  -d "{\"model\":\"haiku\",\"messages\":[{\"role\":\"user\",\"content\":\"say hi $N\"}],\"max_tokens\":5}"

seq 1 300 | xargs -P 40 -n1 ./req.sh $PORTA $PORTB > codes.txt
for i in $(seq 1 20); do echo "$(date '+%H:%M:%S') redis_clients=$(redis-cli -p 55086 CLIENT LIST | grep -c 'cmd=') ping=$(redis-cli -p 55086 PING)"; sleep 1; done

The cache probe right after the burst, run twice: the same prompt to A and then to B, printing the response id and the cache header

for PORT in $PORTA $PORTB; do
  curl -s -D hdr.txt -o body.json -w 'time=%{time_total}s ' "http://127.0.0.1:$PORT/v1/chat/completions" \
    -H 'Authorization: Bearer sk-lit7542' -H 'Content-Type: application/json' \
    -d '{"model":"haiku","messages":[{"role":"user","content":"cache probe 2"}],"max_tokens":5}'
  echo "port=$PORT id=$(jq -r .id body.json) cache_key=$(grep -i '^x-litellm-cache-key:' hdr.txt | cut -d' ' -f2) cost=$(grep -i '^x-litellm-response-cost:' hdr.txt | cut -d' ' -f2)"
done

Before (ff4b558)

  1. Instance A on port 35998 and instance B on port 32205, then the burst. Every request succeeded, and the burst ran from 20:19:57 to 20:20:04

    $ awk '{print $1, $3}' codes.txt | sort | uniq -c
     150 200 32205
     150 200 35998
    $ awk '{print $2}' codes.txt | sort -n | awk '{a[NR]=$1} END{print "min", a[1], "p50", a[int(NR/2)+1], "max", a[NR]}'
    min 0.409953 p50 0.517084 max 2.792997
    
  2. Redis stayed healthy the whole time, answering every PING with the same 13 clients connected

    20:19:57 redis_clients=13 ping=PONG
    20:19:58 redis_clients=13 ping=PONG
    20:19:59 redis_clients=13 ping=PONG
    20:20:00 redis_clients=13 ping=PONG
    20:20:01 redis_clients=13 ping=PONG
    20:20:02 redis_clients=13 ping=PONG
    20:20:03 redis_clients=13 ping=PONG
    20:20:05 redis_clients=13 ping=PONG
    
  3. The breaker opened on all four workers within 1 to 4 s of the burst starting, counting the pool waits as hard connectivity failures

    $ grep -n 'circuit breaker OPENED' proxy-a.log proxy-b.log
    proxy-a.log:65:20:19:58 - LiteLLM:WARNING: redis_cache.py:250 - Redis circuit breaker OPENED after 5 consecutive failures (5 hard connectivity) — fast-failing Redis calls for 60s
    proxy-a.log:124:20:20:01 - LiteLLM:WARNING: redis_cache.py:250 - Redis circuit breaker OPENED after 5 consecutive failures (5 hard connectivity) — fast-failing Redis calls for 60s
    proxy-b.log:45:20:19:59 - LiteLLM:WARNING: redis_cache.py:250 - Redis circuit breaker OPENED after 5 consecutive failures (5 hard connectivity) — fast-failing Redis calls for 60s
    proxy-b.log:46:20:19:59 - LiteLLM:WARNING: redis_cache.py:250 - Redis circuit breaker OPENED after 5 consecutive failures (5 hard connectivity) — fast-failing Redis calls for 60s
    
  4. The cache probe, twice in a row: four fresh ids, no cache key, full provider cost every time. Caching is dark on every worker while Redis is up

    port=35998 time=0.536466s id=chatcmpl-843a2e27-510f-4337-a30b-71b3ca4af56c cache_key= cost=3.6e-05
    port=32205 time=0.531383s id=chatcmpl-51f8f21e-9e89-4b08-9e87-035f874a306e cache_key= cost=3.6e-05
    port=35998 time=0.566635s id=chatcmpl-148fb75e-c7e5-404e-b65f-65e2ee455340 cache_key= cost=3.6e-05
    port=32205 time=0.552085s id=chatcmpl-e024c0d5-d33e-4609-9101-a60bfb7a3f42 cache_key= cost=3.6e-05
    

After (cf1f709)

  1. Instance A on port 55096 and instance B on port 24274, then the burst. Every request succeeded, and the burst ran from 21:00:04 to 21:00:19

    $ awk '{print $1, $3}' codes.txt | sort | uniq -c
     150 200 24274
     150 200 55096
    $ awk '{print $2}' codes.txt | sort -n | awk '{a[NR]=$1} END{print "min", a[1], "p50", a[int(NR/2)+1], "max", a[NR]}'
    min 0.009140 p50 1.597739 max 4.135416
    
  2. Redis stayed healthy the whole time, answering every PING with the same 13 clients connected

    21:00:04 redis_clients=13 ping=PONG
    21:00:05 redis_clients=13 ping=PONG
    21:00:06 redis_clients=13 ping=PONG
    21:00:07 redis_clients=13 ping=PONG
    21:00:08 redis_clients=13 ping=PONG
    21:00:10 redis_clients=13 ping=PONG
    21:00:11 redis_clients=13 ping=PONG
    21:00:12 redis_clients=13 ping=PONG
    
  3. The breaker never opened on any worker

    $ grep -c 'circuit breaker OPENED' proxy-a.log proxy-b.log
    proxy-a.log:0
    proxy-b.log:0
    
  4. The cache probe, twice in a row: A misses once and caches, then B and every later call serve that same id with the cache key

    port=55096 time=1.715799s id=chatcmpl-aebfd930-0682-4cfe-9adb-37229e554cae cache_key= cost=3.8e-05
    port=24274 time=1.228089s id=chatcmpl-aebfd930-0682-4cfe-9adb-37229e554cae cache_key=758f8e4a7ba31ea43a76e4166396fc587549a7eb959460b1c2c457e630dbaa8e cost=3.8e-05
    port=55096 time=0.606666s id=chatcmpl-aebfd930-0682-4cfe-9adb-37229e554cae cache_key=758f8e4a7ba31ea43a76e4166396fc587549a7eb959460b1c2c457e630dbaa8e cost=3.8e-05
    port=24274 time=1.223272s id=chatcmpl-aebfd930-0682-4cfe-9adb-37229e554cae cache_key=758f8e4a7ba31ea43a76e4166396fc587549a7eb959460b1c2c457e630dbaa8e cost=3.8e-05
    

Type

🐛 Bug Fix

Caveats (if any)

Medium

  • A saturated pool now costs a full pool wait per call
    • Burst p50 rose from 0.52 s to 1.6 s on this rig
    • Before, the open breaker skipped Redis and served nothing cached
    • Sizing max_connections for the burst avoids both

Low

  • Only the explicit raise ... from chain is inspected, not __context__
  • Sync BlockingConnectionPool not covered; LiteLLM only uses the async one
  • Each pool wait timeout still logs a full-payload ERROR line; pre-existing
  • Cache hits still report the uncached x-litellm-response-cost; pre-existing
  • Pool wait timeouts now count under failure_class="timeout" on litellm_redis_circuit_breaker_failures_total, not "connectivity"; alerts keyed on the old label need updating
  • The cause chain walk stops after 20 links
  • No CI job runs the unit tests on Python 3.10, so the 3.10 timeout entry is covered by the check below rather than a test
    • uv run --no-project --python 3.10 --with redis==5.3.1 --with fakeredis==2.26.2 python check.py, where check.py saturates a one-connection BlockingConnectionPool and inspects the pool wait error's __cause__
    • 3.10: cause type: asyncio.exceptions.TimeoutError, isinstance(cause, (RedisTimeoutError, TimeoutError)): False, isinstance(cause, asyncio.TimeoutError): True
    • 3.13: cause type: builtins.TimeoutError, both checks True

Final Attestation

  • The tests check the right things, including the edge cases, and regressions in the respective real-world customer use-cases are not possible after this PR
  • 1fe6984 passes /live-pr-risk
  • cf1f709 passes /live-pr-risk

Note

Medium Risk
Changes how Redis health failures are classified for the shared circuit breaker and Prometheus failure_class labels; misclassification could delay opening on real outages or change alerting keyed on connectivity.

Overview
Fixes the Redis circuit breaker treating saturated connection-pool waits as immediate hard connectivity failures when Redis is still healthy.

_is_redis_timeout_failure now walks the exception’s explicit raise … from chain (via _explicit_causes) and classifies a failure as a timeout if any link matches the timeout types. That covers redis-py’s async BlockingConnectionPool pattern: ConnectionError("No connection available.") chained from asyncio.TimeoutError, which should follow the timeout path (duration-gated) instead of opening the breaker at once.

_redis_timeout_error_types also lists asyncio.TimeoutError explicitly for Python 3.10, where it is not yet an alias of TimeoutError.

Tests assert a busy one-connection pool does not open the breaker after many failures, and that only explicit causes count—not incidental __context__ from handling a timeout.

Reviewed by Cursor Bugbot for commit cf1f709. Bugbot is set up for automated code reviews on this repo. Configure here.

redis-py's blocking pool reports a saturated pool as ConnectionError chained
from asyncio.TimeoutError. The circuit breaker classified that as a hard
connectivity failure and opened at once while Redis was healthy. Follow the
explicit cause chain so it counts as a timeout and stays behind the
timeout_min_duration gate
@mateo-berri
mateo-berri requested a review from a team September 11, 2026 03:27
@codspeed

codspeed Bot commented Sep 11, 2026 •

Copy link
Copy Markdown
Contributor

Merging this PR will not alter performance

✅ 31 untouched benchmarks


Comparing litellm_redis_pool_timeout_counts_as_timeout (cf1f709) with litellm_internal_staging (acb9086)

Open in CodSpeed

@greptile-apps

greptile-apps Bot commented Sep 11, 2026 •

Copy link
Copy Markdown
Contributor

Greptile Summary

This PR updates Redis circuit-breaker timeout classification to follow explicit exception causes, allowing saturated connection-pool waits to respect the configured timeout-duration gate. The latest revision also classifies asyncio.TimeoutError correctly on Python 3.10. Regression tests cover pool saturation, explicit cause chains, and ordinary connectivity failures

Confidence Score: 5/5

The PR appears safe to merge, with no outstanding correctness, security, or repository-rule issues identified

Pool wait errors chained from timeouts are now duration-gated, while refused or reset connections remain immediate connectivity failures

Important Files Changed

Filename Overview
litellm/caching/redis_cache.py Adds bounded explicit-cause traversal and cross-version asyncio timeout classification
tests/test_litellm/caching/test_redis_cache.py Adds focused regression coverage for saturated pool waits and exception-chain classification

Reviews (3): Last reviewed commit: "fix(redis): treat asyncio.TimeoutError a..." | Re-trigger Greptile

The recursion detector flags any unignored recursive function, so the
timeout classification now walks the explicit cause chain with a
bounded generator instead of calling itself
@codecov

codecov Bot commented Sep 11, 2026 •

Copy link
Copy Markdown

Codecov Report

❌ Patch coverage is 92.30769% with 1 line in your changes missing coverage. Please review.

Files with missing lines Patch % Lines
litellm/caching/redis_cache.py 92.30% 1 Missing ⚠️

📢 Thoughts on this report? Let us know!

@mateo-berri

Copy link
Copy Markdown
Contributor Author

@greptileai

@mateo-berri

Copy link
Copy Markdown
Contributor Author

bugbot run

@cursor cursor Bot left a comment •

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Cursor Bugbot has reviewed your changes using default effort and found 1 potential issue.

Autofix Details

Bugbot Autofix prepared a fix for the issue found in the latest run.

  • ✅ Fixed: Timeout check misses 3.10 asyncio errors
    • The timeout classifier now includes asyncio.TimeoutError so 3.10 pool-wait ConnectionErrors stay behind the duration gate, with a regression test that simulates that distinct class on 3.12 CI.

Create PR

Or push these changes by commenting:

@cursor push c4dd57b515
Preview (c4dd57b515)
diff --git a/tests/test_litellm/caching/test_redis_cache.py b/tests/test_litellm/caching/test_redis_cache.py
--- a/tests/test_litellm/caching/test_redis_cache.py
+++ b/tests/test_litellm/caching/test_redis_cache.py
@@ -1262,3 +1262,36 @@
     assert _is_redis_timeout_failure(chained.value) is True
     assert _is_redis_timeout_failure(contextual.value) is False
     assert _is_redis_timeout_failure(RedisConnectionError("refused")) is False
+
+
+def test_py310_asyncio_timeout_error_cause_is_a_timeout_failure(monkeypatch):
+    """On py3.10 asyncio.TimeoutError is not TimeoutError, so listing only TimeoutError misses it.
+
+    CI is 3.12, where the two names are the same class and the existing cause-chain test would
+    pass without the explicit entry. Substitute a distinct class to lock the 3.10 path.
+    """
+    import importlib
+
+    from redis.exceptions import ConnectionError as RedisConnectionError
+
+    from litellm.caching.redis_cache import _is_redis_timeout_failure, _redis_timeout_error_types
+
+    class Py310AsyncioTimeoutError(Exception):
+        pass
+
+    redis_cache = importlib.import_module("litellm.caching.redis_cache")
+    _redis_timeout_error_types.cache_clear()
+    monkeypatch.setattr(redis_cache.asyncio, "TimeoutError", Py310AsyncioTimeoutError)
+
+    def raise_pool_wait_timeout() -> None:
+        try:
+            raise Py310AsyncioTimeoutError()
+        except Py310AsyncioTimeoutError as err:
+            raise RedisConnectionError("No connection available.") from err
+
+    try:
+        with pytest.raises(RedisConnectionError) as chained:
+            raise_pool_wait_timeout()
+        assert _is_redis_timeout_failure(chained.value) is True
+    finally:
+        _redis_timeout_error_types.cache_clear()

You can send follow-ups to the cloud agent here.

Comment thread litellm/caching/redis_cache.py
@mateo-berri

Copy link
Copy Markdown
Contributor Author

@greptileai

@mateo-berri

Copy link
Copy Markdown
Contributor Author

bugbot run

@cursor cursor Bot left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

✅ Bugbot reviewed your changes and found no new issues!

Comment @cursor review or bugbot run to trigger another review on this PR

Reviewed by Cursor Bugbot for commit cf1f709. Configure here.

@mateo-berri

Copy link
Copy Markdown
Contributor Author

Closing this so Devin can reopen the same branch and commits under its own authorship, which lets me approve it myself

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

1 participant