diff --git a/doc/SPOE.txt b/doc/SPOE.txt index 8cbf6845a..ce119dc49 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 b5f8ce3d0..9354b5536 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 7d5eb3dba..760e26c60 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);