Skip to content

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

New issue
New issue
Closed
Closed
HTTP/2 POST reset/timeout after upgrade from 8.0.1 to 8.1.1#11194
Assignees
icing
Labels
HTTP/2
@OlekMazur

Description

@OlekMazur
OlekMazur
opened on May 24, 2023

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

Activity

bagder
added
HTTP/2
on May 24, 2023
bagder
assigned
icing
on May 24, 2023
icing

icing commented on May 24, 2023

@icing
icing
on May 24, 2023
Contributor

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

OlekMazur commented on May 24, 2023

@OlekMazur
OlekMazur
on May 24, 2023
Author

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
icing
added a commit that references this issue on May 24, 2023

http2: fix EOF handling on uploads with auth negotiation

d000c92
icing
mentioned this on May 24, 2023
icing

icing commented on May 24, 2023

@icing
icing
on May 24, 2023
Contributor

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

OlekMazur commented on May 24, 2023

@OlekMazur
OlekMazur
on May 24, 2023
Author

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

bagder
closed this as completedin 5c58cb0on May 25, 2023
nekopsykose
mentioned this on May 25, 2023
bradking
mentioned this on Jun 5, 2023
georgii-sosnovikov
mentioned this on Jun 20, 2023
bch
added a commit that references this issue on Jul 19, 2023

http2: fix EOF handling on uploads with auth negotiation

d320638
OlekMazur
mentioned this on Jul 20, 2023
OlekMazur
mentioned this on Sep 19, 2023

1 remaining item

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

Metadata

Metadata

Assignees

Labels

HTTP/2

Type

No type

Projects

No projects

Milestone

No milestone

Relationships

None yet

    Development

    No branches or pull requests

      Participants

      @icing@bagder@OlekMazur

      Issue actions
        HTTP/2 POST reset/timeout after upgrade from 8.0.1 to 8.1.1 · Issue #11194 · curl/curl