Please setNoDelay(true) on socket

[roytan883]

After digging a weird bug, we found that Nodejs doc is wrong on Linux setNoDelay(), which is not use true by default.

At node_modules/nats/lib/nats.js Line 620, please add this.stream.setNoDelay(true)

    // Create the stream
    this.stream = net.createConnection(this.url.port, this.url.hostname);
    this.stream.setNoDelay(true)

also check this on nodejs issue 906

[aricart]

Did a quick test on a small cloud vm and found that performance indeed is a bit better on Linux. On other platforms (OS X) it actually is worse.

PUB
version           average   max   min   samples  rate            
----------------  --------  ----  ----  -------  ----------------
1.0.0_tcpnodelay  1050.125  1079  1041  1000000  952,267 msgs/sec
1.0.0             1073.25   1103  1052  1000000  931,749 msgs/sec

PUBSUB
version           average            max   min   samples  rate            
----------------  -----------------  ----  ----  -------  ----------------
1.0.0_tcpnodelay  1794.142857142857  1828  1762  1000000  557,369 msgs/sec
1.0.0             1843.375           1859  1818  1000000  542,483 msgs/sec

[aricart]

Actually did some testing.

var NATS = require('nats');
var nc = NATS.connect();

nc.on('connect', () => {
        var now = Date.now();	
	nc.subscribe('foo', (m) => {
	  var end = Date.now() - now;
		console.log("took", end, "ms");
		process.exit(1);
	});
	nc.publish('foo');
});

I am getting about 1ms roundtrip without doing anything. Setting the setNoDelay(false), brings it to 38ms. So this must mean that at least on node 10, this value is set by default. Going to dig with more stats on different node versions.

[aricart]

These are runs in the same tiny machine at AWS using node 10 and 6.
off - setNoDelay(false)
on - setNoDelay(true)
or without setting it on or off.

version                    average  max   min   samples  rate            
-------------------------  -------  ----  ----  -------  ----------------
1.0.0_tcpdelay_on_node10   1058.8   1076  1051  1000000  944,465 msgs/sec
1.0.0_node10               1076.7   1088  1067  1000000  928,763 msgs/sec
1.0.0_tcpdelay_off_node10  1079.2   1085  1072  1000000  926,612 msgs/sec
1.0.0_tcpdelay_off         1570.8   1681  1543  1000000  636,618 msgs/sec
1.0.0_tcpdelay_on          1572.8   1751  1530  1000000  635,808 msgs/sec
1.0.0                      1585.8   1613  1575  1000000  630,596 msgs/sec

PUBSUB
version                    average             max   min   samples  rate            
-------------------------  ------------------  ----  ----  -------  ----------------
1.0.0_tcpdelay_on_node10   1789.4              1803  1778  1000000  558,846 msgs/sec
1.0.0_node10               1818.2              1855  1792  1000000  549,994 msgs/sec
1.0.0_tcpdelay_off_node10  1844.6              1925  1812  1000000  542,122 msgs/sec
1.0.0_tcpdelay_on          2270.3              2334  2229  1000000  440,470 msgs/sec
1.0.0_tcpdelay_off         2290.1              2339  2244  1000000  436,662 msgs/sec
1.0.0                      2297.1666666666665  2426  2223  1000000  435,318 msgs/sec

[aricart]

I am going to discuss this with the team.

[roytan883]

Can you test it with Nodejs latest LTS v8.11.3 ?
We found this issue on version 8.11.x

Or expose a option noDelay like preserveBuffers?

[aricart]

Still not seeing any significant change. As you know we do our own buffering of messages which reduces the number of syscalls we do and yields much better performance.

version                            average             max   min   samples  rate             
---------------------------------  ------------------  ----  ----  -------  ----------------
1.0.0_noDelay_node_v10.6.0         1058.8              1076  1051  1000000  944,465 msgs/sec
1.0.0_node_v10.6.0                 1076.7              1088  1067  1000000  928,763 msgs/sec

1.0.0_noDelay_node_v8.11.3         1158.6              1258  1136  1000000  863,110 msgs/sec
1.0.0_node_v8.11.3                 1164.1              1184  1156  1000000  859,045 msgs/sec

1.0.0_remote_noDelay_node_v8.11.3  1346                1379  1294  1000000  742,942 msgs/sec
1.0.0_remote_node_v8.11.3          1308                1406  1248  1000000  764,525 msgs/sec

1.0.0_noDelay_node_v6.14.3         1572.8              1751  1530  1000000  635,808 msgs/sec
1.0.0_node_v6.14.3                 1585.8              1613  1575  1000000  630,596 msgs/sec

PUBSUB
version                            average             max   min   samples  rate             
---------------------------------  ------------------  ----  ----  -------  ----------------
1.0.0_noDelay_node_v10.6.0         1789.4              1803  1778  1000000  558,846 msgs/sec
1.0.0_node_v10.6.0                 1844.6              1925  1812  1000000  542,122 msgs/sec

1.0.0_noDelay_node_v8.11.3         1867.8              1924  1854  1000000  535,389 msgs/sec
1.0.0_node_v8.11.3                 1871.5              1976  1851  1000000  534,330 msgs/sec

1.0.0_remote_noDelay_node_v8.11.3  1795.2              1864  1745  1000000  557,040 msgs/sec
1.0.0_remote_node_v8.11.3          1929.8              1978  1811  1000000  518,188 msgs/sec

1.0.0_noDelay_node_v6.14.3         2270.3              2334  2229 1000000 440,470 msgs/sec
1.0.0_node_v6.14.3                 2297.2              2426  2223 1000000 435,318 msgs/sec  ```

[roytan883]

I think this issue is not about bench performance test.
Its about normal scenario sending two publish together, which lead latency.

Please check our issue here, 3 person test it with different platform, all result that Linux very slow.

I think the buffer of socket is right, but it wait few time (30~40ms) if sending data is too small. In our scenario, we async await the last publish and response finish, that why it is slow. But if you test it in bench performance scenario, the socket buffer fast fill in, so performance will be slightly better.

we also find why redis don't have this problem, its defaultOptions.noDelay: true
https://github.com/luin/ioredis/blob/622975d9d454eca6a9c495d35f5638d68e2662f2/lib/redis.js#L162
https://github.com/luin/ioredis/blob/622975d9d454eca6a9c495d35f5638d68e2662f2/lib/redis.js#L310

[aricart]

The main issue is the number of system calls. The internal buffering takes care of that. The test should be simple:

• Subscribe to an event. The handler records the time.
• The 'connect' handler marks the start time and publishes an event.

The difference between the receive time and the start time is the latency, The way it is implemented, the first message will trigger the writing to the socket on the next event loop if the buffer is not full. Otherwise, the socket is written immediately. If publishing many events in a loop, the least number of system calls is used yielding greater throughput.

"use strict";

var fs = require('fs');
var NATS = require('nats');
var nc = NATS.connect();

var start;
nc.subscribe('foo', () => {
	var end = process.hrtime();
	var s = end[0] - start[0];
	var ns = end[1] - start[1];

	console.log(s*1000000 + ns/1000  + " µs");
	
	nc.close();
});

nc.on('connect', () => {
	start = process.hrtime();
	nc.publish("foo");
});

On the little node where I ran the tests, this yields:

~$ node lat_perf.js 
1253.901 µs