haproxy/src/activity.c
Willy Tarreau d2d3348acb MINOR: activity: enable automatic profiling turn on/off
Instead of having to manually turn task profiling on/off in the
configuration, by default it will work in "auto" mode, which
automatically turns on on any thread experiencing sustained loop
latencies over one millisecond averaged over the last 1024 samples.

This may happen with configs using lots of regex (thing map_reg for
example, which is the lazy way to convert Apache's rewrite rules but
must not be abused), and such high latencies affect all the process
and the problem is most often intermittent (e.g. hitting a map which
is only used for certain host names).

Thus now by default, with profiling set to "auto", it remains off all
the time until something bad happens. This also helps better focus on
the issues when looking at the logs as well as in "show sess" output.
It automatically turns off when the average loop latency over the last
1024 calls goes below 990 microseconds (which typically takes a while
when in idle).

This patch could be backported to stable versions after a bit more
exposure, as it definitely improves observability and the ability to
quickly spot the culprit. In this case, previous patch ("MINOR:
activity: make the profiling status per thread and not global") must
also be taken.
2019-04-25 17:26:46 +02:00

148 lines
4.4 KiB
C

/*
* activity measurement functions.
*
* Copyright 2000-2018 Willy Tarreau <w@1wt.eu>
*
* This program is free software; you can redistribute it and/or
* modify it under the terms of the GNU General Public License
* as published by the Free Software Foundation; either version
* 2 of the License, or (at your option) any later version.
*
*/
#include <common/cfgparse.h>
#include <common/config.h>
#include <common/standard.h>
#include <common/hathreads.h>
#include <common/initcall.h>
#include <types/activity.h>
#include <proto/channel.h>
#include <proto/cli.h>
#include <proto/freq_ctr.h>
#include <proto/stream_interface.h>
/* bit field of profiling options. Beware, may be modified at runtime! */
unsigned int profiling = HA_PROF_TASKS_AUTO;
unsigned long task_profiling_mask = 0;
/* One struct per thread containing all collected measurements */
struct activity activity[MAX_THREADS] __attribute__((aligned(64))) = { };
/* Updates the current thread's statistics about stolen CPU time. The unit for
* <stolen> is half-milliseconds.
*/
void report_stolen_time(uint64_t stolen)
{
activity[tid].cpust_total += stolen;
update_freq_ctr(&activity[tid].cpust_1s, stolen);
update_freq_ctr_period(&activity[tid].cpust_15s, 15000, stolen);
}
/* config parser for global "profiling.tasks", accepts "on" or "off" */
static int cfg_parse_prof_tasks(char **args, int section_type, struct proxy *curpx,
struct proxy *defpx, const char *file, int line,
char **err)
{
if (too_many_args(1, args, err, NULL))
return -1;
if (strcmp(args[1], "on") == 0)
profiling = (profiling & ~HA_PROF_TASKS_MASK) | HA_PROF_TASKS_ON;
else if (strcmp(args[1], "auto") == 0)
profiling = (profiling & ~HA_PROF_TASKS_MASK) | HA_PROF_TASKS_AUTO;
else if (strcmp(args[1], "off") == 0)
profiling = (profiling & ~HA_PROF_TASKS_MASK) | HA_PROF_TASKS_OFF;
else {
memprintf(err, "'%s' expects either 'on', 'auto', or 'off' but got '%s'.", args[0], args[1]);
return -1;
}
return 0;
}
/* parse a "set profiling" command. It always returns 1. */
static int cli_parse_set_profiling(char **args, char *payload, struct appctx *appctx, void *private)
{
if (!cli_has_level(appctx, ACCESS_LVL_ADMIN))
return 1;
if (strcmp(args[2], "tasks") != 0) {
appctx->ctx.cli.severity = LOG_ERR;
appctx->ctx.cli.msg = "Expects 'tasks'.\n";
appctx->st0 = CLI_ST_PRINT;
return 1;
}
if (strcmp(args[3], "on") == 0) {
unsigned int old = profiling;
while (!_HA_ATOMIC_CAS(&profiling, &old, (old & ~HA_PROF_TASKS_MASK) | HA_PROF_TASKS_ON))
;
}
else if (strcmp(args[3], "auto") == 0) {
unsigned int old = profiling;
while (!_HA_ATOMIC_CAS(&profiling, &old, (old & ~HA_PROF_TASKS_MASK) | HA_PROF_TASKS_AUTO))
;
}
else if (strcmp(args[3], "off") == 0) {
unsigned int old = profiling;
while (!_HA_ATOMIC_CAS(&profiling, &old, (old & ~HA_PROF_TASKS_MASK) | HA_PROF_TASKS_OFF))
;
}
else {
appctx->ctx.cli.severity = LOG_ERR;
appctx->ctx.cli.msg = "Expects 'on', 'auto', or 'off'.\n";
appctx->st0 = CLI_ST_PRINT;
return 1;
}
return 1;
}
/* This function dumps all profiling settings. It returns 0 if the output
* buffer is full and it needs to be called again, otherwise non-zero.
*/
static int cli_io_handler_show_profiling(struct appctx *appctx)
{
struct stream_interface *si = appctx->owner;
const char *str;
if (unlikely(si_ic(si)->flags & (CF_WRITE_ERROR|CF_SHUTW)))
return 1;
chunk_reset(&trash);
switch (profiling & HA_PROF_TASKS_MASK) {
case HA_PROF_TASKS_AUTO: str="auto"; break;
case HA_PROF_TASKS_ON: str="on"; break;
default: str="off"; break;
}
chunk_printf(&trash,
"Per-task CPU profiling : %s # set profiling tasks {on|auto|off}\n",
str);
if (ci_putchk(si_ic(si), &trash) == -1) {
/* failed, try again */
si_rx_room_blk(si);
return 0;
}
return 1;
}
/* config keyword parsers */
static struct cfg_kw_list cfg_kws = {ILH, {
{ CFG_GLOBAL, "profiling.tasks", cfg_parse_prof_tasks },
{ 0, NULL, NULL }
}};
INITCALL1(STG_REGISTER, cfg_register_keywords, &cfg_kws);
/* register cli keywords */
static struct cli_kw_list cli_kws = {{ },{
{ { "show", "profiling", NULL }, "show profiling : show CPU profiling options", NULL, cli_io_handler_show_profiling, NULL },
{ { "set", "profiling", NULL }, "set profiling : enable/disable CPU profiling", cli_parse_set_profiling, NULL },
{{},}
}};
INITCALL1(STG_REGISTER, cli_register_kw, &cli_kws);