StackExchange / StackExchange.Redis

General purpose redis client
https://stackexchange.github.io/StackExchange.Redis/
Other
5.88k stars 1.51k forks source link

Long await time & Timeouts #2384

Open Tvde1 opened 1 year ago

Tvde1 commented 1 year ago

Hi, for a while now we have started seeing some very slow calls, and the profiler in our Azure App Service shows us it's due to awaiting in Stackexchange.Redis:

image

I'm unsure about how often this happens, We are on:

<PackageReference Include="Microsoft.Extensions.Caching.StackExchangeRedis" Version="6.0.14" />
<PackageReference Include="StackExchange.Redis" Version="2.6.90" />

I have also caught several RedisTimeoutException

Timeout awaiting response (outbound=0KiB, inbound=0KiB, 5016ms elapsed, timeout is 5000ms),
command=HMGET,
next: HMGET String_NullableProtoDateTime_cLNgWIxRdf7GIrkKW6LBMThPkeuKejPcsiLwiyu115Q=,
inst: 0, qu: 0, qs: 0, aw: False, bw: SpinningDown, rs: ReadAsync, ws: Idle, in: 0, last-in: 0, cur-in: 0, sync-ops: 0, async-ops: 2537900,
serverEndpoint: xxx-prod.redis.cache.windows.net:6380, conn-sec: 53289.39, mc: 1/1/0, mgr: 10 of 10 available,
clientName: pd1ldwk0002JP(SE.Redis-v2.6.90.64945), IOCP: (Busy=0,Free=1000,Min=4,Max=1000),
WORKER: (Busy=5,Free=32762,Min=4,Max=32767), POOL: (Threads=12,QueuedItems=0,CompletedItems=6251437),
v: 2.6.90.64945 (Please take a look at this article for some common client-side issues that can cause timeouts:
https://stackexchange.github.io/StackExchange.Redis/Timeouts) 

This shows the conn-sec: 53289.39 being very high, and not necessarily a lack of worker threads.

I'm not even sure if these two problems are related to the same root cause.

What can I do to investigate this issue better?

Amir-Chehri commented 1 year ago

I think 'conn-sec' is about the duration of your current connection. check this out would you plaese share more details of the way you are using SE.Redis ? Maybe you're in a high load condition? Do you have any concurrency handling mechanisms ? Are you sure that you do not have network issues ?

philon-msft commented 1 year ago

'WORKER: (Busy=5,Free=32762,Min=4,Max=32767)' indicates that you have more Busy threads than the Min thread pool size, which means you're experiencing thread pool throttling. You'll want to ensure all your calls into SE.Redis are using the *Async() methods and/or increase the Min thread pool size. More details in https://stackexchange.github.io/StackExchange.Redis/Timeouts

Tvde1 commented 1 year ago

All calls are awaited. Is it possible that this happens when you just do too many redis calls? Will up the min thread pool for sure

NickCraver commented 1 year ago

@Tvde1 Didn't see the follow-up here is it possible the HMGET is getting a rather large number of keys here?