node-redis icon indicating copy to clipboard operation
node-redis copied to clipboard

Reconnect strategy not being used and ready event fired without being ready.

Open Algirdyz opened this issue 3 years ago • 8 comments

I've recently upgraded to node redis 4.1.0 and I'm having issues with reconnectStrategy and connection handling in general.

Logs from reconnectstrategy are never printed. When I start with redis server down. I still get the ready event triggered. A bit later I get an error event and it immediately "connects" (triggering ready again); And this just continues; The 5 second reconnect timer is not used.

When redis is online when I start the application and I later turn it off: it seems to go even faster. It does not wait long between the ready event and an error.

I'm initializing redis like so:

const options: RedisClientOptions<RedisModules, RedisFunctions, S> = {
    username: this.username,
    password: this.password,
    socket: {
        host: this.host,
        port: this.port,
        reconnectStrategy: (attempts) => {
            console.log(`Redis reconnecting attempt ${attempts}`);
            this.connected = false;
            if (attempts == 1) {
                console.log(`${this.constructor.name} failed to connect to ${this.host}:${this.port}. Reconnecting...`);
            }
            return 5000;
        },
    },
    scripts: scripts,
};
const redisClient = createClient(options);
redisClient.on('ready', () => {
    console.log(`${this.constructor.name} connected to ${this.host}:${this.port}`);
});
redisClient.on('error', (err) => {
    console.log('error');
    return;
});
redisClient.on('reconnecting', () => {
    return;
});
redisClient.on('end', () => {
    return;
});
redisClient.on('connect', () => {
    return;
});

redisClient.connect();

Environment:

  • Node.js Version: v14.16.0
  • Node Redis Version: 4.1.0
  • Platform: Mac OS 12.3.1

Algirdyz avatar May 05 '22 11:05 Algirdyz

This code does not reproduce the issue, am I missing something?

import { createClient } from '@redis/client';

const client = createClient({
        socket: {
            reconnectStrategy() {
                console.log('reconnectStrategy', new Date().toJSON());
                return 5000;
            }
        }
    })
    .on('connect', () => console.log('connect', new Date().toJSON()))
    .on('ready', () => console.log('ready', new Date().toJSON()))
    .on('error', err => console.error('error', err, new Date().toJSON()));

try {
    await client.connect();
} catch (err) {
    console.error('connect err', err, new Date().toJSON());
}

leibale avatar May 10 '22 15:05 leibale

Thanks for your reply. I tried a bit with your code and found some things out. It seems to work when I use a local redis service and start/stop it using brew services start redis

However I work with kubernetes a lot and my redis server is port forwarded to my localhost as follows: kubectl port-forward service/redis-master 7000:6379

When I connect to this redis instance reconnectstrategy does not work

The error for local redis instance is:

error Error: connect ECONNREFUSED 127.0.0.1:6379
    at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16)
    at TCPConnectWrap.callbackTrampoline (internal/async_hooks.js:131:14) {
  errno: -61,
  code: 'ECONNREFUSED',
  syscall: 'connect',
  address: '127.0.0.1',
  port: 6379
} 2022-05-11T15:22:25.365Z

The error for port forwarded redis instance is:

error Error: read ECONNRESET
    at TCP.onStreamRead (internal/stream_base_commons.js:209:20)
    at TCP.callbackTrampoline (internal/async_hooks.js:131:14) {
  errno: -54,
  code: 'ECONNRESET',
  syscall: 'read'
} 2022-05-11T15:24:51.735Z

Algirdyz avatar May 11 '22 15:05 Algirdyz

Also when I get this error it doesn't listen to reconnectstrategy

[error]: Error: Socket closed unexpectedly
    at Socket.<anonymous> (node_modules/@redis/client/dist/lib/client/socket.js:156:118)
    at Object.onceWrapper (events.js:422:26)
    at Socket.emit (events.js:315:20)
    at TCP.<anonymous> (net.js:673:12)
    at TCP.callbackTrampoline (internal/async_hooks.js:131:14)

Algirdyz avatar May 12 '22 14:05 Algirdyz

reconnedStrategy kick in after the second (or more) consecutive error in the socket creation process, for example: try to connect > ECONNREFUSED > reconnedStrategy > try again

with ECONNRESET and Socket closed unexpectedly its a little bit different: try to connect > connect event > ECONNRESET/Socket closed unexpectedly > try to connect (without reconnedStrategy, cause the socket fired a connect event)

leibale avatar May 12 '22 15:05 leibale

So to me sounds like reconnectstrategy should be incorporated into this error flow as well. No?

EDIT: Anyway I did more testing and it seems that literally just changing the port causes the error to go from ECONNREFUSED to ECONNRESET. So I disabled my local redis service and stopped kubernetes portforwarding. So neither of those ports have anything running on them.

When I run the same piece of code you provided just adding localhost as host and either 6379 or 7000 as port. I get ECONNREFUSED on 6379 and ECONNRESET on 7000

I started investigating and found out that there is something called afs-fileserver ruinning on my PC on port 7000. On a mac it is Airplay Receiver apparently... I disabled it and now I get ECONNREFUSED and it uses reconnectstrategy.

However, that makes me think that node-redis does not handle other kinds of disconnects properly? When can ECONNRESET/Socket closed unexpectedly happen? Should I implement ways to recover from that?

Algirdyz avatar May 13 '22 09:05 Algirdyz

  • Experiencing the exact same problem after upgrading from redis v3.x to v4.x
  • Problem: The reconnect strategy behavior is not consistent in handling all error events (as in the previous version)
  • Problem: The specified reconnect strategy is not being invoked initially after the socket is closed unexpectedly
    • A reconnecting event is fired immediately after the connection is lost (with no delay)
  • Problem: Even more alarming is that the client goes into an infinite loop reconnect death spiral if I artificially manufacture a disconnect by temporarily disabling my Ethernet adapter
  • e.g.
[2022-06-06T21:10:56.320] [INFO ] [redis-client    ] [Reconnect Attempt # 0]: Redis server reconnect attempt initiated after 0 ms.
- Total Retry Time: 00:00:00.000 (0 ms).
- Times Connected: 4.
[2022-06-06T21:10:56.324] [ERROR] [redis-client    ] Redis server error encountered:
- Class: Error.
- Message: getaddrinfo ENOTFOUND redis-server-e764038b.databases.appdomain.cloud
- Code: ENOTFOUND.
- Stack: Error: getaddrinfo ENOTFOUND redis-server-e764038b.databases.appdomain.cloud
    at GetAddrInfoReqWrap.onlookup [as oncomplete] (node:dns:71:26).
[2022-06-06T21:10:56.325] [ERROR] [redis-client    ] Redis Error:
{
   "errno": -3008,
   "code": "ENOTFOUND",
   "syscall": "getaddrinfo",
   "hostname": "redis-server-e764038b.databases.appdomain.cloud"
}

mpawlow avatar Jun 07 '22 01:06 mpawlow

I meet the same problem, when some error happened , the time that i set for reconnectStrategy dont work . ECONNREFUSED could work,but ECONNRESET dont work.

mayuehit avatar Sep 22 '22 07:09 mayuehit

#2274 maybe It could solve your question

mayuehit avatar Sep 23 '22 02:09 mayuehit

did anyone have a work around for this issue?

GeekOnGadgets avatar Jan 17 '23 22:01 GeekOnGadgets

@GeekOnGadgets to my understanding there is no issue (see this comment).. wanna share a little bit more?

leibale avatar Jan 18 '23 00:01 leibale

This code does not reproduce the issue, am I missing something?

import { createClient } from '@redis/client';

const client = createClient({
        socket: {
            reconnectStrategy() {
                console.log('reconnectStrategy', new Date().toJSON());
                return 5000;
            }
        }
    })
    .on('connect', () => console.log('connect', new Date().toJSON()))
    .on('ready', () => console.log('ready', new Date().toJSON()))
    .on('error', err => console.error('error', err, new Date().toJSON()));

try {
    await client.connect();
} catch (err) {
    console.error('connect err', err, new Date().toJSON());
}

@leibale In Redis 4.5.1, I discovered that the reconnectStrategy is not called if there is no on('error', err => console.error('error', err, new Date().toJSON()))

ChristopherZhong avatar Jan 20 '23 07:01 ChristopherZhong

@ChristopherZhong see #2302

leibale avatar Jan 20 '23 07:01 leibale