MINOR: activity: support setting/clearing lock/memory watching for task profiling

Damien Claisse reported in issue #3257 a performance regression between
3.2 and 3.3 when task profiling is enabled, more precisely in relation
with the following patches were merged:

  98cc815e3e ("MINOR: activity: collect time spent with a lock held for each task")
  503084643f ("MINOR: activity: collect time spent waiting on a lock for each task")
  9d8c2a888b ("MINOR: activity: collect CPU time spent on memory allocations for each task")

The issue mostly comes from the first patches. What happens is that the
local time is taken when entering and leaving each lock, which costs a
lot on a contended system. The problem here is the lack of finegrained
settings for lock and malloc profiling.

This patch introduces a better approach. The task profiler goes back to
its default behavior in on/auto modes, but the configuration now accepts
new extra options "lock", "no-lock", "memory", "no-memory" to precisely
indicate other timers to watch for each task when profiling turns on.

This is achieved by setting two new flags HA_PROF_TASKS_LOCK and
HA_PROF_TASKS_MEM in the global "profiling" variable.

This patch only parses the new values and assigns them to the global
variable from the config file for now. The doc was updated.

diff --git a/doc/configuration.txt b/doc/configuration.txt
index 25fbdea7804f8b3514f7aa96835f427c32acae63..709e0c5442f268f1c0e02cffaf728b621b172ac6 100644 (file)
--- a/doc/configuration.txt
+++ b/doc/configuration.txt
@@ -4005,7 +4005,7 @@ profiling.memory { on | off }
   use in production. The same may be achieved at run time on the CLI using the
   "set profiling memory" command, please consult the management manual.
 
-profiling.tasks { auto | on | off }
+profiling.tasks { auto | on | off | lock | no-lock | memory | no-memory }*
   Enables ('on') or disables ('off') per-task CPU profiling. When set to 'auto'
   the profiling automatically turns on a thread when it starts to suffer from
   an average latency of 1000 microseconds or higher as reported in the
@@ -4016,6 +4016,18 @@ profiling.tasks { auto | on | off }
   systems, containers, or virtual machines, or when the system swaps (which
   must absolutely never happen on a load balancer).
 
+  When task profiling is enabled, HAProxy can also collect the time each task
+  spends with a lock held or waiting for a lock, as well as the time spent
+  waiting for a memory allocation to succeed in case of a pool cache miss. This
+  can sometimes help understand certain causes of latency. For this, the extra
+  keywords "lock" (to enable lock time collection), "no-lock" (to disable it),
+  "memory" (to enable memory allocation time collection) or "no-memory" (to
+  disable it) may additionally be passed. By default they are not enabled since
+  they can have a non-negligible CPU impact on highly loaded systems (3-10%).
+  Note that the overhead is only taken when profiling is effectively running,
+  so that when running in "auto" mode, it will only appear when HAProxy decides
+  to turn it on.
+
   CPU profiling per task can be very convenient to report where the time is
   spent and which requests have what effect on which other request. Enabling
   it will typically affect the overall's performance by less than 1%, thus it

diff --git a/include/haproxy/activity-t.h b/include/haproxy/activity-t.h
index 5801c9a523975d7a101a736362cdb3365682ec77..37fdeb10a4a63ace6f7c6d6dfa74517115c6f350 100644 (file)
--- a/include/haproxy/activity-t.h
+++ b/include/haproxy/activity-t.h
@@ -33,6 +33,8 @@
 #define HA_PROF_TASKS_MASK  0x00000003     /* per-task CPU profiling mask */
 
 #define HA_PROF_MEMORY      0x00000004     /* memory profiling */
+#define HA_PROF_TASKS_MEM   0x00000008     /* per-task CPU profiling with memory */
+#define HA_PROF_TASKS_LOCK  0x00000010     /* per-task CPU profiling with locks */
 
 
 #ifdef USE_MEMORY_PROFILING

diff --git a/src/activity.c b/src/activity.c
index 0447ed117cdc763c3c33ee8059cd4fe75c0c42e6..4cc2386de58952712d6198897304a83a013648e4 100644 (file)
--- a/src/activity.c
+++ b/src/activity.c
@@ -692,26 +692,41 @@ static int cfg_parse_prof_memory(char **args, int section_type, struct proxy *cu
 }
 #endif // USE_MEMORY_PROFILING
 
-/* config parser for global "profiling.tasks", accepts "on" or "off" */
+/* config parser for global "profiling.tasks", accepts "on", "off", 'auto",
+ * "lock", "no-lock", "memory", "no-memory".
+ */
 static int cfg_parse_prof_tasks(char **args, int section_type, struct proxy *curpx,
                                 const struct proxy *defpx, const char *file, int line,
                                 char **err)
 {
-       if (too_many_args(1, args, err, NULL))
-               return -1;
+       int arg;
 
-       if (strcmp(args[1], "on") == 0) {
-               profiling = (profiling & ~HA_PROF_TASKS_MASK) | HA_PROF_TASKS_ON;
-               HA_ATOMIC_STORE(&prof_task_start_ns, now_ns);
-       }
-       else if (strcmp(args[1], "auto") == 0) {
-               profiling = (profiling & ~HA_PROF_TASKS_MASK) | HA_PROF_TASKS_AOFF;
-               HA_ATOMIC_STORE(&prof_task_start_ns, now_ns);
+       for (arg = 1; *args[arg]; arg++) {
+               if (strcmp(args[arg], "on") == 0) {
+                       profiling = (profiling & ~HA_PROF_TASKS_MASK) | HA_PROF_TASKS_ON;
+                       HA_ATOMIC_STORE(&prof_task_start_ns, now_ns);
+               }
+               else if (strcmp(args[arg], "auto") == 0) {
+                       profiling = (profiling & ~HA_PROF_TASKS_MASK) | HA_PROF_TASKS_AOFF;
+                       HA_ATOMIC_STORE(&prof_task_start_ns, now_ns);
+               }
+               else if (strcmp(args[arg], "off") == 0)
+                       profiling = (profiling & ~HA_PROF_TASKS_MASK) | HA_PROF_TASKS_OFF;
+               else if (strcmp(args[arg], "lock") == 0)
+                       profiling |= HA_PROF_TASKS_LOCK;
+               else if (strcmp(args[arg], "no-lock") == 0)
+                       profiling &= ~HA_PROF_TASKS_LOCK;
+               else if (strcmp(args[arg], "memory") == 0)
+                       profiling |= HA_PROF_TASKS_MEM;
+               else if (strcmp(args[arg], "no-memory") == 0)
+                       profiling &= ~HA_PROF_TASKS_MEM;
+               else
+                       break;
        }
-       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]);
+
+       /* either no arg or invalid arg */
+       if (arg == 1 || *args[arg]) {
+               memprintf(err, "'%s' expects a combination of either 'on', 'auto', 'off', 'lock', 'no-lock', 'memory', or 'no-memory', but got '%s'.", args[0], args[arg]);
                return -1;
        }
        return 0;