Hello,
On 06/07/2021 14:55, Willy Tarreau wrote:
On Tue, Jul 06, 2021 at 12:19:56PM +0200, Tim Düsterhus wrote:
Willy,
On 7/6/21 12:12 PM, Willy Tarreau wrote:
A few points first, that are needed to address various concerns. The
goal here is to defined an HTTPS log format because that's what the
vast majority of users are dealing with day-to-day. For specific usages,
everyone already redefines log formats. But for a very basic setup, right
now it's true that httplog is a bit limited, and all it shows to help guess
there was SSL involved is to append this '~' after the frontend's name.
It was not clear to me that this log format is meant to apply to HTTPS
requests, because the example given by Remi does not include the HTTP verb
and neither the request URI (unless I need glasses). I thought it was a
format for TLS errors or something like this.
At least it was my understanding that it was mostly aimed at HTTPS given
that the discussion we had on the subject started around this :-)
Is this a mistake in the examples? Or is HAProxy going to emit multiple log
lines: One for the TLS connection and one for each HTTP request passing
through this TLS connection?
There was a discussion around logging at various layers, I don't remember
if it was on the list or in a github issue, but I remember having been
involved in this some time ago. I think that it makes sense to ultimately
be able to emit error logs at various levels (i.e. when being certain that
no other event will happen) but it's particularly confusing to log successes
at various levels. Thus typically seeing TLS handshake failures is important
but their success should not be logged as all the info will instead be
available with the traffic logs. There are already enough users complaining
about noise caused by client-aborted connections :-)
Willy
I was indeed more focused on logging SSL related information only, with
the idea that an SSL log line could be displayed after a completed
handshake, hence the lack of upper layer information in the log line.
But it would indeed bring a new level of complexity in the log because
correlating the SSL and HTTP log lines of a specific session might be a
pain. After talking with Willy, an https log was deemed more useful. It
would only be an extension of the existing HTTP log with SSL specific
information added. This log format would concern every log line raised
by the frontends using this log format (one line per HTTP response of
the SSL session).
A quick recap of the topics raised by the multiple conversations had in
this thread :
- we won't used tabs as separators in order to remain consistent with
the existing log format (especially since this new format will only be
an extension of the HTTP one)
- the date format won't change right now, it is a whole new subject
- the logged lines will all have the same "date+process_name+pid" prefix
as the already existing logs
- the HTTP log format won't be touched yet, changing it would be a whole
new subject as well
The log would then be as follows :
>>> Jul 1 18:11:31 haproxy[143338]: 127.0.0.1:37740
[01/Jul/2021:18:11:31.517] \
ssl_frontend~ ssl_frontend/s2 0/0/0/7/+7 200 2750 - - ---- \
1/1/1/1/0 0/0 {1wt.eu} {} "GET /index.html HTTP/1.1 \
0/0/0/0 TLSv1.3/TLS_AES_256_GCM_SHA384
Field Format Extract from the
example above
1 process_name '[' pid ']:' haproxy[143338]:
2 client_ip ':' client_port 127.0.0.1:37740
3 '[' request_date ']' [01/Jul/2021:18:11:31.517]
4 frontend_name ssl_frontend~
5 backend_name '/' server_name ssl_frontend/s2
6 TR '/' Tw '/' Tc '/' Tr '/' Ta*
0/0/0/7/+7
7 status_code 200
8 bytes_read* 2750
9 captured_request_cookie -
10 captured_response_cookie -
11 termination_state ----
12 actconn '/' feconn '/' beconn '/' srv_conn '/' retries*
1/1/1/1/0
13 srv_queue '/'
backend_queue 0/0
14 '{' captured_request_headers* '}' {haproxy.1wt.eu}
15 '{' captured_response_headers*
'}' {}
16 '"' http_request '"' "GET /index.html
HTTP/1.1"
17 *conn_status '/' SSL fe hsk error '/' SSL vfy '/' SSL CA vfy*
0/0/0/0
18 *ssl_version '/' ssl_ciphers* TLSv1.3/TLS_AES_256_GCM_SHA384
and the corresponding log-format :
%ci:%cp [%tr] %ft %b/%s %TR/%Tw/%Tc/%Tr/%Ta %ST %B %CC \
%CS %tsc %ac/%fc/%bc/%sc/%rc %sq/%bq %hr %hs %{+Q}r \
*%[conn_err_code]/%[ssl_fc_hsk_err]/%[ssl_c_err]/%[ssl_c_ca_err]* \
*%sslv/%sslc*
Thanks
Rémi
