search

redis / node-redis

Redis Node.js client
https://redis.js.org/
MIT License
16.95k stars 1.89k forks source link

SocketClosedUnexpectedlyError - Unhandled Error #2624

Open elvince opened 1 year ago

elvince commented 1 year ago

Description

Hi,

We are experiencing issue with the client. Many times a day we have this unhandled error that is thrown away from the redis client.

We have properly set the "Error" handler but it is not catched in it. As a consequence our process is crashing multiple times per day. It is severly impacting our customers.

We already dig into the issue list where this error was mentionned, we tried the PingInterval / SetInterval stuff as we are on Azure but it doesn't fix the issue.

I suspect this is another edge case than the load balancer that drop the connection. If you can see how to catch properly this error so the reconnect system can reopen smoothlty the connection it will save our day.

Thanks,

Node.js Version

Node.js v18.17.1

Redis Server Version

Node.js v18.17.1

Node Redis Version

No response

Platform

Linux

Logs

2023-10-04T09:34:16.491974249Z node:events:492
2023-10-04T09:34:16.492029849Z       throw er; // Unhandled 'error' event
2023-10-04T09:34:16.492037249Z       ^
2023-10-04T09:34:16.492041649Z 
2023-10-04T09:34:16.492045549Z SocketClosedUnexpectedlyError: Socket closed unexpectedly
2023-10-04T09:34:16.492049849Z     at Socket.<anonymous> (/home/site/wwwroot/node_modules/@redis/client/dist/lib/client/socket.js:194:118)
2023-10-04T09:34:16.492054649Z     at Object.onceWrapper (node:events:629:26)
2023-10-04T09:34:16.492058649Z     at Socket.emit (node:events:514:28)
2023-10-04T09:34:16.492062649Z     at TCP.<anonymous> (node:net:323:12)
2023-10-04T09:34:16.492066948Z Emitted 'error' event on Commander instance at:
2023-10-04T09:34:16.492071048Z     at RedisSocket.<anonymous> (/home/site/wwwroot/node_modules/@redis/client/dist/lib/client/index.js:396:14)
2023-10-04T09:34:16.492075148Z     at RedisSocket.emit (node:events:514:28)
2023-10-04T09:34:16.492082148Z     at RedisSocket._RedisSocket_onSocketError (/home/site/wwwroot/node_modules/@redis/client/dist/lib/client/socket.js:217:10)
2023-10-04T09:34:16.492086248Z     at Socket.<anonymous> (/home/site/wwwroot/node_modules/@redis/client/dist/lib/client/socket.js:194:107)
2023-10-04T09:34:16.492090248Z     at Object.onceWrapper (node:events:629:26)
2023-10-04T09:34:16.492094048Z     at Socket.emit (node:events:514:28)
2023-10-04T09:34:16.492097948Z     at TCP.<anonymous> (node:net:323:12)
leibale commented 1 year ago

"Unhandled 'error' event" means that you are not listening to 'error's... maybe you have more than one client in the code and you forgot to listen to errors on one of them?

TDola commented 1 year ago

I am having this problem too. I only have one client, and the on error is set. But it crashes anyways. Using 4.6.10 on node 20.7.0 It will error 10 or so times on the socket, then crash, each time calling the on error handler. Very easy to reproduce, just restart the docker container for redis and your client crashes.

this.client = createClient()
this.client.on('error', err => console.log('Redis Client Error', err))
this.client.on('end', () => {
   console.log('Redis connection ended');
})
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\app\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\app\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\app\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\app\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
undefined
node:internal/process/promises:289
            triggerUncaughtException(err, true /* fromPromise */);
            ^

SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\app\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)

After tracing it, I think the error ultimately comes from something in your code making a get or set to redis while it is down. I am getting around the problem by watching the ready event and using my own state variable to skip over gets and sets while it is disconnected.

elvince commented 1 year ago

I confirm I have only 1 client and I set the error handler.

const _redisClient = createClient(conOptions);

    _redisClient.on('ready', () => {
      console.log('Redis is ready');
    });

    _redisClient.on('reconnecting', () => {
      console.log('client is reconnecting');
    });

    _redisClient.on('end', () => {
      console.log('Redis connection ended');
    });

    _redisClient.on('connect', () => {
      global.console.log('connected');
    });

    _redisClient.on('error', (err) => {
      console.error('Redis error: ', err);
    });

    _redisClient.connect();
    return _redisClient;

Thanks,

elvince commented 1 year ago

In my case, it is not catch inside the error handler :(

If I shutdown the redis server, the error is properly managed: 2023-10-06T13:18:21.252432723Z Redis error: Error: read ECONNRESET 2023-10-06T13:18:21.252493923Z at TCP.onStreamRead (node:internal/stream_base_commons:217:20) { 2023-10-06T13:18:21.252499722Z errno: -104, 2023-10-06T13:18:21.252502922Z code: 'ECONNRESET', 2023-10-06T13:18:21.252505922Z syscall: 'read' 2023-10-06T13:18:21.252508922Z } 2023-10-06T13:18:21.252566422Z client is reconnecting

@leibale Any tips ? Is there a possibility that it happens when 2 command are sent at the same time? thanks,

bossajie commented 1 year ago

How to fix this?

TDola commented 1 year ago

How to fix this?

If its like my solution, double check you are not trying to set or get while the connection is down. Add a global variable for yourself to check that updates

let alive=false
 _redisClient.on('end', () => {
     alive=false
   });

    _redisClient.on('ready', () => {
     alive=true
   });

   _redisClient.on('error', (err) => {
     alive=false
   });

and before redisClient.set()

if (alive){
  redisClient.set(etc, etc2)
}

That way you don't try to set when its dead. I made a whole wrapper class around redis so it was trivial to add a check to all of them

ap0sentada commented 1 year ago

damn, same erro. there's no fix i see

leibale commented 1 year ago

@TDola you can use disableOfllineQueue to achieve the same thing. See here.

@ap0sentada @bossajie @elvince I only managed to reproduce this when a client emits an error and there are no listeners (which is expected behavior). If this error is thrown in other cases, please share code that reproduces it..

TDola commented 1 year ago

@TDola you can use disableOfllineQueue to achieve the same thing. See here.

@ap0sentada @bossajie @elvince I only managed to reproduce this when a client emits an error and there are no listeners (which is expected behavior). If this error is thrown in other cases, please share code that reproduces it..

You can use this code to reproduce the problem.

package.json

{
  "name": "redis-crash-test",
  "version": "1.0.0",
  "description": "",
  "main": "index.js",
  "scripts": {
    "run": "node index.js"
  },
  "type": "module",
  "author": "",
  "license": "ISC",
  "dependencies": {
    "redis": "^4.6.10"
  }
}

npm install it and run it. 

import { createClient } from 'redis'
const client = createClient()
client.on('error', async err => {
    console.log('Redis Client Error', err)
})
client.on('end', () => {
    console.log('Redis connection ended');
})
client.on('ready', () => {
    console.log('redis connected')
})
await client.connect()

const createKeys = () => {
    for (let i = 0; i < 10000; i++) {
        const value = JSON.stringify({test: i}, null, 2)
        // purposely no await to simulate a busy async system
        client.set('test-key:' + performance.now(), value)
    }
}
const removeKeys = async () => {
    const results = await client.keys('test-key:*')
    for (const key of results) {
        // no await on purpose
        client.del(key)
    }
}

const runner=()=>{
    console.log('starting runner loop')
    createKeys()
    console.log('done setting keys')
    removeKeys()
    console.log('done deleting keys, waiting 1000')
    setTimeout(()=>{runner()}, 1000)
}
process.on('SIGINT', async function() {
    console.log("Caught interrupt signal");
    const results = await client.keys('test-key:*')
    for (const key of results) {
        await client.del(key)
    }
    console.log("test keys cleaned")
    process.exit()
})
runner()

leave it to run a little bit, like 10 seconds. Then shut down your redis manually, the script should crash most of the time. Fiddle with the timeout to adjust.

starting runner loop
done setting keys
done deleting keys, waiting 5000
starting runner loop
done setting keys
done deleting keys, waiting 5000
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
redis connected
Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at Socket.<anonymous> (E:\workspace\redis-crash-test\node_modules\@redis\client\dist\lib\client\socket.js:194:118)
    at Object.onceWrapper (node:events:629:26)
    at Socket.emit (node:events:514:28)
    at TCP.<anonymous> (node:net:337:12)
starting runner loop
done setting keys
done deleting keys, waiting 5000
redis connected
Redis Client Error Error: read ECONNRESET
    at TCP.onStreamRead (node:internal/stream_base_commons:217:20) {
  errno: -4077,
  code: 'ECONNRESET',
  syscall: 'read'
}
node:internal/process/promises:289
            triggerUncaughtException(err, true /* fromPromise */);
            ^

Error: read ECONNRESET
    at TCP.onStreamRead (node:internal/stream_base_commons:217:20) {
  errno: -4077,
  code: 'ECONNRESET',
  syscall: 'read'
}

Node.js v20.7.0

The real bug might be that the ready event kept getting called even though the redis server was still down. What was it connecting to?

leibale commented 1 year ago

@TDola its fine not awaiting a promise, but you'll have to catch the errors, otherwise it'll crash with "unhandled promise rejection" error..

I tried reproducing it using

import { createClient } from 'redis';

const client = await createClient()
  .on('error', (err) => console.log('client error', err))
  .on('ready', () => console.log('client is ready'))
  .connect();

function createKeys() {
  for (let i = 0; i < 10000; i++) {
    client.set(`text-key${i.toString()}`, i.toString()).catch(err => {
      console.error(`Error in SET ${i}`, err);
    });
  }
}

async function removeKeys() {
  for (const key of await client.keys('test-key:*')) {
    client.del(key).catch(err => {
      console.error(`Error in DEL ${key}`, err);
    });
  }
}

function runner() {
  console.log('starting runner loop');
  createKeys();

  console.log('done setting keys');
  removeKeys();

  console.log('done deleting keys, waiting 1000');
  setTimeout(runner, 1000);
}

runner();

but... it works...

TDola commented 1 year ago

Your key set is using a number as the ID instead of test-key: so it won't find anything in the key search. I haven't had much coffee yet so I could be wrong in reading that. But if the catch solves it, then perfect that's easily implementable.

function createKeys() {
  for (let i = 0; i < 10000; i++) {
    client.set(i.toString(), i.toString()).catch(err => {
      console.error(`Error in SET ${i}`, err);
    });
  }
}
bossajie commented 1 year ago

We are using createCluster(). Maybe the issue is coming from createCluster() ?

leibale commented 1 year ago

@TDola I've fixed the example, please LMK if you find anything..

@bossajie are you listening to errors on the cluster? i.e.:

import { createCluster } from 'redis';

const cluster = await createCluster(...)
  .on('error', err => console.error('Redis Cluster Error', err)
  .connect();
elvince commented 1 year ago

@leibale That's great that we are moving on this issue. It is difficult to catch issue that is not reproductible.

On TDola case, it was reproductible and you fix it by reviewing the code sample. Is there a way to catch the error on your side when it happenned so we can have more info on where to fix stuff? or the "unhandled promise rejection" bypass you error handling process?

If I properly understand, the issue can arise on promise not awaited / catched, correct? I will double check this point on my side (even if I already did it :D)

thanks

Edit: I checked and all calls are awaited. I hope we can have a way to track this kind of bugs. It seems to happen when no call are made during a long period. I'm on azure app container and I already set the timeout parameter as per your recommendations

 const conOptions: RedisClientOptions = {
    password: xxxx
    socket: {
      host: redisOptions.host,
      port: 6666,
      connectTimeout: 2000,
    },
    pingInterval: 5 * 60 * 1000, //Ping Each 5min. https://learn.microsoft.com/en-us/azure/azure-cache-for-redis/cache-best-practices-connection#idle-timeout
  };
kjxbyz commented 9 months ago

The application(nest.js) is hosted on render, and this error is often reported. Redis uses the vercel kv service.

CacheModule.registerAsync({
      isGlobal: true,
      useFactory: async () => {
        const store = await redisStore({
          socket: {
            host: process.env.KV_HOST,
            port: +process.env.KV_PORT,
            tls: true,
          },
          username: process.env.KV_USERNAME,
          password: process.env.KV_PASSWORD,
          ttl: 60,
        })
        return {
          store: store as unknown as CacheStore,
        }
      },
    }),
    ThrottlerModule.forRootAsync({
      useFactory: () => ({
        throttlers: [{ limit: 10, ttl: seconds(60) }],
        storage: new ThrottlerStorageRedisService({
          host: process.env.KV_HOST,
          port: +process.env.KV_PORT,
          username: process.env.KV_USERNAME,
          password: process.env.KV_PASSWORD,
          tls: true,
          maxRetriesPerRequest: 20,
        } as unknown as RedisOptions),
      }),
    }),
node:events:495
      throw er; // Unhandled 'error' event
      ^
SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at TLSSocket.<anonymous> (/opt/render/project/src/node/node_modules/.pnpm/@redis+client@1.5.14/node_modules/@redis/client/dist/lib/client/socket.js:194:118)
    at Object.onceWrapper (node:events:632:26)
    at TLSSocket.emit (node:events:529:35)
    at node:net:350:12
    at TCP.done (node:_tls_wrap:657:7)
Emitted 'error' event on Commander instance at:
    at RedisSocket.<anonymous> (/opt/render/project/src/node/node_modules/.pnpm/@redis+client@1.5.14/node_modules/@redis/client/dist/lib/client/index.js:412:14)
==> Requesting node version 18
==> Using Node version 18.19.1 via /opt/render/project/src/node/.nvmrc
==> Docs on specifying a Node version: https://render.com/docs/node-version
==> Running 'pnpm start'
> homing-pigeon-workspace@ start /opt/render/project/src/node
> pnpm --filter server start
> server@1.0.0 start /opt/render/project/src/node/server
> cross-env NODE_ENV=production node dist/main
    at RedisSocket.emit (node:events:517:28)
    at RedisSocket._RedisSocket_onSocketError (/opt/render/project/src/node/node_modules/.pnpm/@redis+client@1.5.14/node_modules/@redis/client/dist/lib/client/socket.js:218:10)
    at TLSSocket.<anonymous> (/opt/render/project/src/node/node_modules/.pnpm/@redis+client@1.5.14/node_modules/@redis/client/dist/lib/client/socket.js:194:107)
    at Object.onceWrapper (node:events:632:26)
    [... lines matching original stack trace ...]
    at TCP.done (node:_tls_wrap:657:7)
Node.js v18.19.1
/opt/render/project/src/node/server:
 ERR_PNPM_RECURSIVE_RUN_FIRST_FAIL  server@1.0.0 start: `cross-env NODE_ENV=production node dist/main`
Exit status 1
 ELIFECYCLE  Command failed with exit code 1.

EDIT

node:events:495
      throw er; // Unhandled 'error' event
      ^
SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at TLSSocket.<anonymous> (/opt/render/project/src/node_modules/.pnpm/@redis+client@1.5.16/node_modules/@redis/client/dist/lib/client/socket.js:194:118)
    at Object.onceWrapper (node:events:632:26)
    at TLSSocket.emit (node:events:529:35)
    at node:net:350:12
    at TCP.done (node:_tls_wrap:657:7)
Emitted 'error' event on Commander instance at:
    at RedisSocket.<anonymous> (/opt/render/project/src/node_modules/.pnpm/@redis+client@1.5.16/node_modules/@redis/client/dist/lib/client/index.js:412:14)
    at RedisSocket.emit (node:events:517:28)
    at RedisSocket._RedisSocket_onSocketError (/opt/render/project/src/node_modules/.pnpm/@redis+client@1.5.16/node_modules/@redis/client/dist/lib/client/socket.js:218:10)
    at TLSSocket.<anonymous> (/opt/render/project/src/node_modules/.pnpm/@redis+client@1.5.16/node_modules/@redis/client/dist/lib/client/socket.js:194:107)
    at Object.onceWrapper (node:events:632:26)
    [... lines matching original stack trace ...]
    at TCP.done (node:_tls_wrap:657:7)
git-santosh commented 6 months ago

I am using docker to run Redis and as client, I am using node-redis. when I am executing my code I am getting Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly below is my code 

import { createClient } from "redis";
const client = await createClient({
  socket: {
    host: "127.0.0.1",
    port: 6379,
    legacyMode: true,
  },
})
.on('error', err => console.log('Redis Client Error', err))
await client.connect().catch(console.error);
console.log('redis connected...')

what is wrong in the code and how should we fix it ?

greim commented 6 months ago

I've been having the same/similar issue. In my case I'm using createCluster().

The symptoms are that after a few minutes, Node.js will predictably crash with an unhandled SocketClosedUnexpectedlyError, even though we have a listener on the 'error' event.

Interestingly, the crashes are occasionally V8 heap-allocation-related, rather than an uncaught exception. So something weird definitely seems to be happening on the socket-close condition. Could it possibly be an infinite recursive loop trying to reconnect?

At first, nothing I tried seemed to fix the issue, until I changed the client idle timeout setting from 300 to 0, effectively disabling it. Suddenly the crashing went away.

git-santosh commented 6 months ago

I am using docker to run Redis and as client, I am using node-redis. when I am executing my code I am getting Redis Client Error SocketClosedUnexpectedlyError: Socket closed unexpectedly below is my code

import { createClient } from "redis";
const client = await createClient({
  socket: {
    host: "127.0.0.1",
    port: 6379,
    legacyMode: true,
  },
})
.on('error', err => console.log('Redis Client Error', err))
await client.connect().catch(console.error);
console.log('redis connected...')

what is wrong in the code and how should we fix it ?

FIX : I was using bitnami redis docker image later I used redis docker image after that I didn't see the above error.

odavibatista commented 3 months ago

The application(nest.js) is hosted on render, and this error is often reported. Redis uses the vercel kv service.

CacheModule.registerAsync({
      isGlobal: true,
      useFactory: async () => {
        const store = await redisStore({
          socket: {
            host: process.env.KV_HOST,
            port: +process.env.KV_PORT,
            tls: true,
          },
          username: process.env.KV_USERNAME,
          password: process.env.KV_PASSWORD,
          ttl: 60,
        })
        return {
          store: store as unknown as CacheStore,
        }
      },
    }),
    ThrottlerModule.forRootAsync({
      useFactory: () => ({
        throttlers: [{ limit: 10, ttl: seconds(60) }],
        storage: new ThrottlerStorageRedisService({
          host: process.env.KV_HOST,
          port: +process.env.KV_PORT,
          username: process.env.KV_USERNAME,
          password: process.env.KV_PASSWORD,
          tls: true,
          maxRetriesPerRequest: 20,
        } as unknown as RedisOptions),
      }),
    }),
node:events:495
      throw er; // Unhandled 'error' event
      ^
SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at TLSSocket.<anonymous> (/opt/render/project/src/node/node_modules/.pnpm/@redis+client@1.5.14/node_modules/@redis/client/dist/lib/client/socket.js:194:118)
    at Object.onceWrapper (node:events:632:26)
    at TLSSocket.emit (node:events:529:35)
    at node:net:350:12
    at TCP.done (node:_tls_wrap:657:7)
Emitted 'error' event on Commander instance at:
    at RedisSocket.<anonymous> (/opt/render/project/src/node/node_modules/.pnpm/@redis+client@1.5.14/node_modules/@redis/client/dist/lib/client/index.js:412:14)
==> Requesting node version 18
==> Using Node version 18.19.1 via /opt/render/project/src/node/.nvmrc
==> Docs on specifying a Node version: https://render.com/docs/node-version
==> Running 'pnpm start'
> homing-pigeon-workspace@ start /opt/render/project/src/node
> pnpm --filter server start
> server@1.0.0 start /opt/render/project/src/node/server
> cross-env NODE_ENV=production node dist/main
    at RedisSocket.emit (node:events:517:28)
    at RedisSocket._RedisSocket_onSocketError (/opt/render/project/src/node/node_modules/.pnpm/@redis+client@1.5.14/node_modules/@redis/client/dist/lib/client/socket.js:218:10)
    at TLSSocket.<anonymous> (/opt/render/project/src/node/node_modules/.pnpm/@redis+client@1.5.14/node_modules/@redis/client/dist/lib/client/socket.js:194:107)
    at Object.onceWrapper (node:events:632:26)
    [... lines matching original stack trace ...]
    at TCP.done (node:_tls_wrap:657:7)
Node.js v18.19.1
/opt/render/project/src/node/server:
 ERR_PNPM_RECURSIVE_RUN_FIRST_FAIL  server@1.0.0 start: `cross-env NODE_ENV=production node dist/main`
Exit status 1
 ELIFECYCLE  Command failed with exit code 1.

EDIT

node:events:495
      throw er; // Unhandled 'error' event
      ^
SocketClosedUnexpectedlyError: Socket closed unexpectedly
    at TLSSocket.<anonymous> (/opt/render/project/src/node_modules/.pnpm/@redis+client@1.5.16/node_modules/@redis/client/dist/lib/client/socket.js:194:118)
    at Object.onceWrapper (node:events:632:26)
    at TLSSocket.emit (node:events:529:35)
    at node:net:350:12
    at TCP.done (node:_tls_wrap:657:7)
Emitted 'error' event on Commander instance at:
    at RedisSocket.<anonymous> (/opt/render/project/src/node_modules/.pnpm/@redis+client@1.5.16/node_modules/@redis/client/dist/lib/client/index.js:412:14)
    at RedisSocket.emit (node:events:517:28)
    at RedisSocket._RedisSocket_onSocketError (/opt/render/project/src/node_modules/.pnpm/@redis+client@1.5.16/node_modules/@redis/client/dist/lib/client/socket.js:218:10)
    at TLSSocket.<anonymous> (/opt/render/project/src/node_modules/.pnpm/@redis+client@1.5.16/node_modules/@redis/client/dist/lib/client/socket.js:194:107)
    at Object.onceWrapper (node:events:632:26)
    [... lines matching original stack trace ...]
    at TCP.done (node:_tls_wrap:657:7)

I'm having the same issue

samiursakib commented 2 months ago

How to fix this?

If its like my solution, double check you are not trying to set or get while the connection is down. Add a global variable for yourself to check that updates

let alive=false
 _redisClient.on('end', () => {
     alive=false
   });

    _redisClient.on('ready', () => {
     alive=true
   });

   _redisClient.on('error', (err) => {
     alive=false
   });

and before redisClient.set()

if (alive){
  redisClient.set(etc, etc2)
}

That way you don't try to set when its dead. I made a whole wrapper class around redis so it was trivial to add a check to all of them

Hello @TDola

I implemented my redisClient class this way as you suggested. Here is the class definition.

class Client {
  alive: boolean;
  client: RedisClientType;
  constructor() {
    this.alive = false;
    this.client = createClient({
      username: process.env.REDIS_USERNAME,
      password: process.env.REDIS_PASSWORD,
      socket: {
        host: process.env.REDIS_HOST,
        port: Number(process.env.REDIS_PORT),
        tls: true,
      },
    });
    this.createConnection();
  }

  createConnection = () => {
    try {
      this.client
        .on("error", (err: any) => {
          this.alive = false;
          console.error("Redis error", err);
        })
        .on("ready", () => {
          this.alive = true;
          console.log("Client is ready");
        })
        .on("end", () => {
          this.alive = false;
          console.log("Client ended");
        })
        .connect();
    } catch (err: any) {
      console.error("Error occured during creating client", err);
    } finally {
      // await redisClient.disconnect();
    }
  };

  hSet = async (key: RedisCommandArgument, value: any) => {
    if (this.alive) {
      return await this.client.hSet(key, value);
    }
  };

  hGet = async (key: RedisCommandArgument, field: string) => {
    if (this.alive) {
      return await this.client.hGet(key, field);
    }
  };

  hGetAll = async (key: RedisCommandArgument) => {
    if (this.alive) {
      return await this.client.hGetAll(key);
    }
  };

  exists = async (key: RedisCommandArgument) => {
    if (this.alive) {
      return await this.client.exists(key);
    }
  };

  hIncrBy = async (key: RedisCommandArgument, field: string, value: number) => {
    if (this.alive) {
      return await this.client.hIncrBy(key, field, value);
    }
  };
}

export default new Client();

But this keeps the "Socket unexpectedly closed" error and also introduces a new error saying "cannot read properties of undefined (reading hSet)" which I think indicates that my client is undefined at a point of time. Am I doing something wrong? Any suggestions will be helpful. Thanks in advance.

TDola commented 2 months ago

How to fix this?

If its like my solution, double check you are not trying to set or get while the connection is down. Add a global variable for yourself to check that updates

let alive=false
 _redisClient.on('end', () => {
     alive=false
   });

    _redisClient.on('ready', () => {
     alive=true
   });

   _redisClient.on('error', (err) => {
     alive=false
   });

and before redisClient.set()

if (alive){
  redisClient.set(etc, etc2)
}

That way you don't try to set when its dead. I made a whole wrapper class around redis so it was trivial to add a check to all of them

Hello @TDola

I implemented my redisClient class this way as you suggested. Here is the class definition.

class Client {
  alive: boolean;
  client: RedisClientType;
  constructor() {
    this.alive = false;
    this.client = createClient({
      username: process.env.REDIS_USERNAME,
      password: process.env.REDIS_PASSWORD,
      socket: {
        host: process.env.REDIS_HOST,
        port: Number(process.env.REDIS_PORT),
        tls: true,
      },
    });
    this.createConnection();
  }

  createConnection = () => {
    try {
      this.client
        .on("error", (err: any) => {
          this.alive = false;
          console.error("Redis error", err);
        })
        .on("ready", () => {
          this.alive = true;
          console.log("Client is ready");
        })
        .on("end", () => {
          this.alive = false;
          console.log("Client ended");
        })
        .connect();
    } catch (err: any) {
      console.error("Error occured during creating client", err);
    } finally {
      // await redisClient.disconnect();
    }
  };

  hSet = async (key: RedisCommandArgument, value: any) => {
    if (this.alive) {
      return await this.client.hSet(key, value);
    }
  };

  hGet = async (key: RedisCommandArgument, field: string) => {
    if (this.alive) {
      return await this.client.hGet(key, field);
    }
  };

  hGetAll = async (key: RedisCommandArgument) => {
    if (this.alive) {
      return await this.client.hGetAll(key);
    }
  };

  exists = async (key: RedisCommandArgument) => {
    if (this.alive) {
      return await this.client.exists(key);
    }
  };

  hIncrBy = async (key: RedisCommandArgument, field: string, value: number) => {
    if (this.alive) {
      return await this.client.hIncrBy(key, field, value);
    }
  };
}

export default new Client();

But this keeps the "Socket unexpectedly closed" error and also introduces a new error saying "cannot read properties of undefined (reading hSet)" which I think indicates that my client is undefined at a point of time. Am I doing something wrong? Any suggestions will be helpful. Thanks in advance.

What you have looks pretty much the same as how I implemented it. So it might be just when you are calling it. If you are accidentally calling your sets before you have time to construct your class and wait for the connect to finish.

Also, the catches were unexpectedly important, as shown in the response to my question here https://github.com/redis/node-redis/issues/2624#issuecomment-1770996791