mirrors/haproxy
1
0
Fork 0
mirror of https://git.haproxy.org/git/haproxy.git/ synced 2025-08-05 22:56:57 +02:00
Code Issues Projects Releases Wiki Activity

MINOR: spoe: Add options to store processing times in variables

Browse Source 
"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
This commit is contained in:
Christopher Faulet 2018-03-22 09:08:20 +01:00 committed by Willy Tarreau
parent b2dd1e034c
commit 36bda1cd4a
3 changed files with 164 additions and 3 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

57
doc/SPOE.txt
View File

@ -176,6 +176,8 @@ spoe-agent <name>
- 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 <var name>
See also: "option continue-on-error", "option var-prefix".
option set-process-time <var name>
Define the variable to set to report the processing time of the last event or
group.
Arguments :
<var name> 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 <var name>
Define the variable to set to report the total processing time SPOE for a
stream.
Arguments :
<var name> 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 <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

2
include/types/spoe.h
View File

@ -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 */

108
src/flt_spoe.c
View File

@ -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);