skip to Main Content

While testing a simple node server (written with Hapi.js):

'use strict';

var Hapi = require("hapi");
var count = 0;

const server = Hapi.server({
    port: 3000,
    host: 'localhost'
});

server.route({
    method: 'GET',
    path: '/test',
    handler: (request, h) => {
        count ++;
        console.log(count);
        return count;
    }
});

const init = async () => {
    await server.start();
};

process.on('unhandledRejection', (err) => {
    process.exit(1);
});

init();

start the server:

node ./server.js

run the Apache ab tool:

/usr/bin/ab -n 200 -c 30 localhost:3000/test

Env details:

OS: CentOS release 6.9
Node: v10.14.1
Hapi.js: 17.8.1

I found unexpected results in case of multiple concurrent requests (-c 30): the request handler function has been called more times than the number of requests to be performed (-n 200).

Ab output example:

Benchmarking localhost (be patient)

Server Software:
Server Hostname:        localhost
Server Port:            3000

Document Path:          /test
Document Length:        29 bytes

Concurrency Level:      30
Time taken for tests:   0.137 seconds
Complete requests:      200
Failed requests:        0
Write errors:           0
Total transferred:      36081 bytes
HTML transferred:       6119 bytes
Requests per second:    1459.44 [#/sec] (mean)
Time per request:       20.556 [ms] (mean)
Time per request:       0.685 [ms] (mean, across all concurrent requests)
Transfer rate:          257.12 [Kbytes/sec] received

Connection Times (ms)
              min  mean[+/-sd] median   max
Connect:        0    0   0.1      0       0
Processing:    15   17   1.5     16      20
Waiting:        2    9   3.9      9      18
Total:         15   17   1.5     16      21

Percentage of the requests served within a certain time (ms)
  50%     16
  66%     16
  75%     17
  80%     18
  90%     20
  95%     20
  98%     21
  99%     21
 100%     21 (longest request)

And the node server print out 211 log lines. During various tests the mismatch is variable but always present:

-n 1000 -c 1 -> 1000 log
-n 1000 -c 2 -> ~1000 logs
-n 1000 -c 10 -> ~1001 logs
-n 1000 -c 70 -> ~1008 logs
-n 1000 -c 1000 -> ~1020 logs

It seems that as concurrency increases, the mismatch increases.

I couldn’t figure out whether the ab tool performs more http requests or the node server responds more times than necessary.

Could you please help?

2

Answers


  1. Chosen as BEST ANSWER

    Using the Fiddler proxy I found that AB tool runs more times than the number of requests to be performed (example: -n 200).

    By running a series of consecutive tests:

    # 11 consecutive times
    /usr/bin/ab -n 200 -c 30 -X localhost:8888 http://localhost:3000/test
    

    Both the proxy and the node server report a total of 2209 requests. It looks like that AB is less imprecise with the proxy in the middle, but still imprecise.

    In general, and more important, I never found mismatches between the requests passed through the proxy and the requests received by the node server.

    Thanks!


  2. Its very strange and I don’t get the same results as you on my machine. I would be very surprised if it was ab that was issuing different numbers of actual requests.

    Things i would try:

    • Write a simple server using express rather than hapi. If the issue still occurs you at least know its not a problem with hapi.
    • Intercept the network calls using fiddler
      • ab -X localhost:8888 -n 100 -c 30 http://127.0.0.1:3000/test will use the fiddler proxy which will then let you see the actual calls across the network interface. more details
    • wireshark if you need more power and your feeling brave (I’d only use it if fiddler has let you down)

    If after all these you are still finding an issue then it has been narrowed down to an issue with node, I’m not sure what else it could be. Try using node 8 rather than 10.

    Login or Signup to reply.
Please signup or login to give your own answer.
Back To Top
Search