curl -v has become too verbose to follow for https requests

From: Charles Zhang via curl-users <curl-users_at_lists.haxx.se>
Date: Mon, 30 Jan 2023 11:44:08 +0200

I consider "curl -v" to be handy when doing network diagnostics: It
will show useful details about DNS resolving, TLS handshake, the HTTP
request and response headers that might contain interesting bits, all
in the terminal. However its output has become too spammy for https
requests when server is sending the bulky response. Here is an example
from curl 7.86.0:

$ curl -V
curl 7.86.0 (x86_64-pc-linux-gnu) libcurl/7.86.0 OpenSSL/3.0.7 zlib/1.2.13 brotli/1.0.9 zstd/1.5.2 libidn2/2.3.4 libpsl/0.21.2 (+libidn2/2.3.4) libssh2/1.10.0 nghttp2/1.51.0
Release-Date: 2022-10-26
[...]
$ curl -s -v -o /dev/null https://www.google.com
* Trying [2a00:1450:4008:804::2004]:443...
* Connected to www.google.com (2a00:1450:4008:804::2004) port 443 (#0)
* ALPN: offers h2
* ALPN: offers http/1.1
* CAfile: /etc/ssl/certs/ca-certificates.crt
* CApath: none
* TLSv1.0 (OUT), TLS header, Certificate Status (22):
} [5 bytes data]
* TLSv1.3 (OUT), TLS handshake, Client hello (1):
} [512 bytes data]
[...]
* SSL connection using TLSv1.3 / TLS_AES_256_GCM_SHA384
[...]
* Using HTTP2, server supports multiplexing
* Copying HTTP/2 data in stream buffer to connection buffer after upgrade: len=0
* TLSv1.2 (OUT), TLS header, Supplemental data (23):
} [5 bytes data]
* TLSv1.2 (OUT), TLS header, Supplemental data (23):
} [5 bytes data]
* TLSv1.2 (OUT), TLS header, Supplemental data (23):
} [5 bytes data]
* h2h3 [:method: GET]
* h2h3 [:path: /]
* h2h3 [:scheme: https]
* h2h3 [:authority: www.google.com]
* h2h3 [user-agent: curl/7.86.0]
* h2h3 [accept: */*]
* Using Stream ID: 1 (easy handle 0x55d4135c5e60)
* TLSv1.2 (OUT), TLS header, Supplemental data (23):
} [5 bytes data]
> GET / HTTP/2
> Host: www.google.com
> user-agent: curl/7.86.0
> accept: */*
>
* TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
{ [282 bytes data]
* TLSv1.3 (IN), TLS handshake, Newsession Ticket (4):
{ [282 bytes data]
* old SSL session ID is stale, removing
* TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* TLSv1.2 (OUT), 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]
< HTTP/2 200
< date: Sun, 29 Jan 2023 18:01:32 GMT
[...]
<
* TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
[...repeat 12 times...]
* TLSv1.2 (IN), TLS header, Supplemental data (23):
{ [5 bytes data]
* Connection #0 to host www.google.com left intact

The problem is more evident when downloading large files, that the
scrollback buffer of terminal will be quickly filled up by those
"Supplemental data". curl 7.87.0 behaves mostly the same except for
the extra "[CONN-0-0][CF-SSL]" prefix in messages related to the TLS
library. In current git HEAD (e7512e78c2c5a6d07b47239122c2880bf6ac0e3a),
the terminal would be filled with things like:

* http2_recv: easy 0x556b6c011e30 (stream 1) win 33553255/33553255
{ [5 bytes data]
* nread=1186
* 1186 data received for stream 1 (101214 left in buffer 0x556b6c014810, total 1186)
* h2_process_pending_input: All data in connection buffer processed
* http2_recv: returns 1186 for stream 1
{ [1186 bytes data]

I understand that the verbosity might be related to changes in the
underlying TLS libraries. Windows users are probably familiar with that
"schannel: failed to decrypt data, need more data", but the message
frequency seems to be higher with current OpenSSL. With the refactor
about cfilter (connection filters) ongoing in libcurl, the underlying
modifications will naturally change the debug output. However, I consider
the volume of log to be too much for interactive users trying "-v".

Folding those unnecessary messages behind a new debug flag seems an
obvious way to make "-v" less chatty. However I am not sure if the way
curl and libcurl interact permits an easy implementation.
("--verbose" or "--trace" in curl seems to be a simple wrapper for
CURLOPT_DEBUGFUNCTION, and CURLOPT_VERBOSE is only 0/1.)

As a workaround, if users only want to see the response header, they
can use "-i, --include" or "-I, --head" for outputting it in the same
stream as response body, or use "-D, --dump-header" like "-D -" to see
it in stdout. To see the request header, the manpage curl(1) still
recommends users to use "-v, --verbose". However the useful info will
be quickly flooded away unless users do some custom filtering to the
log by gluing together some scripts.

Cheers,

-- 
Unsubscribe: https://lists.haxx.se/listinfo/curl-users
Etiquette:   https://curl.se/mail/etiquette.html

Received on 2023-01-30