I've recently enabled logging in an application and during shutdown we are getting a lot of error logs RedisConnectionException: SocketClosed. They appear after ConnectionMultiplexer has been disposed (last command is QUIT). I have reproduced the issue in a simple console Program. I've tested it against other instances of Redis and it seems that it only happens with AWS. Those errors don't propagate to the user code but it's annoying that they appear.
Client information: Windows 10, nuget v2.7.20, .NET 8.0.2
Server information: Amazon ElastiCache Redis instance v7.0.7, clustering enabled, 3 shard, 6 nodes
info: StackExchange.Redis.ConnectionMultiplexer[0]
Connecting (sync) on .NET 8.0.2 (StackExchange.Redis: v2.7.20.59961)
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379,password=*****,ssl=True
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379/Interactive: Connecting...
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: BeginConnectAsync
info: StackExchange.Redis.ConnectionMultiplexer[0]
1 unique nodes specified (with tiebreaker)
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: OnConnectedAsync init (State=Connecting)
info: StackExchange.Redis.ConnectionMultiplexer[0]
Allowing 1 endpoint(s) 00:00:05 to respond...
info: StackExchange.Redis.ConnectionMultiplexer[0]
Awaiting 1 available task completion(s) for 5000ms, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=0,Free=32767,Min=32,Max=32767), POOL: (Threads=4,QueuedItems=0,CompletedItems=18,Timers=2)
info: StackExchange.Redis.ConnectionMultiplexer[0]
Configuring TLS
info: StackExchange.Redis.ConnectionMultiplexer[0]
TLS connection established successfully using protocol: Tls12
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379/Interactive: Connected
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: Server handshake
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: Authenticating (password)
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: Setting client name: ***(SE.Redis-v2.7.20.59961)
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: Setting client lib/ver
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: Auto-configuring...
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: Requesting tie-break (Key="__Booksleeve_TieBreak")...
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: Sending critical tracer (handshake): ECHO
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: Flushing outbound buffer
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: OnEstablishingAsync complete
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: Starting read
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: Auto-configured (CLIENT) connection-id: 615888
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: Auto-configured (INFO) role: replica
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: Auto-configured (INFO) version: 7.0.7
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: Auto-configured (INFO) server-type: Cluster
info: StackExchange.Redis.ConnectionMultiplexer[0]
Response from clustercfg.***.***.use1.cache.amazonaws.com:6379/Interactive / GET __Booksleeve_TieBreak: Error: MOVED 6202 ***-0001-002.***.***.use1.cache.amazonaws.com:6379
info: StackExchange.Redis.ConnectionMultiplexer[0]
Response from clustercfg.***.***.use1.cache.amazonaws.com:6379/Interactive / ECHO: BulkString: 16 bytes
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: OnConnectedAsync completed (From command: ECHO)
info: StackExchange.Redis.ConnectionMultiplexer[0]
All 1 available tasks completed cleanly, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=1,Free=32766,Min=32,Max=32767), POOL: (Threads=4,QueuedItems=0,CompletedItems=38,Timers=2)
info: StackExchange.Redis.ConnectionMultiplexer[0]
Endpoint summary:
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: Endpoint is (Interactive: ConnectedEstablished, Subscription: ConnectedEstablished)
info: StackExchange.Redis.ConnectionMultiplexer[0]
Task summary:
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: Returned with success as Cluster replica (Source: From command: ECHO)
info: StackExchange.Redis.ConnectionMultiplexer[0]
***-0001-001.***.***.use1.cache.amazonaws.com:6379: OnConnectedAsync init (State=Connecting)
info: StackExchange.Redis.ConnectionMultiplexer[0]
***-0001-002.***.***.use1.cache.amazonaws.com:6379: OnConnectedAsync init (State=Connecting)
info: StackExchange.Redis.ConnectionMultiplexer[0]
Allowing 2 endpoint(s) 00:00:04.3540000 to respond...
info: StackExchange.Redis.ConnectionMultiplexer[0]
Awaiting 2 available task completion(s) for 4354ms, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=1,Free=32766,Min=32,Max=32767), POOL: (Threads=4,QueuedItems=0,CompletedItems=44,Timers=4)
info: StackExchange.Redis.ConnectionMultiplexer[0]
***-0001-002.***.***.use1.cache.amazonaws.com:6379: OnConnectedAsync completed (From command: ECHO)
info: StackExchange.Redis.ConnectionMultiplexer[0]
***-0001-001.***.***.use1.cache.amazonaws.com:6379: OnConnectedAsync completed (From command: ECHO)
info: StackExchange.Redis.ConnectionMultiplexer[0]
All 2 available tasks completed cleanly, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=1,Free=32766,Min=32,Max=32767), POOL: (Threads=6,QueuedItems=0,CompletedItems=81,Timers=0)
info: StackExchange.Redis.ConnectionMultiplexer[0]
Endpoint summary:
info: StackExchange.Redis.ConnectionMultiplexer[0]
***-0001-001.***.***.use1.cache.amazonaws.com:6379: Endpoint is (Interactive: ConnectedEstablished, Subscription: ConnectedEstablished)
info: StackExchange.Redis.ConnectionMultiplexer[0]
***-0001-002.***.***.use1.cache.amazonaws.com:6379: Endpoint is (Interactive: ConnectedEstablished, Subscription: ConnectedEstablished)
info: StackExchange.Redis.ConnectionMultiplexer[0]
Task summary:
info: StackExchange.Redis.ConnectionMultiplexer[0]
***-0001-001.***.***.use1.cache.amazonaws.com:6379: Returned with success as Cluster replica (Source: From command: ECHO)
info: StackExchange.Redis.ConnectionMultiplexer[0]
***-0001-002.***.***.use1.cache.amazonaws.com:6379: Returned with success as Cluster primary (Source: From command: ECHO)
info: StackExchange.Redis.ConnectionMultiplexer[0]
Cluster: 16384 of 16384 slots covered
info: StackExchange.Redis.ConnectionMultiplexer[0]
Endpoint Summary:
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: Cluster v7.0.7, replica; keep-alive: 00:01:00; int: ConnectedEstablished; sub: ConnectedEstablished, 1 active
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: int ops=16, qu=0, qs=0, qc=0, wr=0, socks=1, non-pref=1; sub ops=7, qu=0, qs=0, qc=0, wr=0, subs=1, socks=1
info: StackExchange.Redis.ConnectionMultiplexer[0]
clustercfg.***.***.use1.cache.amazonaws.com:6379: Circular op-count snapshot; int: 0+16=16 (1.60 ops/s; spans 10s); sub: 0+7=7 (0.70 ops/s; spans 10s)
info: StackExchange.Redis.ConnectionMultiplexer[0]
***-0001-002.***.***.use1.cache.amazonaws.com:6379: Cluster v7.0.7, primary; keep-alive: 00:01:00; int: ConnectedEstablished; sub: ConnectedEstablished, 1 active
info: StackExchange.Redis.ConnectionMultiplexer[0]
***-0001-002.***.***.use1.cache.amazonaws.com:6379: int ops=14, qu=0, qs=1, qc=0, wr=0, socks=1; sub ops=7, qu=0, qs=0, qc=0, wr=0, subs=1, socks=1
info: StackExchange.Redis.ConnectionMultiplexer[0]
***-0001-002.***.***.use1.cache.amazonaws.com:6379: Circular op-count snapshot; int: 0+14=14 (1.40 ops/s; spans 10s); sub: 0+7=7 (0.70 ops/s; spans 10s)
info: StackExchange.Redis.ConnectionMultiplexer[0]
***-0001-001.***.***.use1.cache.amazonaws.com:6379: Cluster v7.0.7, replica; keep-alive: 00:01:00; int: ConnectedEstablished; sub: ConnectedEstablished, 1 active
info: StackExchange.Redis.ConnectionMultiplexer[0]
***-0001-001.***.***.use1.cache.amazonaws.com:6379: int ops=15, qu=0, qs=2, qc=0, wr=0, socks=1; sub ops=7, qu=0, qs=0, qc=0, wr=0, subs=1, socks=1
info: StackExchange.Redis.ConnectionMultiplexer[0]
***-0001-001.***.***.use1.cache.amazonaws.com:6379: Circular op-count snapshot; int: 0+15=15 (1.50 ops/s; spans 10s); sub: 0+7=7 (0.70 ops/s; spans 10s)
info: StackExchange.Redis.ConnectionMultiplexer[0]
Sync timeouts: 0; async timeouts: 0; fire and forget: 0; last heartbeat: -1s ago
info: StackExchange.Redis.ConnectionMultiplexer[0]
Starting heartbeat...
info: StackExchange.Redis.ConnectionMultiplexer[0]
Total connect time: 1,171 ms
fail: StackExchange.Redis.ConnectionMultiplexer[0]
SocketClosed on ***-0001-002.***.***.use1.cache.amazonaws.com:6379/Subscription, Idle/MarkProcessed, last: QUIT, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 0s ago, keep-alive: 60s, state: ConnectedEstablished, mgr: 7 of 10 available, in: 0, last-heartbeat: never, global: 1s ago, v: 2.7.20.59961
StackExchange.Redis.RedisConnectionException: SocketClosed on ***-0001-002.***.***.use1.cache.amazonaws.com:6379/Subscription, Idle/MarkProcessed, last: QUIT, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 0s ago, keep-alive: 60s, state: ConnectedEstablished, mgr: 7 of 10 available, in: 0, last-heartbeat: never, global: 1s ago, v: 2.7.20.59961
fail: StackExchange.Redis.ConnectionMultiplexer[0]
SocketClosed on ***-0001-001.***.***.use1.cache.amazonaws.com:6379/Interactive, Idle/MarkProcessed, last: QUIT, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 0s ago, keep-alive: 60s, state: ConnectedEstablished, mgr: 7 of 10 available, in: 0, last-heartbeat: never, global: 1s ago, v: 2.7.20.59961
StackExchange.Redis.RedisConnectionException: SocketClosed on ***-0001-001.***.***.use1.cache.amazonaws.com:6379/Interactive, Idle/MarkProcessed, last: QUIT, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 0s ago, keep-alive: 60s, state: ConnectedEstablished, mgr: 7 of 10 available, in: 0, last-heartbeat: never, global: 1s ago, v: 2.7.20.59961
fail: StackExchange.Redis.ConnectionMultiplexer[0]
SocketClosed on clustercfg.***.***.use1.cache.amazonaws.com:6379/Interactive, Idle/MarkProcessed, last: QUIT, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 0s ago, keep-alive: 60s, state: ConnectedEstablished, mgr: 7 of 10 available, in: 0, last-heartbeat: never, global: 1s ago, v: 2.7.20.59961
StackExchange.Redis.RedisConnectionException: SocketClosed on clustercfg.***.***.use1.cache.amazonaws.com:6379/Interactive, Idle/MarkProcessed, last: QUIT, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 0s ago, keep-alive: 60s, state: ConnectedEstablished, mgr: 7 of 10 available, in: 0, last-heartbeat: never, global: 1s ago, v: 2.7.20.59961
fail: StackExchange.Redis.ConnectionMultiplexer[0]
SocketClosed on ***-0001-001.***.***.use1.cache.amazonaws.com:6379/Subscription, Idle/MarkProcessed, last: QUIT, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 0s ago, keep-alive: 60s, state: ConnectedEstablished, mgr: 5 of 10 available, in: 0, last-heartbeat: never, global: 1s ago, v: 2.7.20.59961
StackExchange.Redis.RedisConnectionException: SocketClosed on ***-0001-001.***.***.use1.cache.amazonaws.com:6379/Subscription, Idle/MarkProcessed, last: QUIT, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 0s ago, keep-alive: 60s, state: ConnectedEstablished, mgr: 5 of 10 available, in: 0, last-heartbeat: never, global: 1s ago, v: 2.7.20.59961
fail: StackExchange.Redis.ConnectionMultiplexer[0]
SocketClosed on clustercfg.***.***.use1.cache.amazonaws.com:6379/Subscription, Idle/MarkProcessed, last: QUIT, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 0s ago, keep-alive: 60s, state: ConnectedEstablished, mgr: 4 of 10 available, in: 0, last-heartbeat: never, global: 1s ago, v: 2.7.20.59961
StackExchange.Redis.RedisConnectionException: SocketClosed on clustercfg.***.***.use1.cache.amazonaws.com:6379/Subscription, Idle/MarkProcessed, last: QUIT, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 0s ago, keep-alive: 60s, state: ConnectedEstablished, mgr: 4 of 10 available, in: 0, last-heartbeat: never, global: 1s ago, v: 2.7.20.59961
fail: StackExchange.Redis.ConnectionMultiplexer[0]
SocketClosed on ***-0001-002.***.***.use1.cache.amazonaws.com:6379/Interactive, Idle/MarkProcessed, last: QUIT, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 0s ago, keep-alive: 60s, state: ConnectedEstablished, mgr: 4 of 10 available, in: 0, last-heartbeat: never, global: 1s ago, v: 2.7.20.59961
StackExchange.Redis.RedisConnectionException: SocketClosed on ***-0001-002.***.***.use1.cache.amazonaws.com:6379/Interactive, Idle/MarkProcessed, last: QUIT, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 0s ago, keep-alive: 60s, state: ConnectedEstablished, mgr: 4 of 10 available, in: 0, last-heartbeat: never, global: 1s ago, v: 2.7.20.59961
RetroSearch is an open source project built by @garambo | Open a GitHub Issue
Search and Browse the WWW like it's 1997 | Search results from DuckDuckGo
HTML:
3.2
| Encoding:
UTF-8
| Version:
0.7.4