StackExchange.Redis
StackExchange.Redis copied to clipboard
Published
20 hours ago •
StackExchange
StackExchange
Randomly got error Sentinel: The ConnectionMultiplexer is not a Sentinel in Kubernetes pod
Hi @mgravell, I'm using StackExchange.Redis 2.7.17 to connect to Redis Sentinel and facing this strange issue
There is a service with 8 pods running on Kubernetes, sometimes when there is a new deployment that spinned up a new service's pods, there will be 1 pod got this exception "Sentinel: The ConnectionMultiplexer is not a Sentinel connection. Detected as: Standalone". Currently we have to fix it manually by deleting this 'fault' pod, when new pod is intialized, the error is gone
Our connection strings are: kala-c1redis-01.abc.lc:26379;kala-c1redis-02.abc.lc:26379;kala-c1redis-03.abc.lc:26379
I have put the logger into the ConnectionMultiplexer.Connect(options, writer); and here is the log
Do you have any ideas on this?
[
"Redis connection info: Total connect time: 7,096 ms",
"Redis connection info: 08:39:51.0586:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: OnConnectedAsync completed (Disconnected)",
"Redis connection info: 08:39:51.0582:",
"Redis connection info: Starting heartbeat...",
"Redis connection info: 08:39:51.0572:",
"Redis connection info: Sync timeouts: 0; async timeouts: 0; fire and forget: 0; last heartbeat: -1s ago",
"Redis connection info: 08:39:51.0569:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: Circular op-count snapshot; int: 0 (0.00 ops/s; spans 10s); sub: 0 (0.00 ops/s; spans 10s)",
"Redis connection info: 08:39:51.0568:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: int ops=0, qu=0, qs=0, qc=0, wr=0, socks=2; sub ops=0, qu=0, qs=0, qc=0, wr=0, socks=2",
"Redis connection info: 08:39:51.0567:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: Standalone v3.0.0, primary; keep-alive: 00:03:00; int: Disconnected; sub: Connecting; not in use: DidNotRespond",
"Redis connection info: 08:39:51.0566:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: Circular op-count snapshot; int: 0 (0.00 ops/s; spans 10s); sub: 0 (0.00 ops/s; spans 10s)",
"Redis connection info: 08:39:51.0566:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: int ops=0, qu=0, qs=0, qc=0, wr=0, socks=2; sub ops=0, qu=0, qs=0, qc=0, wr=0, socks=2",
"Redis connection info: 08:39:51.0565:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: Standalone v3.0.0, primary; keep-alive: 00:03:00; int: Disconnected; sub: Disconnected; not in use: DidNotRespond",
"Redis connection info: 08:39:51.0564:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: Circular op-count snapshot; int: 0 (0.00 ops/s; spans 10s); sub: 0 (0.00 ops/s; spans 10s)",
"Redis connection info: 08:39:51.0563:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: int ops=0, qu=0, qs=0, qc=0, wr=0, socks=2; sub ops=0, qu=0, qs=0, qc=0, wr=0, socks=2",
"Redis connection info: 08:39:51.0562:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: Standalone v3.0.0, primary; keep-alive: 00:03:00; int: Disconnected; sub: Disconnected; not in use: DidNotRespond",
"Redis connection info: 08:39:51.0561:",
"Redis connection info: Endpoint Summary:",
"Redis connection info: 08:39:51.0560:",
"Redis connection info: Election: No primaries detected",
"Redis connection info: 08:39:51.0559:",
"Redis connection info: Election summary:",
"Redis connection info: 08:39:51.0558:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: Returned, but incorrectly",
"Redis connection info: 08:39:51.0557:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: Returned, but incorrectly",
"Redis connection info: 08:39:51.0556:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: Returned, but incorrectly",
"Redis connection info: 08:39:51.0555:",
"Redis connection info: Task summary:",
"Redis connection info: 08:39:51.0553:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: Endpoint is (Interactive: Disconnected, Subscription: Connecting)",
"Redis connection info: 08:39:51.0552:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: Endpoint is (Interactive: Disconnected, Subscription: Disconnected)",
"Redis connection info: 08:39:51.0551:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: Endpoint is (Interactive: Disconnected, Subscription: Disconnected)",
"Redis connection info: 08:39:51.0550:",
"Redis connection info: Endpoint summary:",
"Redis connection info: 08:39:51.0549:",
"Redis connection info: All 3 available tasks completed cleanly, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=12,Free=32755,Min=1,Max=32767), POOL: (Threads=12,QueuedItems=6,CompletedItems=57,Timers=30)",
"Redis connection info: 08:39:51.0547:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: OnConnectedAsync completed (Disconnected)",
"Redis connection info: 08:39:51.0542:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: OnConnectedAsync completed (Disconnected)",
"Redis connection info: 08:39:51.0536:",
"Redis connection info: Connection failed: kala-c1redis-01.abc.lc:26379 (Interactive, UnableToConnect): UnableToConnect on kala-c1redis-01.abc.lc:26379/Interactive, Initializing/NotStarted, last: NONE, origin: BeginConnectAsync, outstanding: 0, last-read: 6s ago, last-write: 6s ago, keep-alive: 180s, state: Connecting, mgr: 10 of 10 available, last-heartbeat: never, global: 7s ago, v: 2.7.17.27058",
"Redis connection info: 08:39:51.0528:",
"Redis connection info: Connection failed: kala-c1redis-01.abc.lc:26379 (Subscription, UnableToConnect): UnableToConnect on kala-c1redis-01.abc.lc:26379/Subscription, Initializing/NotStarted, last: NONE, origin: BeginConnectAsync, outstanding: 0, last-read: 6s ago, last-write: 6s ago, keep-alive: 180s, state: Connecting, mgr: 10 of 10 available, last-heartbeat: never, global: 7s ago, v: 2.7.17.27058",
"Redis connection info: 08:39:51.0527:",
"Redis connection info: Connection failed: kala-c1redis-02.abc.lc:26379 (Interactive, UnableToConnect): UnableToConnect on kala-c1redis-02.abc.lc:26379/Interactive, Initializing/NotStarted, last: NONE, origin: BeginConnectAsync, outstanding: 0, last-read: 6s ago, last-write: 6s ago, keep-alive: 180s, state: Connecting, mgr: 10 of 10 available, last-heartbeat: never, global: 7s ago, v: 2.7.17.27058",
"Redis connection info: 08:39:51.0525:",
"Redis connection info: Connection failed: kala-c1redis-02.abc.lc:26379 (Subscription, UnableToConnect): UnableToConnect on kala-c1redis-02.abc.lc:26379/Subscription, Initializing/NotStarted, last: NONE, origin: BeginConnectAsync, outstanding: 0, last-read: 6s ago, last-write: 6s ago, keep-alive: 180s, state: Connecting, mgr: 10 of 10 available, last-heartbeat: never, global: 7s ago, v: 2.7.17.27058",
"Redis connection info: 08:39:51.0524:",
"Redis connection info: Connection failed: kala-c1redis-03.abc.lc:26379 (Interactive, UnableToConnect): UnableToConnect on kala-c1redis-03.abc.lc:26379/Interactive, Initializing/NotStarted, last: NONE, origin: BeginConnectAsync, outstanding: 0, last-read: 6s ago, last-write: 6s ago, keep-alive: 180s, state: Connecting, mgr: 10 of 10 available, last-heartbeat: never, global: 7s ago, v: 2.7.17.27058",
"Redis connection info: 08:39:51.0522:",
"Redis connection info: Connection failed: kala-c1redis-03.abc.lc:26379 (Subscription, UnableToConnect): UnableToConnect on kala-c1redis-03.abc.lc:26379/Subscription, Initializing/NotStarted, last: NONE, origin: BeginConnectAsync, outstanding: 0, last-read: 6s ago, last-write: 6s ago, keep-alive: 180s, state: Connecting, mgr: 10 of 10 available, last-heartbeat: never, global: 7s ago, v: 2.7.17.27058",
"Redis connection info: 08:39:51.0506:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: OnConnectedAsync completed (Disconnected)",
"Redis connection info: 08:39:51.0394:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: OnConnectedAsync completed (Disconnected)",
"Redis connection info: 08:39:51.0392:",
"Redis connection info: Awaiting 3 available task completion(s) for 5000ms, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=12,Free=32755,Min=1,Max=32767), POOL: (Threads=12,QueuedItems=19,CompletedItems=37,Timers=30)",
"Redis connection info: 08:39:51.0391:",
"Redis connection info: Allowing 3 endpoint(s) 00:00:05 to respond...",
"Redis connection info: 08:39:51.0388:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: OnConnectedAsync init (State=Connecting)",
"Redis connection info: 08:39:51.0387:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: OnConnectedAsync init (State=Connecting)",
"Redis connection info: 08:39:51.0386:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: OnConnectedAsync init (State=Connecting)",
"Redis connection info: 08:39:51.0384:",
"Redis connection info: 3 unique nodes specified (without tiebreaker)",
"Redis connection info: 08:39:51.0383:",
"Redis connection info: Retrying - attempts left: 1...",
"Redis connection info: 08:39:51.0380:",
"Redis connection info: Resetting failing connections to retry...",
"Redis connection info: 08:39:51.0348:",
"Redis connection info: Sync timeouts: 0; async timeouts: 0; fire and forget: 0; last heartbeat: -1s ago",
"Redis connection info: 08:39:51.0347:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: Circular op-count snapshot; int: 0 (0.00 ops/s; spans 10s); sub: 0 (0.00 ops/s; spans 10s)",
"Redis connection info: 08:39:51.0345:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: int ops=0, qu=0, qs=0, qc=0, wr=0, socks=2; sub ops=0, qu=0, qs=0, qc=0, wr=0, socks=2",
"Redis connection info: 08:39:51.0344:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: Standalone v3.0.0, primary; keep-alive: 00:03:00; int: Connecting; sub: Connecting; not in use: DidNotRespond",
"Redis connection info: 08:39:51.0343:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: Circular op-count snapshot; int: 0 (0.00 ops/s; spans 10s); sub: 0 (0.00 ops/s; spans 10s)",
"Redis connection info: 08:39:51.0342:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: int ops=0, qu=0, qs=0, qc=0, wr=0, socks=2; sub ops=0, qu=0, qs=0, qc=0, wr=0, socks=2",
"Redis connection info: 08:39:51.0340:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: Standalone v3.0.0, primary; keep-alive: 00:03:00; int: Connecting; sub: Connecting; not in use: DidNotRespond",
"Redis connection info: 08:39:51.0339:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: Circular op-count snapshot; int: 0 (0.00 ops/s; spans 10s); sub: 0 (0.00 ops/s; spans 10s)",
"Redis connection info: 08:39:51.0338:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: int ops=0, qu=0, qs=0, qc=0, wr=0, socks=2; sub ops=0, qu=0, qs=0, qc=0, wr=0, socks=2",
"Redis connection info: 08:39:51.0337:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: Standalone v3.0.0, primary; keep-alive: 00:03:00; int: Connecting; sub: Connecting; not in use: DidNotRespond",
"Redis connection info: 08:39:51.0335:",
"Redis connection info: Endpoint Summary:",
"Redis connection info: 08:39:51.0333:",
"Redis connection info: Election: No primaries detected",
"Redis connection info: 08:39:51.0332:",
"Redis connection info: Election summary:",
"Redis connection info: 08:39:51.0331:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: Returned, but incorrectly",
"Redis connection info: 08:39:51.0330:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: Returned, but incorrectly",
"Redis connection info: 08:39:51.0328:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: Returned, but incorrectly",
"Redis connection info: 08:39:51.0327:",
"Redis connection info: Task summary:",
"Redis connection info: 08:39:51.0326:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: Endpoint is (Interactive: Connecting, Subscription: Connecting)",
"Redis connection info: 08:39:51.0325:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: Endpoint is (Interactive: Connecting, Subscription: Connecting)",
"Redis connection info: 08:39:51.0323:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: Endpoint is (Interactive: Connecting, Subscription: Connecting)",
"Redis connection info: 08:39:51.0321:",
"Redis connection info: Endpoint summary:",
"Redis connection info: 08:39:51.0320:",
"Redis connection info: All 3 available tasks completed cleanly, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=12,Free=32755,Min=1,Max=32767), POOL: (Threads=12,QueuedItems=13,CompletedItems=37,Timers=30)",
"Redis connection info: 08:39:51.0317:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: OnConnectedAsync completed (Disconnected)",
"Redis connection info: 08:39:51.0141:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: OnConnectedAsync completed (Disconnected)",
"Redis connection info: 08:39:51.0138:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: OnConnectedAsync completed (Disconnected)",
"Redis connection info: 08:39:51.0030:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: OnConnectedAsync completed (Disconnected)",
"Redis connection info: 08:39:51.0026:",
"Redis connection info: Awaiting 3 available task completion(s) for 5000ms, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=11,Free=32756,Min=1,Max=32767), POOL: (Threads=11,QueuedItems=12,CompletedItems=8,Timers=24)",
"Redis connection info: 08:39:50.0827:",
"Redis connection info: Allowing 3 endpoint(s) 00:00:05 to respond...",
"Redis connection info: 08:39:50.0824:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: OnConnectedAsync init (State=Connecting)",
"Redis connection info: 08:39:50.0823:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: OnConnectedAsync init (State=Connecting)",
"Redis connection info: 08:39:50.0821:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: OnConnectedAsync init (State=Connecting)",
"Redis connection info: 08:39:50.0819:",
"Redis connection info: 3 unique nodes specified (without tiebreaker)",
"Redis connection info: 08:39:50.0817:",
"Redis connection info: Retrying - attempts left: 2...",
"Redis connection info: 08:39:50.0814:",
"Redis connection info: Resetting failing connections to retry...",
"Redis connection info: 08:39:50.0448:",
"Redis connection info: Sync timeouts: 0; async timeouts: 0; fire and forget: 0; last heartbeat: -1s ago",
"Redis connection info: 08:39:50.0445:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: Circular op-count snapshot; int: 0 (0.00 ops/s; spans 10s); sub: 0 (0.00 ops/s; spans 10s)",
"Redis connection info: 08:39:50.0440:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: int ops=0, qu=0, qs=0, qc=0, wr=0, socks=1; sub ops=0, qu=0, qs=0, qc=0, wr=0, socks=1",
"Redis connection info: 08:39:50.0439:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: Standalone v3.0.0, primary; keep-alive: 00:03:00; int: Connecting; sub: Connecting; not in use: DidNotRespond",
"Redis connection info: 08:39:50.0438:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: Circular op-count snapshot; int: 0 (0.00 ops/s; spans 10s); sub: 0 (0.00 ops/s; spans 10s)",
"Redis connection info: 08:39:50.0436:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: int ops=0, qu=0, qs=0, qc=0, wr=0, socks=1; sub ops=0, qu=0, qs=0, qc=0, wr=0, socks=1",
"Redis connection info: 08:39:50.0435:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: Standalone v3.0.0, primary; keep-alive: 00:03:00; int: Connecting; sub: Connecting; not in use: DidNotRespond",
"Redis connection info: 08:39:50.0432:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: Circular op-count snapshot; int: 0 (0.00 ops/s; spans 10s); sub: 0 (0.00 ops/s; spans 10s)",
"Redis connection info: 08:39:50.0105:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: int ops=0, qu=0, qs=0, qc=0, wr=0, socks=1; sub ops=0, qu=0, qs=0, qc=0, wr=0, socks=1",
"Redis connection info: 08:39:49.9992:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: Standalone v3.0.0, primary; keep-alive: 00:03:00; int: Connecting; sub: Connecting; not in use: DidNotRespond",
"Redis connection info: 08:39:49.9953:",
"Redis connection info: Endpoint Summary:",
"Redis connection info: 08:39:49.9939:",
"Redis connection info: Election: No primaries detected",
"Redis connection info: 08:39:49.9881:",
"Redis connection info: Election summary:",
"Redis connection info: 08:39:49.9876:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: Did not respond (Task.Status: WaitingForActivation)",
"Redis connection info: 08:39:49.9756:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: Did not respond (Task.Status: WaitingForActivation)",
"Redis connection info: 08:39:49.9755:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: Did not respond (Task.Status: WaitingForActivation)",
"Redis connection info: 08:39:49.9753:",
"Redis connection info: Task summary:",
"Redis connection info: 08:39:49.9751:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: Endpoint is (Interactive: Connecting, Subscription: Connecting)",
"Redis connection info: 08:39:49.9749:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: Endpoint is (Interactive: Connecting, Subscription: Connecting)",
"Redis connection info: 08:39:49.9748:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: Endpoint is (Interactive: Connecting, Subscription: Connecting)",
"Redis connection info: 08:39:49.9745:",
"Redis connection info: Endpoint summary:",
"Redis connection info: 08:39:49.9728:",
"Redis connection info: Server[2] (kala-c1redis-03.abc.lc:26379) Status: WaitingForActivation (inst: 0, qs: 0, in: 0, qu: 0, aw: False, in-pipe: -1, out-pipe: -1, bw: Inactive, rs: NotStarted. ws: Initializing)",
"Redis connection info: 08:39:49.9727:",
"Redis connection info: Server[1] (kala-c1redis-02.abc.lc:26379) Status: WaitingForActivation (inst: 0, qs: 0, in: 0, qu: 0, aw: False, in-pipe: -1, out-pipe: -1, bw: Inactive, rs: NotStarted. ws: Initializing)",
"Redis connection info: 08:39:49.9725:",
"Redis connection info: Server[0] (kala-c1redis-01.abc.lc:26379) Status: WaitingForActivation (inst: 0, qs: 0, in: 0, qu: 0, aw: False, in-pipe: -1, out-pipe: -1, bw: Inactive, rs: NotStarted. ws: Initializing)",
"Redis connection info: 08:39:49.9721:",
"Redis connection info: Not all available tasks completed cleanly (from ReconfigureAsync#1499, timeout 5000ms), IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=11,Free=32756,Min=1,Max=32767), POOL: (Threads=11,QueuedItems=12,CompletedItems=8,Timers=24)",
"Redis connection info: 08:39:49.9628:",
"Redis connection info: Awaiting 3 available task completion(s) for 5000ms, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=5,Free=32762,Min=1,Max=32767), POOL: (Threads=5,QueuedItems=13,CompletedItems=6,Timers=30)",
"Redis connection info: 08:39:44.0890:",
"Redis connection info: Allowing 3 endpoint(s) 00:00:05 to respond...",
"Redis connection info: 08:39:44.0690:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: OnConnectedAsync init (State=Connecting)",
"Redis connection info: 08:39:44.0671:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: OnConnectedAsync init (State=Connecting)",
"Redis connection info: 08:39:44.0668:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: OnConnectedAsync init (State=Connecting)",
"Redis connection info: 08:39:44.0663:",
"Redis connection info: 3 unique nodes specified (without tiebreaker)",
"Redis connection info: 08:39:44.0631:",
"Redis connection info: kala-c1redis-03.abc.lc:26379: BeginConnectAsync",
"Redis connection info: 08:39:44.0619:",
"Redis connection info: kala-c1redis-03.abc.lc:26379/Interactive: Connecting...",
"Redis connection info: 08:39:44.0613:",
"Redis connection info: kala-c1redis-02.abc.lc:26379: BeginConnectAsync",
"Redis connection info: 08:39:44.0605:",
"Redis connection info: kala-c1redis-02.abc.lc:26379/Interactive: Connecting...",
"Redis connection info: 08:39:44.0597:",
"Redis connection info: kala-c1redis-01.abc.lc:26379: BeginConnectAsync",
"Redis connection info: 08:39:44.0503:",
"Redis connection info: kala-c1redis-01.abc.lc:26379/Interactive: Connecting...",
"Redis connection info: 08:39:44.0309:",
"Redis connection info: kala-c1redis-01.abc.lc:26379,kala-c1redis-02.abc.lc:26379,kala-c1redis-03.abc.lc:26379,serviceName=mymaster,keepAlive=180,ssl=False,abortConnect=False,connectRetry=3",
"Redis connection info: 08:39:44.0209:",
"Redis connection info: Connecting (sync) on .NET 6.0.27 (StackExchange.Redis: v2.7.17.27058)",
"Redis connection info: 08:39:43.9631:"
]
Here is the RedisCacheClient code
public class RedisCacheClientFactory : IRedisCacheClientFactory, IDisposable
{
private readonly ConcurrentDictionary<Tuple<string, string>, Lazy<ConnectionMultiplexer>> _redisConnections;
private readonly IConfiguration _configuration;
private readonly ILogger<RedisCacheClientFactory> _logger;
private readonly SemaphoreSlim _connectionLock = new SemaphoreSlim(1, 1);
private bool _disposed;
private DateTimeOffset _lastReconnectTime = DateTimeOffset.MinValue;
private readonly TimeSpan _minReconnectInterval = TimeSpan.FromMinutes(1);
private readonly object _reconnectLock = new object();
private const string DefaultServiceName = "mymaster";
private readonly bool _enableSsl;
private readonly string _sslCertPath;
private readonly bool _enableDetailLogger;
public RedisCacheClientFactory(ILogger<RedisCacheClientFactory> logger, IConfiguration configuration)
{
_redisConnections = new ConcurrentDictionary<Tuple<string, string>, Lazy<ConnectionMultiplexer>>();
_configuration = configuration;
_logger = logger;
bool.TryParse(_configuration["Redis:EnableSsl"], out _enableSsl);
// SERedis_IssuerCertPath should be set in GitOps ConfigMaps of service/application
_sslCertPath = _configuration["SERedis_IssuerCertPath"];
bool.TryParse(_configuration["Redis:EnableDetailLogger"], out _enableDetailLogger);
}
public ConnectionMultiplexer GetInstance(string connectionString, string instanceName)
{
var key = new Tuple<string, string>(connectionString, instanceName);
var lazyConnection = _redisConnections.GetOrAdd(key, _ => new Lazy<ConnectionMultiplexer>(() => ConnectWithRetry(connectionString, instanceName)));
return lazyConnection.Value;
}
private ConnectionMultiplexer ConnectWithRetry(string connectionString, string instanceName)
{
var connection = CreateConnection(connectionString, instanceName);
connection.ConnectionFailed += OnConnectionFailed;
connection.ConnectionRestored += OnConnectionRestored;
connection.InternalError += OnInternalError;
connection.ErrorMessage += OnErrorMessage;
return connection;
}
private void OnConnectionFailed(object sender, ConnectionFailedEventArgs e)
{
_logger.LogError("Redis error - Connection Failed: {message}", e.Exception?.Message);
if (DateTimeOffset.UtcNow - _lastReconnectTime < _minReconnectInterval)
{
return;
}
lock (_reconnectLock)
{
if (DateTimeOffset.UtcNow - _lastReconnectTime < _minReconnectInterval)
{
return;
}
_lastReconnectTime = DateTimeOffset.UtcNow;
_logger.LogWarning("Attempting to reconnect to Redis...");
foreach (var keyValuePair in _redisConnections)
{
var key = keyValuePair.Key;
_connectionLock.Wait();
try
{
_redisConnections[key] = new Lazy<ConnectionMultiplexer>(() => CreateConnection(key.Item1, key.Item2));
}
finally
{
_connectionLock.Release();
}
}
}
}
private void OnConnectionRestored(object? sender, ConnectionFailedEventArgs e)
{
_logger.LogWarning("Redis error - connection restored");
}
private void OnInternalError(object? sender, InternalErrorEventArgs e)
{
_logger.LogError(e.Exception, "Redis error - internal: {Origin}", e.Origin);
}
private void OnErrorMessage(object? sender, RedisErrorEventArgs e)
{
_logger.LogError("Redis error: {Message}", e.Message);
}
private ConnectionMultiplexer CreateConnection(string connectionString, string instanceName)
{
ConfigurationOptions options = new ConfigurationOptions();
options.TieBreaker = "";
options.AbortOnConnectFail = false;
options.Ssl = false;
options.ConnectRetry = 3;
options.ReconnectRetryPolicy = new ExponentialRetry(5000);
options.KeepAlive = 180;
options.ServiceName = instanceName ?? DefaultServiceName;
options.SocketManager = SocketManager.Shared;
options.IncludeDetailInExceptions = true;
options.IncludePerformanceCountersInExceptions = true;
if (_enableSsl)
{
if (string.IsNullOrEmpty(_sslCertPath))
{
throw new Exception("Redis error: CA cert path not set! Check service GitOps ConfigMap variable");
}
options.Ssl = true;
options.SslProtocols = SslProtocols.Tls12;
}
foreach (var item in connectionString.Split(';'))
{
options.EndPoints.Add(item);
}
if (_enableDetailLogger)
{
var writer = new RedisLoggerTextWriter(_logger, LogLevel.Warning);
return ConnectionMultiplexer.Connect(options, writer);
}
return ConnectionMultiplexer.Connect(options);
}
public void Dispose()
{
if (_disposed) return;
foreach (var connection in _redisConnections.Values)
{
if (connection.IsValueCreated)
{
connection.Value.ConnectionFailed -= OnConnectionFailed;
connection.Value.ConnectionRestored -= OnConnectionRestored;
connection.Value.InternalError -= OnInternalError;
connection.Value.ErrorMessage -= OnErrorMessage;
connection.Value.Dispose();
}
}
_disposed = true;
}
}
Updates: looks like this issue is relevant to our network and Istio usage in our Kubernetes cluster.
I used this annotation to exclude the 26379 and 6379 port and ~~this issue stopped happen since this afternoon~~
traffic.sidecar.istio.io/excludeOutboundPorts: "26379,6379"
https://istio.io/latest/docs/reference/config/annotations/#SidecarTrafficExcludeOutboundPorts
=> The issue still happened this morning, so it's not a correct fix.
Updated: we have tried disable Istio for this service and the issue has gone.
I'll be honest: I have no idea what that means, but: I'm glad you found the problem. I wouldn't have stood a chance.
