TCP resets on high concurrency tests

[acasademont]

While trying to debug php-pm/php-pm#456 I noticed that during high concurrency tests (-c 100) some of the TCP streams where reset and failed. I ended up testing the simplest reactphp http server to reproduce it and compare it with the simplest nodejs server. For the tests, I used the libuv event loop, but it also happens with the StreamSelect loop.

reactphp

<?php

include __DIR__.'/vendor/autoload.php';

$loop = React\EventLoop\Factory::create();

$server = new React\Http\Server(function (Psr\Http\Message\ServerRequestInterface $request) {
    return new React\Http\Response(
        200,
        array('Content-Type' => 'text/plain'),
        "Hello World!\n"
    );
});

$socket = new React\Socket\Server(8080, $loop);
$server->listen($socket);

echo "Server running at http://127.0.0.1:8080\n";

$loop->run();

nodejs

const http = require('http')

const requestHandler = (request, response) => {
  response.end('Hello World!')
}

const server = http.createServer(requestHandler)

server.listen(8080, (err) => {
  if (err) {
    return console.log('something bad happened', err)
  }

  console.log('Server running at http://127.0.0.1:8080')
})

Benchmarked using https://github.com/rakyll/hey, but the resets also occur using ab

hey -n 100 -c 100 http://127.0.0.1:8080/

reactphp

Summary:
  Total:	0.2094 secs
  Slowest:	0.2055 secs
  Fastest:	0.0207 secs
  Average:	0.0767 secs
  Requests/sec:	477.4997

  Total data:	988 bytes
  Size/request:	13 bytes

Response time histogram:
  0.021 [1]	|■
  0.039 [32]	|■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
  0.058 [0]	|
  0.076 [0]	|
  0.095 [0]	|
  0.113 [37]	|■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
  0.132 [2]	|■■
  0.150 [0]	|
  0.169 [0]	|
  0.187 [0]	|
  0.205 [4]	|■■■■


Latency distribution:
  10% in 0.0227 secs
  25% in 0.0239 secs
  50% in 0.1051 secs
  75% in 0.1099 secs
  90% in 0.1122 secs
  95% in 0.2047 secs
  0% in 0.0000 secs

Details (average, fastest, slowest):
  DNS+dialup:	0.0637 secs, 0.0207 secs, 0.2055 secs
  DNS-lookup:	0.0000 secs, 0.0000 secs, 0.0000 secs
  req write:	0.0002 secs, 0.0000 secs, 0.0006 secs
  resp wait:	0.0127 secs, 0.0004 secs, 0.0252 secs
  resp read:	0.0000 secs, 0.0000 secs, 0.0002 secs

Status code distribution:
  [200]	76 responses

Error distribution:
  [17]	Get http://127.0.0.1:8080/: dial tcp 127.0.0.1:8080: connect: connection reset by peer
  [1]	Get http://127.0.0.1:8080/: read tcp 127.0.0.1:57270->127.0.0.1:8080: read: connection reset by peer
  [1]	Get http://127.0.0.1:8080/: read tcp 127.0.0.1:57303->127.0.0.1:8080: read: connection reset by peer
  [1]	Get http://127.0.0.1:8080/: read tcp 127.0.0.1:57307->127.0.0.1:8080: read: connection reset by peer
  [1]	Get http://127.0.0.1:8080/: read tcp 127.0.0.1:57308->127.0.0.1:8080: read: connection reset by peer
  [1]	Get http://127.0.0.1:8080/: read tcp 127.0.0.1:57309->127.0.0.1:8080: read: connection reset by peer
  [1]	Get http://127.0.0.1:8080/: read tcp 127.0.0.1:57323->127.0.0.1:8080: read: connection reset by peer
  [1]	Get http://127.0.0.1:8080/: read tcp 127.0.0.1:57325->127.0.0.1:8080: read: connection reset by peer

nodejs

Summary:
  Total:	0.0574 secs
  Slowest:	0.0393 secs
  Fastest:	0.0176 secs
  Average:	0.0303 secs
  Requests/sec:	1740.8161

  Total data:	1200 bytes
  Size/request:	12 bytes

Response time histogram:
  0.018 [1]	|■
  0.020 [3]	|■■■■
  0.022 [0]	|
  0.024 [6]	|■■■■■■■■
  0.026 [19]	|■■■■■■■■■■■■■■■■■■■■■■■■■
  0.028 [29]	|■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■
  0.031 [1]	|■
  0.033 [2]	|■■■
  0.035 [2]	|■■■
  0.037 [6]	|■■■■■■■■
  0.039 [31]	|■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■■


Latency distribution:
  10% in 0.0244 secs
  25% in 0.0257 secs
  50% in 0.0276 secs
  75% in 0.0376 secs
  90% in 0.0381 secs
  95% in 0.0384 secs
  99% in 0.0393 secs

Details (average, fastest, slowest):
  DNS+dialup:	0.0032 secs, 0.0176 secs, 0.0393 secs
  DNS-lookup:	0.0000 secs, 0.0000 secs, 0.0000 secs
  req write:	0.0001 secs, 0.0000 secs, 0.0033 secs
  resp wait:	0.0262 secs, 0.0076 secs, 0.0389 secs
  resp read:	0.0001 secs, 0.0000 secs, 0.0013 secs

Status code distribution:
  [200]	100 responses

Not sure what could be the culprit here, is this a php streams issue? Or is reactphp somehow inadvertently causing those TCP resets?

Here are the TCP dumps

tcpdump.zip

PS: Besides the TCP resets, the reactphp histogram is also pretty weird, with some requests being very fast, but others being considerably slower. nodejs performance is much more consistent

[clue]

When it comes to socket parameters, ReactPHP inherits all default settings from PHP and does not explicitly provide any other values. Depending on your workload / application, you may want to override certain defaults. In particular, PHP defaults to a socket backlog of 32 outstanding connections.

If you want to test high concurrency, you should explicitly increase this value like this:

$socket = new \React\Socket\Server('0.0.0.0:8080', $loop, array('backlog' => 128));

See also #311 (comment)

I hope this helps 👍

[acasademont]

Thanks @clue, much appreciated! Is this default something we should care about (or explicitly set) or document?

[clue]

@acasademont I agree the documentation isn't perfect, what do you have in mind? 👍

Most (if not all) application would want to apply a higher backlog limit anyway, for instance nodejs appears to apply a default of 511 as per https://nodejs.org/api/net.html#net_server_listen.

As a quick solution for your particular problem, you should manually specify the backlog option to match your specific requirements.

I'm not opposed to applying a new default in the future, but I think this is something best discussed in react/socket. This also implies this will affect all socket servers, so more input is definitely needed before making this change.

[acasademont]

I'd say a saner default would be -1, much like PHP-FPM does? In theory that should pick up the system SOMAXCONN value. I don't really know where that 32 comes from, feels like a very low value (and even worse for php-pm, where we're actually pooling slaves).

[acasademont]

Oh well, seems like FPM is also defaulting to 511, why that same weird number as node?

https://github.com/php/php-src/blob/master/sapi/fpm/fpm/fpm_sockets.h#L17

[clue]

Good luck with figuring out a good default that works across all supported platforms :-)

I'm not aware of any PHP documentation that covers the default backlog of 32, but here's a link to the underlying source code:
https://github.com/php/php-src/blob/5d6e923d46a89fe9cd8fb6c3a6da675aa67197b4/main/streams/transports.c#L159-L163

@acasademont 511 is not only used in Node.js and PHP-FPM, but also in Nginx, Apache, Redis, etc... I'd say 511 was determined to be a safe limit on most OSes (except FreeBSD where it's -1). The backlog limit default in PHP was committed 5 years ago by an user, I don't think there was much discussion about it (the limit default itself) before or after adding a backlog stream context option?

[clue]

@CharlotteDunois It's indeed interesting how this used to be hardcoded to 5 prior to adding the backlog context option for PHP 5.3.3: php/php-src@5b277c4

I agree that a higher default makes more sense for event-driven applications built on top of ReactPHP. 👍

[andig]

I'd suggest to go with the 511 then and not introduce another config option.

[acasademont]

@andig let's do it, going to work on a PR for that and continue from that :)