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

Error, which is returned from retry_strategy remains uncaught

Open pavelsc opened this issue 8 years ago • 23 comments
trafficstars

I have the code below and try to imitate dropped connection using iptables -A OUTPUT -p tcp --dport 6379 -j REJECT.

self.client = redis.createClient(self.cfg.port, self.cfg.host, {
    retry_strategy: function (options) {
        console.log('retry strategy check');
        console.log(options);
        if (options.error) {
            if (options.error.code === 'ECONNREFUSED') {
                // End reconnecting on a specific error and flush all commands with a individual error
                return new Error('The server refused the connection');
            }
            if (options.error.code === 'ECONNRESET') {
                return new Error('The server reset the connection');
            }
            if (options.error.code === 'ETIMEDOUT') {
                return new Error('The server timeouted the connection');
            }
        }
        if (options.total_retry_time > 1000 * 60 * 60) {
            // End reconnecting after a specific timeout and flush all commands with a individual error
            return new Error('Retry time exhausted');
        }
        if (options.attempt > 5) {
            // End reconnecting with built in error
            return new Error('Retry attempts ended');
        }
        // reconnect after
        return 1000;
    }
});
self.client.on('ready', function () {
    log.trace('Redis client: ready');
});
self.client.on('connect', function () {
    log.trace('Redis client: connect');
});
self.client.on('reconnecting', function () {
    log.trace('Redis client: reconnecting');
});
self.client.on('error', function (err) {
    log.error({err: err}, 'Listener.redis.client error: %s', err);
    process.exit(1);
});
self.client.on('end', function () {
    log.trace('Redis client: end');
});
self.client.on('warning', function () {
    log.trace('Redis client: warning');
});

It is supposed that all redis errors are emitted in error event. But here is what i've got in console output:

21:00:14.666Z TRACE script: Redis client: connect 21:00:14.695Z TRACE script: Redis client: ready 21:10:23.837Z TRACE script: Redis client: end retry strategy check { attempt: 1, error: { [Error: Redis connection to redis.callision.info:6379 failed - read ECONNRESET] code: 'ECONNRESET', errno: 'ECONNRESET', syscall: 'read' }, total_retry_time: 0, times_connected: 1 }

/node_modules/q/q.js:155 throw e; ^ AbortError: Stream connection ended and command aborted. It might have been processed. at RedisClient.flush_and_error (/node_modules/redis/index.js:350:23) at RedisClient.connection_gone (/node_modules/redis/index.js:612:18) at RedisClient.on_error (/node_modules/redis/index.js:398:10) at Socket. (/node_modules/redis/index.js:272:14) at emitOne (events.js:90:13) at Socket.emit (events.js:182:7) at emitErrorNT (net.js:1255:8) at nextTickCallbackWith2Args (node.js:474:9) at process._tickCallback (node.js:388:17)

And as a question: Why it takes about 10 minutes to detect that connection is gone? Is there any way to raise an error in case of no response within 10 seconds? May be any option like response_timeout etc.

  • Version: node_redis v.2.6.5 and Redis 3.0.7
  • Platform: Node.js v5.5.0 on Ubuntu 14.04.4 LTS
  • Description: error from retry_strategy remains uncaught

pavelsc avatar Feb 27 '17 22:02 pavelsc

@pavelsc I tried to reproduce this but so far I could not.

Please try to reproduce the issue without any third party modules. Currently you seem to at least use q.

BridgeAR avatar Mar 11 '17 16:03 BridgeAR

I am encountering the same error. If I intentionally provide Redis client a bad URL, the on.error method is not invoked. Here is a simple example:

var redis = require("redis");

exports.handler = function (event, context, callback) {

    console.log("Executing test lambda for diagnosing redis issues");
    
    var redisInfo = {
        HOST: process.env.REDIS_HOST,
        PORT: process.env.REDIS_PORT
    };

    console.log(process.env.REDIS_HOST);
    console.log(process.env.REDIS_PORT);

    console.log("Connecting to Redis...");

    var client = redis.createClient({
        host: redisInfo.HOST,
        port: redisInfo.PORT,
        retry_strategy: function (options) {

            if (options.total_retry_time > 2000) {
                console.log("throwing an error...");
                return new Error('Retry time exhausted');
            }

            return 200;
        }
    });

    // if you'd like to select database 3, instead of 0 (default), call
    // client.select(3, function() { /* ... */ });

    client.on("error", function (err) {
        console.log("Error " + err);
        callback(null, "Error with Redis");
    });

    client.on('connect', function() {
        console.log("Connected to Redis");
    });

    client.on('end', function() {
        console.log("Redis end");
    });

    client.set("string key", "string val", redis.print);
    client.hset("hash key", "hashtest 1", "some value", redis.print);
    client.hset(["hash key", "hashtest 2", "some other value"], redis.print);
    client.hkeys("hash key", function (err, replies) {
        console.log(replies.length + " replies:");
        replies.forEach(function (reply, i) {
            console.log("    " + i + ": " + reply);
        });
        client.quit();
    });
    
    client.quit();

    callback(null, "Success");
};

spowers225 avatar Apr 10 '17 18:04 spowers225

For now I am reverting back to using connect_timeout, which emits on 'error' correctly after a connect timeout expires.

spowers225 avatar Apr 11 '17 13:04 spowers225

I'm having the same issue, using a custom retry_strategy with a bad endpoint ends up in "AbortError:"

mpayne-sds avatar Aug 17 '17 18:08 mpayne-sds

This caught me out today as well. From looking at the code briefly, this seems to be intentional behaviour. https://github.com/NodeRedis/node_redis/blob/79558c524ff783000a6027fb159739770f98b10e/index.js#L405 explicitly states that if retry_strategy is set, not to emit the error and instead continues to throw it. I'd be curious to hear why this is the case though, there doesn't seem to be a reason why it can't emit it instead of throwing from a quick look. Is there any reason this conditional couldn't be taken out, so that the error will always be emitted?

maael avatar Sep 06 '17 13:09 maael

I am having this problem as well, consistently.

karlsnyder0 avatar Sep 28 '17 14:09 karlsnyder0

I too am not able to catch errors when receiving an ENOTFOUND.

{
    host: "foo",
    retry_strategy: function (options) {
        if (options.error && options.error.code === "ENOTFOUND") {
            return new Error("The server was not found");
        }

        // reconnect after
        return 1000;
}

with:

redis.on("error", err => {
    console.error("Cache Error: " + err);
});

Debugging the application, i'm getting into the ENOTFOUND check as noted above in the retry_strategy but it's not invoking the error event handler.

RobGraham avatar Dec 04 '17 23:12 RobGraham

I have the same issue, after digging around through the source code I found that if we change this line (or enable debug mode) https://github.com/NodeRedis/node_redis/blob/009479537eb920d2c34045026a55d31febd1edd7/index.js#L381-L382

And insert this piece of code here (add error to the array right away) https://github.com/NodeRedis/node_redis/blob/009479537eb920d2c34045026a55d31febd1edd7/index.js#L352-L353

    if (options.error) {
      aggregated_errors.push(options.error);
    }

It works and emits 'error' correctly.

The nested loop in that function does not get executed, because 'command_queue' is empty and error never get's added to the array and thus not emitted. If I understand correctly, it's a quite old piece of code, so we do need input from the maintainers or from @BridgeAR

I also saw that on first failed connection emits 'end' event , that might mean something (or not), I picked up Redis two days ago, so not sure how the internals work yet. I'll try to fork and dig around a bit more when if/when I have the time.

v1adko avatar Dec 07 '17 08:12 v1adko

And literally the next issue seems connected to this problem #1198

v1adko avatar Dec 07 '17 09:12 v1adko

@v1adko I'm currently traveling, but I'll try to take a look at it later today or tomorrow (unless Ruben beats me to it).

stockholmux avatar Dec 07 '17 10:12 stockholmux

I have my redis url deliberately wrong to test error scenarios but i see my retry_strategy not invoked when trying to connect to redis. retry_strategy is invoked only when connection is closed.

`const redis = require('redis'); const log = require('./logUtil').logger;

module.exports.connect = () => {

var redisRetryStrategy = function(options) {
    if (options.error && options.error.code === 'ECONNREFUSED') {
        // End reconnecting on a specific error and flush all commands with 
        // a individual error
        log.error('The redis server refused the connection');
        return new Error('The redis server refused the connection');
    }
    
    log.info(`Already spent ${options.total_retry_time} milliseconds to re-establish connection with redis`);
    if (options.total_retry_time > 2000) {
        // End reconnecting after a specific timeout and flush all commands 
        // with a individual error 
        log.error('Retry time exhausted');
        return new Error('Retry time exhausted');
    }
    log.info(`Attempting ${options.attempt} time to establish connection with redis`);
    if (options.attempt > 5) {
        // End reconnecting with built in error 
        log.error('Exhausted the retry attempts to establish connection to redis');
        return undefined;
    }
    // reconnect after 
    return 100;
}


log.info(`Redis connection url is :${process.env.REDIS_URL}`);
var redisClient = redis.createClient(qualifyUrl(process.env.REDIS_URL), {
    retry_strategy: redisRetryStrategy
});

redisClient.offline_queue_length = 3;

redisClient.on('connect', function() {
    console.log('Connected to Redis');
});

redisClient.on('reconnecting', function() {
    console.log('Re-Connecting to Redis');
});

redisClient.on('error', (err)=> {
    console.log(`Error trying to create redis connection: ${JSON.stringify(err)}`);
});
return redisClient;

}

const qualifyUrl = (url) => { return '//' + url.replace(/^/+/,""); };

`

Could someone please help me resolve this issue.

sachinmani avatar Dec 12 '17 10:12 sachinmani

Same here. This nasty hack seems to create the expected behaviour, but not sure if it has any wider implications:

const client = redis.createClient({
  retry_strategy: ({error}) => client.emit('error', error)
});

client.on('error', console.error);

c24w avatar Feb 05 '18 15:02 c24w

I'm having the same issues at the moment. Using retry_strategy, returning the error as indicated by the example in the Readme, yet no error is emitted by the client. The fixes proposed by @v1adko solve the issue at least at face value.

I'm wondering what the backwards incompatibility mentioned here is? https://github.com/NodeRedis/node_redis/blob/009479537eb920d2c34045026a55d31febd1edd7/index.js#L380

As pointed out by @maael , the behaviour appears to be intentional for when retry_strategy is set. So is the behaviour expected, but the documentation is incorrect? Should I be emitting errors for the client manually as suggested by @c24w ?

edit: As I'm digging into the package I'm realising that emitting manually is probably not the way forward. Seems I need to understand the breaking changes mentioned.

lp-belliot avatar Apr 17 '18 02:04 lp-belliot

Any news ? I have the same problem.

matzmz avatar Dec 11 '18 15:12 matzmz

Any news?

multivoltage avatar May 15 '19 16:05 multivoltage

is a wrong idea to do:

if (options.error && options.error.code === 'ECONNREFUSED') {
  // End reconnecting on a specific error and flush all commands with
  // a individual error
  return Math.min(options.attempt * 100, 3000);
}```

multivoltage avatar May 15 '19 16:05 multivoltage

having the same issue, retry_Strategy not triggering error event, no fix yet?

lkwjohn avatar Jul 23 '19 09:07 lkwjohn

Did anyone succeed?

Demmonius avatar Aug 09 '19 09:08 Demmonius

We switched our implementation to https://github.com/luin/ioredis instead, which brought a few improvements (native Promises, lazyConnect(avoid opening a connection when instanciating the redis client, helped us handle errors exactly where we needed)), and allows the following code to run:

let cachedItem;

  try {
    logger.debug(`Fetching GraphCMS query in redis cache...`);
    // XXX If fetching data from redis fails, we will fall back to running the query against GraphCMS API in order to ensure the client gets the data anyway
    cachedItem = await redisClient.get(body);
  } catch (e) {
    logger.debug(`An exception occurred while fetching redis cache.`);
    logger.error(e);
    epsagon.setError(e);
  }

Using the following utils/redis.js:

import { createLogger } from '@unly/utils-simple-logger';
import Redis from 'ioredis';
import epsagon from './epsagon';

const logger = createLogger({
  label: 'Redis client',
});

/**
 * Creates a redis client
 *
 * @param url Url of the redis client, must contain the port number and be of the form "localhost:6379"
 * @param password Password of the redis client
 * @param maxRetriesPerRequest By default, all pending commands will be flushed with an error every 20 retry attempts.
 *          That makes sure commands won't wait forever when the connection is down.
 *          Set to null to disable this behavior, and every command will wait forever until the connection is alive again.
 * @return {Redis}
 */
export const getClient = (url = process.env.REDIS_URL, password = process.env.REDIS_PASSWORD, maxRetriesPerRequest = 20) => {
  const client = new Redis(`redis://${url}`, {
    password,
    showFriendlyErrorStack: true, // See https://github.com/luin/ioredis#error-handling
    lazyConnect: true, // XXX Don't attempt to connect when initializing the client, in order to properly handle connection failure on a use-case basis
    maxRetriesPerRequest,
  });

  client.on('connect', function () {
    logger.info('Connected to redis instance');
  });

  client.on('ready', function () {
    logger.info('Redis instance is ready (data loaded from disk)');
  });

  // Handles redis connection temporarily going down without app crashing
  // If an error is handled here, then redis will attempt to retry the request based on maxRetriesPerRequest
  client.on('error', function (e) {
    logger.error(`Error connecting to redis: "${e}"`);
    epsagon.setError(e);
  });

  return client;
};

And utils/redis.test.js file:

import { getClient } from './redis';

let redisClient;
let redisClientFailure;

describe('utils/redis.js', () => {
  beforeAll(() => {
    redisClient = getClient();
    redisClientFailure = getClient('localhost:5555', null, 0); // XXX This shouldn't throw an error because we're using lazyConnect:true which doesn't automatically connect to redis
  });

  afterAll(async () => {
    await redisClient.quit();
    await redisClientFailure.quit();
  });

  describe('should successfully init the redis client', () => {
    test('when provided connection info are correct', async () => {
      // Environment variables are from the .env.test file - This tests a localhost connection only
      expect(redisClient.options.host).toEqual(process.env.REDIS_URL.split(':')[0]);
      expect(redisClient.options.port).toEqual(parseInt(process.env.REDIS_URL.split(':')[1], 10));
      expect(redisClient.options.password).toEqual(process.env.REDIS_PASSWORD);
    });

    test('when connection info are incorrect', async () => {
      expect(redisClientFailure.options.host).toEqual('localhost');
      expect(redisClientFailure.options.port).toEqual(5555);
    });
  });

  describe('should successfully perform native operations (read/write/delete/update)', () => {
    test('when using async/await (using native node.js promises)', async () => {
      const setResult = await redisClient.set('key-1', 'value-1');
      expect(setResult).toEqual('OK');

      const result = await redisClient.get('key-1');
      expect(result).toEqual('value-1');

      const delResult = await redisClient.del('key-1');
      expect(delResult).toEqual(1);

      const setResultB = await redisClient.set('key-1', 'value-1b');
      expect(setResultB).toEqual('OK');

      const resultB = await redisClient.get('key-1');
      expect(resultB).toEqual('value-1b');

      const setResultC = await redisClient.set('key-1', 'value-1c');
      expect(setResultC).toEqual('OK');

      const resultC = await redisClient.get('key-1');
      expect(resultC).toEqual('value-1c');
    });
  });

  describe('should allow to catch an error when failing to open a connection to redis, in order to gracefully handle the error instead of crashing the app', () => {
    test('when connection info are incorrect', async () => {
      expect(redisClientFailure.options.host).toEqual('localhost');
      expect(redisClientFailure.options.port).toEqual(5555);

      try {
        await redisClientFailure.set('key-1', 'value-1'); // This should throw an error, because the connection to redis will be made when executing the
        expect(true).toBe(false); // This shouldn't be called, or the test will fail
      } catch (e) {
        expect(e).toBeDefined();
        expect(e.message).toContain('Reached the max retries per request limit');
      }
      await redisClientFailure.quit();
    });
  });
});

Env variables:

REDIS_URL=localhost:6379
REDIS_PASSWORD=mypasswordissostrong

Vadorequest avatar Aug 11 '19 13:08 Vadorequest

I'm also encountering this issue. Will try switching to https://github.com/luin/ioredis for now

Coriou avatar Mar 18 '21 11:03 Coriou

Same issue. Here is where an error is being thrown before retrying. https://github.com/redis/node-redis/blob/a7d5bc7ca4da6cde66140ae4fea96a8ea6e7ce64/packages/client/lib/client/socket.ts#L170

sswayney avatar Jun 08 '23 17:06 sswayney

same issue here, do you have a fix using this package? because, I have a solution using IO Redis, but i wanted to use nests-redis directly.

mbsanchez01 avatar Jul 25 '23 16:07 mbsanchez01

https://github.com/redis/node-redis/issues/1202#issuecomment-520228718 was my fix, basically using a different library.

Vadorequest avatar Jul 26 '23 06:07 Vadorequest