From 98b930d04329ccedbd85b1862f24e52933ba45e5 Mon Sep 17 00:00:00 2001 From: Remi Tricot-Le Breton Date: Thu, 29 Jul 2021 09:45:52 +0200 Subject: [PATCH] MINOR: ssl: Define a default https log format This patch adds a new httpslog option and a new HTTP over SSL log-format that expands the default HTTP format and adds SSL specific information. --- doc/configuration.txt | 115 +++++++++++++++++++++++++++++++++++++++--- include/haproxy/log.h | 1 + src/cfgparse-listen.c | 50 ++++++++++++++++-- src/log.c | 1 + src/proxy.c | 16 ++++-- 5 files changed, 171 insertions(+), 12 deletions(-) diff --git a/doc/configuration.txt b/doc/configuration.txt index cd40d1cde..710d8112a 100644 --- a/doc/configuration.txt +++ b/doc/configuration.txt @@ -99,8 +99,9 @@ Summary 8.2.1. Default log format 8.2.2. TCP log format 8.2.3. HTTP log format -8.2.4. Custom log format -8.2.5. Error log format +8.2.4. HTTPS log format +8.2.5. Custom log format +8.2.6. Error log format 8.3. Advanced logging options 8.3.1. Disabling logging of external tests 8.3.2. Logging before waiting for the session to terminate @@ -3607,6 +3608,7 @@ option http-use-proxy-header (*) X X X - option httpchk X - X X option httpclose (*) X X X X option httplog X X X - +option httpslog X X X - option independent-streams (*) X X X X option ldap-check X - X X option external-check X - X X @@ -7814,8 +7816,8 @@ log-format the same log format. Please see section 8.2.4 which covers the log format string in depth. - "log-format" directive overrides previous "option tcplog", "log-format" and - "option httplog" directives. + "log-format" directive overrides previous "option tcplog", "log-format", + "option httplog" and "option httpslog" directives. log-format-sd Specifies the RFC5424 structured-data log format string @@ -8855,6 +8857,23 @@ option httplog [ clf ] See also : section 8 about logging. +option httpslog + Enable logging of HTTPS request, session state and timers + May be used in sections : defaults | frontend | listen | backend + yes | yes | yes | no + + By default, the log output format is very poor, as it only contains the + source and destination addresses, and the instance name. By specifying + "option httpslog", each log line turns into a much richer format including, + but not limited to, the HTTP request, the connection timers, the session + status, the connections numbers, the captured headers and cookies, the + frontend, backend and server name, the SSL certificate verification and SSL + handshake statuses, and of course the source address and ports. + + "option httpslog" overrides any previous "log-format" directive. + + See also : section 8 about logging. + option independent-streams no option independent-streams @@ -20739,7 +20758,84 @@ Detailed fields description : is the reason why this field must always remain the last one. -8.2.4. Custom log format +8.2.4. HTTPS log format +---------------------- + +The HTTPS format is the best suited for HTTP over SSL connections. It is an +extension of the HTTP format (see section 8.2.3) to which SSL related +information are added. It is enabled when "option httpslog" is specified in the +frontend. Just like the TCP and HTTP formats, the log is usually emitted at the +end of the session, unless "option logasap" is specified. A session which +matches the "monitor" rules will never logged. It is also possible not to log +sessions for which no data were sent by the client by specifying "option +dontlognull" in the frontend. Successful connections will not be logged if +"option dontlog-normal" is specified in the frontend. + +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 +HTTP ones, refer to the HTTP section. + + Example : + frontend https-in + mode http + option httpslog + log global + bind *:443 ssl crt mycerts/srv.pem ... + default_backend bck + + backend static + server srv1 127.0.0.1:8000 ssl crt mycerts/clt.pem ... + + >>> 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 TLSv1.3/TLS_AES_256_GCM_SHA384 + + Field Format Extract from the example above + 1 process_name '[' pid ']:' haproxy[14389]: + 2 client_ip ':' client_port 10.0.1.2:33317 + 3 '[' request_date ']' [06/Feb/2009:12:14:14.655] + 4 frontend_name https-in + 5 backend_name '/' server_name static/srv1 + 6 TR '/' Tw '/' Tc '/' Tr '/' Ta* 10/0/30/69/109 + 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_fc_hsk_err '/' ssl_c_err '/' ssl_c_ca_err 0/0/0/0 + 18 ssl_version '/' ssl_ciphers TLSv1.3/TLS_AES_256_GCM_SHA384 + +Detailed fields description : + - "conn_status" is the status of the connection on the frontend's side. It + corresponds to the "fc_conn_err" sample fetch. See the "fc_conn_err" and + "fc_conn_err_str" fetches for more information. + + - "ssl_fc_hsk_err" is the status of the SSL handshake from the frontend's + point of view. It will be 0 if everything went well. See the + "ssl_fc_hsk_err" sample fetch's description for more information. + + - "ssl_c_err" is the status of the client's certificate verification process. + The handshake might be successful while having a non-null verification + error code if it is an ignored one. See the "ssl_c_err" sample fetch and + the "crt-ignore-err" option. + + - "ssl_c_ca_err" is the status of the client's certificate chain verification + process. The handshake might be successful while having a non-null + verification error code if it is an ignored one. See the "ssl_c_ca_err" + sample fetch and the "ca-ignore-err" option. + + - "ssl_version" is the SSL version of the frontend. + + - "ssl_ciphers" is the SSL cipher used for the connection. + + +8.2.5. Custom log format ------------------------ The directive log-format allows you to customize the logs in http mode and tcp @@ -20793,6 +20889,13 @@ the default CLF format is defined this way : %ms %ft %b %s %TR %Tw %Tc %Tr %Ta %tsc %ac %fc \ %bc %sc %rc %sq %bq %CC %CS %hrl %hsl" +the default HTTPS format is defined this way : + + 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_conn_err]/%[ssl_fc_hsk_err,hex]/%[ssl_c_err]/%[ssl_c_ca_err] \ + %sslv/%sslc" + and the default TCP format is defined this way : log-format "%ci:%cp [%t] %ft %b/%s %Tw/%Tc/%Tt %B %ts \ @@ -20873,7 +20976,7 @@ Please refer to the table below for currently defined variables : R = Restrictions : H = mode http only ; S = SSL only -8.2.5. Error log format +8.2.6. Error log format ----------------------- When an incoming connection fails due to an SSL handshake or an invalid PROXY diff --git a/include/haproxy/log.h b/include/haproxy/log.h index 8bd448697..4503be428 100644 --- a/include/haproxy/log.h +++ b/include/haproxy/log.h @@ -38,6 +38,7 @@ extern char *log_format; extern char default_tcp_log_format[]; extern char default_http_log_format[]; extern char clf_http_log_format[]; +extern char default_https_log_format[]; extern char default_rfc5424_sd_log_format[]; diff --git a/src/cfgparse-listen.c b/src/cfgparse-listen.c index 483bfa268..bdbb6030a 100644 --- a/src/cfgparse-listen.c +++ b/src/cfgparse-listen.c @@ -2064,6 +2064,8 @@ stats_error_parsing: oldlogformat = "option tcplog"; else if (curproxy->conf.logformat_string == clf_http_log_format) oldlogformat = "option httplog clf"; + else if (curproxy->conf.logformat_string == default_https_log_format) + oldlogformat = "option httpslog"; if (logformat == clf_http_log_format) clflogformat = " clf"; ha_warning("parsing [%s:%d]: 'option httplog%s' overrides previous '%s' in 'defaults' section.\n", @@ -2071,7 +2073,8 @@ stats_error_parsing: } if (curproxy->conf.logformat_string != default_http_log_format && curproxy->conf.logformat_string != default_tcp_log_format && - curproxy->conf.logformat_string != clf_http_log_format) + curproxy->conf.logformat_string != clf_http_log_format && + curproxy->conf.logformat_string != default_https_log_format) free(curproxy->conf.logformat_string); curproxy->conf.logformat_string = logformat; @@ -2095,13 +2098,16 @@ stats_error_parsing: oldlogformat = "option tcplog"; else if (curproxy->conf.logformat_string == clf_http_log_format) oldlogformat = "option httplog clf"; + else if (curproxy->conf.logformat_string == default_https_log_format) + oldlogformat = "option httpslog"; ha_warning("parsing [%s:%d]: 'option tcplog' overrides previous '%s' in 'defaults' section.\n", file, linenum, oldlogformat); } /* generate a detailed TCP log */ if (curproxy->conf.logformat_string != default_http_log_format && curproxy->conf.logformat_string != default_tcp_log_format && - curproxy->conf.logformat_string != clf_http_log_format) + curproxy->conf.logformat_string != clf_http_log_format && + curproxy->conf.logformat_string != default_https_log_format) free(curproxy->conf.logformat_string); curproxy->conf.logformat_string = default_tcp_log_format; @@ -2118,6 +2124,41 @@ stats_error_parsing: err_code |= ERR_WARN; } } + else if (strcmp(args[1], "httpslog") == 0) { + char *logformat; + /* generate a complete HTTP log */ + logformat = default_https_log_format; + if (curproxy->conf.logformat_string && curproxy->cap & PR_CAP_DEF) { + char *oldlogformat = "log-format"; + + if (curproxy->conf.logformat_string == default_http_log_format) + oldlogformat = "option httplog"; + else if (curproxy->conf.logformat_string == default_tcp_log_format) + oldlogformat = "option tcplog"; + else if (curproxy->conf.logformat_string == clf_http_log_format) + oldlogformat = "option httplog clf"; + else if (curproxy->conf.logformat_string == default_https_log_format) + oldlogformat = "option httpslog"; + ha_warning("parsing [%s:%d]: 'option httplog' overrides previous '%s' in 'defaults' section.\n", + file, linenum, oldlogformat); + } + if (curproxy->conf.logformat_string != default_http_log_format && + curproxy->conf.logformat_string != default_tcp_log_format && + curproxy->conf.logformat_string != clf_http_log_format && + curproxy->conf.logformat_string != default_https_log_format) + free(curproxy->conf.logformat_string); + curproxy->conf.logformat_string = logformat; + + free(curproxy->conf.lfs_file); + curproxy->conf.lfs_file = strdup(curproxy->conf.args.file); + curproxy->conf.lfs_line = curproxy->conf.args.line; + + if (!(curproxy->cap & PR_CAP_DEF) && !(curproxy->cap & PR_CAP_FE)) { + ha_warning("parsing [%s:%d] : backend '%s' : 'option httpslog' directive is ignored in backends.\n", + file, linenum, curproxy->id); + err_code |= ERR_WARN; + } + } else if (strcmp(args[1], "tcpka") == 0) { /* enable TCP keep-alives on client and server streams */ if (warnifnotcap(curproxy, PR_CAP_BE | PR_CAP_FE, file, linenum, args[1], NULL)) @@ -2654,12 +2695,15 @@ stats_error_parsing: oldlogformat = "option tcplog"; else if (curproxy->conf.logformat_string == clf_http_log_format) oldlogformat = "option httplog clf"; + else if (curproxy->conf.logformat_string == default_https_log_format) + oldlogformat = "option httpslog"; ha_warning("parsing [%s:%d]: 'log-format' overrides previous '%s' in 'defaults' section.\n", file, linenum, oldlogformat); } if (curproxy->conf.logformat_string != default_http_log_format && curproxy->conf.logformat_string != default_tcp_log_format && - curproxy->conf.logformat_string != clf_http_log_format) + curproxy->conf.logformat_string != clf_http_log_format && + curproxy->conf.logformat_string != default_https_log_format) free(curproxy->conf.logformat_string); curproxy->conf.logformat_string = strdup(args[1]); if (!curproxy->conf.logformat_string) diff --git a/src/log.c b/src/log.c index 2ba645a9f..842e2c950 100644 --- a/src/log.c +++ b/src/log.c @@ -193,6 +193,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_conn_err]/%[ssl_fc_hsk_err,hex]/%[ssl_c_err]/%[ssl_c_ca_err] %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; diff --git a/src/proxy.c b/src/proxy.c index 10762e296..fc5371f69 100644 --- a/src/proxy.c +++ b/src/proxy.c @@ -160,7 +160,8 @@ void free_proxy(struct proxy *p) #endif if (p->conf.logformat_string != default_http_log_format && p->conf.logformat_string != default_tcp_log_format && - p->conf.logformat_string != clf_http_log_format) + p->conf.logformat_string != clf_http_log_format && + p->conf.logformat_string != default_https_log_format) free(p->conf.logformat_string); free(p->conf.lfs_file); @@ -1279,6 +1280,13 @@ int proxy_cfg_ensure_no_http(struct proxy *curproxy) curproxy->conf.lfs_file, curproxy->conf.lfs_line, proxy_type_str(curproxy), curproxy->id); } + else if (curproxy->conf.logformat_string == default_https_log_format) { + /* Note: we don't change the directive's file:line number */ + curproxy->conf.logformat_string = default_tcp_log_format; + ha_warning("parsing [%s:%d] : 'option httpslog' not usable with %s '%s' (needs 'mode http'). Falling back to 'option tcplog'.\n", + curproxy->conf.lfs_file, curproxy->conf.lfs_line, + proxy_type_str(curproxy), curproxy->id); + } return 0; } @@ -1416,7 +1424,8 @@ void proxy_free_defaults(struct proxy *defproxy) if (defproxy->conf.logformat_string != default_http_log_format && defproxy->conf.logformat_string != default_tcp_log_format && - defproxy->conf.logformat_string != clf_http_log_format) { + defproxy->conf.logformat_string != clf_http_log_format && + defproxy->conf.logformat_string != default_https_log_format) { ha_free(&defproxy->conf.logformat_string); } @@ -1639,7 +1648,8 @@ static int proxy_defproxy_cpy(struct proxy *curproxy, const struct proxy *defpro if (curproxy->conf.logformat_string && curproxy->conf.logformat_string != default_http_log_format && curproxy->conf.logformat_string != default_tcp_log_format && - curproxy->conf.logformat_string != clf_http_log_format) + curproxy->conf.logformat_string != clf_http_log_format && + curproxy->conf.logformat_string != default_https_log_format) curproxy->conf.logformat_string = strdup(curproxy->conf.logformat_string); if (defproxy->conf.lfs_file) {