Problem with concurrent 'multi' commands

[strada]

I've run into a problem trying to run 'multi' (transaction) queries in parallel. I've simplified the code to make it more understandable, this function is called in a http request handler, and therefore can run in parallel if multiple requests are made concurrently. DBProvider.client is the client object from node_redis.

DBProvider.prototype.getIntersection = function(callback) {
    var self = this;
    this.client.sinter('setA', 'setB', function(error, intersection) {
        console.log(intersection.length);
    });
};

When running this query in parallel, it works fine, it always logs the right intersection count between the two sets in console, for example:

1021
1021
...

The problem occurs when 'multi' queries is in play:

DBProvider.prototype.getIntersection = function(callback) {
    var self = this;
    var multi;
    this.client.sinter('setA', 'setB', function(error, intersection) {
        console.log(intersection.length);
        if(!error) {
            var intersectionCount = intersection.length;
            multi = self.client.multi();
            for (var i=0; i < intersectionCount; i++) {
                multi.hgetall('d:' + intersection[i]);
            }
            multi.exec(function(error, replies) {
                console.log(replies.length);
                if(replies.length < 10) {
                    console.log(replies);
                } 
            });
        }
    });
};

This is the console output when the 2nd function is called in parallel with concurrent http requests.

1021
1021
1021
4
4
4
4
6
QUEUED
6
6
QUEUED
...

The redis client starts returning this reply from then on, and this persists until I restart the server(and therefore create a new node_redis client). Am I using multi queries wrong, should I make the requests wait so that there are no concurrent multi queries?

node_redis version is 0.8.2.

Note: I've solved my problem by not using 'multi' and issuing about a thousand hgetall commands in the for loop, and counting the callbacks(not ideal but works). I'm creating this issue to document the problem I had so the module maintainers can test.

[brycebaril]

Can you try with the hiredis parser? npm install hiredis?

I made a modified version of your test code that sometimes is able to trigger the issue:

var redis = require("redis");
var client = redis.createClient();
var http = require("http");

http.createServer(function (req, res) {
  getIntersection(function () {
    res.writeHead(200, {'Content-Type': 'text/plain'});
    res.end('Hello World\n');
  });
}).listen(1337, '127.0.0.1');
console.log('Server running at http://127.0.0.1:1337/');

function setup() {
  var seta = [];
  for (var i = 0; i < 2000; i++) {
    seta.push("foo" + i);
    client.hmset("foo" + i, {key: "value"});
  }
  var setb = [];
  for (var j = 1000; j < 3000; j++) {
    setb.push("foo" + j);
    client.hmset("foo" + j, {key: "value"});
  }

  client.sadd("setA", seta, console.log);
  client.sadd("setB", setb, console.log);
}

setup();

function getIntersection(callback) {
    var multi;
    client.sinter('setA', 'setB', function(error, intersection) {
        console.log(intersection.length);
        if(!error) {
            var intersectionCount = intersection.length;
            multi = client.multi();
            for (var i=0; i < intersectionCount; i++) {
                multi.hgetall(intersection[i]);
            }
            multi.exec(function(error, replies) {
                console.log(replies.length);
                if(replies.length < 30) {
                    console.log(replies);
                }
                callback();
            });
        }
    });
};

When the bug is triggered, it looks like this is the debug output:

6
send 127.0.0.1:6379 id 1: *1
$5
MULTI

send_command buffered_writes: 0  should_buffer: false
send 127.0.0.1:6379 id 1: *2
$7
hgetall
$1
Q

send_command buffered_writes: 0  should_buffer: false
send 127.0.0.1:6379 id 1: *2
$7
hgetall
$1
U

send_command buffered_writes: 0  should_buffer: false
send 127.0.0.1:6379 id 1: *2
$7
hgetall
$1
E

send_command buffered_writes: 0  should_buffer: false
send 127.0.0.1:6379 id 1: *2
$7
hgetall
$1
U

send_command buffered_writes: 0  should_buffer: false
send 127.0.0.1:6379 id 1: *2
$7
hgetall
$1
E

send_command buffered_writes: 0  should_buffer: false
send 127.0.0.1:6379 id 1: *2
$7
hgetall
$1
D

It then starts returing "6" which looks like because that is the number of letters in "QUEUED". From there on the parser is suffering by off-by-at-least-one errors until it sends an illegal command to Redis and throws.

If I npm install hiredis to bypass the javascript parser I'm unable to reproduce the error. If that's an option for you, try with the hiredis parser.

Looks like another parser bug in the javascript parser, more and more of which have been cropping up recently.

[nfarina]

We've seen this a LOT when under heavy load. We're using the Javascript parser as well. We had to quit using multi() in a few places.

[brycebaril]

I have a fix for this, will submit the PR soon.

[strada]

I can confirm the problem does not occur with hiredis parser.