socket.io-redis-adapter: timeout reached while waiting for clients response

I have been investigating the error “Timeout reached …” and as mentioned by @darrachequesne it seems to come from an error with numsub (issue #267).

During my tests on the function “allRooms” to get the list of all rooms across every node, I noticed 3 types of response :

1. An array with all the rooms across the nodes.
2. An empty array.
3. A timeout error.

I used the following configuration:

• A redis-cluster of 3 masters (redis-1,redis-2,redis-3).
• 3 clients (nodejs servers).
• 1 socket joining a room named “room1” at the connection.

By monitoring the 3 redis I noted the following subscriptions :

• 0 client subscribed to redis-1
• 1 client subscribed to redis-2
• 2 clients subscribed to redis-3

As mentioned in the issue #267 by @SunGg12138, “pubsub numsub channel” it returns only the results pertaining to the server you’re directly connected to.

So in my case: When “pubsub numsub channel” is received by the redis-1 it systematically returns the “Timeout error”. When “pubsub numsub channel” is received by the redis-2 it only returns the rooms of one of the three nodes ( it is not always the same node). When “pubsub numsub channel” is received by the redis-3 it returns the rooms of two of the three nodes ( it is not always the same nodes).

This could explain the error of the empty array ( only the nodes without rooms are requested). As the response with the array with all the rooms ( the nodes with no rooms are not requested which does not affect the expected result).

I then restarted the clients to have another configuration:

• 3 clients subscribed to redis-1
• 0 client subscribed to redis-2
• 0 client subscribed to redis-3

In this configuration I had only two types of response:

1. An array with all the rooms across the nodes.
2. A timeout error.

I restarted the clients again to have another configuration:

• 1 client subscribed to redis-1
• 1 client subscribed to redis-2
• 1 client subscribed to redis-3

In this configuration I had only two types of response:

1. An array with all the rooms across the nodes.
2. An empty array.

Those results seems to confirm that the problem comes from numsub.

Finally, I manually set the value of numsub to 3 (in the source code) which corresponds to the number of clients. And I only had the good responses : An array with all the rooms across the nodes.

I imagine that solving the issue #267 will solve this one too.

I have the same issue as well.

Have the same issue, retry_strategy and requestsTimeout == 3000 doesn’t help

The current behaviour for clients method:

1. (requester) get the current number of subscribers N on the socket.io-request#/# channel with numsub
2. (requester) publish the request on the socket.io-request#/# channel
3. (other nodes) receive the request, and publish the response on the socket.io-response#/# channel
4. (requester) wait for N responses or timeout

What could cause timeout reached while waiting for clients response:

• the numsub is incorrect (which is what happen with a Redis cluster, https://github.com/socketio/socket.io-redis/issues/267)
• a node miss a request
• the requester miss a response

I’m open to suggestions for how to fix that issue.

When i try to join a client in different name space to a room is in another name-space like this:

const trips = io.of('/trips') ;
const driversNamespace= (socket) => {
    socket.on('trip.join',(tripRoom)=>{
        trips.adapter.remoteJoin(socket.id, tripRoom, (err) => {
            if (err) { return console.log(err) ; }
          });
    });
}

It will do ‘PUBLISH’ command in redis when i do monitor:

1522925476.363203 [0 127.0.0.1:45940] "publish" "socket.io-request#/trips#" "{\"requestid\":\"ua3DYX\",\"type\":3,\"sid\":\"/drivers#bTYmdLtRHgfkoWS_AAAB\",\"room\":\"7777\"}"

But it returns error :

Error: timeout reached while waiting for remoteJoin response
    at Timeout._onTimeout (/home/SocketApp/node_modules/socket.io-redis/index.js:591:46)
    at ontimeout (timers.js:466:11)
    at tryOnTimeout (timers.js:304:5)
    at Timer.listOnTimeout (timers.js:267:5)

It is on a single instance of node process, I have not multiple. Redis: v 4.0.7 Node : v 9.9.0 Socket.io : v 2.0.4 Socket.io-redis : v 5.2.0

Hi. I have similar problem when use ioredis cluster, if i use just one redis node, all work good.

Node version 6.9.1. ioredis version 3.1.1 socket.io version 2.0.3, socket.io-redis version 5.2.0

Here’s error stacktrace:

   Error: timeout reached while waiting for clients response
       at Timeout._onTimeout (/Users/alexander/workplace/WebstormProjects/match-server-v2.0/node_modules/socket.io-redis/index.js:457:48)
       at ontimeout (timers.js:365:14)
       at tryOnTimeout (timers.js:237:5)
       at Timer.listOnTimeout (timers.js:207:5),

Code where error occurs:

        io.of('/')
            .in(roomId)
            .clients((error, clients) => {
                console.log({error, clients});
            }))

Here are the detailed Redis logs for the cluster with 3 nodes: first node

1508835397.785039 [0 172.17.0.1:37486] "info"
1508835397.912534 [0 172.17.0.1:37492] "info"
1508835397.920732 [0 172.17.0.1:37494] "info"
1508835398.038396 [0 172.17.0.1:37500] "info"
1508835398.045952 [0 172.17.0.1:37504] "info"
1508835398.154000 [0 172.17.0.1:37508] "info"
1508835401.674671 [0 172.17.0.1:37500] "pubsub" "numsub" "socket.io-request#/#"
1508835401.680840 [0 172.17.0.1:37500] "publish" "socket.io-response#/#" "{\"requestid\":\"8iUQCy\",\"clients\":[\"4sQ5sThjFl5VRSK5AAAA\"]}"
1508835406.570126 [0 172.17.0.1:37500] "publish" "socket.io-request#/#" "{\"requestid\":\"eQAHCN\",\"type\":4,\"room\":\"59ef00499f931a059c3579a0\"}"

second node

1508835397.808031 [0 172.17.0.1:40708] "info"
1508835401.486206 [0 172.17.0.1:40708] "flushdb"
1508835401.676574 [0 172.17.0.1:40732] "info"
1508835401.679331 [0 172.17.0.1:40732] "publish" "socket.io-request#/#" "{\"requestid\":\"8iUQCy\",\"type\":0,\"rooms\":[\"59ef00499f931a059c3579a0\"]}"

third node

1508835397.921025 [0 172.17.0.1:33888] "info"
1508835398.041315 [0 172.17.0.1:33894] "info"
1508835398.160236 [0 172.17.0.1:33902] "info"
1508835401.668258 [0 172.17.0.1:33894] "publish" "socket.io#/#59ef00499f931a059c3579a0#" "\x93\xa6jHfnFk\x83\xa4type\x02\xa4data\x92\xaastartMatch\x81\xa5match\x82\xa2id\xb859ef00499f931a059c3579a0\xa7players\x92\x83\xa2id\xa9Sk-Lgt3a-\xa8socketId\xb44sQ5sThjFl5VRSK5AAAA\xa8masterId\xcd\a\xd0\x83\xa2id\xaaSklWUxK3pW\xa8socketId\xb4x7RTcB7LK_Dr3nacAAAB\xa8masterId\xcd\x03\xe8\xa3nsp\xa1/\x82\xa5rooms\x91\xb859ef00499f931a059c3579a0\xa5flags\x80"
1508835406.571641 [0 172.17.0.1:33894] "publish" "socket.io-request#/#" "{\"requestid\":\"EphjJ2\",\"type\":4,\"room\":\"59ef00499f931a059c3579a0\"}"

And logs fore one node:

1508833863.076963 [0 172.17.0.1:58006] "info"
1508833863.089255 [0 172.17.0.1:58008] "info"
1508833863.092777 [0 172.17.0.1:58010] "info"
1508833863.099009 [0 172.17.0.1:58010] "psubscribe" "socket.io#/#*"
1508833863.099208 [0 172.17.0.1:58010] "subscribe" "socket.io-request#/#" "socket.io-response#/#"
1508833866.553421 [0 172.17.0.1:58006] "flushdb"
1508833866.741205 [0 172.17.0.1:58008] "publish" "socket.io#/#59eefa4a8c200c04be80405b#" "\x93\xa64douZ8\x83\xa4type\x02\xa4data\x92\xaastartMatch\x81\xa5match\x82\xa2id\xb859eefa4a8c200c04be80405b\xa7players\x92\x83\xa2id\xa9rJmI9O36W\xa8socketId\xb4KrR55l9UdCAefUDiAAAA\xa8masterId\xcd\a\xd0\x83\xa2id\xaaH1lmIqun6-\xa8socketId\xb4zXlEv96OLifVdCbsAAAB\xa8masterId\xcd\x03\xe8\xa3nsp\xa1/\x82\xa5rooms\x91\xb859eefa4a8c200c04be80405b\xa5flags\x80"
1508833866.746579 [0 172.17.0.1:58008] "pubsub" "numsub" "socket.io-request#/#"
1508833866.747475 [0 172.17.0.1:58008] "publish" "socket.io-request#/#" "{\"requestid\":\"SbCHbD\",\"type\":0,\"rooms\":[\"59eefa4a8c200c04be80405b\"]}"
1508833866.748405 [0 172.17.0.1:58008] "publish" "socket.io-response#/#" "{\"requestid\":\"SbCHbD\",\"clients\":[\"KrR55l9UdCAefUDiAAAA\"]}"
1508833866.749871 [0 172.17.0.1:58008] "publish" "socket.io#/#59eefa4a8c200c04be80405b#" "\x93\xa64douZ8\x83\xa4type\x02\xa4data\x92\xaaleaveMatch\x82\xaadeserterId\xaaH1lmIqun6-\xa5match\x82\xa2id\xb859eefa4a8c200c04be80405b\xa7players\x92\x83\xa2id\xa9rJmI9O36W\xa8socketId\xb4KrR55l9UdCAefUDiAAAA\xa8masterId\xcd\a\xd0\x83\xa2id\xaaH1lmIqun6-\xa8socketId\xb4zXlEv96OLifVdCbsAAAB\xa8masterId\xcd\x03\xe8\xa3nsp\xa1/\x82\xa5rooms\x91\xb859eefa4a8c200c04be80405b\xa5flags\x80"
1508833866.753714 [0 172.17.0.1:58008] "publish" "socket.io#/#59eefa4a8c200c04be80405b#" "\x93\xa64douZ8\x83\xa4type\x02\xa4data\x92\xadreturnInMatch\x82\xaareturneeId\xaaH1lmIqun6-\xa5match\x82\xa2id\xb859eefa4a8c200c04be80405b\xa7players\x92\x83\xa2id\xa9rJmI9O36W\xa8socketId\xb4KrR55l9UdCAefUDiAAAA\xa8masterId\xcd\a\xd0\x82\xa2id\xaaH1lmIqun6-\xa8masterId\xcd\x03\xe8\xa3nsp\xa1/\x82\xa5rooms\x91\xb859eefa4a8c200c04be80405b\xa5flags\x80"
1508833866.769642 [0 172.17.0.1:58008] "publish" "socket.io-request#/#" "{\"requestid\":\"CwLPeQ\",\"type\":4,\"room\":\"59eefa4a8c200c04be80405b\"}"
1508833866.770290 [0 172.17.0.1:58008] "publish" "socket.io-request#/#" "{\"requestid\":\"HaY3Li\",\"type\":4,\"room\":\"59eefa4a8c200c04be80405b\"}"

Sometimes there is no error, but more often.

I was able to fix this in my project. Here is what I was using before to connect the adapter:

  if(ENV == 'production') {
    let redisPassword = redisURL.auth.split(':')[1];
    console.log(`redis host: ${redisHost}, port: ${redisPort}, password: ${redisPassword}`);

    let pub = redis.createClient(redisPort, redisHost, {
      no_ready_check: true,
      return_buffers: true
    });

    let sub = redis.createClient(redisPort, redisHost, {
      no_ready_check: true,
      return_buffers: true
    });

    pub.auth(redisPassword);
    sub.auth(redisPassword);

    io.adapter(socketRedis({
      pubClient: pub,
      subClient: sub,
      host: redisHost,
      port: redisPort,
      requestsTimeout: 3000,
      key: 'chat-socket'
    }));
  } else {
    io.adapter(socketRedis({
      host: redisHost,
      port: redisPort,
      key: 'chat-socket',
    }));
  }

This was written before I took over the project, so I can’t say why it’s using 2 clients for pub and sub, but it explains why it was working locally but not in production mode. Changing that to the following fixed it:

  io.adapter(socketRedis(REDIS_URL, {
    requestsTimeout: 3000,
    key: 'chat-socket'
  }));

Why this started to fail when we switched to yarn, I have no idea.

@Natashkinsasha Are you using an AWS ElastiCache? In this case you could try the following code:

  var ioredis = require("ioredis");
  pubClient = new ioredis.createClient(options);
  subClient = new ioredis.createClient(options);
  var adapter = require('socket.io-redis');
  io.adapter(adapter({ pubClient: pubClient, subClient: subClient}));

instead of using “new ioredis.Cluster()”, that worked for me.

Just be careful if you use redlock as well, for redlock you want to use lockClient = new ioredis.Cluster([options]); but not for socket.io-redis.

Source: https://github.com/luin/ioredis/issues/432 (well, and the code above worked for me at least)

我有同样的问题，经过 7 天的研究，我仍然没有找到任何解决方案。

how to resolve this?

mark

Hello. Any progress ?

I have this issue as well… is there an update on this? i’d really not prefer to write a custom function to manage sockets in a room. This works fine on single instance redis, only an issue for me when using cluster.