curl-library
Large POST requests get stuck when sent with HTTP/2 (works with HTTP 1.1)
Date: Thu, 18 Apr 2019 09:19:48 -0700
Hi,
I've compiled libcurl with HTTP/2 support (openssl, nghttp2) for my project.
curl 7.56.1 (although I had the same issue with the latest, I backed
out to that one due to unrelated issue with gzip encoding in the
latest)
nghttp2 v1.37.0
openssl 1.1.0
I've compiled and run the same app on MacOSX and Android (x64), with
the same results.
I have a problem where my POST requests (which send ~8M chunks of
data per request) get stuck and timeout but only if I enable HTTP/2
(forced via CURL_HTTP_VERSION_2TLS), seemingly when another (GET)
requests is executed on the same multi handle.
Smaller POST requests go through with HTTP/2 fine (my theory is
because they aren't as likely to overlap with the GET requests).
The same exact code works fine with no issues if I force HTTP 1.1
(via curl_easy_setopt(handle, CURLOPT_HTTP_VERSION,
CURL_HTTP_VERSION_1_1))
I was able to upload the same data with command line curl that I
happened to have on my system (curl 7.54.0 (x86_64-apple-darwin18.0)
libcurl/7.54.0 LibreSSL/2.6.4 zlib/1.2.11 nghttp2/1.24.1) with HTTP/2
enabled with no issues, but it doesn't exactly match my use case since
I'm executing multiple requests in parallel in my application, which
leads me to believe that there's either something I'm not doing right
with my implementation or there's some issue with the library with
multiple parallel requests being executed. But it's at least an
indication that the server is probably fine.
I'm also able to upload to the same server with HTTP/2 using
NSURLSession (native MacOSX API), with the same app level code (our
networking layer is abstracted away).
Here's a log from a successful upload with curl command line tool
(hostname etc redacted):
* TCP_NODELAY set
* Connected to xxx (xxxx) port 443 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* Cipher selection: ALL:!EXPORT:!EXPORT40:!EXPORT56:!aNULL:!LOW:!RC4:@STRENGTH
* successfully set certificate verify locations:
* CAfile: /etc/ssl/cert.pem
CApath: none
* TLSv1.2 (OUT), TLS handshake, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Server hello (2):
* TLSv1.2 (IN), TLS handshake, Certificate (11):
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
* TLSv1.2 (IN), TLS handshake, Server finished (14):
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
* TLSv1.2 (OUT), TLS change cipher, Client hello (1):
* TLSv1.2 (OUT), TLS handshake, Finished (20):
* TLSv1.2 (IN), TLS change cipher, Client hello (1):
* TLSv1.2 (IN), TLS handshake, Finished (20):
* SSL connection using TLSv1.2 / ECDHE-RSA-AES128-GCM-SHA256
* ALPN, server accepted to use h2
* Server certificate:
* subject: OU=Domain Control Validated; OU=EssentialSSL; CN=xxxx
* start date: Sep 28 00:00:00 2018 GMT
* expire date: Sep 28 23:59:59 2019 GMT
* subjectAltName: host "xxxx" matched cert's "xxxx"
* issuer: C=GB; ST=Greater Manchester; L=Salford; O=COMODO CA
Limited; CN=COMODO RSA Domain Validation Secure Server CA
* SSL certificate verify ok.
* Using HTTP2, server supports multi-use
* Connection state changed (HTTP/2 confirmed)
* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
* Using Stream ID: 1 (easy handle 0x7fc96380b600)
> POST /v9/batch HTTP/2
> Host: www.flashbackapp.com
> Accept: */*
> Authorization: bearer - redacted
> Accept-Encoding: application/msgpack
> Content-Type: application/msgpack
> Content-Length: 7578390
>
* Connection state changed (MAX_CONCURRENT_STREAMS updated)!
* We are completely uploaded and fine
< HTTP/2 202
< server: nginx/1.15.5
< date: Wed, 17 Apr 2019 22:38:35 GMT
< content-length: 0
< content-security-policy: default-src 'self'; script-src 'none';
style-src 'unsafe-inline'
< referrer-policy: strict-origin-when-cross-origin
< strict-transport-security: max-age=15724800; includeSubDomains
< x-content-security-policy: default-src 'self'; script-src 'none';
style-src 'unsafe-inline'
< x-content-type-options: nosniff
< x-frame-options: sameorigin
< x-webkit-csp: default-src 'self'; script-src 'none'; style-src 'unsafe-inline'
< x-xss-protection: 1; mode=block
<
* Connection #0 to host xxx left intact
Attached is a log from the debug trace callback from my app (there
are two simultaneous POSTS with occasional GETs), there you can see
that the connection is eventually dropped by the server (but if I set
CURLOPT_TIMEOUT to say 30 seconds it'd be dropped by the client due to
lack of network activity):
> 2019-04-17 23:46:17 | I | 5603015 | CRC | CurlHttpRequestContext.cpp:324 | OnTraceCallback | [0x7f84df801800] Info: HTTP/2 stream 31 was not closed cleanly: PROTOCOL_ERROR (err 1)
Here [0x7f84df801800] is the POST easy curl handle. You can see that
the last time it sent any data was exactly 1 minute before that (the 1
min timeout here is likely enforced by the server):
> 2019-04-17 23:45:17 | I | 5603015 | CRC | CurlHttpRequestContext.cpp:349 | OnTraceCallback | [0x7f84df801800] => Send data, 0000000000 bytes (0x00000000)
And after that it's only SSL chatter on that handle.
With app level logging I can see that CURLOPT_READFUNCTION callback
gets invoked up until the point where another GET request happens, and
then I see no callbacks anymore, and the connection eventually times
out or is closed by the server.
I've exhausted my options trying to figure it out. The only reliable
correlation I found is with the other parallel GET request: if I delay
it, the upload will proceed farther.
I don't think it's a server issue because as I mentioned, I was able
to upload a single file with curl tool without issues.
I'd appreciate any help or ideas on how to debug this further.
Some additional data sniffed with Charles proxy for requests made by
my app in case it's useful:
Client Settings SETTINGS_HEADER_TABLE_SIZE = 4096 SETTINGS_ENABLE_PUSH
= 0 SETTINGS_MAX_CONCURRENT_STREAMS = 100 SETTINGS_INITIAL_WINDOW_SIZE
= 1073741824 SETTINGS_MAX_FRAME_SIZE = 16384
SETTINGS_MAX_HEADER_LIST_SIZE = unlimited
Server Settings SETTINGS_HEADER_TABLE_SIZE = 4096 SETTINGS_ENABLE_PUSH
= 1 SETTINGS_MAX_CONCURRENT_STREAMS = 128 SETTINGS_INITIAL_WINDOW_SIZE
= 65536 SETTINGS_MAX_FRAME_SIZE = 16777215
SETTINGS_MAX_HEADER_LIST_SIZE = unlimited
ALPN h2
Client Supported [h2, http/1.1]
Server Chosen h2
Charles Supported [h2, http/1.1]
-------------------------------------------------------------------
Unsubscribe: https://cool.haxx.se/list/listinfo/curl-library
Etiquette: https://curl.haxx.se/mail/etiquette.html
- application/zip attachment: trace.log.zip