How to get response time of each proxy-request done by node-http-proxy?

Question

i want to compute the response-time for each proxy-request, done by node-http-proxy, like this:

var httpProxy = require('http-proxy');
var proxy = httpProxy.createProxyServer();

require('http').createServer(function(req, res) {
   // start-time for one request
   proxy.web(req, res, { target: 'localhost:80' });
}).listen(3000);

proxy.on('proxyRes', function (res) {
  // end-time for one request to calculate the time
  console.log('RAW Response from the target', JSON.stringify(res.headers, true, 2));
});

so i want to get the time-difference between the start-time and the ent-time. i am be able to catch the proxyRes event, but how to match the proxy-response to the right client-request?

update: i tried the following:

var httpProxy = require('http-proxy');
var http = require('http');

var proxy = new httpProxy.createProxyServer({
    target: {
        host: 'localhost',
        port: 80
    }
});

var start_time = 0;
var proxyServer = http.createServer(function (req, res) {


    start_time = new Date().getTime();

    proxy.web(req, res);

    res.on('finish', function() {
        console.log("The request was proxied in " + (new Date().getTime() - start_time) + "ms");
    });
});

proxyServer.listen(3000);

// Proxy-Target server
var n = 0; sleep = 0;
http.createServer(function (req, res) {

    n++;

    var start_time = new Date().getTime();

    res.writeHead(200, {'Content-Type': 'text/plain'});

    if (n % 2 == 0){
        sleep = 2000;
    } else {
        sleep = 5000;
    }

    setTimeout(function(){
        res.end("...");
    }, sleep);

    res.on('finish', function(d) {
        var diff_time = new Date().getTime() - start_time;
        console.log("The request was processed in " + (new Date().getTime() - start_time) + "ms");
    });

}).listen(80);

so, the time of the target-server is measured correctly, cause one request could last either 2 oder 5 seconds, but the proxy measures sometimes response-times of only some milli-seconds. I tried it by using apache-bench like: ab -n 10 -c 3 http://localhost:3000/ and the result of the console:

The request was processed in 2007ms
The request was proxied in 2017ms
The request was processed in 2003ms
The request was proxied in 2006ms
The request was processed in 5002ms
The request was processed in 5001ms
The request was proxied in 980ms
The request was proxied in 981ms
The request was processed in 2002ms
The request was proxied in 2006ms
The request was processed in 2002ms
The request was proxied in 2005ms
The request was processed in 5000ms
The request was proxied in 8ms
The request was processed in 5000ms
The request was proxied in 982ms
The request was processed in 2001ms
The request was proxied in 2005ms
The request was processed in 5002ms
The request was proxied in 4998ms

Could you just use `new Date().getTime()` and log the difference? — brandonscript, Jan 23 '14 at 17:48
i dont think so, because the proxy works asynchronous, so i have to match on proxy-request to its related response. and therefore i have to identify one request in some way. — chris, Jan 23 '14 at 18:05
The script runs asynchronously, but the proxy doesn't look like it does. You should be able to put both in the callback (after response is received) and measure it that way. — brandonscript, Jan 23 '14 at 18:10
could you give me little bit more about your idea? and i am not sure, but i think the `proxy.web()` function is asynchronous, eventually there are emitted events like `proxyRes` to listen for. and for my understanding, only async. functions are emitting events, or am i wrong? — chris, Jan 23 '14 at 18:35

score 4 · Accepted Answer · answered Jan 25 '14 at 19:42

now it works, got the key hint on the nodejs google-gloup, the cope of start_time was not set locally, so here is the working code:

var httpProxy = require('http-proxy');
var http = require('http');

var proxy = new httpProxy.createProxyServer({});

// before: var start_time = 0;
var proxyServer = http.createServer(function (req, res) {

    // now
    var start_time = new Date().getTime();

    proxy.web(req, res, { target: 'http://localhost:80' });

    res.on('finish', function() {
       console.log("The request was proxied in " + (new Date().getTime() - start_time) + "ms");
    });
});
proxyServer.listen(3000);

score 1 · Answer 2 · answered Jan 23 '14 at 18:38

1

(untested, but let's see if this works)

var httpProxy = require('http-proxy');
var proxy = httpProxy.createProxyServer();
var startTime = 0;
var endTime = 0;

require('http').createServer(function(req, res) {
   // start-time for one request
   startTime = new Date().getTime();
   proxy.web(req, res, { 
        target: 'localhost:80' 
   });
}).listen(3000);

proxy.on('proxyRes', function (res) {
  // end-time for one request to calculate the time
  endTime = new Date().getTime();
  console.log(endTime - startTime);
  console.log('RAW Response from the target', JSON.stringify(res.headers, true, 2));
});

answered Jan 23 '14 at 18:38

brandonscript

68,675
32
163
220

thanks so far, but with this code, every new client-connection results in setting `startTime` to the current time. so when one early reqest lasts longer to process than a later one, the startTime for the first request is not correct anymore. i tried it by adding `console.out("startTime");` before `proxy.web()` and `console.out("endTime");` inside `proxy.on(...);` the output-order had to be the same at any time, but it wasnt, so the proxy is working async. – chris Jan 23 '14 at 19:00

How to get response time of each proxy-request done by node-http-proxy?

2 Answers2