New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Hyper slowness issue #11203
Comments
After updating Rust with: rustup update
rustup toolchain install nightly-x86_64-pc-windows-msvc
rustup override set nightly-x86_64-pc-windows-msvc a |
Reproduces for me as well on Linux. |
Added some debug info's to this. I see that in
this explains the "slowness" of handling hyper transfers. Experimentally, if I change step 5 to call This seem to be y hyper internal synchronization issue that make IO result not available though they have been processed internally. Only when calling the hyper poll function again, the result is returned. |
Hope someone (you?) is working on a fix. I'm clueless about such internal details. |
@gvanem you are right. I wanted to document my observations to drag the hyper project in. I think this is a bug on their behalf, but if the insist everything is fine, we'll make a workaround in curl. |
Opened hyperium/hyper#3237 |
We also have #10803 as known bug now. It is a memory-leak with hyper as a backend. |
- refs curl#11203 where hyper was reported as being slow - fixes hyper_executor_poll to loop until it is out of tasks as advised by @seanmonstar in hyperium/hyper#3237 - added a fix in hyper io handling for detecting EAGAIN - added some debug logs to see IO results - pytest http/1.1 test cases pass - pytest h2 test cases fail on connection reuse. HTTP/2 connection reuse does not seem to work. Hyper submits a request on a reused connection, curl's IO works and thereafter hyper declares `Hyper: [1] operation was canceled: connection closed` on stderr without any error being logged before.
On advisement of @seanmonstar I made some small changes that resolve the slowness for me. Pr in #11344. I see our http/1.1 test cases work, h2 has issues with connection reuse. |
Does not fix it for @gvanem apparently |
- refs curl#11203 where hyper was reported as being slow - fixes hyper_executor_poll to loop until it is out of tasks as advised by @seanmonstar in hyperium/hyper#3237 - added a fix in hyper io handling for detecting EAGAIN - added some debug logs to see IO results - pytest http/1.1 test cases pass - pytest h2 test cases fail on connection reuse. HTTP/2 connection reuse does not seem to work. Hyper submits a request on a reused connection, curl's IO works and thereafter hyper declares `Hyper: [1] operation was canceled: connection closed` on stderr without any error being logged before. Fixes curl#11203 Reported-by: Gisle Vanem Advised-by: Sean McArthur Closes curl#11344
I can replicate the slowness on Linux. I used this script:
With normal curl it takes 1-2 seconds to complete. With curl+hyper it takes about a minute; the first result comes immediately, then there is a pause of about 30 seconds before the second result, then another pause of about 30 seconds before the third result. |
With everything up-to-date,
Besides the response of first URL got dropped in some cases! |
Some notes from my investigations: The first response arrives quickly. After that, logging shows that I grepped for 30 and found that the The 1 second delay comes from a
Questions:
|
When the 30 second hang occurs, curl wants to send off the (second) request over the connection. But due to hyper's asynch API and behavior (combined with some bug in curl obviously) curl does not know it is still sending the request but it has already moved on to the (Presumably the socket gets readable after 30 seconds anyway for some reason and that triggers the send to get sent.) This is can be seen by |
My adjusted reproduce script with tracing + time stamps #! /bin/sh
./src/curl --trace-ascii - --trace-time -K - <<EOF | tee dump
url=https://api.adsb.lol/api/0/route/SAS4133
url=https://api.adsb.lol/api/0/route/BBD6810
url=https://api.adsb.lol/api/0/route/THY19Y
EOF |
Vanilla curl is using http/1.1 while curl+hyper is using h2. Is that significant? |
Also, the 30 second thing might be due to an SSL timeout, which trigger a new connection? |
My vanilla build uses h2 for this. But no, that does not matter.
No, the trace shows no new connection. And a curl will not silently do a new connection if a transfer fails in the middle, it would return an error. |
There's also an issue with Hyper + GnuTls as the backend and possibly
|
@gvanem can you inspect/dump the values of that assertion failure? |
Adding a
|
hmm, a 64bit -1 as unsigned. but the var
|
Don't ask, but it seems some Rust code inside Hyper caused a panic. |
We have looked into this issue and have found the potential problem. I can reproduce the issue with hyper + Rustls / OpenSSL and various endpoints. Some appeared to be somewhat fast and some slow (> 60 seconds). For example: # this takes > 60 seconds
curl https://api.adsb.lol/api/0/route/SAS4133 https://api.adsb.lol/api/0/route/BBD6810 https://api.adsb.lol/api/0/route/THY19Y
# this takes 300 ms
curl --http1.1 https://api.adsb.lol/api/0/route/SAS4133 https://api.adsb.lol/api/0/route/BBD6810 https://api.adsb.lol/api/0/route/THY19Y
# this takes around 4 seconds
curl https://github.com/curl/curl/issues/11203 https://github.com/curl/curl/issues/10803 https://github.com/curl/curl/pull/11729 So the problem appears to only occur with HTTP2 and some servers cause a delay of 30 seconds for the 2nd and 3rd request. I have confirmed this by testing several of different endpoints. Inspecting the HTTP2 traffic with wireshark (and a SSLKEYLOGFILE) I noticed that curl with the default backend sends over:
Curl with hyper sends over:
All web servers I tested cannot handle the second / third HTTP2 connection preface / Settings / window update (i think this is called a "handshake" in The hyper API is constructed in such a way that this "handshake" is performed every time a new hyper client is constructed. So my first plan to fix this was reusing the hyper client in Would you see any problems in reusing the executor / client for multiple requests? |
At least from hyper's point of view, they are meant to be reusable. |
No. The easy handles are already encouraged to be reused in the public libcurl API. If we can reuse more parts within it, we should. |
I have looked into persisting the |
The hypertransfer struct itself persists between requests since it is a member of the
Note that this handle is the handle for a transfer, but not for data that associated with the connections. They are in the |
is
Yes, but somehow the executor gets cleared and we can't figure out why. This patch
diff --git a/lib/c-hyper.c b/lib/c-hyper.c
index 61ca29a3a..d72c2c575 100644
--- a/lib/c-hyper.c
+++ b/lib/c-hyper.c
@@ -912,8 +912,11 @@ CURLcode Curl_http(struct Curl_easy *data, bool *done)
the rest of the request in the PERFORM phase. */
*done = TRUE;
+ infof(data, "-------------------------> the hyptransfer pointer is %p", h);
+ infof(data, "-------------------------> the executor pointer is %p", h->exec);
+
infof(data, "Time for the Hyper dance");
- memset(h, 0, sizeof(struct hyptransfer));
+ // memset(h, 0, sizeof(struct hyptransfer));
result = Curl_http_host(data, conn);
if(result)
@@ -1261,8 +1264,8 @@ void Curl_hyper_done(struct Curl_easy *data)
{
struct hyptransfer *h = &data->hyp;
if(h->exec) {
- hyper_executor_free(h->exec);
- h->exec = NULL;
+ // hyper_executor_free(h->exec);
+ // h->exec = NULL;
}
if(h->read_waker) {
hyper_waker_free(h->read_waker); we see this output
so |
The executor is independent of the connection, right? Then I think the Curl_easy sounds like exactly the right place for it to be.
I can find two places where curl does it:
|
those are the obvious places, but
so just a simple grep does not answer the question of why that field is reset. So I tried some fancier debugging by watching the memory address of the executor in the hyptransfer struct (so
So far it kind of makes sense. The line number seems to be off-by-one though, the actual write happens a line earlier. So now if this field were persisted, we'd expect no further changes to it until all requests have completed, right? Well that is not what I see
we hit this place several more times
So that just looks like
So, the But we never see |
Right now, yes, as I said before
It is a sub-struct of |
- refs curl#11203 where hyper was reported as being slow - fixes hyper_executor_poll to loop until it is out of tasks as advised by @seanmonstar in hyperium/hyper#3237 - added a fix in hyper io handling for detecting EAGAIN - added some debug logs to see IO results - pytest http/1.1 test cases pass - pytest h2 test cases fail on connection reuse. HTTP/2 connection reuse does not seem to work. Hyper submits a request on a reused connection, curl's IO works and thereafter hyper declares `Hyper: [1] operation was canceled: connection closed` on stderr without any error being logged before. Fixes curl#11203 Reported-by: Gisle Vanem Advised-by: Sean McArthur Closes curl#11344
@bagder thanks a lot for your help! I was able to persist the hyper client between requests by making it part of the However I encountered a potential issue in the hyper C API:
A minimal way of reproducing this issue is by not-freeing the hyper client and trying to perform a HTTP/2 request with curl: diff --git a/lib/c-hyper.c b/lib/c-hyper.c
index c558955c9..c85fb5569 100644
--- a/lib/c-hyper.c
+++ b/lib/c-hyper.c
@@ -1218,8 +1218,8 @@ CURLcode Curl_http(struct Curl_easy *data, bool *done)
}
sendtask = NULL; /* ownership passed on */
- hyper_clientconn_free(client);
- client = NULL;
+ /* hyper_clientconn_free(client);
+ client = NULL; */
if((httpreq == HTTPREQ_GET) || (httpreq == HTTPREQ_HEAD)) {
/* HTTP GET/HEAD download */ @seanmonstar do you have any idea why the request is not sent if we do not free the client? |
I'm not sure I follow this. What struct did you move? hyper does not manage connections for libcurl, so I fail to see how that is important here. We setup all the necessary configs per request in
That sounds like a hyper bug to me. At least based on the rust API docs for |
If that's really the case, that would be a hyper bug. I can't think of anything in hyper that would need to wait until it was freed to send. |
I did this
Trying to transfer 3 URLs like:
to get Airplane flight-information (in series or parallel), causes curl to hang for a really long time between each URL.
But only when built with
-DUSE_HYPER
!? Entering the URLs either from a config-file or set on the command-line doesn't matter.A simple
get-urls.bat
file to reproduce:Running the above
.bat
file takes at least 1 minute to complete! With--parallel
or not.I expected the following
The transfer to complete in < 1 sec. as the
curl.exe
bundled with Win-10 does:Adding the
--parallel
option I'd assume the URLs would be issued in parallel. Doesn't look so to me.Version info:
I'm on Windows-10, 22H2 (OS-build 19045.2965).
The text was updated successfully, but these errors were encountered: