search

StackExchange / StackExchange.Redis

General purpose redis client
https://stackexchange.github.io/StackExchange.Redis/
Other
5.88k stars 1.51k forks source link

Connection is not establishing with redis 7 server using StackExchange.Redis 2.7.1 version #2647

Closed attururosireddy closed 7 months ago

attururosireddy commented 7 months ago

Connection is not establishing with redis 7 server using StackExchange.Redis 2.7.17. But the same code works with redis 6 server.

Is StackExchange.Redis 2.7.17 compatible with redis 7. Please share your views 

using (StringWriter logs = new StringWriter())
 {   
         var options = ConfigurationOptions.Parse("redisserver");
         options.AbortOnConnectFail = false;
         ConnectionMultiplexer connectionMultiplexer = ConnectionMultiplexer.Connect(options, logs);
         var result = connectionMultiplexer.IsConnected // output is always false
 }

Please find the below logs

13:47:45.2344: Connecting (sync) on .NET 7.0.16 (StackExchange.Redis: v2.7.17.27058)
13:47:45.2678: redisserver:6379,syncTimeout=1000,allowAdmin=True,connectTimeout=1000,ssl=False,abortConnect=False
13:47:45.2779: redisserver:6379/Interactive: Connecting...
13:47:45.2908: redisserver:6379: BeginConnectAsync
13:47:45.2946: 1 unique nodes specified (with tiebreaker)
13:47:45.2956: redisserver:6379: OnConnectedAsync init (State=Connecting)
13:47:45.2971: Allowing 1 endpoint(s) 00:00:01 to respond...
13:47:45.3004: Awaiting 1 available task completion(s) for 1000ms, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=2,Free=32765,Min=8,Max=32767), POOL: (Threads=8,QueuedItems=0,CompletedItems=45,Timers=11)
13:47:45.3108: redisserver:6379/Interactive: Connected
13:47:45.3183: redisserver:6379: Server handshake
13:47:45.3536: redisserver:6379: Setting client name: scemodule-6c76dc7488-65ps7(SE.Redis-v2.7.17.27058)
13:47:45.3724: redisserver:6379: Setting client lib/ver
13:47:45.3757: redisserver:6379: Auto-configuring...
13:47:45.3773: redisserver:6379: Requesting tie-break (Key="__Booksleeve_TieBreak")...
13:47:45.3785: redisserver:6379/Interactive: Writing: GET __Booksleeve_TieBreak
13:47:45.3789: redisserver:6379: Sending critical tracer (handshake): ECHO
13:47:45.3789: redisserver:6379/Interactive: Writing: ECHO
13:47:45.3789: redisserver:6379: Flushing outbound buffer
13:47:45.3789: redisserver:6379: OnEstablishingAsync complete
13:47:45.3790: redisserver:6379: Starting read
13:47:45.3960: redisserver:6379: OnConnectedAsync completed (Disconnected)
13:47:45.3976: All 1 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=3,CompletedItems=59,Timers=10)
13:47:45.3980: Endpoint summary:
13:47:45.3987: redisserver:6379: Endpoint is (Interactive: ConnectedEstablishing, Subscription: Connecting)
13:47:45.3987: Task summary:
13:47:45.3988: redisserver:6379: Returned, but incorrectly
13:47:45.4008: Election summary:
13:47:45.4009: Election: redisserver:6379 had no tiebreaker set
13:47:45.4009: Election: No primaries detected
13:47:45.4014: Endpoint Summary:
13:47:45.4022: redisserver:6379: Standalone v3.0.0, primary; keep-alive: 00:01:00; int: ConnectedEstablishing; sub: Disconnected; not in use: DidNotRespond
13:47:45.4038: redisserver:6379: int ops=24, qu=0, qs=12, qc=0, wr=0, socks=2; sub ops=12, qu=0, qs=0, qc=0, wr=0, socks=2
13:47:45.4065: Connection failed: redisserver:6379 (Subscription, SocketClosed): SocketClosed (ReadEndOfStream, last-recv: 0) on redisserver:6379/Subscription, Flushed/MarkProcessed, last: SUBSCRIBE, origin: ReadFromPipe, outstanding: 5, last-read: 0s ago, last-write: 0s ago, unanswered-write: 0s ago, keep-alive: 60s, state: ConnectedEstablishing, mgr: 9 of 10 available, last-heartbeat: never, global: 0s ago, v: 2.7.17.27058
13:47:45.4075: Connection failed: redisserver:6379 (Interactive, SocketClosed): SocketClosed (ReadEndOfStream, last-recv: 0) on redisserver:6379/Interactive, Flushed/MarkProcessed, last: CLIENT, origin: ReadFromPipe, outstanding: 11, last-read: 0s ago, last-write: 0s ago, unanswered-write: 0s ago, keep-alive: 60s, state: ConnectedEstablishing, mgr: 9 of 10 available, last-heartbeat: never, global: 0s ago, v: 2.7.17.27058
13:47:45.4076: Connection failed: redisserver:6379 (Subscription, SocketClosed): SocketClosed (ReadEndOfStream, 0-sent, last-recv: 0) on redisserver:6379/Subscription, Flushed/MarkProcessed, last: SUBSCRIBE, origin: ReadFromPipe, outstanding: 5, last-read: 0s ago, last-write: 0s ago, unanswered-write: 0s ago, keep-alive: 60s, state: ConnectedEstablishing, mgr: 8 of 10 available, last-heartbeat: never, global: 0s ago, v: 2.7.17.27058
13:47:45.4161: redisserver:6379: Circular op-count snapshot; int: 0+24=24 (2.40 ops/s; spans 10s); sub: 0+12=12 (1.20 ops/s; spans 10s)
13:47:45.4165: Sync timeouts: 0; async timeouts: 0; fire and forget: 0; last heartbeat: -1s ago
13:47:45.4165: Resetting failing connections to retry...
13:47:45.4172: Retrying - attempts left: 2...
13:47:45.4172: 1 unique nodes specified (with tiebreaker)
13:47:45.4172: redisserver:6379: OnConnectedAsync init (State=Connecting)
13:47:45.4172: Allowing 1 endpoint(s) 00:00:01 to respond...
13:47:45.4173: Awaiting 1 available task completion(s) for 1000ms, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=4,Free=32763,Min=8,Max=32767), POOL: (Threads=9,QueuedItems=0,CompletedItems=82,Timers=11)
13:47:45.4185: redisserver:6379: OnConnectedAsync completed (Disconnected)
13:47:45.4186: All 1 available tasks completed cleanly, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=6,Free=32761,Min=8,Max=32767), POOL: (Threads=9,QueuedItems=0,CompletedItems=91,Timers=9)
13:47:45.4187: Endpoint summary:
13:47:45.4187: redisserver:6379: Endpoint is (Interactive: Disconnected, Subscription: ConnectedEstablishing)
13:47:45.4187: Task summary:
13:47:45.4187: redisserver:6379: Returned, but incorrectly
13:47:45.4187: Election summary:
13:47:45.4187: Election: redisserver:6379 had no tiebreaker set
13:47:45.4187: Election: No primaries detected
13:47:45.4187: Endpoint Summary:
13:47:45.4187: redisserver:6379: Standalone v3.0.0, primary; keep-alive: 00:01:00; int: Disconnected; sub: ConnectedEstablishing; not in use: DidNotRespond
13:47:45.4187: redisserver:6379: int ops=36, qu=0, qs=0, qc=0, wr=0, socks=3; sub ops=13, qu=0, qs=2, qc=0, wr=0, socks=3
13:47:45.4187: redisserver:6379: Circular op-count snapshot; int: 0+36=36 (3.60 ops/s; spans 10s); sub: 0+13=13 (1.30 ops/s; spans 10s)
13:47:45.4188: Sync timeouts: 0; async timeouts: 0; fire and forget: 0; last heartbeat: -1s ago
13:47:45.4188: Resetting failing connections to retry...
13:47:45.4193: Retrying - attempts left: 1...
13:47:45.4193: 1 unique nodes specified (with tiebreaker)
13:47:45.4193: redisserver:6379: OnConnectedAsync init (State=Connecting)
13:47:45.4193: Allowing 1 endpoint(s) 00:00:01 to respond...
13:47:45.4193: Awaiting 1 available task completion(s) for 1000ms, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=5,Free=32762,Min=8,Max=32767), POOL: (Threads=9,QueuedItems=0,CompletedItems=97,Timers=11)
13:47:45.4212: redisserver:6379: OnConnectedAsync completed (Disconnected)
13:47:45.4212: All 1 available tasks completed cleanly, IOCP: (Busy=0,Free=1000,Min=1,Max=1000), WORKER: (Busy=4,Free=32763,Min=8,Max=32767), POOL: (Threads=9,QueuedItems=1,CompletedItems=111,Timers=9)
13:47:45.4213: Endpoint summary:
13:47:45.4213: redisserver:6379: Endpoint is (Interactive: Disconnected, Subscription: Disconnected)
13:47:45.4213: Task summary:
13:47:45.4213: redisserver:6379: Returned, but incorrectly
13:47:45.4213: Election summary:
13:47:45.4213: Election: redisserver:6379 had no tiebreaker set
13:47:45.4213: Election: No primaries detected
13:47:45.4213: Endpoint Summary:
13:47:45.4213: redisserver:6379: Standalone v3.0.0, primary; keep-alive: 00:01:00; int: Disconnected; sub: Disconnected; not in use: DidNotRespond
13:47:45.4213: redisserver:6379: int ops=48, qu=0, qs=0, qc=0, wr=0, socks=4; sub ops=24, qu=0, qs=0, qc=0, wr=0, socks=4
13:47:45.4213: redisserver:6379: Circular op-count snapshot; int: 0+48=48 (4.80 ops/s; spans 10s); sub: 0+24=24 (2.40 ops/s; spans 10s)
13:47:45.4213: Sync timeouts: 0; async timeouts: 0; fire and forget: 0; last heartbeat: -1s ago
13:47:45.4215: Starting heartbeat...
13:47:45.4226: Total connect time: 190 ms

(edited for formatting)

mgravell commented 7 months ago

This is intriguing, but I suspect there's something config related; testing locally, I have a 7.1.240 server:

marc@mgx:~$ redis-cli
127.0.0.1:6379> info server
# Server
redis_version:7.1.240

and testing with:

using StackExchange.Redis;

using var muxer = ConnectionMultiplexer.Connect("localhost");
Console.WriteLine(muxer.IsConnected);
foreach (var server in muxer.GetServers())
{
    Console.WriteLine($"{server}: {server.Version}");
}

I see:

True
MGX(SE.Redis - v2.7.17.27058): 7.1.240

so: I accept that it isn't connecting, but: there is no fundamental/inherent reason that it shouldn't, which means we need to look more at "why?"

The first thing I would suggest is: try connecting from that same machine via redis-cli - much like I have above. If that fails, all bets are off. In particular: does:

redis-cli -h redisserver info server

work from the test machine?

mgravell commented 7 months ago

My initial hunches, to be explicit:

attururosireddy commented 7 months ago

sh-5.1$ redis-cli -h redisserver info server

DENIED Redis is running in protected mode because protected mode is enabled and no password is set for the default user. In this mode connections are only accepted from the loopback interface. If you want to connect from external computers to Redis you may adopt one of the following solutions: 1) Just disable protected mode sending the command 'CONFIG SET protected-mode no' from the loopback interface by connecting to Redis from the same host the server is running, however MAKE SURE Redis is not publicly accessible from internet if you do so. Use CONFIG REWRITE to make this change permanent. 2) Alternatively you can just disable the protected mode by editing the Redis configuration file, and setting the protected mode option to 'no', and then restarting the server. 3) If you started the server manually just for testing, restart it with the '--protected-mode no' option. 4) Setup a an authentication password for the default user. NOTE: You only need to do one of the above things in order for the server to start accepting connections from the outside.

mgravell commented 7 months ago

so... fix that :) this is entirely a "your server" thing

attururosireddy commented 7 months ago

But I am getting valid response from Redis 6 server with same below redis.conf

save 60 1 dbfilename dbname.rdb dir ./ bind 0.0.0.0 port 6379

Connection didnt establish when I upgrade from Redis 6 to Redis 7

mgravell commented 7 months ago

Yes, redis 7 at the server changes the security mode in the scenarios described in the DENIED; you upgraded the server to 7, which means those new redis 7 rules apply. You need to pick one of the available options described (1-4, as most appropriate to your needs), and do that.

To rephrase: redis 7 has changed the rules, and is rejecting your connection. I can't do anything about that at the client - all clients (including redis-cli) will be unable to connect if the server doesn't allow remote connections; you need to reconfigure the server. Options 1 and 2 use the redis 6 rules; option 3 only applies to ad-hoc runs, and option 4 needs you to configure the client and server with the same auth credentials.

attururosireddy commented 7 months ago

@mgravell Thank you very much for this command "redis-cli -h redisserver info server" which helped to find the root cause

mgravell commented 7 months ago

Checking notes, it looks like protected mode has existed since 3.2.0 - I wonder if it is possible that your redis 6 server was running, but CONFIG SET protected-mode no had been executed, without a CONFIG REWRITE, i.e. the reconfiguration was transient in the running server process, but the moment you restarted the server (as part of the upgrade) it defaulted back to protected mode.