Skip to content

connection reuse lead to continuous timout after network changed #17225

Open
@Cering

Description

@Cering

I did this

  • Hello, I found a continuous timout error in my iphone, when its network from wifi change to cellular, the reproduce steps is:
  1. send https request(https://msg.qy.net) in wifi network, it succeed and will keep in the connection pool
2025-04-29 17:41:38.173   STATE: INIT => CONNECT handle 0x12256f008; line 1940 (connection #-5000)
2025-04-29 17:41:38.173   Added connection 8. The cache now contains 5 members
2025-04-29 17:41:38.176   STATE: CONNECT => RESOLVING handle 0x12256f008; line 1986 (connection #8)
2025-04-29 17:41:38.201   STATE: RESOLVING => CONNECTING handle 0x12256f008; line 2060 (connection #8)
2025-04-29 17:41:38.217   Connected to msg.qy.net (111.202.15.31) port 443 (#8)
2025-04-29 17:41:38.217   ALPN: offers h2,http/1.1
2025-04-29 17:41:38.217   [CONN-8] Didn't find Session ID in cache for host HTTPS://msg.qy.net:443
2025-04-29 17:41:38.217   TLSv1.3 (OUT), TLS handshake, Client hello (1):
2025-04-29 17:41:38.289   TLSv1.3 (IN), TLS handshake, Server hello (2):
2025-04-29 17:41:38.290   TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
2025-04-29 17:41:38.290   TLSv1.3 (IN), TLS handshake, Certificate (11):
2025-04-29 17:41:38.290   TLSv1.3 (IN), TLS handshake, CERT verify (15):
2025-04-29 17:41:38.292   TLSv1.3 (IN), TLS handshake, Finished (20):
2025-04-29 17:41:38.292   TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
2025-04-29 17:41:38.292   TLSv1.3 (OUT), TLS handshake, Finished (20):
2025-04-29 17:41:38.292   SSL connection using TLSv1.3 / TLS_AES_256_GCM_SHA384
2025-04-29 17:41:38.292   ALPN: server accepted h2
2025-04-29 17:41:38.292   Server certificate:
2025-04-29 17:41:38.292   using HTTP/2
2025-04-29 17:41:38.292   STATE: CONNECTING => PROTOCONNECT handle 0x12256f008; line 2104 (connection #8)
2025-04-29 17:41:38.292   multi changed, check CONNECT_PEND queue
2025-04-29 17:41:38.292   STATE: PROTOCONNECT => DO handle 0x12256f008; line 2134 (connection #8)
2025-04-29 17:41:38.292   Using Stream ID: 1 (easy handle 0x12256f008)
2025-04-29 17:41:38.293   STATE: DO => DID handle 0x12256f008; line 2230 (connection #8)
2025-04-29 17:41:38.293   STATE: DID => PERFORMING handle 0x12256f008; line 2349 (connection #8)
2025-04-29 17:41:38.339   TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
2025-04-29 17:41:38.339   [CONN-8] Didn't find Session ID in cache for host HTTPS://msg.qy.net:443
2025-04-29 17:41:38.339   [CONN-8] Added Session ID to cache for HTTPS://msg.qy.net:443 [server]
2025-04-29 17:41:38.339   TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
2025-04-29 17:41:38.339   [CONN-8] Found Session ID in cache for host HTTPS://msg.qy.net:443
2025-04-29 17:41:38.339   old SSL session ID is stale, removing
2025-04-29 17:41:38.339   [CONN-8] Added Session ID to cache for HTTPS://msg.qy.net:443 [server]
2025-04-29 17:41:38.340   HTTP/2 found, allow multiplexing
2025-04-29 17:41:38.380   multi changed, check CONNECT_PEND queue
2025-04-29 17:41:38.380   Curl_readwrite: forcibly told to drain data
2025-04-29 17:41:38.380   STATE: PERFORMING => DONE handle 0x12256f008; line 2548 (connection #8)
2025-04-29 17:41:38.380   multi_done: status: 0 prem: 0 done: 0
2025-04-29 17:41:38.380   Connection #8 to host msg.qy.net left intact
2025-04-29 17:41:38.380   Expire cleared (transfer 0x12256f008)
  1. send another same request in wifi network, the connection is reused(multiplexing) and still ok
2025-04-29 17:41:40.492   STATE: INIT => CONNECT handle 0x155790808; line 1940 (connection #-5000)
2025-04-29 17:41:40.492   Found bundle for host: 0x302439888 [can multiplex]
2025-04-29 17:41:40.492   Re-using existing connection #8 with host msg.qy.net
2025-04-29 17:41:40.493   STATE: CONNECT => CONNECTING handle 0x155790808; line 1996 (connection #8)
2025-04-29 17:41:40.493   STATE: CONNECTING => PROTOCONNECT handle 0x155790808; line 2104 (connection #8)
2025-04-29 17:41:40.493   STATE: PROTOCONNECT => DO handle 0x155790808; line 2123 (connection #8)
2025-04-29 17:41:40.493   Using Stream ID: 3 (easy handle 0x155790808)
2025-04-29 17:41:40.493   STATE: DO => DID handle 0x155790808; line 2230 (connection #8)
2025-04-29 17:41:40.493   STATE: DID => PERFORMING handle 0x155790808; line 2349 (connection #8)
2025-04-29 17:41:40.493   We are completely uploaded and fine
2025-04-29 17:41:40.511   HTTP/2 found, allow multiplexing
2025-04-29 17:41:40.511   Curl_readwrite: forcibly told to drain data
2025-04-29 17:41:40.511   STATE: PERFORMING => DONE handle 0x155790808; line 2548 (connection #8)
2025-04-29 17:41:40.511   multi_done: status: 0 prem: 0 done: 0
2025-04-29 17:41:40.511   Connection #8 to host msg.qy.net left intact
2025-04-29 17:41:40.512   Expire cleared (transfer 0x155790808)
  1. in 2025-04-29 17:42:39.423, I close the phone's wifi netowrk and swith to use cellular network.
    Send same request again, and found that it still try to reuse(multiplexing) the invalid connection which was built in wifi network, and get a timeout error(28).
    Moreover,if I keep retry this request(the interval is less than timeout), it will always get a timeout error after change to cellulat network. It seems that curl prefer to try Re-using existing connection #8 with host msg.qy.net, and this invalid connection can not be deleted because of Connection still in use 3, no more multi_done now!
2025-04-29 17:42:40.177    STATE: INIT => CONNECT handle 0x168056808; line 1940 (connection #-5000)
2025-04-29 17:42:40.177    Found bundle for host: 0x302439888 [can multiplex]
2025-04-29 17:42:40.177    Multiplexed connection found
2025-04-29 17:42:40.177    Re-using existing connection #8 with host msg.qy.net
2025-04-29 17:42:40.177    STATE: CONNECT => PROTOCONNECT handle 0x168056808; line 1994 (connection #8)
2025-04-29 17:42:40.177    STATE: PROTOCONNECT => DO handle 0x168056808; line 2123 (connection #8)
2025-04-29 17:42:40.177    Using Stream ID: 129 (easy handle 0x168056808)
2025-04-29 17:42:40.177    STATE: DO => DID handle 0x168056808; line 2230 (connection #8)
2025-04-29 17:42:40.177    STATE: DID => PERFORMING handle 0x168056808; line 2349 (connection #8)
2025-04-29 17:42:40.177    We are completely uploaded and fine
2025-04-29 17:42:43.204    Operation timed out after 3027 milliseconds with 0 bytes received
2025-04-29 17:42:43.204    multi_done: status: 28 prem: 1 done: 0
2025-04-29 17:42:43.204    Connection still in use 3, no more multi_done now!
2025-04-29 17:42:43.204    Expire cleared (transfer 0x168056808)

I expected the following

  • if change to http request, it will also try reuse connection in pool, and get timeout after change network. But without multiplex, the connection will be closed after timeout error, like below, and next retry request will create a new connection from cellular network and then succeed
2025-04-29 17:42:46.075    Operation timed out after 6000 milliseconds with 0 bytes received
2025-04-29 17:42:46.076    multi_done: status: 28 prem: 1 done: 0
2025-04-29 17:42:46.076    multi_done, not re-using connection=53, forbid=0, close=1, premature=1, conn_multiplex=0
2025-04-29 17:42:46.076    The cache now contains 9 members
2025-04-29 17:42:46.076    Curl_disconnect(conn #53, dead=1)
2025-04-29 17:42:46.076    Closing connection 53
2025-04-29 17:42:46.076    Expire cleared (transfer 0x167fb1808)
  • Although set a CURLOPT_FRESH_CONNECT option for the https request after network changed, it will force to create a new connection and succeed. But is there a graceful method to adapt the network changing scene? Thanks

curl/libcurl version

libcurl/8.0.1 OpenSSL/1.1.1w zlib/1.2.12 nghttp2/1.41.0

operating system

iphone

Metadata

Metadata

Assignees

No one assigned

    Type

    No type

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions