Not automatically updated if the primary changes with Redis Sentinel since v2.8.58

[Broderick890]

redis version :redis:6.2.7-alpine

Steps to reproduce the issue:

in the sentinel server run below:

SENTINEL failover mymaster

in the application run below:
connectionMultiplexer.GetDatabase().HashSet("test", "test", "test");

throw exception below:

No connection (requires writable - not eligible for replica) is active/available to service this operation: HSET test; SocketClosed (ReadEndOfStream, last-recv: 0) on 192.168.1.2:6379/Subscription, Idle/MarkProcessed, last: SUBSCRIBE, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 32s ago, keep-alive: 60s, state: ConnectedEstablished, mgr: 7 of 10 available, in: 0, in-pipe: 0, out-pipe: 0, last-heartbeat: 0s ago, last-mbeat: 0s ago, global: 0s ago, v: 2.9.17.8862, mc: 1/1/0, mgr: 9 of 10 available, clientName: pc(SE.Redis-v2.9.17.8862), IOCP: (Busy=0,Free=128,Min=16,Max=128), WORKER: (Busy=3,Free=125,Min=16,Max=128), POOL: (Threads=19,QueuedItems=0,CompletedItems=3511,Timers=19), v: 2.9.17.8862

No problems were encountered previous v2.8.58

[mgravell]

To clarify; you're connecting via the sentinel endpoint, and then changing the primary (via sentinel) and taking the old primary offline; is that correct? I'm pretty sure we haven't changed anything in that area in a very long time, but I'll also note that sentinel isn't an area that has seen huge focus. It looks the code to subscribe to sentinel notifications should still be there. Basically: "huh, that's weird". I'll see if I can reproduce a failure.

[Broderick890]

thank you !

[averenium]

Hello
Have the same problem after update in production
Nowaday i test it with with 2.8.0 an 2.9.17 in our environment.
I dont have direct problem version because i cannot reproduce it in local environment but think the problem same with this issue (if not I can create new)

(I am so sorry but i can attach logs only from 2.9.17. If you need i can request additional test for old version but that version works ok)

Behavior Comparison

#	Action	2.8.0	2.9.17
1	Initial State	Two Redis servers with Sentinels online.	Two Redis servers with Sentinels online.
2	Primary Server Shutdown	A failover to the new master occurs.	A failover to the new master occurs.
3	Behavior During Failover	Sends SET requests to the new master. Observes UnableToConnect on .../Interactive, Initializing/NotStarted errors for the old (down) master.	Sends SET requests to the new master. Observes UnableToConnect on .../Interactive, Initializing/NotStarted errors for the old (down) master.
4	Return of Old Primary	The old primary server comes back online.	The old primary server comes back online.
5	Reaction to Return	Successfully handles the reconnection, observing a few Socket closed exceptions during the process. Operation stabilizes.	Starts reconfiguration. Result of reconfiguration: Server summary: $1:6379: Standalone v8.0.0, replica; 16 databases; keep-alive: 00:01:00; int: ConnectedEstablished; sub: ConnectedEstablished, 1 active Server summary: $2:6379: Standalone v8.0.0, primary; 16 databases; keep-alive: 00:01:00; int: ConnectedEstablished; sub: ConnectedEstablished, 1 active; not in use: RedundantPrimary
6	Final Result	Operation continues correctly, sending all commands to the true primary.	Selects the incorrect (old) server as the primary. All subsequent SET commands fail to execute until the application is restarted. No connection (requires writable - not eligible for replica) is active/available to service this operation: SET

---

Client log from 2.9.17. $1 - OLD Primary (at start of log - shutdown) $2 - NEW Primary (at start of log - already primary). Set result: True - message deliverd to primary server

------ MISSING OLD PRIMARY. Set result: True - message delivered to new primary, exception connect to old primary
[14:44:31 INF] Set result: True
[14:44:31 INF] Resurrecting Interactive/$1:6379 (retry: 261)
[14:44:31 ERR] UnableToConnect on $1:6379/Interactive, Initializing/NotStarted, last: SET, origin: BeginConnectAsync, outstanding: 0, last-read: 0s ago, last-write: 0s ago, keep-alive: 60s, state: Connecting, mgr: 10 of 10 available, last-heartbeat: never, last-mbeat: 0s ago, global: 0s ago, v: 2.9.17.8862
StackExchange.Redis.RedisConnectionException: UnableToConnect on $1:6379/Interactive, Initializing/NotStarted, last: SET, origin: BeginConnectAsync, outstanding: 0, last-read: 0s ago, last-write: 0s ago, keep-alive: 60s, state: Connecting, mgr: 10 of 10 available, last-heartbeat: never, last-mbeat: 0s ago, global: 0s ago, v: 2.9.17.8862
[14:44:32 INF] Set result: True
[14:44:33 INF] Resurrecting Subscription/$1:6379 (retry: 268)
[14:44:33 INF] Set result: True
----- OLD PRIMARY RETURNED 
[14:44:33 INF] $1:26379,$2:26379,serviceName=test,syncTimeout=3000,password=*****,abortConnect=False,defaultDatabase=0
[14:44:33 INF] 2 unique nodes specified (without tiebreaker)
[14:44:33 INF] $1:6379: OnConnectedAsync init (State=Disconnected)
[14:44:33 INF] $2:6379: OnConnectedAsync already connected start
[14:44:33 INF] Allowing 2 endpoint(s) 00:00:05 to respond...
[14:44:33 INF] Awaiting 2 available task completion(s) for 5000ms, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=4,Free=32763,Min=8,Max=32767), POOL: (Threads=7,QueuedItems=0,CompletedItems=67185,Timers=8)
[14:44:33 INF] Response from $2:6379/Interactive / PING: SimpleString: PONG
[14:44:33 INF] $2:6379: OnConnectedAsync already connected end
[14:44:34 INF] Resurrecting Interactive/$1:26379 (retry: 269)
[14:44:34 INF] $1:26379,$2:26379,serviceName=test,syncTimeout=3000,password=*****,abortConnect=False,defaultDatabase=0
[14:44:34 INF] 2 unique nodes specified (without tiebreaker)
[14:44:34 INF] $1:26379: OnConnectedAsync already connected start
[14:44:34 INF] $2:26379: OnConnectedAsync already connected start
[14:44:34 INF] Allowing 2 endpoint(s) 00:00:05 to respond...
[14:44:34 INF] Awaiting 2 available task completion(s) for 5000ms, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=4,Free=32763,Min=8,Max=32767), POOL: (Threads=7,QueuedItems=0,CompletedItems=67192,Timers=9)
[14:44:34 INF] Response from $1:26379/Interactive / PING: SimpleString: PONG
[14:44:34 INF] Response from $2:26379/Interactive / PING: SimpleString: PONG
[14:44:34 INF] $1:26379: OnConnectedAsync already connected end
[14:44:34 INF] $2:26379: OnConnectedAsync already connected end
[14:44:34 INF] All 2 available tasks completed cleanly, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=5,Free=32762,Min=8,Max=32767), POOL: (Threads=7,QueuedItems=0,CompletedItems=67195,Timers=9)
[14:44:34 INF] Endpoint summary:
[14:44:34 INF]   $1:26379: Endpoint is (Interactive: ConnectedEstablished, Subscription: Disconnected)
[14:44:34 INF]   $2:26379: Endpoint is (Interactive: ConnectedEstablished, Subscription: ConnectedEstablished)
[14:44:34 INF] Task summary:
[14:44:34 INF]   $1:26379: Returned with success as Sentinel primary (Source: Already connected)
[14:44:34 INF]   $2:26379: Returned with success as Sentinel primary (Source: Already connected)
[14:44:34 INF] Election summary:
[14:44:34 INF]   Election: Multiple primaries detected...
[14:44:34 INF]   Election: Choosing primary arbitrarily: $1:26379
[14:44:34 INF] $1:26379: Clearing as RedundantPrimary
[14:44:34 INF] $2:26379: Setting as RedundantPrimary
[14:44:34 INF] Subscriptions attempting reconnect: 2
[14:44:34 INF] Endpoint Summary:
[14:44:34 INF] Server summary: $1:26379: Sentinel v8.0.0, primary; keep-alive: 00:01:00; int: ConnectedEstablished; sub: Disconnected, counters: $1:26379: int ops=185, qu=0, qs=2, qc=0, wr=0, socks=271; sub ops=173, qu=0, qs=0, qc=0, wr=0, socks=266, profile: $1:26379: Circular op-count snapshot; int: 177+8=185 (0,80 ops/s; spans 10s); sub: 173 (0,00 ops/s; spans 10s)
[14:44:34 INF] Server summary: $2:26379: Sentinel v8.0.0, primary; keep-alive: 00:01:00; int: ConnectedEstablished; sub: ConnectedEstablished, 1 active; not in use: RedundantPrimary, counters: $2:26379: int ops=210, qu=0, qs=0, qc=0, wr=0, socks=1; sub ops=195, qu=0, qs=0, qc=0, wr=0, subs=1, socks=1, profile: $2:26379: Circular op-count snapshot; int: 208+1+1=210 (0,20 ops/s; spans 10s); sub: 195 (0,00 ops/s; spans 10s)
[14:44:34 INF] Sync timeouts: 6; async timeouts: 0; fire and forget: 6; last heartbeat: 0s ago
[14:44:34 INF] Set result: True
[14:44:35 INF] Set result: True
[14:44:36 INF] Set result: True
[14:44:37 INF] Set result: True
[14:44:38 INF] Resurrecting Subscription/$1:26379 (retry: 265)
[14:44:38 INF] $1:26379,$2:26379,serviceName=test,syncTimeout=3000,password=*****,abortConnect=False,defaultDatabase=0
[14:44:38 INF] 2 unique nodes specified (without tiebreaker)
[14:44:38 INF] $1:26379: OnConnectedAsync already connected start
[14:44:38 INF] $2:26379: OnConnectedAsync already connected start
[14:44:38 INF] Allowing 2 endpoint(s) 00:00:05 to respond...
[14:44:38 INF] Awaiting 2 available task completion(s) for 5000ms, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=2,Free=32765,Min=8,Max=32767), POOL: (Threads=8,QueuedItems=0,CompletedItems=67239,Timers=6)
[14:44:38 INF] Response from $1:26379/Interactive / PING: SimpleString: PONG
[14:44:38 INF] Response from $2:26379/Interactive / PING: SimpleString: PONG
[14:44:38 INF] $1:26379: OnConnectedAsync already connected end
[14:44:38 INF] $2:26379: OnConnectedAsync already connected end
[14:44:38 INF] All 2 available tasks completed cleanly, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=3,Free=32764,Min=8,Max=32767), POOL: (Threads=8,QueuedItems=0,CompletedItems=67243,Timers=6)
[14:44:38 INF] Endpoint summary:
[14:44:38 INF]   $1:26379: Endpoint is (Interactive: ConnectedEstablished, Subscription: ConnectedEstablished)
[14:44:38 INF]   $2:26379: Endpoint is (Interactive: ConnectedEstablished, Subscription: ConnectedEstablished)
[14:44:38 INF] Task summary:
[14:44:38 INF]   $1:26379: Returned with success as Sentinel primary (Source: Already connected)
[14:44:38 INF]   $2:26379: Returned with success as Sentinel primary (Source: Already connected)
[14:44:38 INF] Election summary:
[14:44:38 INF]   Election: Multiple primaries detected...
[14:44:38 INF]   Election: Choosing primary arbitrarily: $1:26379
[14:44:38 INF] $1:26379: Clearing as RedundantPrimary
[14:44:38 INF] $2:26379: Setting as RedundantPrimary
[14:44:38 INF] No subscription changes necessary
[14:44:38 INF] Endpoint Summary:
[14:44:38 INF] Server summary: $1:26379: Sentinel v8.0.0, primary; keep-alive: 00:01:00; int: ConnectedEstablished; sub: ConnectedEstablished, 3 active, counters: $1:26379: int ops=187, qu=0, qs=0, qc=0, wr=0, socks=271; sub ops=178, qu=0, qs=0, qc=0, wr=0, subs=3, socks=267, profile: $1:26379: Circular op-count snapshot; int: 177+9+1=187 (1,00 ops/s; spans 10s); sub: 173+5=178 (0,50 ops/s; spans 10s)
[14:44:38 INF] Server summary: $2:26379: Sentinel v8.0.0, primary; keep-alive: 00:01:00; int: ConnectedEstablished; sub: ConnectedEstablished, 1 active; not in use: RedundantPrimary, counters: $2:26379: int ops=212, qu=0, qs=0, qc=0, wr=0, socks=1; sub ops=195, qu=0, qs=0, qc=0, wr=0, subs=1, socks=1, profile: $2:26379: Circular op-count snapshot; int: 208+1+2+1=212 (0,40 ops/s; spans 10s); sub: 195 (0,00 ops/s; spans 10s)
[14:44:38 INF] Sync timeouts: 6; async timeouts: 0; fire and forget: 8; last heartbeat: 0s ago
[14:44:38 INF] Not all available tasks completed cleanly (from ReconfigureAsync#1499, timeout 5000ms), IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=3,Free=32764,Min=8,Max=32767), POOL: (Threads=8,QueuedItems=0,CompletedItems=67246,Timers=5)
[14:44:38 INF]   Server[0] ($1:6379) Status: WaitingForActivation (inst: 0, qs: 0, in: -1, qu: 0, aw: False, in-pipe: -1, out-pipe: -1, bw: SpinningDown, rs: NA. ws: NA)
[14:44:38 INF]   Server[1] ($2:6379) Status: RanToCompletion (inst: 1, qs: 0, in: 0, qu: 1, aw: False, in-pipe: 0, out-pipe: 0, bw: Inactive, rs: ReadAsync. ws: Idle)
[14:44:38 INF] Endpoint summary:
[14:44:38 INF]   $1:6379: Endpoint is (Interactive: Disconnected, Subscription: ConnectedEstablished)
[14:44:38 INF]   $2:6379: Endpoint is (Interactive: ConnectedEstablished, Subscription: ConnectedEstablished)
[14:44:38 INF] Task summary:
[14:44:38 INF]   $1:6379: Did not respond (Task.Status: WaitingForActivation)
[14:44:38 INF]   $2:6379: Returned with success as Standalone primary (Source: Already connected)
[14:44:38 INF] Election summary:
[14:44:38 INF]   Election: Single primary detected: $2:6379Reconf
[14:44:38 INF] $2:6379: Clearing as RedundantPrimary
[14:44:38 INF] No subscription changes necessary
[14:44:38 INF] Endpoint Summary:
[14:44:38 INF] Server summary: $1:6379: Standalone v8.0.0, primary; 16 databases; keep-alive: 00:01:00; int: Disconnected; sub: ConnectedEstablished, 1 active; not in use: DidNotRespond, counters: $1:6379: int ops=9863, qu=0, qs=0, qc=0, wr=0, socks=263; sub ops=182, qu=0, qs=0, qc=0, wr=0, subs=1, socks=270, profile: $1:6379: Circular op-count snapshot; int: 9863 (0,00 ops/s; spans 10s); sub: 175+7=182 (0,70 ops/s; spans 10s)
[14:44:38 INF] Server summary: $2:6379: Standalone v8.0.0, primary; 16 databases; keep-alive: 00:01:00; int: ConnectedEstablished; sub: ConnectedEstablished, 1 active, counters: $2:6379: int ops=1598, qu=0, qs=0, qc=0, wr=0, socks=2; sub ops=205, qu=0, qs=0, qc=0, wr=0, subs=1, socks=2, profile: $2:6379: Circular op-count snapshot; int: 1588+1+1+1+2+1+1+1+1+1=1598 (1,00 ops/s; spans 10s); sub: 205 (0,00 ops/s; spans 10s)
[14:44:38 INF] Sync timeouts: 0; async timeouts: 0; fire and forget: 0; last heartbeat: 0s ago
[14:44:38 INF] Set result: True
[14:44:39 INF] Resurrecting Interactive/$1:6379 (retry: 262)
[14:44:39 INF] $1:6379: OnConnectedAsync completed (From command: ECHO)
[14:44:39 INF] $1:26379,$2:26379,serviceName=test,syncTimeout=3000,password=*****,abortConnect=False,defaultDatabase=0
[14:44:39 INF] 2 unique nodes specified (without tiebreaker)
[14:44:39 INF] $1:6379: OnConnectedAsync already connected start
[14:44:39 INF] $2:6379: OnConnectedAsync already connected start
[14:44:39 INF] Allowing 2 endpoint(s) 00:00:05 to respond...
[14:44:39 INF] Awaiting 2 available task completion(s) for 5000ms, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=4,Free=32763,Min=8,Max=32767), POOL: (Threads=8,QueuedItems=0,CompletedItems=67263,Timers=5)
[14:44:39 INF] Response from $2:6379/Interactive / PING: SimpleString: PONG
[14:44:39 INF] Response from $1:6379/Interactive / PING: SimpleString: PONG
[14:44:39 INF] $2:6379: OnConnectedAsync already connected end
[14:44:39 INF] $1:6379: OnConnectedAsync already connected end
[14:44:39 INF] All 2 available tasks completed cleanly, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=5,Free=32762,Min=8,Max=32767), POOL: (Threads=8,QueuedItems=0,CompletedItems=67275,Timers=5)
[14:44:39 INF] Endpoint summary:
[14:44:39 INF]   $1:6379: Endpoint is (Interactive: ConnectedEstablished, Subscription: ConnectedEstablished)
[14:44:39 INF]   $2:6379: Endpoint is (Interactive: ConnectedEstablished, Subscription: ConnectedEstablished)
[14:44:39 INF] Task summary:
[14:44:39 INF]   $1:6379: Returned with success as Standalone primary (Source: Already connected)
[14:44:39 INF]   $2:6379: Returned with success as Standalone primary (Source: Already connected)
[14:44:39 INF] Election summary:
[14:44:39 INF]   Election: Multiple primaries detected...
[14:44:39 INF]   Election: Choosing primary arbitrarily: $1:6379
[14:44:39 INF] $1:6379: Clearing as RedundantPrimary
[14:44:39 INF] $2:6379: Setting as RedundantPrimary
[14:44:39 INF] No subscription changes necessary
[14:44:39 INF] Endpoint Summary:
[14:44:39 INF] Server summary: $1:6379: Standalone v8.0.0, primary; 16 databases; keep-alive: 00:01:00; int: ConnectedEstablished; sub: ConnectedEstablished, 1 active, counters: $1:6379: int ops=9877, qu=0, qs=0, qc=0, wr=0, socks=264; sub ops=182, qu=0, qs=0, qc=0, wr=0, subs=1, socks=270, profile: $1:6379: Circular op-count snapshot; int: 9863+14=9877 (1,40 ops/s; spans 10s); sub: 175+7=182 (0,70 ops/s; spans 10s)
[14:44:39 INF] Server summary: $2:6379: Standalone v8.0.0, primary; 16 databases; keep-alive: 00:01:00; int: ConnectedEstablished; sub: ConnectedEstablished, 1 active; not in use: RedundantPrimary, counters: $2:6379: int ops=1600, qu=0, qs=0, qc=0, wr=0, socks=2; sub ops=205, qu=0, qs=0, qc=0, wr=0, subs=1, socks=2, profile: $2:6379: Circular op-count snapshot; int: 1589+1+1+2+1+1+1+1+2+1=1600 (1,10 ops/s; spans 10s); sub: 205 (0,00 ops/s; spans 10s)
[14:44:39 INF] Sync timeouts: 0; async timeouts: 0; fire and forget: 0; last heartbeat: 0s ago
[14:44:39 INF] Set result: True
[14:44:40 INF] Set result: True
[14:44:41 INF] Set result: True
[14:44:41 ERR] SocketClosed (ReadEndOfStream, last-recv: 0) on $1:6379/Subscription, Idle/MarkProcessed, last: SUBSCRIBE, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 8s ago, keep-alive: 60s, state: ConnectedEstablished, mgr: 8 of 10 available, in: 0, in-pipe: 0, out-pipe: 0, last-heartbeat: 0s ago, last-mbeat: 0s ago, global: 0s ago, v: 2.9.17.8862
StackExchange.Redis.RedisConnectionException: SocketClosed (ReadEndOfStream, last-recv: 0) on $1:6379/Subscription, Idle/MarkProcessed, last: SUBSCRIBE, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 8s ago, keep-alive: 60s, state: ConnectedEstablished, mgr: 8 of 10 available, in: 0, in-pipe: 0, out-pipe: 0, last-heartbeat: 0s ago, last-mbeat: 0s ago, global: 0s ago, v: 2.9.17.8862
[14:44:41 ERR] SocketClosed (ReadEndOfStream, last-recv: 0) on $1:6379/Interactive, Idle/MarkProcessed, last: SET, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 0s ago, keep-alive: 60s, state: ConnectedEstablished, mgr: 8 of 10 available, in: 0, in-pipe: 0, out-pipe: 0, last-heartbeat: 0s ago, last-mbeat: 0s ago, global: 0s ago, v: 2.9.17.8862
StackExchange.Redis.RedisConnectionException: SocketClosed (ReadEndOfStream, last-recv: 0) on $1:6379/Interactive, Idle/MarkProcessed, last: SET, origin: ReadFromPipe, outstanding: 0, last-read: 0s ago, last-write: 0s ago, keep-alive: 60s, state: ConnectedEstablished, mgr: 8 of 10 available, in: 0, in-pipe: 0, out-pipe: 0, last-heartbeat: 0s ago, last-mbeat: 0s ago, global: 0s ago, v: 2.9.17.8862
[14:44:41 INF] $1:26379,$2:26379,serviceName=test,syncTimeout=3000,password=*****,abortConnect=False,defaultDatabase=0
[14:44:41 INF] 2 unique nodes specified (without tiebreaker)
[14:44:41 INF] $1:6379: OnConnectedAsync init (State=Connecting)
[14:44:41 INF] $2:6379: OnConnectedAsync already connected start
[14:44:41 INF] Allowing 2 endpoint(s) 00:00:05 to respond...
[14:44:41 INF] Awaiting 2 available task completion(s) for 5000ms, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=5,Free=32762,Min=8,Max=32767), POOL: (Threads=8,QueuedItems=0,CompletedItems=67308,Timers=7)
[14:44:41 INF] Response from $2:6379/Interactive / PING: SimpleString: PONG
[14:44:41 INF] $2:6379: OnConnectedAsync already connected end
[14:44:41 INF] $1:6379: OnConnectedAsync completed (From command: ECHO)
[14:44:41 INF] All 2 available tasks completed cleanly, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=7,Free=32760,Min=8,Max=32767), POOL: (Threads=8,QueuedItems=0,CompletedItems=67328,Timers=5)
[14:44:41 INF] Endpoint summary:
[14:44:41 INF]   $1:6379: Endpoint is (Interactive: ConnectedEstablished, Subscription: ConnectedEstablished)
[14:44:41 INF]   $2:6379: Endpoint is (Interactive: ConnectedEstablished, Subscription: ConnectedEstablished)
[14:44:41 INF] Task summary:
[14:44:41 INF]   $1:6379: Returned with success as Standalone replica (Source: From command: ECHO)
[14:44:41 INF]   $2:6379: Returned with success as Standalone primary (Source: Already connected)
[14:44:41 INF] Election summary:
[14:44:41 INF]   Election: Single primary detected: $2:6379

---- I think the problem is here

[14:44:41 INF] $2:6379: Clearing as RedundantPrimary
[14:44:41 INF] No subscription changes necessary
[14:44:41 INF] Endpoint Summary:
[14:44:41 INF] Server summary: $1:6379: Standalone v8.0.0, replica; 16 databases; keep-alive: 00:01:00; int: ConnectedEstablished; sub: ConnectedEstablished, 1 active, counters: $1:6379: int ops=9893, qu=0, qs=1, qc=0, wr=0, socks=265; sub ops=189, qu=0, qs=0, qc=0, wr=0, subs=1, socks=271, profile: $1:6379: Circular op-count snapshot; int: 9863+15+1+14=9893 (3,00 ops/s; spans 10s); sub: 175+7+7=189 (1,40 ops/s; spans 10s)
[14:44:41 INF] Server summary: $2:6379: Standalone v8.0.0, primary; 16 databases; keep-alive: 00:01:00; int: ConnectedEstablished; sub: ConnectedEstablished, 1 active; not in use: RedundantPrimary, counters: $2:6379: int ops=1601, qu=0, qs=0, qc=0, wr=0, socks=2; sub ops=206, qu=0, qs=0, qc=0, wr=0, subs=1, socks=2, profile: $2:6379: Circular op-count snapshot; int: 1591+2+1+1+1+1+2+1+1=1601 (1,00 ops/s; spans 10s); sub: 205+1=206 (0,10 ops/s; spans 10s)
[14:44:41 INF] Sync timeouts: 0; async timeouts: 0; fire and forget: 0; last heartbeat: 0s ago

------ NO PRIMARY IN 2.9.17 

StackExchange.Redis.RedisConnectionException: No connection (requires writable - not eligible for replica) is active/available to service this operation: SET Test_Tech_2_9, mc: 1/1/0, mgr: 10 of 10 available, clientName: dnh0-2-143(SE.Redis-v2.9.17.8862), IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=3,Free=32764,Min=8,Max=32767), POOL: (Threads=9,QueuedItems=0,CompletedItems=67365,Timers=4), v: 2.9.17.8862
   at StackExchange.Redis.ConnectionMultiplexer.ThrowFailed[T](TaskCompletionSource`1 source, Exception unthrownException) in /_/src/StackExchange.Redis/ConnectionMultiplexer.cs:line 2037
--- End of stack trace from previous location ---
   at Program.<>c__DisplayClass0_0.<<<Main>$>b__10>d.MoveNext() in /home/DN020397LEJ/ext/TechService2/PrivatBank.TechService.WebMonitoring.Web/Program.cs:line 107
StackExchange.Redis.RedisConnectionException: No connection (requires writable - not eligible for replica) is active/available to service this operation: SET Test_Tech_2_9, mc: 1/1/0, mgr: 10 of 10 available, clientName: dnh0-2-143(SE.Redis-v2.9.17.8862), IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=2,Free=32765,Min=8,Max=32767), POOL: (Threads=9,QueuedItems=0,CompletedItems=67375,Timers=3), v: 2.9.17.8862
   at StackExchange.Redis.ConnectionMultiplexer.ThrowFailed[T](TaskCompletionSource`1 source, Exception unthrownException) in /_/src/StackExchange.Redis/ConnectionMultiplexer.cs:line 2037
--- End of stack trace from previous location ---
   at Program.<>c__DisplayClass0_0.<<<Main>$>b__10>d.MoveNext() in /home/DN020397LEJ/ext/TechService2/PrivatBank.TechService.WebMonitoring.Web/Program.cs:line 107

[kcbark]

The last working version after investigating locally here seems to be 2.8.47.

[sluebbert]

We noticed the issue on 2.8.58 and latest (2.9.17).
Downgrading to 2.8.47 worked for us as well.

Simply asking the Redis sentinels to perform a graceful failover with the SENTINEL FAILOVER command is enough for us to recreate this. The client keeps its connection to the old master (now replica) and fails to allow any writes until a new connection is made.

[mgravell]

I've isolated this to this commit, which is super weird because all that is meant to change is some logging internals. Working on it...

[mgravell]

Found it; erroneous deletion: b4aaced#diff-b874d835cf9aa762b0e52adf8c37c2ed87b244f10dd36749ffdf735f0aea0e53L1645