ioredis: Cluster: Failed to refresh slots cache. when options.redisOptions.enableOfflineQueue = false

If I pass options to new Cluster with options.redisOptions.enableOfflineQueue = false, ioredis (3.2.2) fails to connect to the cluster. If I remove setting that specific option, then everything is good (went through them one-by-one).

Below is sample code with the output when options.redisOptions.enableOfflineQueue = false.

Note that I also have set options.enableOfflineQueue = false - it is not entirely clear if both need to be set. In my usage, I do NOT want commands to be queued when the cluster or the intended node is not available.

'use strict';

let Redis = require('ioredis');

function _retryStrategy(times) {
    let retry;

    if (times === 1) {
        retry = 1;  // immediate retry
    } else {
        retry = Math.min((times - 1) * 2000, 20000);
    }
    return retry;
}

const options = {
    // Cluster-level options
    // Override ioredis defaults.
    clusterRetryStrategy   : _retryStrategy,
    enableOfflineQueue     : false,                     // ioredis default is true
    scaleReads             : 'all',                     // ioredis default is 'master'

    // ioredis defaults - explicitly set for clarity.
    enableReadyCheck       : true,
    maxRedirections        : 16,
    retryDelayOnFailover   : 100,
    retryDelayOnClusterDown: 100,
    retryDelayOnTryAgain   : 100,

    // Per Server options
    redisOptions: {
        // Override ioredis defaults.
        enableOfflineQueue           : false,           // ioredis default is true   !!! THIS IS THE PROBLEM !!!
        connectTimeout               : 2000,            // ioredis default is 10000
        autoResendUnfulfilledCommands: false,           // ioredis default is true
        retryStrategy                : _retryStrategy,
        readOnly                     : true,            // ioredis default is false

        // ioredis defaults - explicitly set for clarity.
        family           : 4,
        path             : null,
        keepAlive        : 0,
        noDelay          : true,
        db               : 0,
        dropBufferSupport: false,
        enableReadyCheck : true,
        autoResubscribe  : true,
        lazyConnect      : false,
        keyPrefix        : '',
        stringNumbers    : false
     }
};

let startupNodes = [];
for (let i = 0; i < 3; i++) {
    startupNodes[i] = {
        host: '127.0.0.1',
        port: 6400 + (10*i)
    };
    console.log('Using startupNode %s:%d.', startupNodes[i].host, startupNodes[i].port);
}

let client = new Redis.Cluster(startupNodes, options);

client.on('ready', function() {
    console.log('Redis Cluster is Ready.');
});

client.cluster('info', function (err, clusterInfo) {
    if (err) {
        console.log('Redis Cluster is not yet ready. err=%j', err);
    } else {
        console.log('Redis Cluster Info=%j', clusterInfo);
    }
});
/usr/src/app# DEBUG=ioredis:* node clustertest.js    
Using startupNode 127.0.0.1:6400.
Using startupNode 127.0.0.1:6410.
Using startupNode 127.0.0.1:6420.
  ioredis:cluster status: [empty] -> connecting +0ms
  ioredis:redis status[127.0.0.1:6400]: [empty] -> connecting +3ms
  ioredis:redis status[127.0.0.1:6410]: [empty] -> connecting +2ms
  ioredis:redis status[127.0.0.1:6420]: [empty] -> connecting +0ms
  ioredis:cluster getting slot cache from 127.0.0.1:6410 +1ms
  ioredis:redis status[127.0.0.1:6400]: connecting -> connect +15ms
  ioredis:redis write command[0] -> info() +0ms
  ioredis:redis status[127.0.0.1:6410]: connecting -> connect +2ms
  ioredis:redis write command[0] -> info() +0ms
  ioredis:redis status[127.0.0.1:6420]: connecting -> connect +1ms
  ioredis:redis write command[0] -> info() +0ms
  ioredis:cluster getting slot cache from 127.0.0.1:6420 +3ms
Redis Cluster is not yet ready. err={}
  ioredis:cluster getting slot cache from 127.0.0.1:6400 +2ms
[ioredis] Unhandled error event: Error: Failed to refresh slots cache.
    at tryNode (/usr/src/app/node_modules/ioredis/lib/cluster/index.js:375:19)
    at /usr/src/app/node_modules/ioredis/lib/cluster/index.js:387:9
    at /usr/src/app/node_modules/ioredis/lib/cluster/index.js:591:14
    at run (/usr/src/app/node_modules/ioredis/lib/utils/index.js:153:16)
    at tryCatcher (/usr/src/app/node_modules/bluebird/js/release/util.js:16:23)
    at Promise.errorAdapter [as _rejectionHandler0] (/usr/src/app/node_modules/bluebird/js/release/nodeify.js:35:34)
    at Promise._settlePromise (/usr/src/app/node_modules/bluebird/js/release/promise.js:566:21)
    at Promise._settlePromise0 (/usr/src/app/node_modules/bluebird/js/release/promise.js:614:10)
    at Promise._settlePromises (/usr/src/app/node_modules/bluebird/js/release/promise.js:689:18)
    at Async._drainQueue (/usr/src/app/node_modules/bluebird/js/release/async.js:133:16)
    at Async._drainQueues (/usr/src/app/node_modules/bluebird/js/release/async.js:143:10)
    at Immediate.Async.drainQueues (/usr/src/app/node_modules/bluebird/js/release/async.js:17:14)
    at runCallback (timers.js:789:20)
    at tryOnImmediate (timers.js:751:5)
    at processImmediate [as _immediateCallback] (timers.js:722:5)
  ioredis:redis status[127.0.0.1:6410]: connect -> ready +7ms
  ioredis:redis status[127.0.0.1:6420]: connect -> ready +2ms
  ioredis:redis status[127.0.0.1:6420]: ready -> close +1ms
  ioredis:connection skip reconnecting since the connection is manually closed. +0ms
  ioredis:redis status[127.0.0.1:6420]: close -> end +0ms
  ioredis:redis status[127.0.0.1:6410]: ready -> close +1ms
  ioredis:connection skip reconnecting since the connection is manually closed. +0ms
  ioredis:redis status[127.0.0.1:6410]: close -> end +0ms
  ioredis:redis status[127.0.0.1:6400]: connect -> ready +1ms
  ioredis:redis status[127.0.0.1:6400]: ready -> close +0ms
  ioredis:connection skip reconnecting since the connection is manually closed. +0ms
  ioredis:redis status[127.0.0.1:6400]: close -> end +1ms
  ioredis:cluster status: connecting -> close +0ms
  ioredis:cluster status: close -> reconnecting +1ms
  ioredis:cluster Cluster is disconnected. Retrying after 1ms +2ms
  ioredis:cluster status: reconnecting -> connecting +0ms
  ioredis:redis status[127.0.0.1:6400]: [empty] -> connecting +1ms
  ioredis:redis status[127.0.0.1:6410]: [empty] -> connecting +1ms
  ioredis:redis status[127.0.0.1:6420]: [empty] -> connecting +1ms
  ioredis:cluster getting slot cache from 127.0.0.1:6410 +0ms
  ioredis:redis status[127.0.0.1:6400]: connecting -> connect +3ms
  ioredis:redis write command[0] -> info() +1ms
  ioredis:redis status[127.0.0.1:6410]: connecting -> connect +0ms
  ioredis:redis write command[0] -> info() +0ms
  ioredis:redis status[127.0.0.1:6420]: connecting -> connect +1ms
  ioredis:redis write command[0] -> info() +0ms
  ioredis:cluster getting slot cache from 127.0.0.1:6420 +0ms
  ioredis:cluster getting slot cache from 127.0.0.1:6400 +1ms
[ioredis] Unhandled error event: Error: Failed to refresh slots cache.
    at tryNode (/usr/src/app/node_modules/ioredis/lib/cluster/index.js:375:19)
    at /usr/src/app/node_modules/ioredis/lib/cluster/index.js:387:9
    at /usr/src/app/node_modules/ioredis/lib/cluster/index.js:591:14
    at run (/usr/src/app/node_modules/ioredis/lib/utils/index.js:153:16)
    at tryCatcher (/usr/src/app/node_modules/bluebird/js/release/util.js:16:23)
    at Promise.errorAdapter [as _rejectionHandler0] (/usr/src/app/node_modules/bluebird/js/release/nodeify.js:35:34)
    at Promise._settlePromise (/usr/src/app/node_modules/bluebird/js/release/promise.js:566:21)
    at Promise._settlePromise0 (/usr/src/app/node_modules/bluebird/js/release/promise.js:614:10)
    at Promise._settlePromises (/usr/src/app/node_modules/bluebird/js/release/promise.js:689:18)
    at Async._drainQueue (/usr/src/app/node_modules/bluebird/js/release/async.js:133:16)
    at Async._drainQueues (/usr/src/app/node_modules/bluebird/js/release/async.js:143:10)
    at Immediate.Async.drainQueues (/usr/src/app/node_modules/bluebird/js/release/async.js:17:14)
    at runCallback (timers.js:789:20)
    at tryOnImmediate (timers.js:751:5)
    at processImmediate [as _immediateCallback] (timers.js:722:5)
  ioredis:redis status[127.0.0.1:6410]: connect -> ready +7ms
  ioredis:redis status[127.0.0.1:6410]: ready -> close +1ms
  ioredis:connection skip reconnecting since the connection is manually closed. +1ms
  ioredis:redis status[127.0.0.1:6410]: close -> end +0ms
  ioredis:redis status[127.0.0.1:6400]: connect -> ready +4ms
  ioredis:redis status[127.0.0.1:6420]: connect -> ready +1ms
  ioredis:redis status[127.0.0.1:6420]: ready -> close +0ms
  ioredis:connection skip reconnecting since the connection is manually closed. +0ms
  ioredis:redis status[127.0.0.1:6420]: close -> end +1ms
  ioredis:redis status[127.0.0.1:6400]: ready -> close +0ms
  ioredis:connection skip reconnecting since the connection is manually closed. +0ms
  ioredis:redis status[127.0.0.1:6400]: close -> end +0ms
  ioredis:cluster status: connecting -> close +0ms
  ioredis:cluster status: close -> reconnecting +1ms
^C

If I comment out the one line, then all is good:

/usr/src/app# DEBUG=ioredis:* node clustertest.js
Using startupNode 127.0.0.1:6400.
Using startupNode 127.0.0.1:6410.
Using startupNode 127.0.0.1:6420.
  ioredis:cluster status: [empty] -> connecting +0ms
  ioredis:redis status[127.0.0.1:6400]: [empty] -> connecting +3ms
  ioredis:redis status[127.0.0.1:6410]: [empty] -> connecting +3ms
  ioredis:redis status[127.0.0.1:6420]: [empty] -> connecting +0ms
  ioredis:cluster getting slot cache from 127.0.0.1:6420 +2ms
  ioredis:redis queue command[0] -> cluster(slots) +2ms
  ioredis:redis queue command[0] -> cluster(info) +2ms
  ioredis:redis status[127.0.0.1:6400]: connecting -> connect +6ms
  ioredis:redis write command[0] -> info() +1ms
  ioredis:redis status[127.0.0.1:6410]: connecting -> connect +2ms
  ioredis:redis write command[0] -> info() +0ms
  ioredis:redis status[127.0.0.1:6420]: connecting -> connect +0ms
  ioredis:redis write command[0] -> info() +0ms
  ioredis:redis status[127.0.0.1:6410]: connect -> ready +14ms
  ioredis:connection send 1 commands in offline queue +0ms
  ioredis:redis write command[0] -> cluster(info) +1ms
  ioredis:redis status[127.0.0.1:6400]: connect -> ready +1ms
Redis Cluster Info="cluster_state:ok\r\ncluster_slots_assigned:16384\r\ncluster_slots_ok:16384\r\ncluster_slots_pfail:0\r\ncluster_slots_fail:0\r\ncluster_known_nodes:6\r\ncluster_size:3\r\ncluster_current_epoch:3\r\ncluster_my_epoch:2\r\ncluster_stats_messages_ping_sent:7405\r\ncluster_stats_messages_pong_sent:6762\r\ncluster_stats_messages_meet_sent:1\r\ncluster_stats_messages_sent:14168\r\ncluster_stats_messages_ping_received:6758\r\ncluster_stats_messages_pong_received:7406\r\ncluster_stats_messages_meet_received:4\r\ncluster_stats_messages_received:14168\r\n"
  ioredis:redis status[127.0.0.1:6420]: connect -> ready +2ms
  ioredis:connection send 1 commands in offline queue +1ms
  ioredis:redis write command[0] -> cluster(slots) +0ms
  ioredis:redis status[127.0.0.1:6401]: [empty] -> connecting +11ms
  ioredis:redis status[127.0.0.1:6421]: [empty] -> connecting +1ms
  ioredis:redis status[127.0.0.1:6411]: [empty] -> connecting +0ms
  ioredis:cluster status: connecting -> connect +1ms
  ioredis:redis write command[0] -> cluster(info) +1ms
  ioredis:redis status[127.0.0.1:6401]: connecting -> connect +3ms
  ioredis:redis write command[0] -> info() +1ms
  ioredis:redis status[127.0.0.1:6421]: connecting -> connect +1ms
  ioredis:redis write command[0] -> info() +1ms
  ioredis:redis status[127.0.0.1:6411]: connecting -> connect +0ms
  ioredis:redis write command[0] -> info() +0ms
  ioredis:cluster status: connect -> ready +1ms
Redis Cluster is Ready.
  ioredis:redis status[127.0.0.1:6411]: connect -> ready +5ms
  ioredis:connection set the connection to readonly mode +0ms
  ioredis:redis write command[0] -> readonly() +1ms
  ioredis:redis status[127.0.0.1:6401]: connect -> ready +2ms
  ioredis:connection set the connection to readonly mode +2ms
  ioredis:redis write command[0] -> readonly() +0ms
  ioredis:redis status[127.0.0.1:6421]: connect -> ready +1ms
  ioredis:connection set the connection to readonly mode +1ms
  ioredis:redis write command[0] -> readonly() +0ms
^C

About this issue

  • Original URL
  • State: closed
  • Created 6 years ago
  • Comments: 20

Most upvoted comments

Again, thanks for digging into this. I have some rather ugly code that periodically performs a CLUSTER NODES and compares the count with cluster.nodes and if the count is different I destroy and recreate the ioredis client. Not the cleanest or more efficient. Similarly, to work around the issue captured here where the client never connects - I simply have a timeout to guard against this condition and again destroy and recreate the ioredis client. Looking forward to ripping that code out and completely rely on ioredis to maintain and automatically recover connections.