Skip to content
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

http2, refused stream handling for retry #12054

Closed
wants to merge 1 commit into from

Conversation

icing
Copy link
Contributor

@icing icing commented Oct 7, 2023

- answer HTTP/2 streams refused via a GOAWAY from the server to
  respond with CURLE_RECV_ERROR in order to trigger a retry
  on another connection
- refs curl#11859
@calvin2021y
Copy link

calvin2021y commented Oct 7, 2023

Thanks for this fix.

Can you take a look at this #12050

libcurl with multi http3 handle, after timeout error, the follow request repeat timeout error until max idle age expired. (or use new CURLM create request)

seems the new timeout error keep "max idle age" not expired, so if there is new request one by one, you will always get timeout error and no chance create new connection.

@icing icing requested a review from bagder October 7, 2023 19:13
@lukepalmer
Copy link

Thanks for the change! I gave this a try. Throughout I have used an nginx setting of "keepalive_requests 3;" which is unrealistic but helps exercise the problem.

First, good news: this change makes requests of size 5 succeed 100% of the time for me.

Bad news: There is another problem with larger requests. When I increase to 20 requests (not 19 or lower) I get an error that says:

curl: (56) Connection died, tried 5 times before giving up

In a larger trial of 10,000 requests only about 1/3rd succeed with 2/3rds of the request failing with the above error. Note unrealistic nginx settings here.

I really do not like this next part but I triple checked that it's accurate. If I invoke curl with traces turned on like this:
curl --parallel -v --trace-config ids,time,http/2
The problem almost entirely vanishes. In runs of 10,000 requests only about 5 will fail.

Here is a trace, sorry it's so large but it has to be.

trace.txt.gz

@jay
Copy link
Member

jay commented Oct 7, 2023

curl: (56) Connection died, tried 5 times before giving up

curl/lib/transfer.c

Lines 1810 to 1816 in 6fa1d81

#define CONN_MAX_RETRIES 5
if(data->state.retrycount++ >= CONN_MAX_RETRIES) {
failf(data, "Connection died, tried %d times before giving up",
CONN_MAX_RETRIES);
data->state.retrycount = 0;
return CURLE_SEND_ERROR;
}

I might be missing something but isn't it doing what is expected. Here's the first section with that error, filtered for [1426-512]

18:20:32.189615 [1426-512] * [HTTP/2] [11] data done send
18:20:32.189635 [1426-512] { [5 bytes data]
18:20:32.189661 [1426-512] * [HTTP/2] [0] ingress: read 17 bytes
18:20:32.189678 [1426-512] * [HTTP/2] [0] <- FRAME[GOAWAY, error=0, reason='', last_stream=5]
18:20:32.189693 [1426-512] * received GOAWAY, error=0, last_stream=5
18:20:32.189709 [1426-512] * [HTTP/2] [11] RESET: REFUSED_STREAM (err 7)
18:20:32.189725 [1426-512] * [HTTP/2] [11] DRAIN dselect_bits=1
18:20:32.189805 [1426-512] { [5 bytes data]
18:20:32.189829 [1426-512] * [HTTP/2] [0] ingress: read 381 bytes
18:20:32.189978 [1426-512] * [HTTP/2] [1] <- FRAME[HEADERS, len=124, hend=1, eos=0]
18:20:32.190020 [1426-512] * [HTTP/2] [1] <- FRAME[DATA, len=239, eos=1, padlen=0]
18:20:32.190069 [1426-512] { [5 bytes data]
18:20:32.190095 [1426-512] * [HTTP/2] [0] ingress: read 381 bytes
18:20:32.190248 [1426-512] * [HTTP/2] [3] <- FRAME[HEADERS, len=124, hend=1, eos=0]
18:20:32.190280 [1426-512] * [HTTP/2] [3] <- FRAME[DATA, len=239, eos=1, padlen=0]
18:20:32.190329 [1426-512] * [HTTP/2] [11] returning CLOSE
18:20:32.190344 [1426-512] * [HTTP/2] [11] REFUSED_STREAM, try again on a new connection
18:20:32.190360 [1426-512] * [HTTP/2] [11] stream_recv(len=102400) -> -1, 56
18:20:32.190376 [1426-512] * [HTTP/2] [11] cf_recv(len=102400) -> -1 56, buffered=0, window=-1/-1, connection 1048575522/1048576000
18:20:32.190397 [1426-512] * Connection died, tried 5 times before giving up

@calvin2021y
Copy link

I get more than 100 of thousands error 55 GOAWAY report every day from firebase, hope this get totally fixed soon.

@black-desk
Copy link

I wrote an example here: https://github.com/black-desk/curl-11859

This example works very fine with this PR.

@calvin2021y
Copy link

I wrote an example here: https://github.com/black-desk/curl-11859

This example works very fine with this PR.

I am not sure this test case suit for this problem. easy handle should create one after one to trigger it . (not create all easy handle at once)

Is this test case verify the problem with 8.3.0 ?

@bagder
Copy link
Member

bagder commented Oct 8, 2023

I am not sure this test case suit for this problem. easy handle should create one after one to trigger it . (not create all easy handle at once)

The problem is identified to be a GOAWAY on the connection or connections libcurl wants to use, it seems unrelated to how many easy handles that are used.

@bagder
Copy link
Member

bagder commented Oct 8, 2023

Since this PR fixes the immediate initial problem it is now merged. There might be more to do, but lets deal with that in follow-up PRs.

@black-desk
Copy link

I wrote an example here: https://github.com/black-desk/curl-11859

This example works very fine with this PR.

I am not sure this test case suit for this problem. easy handle should create one after one to trigger it . (not create all easy handle at once)

Is this test case verify the problem with 8.3.0 ?

This test failed with 8.3.0.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Development

Successfully merging this pull request may close these issues.

None yet

6 participants