HTTP/2 POST reset/timeout after upgrade from 8.0.1 to 8.1.1 #11194

OlekMazur · 2023-05-24T10:26:43Z

After upgrade from 8.0.1 to 8.1.1 libcurl is unable to POST anything to IBM Cloud (OpenWhisk) using HTTP/2.
I reproduced the problem using curl on Fedora. Unfortunately there seems to be no public endpoint to retest it.
I'm not sure if it is a duplicate of #11181.

I did this

curl --verbose --header "Content-Type: text/csv" --data-binary @file --digest --user test:test https://eu-gb.functions.appdomain.cloud/api/v1/<my_secret_api_endpoint>

I expected the following

*   Trying 172.65.198.79:443...
* Connected to eu-gb.functions.appdomain.cloud (172.65.198.79) port 443 (#0)
* ALPN: offers h2,http/1.1
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
*  CAfile: /etc/pki/tls/certs/ca-bundle.crt
*  CApath: none
* TLSv1.3 (IN), TLS handshake, Server hello (2):
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
* TLSv1.3 (IN), TLS handshake, Certificate (11):
* TLSv1.3 (IN), TLS handshake, CERT verify (15):
* TLSv1.3 (IN), TLS handshake, Finished (20):
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.3 (OUT), TLS handshake, Finished (20):
* SSL connection using TLSv1.3 / TLS_AES_256_GCM_SHA384
* ALPN: server accepted h2
* Server certificate:
*  subject: CN=eu-gb.functions.appdomain.cloud
*  start date: May 13 05:16:57 2023 GMT
*  expire date: Aug 11 05:16:56 2023 GMT
*  subjectAltName: host "eu-gb.functions.appdomain.cloud" matched cert's "eu-gb.functions.appdomain.cloud"
*  issuer: C=US; O=Let's Encrypt; CN=R3
*  SSL certificate verify ok.
* using HTTP/2
* Server auth using Digest with user 'test'
* h2h3 [:method: POST]
* h2h3 [:path: /api/v1/<my_secret_api_endpoint>]
* h2h3 [:scheme: https]
* h2h3 [:authority: eu-gb.functions.appdomain.cloud]
* h2h3 [user-agent: curl/8.0.1]
* h2h3 [accept: */*]
* h2h3 [content-type: text/csv]
* h2h3 [content-length: 0]
* Using Stream ID: 1 (easy handle 0x55a287426390)
> POST /api/v1/<my_secret_api_endpoint> HTTP/2
> Host: eu-gb.functions.appdomain.cloud
> user-agent: curl/8.0.1
> accept: */*
> content-type: text/csv
> content-length: 0
> 
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* old SSL session ID is stale, removing
< HTTP/2 401 
< date: Wed, 24 May 2023 01:52:10 GMT
< content-length: 0
< x-request-id: XXX
< access-control-allow-origin: *
< access-control-allow-methods: OPTIONS, GET, DELETE, POST, PUT, HEAD, PATCH
< access-control-allow-headers: Authorization, Origin, X-Requested-With, Content-Type, Accept, User-Agent
< x-openwhisk-activation-id: XXX
< www-authenticate: Digest realm="My secret realm",qop="auth",nonce="XXX",opaque="XXX"
< strict-transport-security: max-age=15724800; includeSubDomains
< ibm_cloud_functions: OpenWhisk
< 
* Connection #0 to host eu-gb.functions.appdomain.cloud left intact
* Issue another request to this URL: 'https://eu-gb.functions.appdomain.cloud/api/v1/<my_secret_api_endpoint>'
* Found bundle for host: 0x55a28741f580 [can multiplex]
* Re-using existing connection #0 with host eu-gb.functions.appdomain.cloud
* Server auth using Digest with user 'test'
* h2h3 [:method: POST]
* h2h3 [:path: /api/v1/<my_secret_api_endpoint>]
* h2h3 [:scheme: https]
* h2h3 [:authority: eu-gb.functions.appdomain.cloud]
* h2h3 [authorization: Digest username="test", realm="My secret realm", nonce="XXX", uri="/api/v1/<my_secret_api_endpoint>", cnonce="XXX", nc=00000001, qop=auth, response="XXX", opaque="XXX"]
* h2h3 [user-agent: curl/8.0.1]
* h2h3 [accept: */*]
* h2h3 [content-type: text/csv]
* h2h3 [content-length: 13]
* Using Stream ID: 3 (easy handle 0x55a287426390)
> POST /api/v1/<my_secret_api_endpoint> HTTP/2
> Host: eu-gb.functions.appdomain.cloud
> authorization: Digest username="test", realm="My secret realm", nonce="XXX", uri="/api/v1/<my_secret_api_endpoint>", cnonce="XXX", nc=00000001, qop=auth, response="XXX", opaque="XXX"
> user-agent: curl/8.0.1
> accept: */*
> content-type: text/csv
> content-length: 13
> 
* We are completely uploaded and fine
< HTTP/2 200 
< date: Wed, 24 May 2023 01:52:10 GMT
< content-type: text/csv; charset=UTF-8
< content-length: 93
< x-request-id: XXX
< access-control-allow-origin: *
< access-control-allow-methods: OPTIONS, GET, DELETE, POST, PUT, HEAD, PATCH
< access-control-allow-headers: Authorization, Origin, X-Requested-With, Content-Type, Accept, User-Agent
< x-openwhisk-activation-id: XXX
< strict-transport-security: max-age=15724800; includeSubDomains
< ibm_cloud_functions: OpenWhisk
< 
some response
* Connection #0 to host eu-gb.functions.appdomain.cloud left intact

This is how it used to work with curl 8.0.1. Now, after upgrade to 8.1.1, I'm always getting an error:

* TLSv1.3 (OUT), TLS handshake, Client hello (1):
* TLSv1.3 (IN), TLS handshake, Server hello (2):
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
* TLSv1.3 (IN), TLS handshake, Certificate (11):
* TLSv1.3 (IN), TLS handshake, CERT verify (15):
* TLSv1.3 (IN), TLS handshake, Finished (20):
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
* TLSv1.3 (OUT), TLS handshake, Finished (20):
> POST /api/v1/<my_secret_api_endpoint> HTTP/2
> Host: eu-gb.functions.appdomain.cloud
> User-Agent: curl/8.1.1
> Accept: */*
> Content-Type: text/csv
> Content-Length: 0
> 
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
* HTTP/2 stream 1 was reset
curl: (56) HTTP/2 stream 1 was reset

curl/libcurl version

Working:
curl 8.0.1 (x86_64-redhat-linux-gnu) libcurl/8.0.1 OpenSSL/3.0.8 zlib/1.2.13 brotli/1.0.9 libidn2/2.3.4 libpsl/0.21.2 (+libidn2/2.3.4) libssh/0.10.5/openssl/zlib nghttp2/1.52.0
Release-Date: 2023-03-20
Protocols: dict file ftp ftps gopher gophers http https imap imaps ldap ldaps mqtt pop3 pop3s rtsp scp sftp smb smbs smtp smtps telnet tftp
Features: alt-svc AsynchDNS brotli GSS-API HSTS HTTP2 HTTPS-proxy IDN IPv6 Kerberos Largefile libz NTLM NTLM_WB PSL SPNEGO SSL threadsafe TLS-SRP UnixSockets

Not working:
curl 8.1.1 (x86_64-pc-linux-gnu) libcurl/8.1.1 OpenSSL/3.0.8 zlib/1.2.13 brotli/1.0.9 zstd/1.5.5 nghttp2/1.52.0
Release-Date: 2023-05-23
Protocols: http https imap imaps smtp smtps
Features: AsynchDNS brotli HTTP2 HTTPS-proxy Largefile libz NTLM SSL threadsafe zstd

./configure --disable-static --enable-shared
--enable-warnings --disable-curldebug --enable-symbol-hiding
--disable-ares --enable-silent-rules --disable-largefile
--enable-versioned-symbols --enable-threaded-resolver
--enable-http --enable-cookies --enable-proxy
--enable-http-auth --enable-crypto-auth
--enable-imap --enable-smtp
--disable-ftp --disable-file --disable-ldap --disable-ldaps
--disable-rtsp --disable-dict
--disable-telnet --disable-tftp --disable-pop3
--disable-gopher --disable-manual
--disable-libcurl-option --disable-ipv6 --disable-unix-sockets
--disable-verbose --disable-sspi
--disable-smb --disable-ntlm-wb --disable-mqtt
--disable-doh --disable-mime
--disable-dateparse --disable-netrc --disable-progress-meter
--disable-dnsshuffle --disable-tls-srp
--disable-hsts --disable-alt-svc
--without-gnutls --with-openssl
--without-libssh2 --without-librtmp \

operating system

Linux 6.2.15-300.fc38.x86_64 #1 SMP PREEMPT_DYNAMIC Thu May 11 17:37:39 UTC 2023 x86_64 GNU/Linux

The text was updated successfully, but these errors were encountered:

icing · 2023-05-24T13:42:50Z

Thanks for your report. As I see it, the output of the failed command was not complete. For example, there is not ALPN negotiated to be seen and other things are missing. Could you include the complete output of an 8.1.1 attempt? Thanks.

Also, in my local testing, digest authentication with POSTs works for me. Since there is no public endpoint, would you be able to build curl yourself with --enable-debug so that we can get more verbose logs of what is going on?

With a debug-enabled curl, once can run:

> CURL_DEBUG=http/2 curl -v args

and get more specifics. Thanks.

OlekMazur · 2023-05-24T15:17:18Z

It was the complete output, unfortunately.

With debug logs it looks like follows:

CURL_DEBUG=http/2 ~/src/curl-8.1.1/src/curl --verbose --header "Content-Type: text/csv" --data-binary @/tmp/test --digest --user test:test https://eu-gb.functions.appdomain.cloud/api/v1/<my_secret_api_endpoint> 2>&1|tee /tmp/curl.txt
} [5 bytes data]
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
} [512 bytes data]
* TLSv1.3 (IN), TLS handshake, Server hello (2):
{ [122 bytes data]
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
{ [19 bytes data]
* TLSv1.3 (IN), TLS handshake, Certificate (11):
{ [4061 bytes data]
* TLSv1.3 (IN), TLS handshake, CERT verify (15):
{ [264 bytes data]
* TLSv1.3 (IN), TLS handshake, Finished (20):
{ [52 bytes data]
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
} [1 bytes data]
* TLSv1.3 (OUT), TLS handshake, Finished (20):
} [52 bytes data]
* [CONN-0-HTTP/2] h2 conn flush 64 bytes
} [5 bytes data]
* [CONN-0-HTTP/2] send request allowed 1 (easy handle 0x9bb948)
* [CONN-0-HTTP/2] [h2sid=1] cf_send(len=184) submit https://eu-gb.functions.appdomain.cloud/api/v1/<my_secret_api_endpoint>
* [CONN-0-HTTP/2] [h2sid=1] submit -> 184, 0
* [CONN-0-HTTP/2] [h2sid=1] req_body_read(len=16384) left=13 -> 0, 81
* [CONN-0-HTTP/2] h2 conn flush 100 bytes
} [5 bytes data]
* [CONN-0-HTTP/2] [h2sid=1] cf_send(len=184) -> 184, 0, buffered=0, upload_left=13, stream-window=65535, connection-window=65535
> POST /api/v1/<my_secret_api_endpoint> HTTP/2
> Host: eu-gb.functions.appdomain.cloud
> User-Agent: curl/8.1.1
> Accept: */*
> Content-Type: text/csv
> Content-Length: 0
> 
* [CONN-0-HTTP/2] stream_recv(len=102400) -> -1, 81
* [CONN-0-HTTP/2] stream_recv(len=102400) -> -1, 81
* [CONN-0-HTTP/2] [h2sid=1] cf_recv(len=102400) -> -1 81, buffered=0, window=0/65535, connection 1048576000/1048576000
* [CONN-0-HTTP/2] [h2sid=1] data done send
* [CONN-0-HTTP/2] stream_recv(len=102400) -> -1, 81
* [CONN-0-HTTP/2] stream_recv(len=102400) -> -1, 81
* [CONN-0-HTTP/2] [h2sid=1] req_body_read(len=16384) left=13 -> 0, 81
* [CONN-0-HTTP/2] [h2sid=1] cf_recv(len=102400) -> -1 81, buffered=0, window=0/65535, connection 1048576000/1048576000
* [CONN-0-HTTP/2] stream_recv(len=102400) -> -1, 81
{ [5 bytes data]
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
{ [57 bytes data]
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
{ [57 bytes data]
* [CONN-0-HTTP/2] FRAME[SETTINGS]
* [CONN-0-HTTP/2] MAX_CONCURRENT_STREAMS == 128
* [CONN-0-HTTP/2] ENABLE_PUSH == TRUE
* [CONN-0-HTTP/2] MAX_CONCURRENT_STREAMS now 128
* [CONN-0-HTTP/2] FRAME[WINDOW_UPDATE]
* [CONN-0-HTTP/2] FRAME[SETTINGS]
* [CONN-0-HTTP/2] MAX_CONCURRENT_STREAMS == 128
* [CONN-0-HTTP/2] ENABLE_PUSH == TRUE
* [CONN-0-HTTP/2] [h2sid=1] FRAME[WINDOW_UPDATE]
* [CONN-0-HTTP/2] stream_recv(len=102400) -> -1, 81
* [CONN-0-HTTP/2] h2 conn flush 9 bytes
} [5 bytes data]
* [CONN-0-HTTP/2] [h2sid=1] cf_recv(len=102400) -> -1 81, buffered=0, window=0/10485760, connection 1048576000/1048576000
* [CONN-0-HTTP/2] stream_recv(len=102400) -> -1, 81
{ [5 bytes data]
* [CONN-0-HTTP/2] [h2sid=1] FRAME[RST]
* [CONN-0-HTTP/2] [h2sid=1] on_stream_close(), PROTOCOL_ERROR (err 1)
* [CONN-0-HTTP/2] [h2sid=1] closed now
* [CONN-0-HTTP/2] [h2sid=1] returning CLOSE
* HTTP/2 stream 1 was reset
* [CONN-0-HTTP/2] stream_recv(len=102400) -> -1, 56
* [CONN-0-HTTP/2] [h2sid=1] cf_recv(len=102400) -> -1 56, buffered=0, window=-1/-1, connection 1048576000/1048576000

curl: (56) HTTP/2 stream 1 was reset

and the content of /tmp/test was just

T;1684939006

- doing a POST with `--digest` does an override on the initial request with `Content-Lenght: 0`, but the http2 filter was unaware of that and expected the originally request body. It did therefore not send a final DATA frame with EOF flag to the server. - The fix overrides any initial notion of post size when the `done_send` event is triggered by the transfer loop, leading to the EOF that is necessary. - refs curl#11194. The fault did not happen in testing, as Apache httpd never tries to read the request body of the initial request, sends the 401 reply and closes the stream. The server used in the reported issue however tried to read the EOF and timed out on the request.

icing · 2023-05-24T16:56:21Z

Thanks for the fast reply. I could reproduce the problem using the url in your tests and made PR #11200 as fix.

It would be nice if you could verify that this works for you as well.

OlekMazur · 2023-05-24T18:03:24Z

I applied the fix on top of 8.1.1 release and now the previously failing query succeeds.
Thanks for quick fix.

- doing a POST with `--digest` does an override on the initial request with `Content-Length: 0`, but the http2 filter was unaware of that and expected the originally request body. It did therefore not send a final DATA frame with EOF flag to the server. - The fix overrides any initial notion of post size when the `done_send` event is triggered by the transfer loop, leading to the EOF that is necessary. - refs curl#11194. The fault did not happen in testing, as Apache httpd never tries to read the request body of the initial request, sends the 401 reply and closes the stream. The server used in the reported issue however tried to read the EOF and timed out on the request. Reported-by: Aleksander Mazur Fixes curl#11194 Cloes curl#11200

bagder added the HTTP/2 label May 24, 2023

bagder assigned icing May 24, 2023

icing mentioned this issue May 24, 2023

http2: fix EOF handling on uploads with auth negotiation #11200

Closed

bagder closed this as completed in 5c58cb0 May 25, 2023

nekopsykose mentioned this issue May 25, 2023

git clone fails with http2 since 8.1.0 for a specific repo #11201

Closed

bradking mentioned this issue Jun 5, 2023

Bump to 8.1.2 curl/curl-docker#83

Open

georgii-sosnovikov mentioned this issue Jun 20, 2023

Error: curl 56 HTTP/2 stream N was reset #11353

Closed

OlekMazur mentioned this issue Jul 20, 2023

HTTP/2 POST gives timeout/protocol error after upgrade from 8.1.2 to 8.2.0 #11485

Closed

OlekMazur mentioned this issue Sep 19, 2023

curl enters busy loop when POSTing HTTP/2 to IBM Cloud using digest auth #11892

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

HTTP/2 POST reset/timeout after upgrade from 8.0.1 to 8.1.1 #11194

HTTP/2 POST reset/timeout after upgrade from 8.0.1 to 8.1.1 #11194

OlekMazur commented May 24, 2023

icing commented May 24, 2023

OlekMazur commented May 24, 2023

icing commented May 24, 2023

OlekMazur commented May 24, 2023

HTTP/2 POST reset/timeout after upgrade from 8.0.1 to 8.1.1 #11194

HTTP/2 POST reset/timeout after upgrade from 8.0.1 to 8.1.1 #11194

Comments

OlekMazur commented May 24, 2023

I did this

I expected the following

curl/libcurl version

operating system

icing commented May 24, 2023

OlekMazur commented May 24, 2023

icing commented May 24, 2023

OlekMazur commented May 24, 2023