Behaviour of https changed in curl 7.87.0 if 'Connection: close' header is present.

[hideishi-m]

I did this

curl \
     --http1.1 \
     --cacert /etc/pki/tls/certs/ca-bundle.crt \
     -H 'Connection: close' \
     https://www.google.com >/dev/null
echo $?

Output with curl 7.87.0 is:

curl: (56) OpenSSL SSL_read: Connection closed abruptly, errno 0 (Fatal because this is a curl debug build)
56

Please note that I deliverately built curl with --enable-debug.

Following is the output with --verbose.

* STATE: INIT => CONNECT handle 0x25439b8; line 1909 (connection #-5000)
* Added connection 0. The cache now contains 1 members
* STATE: CONNECT => RESOLVING handle 0x25439b8; line 1955 (connection #0)
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0* [CONN-0-0] setup, init filter chain
* [CONN-0-0] cf_add(filter=SOCKET)
* [CONN-0-0] cf_add(filter=SSL)
* [CONN-0-0][CF-SOCKET] setup(remotehost=www.google.com)
* STATE: RESOLVING => CONNECTING handle 0x25439b8; line 2029 (connection #0)
* family0 == v4, family1 == v6
*   Trying 172.217.161.36:443...
* [CONN-0-0] connect(block=0)-> 0, done=0
* [CONN-0-0] connect(block=0)-> 0, done=0
* [CONN-0-0] connect(block=0)-> 0, done=0
* [CONN-0-0] connect(block=0)-> 0, done=0
* Connected to www.google.com (172.217.161.36) port 443 (#0)
* ALPN: offers http/1.1
*  CAfile: /etc/pki/tls/certs/ca-bundle.crt
*  CApath: none
* [CONN-0] Didn't find Session ID in cache for host HTTPS://www.google.com:443
* [CONN-0-0][CF-SSL] TLSv1.0 (OUT), TLS header, Certificate Status (22):
} [5 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.3 (OUT), TLS handshake, Client hello (1):
} [512 bytes data]
* [CONN-0-0] connect(block=0)-> 0, done=0
* [CONN-0-0] connect(block=0)-> 0, done=0
* [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Certificate Status (22):
{ [5 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.3 (IN), TLS handshake, Server hello (2):
{ [122 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Finished (20):
{ [5 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
{ [21 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.3 (IN), TLS handshake, Certificate (11):
{ [4004 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.3 (IN), TLS handshake, CERT verify (15):
{ [79 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.3 (IN), TLS handshake, Finished (20):
{ [52 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.2 (OUT), TLS header, Finished (20):
} [5 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
} [1 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.2 (OUT), TLS header, Supplemental data (23):
} [5 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.3 (OUT), TLS handshake, Finished (20):
} [52 bytes data]
* SSL connection using TLSv1.3 / TLS_AES_256_GCM_SHA384
* ALPN: server accepted http/1.1
* Server certificate:
*  subject: CN=www.google.com
*  start date: Nov 28 08:19:01 2022 GMT
*  expire date: Feb 20 08:19:00 2023 GMT
*  subjectAltName: host "www.google.com" matched cert's "www.google.com"
*  issuer: C=US; O=Google Trust Services LLC; CN=GTS CA 1C3
*  SSL certificate verify ok.
* [CONN-0-0] connect(block=0)-> 0, done=1
* STATE: CONNECTING => PROTOCONNECT handle 0x25439b8; line 2073 (connection #0)
* [CONN-0-0] connect(block=0)-> 0, done=1
* STATE: PROTOCONNECT => DO handle 0x25439b8; line 2103 (connection #0)
* [CONN-0-0][CF-SSL] TLSv1.2 (OUT), TLS header, Supplemental data (23):
} [5 bytes data]
> GET / HTTP/1.1
> Host: www.google.com
> User-Agent: curl/7.86.0
> Accept: */*
> Connection: close
>
* STATE: DO => DID handle 0x25439b8; line 2199 (connection #0)
* STATE: DID => PERFORMING handle 0x25439b8; line 2318 (connection #0)
* Curl_readwrite(handle=0x25439b8) -> 0
* [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
{ [288 bytes data]
* [CONN-0] Didn't find Session ID in cache for host HTTPS://www.google.com:443
* [CONN-0] Added Session ID to cache for HTTPS://www.google.com:443 [server]
* [CONN-0-0][CF-SSL] TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
{ [288 bytes data]
* [CONN-0] Found Session ID in cache for host HTTPS://www.google.com:443
* old SSL session ID is stale, removing
* [CONN-0] Added Session ID to cache for HTTPS://www.google.com:443 [server]
* [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* Mark bundle as not supporting multiuse
* HTTP 1.1 or later with persistent connection
< HTTP/1.1 200 OK
< Date: Wed, 28 Dec 2022 07:05:21 GMT
< Expires: -1
< Cache-Control: private, max-age=0
< Content-Type: text/html; charset=ISO-8859-1
< Cross-Origin-Opener-Policy-Report-Only: same-origin-allow-popups; report-to="gws"
< Report-To: {"group":"gws","max_age":2592000,"endpoints":[{"url":"https://csp.withgoogle.com/csp/report-to/gws/other"}]}
< P3P: CP="This is not a P3P policy! See g.co/p3phelp for more info."
< Server: gws
< X-XSS-Protection: 0
< X-Frame-Options: SAMEORIGIN
< Set-Cookie: 1P_JAR=2022-12-28-07; expires=Fri, 27-Jan-2023 07:05:22 GMT; path=/; domain=.google.com; Secure
< Set-Cookie: AEC=AakniGM3qBKL-bKwPhSSnCMkNYnctWuhS06yj_qB6bZIc0S_dAtdkFOcMA; expires=Mon, 26-Jun-2023 07:05:22 GMT; path=/; domain=.google.com; Secure; HttpOnly; SameSite=lax
< Set-Cookie: NID=511=DEs0VJ0bE1TjFIy9gP7eJ6kkbOSjSc6iaMdKpJtmq_OI07tQVeyQd8p1jbGR7UsiUCM8AHzoUJN9v-13ROJ0VFzLAJ-cNsSdGmVGJeJnwBPyHLlIoX0h9an8yuyzRT2t1gdpMPgqNWf1MKk9QHMsIM2PLlbUt8y5nWFN1burWGM; expires=Thu, 29-Jun-2023 07:05:21 GMT; path=/; domain=.google.com; HttpOnly
< Alt-Svc: h3=":443"; ma=2592000,h3-29=":443"; ma=2592000,h3-Q050=":443"; ma=2592000,h3-Q046=":443"; ma=2592000,h3-Q043=":443"; ma=2592000,quic=":443"; ma=2592000; v="46,43"
< Accept-Ranges: none
< Vary: Accept-Encoding
< Connection: close
< Transfer-Encoding: chunked
<
{ [75 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* OpenSSL SSL_read: Connection closed abruptly, errno 0 (Fatal because this is a curl debug build)
* readwrite_data(handle=0x25439b8) -> 56
* Curl_readwrite(handle=0x25439b8) -> 56
* multi_done: status: 56 prem: 1 done: 0
100 15087    0 15087    0     0  37253      0 --:--:-- --:--:-- --:--:-- 37344
* multi_done, not re-using connection=0, forbid=0, close=1, premature=1, stream=0
* The cache now contains 0 members
* Curl_disconnect(conn #0, dead=1)
* Closing connection 0
* [CONN-0-0][CF-SSL] TLSv1.2 (OUT), TLS header, Supplemental data (23):
} [5 bytes data]
* [CONN-0-0][CF-SSL] TLSv1.3 (OUT), TLS alert, close notify (256):
} [2 bytes data]
* Expire cleared (transfer 0x25439b8)
curl: (56) OpenSSL SSL_read: Connection closed abruptly, errno 0 (Fatal because this is a curl debug build)
56

I expected the following

With curl 7.86.0, the same command return 0 (success) without any error even with --enable-debug.

Following is the output with --verbose.

* STATE: INIT => CONNECT handle 0x9f5938; line 1879 (connection #-5000)
* Added connection 0. The cache now contains 1 members
* STATE: CONNECT => RESOLVING handle 0x9f5938; line 1925 (connection #0)
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0* family0 == v4, family1 == v6
*   Trying 172.217.161.68:443...
* STATE: RESOLVING => CONNECTING handle 0x9f5938; line 2009 (connection #0)
* Connected to www.google.com (172.217.161.68) port 443 (#0)
* STATE: CONNECTING => PROTOCONNECT handle 0x9f5938; line 2074 (connection #0)
* ALPN: offers http/1.1
*  CAfile: /etc/pki/tls/certs/ca-bundle.crt
*  CApath: none
* Didn't find Session ID in cache for host HTTPS://www.google.com:443
* TLSv1.0 (OUT), TLS header, Certificate Status (22):
} [5 bytes data]
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
} [512 bytes data]
* STATE: PROTOCONNECT => PROTOCONNECTING handle 0x9f5938; line 2092 (connection #0)
* TLSv1.2 (IN), TLS header, Certificate Status (22):
{ [5 bytes data]
* TLSv1.3 (IN), TLS handshake, Server hello (2):
{ [122 bytes data]
* TLSv1.2 (IN), TLS header, Finished (20):
{ [5 bytes data]
* TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* TLSv1.3 (IN), TLS handshake, Encrypted Extensions (8):
{ [21 bytes data]
* TLSv1.3 (IN), TLS handshake, Certificate (11):
{ [4004 bytes data]
* TLSv1.3 (IN), TLS handshake, CERT verify (15):
{ [80 bytes data]
* TLSv1.3 (IN), TLS handshake, Finished (20):
{ [52 bytes data]
* TLSv1.2 (OUT), TLS header, Finished (20):
} [5 bytes data]
* TLSv1.3 (OUT), TLS change cipher, Change cipher spec (1):
} [1 bytes data]
* TLSv1.2 (OUT), TLS header, Supplemental data (23):
} [5 bytes data]
* TLSv1.3 (OUT), TLS handshake, Finished (20):
} [52 bytes data]
* SSL connection using TLSv1.3 / TLS_AES_256_GCM_SHA384
* ALPN: server accepted http/1.1
* Server certificate:
*  subject: CN=www.google.com
*  start date: Nov 28 08:19:01 2022 GMT
*  expire date: Feb 20 08:19:00 2023 GMT
*  subjectAltName: host "www.google.com" matched cert's "www.google.com"
*  issuer: C=US; O=Google Trust Services LLC; CN=GTS CA 1C3
*  SSL certificate verify ok.
* STATE: PROTOCONNECTING => DO handle 0x9f5938; line 2111 (connection #0)
* TLSv1.2 (OUT), TLS header, Supplemental data (23):
} [5 bytes data]
> GET / HTTP/1.1
> Host: www.google.com
> User-Agent: curl/7.86.0
> Accept: */*
> Connection: close
>
* STATE: DO => DID handle 0x9f5938; line 2191 (connection #0)
* STATE: DID => PERFORMING handle 0x9f5938; line 2310 (connection #0)
* TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
{ [288 bytes data]
* Didn't find Session ID in cache for host HTTPS://www.google.com:443
* Added Session ID to cache for HTTPS://www.google.com:443 [server]
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
{ [288 bytes data]
* Found Session ID in cache for host HTTPS://www.google.com:443
* old SSL session ID is stale, removing
* Added Session ID to cache for HTTPS://www.google.com:443 [server]
* TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* Mark bundle as not supporting multiuse
* HTTP 1.1 or later with persistent connection
< HTTP/1.1 200 OK
< Date: Wed, 28 Dec 2022 07:03:32 GMT
< Expires: -1
< Cache-Control: private, max-age=0
< Content-Type: text/html; charset=ISO-8859-1
< Cross-Origin-Opener-Policy-Report-Only: same-origin-allow-popups; report-to="gws"
< Report-To: {"group":"gws","max_age":2592000,"endpoints":[{"url":"https://csp.withgoogle.com/csp/report-to/gws/other"}]}
< P3P: CP="This is not a P3P policy! See g.co/p3phelp for more info."
< Server: gws
< X-XSS-Protection: 0
< X-Frame-Options: SAMEORIGIN
< Set-Cookie: 1P_JAR=2022-12-28-07; expires=Fri, 27-Jan-2023 07:03:32 GMT; path=/; domain=.google.com; Secure
< Set-Cookie: AEC=AakniGM6ONSrec_kmMy_a8LMmaiJP7sRUb-AhgzNvTFXtB2c_GepL3og9A; expires=Mon, 26-Jun-2023 07:03:32 GMT; path=/; domain=.google.com; Secure; HttpOnly; SameSite=lax
< Set-Cookie: NID=511=N9wTNwX5-bwrbQhVTWrCMmwNP2H0f9QYpcoMCoaPmUkhNZzC2948XlH-pdcK7_KNQMWGa8DlD8eT_hGZvy6tsUTOsH3N_px3aPcZIqVxEyGIqNZa-AJvaUq_Y3yh1EGMRlLENsl4DvQgA9nb-l70IjeO1DhfV_ySoL5lW03HI-I; expires=Thu, 29-Jun-2023 07:03:32 GMT; path=/; domain=.google.com; HttpOnly
< Alt-Svc: h3=":443"; ma=2592000,h3-29=":443"; ma=2592000,h3-Q050=":443"; ma=2592000,h3-Q046=":443"; ma=2592000,h3-Q043=":443"; ma=2592000,quic=":443"; ma=2592000; v="46,43"
< Accept-Ranges: none
< Vary: Accept-Encoding
< Connection: close
< Transfer-Encoding: chunked
<
{ [75 bytes data]
* TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* STATE: PERFORMING => DONE handle 0x9f5938; line 2509 (connection #0)
* multi_done: status: 0 prem: 0 done: 0
100 15105    0 15105    0     0  67748      0 --:--:-- --:--:-- --:--:-- 68040
* The cache now contains 0 members
* Closing connection 0
* TLSv1.2 (OUT), TLS header, Supplemental data (23):
} [5 bytes data]
* TLSv1.3 (OUT), TLS alert, decode error (562):
} [2 bytes data]
* Expire cleared (transfer 0x9f5938)
0

curl/libcurl version

curl 7.87.0 (x86_64-redhat-linux-gnu) libcurl/7.87.0 OpenSSL/3.0.7 zlib/1.2.11 brotli/1.0.9 zstd/1.4.4 libidn2/2.2.0 libpsl/0.20.2 (+libidn2/2.2.0) libssh2/1.9.0 nghttp2/1.51.0 libgsasl/1.8.0
Release-Date: 2022-12-21
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 Debug gsasl GSS-API HSTS HTTP2 HTTPS-proxy IDN IPv6 Kerberos Largefile libz NTLM NTLM_WB PSL SPNEGO SSL threadsafe TLS-SRP TrackMemory UnixSockets zstd

operating system

Linux dev-kusanagi9.magisystem.net 4.18.0-408.el8.x86_64 #1 SMP Mon Jul 18 17:42:52 UTC 2022 x86_64 x86_64 x86_64 GNU/Linux

[bagder]

This is not a bug, it is on purpose: "Fatal because this is a curl debug build"

Can you elaborate on why this is a problem for you?

[hideishi-m]

Hi @bagder , sure.

My point is that "Fatal because this is a curl debug build" did not appear in 7.86.0 with --enable-debug where it now appears in 7.87.0 with --enable-debug.
If it has been on purpose, then the message should have appeared in 7.86.0 as well.

I did a trace on both 7.86.0 and 7.87.0 and it seems that recent refactoring in lib/vtls/openssl.c has made a change in handling connection.
Therefore, I suspect that this might be a regression caused in 7.87.0.

[hideishi-m]

To be more precise,

https://github.com/curl/curl/blob/master/lib/vtls/openssl.c#L4683

In 7.86.0, err did not equal to SSL_ERROR_SYSCALL, hence no error message even with --enable-debug.
In 7.87.0, err equals to SSL_ERROR_SYSCALL, and because --enable-debug is on, it shows the above error message.

My point is that err was not SSL_ERROR_SYSCALL in the previous version regardless of --enable-debug and message.

[hideishi-m]

Thank you for the fix.
I applied your fix locally and confirmed that it works the same as 7.86.0 without any error message even with --enable-debug.
Looking forward to be merged in the next release.