Skip to content
This repository has been archived by the owner on Apr 22, 2023. It is now read-only.

Significant performance regression in http in v0.10.32+ #8940

Closed
mscdex opened this issue Dec 24, 2014 · 9 comments
Closed

Significant performance regression in http in v0.10.32+ #8940

mscdex opened this issue Dec 24, 2014 · 9 comments
Labels
Milestone

Comments

@mscdex
Copy link

mscdex commented Dec 24, 2014

I just noticed a slowdown since 1fddc1f (v0.10.32+). Before this commit, I was getting ~14-15k req/s with my custom http server, after this commit I get ~1.2k req/s. I tested with v0.11.14 and the slowdown does not exist there.

My performance test consists merely of:

var http = require('http');
var body = new Buffer('Hello World');
http.createServer(function(req, res) {
  res.writeHead(200); // or: `res.statusCode = 200;`
  res.end(body); // change this to `res.end();` to see the expected speed post-1fddc1fee8
}).listen(3333);

I am using wrk to hit this server like so:

wrk 'http://localhost:3333/' -d 3 -c 50 -t 4 | grep 'Requests/sec' | awk '{ print "  " $2 }'
@mscdex
Copy link
Author

mscdex commented Dec 24, 2014

Shouldn't this._hasBody on this line be negated if the we're bypassing the hot code path for HEAD requests?

@CGavrila
Copy link

CGavrila commented Jan 6, 2015

I tested with Apache Bench (ab -n 100000 -c 1000 http://localhost:3333/)

v0.10.31
Requests per second:    7727.95 [#/sec] (mean)
v0.10.33
Requests per second:    7456.91 [#/sec] (mean)
v0.10.35
Requests per second:    7761.27 [#/sec] (mean)
v0.11.14
Requests per second:    7488.35 [#/sec] (mean)

I have to say that I've never worked with wrk. However, -d 3 -c 50 -t 4 seems like you're running it too short.

Could you try it for a longer period ?

@mscdex
Copy link
Author

mscdex commented Jan 6, 2015

The length of time has no bearing on speed (or at least it shouldn't). Anyway, I tried durations of 3, 10, 30, etc. for the fun of it and it's still approximately the same dismal performance.

@CGavrila
Copy link

CGavrila commented Jan 6, 2015

Indeed, normally it shouldn't have much impact, but I wanted to get it out of the way.

Could you try with Apache Bench as well ? On Ubuntu it should be sudo apt-get install -y apache2 to install and then ab -n 100000 -c 1000 http://localhost:3333/ for example. Shouldn't take more than 2 minutes.

@arch1t3ct
Copy link

He is not alone. I had the same issue on production with up to 20k qps. Did some profiling to see what's wrong and it seems that response just slows down. In my case: from 1ms to 30ms. Tried different versions of node and the last one that is not affected is v0.10.31. I think it is related to 1fddc1f

Also note, that my system is using keep alive and chunked content. This is kind of a serious issue with such a huge performance impact. Strange, that no one noticed. Maybe there's a specific way of using http server for this to occur? Stripped down version of my http server:

http.Server(function (request, response) {
    response.writeHead(status, headers);
    response.end(body);
}).listen(port, host);

@mscdex
Copy link
Author

mscdex commented Jan 8, 2015

@CGavrila So far I'm only able to reproduce it with wrk. ab isn't a good test for this issue I think because it only does http 1.0 and also only does keep-alive for non-chunked responses. To trigger the slow path introduced by 1fddc1f, (as far as I can tell) there needs to be both keep-alive and chunked responses.

@trevnorris
Copy link

I can't say for sure that the issue is Node's fault, but wrk has a strange quirk that causes massive slow down. As you can see from the ab benchmark (and it would be faster if -k was included) there is no slowdown.

/cc @tjfontaine

@misterdjules misterdjules added this to the 0.10.37 milestone Mar 3, 2015
@misterdjules
Copy link

@joyent/node-coreteam Added to the 0.10.37 milestone as it seems to be a significant performance issue for which we seem to have a good candidate fix.

misterdjules pushed a commit to misterdjules/node that referenced this issue Mar 4, 2015
A significant performance regressions has been introduced in 1fddc1f for
GET requests which send data through response.end(). The number of
requests per second dropped to somewhere around 6% of their previous
level. (nodejs#8940)

The fix consists of removing a part of the lines added by 1fddc1f,
lines which were supposed to affect only HEAD requests, but interfered
with GET requests instead.

The lines removed would not have affected the behaviour in the case of
a HEAD request as this._hasBody would always be false. Therefore, they
were not required to fix the issue reported in nodejs#8361.
misterdjules pushed a commit to misterdjules/node that referenced this issue Mar 5, 2015
A significant performance regressions has been introduced in 1fddc1f for
GET requests which send data through response.end(). The number of
requests per second dropped to somewhere around 6% of their previous
level.

The fix consists of removing a part of the lines added by 1fddc1f,
lines which were supposed to affect only HEAD requests, but interfered
with GET requests instead.

The lines removed would not have affected the behaviour in the case of
a HEAD request as this._hasBody would always be false. Therefore, they
were not required to fix the issue reported in nodejs#8361.

Fixes nodejs#8940.

PR: nodejs#9026
PR-URL: nodejs#9026
Reviewed-By: Julien Gilli <julien.gilli@joyent.com>
@misterdjules
Copy link

Fixed by 8bcd0a4, thank you @mscdex, @CGavrila and everyone who helped fix this issue!

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
Projects
None yet
Development

No branches or pull requests

5 participants