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.

Sign up for GitHub

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

Jump to bottom

http3 ngtcp2: QUIC connection left intact after Operation timed out #12064

Closed
calvin2021y opened this issue Oct 8, 2023 · 11 comments
Closed

http3 ngtcp2: QUIC connection left intact after Operation timed out #12064

calvin2021y opened this issue Oct 8, 2023 · 11 comments
Assignees
@icing
Labels
HTTP/3 h3 or quic related

Comments

@calvin2021y
Copy link

I did this

build libcurl with master branch and openssl-3.0.10+quic, lastest ngtcp2 and nghttp3 release.

set CURLOPT_MAXAGE_CONN more than 110, with multi interface.

with step:

  1. send request to https://1.1.1.1 with http3 protocol, get 200 response.

  2. wait 110 secends

  3. send request to https://1.1.1.1 with http3 protocol again with same multi handle , get timeout error

  4. wait 1~ 10 secends

  5. send request to https://1.1.1.1 with http3 protocol again with same multi handle , get timeout error

repeat 4, 5 will keep get timeout error.

there is the trace logs:

*   Trying 1.1.1.1:443...
* QUIC cipher selection: TLS_AES_128_GCM_SHA256:TLS_AES_256_GCM_SHA384:TLS_CHACHA20_POLY1305_SHA256:TLS_AES_128_CCM_SHA256
*  subjectAltName: host "1.1.1.1" matched cert's IP address!
* Verified certificate just fine
* Connected to 1.1.1.1 (1.1.1.1) port 443
* using HTTP/3
* [HTTP/3] [0] OPENED stream for https://1.1.1.1/
* [HTTP/3] [0] [:method: GET]
* [HTTP/3] [0] [:scheme: https]
* [HTTP/3] [0] [:authority: 1.1.1.1]
* [HTTP/3] [0] [:path: /]
* [HTTP/3] [0] [accept: */*]
* [HTTP/3] [0] [user-agent: curl/8.3.0]
> GET / HTTP/3
Host: 1.1.1.1
Accept: */*
User-Agent: curl/8.3.0

< HTTP/3 200 
< date: Sun, 08 Oct 2023 15:15:08 GMT
< content-type: text/html
< report-to: {"endpoints":[{"url":"https:\/\/a.nel.cloudflare.com\/report\/v3?s=dJkPRYeedFYxg%2B%2FLhPQwNqz8QX2WcEnECCVIwKTGahkSIF0uR%2FimwiBuCzRrKQEwrQge2f8rz%2F5nfsdc9rb2JLlKx6%2BWDHosS8FsksBclFdstpgMnKCvseU%3D"}],"group":"cf-nel","max_age":604800}
< nel: {"report_to":"cf-nel","max_age":604800}
< last-modified: Fri, 21 Jul 2023 21:11:33 GMT
< strict-transport-security: max-age=31536000
< served-in-seconds: 0.003
< cache-control: public, max-age=14400
< cf-cache-status: HIT
< age: 86
< expires: Sun, 08 Oct 2023 19:15:08 GMT
< accept-ranges: bytes
< set-cookie: __cf_bm=vkUo3U81K2ATeD475_RTtYw1qI8pctpCVkUNW.1Lwtk-1696778108-0-AV659yNcP8Iww20X2dCfmihU25a7ZPvzK4bF4CYXrOk4twIo7m38EQWR2JLN+g1d9iPwIwz3ft/CSuOXrhS+DbM=; path=/; expires=Sun, 08-Oct-23 15:45:08 GMT; domain=.every1dns.com; HttpOnly; Secure; SameSite=None
< server: cloudflare
< cf-ray: 812f566bcf49125e-DXB
< alt-svc: h3=":443"; ma=86400
< 
* Connection #0 to host 1.1.1.1 left intact









* Found bundle for host: 0x600001148600 [can multiplex]
* Re-using existing connection with host 1.1.1.1
* [HTTP/3] [4] OPENED stream for https://1.1.1.1/
* [HTTP/3] [4] [:method: GET]
* [HTTP/3] [4] [:scheme: https]
* [HTTP/3] [4] [:authority: 1.1.1.1]
* [HTTP/3] [4] [:path: /]
* [HTTP/3] [4] [accept: */*]
* [HTTP/3] [4] [user-agent: curl/8.3.0]
> GET / HTTP/3
Host: 1.1.1.1
Accept: */*
User-Agent: curl/8.3.0

* Operation timed out after 7001 milliseconds with 0 bytes received
* Connection #0 to host 1.1.1.1 left intact


* Found bundle for host: 0x600001148600 [can multiplex]
* Re-using existing connection with host 1.1.1.1
* [HTTP/3] [8] OPENED stream for https://1.1.1.1/
* [HTTP/3] [8] [:method: GET]
* [HTTP/3] [8] [:scheme: https]
* [HTTP/3] [8] [:authority: 1.1.1.1]
* [HTTP/3] [8] [:path: /]
* [HTTP/3] [8] [accept: */*]
* [HTTP/3] [8] [user-agent: curl/8.3.0]
> GET / HTTP/3
Host: 1.1.1.1
Accept: */*
User-Agent: curl/8.3.0







* Operation timed out after 7000 milliseconds with 0 bytes received
* Connection #0 to host 1.1.1.1 left intact






* Found bundle for host: 0x600001148600 [can multiplex]
* Re-using existing connection with host 1.1.1.1
* [HTTP/3] [12] OPENED stream for https://1.1.1.1/
* [HTTP/3] [12] [:method: GET]
* [HTTP/3] [12] [:scheme: https]
* [HTTP/3] [12] [:authority: 1.1.1.1]
* [HTTP/3] [12] [:path: /]
* [HTTP/3] [12] [accept: */*]
* [HTTP/3] [12] [user-agent: curl/8.3.0]
> GET / HTTP/3
Host: 1.1.1.1
Accept: */*
User-Agent: curl/8.3.0

* Operation timed out after 7001 milliseconds with 0 bytes received
* Connection #0 to host 1.1.1.1 left intact

I expected the following

I expected after timeout error, recreate new connection for other request.

curl/libcurl version

test with 8.3.0 and master branch.

operating system

not matter
@bagder bagder added the HTTP/3 h3 or quic related label Oct 8, 2023
@bagder
Copy link
Member

bagder commented Oct 8, 2023

  • Operation timed out after 7001 milliseconds with 0 bytes received
  • Connection #0 to host 1.1.1.1 left intact

Yeah, that seems... wrong?

@bagder
Copy link
Member

bagder commented Oct 8, 2023

Or maybe not. The connection does not need to get closed due a timeout, as the streams are independent over QUIC.

@calvin2021y
Copy link
Author

The request keep get timeout, in the mean time if you do a new curl http3 request with new process you will get 200 response.

@bagder
Copy link
Member

bagder commented Oct 8, 2023

The request keep get timeout, in the mean time if you do a new curl http3 request with new process you will get 200 response.

Sure, but that doesn't explain where the problem is. Why does it get a timeout? Did the connection get closed?

@calvin2021y
Copy link
Author

calvin2021y commented Oct 8, 2023 •
edited

I guess wait 110 secends cause the connect closed. (by router of client side or cloudflare server)

if change wait time and CURLOPT_MAXAGE_CONN into 70, it will work fine.

@bagder
Copy link
Member

bagder commented Oct 8, 2023 •
edited

I guess

Right, we are just guessing so far.

@calvin2021y
Copy link
Author

The client side libcurl is not closed it, the outside close it but libcurl can't realize the connection is closed.

the connection is closed, but it keep left intact status if you are try use it. ( Although the server did not return any data during this period )

@bagder
Copy link
Member

bagder commented Oct 8, 2023

The client side libcurl is not closed it, the outside close it but libcurl can't realize the connection is closed.

Do you have a packet trace showing this or is this what you assume is happening?

@calvin2021y
Copy link
Author

calvin2021y commented Oct 8, 2023 •
edited

http3.csv

This is the wireshark packet record, confirm my guess.

send 2nd request at 110s, 3nd request at 117s. zero packet response from 1.1.1.1 and get timeout error from curl.

@bagder
Copy link
Member

bagder commented Oct 9, 2023

Thanks, yes it makes total sense. But due to QUIC etc we probably need to do a rethink how to fix this best.

@bagder
Copy link
Member

bagder commented Oct 10, 2023

Reproducer test case: issue-12064.c

If the URL is instead changed to https://curl.se, it instead detects that the connection is closed when the second request is sent off. It might indicate a difference is how the QUIC connection is shutdown.

icing added a commit to icing/curl that referenced this issue Oct 10, 2023
@icing
QUIC, manage connection idle timeouts
f4b8fd2 
- configure a 120s idle timeout on our side of the connection
- track the timestamp when actual socket IO happens
- check IO timestamp to our *and* the peer's idle timeouts
  in "is this connection alive" checks
- refs curl#12064
@icing icing mentioned this issue Oct 10, 2023
Closed
@bagder bagder closed this as completed in 9cc5787 Oct 13, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@icing icing

Labels
HTTP/3 h3 or quic related
Milestone
No milestone
Development

No branches or pull requests
3 participants
@icing @bagder @calvin2021y