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. |
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. |
@marlonbaeten I think I found the source of the "request never sends" problem you found: hyperium/hyper#3369. I also filed a PR that fixes it: hyperium/hyper#3370. Please let us know if that fixes it for you! For this slowness bug it seems there are two problems:
@marlonbaeten it sounds like you're moving in the right direction with persisting the |
@jsha nice work! I think your summary is correct. Together with @folkertdev I have tried several approaches in persisting both the
I hope to try out your fix for hyper this week. Good luck! [1] #11203 (comment) |
I think the libcurl story is easy enough but I can't tell much about hyper and how we are supposed to work with it since the API is undocumented unless you can do the rust-to-C translation in your head. And it seems very few can. |
I've dug into this a little and feel like I made good progress, but I believe I'm running into an issue of conflicting lifecycles. If you want to view my branch-in-progress, very non-working, it's here: https://github.com/curl/curl/compare/master...jsha:curl:fix-hyper?expand=1 Here's the lifecycle issue. @bagder and @seanmonstar please correct me if I'm wrong about these assumptions. Hyper has read and write callbacks. These get bundled into a Also bundled into the Right now Curl sets the Really, I think the But that runs into a problem. The Lines 145 to 158 in 31d96af
In other words, to do a read or write, we need to pass a valid Is there any object we can set as the |
Great research @jsha In curl a single connection might have many concurrent transfers (when multiplexed) so a connection cannot itself identify a single transfer - each connection has a list transfers. Also, every ongoing transfer has a single current connection it uses (at a time). An individual connection is used by none, one or many transfers.
Right. Because the connection can be used by up to several hundred concurrent transfers... |
There are other places in curl with the same use pattern/problem. Callbacks in OpenSSL, nghttp2 and quiche. The solution there, all of those being connection filters, is to either:
Moving hyper from a http "protocol handler" replacement to a connection filter is not a small task. But it might be the better design. |
Great, thanks for the confirmation @bagder. And thanks for pointing a way forward @icing. I think for the short term, we should disable HTTP/2 support in the Hyper integration, because it's broken (sends the connection preface on every request) and requires a rearchitecture to fix, which might take some time. The other alternative would be to have the HTTP/2 support send only a single request per connection. But it seems better to fall back to HTTP/1.1 where connections can be reused. |
I've posted #12191 with the quick / temporary fix of disabling HTTP2 with Hyper. |
I've posted hyperium/hyper#3424 adding documentation for Hyper's FFI API. @bagder @icing would one of you be willing to add more detail to the connection filter docs and/or cfilters.h? I looked at docs/CONNECTION-FILTERS.md and I don't understand how the connection filter API handles multiplexing of multiple requests on a single connection. Also, the docs suggest that HTTP/2 might be a connection filter, which seems to be presently the case, so maybe it needs some updating? Thanks! |
@jsha After getting the latest Hyper + curl from The API at ADSB-LOL has changed into a new JSON-format. So with this .bat-file: @echo off
setlocal
set CURL_SSL_BACKEND=schannel
set URLS= https://vrs-standing-data.adsb.lol/routes/SA/SAS4133.json ^
https://vrs-standing-data.adsb.lol/routes/BB/BBD6810.json ^
https://vrs-standing-data.adsb.lol/routes/TH/THY19Y.json
echo Using 'c:\Windows\system32\curl.exe':
timer
c:\Windows\system32\curl.exe -s %URLS% > NUL
timer
echo.
echo Using 'curl -- tip of git master':
timer
%~dp0\src\curl -s %URLS% > NUL
timer The timings are:
Much better; not >1 minute as before. |
@gvanem thanks for verifying that things got faster. I'm not very surprised that the Hyper backend is still slightly slower than the nghttp2 (default) backend, because the hyper backend is now using HTTP/1.1. I'm guessing that curl serializes the requests when using HTTP/1.1 and parallelizes them when using HTTP/2. I think the solution will be as @icing said: to rewrite the Hyper backend as a connection filter so we can restore HTTP/2 support with the Hyper backend and have it work properly. |
Has this been done? Just rebuilt everything and now it's only 20% slower than the Win-10 bundled curl:
|
This is mentioned in |
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: