]> git.ipfire.org Git - thirdparty/haproxy.git/commitdiff
MAJOR: log: implement proper postparsing for logformat expressions
authorAurelien DARRAGON <adarragon@haproxy.com>
Fri, 23 Feb 2024 16:26:32 +0000 (17:26 +0100)
committerAurelien DARRAGON <adarragon@haproxy.com>
Thu, 4 Apr 2024 17:10:01 +0000 (19:10 +0200)
This patch tries to address a design flaw with how logformat expressions
are parsed from config. Indeed, some parse_logformat_string() calls are
performed during config parsing when the proxy mode is not yet known.

Here's a config example that illustrates the issue:

  defaults
     mode tcp

  listen test
     bind :8888
     http-response set-header custom-hdr "%trl" # needs http
     mode http

The above config should work, because the effective proxy mode is http,
yet haproxy fails with this error:

  [ALERT]    (99051) : config : parsing [repro.conf:6] : error detected in proxy 'test' while parsing 'http-response set-header' rule : format tag 'trl' is reserved for HTTP mode.

To fix the issue once and for all, let's implement smart postparsing for
logformat expressions encountered during config parsing:

  - split parse_logformat_string() (and subfonctions) in order to create a
    new lf_expr_postcheck() function that must be called to finish
    preparing and checking the logformat expression once the proxy type is
    known.
  - save some config hints info during parse_logformat_string() to
    generate more precise error messages during lf_expr_postcheck(), if
    needed, we rely on curpx->conf.args.{file,line} hints for that because
    parse_logformat_string() doesn't know about current file and line
    number.
  - lf_expr_postcheck() uses PR_FL_CHECKED proxy flag to know if the
    function may try to make the proxy compatible with the expression, or
    if it should simply fail as soon as an incompatibility is detected.
  - if parse_logformat_string() is called from an unchecked proxy, then
    schedule the expression for postparsing, else (ie: during runtime),
    run the postcheck right away.

This change will also allow for some logformat expression error handling
simplifications in the future.

include/haproxy/log-t.h
include/haproxy/log.h
include/haproxy/proxy-t.h
src/http_act.c
src/http_client.c
src/http_htx.c
src/http_rules.c
src/log.c
src/proxy.c
src/vars.c

index d9d41f5348f430f1de9c4e6dc91a2650a3372759..bf1ac2c87fde0895e8f10cc1d3dbb2ea2bcadd3b 100644 (file)
@@ -170,7 +170,12 @@ struct logformat_node {
 
 /* a full logformat expr made of one or multiple logformat nodes */
 struct lf_expr {
-       struct list nodes; /* logformat_node list */
+       struct list list;   /* to store lf_expr inside a list */
+       struct list nodes;  /* logformat_node list */
+       struct {
+               char *file; /* file where the lft appears */
+               int line;   /* line where the lft appears */
+       } conf; // parsing hints
 };
 
 /* Range of indexes for log sampling. */
index b0e87ccf9d4432577d1fa55baf2baefe06ecff22..3b9678c32652ff328f5464c6e763b6d0e9607835 100644 (file)
@@ -71,6 +71,7 @@ static inline int lf_expr_isempty(const struct lf_expr *expr)
 {
        return LIST_ISEMPTY(&expr->nodes);
 }
+int lf_expr_postcheck(struct lf_expr *lf_expr, struct proxy *px, char **err);
 
 /* Deinitialize log buffers used for syslog messages */
 void free_logformat_list(struct list *fmt);
index f387093ebc92c7ca3eb828a4587dea4235511de6..08ec3ec003360f6ca1876b709ea86a7ee7bde55c 100644 (file)
@@ -439,6 +439,7 @@ struct proxy {
                char *error_logformat_string;
                char *elfs_file;
                int elfs_line;
+               struct list lf_checks;          /* list of logformats found in the proxy section that needs to be checked during postparse */
        } conf;                                 /* config information */
        struct http_ext *http_ext;              /* http ext options */
        struct eb_root used_server_addr;        /* list of server addresses in use */
index e6a4390b7e0762b832a4df2c8e5243f8d6aef819..3a902ab352d3c5858c06d81d6baa74e34efbb47c 100644 (file)
@@ -1522,10 +1522,6 @@ static enum act_parse_ret parse_http_set_header(const char **args, int *orig_arg
                return ACT_RET_PRS_ERR;
        }
 
-       free(px->conf.lfs_file);
-       px->conf.lfs_file = strdup(px->conf.args.file);
-       px->conf.lfs_line = px->conf.args.line;
-
        /* some characters are totally forbidden in header names and
         * may happen by accident when writing configs, causing strange
         * failures in field. Better catch these ones early, nobody will
@@ -1654,10 +1650,6 @@ static enum act_parse_ret parse_http_replace_header(const char **args, int *orig
                return ACT_RET_PRS_ERR;
        }
 
-       free(px->conf.lfs_file);
-       px->conf.lfs_file = strdup(px->conf.args.file);
-       px->conf.lfs_line = px->conf.args.line;
-
        *orig_arg = cur_arg + 1;
        return ACT_RET_PRS_OK;
 }
@@ -1975,10 +1967,6 @@ static enum act_parse_ret parse_http_set_map(const char **args, int *orig_arg, s
                }
        }
 
-       free(px->conf.lfs_file);
-       px->conf.lfs_file = strdup(px->conf.args.file);
-       px->conf.lfs_line = px->conf.args.line;
-
        *orig_arg = cur_arg + 1;
        return ACT_RET_PRS_OK;
 }
index e329954446f14402a4f4ff681f48d9b116d496e8..d8d9654a2152d8a26a476e9819b3df0621c0579f 100644 (file)
@@ -1335,13 +1335,34 @@ err:
  */
 static int httpclient_precheck()
 {
+       int err_code = ERR_NONE;
+       char *errmsg = NULL;
+
        /* initialize the default httpclient_proxy which is used for the CLI and the lua */
 
        httpclient_proxy = httpclient_create_proxy("<HTTPCLIENT>");
        if (!httpclient_proxy)
                return ERR_RETRYABLE;
+       if (httpclient_proxy->conf.logformat_string) {
+               httpclient_proxy->conf.args.ctx = ARGC_LOG;
+               if (!parse_logformat_string(httpclient_proxy->conf.logformat_string,
+                                           httpclient_proxy, &httpclient_proxy->logformat,
+                                           LOG_OPT_MANDATORY|LOG_OPT_MERGE_SPACES,
+                                           SMP_VAL_FE_LOG_END, &errmsg)) {
+                       memprintf(&errmsg, "failed to parse log-format : %s.", errmsg);
+                       err_code |= ERR_ALERT | ERR_FATAL;
+                       goto err;
+               }
+               httpclient_proxy->conf.args.file = NULL;
+               httpclient_proxy->conf.args.line = 0;
+       }
 
-       return ERR_NONE;
+ err:
+       if (err_code & ERR_CODE) {
+               ha_alert("httpclient: failed to initialize: %s\n", errmsg);
+               free(errmsg);
+       }
+       return err_code;
 }
 
 /* Initialize the logs for every proxy dedicated to the httpclient */
@@ -1372,18 +1393,6 @@ static int httpclient_postcheck_proxy(struct proxy *curproxy)
                }
                LIST_APPEND(&curproxy->loggers, &node->list);
        }
-       if (curproxy->conf.logformat_string) {
-               curproxy->conf.args.ctx = ARGC_LOG;
-               if (!parse_logformat_string(curproxy->conf.logformat_string, curproxy, &curproxy->logformat,
-                                           LOG_OPT_MANDATORY|LOG_OPT_MERGE_SPACES,
-                                           SMP_VAL_FE_LOG_END, &errmsg)) {
-                       memprintf(&errmsg, "failed to parse log-format : %s.", errmsg);
-                       err_code |= ERR_ALERT | ERR_FATAL;
-                       goto err;
-               }
-               curproxy->conf.args.file = NULL;
-               curproxy->conf.args.line = 0;
-       }
 
 #ifdef USE_OPENSSL
        /* initialize the SNI for the SSL servers */
index 2cd738f77b40e5734d835da45e07b27c3a7d4cfb..405b688b6b25543cd505249623b7e0242895c8a8 100644 (file)
@@ -1718,9 +1718,6 @@ struct http_reply *http_parse_http_reply(const char **args, int *orig_arg, struc
                        if (!parse_logformat_string(args[cur_arg+1], px, &hdr->value, LOG_OPT_HTTP, cap, errmsg))
                                goto error;
 
-                       free(px->conf.lfs_file);
-                       px->conf.lfs_file = strdup(px->conf.args.file);
-                       px->conf.lfs_line = px->conf.args.line;
                        cur_arg += 2;
                }
                else
@@ -1804,10 +1801,6 @@ struct http_reply *http_parse_http_reply(const char **args, int *orig_arg, struc
                }
                if (!parse_logformat_string(obj, px, &reply->body.fmt, LOG_OPT_HTTP, cap, errmsg))
                        goto error;
-
-               free(px->conf.lfs_file);
-               px->conf.lfs_file = strdup(px->conf.args.file);
-               px->conf.lfs_line = px->conf.args.line;
        }
 
        free(obj);
index b1f60c2e76b7770d8ba6278700caf25c6577ae54..6ceacdf7eec64551bb746fa0695f622dfa6c6fc6 100644 (file)
@@ -466,9 +466,6 @@ struct redirect_rule *http_parse_redirect_rule(const char *file, int linenum, st
                        if (!parse_logformat_string(destination, curproxy, &rule->rdr_fmt, LOG_OPT_HTTP, cap, errmsg)) {
                                goto err;
                        }
-                       free(curproxy->conf.lfs_file);
-                       curproxy->conf.lfs_file = strdup(curproxy->conf.args.file);
-                       curproxy->conf.lfs_line = curproxy->conf.args.line;
                }
        }
 
index 86a2edbd680f01c4b02561fc9d22ab280109d2ca..28e1c5655ce29ce5858216157e3871881b60f4c7 100644 (file)
--- a/src/log.c
+++ b/src/log.c
@@ -304,9 +304,11 @@ struct logformat_tag_args tag_args_list[] = {
  */
 int prepare_addrsource(struct logformat_node *node, struct proxy *curproxy)
 {
-       curproxy->options2 |= PR_O2_SRC_ADDR;
+       if ((curproxy->flags & PR_FL_CHECKED))
+               return 0;
 
-       return 0;
+       curproxy->options2 |= PR_O2_SRC_ADDR;
+       return 1;
 }
 
 
@@ -379,40 +381,29 @@ int parse_logformat_tag(char *arg, int arg_len, char *name, int name_len, int ty
        for (j = 0; logformat_tags[j].name; j++) { // search a log type
                if (strlen(logformat_tags[j].name) == tag_len &&
                    strncmp(tag, logformat_tags[j].name, tag_len) == 0) {
-                       if (logformat_tags[j].mode != PR_MODE_HTTP || curproxy->mode == PR_MODE_HTTP) {
-                               node = calloc(1, sizeof(*node));
-                               if (!node) {
-                                       memprintf(err, "out of memory error");
+                       node = calloc(1, sizeof(*node));
+                       if (!node) {
+                               memprintf(err, "out of memory error");
+                               goto error_free;
+                       }
+                       node->type = LOG_FMT_TAG;
+                       node->tag = &logformat_tags[j];
+                       node->typecast = typecast;
+                       if (name)
+                               node->name = my_strndup(name, name_len);
+                       node->options = *defoptions;
+                       if (arg_len) {
+                               node->arg = my_strndup(arg, arg_len);
+                               if (!parse_logformat_tag_args(node->arg, node, err))
                                        goto error_free;
-                               }
-                               node->type = LOG_FMT_TAG;
-                               node->tag = &logformat_tags[j];
-                               node->typecast = typecast;
-                               if (name)
-                                       node->name = my_strndup(name, name_len);
-                               node->options = *defoptions;
-                               if (arg_len) {
-                                       node->arg = my_strndup(arg, arg_len);
-                                       if (!parse_logformat_tag_args(node->arg, node, err))
-                                               goto error_free;
-                               }
-                               if (node->tag->type == LOG_FMT_GLOBAL) {
-                                       *defoptions = node->options;
-                                       free_logformat_node(node);
-                               } else {
-                                       if (logformat_tags[j].config_callback &&
-                                           logformat_tags[j].config_callback(node, curproxy) != 0) {
-                                               goto error_free;
-                                       }
-                                       curproxy->to_log |= logformat_tags[j].lw;
-                                       LIST_APPEND(list_format, &node->list);
-                               }
-                               return 1;
+                       }
+                       if (node->tag->type == LOG_FMT_GLOBAL) {
+                               *defoptions = node->options;
+                               free_logformat_node(node);
                        } else {
-                               memprintf(err, "format tag '%s' is reserved for HTTP mode",
-                                         logformat_tags[j].name);
-                               goto error_free;
+                               LIST_APPEND(list_format, &node->list);
                        }
+                       return 1;
                }
        }
 
@@ -527,17 +518,6 @@ int add_sample_to_logformat_list(char *text, char *name, int name_len, int typec
                           curpx->conf.args.file, curpx->conf.args.line, text);
        }
 
-       /* check if we need to allocate an http_txn struct for HTTP parsing */
-       /* Note, we may also need to set curpx->to_log with certain fetches */
-       curpx->http_needed |= !!(expr->fetch->use & SMP_USE_HTTP_ANY);
-
-       /* FIXME: temporary workaround for missing LW_XPRT and LW_REQ flags
-        * needed with some sample fetches (eg: ssl*). We always set it for
-        * now on, but this will leave with sample capabilities soon.
-        */
-       curpx->to_log |= LW_XPRT;
-       if (curpx->http_needed)
-               curpx->to_log |= LW_REQ;
        LIST_APPEND(list_format, &node->list);
        return 1;
 
@@ -547,7 +527,10 @@ int add_sample_to_logformat_list(char *text, char *name, int name_len, int typec
 }
 
 /*
- * Parse the log_format string and fill a linked list.
+ * Parse the log_format string and fill a logformat expression. The logformat
+ * expression will be scheduled for postcheck on the proxy unless the proxy was
+ * already checked, in which case all checks will be performed right away.
+ *
  * Tag name are preceded by % and composed by characters [a-zA-Z0-9]* : %tagname
  * You can set arguments using { } : %{many arguments}tagname.
  * The curproxy->conf.args.ctx must be set by the caller.
@@ -579,11 +562,18 @@ int parse_logformat_string(const char *fmt, struct proxy *curproxy, struct lf_ex
                memprintf(err, "out of memory error");
                return 0;
        }
-       curproxy->to_log |= LW_INIT;
 
        /* reset the old expr first (if previously defined) */
        lf_expr_deinit(lf_expr);
 
+       /* Save some parsing infos to raise relevant error messages during
+        * postparsing if needed.
+        */
+       if (curproxy->conf.args.file) {
+               lf_expr->conf.file = strdup(curproxy->conf.args.file);
+               lf_expr->conf.line = curproxy->conf.args.line;
+       }
+
        for (cformat = LF_INIT; cformat != LF_END; str++) {
                pformat = cformat;
 
@@ -760,14 +750,123 @@ int parse_logformat_string(const char *fmt, struct proxy *curproxy, struct lf_ex
                memprintf(err, "truncated line after '%s'", tag ? tag : arg ? arg : "%");
                goto fail;
        }
-       free(backfmt);
+       ha_free(&backfmt);
+
+       if (!(curproxy->flags & PR_FL_CHECKED)) {
+               /* add the lf_expr to the proxy checks to delay postparsing
+                * since config-related proxy properties are not stable yet
+                */
+               LIST_APPEND(&curproxy->conf.lf_checks, &lf_expr->list);
+       }
+       else {
+               /* probably called during runtime or with proxy already checked,
+                * perform the postcheck right away
+                */
+               if (!lf_expr_postcheck(lf_expr, curproxy, err))
+                       goto fail;
+       }
+
+       return 1;
+ fail:
+       ha_free(&backfmt);
+       return 0;
+}
+
+/* Performs a postparsing check on logformat expression <expr> for a given <px>
+ * proxy. The function will behave differently depending on the proxy state
+ * (during parsing we will try to adapt proxy configuration to make it
+ * compatible with logformat expression, but once the proxy is checked, we fail
+ * as soon as we face incompatibilities)
+ *
+ * It returns 1 on success and 0 on error, <err> will be set in case of error.
+ */
+int lf_expr_postcheck(struct lf_expr *lf_expr, struct proxy *px, char **err)
+{
+       struct logformat_node *lf;
+
+       if (!(px->flags & PR_FL_CHECKED))
+               px->to_log |= LW_INIT;
+
+       list_for_each_entry(lf, &lf_expr->nodes, list) {
+               if (lf->type == LOG_FMT_EXPR) {
+                       struct sample_expr *expr = lf->expr;
+                       uint8_t http_needed = !!(expr->fetch->use & SMP_USE_HTTP_ANY);
+
+                       if ((px->flags & PR_FL_CHECKED)) {
+                               /* fail as soon as proxy properties are not compatible */
+                               if (http_needed && !px->http_needed) {
+                                       memprintf(err, "sample fetch '%s' requires HTTP enabled proxy which is not available here",
+                                                 expr->fetch->kw);
+                                       goto fail;
+                               }
+                               continue;
+                       }
+                       /* check if we need to allocate an http_txn struct for HTTP parsing */
+                       /* Note, we may also need to set curpx->to_log with certain fetches */
+                       px->http_needed |= http_needed;
+
+                       /* FIXME: temporary workaround for missing LW_XPRT and LW_REQ flags
+                        * needed with some sample fetches (eg: ssl*). We always set it for
+                        * now on, but this will leave with sample capabilities soon.
+                        */
+                       px->to_log |= LW_XPRT;
+                       if (px->http_needed)
+                               px->to_log |= LW_REQ;
+               }
+               else if (lf->type == LOG_FMT_TAG) {
+                       if (lf->tag->mode == PR_MODE_HTTP && px->mode != PR_MODE_HTTP) {
+                               memprintf(err, "format tag '%s' is reserved for HTTP mode",
+                                         lf->tag->name);
+                               goto fail;
+                       }
+                       if (lf->tag->config_callback &&
+                           !lf->tag->config_callback(lf, px)) {
+                               memprintf(err, "cannot configure format tag '%s' in this context",
+                                         lf->tag->name);
+                               goto fail;
+                       }
+                       if (!(px->flags & PR_FL_CHECKED))
+                               px->to_log |= lf->tag->lw;
+               }
+       }
+       if ((px->to_log & (LW_REQ | LW_RESP)) &&
+           (px->mode != PR_MODE_HTTP && !(px->options & PR_O_HTTP_UPG))) {
+               memprintf(err, "logformat expression not usable here (at least one node depends on HTTP mode)");
+               goto fail;
+       }
 
        return 1;
  fail:
-       free(backfmt);
        return 0;
 }
 
+/* postparse logformats defined at <px> level */
+static int postcheck_logformat_proxy(struct proxy *px)
+{
+       char *err = NULL;
+       struct lf_expr *lf_expr, *back_lf;
+       int err_code = ERR_NONE;
+
+       list_for_each_entry_safe(lf_expr, back_lf, &px->conf.lf_checks, list) {
+               if (!lf_expr_postcheck(lf_expr, px, &err))
+                       err_code |= ERR_FATAL | ERR_ALERT;
+               /* check performed, ensure it doesn't get checked twice */
+               LIST_DEL_INIT(&lf_expr->list);
+               if (err_code & ERR_CODE)
+                       break;
+       }
+
+       if (err) {
+               memprintf(&err, "error detected while postparsing logformat expression used by %s '%s' : %s", proxy_type_str(px), px->id, err);
+               if (lf_expr->conf.file)
+                       memprintf(&err, "parsing [%s:%d] : %s.\n", lf_expr->conf.file, lf_expr->conf.line, err);
+               ha_alert("%s", err);
+               ha_free(&err);
+       }
+
+       return err_code;
+}
+
 /*
  * Parse the first range of indexes from a string made of a list of comma separated
  * ranges of indexes. Note that an index may be considered as a particular range
@@ -2599,12 +2698,19 @@ void free_logformat_list(struct list *fmt)
 void lf_expr_init(struct lf_expr *expr)
 {
        LIST_INIT(&expr->nodes);
+       LIST_INIT(&expr->list);
+       expr->conf.file = NULL;
+       expr->conf.line = 0;
 }
 
 /* Releases and resets a log-format expression */
 void lf_expr_deinit(struct lf_expr *expr)
 {
        free_logformat_list(&expr->nodes);
+       free(expr->conf.file);
+       /* remove from parent list (if any) */
+       LIST_DEL_INIT(&expr->list);
+
        lf_expr_init(expr);
 }
 
@@ -2619,11 +2725,19 @@ void lf_expr_xfer(struct lf_expr *src, struct lf_expr *dst)
        lf_expr_deinit(dst);
 
        /* then proceed with transfer between <src> and <dst> */
+       dst->conf.file = src->conf.file;
+       dst->conf.line = src->conf.line;
        list_for_each_entry_safe(lf, lfb, &src->nodes, list) {
                LIST_DELETE(&lf->list);
                LIST_APPEND(&dst->nodes, &lf->list);
        }
 
+       /* replace <src> with <dst> in <src>'s list by first adding
+        * <dst> after <src>, then removing <src>...
+        */
+       LIST_INSERT(&src->list, &dst->list);
+       LIST_DEL_INIT(&src->list);
+
        /* src is now empty, perform an explicit reset */
        lf_expr_init(src);
 }
@@ -4654,6 +4768,7 @@ static int postresolve_loggers()
 REGISTER_CONFIG_SECTION("log-forward", cfg_parse_log_forward, NULL);
 REGISTER_POST_CHECK(postresolve_loggers);
 REGISTER_POST_PROXY_CHECK(postcheck_log_backend);
+REGISTER_POST_PROXY_CHECK(postcheck_logformat_proxy);
 
 REGISTER_PER_THREAD_ALLOC(init_log_buffers);
 REGISTER_PER_THREAD_FREE(deinit_log_buffers);
index 9002954c530efbdf88a03c60c1bf5e9ed31afc8e..20fc15601b3f4ed6ac1bae47f9609636ca7ce204 100644 (file)
@@ -1279,12 +1279,6 @@ int proxy_cfg_ensure_no_http(struct proxy *curproxy)
                ha_warning("Layer 7 hash not possible for %s '%s' (needs 'mode http'). Falling back to round robin.\n",
                           proxy_type_str(curproxy), curproxy->id);
        }
-       if (curproxy->to_log & (LW_REQ | LW_RESP)) {
-               curproxy->to_log &= ~(LW_REQ | LW_RESP);
-               ha_warning("parsing [%s:%d] : HTTP log/header format not usable with %s '%s' (needs 'mode http').\n",
-                          curproxy->conf.lfs_file, curproxy->conf.lfs_line,
-                          proxy_type_str(curproxy), curproxy->id);
-       }
        if (curproxy->conf.logformat_string == default_http_log_format ||
            curproxy->conf.logformat_string == clf_http_log_format) {
                /* Note: we don't change the directive's file:line number */
@@ -1356,6 +1350,7 @@ void init_new_proxy(struct proxy *p)
        LIST_INIT(&p->conf.listeners);
        LIST_INIT(&p->conf.errors);
        LIST_INIT(&p->conf.args.list);
+       LIST_INIT(&p->conf.lf_checks);
        LIST_INIT(&p->filter_configs);
        LIST_INIT(&p->tcpcheck_rules.preset_vars);
 
index 6447818edf96e547112aa34878b262c54e383706..9f706cff4ab2f5ecce7049ad50a7c7200411930a 100644 (file)
@@ -1022,11 +1022,6 @@ static enum act_parse_ret parse_store(const char **args, int *arg, struct proxy
                        return ACT_RET_PRS_ERR;
 
                (*arg)++;
-
-               /* for late error reporting */
-               free(px->conf.lfs_file);
-               px->conf.lfs_file = strdup(px->conf.args.file);
-               px->conf.lfs_line = px->conf.args.line;
        } else {
                /* set-var */
                rule->arg.vars.expr = sample_parse_expr((char **)args, arg, px->conf.args.file,
@@ -1065,6 +1060,7 @@ static int vars_parse_global_set_var(char **args, int section_type, struct proxy
        struct proxy px = {
                .id = "CFG",
                .conf.args = { .file = file, .line = line, },
+               .flags = PR_FL_CHECKED,
        };
        struct act_rule rule = {
                .arg.vars.scope = SCOPE_PROC,
@@ -1185,6 +1181,7 @@ static int vars_parse_cli_set_var(char **args, char *payload, struct appctx *app
        struct proxy px = {
                .id = "CLI",
                .conf.args = { .file = "CLI", .line = 0, },
+               .flags = PR_FL_CHECKED,
        };
        struct act_rule rule = {
                .arg.vars.scope = SCOPE_PROC,