I have an Azure App Service, running 2 instances, that makes use of a shared Azure Redis Cache. Most of the time, everything is fine. But some days, I see RedisTimeoutException errors in my App Service logs. Typically, there is a timeout on a Write (SETEX) immediately followed by ~10 more timeouts which are a mix of Reads and Writes (other operations that were queued up behind the one that timed-out, I think).
Example:
StackExchange.Redis.RedisTimeoutException: Timeout awaiting response
(outbound=0KiB, inbound=1KiB, 5984ms elapsed, timeout is 5000ms), command=SETEX, next: GET <Key_name>,
inst: 0, qu: 0, qs: 14, aw: False, rs: ReadAsync, ws: Idle, in: 0,
serverEndpoint: <Azure_Redis_instance>, mc: 1/1/0, mgr: 10 of 10 available, clientName: <App_service_instance>,
IOCP: (Busy=0,Free=1000,Min=2,Max=1000), WORKER: (Busy=2,Free=32765,Min=2,Max=32767), v: 2.1.28.64774
(Please take a look at this article for some common client-side issues that can cause timeouts: https://stackexchange.github.io/StackExchange.Redis/Timeouts)
I have followed the URL in their exception message and read through their explanation of possible timeout causes, but I don't believe any of these are the cause. This subheading caught my attention because I do see qs: 14 in my exception above, but we're not using any commands that would be long-running. We only set/get individual cache entries using their key.
I've used Azure Portal > App Service > Metrics blade to look at the App Service during the time that these errors were appearing, and I don't see any spikes in CPU time, memory working set or connections (on either instance of the App Service). I also checked the Redis Cache instance, and didn't see any spikes in memory or CPU usage.
I'm not sure what to look into next. Eg:
- Would you try their suggestion to use a pool of ConnectionMultiplexer objects to avoid operations queueing up behind a slow operation? (I'd rather find out why it's slow)
- Is there another key performance metric that I'm overlooking?
- I didn't see an explanation for
mc: 1/1/0, what does that mean?