Erroneous debug text when paired with OpenSSL 1.0.2 #219

Closed
wahjava opened this Issue Apr 15, 2015 · 9 comments

Comments

Projects
None yet
4 participants
@wahjava

wahjava commented Apr 15, 2015

When running curl-7.41.0 on FreeBSD 10.1-RELEASE compiled with openssl-1.0.2, I get following erroneous debug messages:

λ curl -svv -o /dev/null 'https://www.freebsd.org/'
*   Trying 8.8.178.110...
*   Trying 2001:1900:2254:206a::50:0...
* Connected to www.freebsd.org (8.8.178.110) port 443 (#0)
* successfully set certificate verify locations:
*   CAfile: /usr/local/share/certs/ca-root-nss.crt
  CApath: none
* TLSv1.2, TLS Unknown, Unknown (22):
} [5 bytes data]
* TLSv1.2, TLS handshake, Client hello (1):
} [512 bytes data]
* SSLv2, Unknown (22):
{ [5 bytes data]
* TLSv1.2, TLS handshake, Server hello (2):
{ [98 bytes data]
* SSLv2, Unknown (22):
{ [5 bytes data]
* TLSv1.2, TLS handshake, CERT (11):
{ [4469 bytes data]
* SSLv2, Unknown (22):
{ [5 bytes data]
* TLSv1.2, TLS handshake, Server key exchange (12):
{ [589 bytes data]
* SSLv2, Unknown (22):
{ [5 bytes data]
* TLSv1.2, TLS handshake, Server finished (14):
{ [4 bytes data]
* SSLv2, Unknown (22):
} [5 bytes data]
* TLSv1.2, TLS handshake, Client key exchange (16):
} [70 bytes data]
* SSLv2, Unknown (20):
} [5 bytes data]
* TLSv1.2, TLS change cipher, Client hello (1):
} [1 bytes data]
* SSLv2, Unknown (22):
} [5 bytes data]
* TLSv1.2, TLS handshake, Finished (20):
} [16 bytes data]
* SSLv2, Unknown (20):
{ [5 bytes data]
* TLSv1.2, TLS change cipher, Client hello (1):
{ [1 bytes data]
* SSLv2, Unknown (22):
{ [5 bytes data]
* TLSv1.2, TLS handshake, Finished (20):
{ [16 bytes data]
* SSL connection using TLSv1.2 / ECDHE-RSA-AES128-GCM-SHA256
* Server certificate:
*        subject: OU=Domain Control Validated; OU=Gandi Standard Wildcard SSL; CN=*.freebsd.org
*        start date: 2014-11-18 00:00:00 GMT
*        expire date: 2015-11-18 23:59:59 GMT
*        subjectAltName: www.freebsd.org matched
*        issuer: C=FR; ST=Paris; L=Paris; O=Gandi; CN=Gandi Standard SSL CA 2
*        SSL certificate verify ok.
* SSLv2, Unknown (23):
} [5 bytes data]
> GET / HTTP/1.1
> User-Agent: curl/7.41.0
> Host: www.freebsd.org
> Accept: */*
> 
* SSLv2, Unknown (23):
{ [5 bytes data]
< HTTP/1.1 200 OK
< Date: Sun, 05 Apr 2015 03:22:12 GMT
< Content-Type: text/html
< Transfer-Encoding: chunked
< Connection: keep-alive
< Last-Modified: Sun, 05 Apr 2015 03:10:15 GMT
< ETag: "5520a797-6f25"
< Server: ToTheCloud/v0.01
< X-Varnish: 1938974843 1938974183
< Age: 25
< Via: 1.1 wfe0.ysv.FreeBSD.org
< X-Cache: HIT
< Strict-Transport-Security: max-age=31536000; includeSubdomains
< 
{ [3820 bytes data]
* SSLv2, Unknown (23):
{ [5 bytes data]
* SSLv2, Unknown (23):
{ [5 bytes data]
* SSLv2, Unknown (23):
{ [5 bytes data]
* SSLv2, Unknown (23):
{ [5 bytes data]
* SSLv2, Unknown (23):
{ [5 bytes data]
* SSLv2, Unknown (23):
{ [5 bytes data]
* SSLv2, Unknown (23):
{ [5 bytes data]
* SSLv2, Unknown (23):
{ [5 bytes data]
* Connection #0 to host www.freebsd.org left intact

As reported in the original bug report, it seems to happen on Windows as well.

Let us know if you need any other information.

Thanks!

@bagder bagder added the SSL/TLS label Apr 15, 2015

@michael-o

This comment has been minimized.

Show comment
Hide comment
@michael-o

michael-o Apr 29, 2015

Member

I can confirm this on 9.3-STABLE with 7.42.0.

Member

michael-o commented Apr 29, 2015

I can confirm this on 9.3-STABLE with 7.42.0.

bagder added a commit that referenced this issue May 4, 2015

openssl: skip trace outputs for ssl_ver == 0
The OpenSSL trace callback is wonderfully undocumented but given a
journey in the source code, it seems the cases were ssl_ver is zero
doesn't follow the same pattern and thus turned out confusing and
misleading. For now, we skip doing any CURLINFO_TEXT logging on those
but keep sending them as CURLINFO_SSL_DATA_OUT/IN.

Also, I added direction to the text info and I edited some functions
slightly.

Bug: #219
Reported-by: Jay Satiro, Ashish Shukla
@bagder

This comment has been minimized.

Show comment
Hide comment
@bagder

bagder May 4, 2015

Member

Thanks, fix landed in 690317a

Member

bagder commented May 4, 2015

Thanks, fix landed in 690317a

@bagder bagder closed this May 4, 2015

@michael-o

This comment has been minimized.

Show comment
Hide comment
@michael-o

michael-o May 4, 2015

Member

I will give it a try tomorrow.

Member

michael-o commented May 4, 2015

I will give it a try tomorrow.

@jay

This comment has been minimized.

Show comment
Hide comment
@jay

jay May 5, 2015

Member

Thanks for investigating and fixing this Daniel. Using OpenSSL 1.0.2a and curl commit 8a35211 2015-05-04 this is the output I get now in Windows Visual Studio 2010 configuration 'DLL Debug - DLL OpenSSL' (either Win32 or x64) when I connect to https://google.com:

* TLSv1.2 (OUT), TLS header, Certificate Status (22):
* TLSv1.2 (OUT), TLS handshake, Client hello (1):
* STATE: SENDPROTOCONNECT => PROTOCONNECT handle 0x1e9f788; line 1210 (connection #0)
* 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):

There is no [xx bytes of data] message any longer. I think it looks cleaner this way but I'm not sure if that's what you intended because there is still a colon at the end of each action line.

Member

jay commented May 5, 2015

Thanks for investigating and fixing this Daniel. Using OpenSSL 1.0.2a and curl commit 8a35211 2015-05-04 this is the output I get now in Windows Visual Studio 2010 configuration 'DLL Debug - DLL OpenSSL' (either Win32 or x64) when I connect to https://google.com:

* TLSv1.2 (OUT), TLS header, Certificate Status (22):
* TLSv1.2 (OUT), TLS handshake, Client hello (1):
* STATE: SENDPROTOCONNECT => PROTOCONNECT handle 0x1e9f788; line 1210 (connection #0)
* 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):

There is no [xx bytes of data] message any longer. I think it looks cleaner this way but I'm not sure if that's what you intended because there is still a colon at the end of each action line.

@bagder

This comment has been minimized.

Show comment
Hide comment
@bagder

bagder May 5, 2015

Member

Really? I don't see how this change could have that effect (and my unpatched 7.42.1 comparison output doesn't show any such "xx bytes of data" output). This change should only remove "unknown" lines and change the explanatory texts somewhat. Or have I missed something?

If you need the full details I'd say that --trace and --trace-ascii are the better options.

Member

bagder commented May 5, 2015

Really? I don't see how this change could have that effect (and my unpatched 7.42.1 comparison output doesn't show any such "xx bytes of data" output). This change should only remove "unknown" lines and change the explanatory texts somewhat. Or have I missed something?

If you need the full details I'd say that --trace and --trace-ascii are the better options.

@jay

This comment has been minimized.

Show comment
Hide comment
@jay

jay May 5, 2015

Member

Nevermind I was comparing it against the OP's output instead of my own. I tried the commit before your changes and I don't get the [data] messages there either. Also I checked the sourceforge bug and I didn't get [data] there either.

Member

jay commented May 5, 2015

Nevermind I was comparing it against the OP's output instead of my own. I tried the commit before your changes and I don't get the [data] messages there either. Also I checked the sourceforge bug and I didn't get [data] there either.

@bagder

This comment has been minimized.

Show comment
Hide comment
@bagder

bagder May 5, 2015

Member

Ok, goodie. Then I wasn't hallucinating too badly! =)

Member

bagder commented May 5, 2015

Ok, goodie. Then I wasn't hallucinating too badly! =)

@michael-o

This comment has been minimized.

Show comment
Hide comment
@michael-o

michael-o May 5, 2015

Member

Looks ok now:

* ALPN, offering http/1.1
* Cipher selection: ALL:!EXPORT:!EXPORT40:!EXPORT56:!aNULL:!LOW:!RC4:@STRENGTH
* successfully set certificate verify locations:
*   CAfile: /usr/local/share/certs/combined-ca.pem
  CApath: none
* TLSv1.2 (OUT), TLS header, Certificate Status (22):
} [5 bytes data]
* TLSv1.2 (OUT), TLS handshake, Client hello (1):
} [512 bytes data]
* TLSv1.2 (IN), TLS handshake, Server hello (2):
{ [98 bytes data]
* TLSv1.2 (IN), TLS handshake, Certificate (11):
{ [1873 bytes data]
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
{ [589 bytes data]
* TLSv1.2 (IN), TLS handshake, Server finished (14):
{ [4 bytes data]
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
} [70 bytes data]
* TLSv1.2 (OUT), TLS change cipher, Client hello (1):
} [1 bytes data]
* TLSv1.2 (OUT), TLS handshake, Finished (20):
} [16 bytes data]
* TLSv1.2 (IN), TLS change cipher, Client hello (1):
{ [1 bytes data]
* TLSv1.2 (IN), TLS handshake, Finished (20):
{ [16 bytes data]
* SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384
* ALPN, server did not agree to a protocol
* Server certificate:

Is the colon referring to the byte data below? If not, I'd rather remove that.

Member

michael-o commented May 5, 2015

Looks ok now:

* ALPN, offering http/1.1
* Cipher selection: ALL:!EXPORT:!EXPORT40:!EXPORT56:!aNULL:!LOW:!RC4:@STRENGTH
* successfully set certificate verify locations:
*   CAfile: /usr/local/share/certs/combined-ca.pem
  CApath: none
* TLSv1.2 (OUT), TLS header, Certificate Status (22):
} [5 bytes data]
* TLSv1.2 (OUT), TLS handshake, Client hello (1):
} [512 bytes data]
* TLSv1.2 (IN), TLS handshake, Server hello (2):
{ [98 bytes data]
* TLSv1.2 (IN), TLS handshake, Certificate (11):
{ [1873 bytes data]
* TLSv1.2 (IN), TLS handshake, Server key exchange (12):
{ [589 bytes data]
* TLSv1.2 (IN), TLS handshake, Server finished (14):
{ [4 bytes data]
* TLSv1.2 (OUT), TLS handshake, Client key exchange (16):
} [70 bytes data]
* TLSv1.2 (OUT), TLS change cipher, Client hello (1):
} [1 bytes data]
* TLSv1.2 (OUT), TLS handshake, Finished (20):
} [16 bytes data]
* TLSv1.2 (IN), TLS change cipher, Client hello (1):
{ [1 bytes data]
* TLSv1.2 (IN), TLS handshake, Finished (20):
{ [16 bytes data]
* SSL connection using TLSv1.2 / ECDHE-RSA-AES256-GCM-SHA384
* ALPN, server did not agree to a protocol
* Server certificate:

Is the colon referring to the byte data below? If not, I'd rather remove that.

@michael-o

This comment has been minimized.

Show comment
Hide comment
@michael-o

michael-o May 5, 2015

Member

Just checked on another OS with OpenSSL 0.9.8. It's fine too.

Member

michael-o commented May 5, 2015

Just checked on another OS with OpenSSL 0.9.8. It's fine too.

jsonn pushed a commit to jsonn/pkgsrc that referenced this issue Jun 30, 2015

spz
update of curl to version 7.43.0. Upstream RELEASE_NOTES:
Curl and libcurl 7.43.0

 Public curl releases:         147
 Command line options:         176
 curl_easy_setopt() options:   219
 Public functions in libcurl:  58
 Contributors:                 1291

This release includes the following changes:

 o Added CURLOPT_PROXY_SERVICE_NAME[11]
 o Added CURLOPT_SERVICE_NAME[12]
 o New curl option: --proxy-service-name[13]
 o Mew curl option: --service-name [14]
 o New curl option: --data-raw [5]
 o Added CURLOPT_PIPEWAIT [15]
 o Added support for multiplexing transfers using HTTP/2, enable this
   with the new CURLPIPE_MULTIPLEX bit for CURLMOPT_PIPELINING [16]
 o HTTP/2: requires nghttp2 1.0.0 or later
 o scripts: add zsh.pl for generating zsh completion
 o curl.h: add CURL_HTTP_VERSION_2

This release includes the following bugfixes:

 o CVE-2015-3236: lingering HTTP credentials in connection re-use [30]
 o CVE-2015-3237: SMB send off unrelated memory contents [31]
 o nss: fix compilation failure with old versions of NSS [1]
 o curl_easy_getinfo.3: document 'internals' in CURLINFO_TLS_SESSION
 o schannel.c: Fix possible SEC_E_BUFFER_TOO_SMALL error
 o Curl_ossl_init: load builtin modules [2]
 o configure: follow-up fix for krb5-config [3]
 o sasl_sspi: Populate domain from the realm in the challenge [4]
 o netrc: support 'default' token
 o README: convert to UTF-8
 o cyassl: Implement public key pinning
 o nss: implement public key pinning for NSS backend
 o mingw build: add arch -m32/-m64 to LDFLAGS
 o schannel: Fix out of bounds array [6]
 o configure: remove autogenerated files by autoconf
 o configure: remove --automake from libtoolize call
 o acinclude.m4: fix shell test for default CA cert bundle/path
 o schannel: fix regression in schannel_recv [7]
 o openssl: skip trace outputs for ssl_ver == 0 [8]
 o gnutls: properly retrieve certificate status
 o netrc: Read in text mode when cygwin [9]
 o winbuild: Document the option used to statically link the CRT [10]
 o FTP: Make EPSV use the control IP address rather than the original host
 o FTP: fix dangling conn->ip_addr dereference on verbose EPSV
 o conncache: keep bundles on host+port bases, not only host names
 o runtests.pl: use 'h2c' now, no -14 anymore
 o curlver: introducing new version number (checking) macros
 o openssl: boringssl build brekage, use SSL_CTX_set_msg_callback [17]
 o CURLOPT_POSTFIELDS.3: correct variable names [18]
 o curl_easy_unescape.3: update RFC reference [19]
 o gnutls: don't fail on non-fatal alerts during handshake
 o testcurl.pl: allow source to be in an arbitrary directory
 o CURLOPT_HTTPPROXYTUNNEL.3: only works with a HTTP proxy
 o SSPI-error: Change SEC_E_ILLEGAL_MESSAGE description [20]
 o parse_proxy: switch off tunneling if non-HTTP proxy [21]
 o share_init: fix OOM crash
 o perl: remove subdir, not touched in 9 years
 o CURLOPT_COOKIELIST.3: Add example
 o CURLOPT_COOKIE.3: Explain that the cookies won't be modified [22]
 o CURLOPT_COOKIELIST.3: Explain Set-Cookie without a domain [23]
 o FAQ: How do I port libcurl to my OS?
 o openssl: Use TLS_client_method for OpenSSL 1.1.0+
 o HTTP-NTLM: fail auth on connection close instead of looping [24]
 o curl_setup: Add macros for FOPEN_READTEXT, FOPEN_WRITETEXT [25]
 o curl_getdate.3: update RFC reference
 o curl_multi_info_read.3: added example
 o curl_multi_perform.3: added example
 o curl_multi_timeout.3: added example
 o cookie: Stop exporting any-domain cookies [26]
 o openssl: remove dummy callback use from SSL_CTX_set_verify()
 o openssl: remove SSL_get_session()-using code
 o openssl: removed USERDATA_IN_PWD_CALLBACK kludge
 o openssl: removed error string #ifdef
 o openssl: Fix verification of server-sent legacy intermediates [27]
 o docs: man page indentation and syntax fixes
 o docs: Spelling fixes
 o fopen.c: fix a few compiler warnings
 o CURLOPT_OPENSOCKETFUNCTION: return error at once [28]
 o schannel: Add support for optional client certificates
 o build: Properly detect OpenSSL 1.0.2 when using configure
 o urldata: store POST size in state.infilesize too [29]
 o security:choose_mech remove dead code
 o rtsp_do: remove dead code
 o docs: many HTTP URIs changed to HTTPS
 o schannel: schannel_recv overhaul [32]

This release includes the following known bugs:

 o see docs/KNOWN_BUGS (http://curl.haxx.se/docs/knownbugs.html)

This release would not have looked like this without help, code, reports and
advice from friends like these:

  Alessandro Ghedini, Alexander Dyagilev, Anders Bakken, Anthony Avina,
  Ashish Shukla, Bert Huijben, Brian Chrisman, Brian Prodoehl, Chris Araman,
  Dagobert Michelsen, Dan Fandrich, Daniel Melani, Daniel Stenberg,
  Dmitry Eremin-Solenikov, Drake Arconis, Egon Eckert, Frank Meier, Fred Stluka,
  Gisle Vanem, Grant Pannell, Isaac Boukris, Jens Rantil, Joel Depooter,
  Kamil Dudka, Linus Nielsen Feltzing, Linus Nielsen Feltzing Feltzing,
  Liviu Chircu, Marc Hoersken, Michael Osipov, Oren Souroujon, Orgad Shaneh,
  Patrick Monnerat, Patrick Rapin, Paul Howarth, Paul Oliver, Rafayel Mkrtchyan,
  Ray Satiro, Sean Boudreau, Tatsuhiro Tsujikawa, Tomas Tomecek, Viktor Szakáts,
  Ville Skyttä, Yehezkel Horowitz,
  (43 contributors)

        Thanks! (and sorry if I forgot to mention someone)

References to bug reports and discussions on issues:

 [1] = http://curl.haxx.se/mail/lib-2015-04/0095.html
 [2] = curl/curl#206
 [3] = curl/curl@5b66860#commitcomment-10473445
 [4] = curl/curl#141
 [5] = curl/curl#198
 [6] = http://curl.haxx.se/mail/lib-2015-04/0199.html
 [7] = curl/curl#244
 [8] = curl/curl#219
 [9] = curl/curl#258
 [10] = curl/curl#254
 [11] = http://curl.haxx.se/libcurl/c/CURLOPT_PROXY_SERVICE_NAME.html
 [12] = http://curl.haxx.se/libcurl/c/CURLOPT_SERVICE_NAME.html
 [13] = http://curl.haxx.se/docs/manpage.html#--proxy-service-name
 [14] = http://curl.haxx.se/docs/manpage.html#--service-name
 [15] = http://curl.haxx.se/libcurl/c/CURLOPT_PIPEWAIT.html
 [16] = http://curl.haxx.se/libcurl/c/CURLMOPT_PIPELINING.html
 [17] = curl/curl#275
 [18] = curl/curl#281
 [19] = curl/curl#282
 [20] = curl/curl#267
 [21] = http://curl.haxx.se/mail/lib-2015-05/0056.html
 [22] = http://curl.haxx.se/mail/lib-2015-05/0115.html
 [23] = http://curl.haxx.se/mail/lib-2015-05/0137.html
 [24] = curl/curl#256
 [25] = curl/curl#258 (comment)
 [26] = curl/curl#292
 [27] = https://rt.openssl.org/Ticket/Display.html?id=3621&user=guest&pass=guest
 [28] = http://curl.haxx.se/mail/lib-2015-06/0047.html
 [29] = http://curl.haxx.se/mail/lib-2015-06/0019.html
 [30] = http://curl.haxx.se/docs/adv_20150617A.html
 [31] = http://curl.haxx.se/docs/adv_20150617B.html
 [32] = curl/curl#244

jgsogo added a commit to jgsogo/curl that referenced this issue Oct 19, 2015

openssl: skip trace outputs for ssl_ver == 0
The OpenSSL trace callback is wonderfully undocumented but given a
journey in the source code, it seems the cases were ssl_ver is zero
doesn't follow the same pattern and thus turned out confusing and
misleading. For now, we skip doing any CURLINFO_TEXT logging on those
but keep sending them as CURLINFO_SSL_DATA_OUT/IN.

Also, I added direction to the text info and I edited some functions
slightly.

Bug: curl#219
Reported-by: Jay Satiro, Ashish Shukla

@curl curl locked as resolved and limited conversation to collaborators May 7, 2018

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