Skip to content

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

Merged
mateo-berri merged 5 commits into
litellm_internal_stagingfrom
litellm_redis_pool_timeout_counts_as_timeout
Sep 12, 2026
Merged

mateo-berri merged 5 commits into
litellm_internal_stagingfrom
litellm_redis_pool_timeout_counts_as_timeout

Conversation

@devin-ai-integration

@devin-ai-integration devin-ai-integration Bot 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 alert behavior, but scope is limited to timeout vs connectivity handling in redis_cache.py.

Overview
Fixes false Redis circuit breaker opens when the async connection pool is saturated but Redis is still healthy.

_is_redis_timeout_failure no longer looks only at the outer exception type. It walks the bounded explicit __cause__ chain (via new _explicit_causes) and treats the failure as a timeout if any link matches timeout types—including asyncio.TimeoutError, which is now listed explicitly for Python 3.10 where it is not yet an alias of TimeoutError. That matches redis-py’s pattern of raising ConnectionError("No connection available.") from a pool-wait timeout, so those errors count as timeout failures (subject to timeout_min_duration) instead of immediate hard connectivity trips.

Tests add a fakeredis saturated BlockingConnectionPool scenario and assert raise ... from vs contextual except handling for classification.

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

Reopened from #40672 with the same commits so the approval can come from someone other than the author

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
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
@devin-ai-integration

Copy link
Copy Markdown
Contributor Author

🤖 Devin AI Engineer

I'll be helping with this pull request! Here's what you should know:

✅ I will automatically:

  • Address comments on this PR. Add '(aside)' to your comment to have me ignore it.
  • Look at CI failures and help fix them

Note: I can only respond to comments from users who have write access to this repository.

⚙️ Control Options:

  • Disable automatic comment, CI, and merge conflict monitoring

@mateo-berri mateo-berri 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.

LGTM

@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 (51abb95) with litellm_internal_staging (9276317)1

Open in CodSpeed

Footnotes

  1. No successful run was found on litellm_internal_staging (fe5ff9d) during the generation of this report, so 9276317 was used instead as the comparison base. There might be some changes unrelated to this pull request in this report. ↩

@greptile-apps

greptile-apps Bot commented Sep 11, 2026

Copy link
Copy Markdown
Contributor

Greptile Summary

This PR updates Redis circuit-breaker classification so blocking-pool wait failures chained from timeout exceptions remain subject to the timeout-duration gate

  • Walks explicit exception causes with a bounded traversal
  • Handles asyncio.TimeoutError independently across supported Python versions
  • Adds regression coverage for pool saturation and explicit versus implicit exception chaining

Confidence Score: 5/5

The PR appears safe to merge, with focused classification logic and regression coverage for the reported pool-saturation behavior

No actionable failure remains; the breaker still distinguishes hard connectivity failures while recognizing the explicit timeout cause emitted for exhausted async blocking pools

Important Files Changed

Filename Overview
litellm/caching/redis_cache.py Adds bounded explicit-cause traversal so Redis pool wait failures are classified as timeouts without treating implicit exception context as one
tests/test_litellm/caching/test_redis_cache.py Adds focused regression tests covering a saturated async blocking pool and explicit-cause-only timeout detection

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

…itellm_redis_pool_timeout_counts_as_timeout

# Conflicts:
#	tests/test_litellm/caching/test_redis_cache.py
@mateo-berri

Copy link
Copy Markdown
Contributor

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 51abb95. Configure here.

@mateo-berri
mateo-berri merged commit 426e675 into litellm_internal_staging Sep 12, 2026
87 of 88 checks passed
@mateo-berri
mateo-berri deleted the litellm_redis_pool_timeout_counts_as_timeout branch September 12, 2026 22:43
@codecov

codecov Bot commented Sep 12, 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!

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