Massive SocketClosed Exceptions and ConnectionRestored with hanging requests about stackexchange.redis HOT 4 OPEN

Using the ConnectionPoolManager for Round Robin ConnectionMultiplexer.

Unfortunately, that's not something we're familiar with or control, but my first guess given your symptoms is that is re-creating multiplexers rather than letting them re-connect internally, likely spiking your socket counts too. I'd need to see the full exceptions (we're getting truncated there) and how long we've been connected to get a better idea. The full exception message will also contain some thread pool and queue data which is rather helpful in diagnosing these.

from stackexchange.redis.

Hi Nick,

thanks for your answer. I can even reproduce this behaviour, when just using one instance of connectionmultiplexer, ignoring the ConnectionPoolManager.
I enabled some more debug information. Here is a full exception:

2024-04-23 17:16:51,582 level=ERROR,class=CustomRedisCacheService,id=4fd044dc-cef5-4b48-976c-bdb0cf17b16d,action=GetValueAsync,"StackExchange.Redis.RedisConnectionException: No connection is active/available to service this operation: TTL+GET Measurement.ApiMeas... It was not possible to connect to the redis server(s). ConnectTimeout, mc: 1/1/0, clientName: 47VMR02(SE.Redis-v2.7.33.41805), PerfCounterHelperkeyHashSlot: 4497, IOCP: (Busy=0,Free=1000,Min=4,Max=1000), WORKER: (Busy=241,Free=32526,Min=4,Max=32767), POOL: (Threads=361,QueuedItems=1186,CompletedItems=435500,Timers=35), v: 2.7.33.41805
---> System.AggregateException: One or more errors occurred. (It was not possible to connect to the redis server(s). ConnectTimeout) (It was not possible to connect to the redis server(s). ConnectTimeout) (It was not possible to connect to the redis server(s). ConnectTimeout) (It was not possible to connect to the redis server(s). ConnectTimeout) (It was not possible to connect to the redis server(s). ConnectTimeout) (It was not possible to connect to the redis server(s). ConnectTimeout) (SocketClosed (ReadEndOfStream, last-recv: 0) on 192.168.47.162:6379/Interactive, Idle/MarkProcessed, last: SETEX, origin: ReadFromPipe, outstanding: 413, last-read: 0s ago, last-write: 0s ago, keep-alive: 3600000s, state: ConnectedEstablished, mgr: , in: 0, in-pipe: 0, out-pipe: 108914, last-heartbeat: 0s ago, last-mbeat: 0s ago, global: 0s ago, v: 2.7.33.41805) (SocketClosed (ReadEndOfStream, last-recv: 0) on 192.168.47.192:6379/Interactive, Idle/MarkProcessed, last: GET, origin: ReadFromPipe, outstanding: 436, last-read: 0s ago, last-write: 0s ago, keep-alive: 3600000s, state: ConnectedEstablished, mgr: , in: 0, in-pipe: 0, out-pipe: 110859, last-heartbeat: 0s ago, last-mbeat: 0s ago, global: 0s ago, v: 2.7.33.41805) (SocketClosed (ReadEndOfStream, last-recv: 0) on 192.168.47.191:6379/Interactive, Idle/MarkProcessed, last: GET, origin: ReadFromPipe, outstanding: 396, last-read: 0s ago, last-write: 0s ago, keep-alive: 3600000s, state: ConnectedEstablished, mgr: , in: 0, in-pipe: 0, out-pipe: 62341, last-heartbeat: 0s ago, last-mbeat: 0s ago, global: 0s ago, v: 2.7.33.41805) (SocketClosed (ReadEndOfStream, last-recv: 0) on 192.168.47.195:6379/Interactive, Idle/MarkProcessed, last: INFO, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 27s ago, keep-alive: 3600000s, state: ConnectedEstablished, mgr: , in: 0, in-pipe: 0, out-pipe: 0, last-heartbeat: 0s ago, last-mbeat: 0s ago, global: 0s ago, v: 2.7.33.41805) (SocketClosed (ReadEndOfStream, last-recv: 0) on 192.168.47.185:6379/Interactive, Idle/MarkProcessed, last: INFO, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 55s ago, keep-alive: 3600000s, state: ConnectedEstablished, mgr: , in: 0, in-pipe: 0, out-pipe: 0, last-heartbeat: 0s ago, last-mbeat: 0s ago, global: 0s ago, v: 2.7.33.41805) (SocketClosed (ReadEndOfStream, last-recv: 0) on 192.168.47.187:6379/Interactive, Idle/MarkProcessed, last: INFO, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 27s ago, keep-alive: 3600000s, state: ConnectedEstablished, mgr: , in: 0, in-pipe: 0, out-pipe: 0, last-heartbeat: 0s ago, last-mbeat: 0s ago, global: 0s ago, v: 2.7.33.41805)
---> StackExchange.Redis.RedisConnectionException: It was not possible to connect to the redis server(s). ConnectTimeout
--- End of inner exception stack trace ---
---> (Inner Exception #1) StackExchange.Redis.RedisConnectionException: It was not possible to connect to the redis server(s). ConnectTimeout<---

---> (Inner Exception #2) StackExchange.Redis.RedisConnectionException: It was not possible to connect to the redis server(s). ConnectTimeout<---

---> (Inner Exception #3) StackExchange.Redis.RedisConnectionException: It was not possible to connect to the redis server(s). ConnectTimeout<---

---> (Inner Exception #4) StackExchange.Redis.RedisConnectionException: It was not possible to connect to the redis server(s). ConnectTimeout<---

---> (Inner Exception #5) StackExchange.Redis.RedisConnectionException: It was not possible to connect to the redis server(s). ConnectTimeout<---

---> (Inner Exception #6) StackExchange.Redis.RedisConnectionException: SocketClosed (ReadEndOfStream, last-recv: 0) on 192.168.47.162:6379/Interactive, Idle/MarkProcessed, last: SETEX, origin: ReadFromPipe, outstanding: 413, last-read: 0s ago, last-write: 0s ago, keep-alive: 3600000s, state: ConnectedEstablished, mgr: , in: 0, in-pipe: 0, out-pipe: 108914, last-heartbeat: 0s ago, last-mbeat: 0s ago, global: 0s ago, v: 2.7.33.41805
at Sma.Sp.Measurement.CustomRedisCacheService.SetValueAsync(CacheKey key, Object value, CacheExpiry expiry) in D:\Development\IguanaBL\BusinessCore\Sma.Sp.Measurement\Code\Sma.Sp.Measurement\CustomRedisCacheService.cs:line 169<---

---> (Inner Exception #7) StackExchange.Redis.RedisConnectionException: SocketClosed (ReadEndOfStream, last-recv: 0) on 192.168.47.192:6379/Interactive, Idle/MarkProcessed, last: GET, origin: ReadFromPipe, outstanding: 436, last-read: 0s ago, last-write: 0s ago, keep-alive: 3600000s, state: ConnectedEstablished, mgr: , in: 0, in-pipe: 0, out-pipe: 110859, last-heartbeat: 0s ago, last-mbeat: 0s ago, global: 0s ago, v: 2.7.33.41805
at Sma.Sp.Measurement.CustomRedisCacheService.GetValueAsync(CacheKey cacheKey, Type responseType) in D:\Development\IguanaBL\BusinessCore\Sma.Sp.Measurement\Code\Sma.Sp.Measurement\CustomRedisCacheService.cs:line 80<---

---> (Inner Exception #8) StackExchange.Redis.RedisConnectionException: SocketClosed (ReadEndOfStream, last-recv: 0) on 192.168.47.191:6379/Interactive, Idle/MarkProcessed, last: GET, origin: ReadFromPipe, outstanding: 396, last-read: 0s ago, last-write: 0s ago, keep-alive: 3600000s, state: ConnectedEstablished, mgr: , in: 0, in-pipe: 0, out-pipe: 62341, last-heartbeat: 0s ago, last-mbeat: 0s ago, global: 0s ago, v: 2.7.33.41805
at Sma.Sp.Measurement.CustomRedisCacheService.GetValueAsync(CacheKey cacheKey, Type responseType) in D:\Development\IguanaBL\BusinessCore\Sma.Sp.Measurement\Code\Sma.Sp.Measurement\CustomRedisCacheService.cs:line 80<---

---> (Inner Exception #9) StackExchange.Redis.RedisConnectionException: SocketClosed (ReadEndOfStream, last-recv: 0) on 192.168.47.195:6379/Interactive, Idle/MarkProcessed, last: INFO, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 27s ago, keep-alive: 3600000s, state: ConnectedEstablished, mgr: , in: 0, in-pipe: 0, out-pipe: 0, last-heartbeat: 0s ago, last-mbeat: 0s ago, global: 0s ago, v: 2.7.33.41805<---

---> (Inner Exception #10) StackExchange.Redis.RedisConnectionException: SocketClosed (ReadEndOfStream, last-recv: 0) on 192.168.47.185:6379/Interactive, Idle/MarkProcessed, last: INFO, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 55s ago, keep-alive: 3600000s, state: ConnectedEstablished, mgr: , in: 0, in-pipe: 0, out-pipe: 0, last-heartbeat: 0s ago, last-mbeat: 0s ago, global: 0s ago, v: 2.7.33.41805<---

---> (Inner Exception #11) StackExchange.Redis.RedisConnectionException: SocketClosed (ReadEndOfStream, last-recv: 0) on 192.168.47.187:6379/Interactive, Idle/MarkProcessed, last: INFO, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 27s ago, keep-alive: 3600000s, state: ConnectedEstablished, mgr: , in: 0, in-pipe: 0, out-pipe: 0, last-heartbeat: 0s ago, last-mbeat: 0s ago, global: 0s ago, v: 2.7.33.41805<---

--- End of inner exception stack trace ---
at StackExchange.Redis.ConnectionMultiplexer.ThrowFailed[T](TaskCompletionSource`1 source, Exception unthrownException) in /_/src/StackExchange.Redis/ConnectionMultiplexer.cs:line 2048
--- End of stack trace from previous location ---

from stackexchange.redis.

worth mentioning, that the same connectionmultiplexer instance worked fine for several minutes before starting with this with answer times around 0-10 ms

from stackexchange.redis.

It looks like you have some extreme thread exhaustion as indicated by WORKER: (Busy=241,Free=32526,Min=4,Max=32767), POOL: (Threads=361,QueuedItems=1186,CompletedItems=435500,Timers=35), this will be that tasks for connecting to Redis or completing commands get so far behind in the queue, they timeout before being completed (at the shared threadpool level). I'd suggest taking a dump and see what those hundreds of threads are doing, it's likely something's either locking or a remote call that should be async elsewhere in the application.

from stackexchange.redis.