MEDIUM: log: add the client's SNI to the default HTTPS log format

During a troublehooting it came obvious that the SNI always ought to
be logged on httpslog, as it explains errors caused by selection of
the default certificate (or failure to do so in case of strict-sni).

This expectation was also confirmed on the mailing list.

Since the field may be empty it appeared important not to leave an
empty string in the current format, so it was decided to place the
field before a '/' preceding the SSL version and ciphers, so that
in the worst case a missing field leads to a field looking like
"/TLSv1.2/AES...", though usually a missing element still results
in a "-" in logs.

This will change the log format for users who already deployed the
2.5-dev versions (hence the medium level) but no released version
was using this format yet so there's no harm for stable deployments.
The reg-test was updated to check for "-" there since we don't send
SNI in reg-tests.

Link: https://www.mail-archive.com/haproxy@formilux.org/msg41410.html
Cc: William Lallemand <wlallemand@haproxy.org>
This commit is contained in:
Willy Tarreau 2021-11-05 19:14:55 +01:00
parent 579259d150
commit 68574dd492
3 changed files with 17 additions and 9 deletions

View File

@ -21268,7 +21268,7 @@ if required. Refer to section 8.2.5 "Custom log format" to see how to use this:
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 \
%[fc_err]/%[ssl_fc_err,hex]/%[ssl_c_err]/\
%[ssl_c_ca_err]/%[ssl_fc_is_resumed] %sslv/%sslc"
%[ssl_c_ca_err]/%[ssl_fc_is_resumed] %[ssl_fc_sni]/%sslv/%sslc"
This format is basically the HTTP one (see section 8.2.3) with new fields
appended to it. The new fields (lines 17 and 18) will be detailed here. For the
@ -21288,7 +21288,8 @@ HTTP ones, refer to the HTTP section.
>>> Feb 6 12:14:14 localhost \
haproxy[14389]: 10.0.1.2:33317 [06/Feb/2009:12:14:14.655] https-in \
static/srv1 10/0/30/69/109 200 2750 - - ---- 1/1/1/1/0 0/0 {1wt.eu} \
{} "GET /index.html HTTP/1.1" 0/0/0/0/0 TLSv1.3/TLS_AES_256_GCM_SHA384
{} "GET /index.html HTTP/1.1" 0/0/0/0/0 \
1wt.eu/TLSv1.3/TLS_AES_256_GCM_SHA384
Field Format Extract from the example above
1 process_name '[' pid ']:' haproxy[14389]:
@ -21309,7 +21310,8 @@ HTTP ones, refer to the HTTP section.
16 '"' http_request '"' "GET /index.html HTTP/1.1"
17 fc_err '/' ssl_fc_err '/' ssl_c_err
'/' ssl_c_ca_err '/' ssl_fc_is_resumed 0/0/0/0/0
18 ssl_version '/' ssl_ciphers TLSv1.3/TLS_AES_256_GCM_SHA384
18 ssl_fc_sni '/' ssl_version
'/' ssl_ciphers 1wt.eu/TLSv1.3/TLS_AES_256_GCM_SHA384
Detailed fields description :
- "fc_err" is the status of the connection on the frontend's side. It
@ -21336,6 +21338,12 @@ Detailed fields description :
the stateful cache or a stateless ticket. Don't forgot that a TLS session
can be shared by multiple requests.
- "ssl_fc_sni" is the SNI (Server Name Indication) presented by the client
to select the certificate to be used. It usually matches the host name for
the first request of a connection. An absence of this field may indicate
that the SNI was not sent by the client, and will lead haproxy to use the
default certificate, or to reject the connection in case of strict-sni.
- "ssl_version" is the SSL version of the frontend.
- "ssl_ciphers" is the SSL cipher used for the connection.

View File

@ -63,24 +63,24 @@ syslog Slg_cust_fmt -level info {
syslog Slg_https_fmt -level info {
recv
expect ~ ".*https_logfmt_ssl_lst~ https_logfmt_ssl_lst/s1.*0/0000000000000000/0/0/.? TLSv1.2/AES256-GCM-SHA384"
expect ~ ".*https_logfmt_ssl_lst~ https_logfmt_ssl_lst/s1.*0/0000000000000000/0/0/.? -/TLSv1.2/AES256-GCM-SHA384"
barrier b1 sync
} -start
syslog Slg_https_fmt_err -level info {
recv
expect ~ "ERROR.*https_logfmt_ssl_lst~ https_logfmt_ssl_lst/<NOSRV>.*30/0000000000000086/0/2/.? TLSv1.2/\\(NONE\\)"
expect ~ "ERROR.*https_logfmt_ssl_lst~ https_logfmt_ssl_lst/<NOSRV>.*30/0000000000000086/0/2/.? -/TLSv1.2/\\(NONE\\)"
barrier b1 sync
recv
expect ~ "ERROR.*https_logfmt_ssl_lst~ https_logfmt_ssl_lst/<NOSRV>.*31/0000000000000086/20/0/.? TLSv1.2/\\(NONE\\)"
expect ~ "ERROR.*https_logfmt_ssl_lst~ https_logfmt_ssl_lst/<NOSRV>.*31/0000000000000086/20/0/.? -/TLSv1.2/\\(NONE\\)"
barrier b1 sync
recv
expect ~ "ERROR.*https_logfmt_ssl_lst~ https_logfmt_ssl_lst/<NOSRV>.*34/00000000000000C1/0/0/.? TLSv1.2/\\(NONE\\)"
expect ~ "ERROR.*https_logfmt_ssl_lst~ https_logfmt_ssl_lst/<NOSRV>.*34/00000000000000C1/0/0/.? -/TLSv1.2/\\(NONE\\)"
} -start
syslog Slg_logconnerror -level info {
@ -214,7 +214,7 @@ haproxy h1 -conf {
option log-separate-errors
mode http
option httpslog
error-log-format "ERROR %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 %[fc_err]/%[ssl_fc_err,and(proc.ssl_error_mask),hex]/%[ssl_c_err]/%[ssl_c_ca_err]/%[ssl_fc_is_resumed] %sslv/%sslc"
error-log-format "ERROR %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 %[fc_err]/%[ssl_fc_err,and(proc.ssl_error_mask),hex]/%[ssl_c_err]/%[ssl_c_ca_err]/%[ssl_fc_is_resumed] %[ssl_fc_sni]/%sslv/%sslc"
bind "${tmpdir}/https_logfmt_ssl.sock" ssl crt ${testdir}/set_cafile_server.pem ca-verify-file ${testdir}/set_cafile_rootCA.crt ca-file ${testdir}/set_cafile_interCA1.crt verify required ciphers "kRSA"
server s1 ${s1_addr}:${s1_port}

View File

@ -195,7 +195,7 @@ static const struct logformat_type logformat_keywords[] = {
};
char default_http_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"; // default format
char default_https_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 %[fc_err]/%[ssl_fc_err,hex]/%[ssl_c_err]/%[ssl_c_ca_err]/%[ssl_fc_is_resumed] %sslv/%sslc";
char default_https_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 %[fc_err]/%[ssl_fc_err,hex]/%[ssl_c_err]/%[ssl_c_ca_err]/%[ssl_fc_is_resumed] %[ssl_fc_sni]/%sslv/%sslc";
char clf_http_log_format[] = "%{+Q}o %{-Q}ci - - [%trg] %r %ST %B \"\" \"\" %cp %ms %ft %b %s %TR %Tw %Tc %Tr %Ta %tsc %ac %fc %bc %sc %rc %sq %bq %CC %CS %hrl %hsl";
char default_tcp_log_format[] = "%ci:%cp [%t] %ft %b/%s %Tw/%Tc/%Tt %B %ts %ac/%fc/%bc/%sc/%rc %sq/%bq";
char *log_format = NULL;