Concurrent calls to setTimeout cause more delays than expected

Question

I'm working on a small demo of Node performance and was surprised to see the following example with 50 concurrent calls to setTimeout take over 4 seconds instead of 500ms.

The following code sets up a very simple express server that listens for all requests, and responds 500ms later using setTimeout. Then it has a client that makes 50 requests passing in a number to track requests and corresponding responses.

// SERVER
var express = require('express');
var app = express();

app.get('*', function (req, res) {
    setTimeout(function () {
        return res.send(req.query.i);
    }, 500);
});

app.listen(8099);

// CLIENT
var http = require('http');

function start() {
    for (var i = 0; i < 50; i++) {
        console.log(new Date().getSeconds() + ':' + new Date().getMilliseconds() + ' - Sending ' + i);
        http.get('http://localhost:8099?i=' + i, responseHandler);
    }

    function responseHandler(res) {
        res.on('data', function (body) {
            return console.log(new Date().getSeconds() + ':' + new Date().getMilliseconds() + ' - Received ' + body);
        });
    }
}

start();

I expected the code to take 30-50ms to make all the setTimeout calls and then 500ms later all of them would respond around the same time. Instead I see them respond in groups of 5, with 500ms between each group of 5.

I tried a number of simpler alternatives which all do fix the problem. If I take the setTimeout out and immediately respond, all 50 responses come in within 100ms. If I take the web server out of the equation and just have 50 calls to setTimeout, then all 50 calls are queued immediately and all 50 come back at the same time 500ms later.

What could be causing the extra delays when express and http calls are combined with setTimeout?

You are experiencing those delays [because of the event queue](http://stackoverflow.com/questions/19822668/what-exactly-is-a-node-js-event-loop-tick). — Alex W, Jul 12 '14 at 15:51
I can confirm these findings. Alex, that's not a helpful comment: *everything* asynchronous is related to the event queue. Saying this is "because of the event queue" is like saying "it's because of programming". Meaningless. My suspicion is that the timer functions in Node have some kind of "meta queueing". That is, in the timer queue, Node takes the next five available timers and schedules those for processing. Not sure, though...looking at the Node source code now. — Ethan Brown, Jul 12 '14 at 17:08
I take back what I said: I don't think it's a limitation of `setTimeout` (because, as Samuel said in his post, if you run this test without HTTP requests, it works as expected). So this must be an HTTP/Express queue issue. — Ethan Brown, Jul 12 '14 at 17:22

Ethan Brown · Accepted Answer · 2014-07-12T18:39:49.760

1

The issue has nothing to do with setTimeout (as you might have guessed when you ran your test without the client/server setup). The issue is the number of open HTTP sockets that a Node http server will handle at any given time.

The setting that controls this is Agent.maxSockets (see the documentation for more information).

The default value for maxSockets is five. So if you send 50 requests to your app, it will process 5 of them at a time until they complete before moving on to new requests. Since they can't complete until the setTimeout functions invoke their callbacks, you'll get your requests responded to in bursts of five approximately every 500 milliseconds.

If you want proof of this, all you have to do is change the value of maxSockets:

http.globalAgent.maxSockets = 10;

Now you will see requests get processed in bursts of 10 instead. If you set it to 50, you should see the behavior you're looking for.

Note that it's probably set to 5 for a pretty good reason, so I don't think the "solution" to your problem is just set maxSockets to Infinity or something terrifying like that.

mscdex points out in the comments that you can specify a cusotm agent in http.request, and also that there are going to be changes to the default maxSockets in Node v0.12.

edited Jul 12 '14 at 18:39

answered Jul 12 '14 at 17:33

Ethan Brown

26,892
4
80
92

A couple of notes: it should be made clearer that you can create a new/custom Agent instance that has its own `maxSockets` that you can pass to `http.request()` instead of mutating the default/global Agent's `maxSockets`. Also, the default/global Agent `maxSockets` is not going to be restricted (to 5) anymore with node v0.12. – mscdex Jul 12 '14 at 18:22
Thanks for the info, mscdex. I'll update my answer. – Ethan Brown Jul 12 '14 at 18:37
Perfect. That fixed it. For my test I set it to 50. I understand the need for max sockets but 5 is very small, especially if you have an I/O intensive app where the majority of time is waiting on a lot of I/O or outside processes. – Samuel Neff Jul 12 '14 at 18:43
You can always use cluster, too, to spin up multiple instances. – Ethan Brown Jul 12 '14 at 18:50

Concurrent calls to setTimeout cause more delays than expected

1 Answers1