Long latency between publishing and delivering

[tom-wr]

I'm running RabbitMQ v2.8.5 with node.js v0.8.6 and the amqp-node client. I've set up a simple publish/consume test in two different ways each produces a different latency and I can't work out why. The latency was measured from the time the message was sent to the time it was delivered.

The first method uses two separate processes - one for the publishing app - one for the consuming app. It produces a latency of about at 4ms. The second method uses just one app to produce and consume. This produces a latency of about 40ms.

I have output from wireshark looking something similar to:

#     Time          From                   To               Protocol   Length   Info
...
155 1.539600    127.0.0.1             127.0.0.1             AMQP     115     Basic.Publish
157 1.579834    127.0.0.1             127.0.0.1             AMQP     3873   Content-Header Content-Body
159 1.580942    127.0.0.1             127.0.0.1             AMQP     3963   Basic-Deliver Content-Header Content-Body
160 1.590769    127.0.0.1             127.0.0.1             AMQP     115     Basic.Publish
162 1.627732    127.0.0.1             127.0.0.1             AMQP     3873   Content-Header Content-Body
164 1.628295    127.0.0.1             127.0.0.1             AMQP     3963   Basic-Deliver Content-Header Content-Body
165 1.638748    127.0.0.1             127.0.0.1             AMQP     115     Basic.Publish
167 1.675834    127.0.0.1             127.0.0.1             AMQP     3873   Content-Header Content-Body
169 1.676850    127.0.0.1             127.0.0.1             AMQP     3963   Basic-Deliver Content-Header Content-Body
...

Method #1 Producer:

var amqp = require('amqp'),
connection = amqp.createConnection({host:'localhost'}),
testExchange = {};

connection.on('ready', function(){
    testExchange = connection.exchange('testExchange', {type:'topic', autoDelete:true});
    testMessage();
});

function testMessage(){
    console.log('message sent');
    testExchange.publish('test.message', { msg:'testMessage', time: new Date().getTime() });
    setTimeout(testMessage, 500);
}

Method #1 Consumer

var amqp = require('amqp'),
connection = amqp.createConnection({host:'localhost'}),
connection.on('ready', function(){
    var testExchange = connection.exchange('testExchange', {type:'topic', autoDelete:true});
    var testQ = connection.queue('testQ', function(queue){
        queue.bind('testExchange', 'test.#');
        queue.subscribe( function(message){
            console.log('message received');
            var now = new Date().getTime();
            console.log(now-message.time);
        });
    });
});

Method #2 Producer and Consumer

var amqp = require('amqp'),
connection = amqp.createConnection({host:'localhost'}),
testExchange = {};

connection.on('ready', function(){
    testExchange = connection.exchange('testExchange', {type:'topic', autoDelete:true});
    var testQ = connection.queue('testQ', function(queue){
        queue.bind('testExchange', 'test.#');
            queue.subscribe( function(message){
                console.log('message received');
                var now = new Date().getTime();
                console.log(now-message.time);
             });
        testMessage();
    });
});

function testMessage(){
    console.log('message sent');
    testExchange.publish('test.message', { msg:'testMessage', time: new Date().getTime() });
    setTimeout(testMessage, 500);
}

[whizz]

Hi there. My guess is, in the second method, you send the message before the queue is bound to the exchange. Therefore, the difference is in the time it takes for the queue to bind and subscribe. Remeber, node is asynchronous most of the time, so the actual order of events (or could be):

1. create queue
2. start binding
3. send test message
4. binding is finished
5. start subscribing
6. subscribing is finished
7. receive message
8. print output