From 7a21c3a4ef1577985621953a79e2776ef97837ab Mon Sep 17 00:00:00 2001 From: Aurelien DARRAGON Date: Fri, 23 Feb 2024 17:26:32 +0100 Subject: [PATCH] MAJOR: log: implement proper postparsing for logformat expressions 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 | 7 +- include/haproxy/log.h | 1 + include/haproxy/proxy-t.h | 1 + src/http_act.c | 12 --- src/http_client.c | 35 ++++--- src/http_htx.c | 7 -- src/http_rules.c | 3 - src/log.c | 211 +++++++++++++++++++++++++++++--------- src/proxy.c | 7 +- src/vars.c | 7 +- 10 files changed, 196 insertions(+), 95 deletions(-) diff --git a/include/haproxy/log-t.h b/include/haproxy/log-t.h index d9d41f5348..bf1ac2c87f 100644 --- a/include/haproxy/log-t.h +++ b/include/haproxy/log-t.h @@ -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. */ diff --git a/include/haproxy/log.h b/include/haproxy/log.h index b0e87ccf9d..3b9678c326 100644 --- a/include/haproxy/log.h +++ b/include/haproxy/log.h @@ -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); diff --git a/include/haproxy/proxy-t.h b/include/haproxy/proxy-t.h index f387093ebc..08ec3ec003 100644 --- a/include/haproxy/proxy-t.h +++ b/include/haproxy/proxy-t.h @@ -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 */ diff --git a/src/http_act.c b/src/http_act.c index e6a4390b7e..3a902ab352 100644 --- a/src/http_act.c +++ b/src/http_act.c @@ -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; } diff --git a/src/http_client.c b/src/http_client.c index e329954446..d8d9654a21 100644 --- a/src/http_client.c +++ b/src/http_client.c @@ -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(""); 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 */ diff --git a/src/http_htx.c b/src/http_htx.c index 2cd738f77b..405b688b6b 100644 --- a/src/http_htx.c +++ b/src/http_htx.c @@ -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); diff --git a/src/http_rules.c b/src/http_rules.c index b1f60c2e76..6ceacdf7ee 100644 --- a/src/http_rules.c +++ b/src/http_rules.c @@ -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; } } diff --git a/src/log.c b/src/log.c index 86a2edbd68..28e1c5655c 100644 --- 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 for a given + * 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, 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 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 and */ + 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 with in 's list by first adding + * after , then removing ... + */ + 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); diff --git a/src/proxy.c b/src/proxy.c index 9002954c53..20fc15601b 100644 --- a/src/proxy.c +++ b/src/proxy.c @@ -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); diff --git a/src/vars.c b/src/vars.c index 6447818edf..9f706cff4a 100644 --- a/src/vars.c +++ b/src/vars.c @@ -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, -- 2.39.5