Pistache very poor performance when POST size exceeds Endpoint::options().maxRequestSize(), and maxRequestSize is large.
#1190
Comments
|
Good find @dennisjenkins75. Try the following:
|
|
Still has same poor behavior. I then recompiled my entire project from scratch, ran my normal unit tests (pass), enabled the test that attempts to POST 128 MiB when my app has I'll work on a stand alone minimal repro server demo, that can be triggered with |
|
My gut instinct tells me this probably something to do with inefficient |
|
Well nuts. I wrote a stand-alone repro, and it does not reproduce the issue. However, an edited version of the example "rest_server" does reproduce it. The profile and stack traces point to something inside pistache. #include <pistache/description.h>
#include <pistache/endpoint.h>
#include <pistache/http.h>
using namespace Pistache;
struct RequestHandler : public Http::Handler {
HTTP_PROTOTYPE(RequestHandler)
RequestHandler() {}
void onRequest(const Http::Request& request,
Http::ResponseWriter writer) override {
std::cerr << request.method() << " " << request.resource() << " "
<< request.body().size() << "\n";
writer.send(Http::Code::Ok, "");
}
};
int main(int argc, char *argv[]) {
size_t max_req_size = Const::MaxBuffer;
uint16_t port = 9080;
if (argc > 1) {
max_req_size = strtoul(argv[1], nullptr, 10);
if (argc > 2) {
port = static_cast<uint16_t>(strtoul(argv[2], nullptr, 10));
}
}
std::cout << "MaxRequestSize = " << max_req_size << "\n";
std::cout << "Port = " << port << "\n";
auto opts = Http::Endpoint::options()
.maxRequestSize(max_req_size)
.keepaliveTimeout(std::chrono::seconds(2))
.threads(1)
.flags(Tcp::Options::ReuseAddr);
Http::Endpoint endpoint(Address(Ipv4::any(), Port(port)));
endpoint.init(opts);
endpoint.setHandler(Http::make_handler<RequestHandler>());
endpoint.serve();
return 0;
} $ make && ./output/pistache-demo 41943040 9999
LINK output/pistache-demo
MaxRequestSize = 41943040
Port = 9999
# in another shell
$ dd if=/dev/random of=blob.bin bs=1048576 count=128
$ time curl -v -X POST -H "Content-type: application/octet-stream" -d @blob.bin http://localhost:9999/
...
< HTTP/1.1 413 Request Entity Too Large
< Content-Length: 36
<
* Excess found in a read: excess = 150, size = 36, maxdownload = 36, bytecount = 0
* Closing connection
Request exceeded maximum buffer size
real 0m1.259s
... |
TL;DR
If one creates a pistacheio Endpoint with a large
maxRequestSize(in the MiB range), and then sends a HTTP request with a request body larger than this size, Pistacheio takes a VERY LONG TIME to return HTTP 413 error, and during that time is is burning 100% of a CPU core.I do not have a simple repro to post yet. The following was obtained and tuned via trial and error. My own system has a
maxRequestSizeof 4 MiB, b/c my typical max realistic payload is ~1 MiB. However, one of my data sources generates a legit 66 MiB payload, and my pistacheio server process appeared to hang. Upon further debugging, I determined that its not hung, just acting very insufficiently. The following is my rambling attempt to get to the bottom of the issue.NOTE: This issue does not successfully repro with the default example
rest_serverthat ships with pistachio, because that binary keeps the default 4 KiBmaxRequestSize.Long Version
Under these circumstances this is a potential DOS attack against pistacheio.
I've built pistacheio from source (2023-12-05), and installed it into
/usr/local:In my pistache app, I construct the
Http::Endpoint::options()with.maxRequestSize(4 * 1024 * 1024)(4 MiB).If I attempt to POST (via libcurl) a 6 MiB payload, pistache returns HTTP 413 in just a few seconds. If I increase that payload to 66 MiB, pistache appears to hang for a long time (it will return after many minutes with HTTP 413). While "hung", its stack looks like this:
The amount of time (on my system anyway) that it takes for pistache to "handle" the request and return HTTP 413 is not linear with respect to the size of the request:
ok, so it starts out quadratic of sorts, then asymptotically approaches linear.
Anyway, IMHO, pistache appears to be processing all of the POST data, even though the
maxRequestSizewas set to something much smaller.It would be nice to get a CPU profile of pistacheio while its doing this, but gprof produced an output of all 0% in each child function (I did not debug this yet).
Using
sudo perf top -p ....:Running a strace on my process while its attempting to handle a "too large post request" (in a unit test that I just wrote while debugging this issue), shows that it is ready the socket at 4 kiB each time, instead of the max remaining buffer amount. This is not optimal. Yet the actual pistachio source code shows that it will try to read the entire remaining buffer.
(from src/common/transport.cc, method
Transport::handleIncoming)but
Const::MaxBufferis equal to 4096 and not configurable. So no matter how large we setmaxRequestSize()to, pistache will only ever read 4096 bytes at a time. For small requests this is probably fine, but for a 66 MiB payload, this is 16896 reads, which appear to then be processed one byte at a time?Main Observation
maxRequestSize= 4 MiB, a 3.999 MiB request completes in a fraction of a second. Yet a 40 MiB request takes many minutes. SettingmaxRequestSizeto 80 MiB, the same 40 MiB request completes in only a few seconds. ISTM that once pistache decides that it will reject the request due to it being too large (HTTP 413), that it consumes the payload very inefficiently.Stand alone repro of this issue
I can work on this in a bit.
The text was updated successfully, but these errors were encountered: