Pipeline mode (wait_all_responses) issue with ttl and data

[evengar2008]

When using Redis::Fast in pipeline mode with wait_all_responses command we found some strange behavior.

We expect that in case of network connectivity issues/redis server going down, redis instance in perl script/module will wait for timeout and then crash if all reconnect attempts fail in specified time interval.

However, that's not the case when we are in the pipeline mode. Just after the redis goes down, wait_all_responses() returns last actual TTL and data for the specified key, then waits for timeout and then crashes with Redis server connect error.

No error is saved in the $error variable in the callback passed to Redis::Fast ttl and get commands. Neither does the Redis::Fast instance crash just after redis connection is lost as it could have been expected.

Is this supposed behavior?

Here is PoC

#!/usr/bin/perl

use Redis::Fast;
use Data::Dumper;

my $redis_host = "redis:6379";

my $redis = Redis::Fast->new(
    server        => $redis_host,
    reconnect     => 1,
    every         => 100_000,
    cnx_timeout   => 1,
    read_timeout  => 10,
    write_timeout => 10,
    encoding      => undef,
    select        => 'cache',
);

my $test_key = "RedisTestKey";

my ($data, $ttl, $error);

$redis->set( $test_key => 'value' );
$redis->expire( $test_key, 60 );

sub get_data_from_redis {
    my ($key) = @_;

    $redis->get( $key,      sub { $data = $_[0]; $error //= $_[1];  } );
    $redis->ttl( $key,      sub { $ttl = $_[0];  $error //= $_[1];  } );
    $redis->wait_all_responses();

    print Dumper(
        {
            data     => $data,
            ttl      => $ttl,
            error    => $error,
            eval_err => $@,
        }
    );

    return $data, $ttl;
}

while (1) {
    my ( $cached_data, $current_ttl ) = get_data_from_redis( $test_key );
    print Dumper( { cached_data => $cached_data, current_ttl => $current_ttl } );

    sleep(3);
}

terminal output when running this script:

# start script in terminal tab1

➜  ~  perl test2.pl

$VAR1 = {
          'eval_err' => '',
          'error' => undef,
          'data' => 'value',
          'ttl' => 60
        };
$VAR1 = {
          'cached_data' => 'value',
          'current_ttl' => 60
        };

$VAR1 = {
          'eval_err' => '',
          'data' => 'value',
          'error' => undef,
          'ttl' => 57
        };
$VAR1 = {
          'cached_data' => 'value',
          'current_ttl' => 57
        };

$VAR1 = {
          'eval_err' => '',
          'data' => 'value',
          'error' => undef,
          'ttl' => 54
        };
$VAR1 = {
          'current_ttl' => 54,
          'cached_data' => 'value'
        };

# stop redis service/container in parallel opened tab2

$VAR1 = {
          'eval_err' => '',
          'data' => 'value',
          'error' => undef,
          'ttl' => 54
        };
$VAR1 = {
          'current_ttl' => 54,
          'cached_data' => 'value'
        };

# timeout 1s

Could not connect to Redis server at redis:6379 at /usr/local/lib/x86_64-linux-gnu/perl/5.26.1/Redis/Fast.pm line 264.

# redis instance crashes, but just before that last actual TTL and data are returned.

@vaneska @TatyanaUstinova

[evengar2008]

plus @vsespb

[vsespb]

+1, reproducible.

also PoC code works without bug in pureperl Redis module.

[vsespb]

I think I simplified PoC code:

#!/usr/bin/perl

use strict;
use warnings;
use Redis::Fast;
use Data::Dumper;

my $redis_host = "redis:6379";

my $redis = Redis::Fast->new(
    server        => $redis_host,
    reconnect     => 1,
    every         => 100_000,
    cnx_timeout   => 1,
    read_timeout  => 10,
    write_timeout => 10,
    encoding      => undef,
    select        => 'cache',
);

my $test_key = "RedisTestKey";

$redis->set( $test_key => 'MyValue' );

while (1) {
    my ($data, $error);
    my $is_called = 0;
    $redis->get( $test_key,      sub { $is_called = 1; $data = $_[0]; $error = $_[1];  } );
    $redis->wait_all_responses();
    die "Callback never called" unless $is_called;
    print "data: $data\n";

    sleep(3);
}

If you run this script and stop redis server during execution, it'll die with:

$ perl redispoc1.pl 
data: MyValue
data: MyValue
Callback never called at redispoc1.pl line 31.

and that seems to be a bug. Correct behaviour: callback should be called and $error should be set. Or reconnect should happen and callback called with real data (that how pureperl Redis works).

Please note that there is different case:

#!/usr/bin/perl

$|=1;

use strict;
use warnings;
use Redis::Fast;
use Data::Dumper;

my $redis_host = "redis:6379";

my $redis = Redis::Fast->new(
    server        => $redis_host,
    reconnect     => 1,
    every         => 100_000,
    cnx_timeout   => 1,
    read_timeout  => 10,
    write_timeout => 10,
    encoding      => undef,
    select        => 'cache',
);

my $test_key = "RedisTestKey";

$redis->set( $test_key => 'MyValue' );

while (1) {
    my ($data, $error);
    my $is_called = 0;
    $redis->get( $test_key,      sub { } );
    print "now stop redis-server!\n";
    sleep 3;
    $redis->get( $test_key,      sub { $is_called = 1; $data = $_[0]; $error = $_[1];  } );
    $redis->wait_all_responses();
    die "Callback never called" unless $is_called;
    print "data: $data\n";
}

with this script we can stop redis-server after 1st pipelined command sent, but before second pipelined command sent. In this case both Redis and Redis::Fast fail, but Redis::Fast fails again with Callback never called which is a bug too.

[shogo82148]

I've just released v0.31 including #118 it fixes this issue. please try it.

[evengar2008]

@shogo82148 Thank you, just tested the updated lib. Works as expected