Faye Latency

‹prev | My Chain | next›

Tonight, I continue my investigation into latency in faye. This latency manifests itself in my (fab) game collisions:



On my screen, the reaction to a collision is much faster than on the screens of other players. I tried shifting code about to resolve the issue, without luck.

I will use the node-repl to investigate tonight. I establish a faye subscription to a "/test" channel and then send a message on that same channel. When the message is received, I store the time and when the message is sent, I record the time. The difference should be the latency built-in:

node> var faye = require("faye");
node> var client = new faye.Client('http://localhost:4011/faye');
node> var d1, d2;
node> var s = client.subscribe('/test', function(message) {puts(message); d2 = new Date()});
node> client.publish('/test', 'test'); d1 = new Date();
Sat, 14 Aug 2010 08:47:39 GMT
node> d2

Hunh? The variable d2, declared with global scope, should have been set when the subscribed channel received the message. In fact, the puts() statement inside the subscription function proves that the message was received. What gives?

Trying this in a more generic setting, I find that function scope is not able to affect a variable declared outside of it:

node> var foo = "bar";
node> function fn() { foo = "foo"; }
node> foo
'bar'
node> fn();
node> foo
'bar'

That same code works as I expect in the browser:



Dang, looks like different global variable semantics in node-repl. Luckily, a global object will work in node-repl:

node> var faye = require("faye");
node> var client = new faye.Client('http://localhost:4011/faye');
node> var dates={};
node> var s = client.subscribe('/test', function(message) {dates['received'] = new Date()});
node> client.publish('/test', 'test'); dates['sent'] = new Date();
Sat, 14 Aug 2010 08:58:39 GMT

After that, I have both sent and received attributes in my global object:

node> dates
{ sent: Sat, 14 Aug 2010 08:58:39 GMT
, received: Sat, 14 Aug 2010 08:58:40 GMT
}

Those are date values, not strings, so I can do simple arithmetic on them to see how long it takes for the round trip message:

node> dates['received'] - dates['sent']
217

Hmmm... 200 milliseconds. That might account for the delay that I am seeing. To make sure that is not a one time only thing, I run the numbers a few more times:

node> client.publish('/test', 'test'); dates['sent'] = new Date();
Sat, 14 Aug 2010 08:59:27 GMT
node> dates['received'] - dates['sent']
215
node> client.publish('/test', 'test'); dates['sent'] = new Date();
Sat, 14 Aug 2010 08:59:30 GMT
node> dates['received'] - dates['sent']
212
node> client.publish('/test', 'test'); dates['sent'] = new Date();
Sat, 14 Aug 2010 08:59:35 GMT
node> dates['received'] - dates['sent']
211
node> client.publish('/test', 'test'); dates['sent'] = new Date();
Sat, 14 Aug 2010 08:59:40 GMT
node> dates['received'] - dates['sent']
212
node> client.publish('/test', 'test'); dates['sent'] = new Date();
Sat, 14 Aug 2010 08:59:43 GMT
node> dates['received'] - dates['sent']
212

Yup. That's consistently 200+ milliseconds. And that is just on my local machine. What is going to happen when this is happening over Internet connections? I thought I might have to deal with this back when I was passing messages over comet. Now I cannot avoid it if I am going to continue pursuing faye message passing.

And I will get started on mitigating this problem tomorrow.

Day #195