Measuring time on node.js http requests

I was wondering if we can measure the time it takes for an http request to be completed using node.js. Modifying slightly an example from the documentation (here), one can easily write down the following code.

var http = require('http');
var stamp1 = new Date();
var stamp2, stamp3, stamp4;
var options = {
  hostname: 'www.google.com',
  port: 80,
  path: '/upload',
  method: 'POST'
};

var req = http.request(options, function(res) {
  stamp3 = new Date();
  console.log('STATUS: ' + res.statusCode);
  console.log('HEADERS: ' + JSON.stringify(res.headers));
  res.setEncoding('utf8');
  res.on('data', function (chunk) {
    console.log('BODY: ' + chunk);
  });
  res.on('end', function () {
    stamp4 = new Date();
    console.log ("Stamp 3: " + stamp3);
    console.log ("Stamp 4: " + stamp4);
  });
});
req.on('error', function(e) {
  console.log('problem with request: ' + e.message);
});

// write data to request body
req.write('data\n');
req.write('data\n');
req.end();

stamp2 = new Date();
console.log ("Stamp 1: " + stamp1);
console.log ("Stamp 2: " + stamp2);

Now let me come to my point. On the response one can easily measure the time it takes for the response, since in the beginning stamp3 is set and on end stamp 4 is set. So, in principle for relatively large amounts of data these two timestamps will be different.

However, the question that I have is whether stamps 1 and 2 actually measure what is happening when the request is being prepared and dispatched. In other words, is req.write(....) a synchronous operation? Based on node.js principles I would expect req.write(...) to be an asynchronous operation where one can pass an arbitrarily large document and then upon successful completion we can have a callback knowing that the request has finished.

Comments?

Two function already exist for that:

  • console.time(id), start the timer
  • console.timeEnd(id) end the timer, print id followed by the time in ms

So in your case:

var req = http.request(options, function(res) {
    console.time('Requete: '); //Begin to count the time
    stamp3 = new Date();
    console.log('STATUS: ' + res.statusCode);
    console.log('HEADERS: ' + JSON.stringify(res.headers));
    res.setEncoding('utf8');
    res.on('data', function (chunk) {
        console.log('BODY: ' + chunk);
    });
    res.on('end', function () {
        stamp4 = new Date();
        console.log ("Stamp 3: " + stamp3);
        console.log ("Stamp 4: " + stamp4);
        console.timeEnd('Requete: '); //Will print "Requete: X" with X being the time in ms
    });
});

The docs mention no callback, so I'm assuming req.write as well as res.end to be synchronous.

So in your case if you're referring to just that one request that you're initializing, I think the time measurement should be accurate. I don't expect the time difference to be very big though (perhaps even in the same milisecond).