From: Christopher Faulet Date: Thu, 22 Mar 2018 08:08:20 +0000 (+0100) Subject: MINOR: spoe: Add options to store processing times in variables X-Git-Tag: v1.9-dev1~317 X-Git-Url: http://git.ipfire.org/?a=commitdiff_plain;h=36bda1cd4ae49724d37cc6cf24729d4303fb10cc;p=thirdparty%2Fhaproxy.git MINOR: spoe: Add options to store processing times in variables "set-process-time" and "set-total-time" options have been added to store processing times in the transaction scope, at each event and group processing, the current one and the total one. So it is possible to get them. TODO: documentation --- diff --git a/doc/SPOE.txt b/doc/SPOE.txt index 8cbf6845a1..ce119dc493 100644 --- a/doc/SPOE.txt +++ b/doc/SPOE.txt @@ -176,6 +176,8 @@ spoe-agent - option continue-on-error - option force-set-var - option set-on-error + - option set-process-time + - option set-total-time - option var-prefix - register-var-names - timeout hello|idle|processing @@ -308,6 +310,55 @@ option set-on-error See also: "option continue-on-error", "option var-prefix". + +option set-process-time + Define the variable to set to report the processing time of the last event or + group. + + Arguments : + + is the variable name, without the scope. The name may only + contain characters 'a-z', 'A-Z', '0-9', '.' and '_'. + + This variable will be set in the scope of the transaction. As for all other + variables define by the SPOE, it will be prefixed. So, if your variable name + is "process_time" and your prefix is "my_spoe_pfx", the variable will be + "txn.my_spoe_pfx.process_time". + + When set, the variable is an integer representing the delay to process the + event or the group, in milliseconds. From the stream point of view, it is the + latency added by the SPOE processing for the last handled event or group. + + If several events or groups are processed for the same stream, this value + will be overrideen. + + See also: "option set-total-time". + + +option set-total-time + Define the variable to set to report the total processing time SPOE for a + stream. + + Arguments : + + is the variable name, without the scope. The name may only + contain characters 'a-z', 'A-Z', '0-9', '.' and '_'. + + This variable will be set in the scope of the transaction. As for all other + variables define by the SPOE, it will be prefixed. So, if your variable name + is "total_time" and your prefix is "my_spoe_pfx", the variable will be + "txn.my_spoe_pfx.total_time". + + When set, the variable is an integer representing the sum of processing times + for a stream, in milliseconds. From the stream point of view, it is the + latency added by the SPOE processing. + + If several events or groups are processed for the same stream, this value + will be updated. + + See also: "option set-process-time". + + option var-prefix Define the prefix used when variables are set by an agent. @@ -1142,10 +1193,10 @@ The messages are logged using the stream's logger and use the following format: * wT : the delay before the reponse is received. No fragmentation supported here. * resT : the delay to process the response. No fragmentation supported - here. + here. * pT : the delay to process the event or the group. From the stream - point of view, it is the latency added by the SPOE processing. - It is more or less the sum of values above. + point of view, it is the latency added by the SPOE processing. + It is more or less the sum of values above. For all these time events, -1 means the processing was interrupted before the end. So -1 for the queue time means the request was never dequeued. For diff --git a/include/types/spoe.h b/include/types/spoe.h index b5f8ce3d0b..9354b5536d 100644 --- a/include/types/spoe.h +++ b/include/types/spoe.h @@ -246,6 +246,8 @@ struct spoe_agent { char *engine_id; /* engine-id string */ char *var_pfx; /* Prefix used for vars set by the agent */ char *var_on_error; /* Variable to set when an error occurred, in the TXN scope */ + char *var_t_process; /* Variable to set to report the processing time of the last event/group, in the TXN scope */ + char *var_t_total; /* Variable to set to report the cumulative processing time, in the TXN scope */ unsigned int flags; /* SPOE_FL_* */ unsigned int cps_max; /* Maximum # of connections per second */ unsigned int eps_max; /* Maximum # of errors per second */ diff --git a/src/flt_spoe.c b/src/flt_spoe.c index 7d5eb3dba1..760e26c603 100644 --- a/src/flt_spoe.c +++ b/src/flt_spoe.c @@ -165,6 +165,8 @@ spoe_release_agent(struct spoe_agent *agent) free(agent->var_pfx); free(agent->engine_id); free(agent->var_on_error); + free(agent->var_t_process); + free(agent->var_t_total); list_for_each_entry_safe(msg, msgback, &agent->messages, list) { LIST_DEL(&msg->list); spoe_release_message(msg); @@ -2527,6 +2529,30 @@ spoe_update_stats(struct stream *s, struct spoe_agent *agent, tv_zero(&ctx->stats.tv_wait); tv_zero(&ctx->stats.tv_response); } + + if (agent->var_t_process) { + struct sample smp; + + memset(&smp, 0, sizeof(smp)); + smp_set_owner(&smp, s->be, s->sess, s, dir|SMP_OPT_FINAL); + smp.data.u.sint = ctx->stats.t_process; + smp.data.type = SMP_T_SINT; + + spoe_set_var(ctx, "txn", agent->var_t_process, + strlen(agent->var_t_process), &smp); + } + + if (agent->var_t_total) { + struct sample smp; + + memset(&smp, 0, sizeof(smp)); + smp_set_owner(&smp, s->be, s->sess, s, dir|SMP_OPT_FINAL); + smp.data.u.sint = ctx->stats.t_total; + smp.data.type = SMP_T_SINT; + + spoe_set_var(ctx, "txn", agent->var_t_total, + strlen(agent->var_t_total), &smp); + } } static void @@ -3261,6 +3287,8 @@ cfg_parse_spoe_agent(const char *file, int linenum, char **args, int kwm) curagent->engine_id = NULL; curagent->var_pfx = NULL; curagent->var_on_error = NULL; + curagent->var_t_process = NULL; + curagent->var_t_total = NULL; curagent->flags = (SPOE_FL_PIPELINING | SPOE_FL_SND_FRAGMENTATION); if (global.nbthread == 1) curagent->flags |= SPOE_FL_ASYNC; @@ -3499,6 +3527,54 @@ cfg_parse_spoe_agent(const char *file, int linenum, char **args, int kwm) } curagent->var_on_error = strdup(args[2]); } + else if (!strcmp(args[1], "set-process-time")) { + char *tmp; + + if (!*args[2]) { + ha_alert("parsing [%s:%d]: '%s %s' expects a value.\n", + file, linenum, args[0], + args[1]); + err_code |= ERR_ALERT | ERR_FATAL; + goto out; + } + if (alertif_too_many_args(2, file, linenum, args, &err_code)) + goto out; + tmp = args[2]; + while (*tmp) { + if (!isalnum(*tmp) && *tmp != '_' && *tmp != '.') { + ha_alert("parsing [%s:%d]: '%s %s' only supports [a-zA-Z_-.] chars.\n", + file, linenum, args[0], args[1]); + err_code |= ERR_ALERT | ERR_FATAL; + goto out; + } + tmp++; + } + curagent->var_t_process = strdup(args[2]); + } + else if (!strcmp(args[1], "set-total-time")) { + char *tmp; + + if (!*args[2]) { + ha_alert("parsing [%s:%d]: '%s %s' expects a value.\n", + file, linenum, args[0], + args[1]); + err_code |= ERR_ALERT | ERR_FATAL; + goto out; + } + if (alertif_too_many_args(2, file, linenum, args, &err_code)) + goto out; + tmp = args[2]; + while (*tmp) { + if (!isalnum(*tmp) && *tmp != '_' && *tmp != '.') { + ha_alert("parsing [%s:%d]: '%s %s' only supports [a-zA-Z_-.] chars.\n", + file, linenum, args[0], args[1]); + err_code |= ERR_ALERT | ERR_FATAL; + goto out; + } + tmp++; + } + curagent->var_t_total = strdup(args[2]); + } else { ha_alert("parsing [%s:%d]: option '%s' is not supported.\n", file, linenum, args[1]); @@ -4013,6 +4089,38 @@ parse_spoe_flt(char **args, int *cur_arg, struct proxy *px, } } + if (curagent->var_t_process) { + struct arg arg; + + trash.len = snprintf(trash.str, trash.size, "txn.%s.%s", + curagent->var_pfx, curagent->var_t_process); + + arg.type = ARGT_STR; + arg.data.str.str = trash.str; + arg.data.str.len = trash.len; + if (!vars_check_arg(&arg, err)) { + memprintf(err, "SPOE agent '%s': failed to register variable %s.%s (%s)", + curagent->id, curagent->var_pfx, curagent->var_t_process, *err); + goto error; + } + } + + if (curagent->var_t_total) { + struct arg arg; + + trash.len = snprintf(trash.str, trash.size, "txn.%s.%s", + curagent->var_pfx, curagent->var_t_total); + + arg.type = ARGT_STR; + arg.data.str.str = trash.str; + arg.data.str.len = trash.len; + if (!vars_check_arg(&arg, err)) { + memprintf(err, "SPOE agent '%s': failed to register variable %s.%s (%s)", + curagent->id, curagent->var_pfx, curagent->var_t_process, *err); + goto error; + } + } + if (LIST_ISEMPTY(&curmphs) && LIST_ISEMPTY(&curgphs)) { ha_warning("Proxy '%s': No message/group used by SPOE agent '%s' declared at %s:%d.\n", px->id, curagent->id, curagent->conf.file, curagent->conf.line);