trace2: add global counter mechanism

Add global counters mechanism to Trace2.

The Trace2 counters mechanism adds the ability to create a set of
global counter variables and an API to increment them efficiently.
Counters can optionally report per-thread usage in addition to the sum
across all threads.

Counter events are emitted to the Trace2 logs when a thread exits and
at process exit.

Counters are an alternative to `data` and `data_json` events.

Counters are useful when you want to measure something across the life
of the process, when you don't want per-measurement events for
performance reasons, when the data does not fit conveniently within a
region, or when your control flow does not easily let you write the
final total.  For example, you might use this to report the number of
calls to unzip() or the number of de-delta steps during a checkout.

Signed-off-by: Jeff Hostetler <[email protected]>
Signed-off-by: Junio C Hamano <[email protected]>

Author: jeffhostetler

Documentation/technical/api-trace2.txt

@@ -805,6 +805,37 @@ The "value" field may be an integer or a string.
 }
 ------------
 
+`"th_counter"`::
+	This event logs the value of a counter variable in a thread.
+	This event is generated when a thread exits for counters that
+	requested per-thread events.
++
+------------
+{
+	"event":"th_counter",
+	...
+	"category":"my_category",
+	"name":"my_counter",
+	"count":23
+}
+------------
+
+`"counter"`::
+	This event logs the value of a counter variable across all threads.
+	This event is generated when the process exits.  The total value
+	reported here is the sum across all threads.
++
+------------
+{
+	"event":"counter",
+	...
+	"category":"my_category",
+	"name":"my_counter",
+	"count":23
+}
+------------
+
+
 == Example Trace2 API Usage
 
 Here is a hypothetical usage of the Trace2 API showing the intended

Makefile

@@ -1094,6 +1094,7 @@ LIB_OBJS += trace.o
 LIB_OBJS += trace2.o
 LIB_OBJS += trace2/tr2_cfg.o
 LIB_OBJS += trace2/tr2_cmd_name.o
+LIB_OBJS += trace2/tr2_ctr.o
 LIB_OBJS += trace2/tr2_dst.o
 LIB_OBJS += trace2/tr2_sid.o
 LIB_OBJS += trace2/tr2_sysenv.o

t/helper/test-trace2.c

@@ -323,6 +323,92 @@ static int ut_101timer(int argc, const char **argv)
 	return 0;
 }
 
+/*
+ * Single-threaded counter test.  Add several values to the TEST1 counter.
+ * The test script can verify that the final sum is reported in the "counter"
+ * event.
+ */
+static int ut_200counter(int argc, const char **argv)
+{
+	const char *usage_error =
+		"expect <v1> [<v2> [...]]";
+	int value;
+	int k;
+
+	if (argc < 1)
+		die("%s", usage_error);
+
+	for (k = 0; k < argc; k++) {
+		if (get_i(&value, argv[k]))
+			die("invalid value[%s] -- %s",
+			    argv[k], usage_error);
+		trace2_counter_add(TRACE2_COUNTER_ID_TEST1, value);
+	}
+
+	return 0;
+}
+
+/*
+ * Multi-threaded counter test.  Create seveal threads that each increment
+ * the TEST2 global counter.  The test script can verify that an individual
+ * "th_counter" event is generated with a partial sum for each thread and
+ * that a final aggregate "counter" event is generated.
+ */
+
+struct ut_201_data {
+	int v1;
+	int v2;
+};
+
+static void *ut_201counter_thread_proc(void *_ut_201_data)
+{
+	struct ut_201_data *data = _ut_201_data;
+
+	trace2_thread_start("ut_201");
+
+	trace2_counter_add(TRACE2_COUNTER_ID_TEST2, data->v1);
+	trace2_counter_add(TRACE2_COUNTER_ID_TEST2, data->v2);
+
+	trace2_thread_exit();
+	return NULL;
+}
+
+static int ut_201counter(int argc, const char **argv)
+{
+	const char *usage_error =
+		"expect <v1> <v2> <threads>";
+
+	struct ut_201_data data = { 0, 0 };
+	int nr_threads = 0;
+	int k;
+	pthread_t *pids = NULL;
+
+	if (argc != 3)
+		die("%s", usage_error);
+	if (get_i(&data.v1, argv[0]))
+		die("%s", usage_error);
+	if (get_i(&data.v2, argv[1]))
+		die("%s", usage_error);
+	if (get_i(&nr_threads, argv[2]))
+		die("%s", usage_error);
+
+	CALLOC_ARRAY(pids, nr_threads);
+
+	for (k = 0; k < nr_threads; k++) {
+		if (pthread_create(&pids[k], NULL, ut_201counter_thread_proc, &data))
+			die("failed to create thread[%d]", k);
+	}
+
+	for (k = 0; k < nr_threads; k++) {
+		if (pthread_join(pids[k], NULL))
+			die("failed to join thread[%d]", k);
+	}
+
+	free(pids);
+
+	return 0;
+}
+
 /*
  * Usage:
  *     test-tool trace2 <ut_name_1> <ut_usage_1>
@@ -346,6 +432,9 @@ static struct unit_test ut_table[] = {
 
 	{ ut_100timer,    "100timer",  "<count> <ms_delay>" },
 	{ ut_101timer,    "101timer",  "<count> <ms_delay> <threads>" },
+
+	{ ut_200counter,  "200counter", "<v1> [<v2> [<v3> [...]]]" },
+	{ ut_201counter,  "201counter", "<v1> <v2> <threads>" },
 };
 /* clang-format on */
 

t/t0211-trace2-perf.sh

@@ -222,4 +222,50 @@ test_expect_success 'stopwatch timer test/test2' '
 	have_timer_event "main" "timer" "test" "test2" 15 actual
 '
 
+# Exercise the global counters and confirm that we get the expected values.
+#
+# The counter "test/test1" should only emit a global summary "counter" event.
+# The counter "test/test2" could emit per-thread "th_counter" events and a
+# global summary "counter" event.
+
+have_counter_event () {
+	thread=$1 event=$2 category=$3 name=$4 value=$5 file=$6 &&
+
+	pattern="d0|${thread}|${event}||||${category}|name:${name} value:${value}" &&
+
+	grep "${patern}" ${file}
+}
+
+test_expect_success 'global counter test/test1' '
+	test_when_finished "rm trace.perf actual" &&
+	test_config_global trace2.perfBrief 1 &&
+	test_config_global trace2.perfTarget "$(pwd)/trace.perf" &&
+
+	# Use the counter "test1" and add n integers.
+	test-tool trace2 200counter 1 2 3 4 5 &&
+
+	perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual &&
+
+	have_counter_event "main" "counter" "test" "test1" 15 actual
+'
+
+test_expect_success 'global counter test/test2' '
+	test_when_finished "rm trace.perf actual" &&
+	test_config_global trace2.perfBrief 1 &&
+	test_config_global trace2.perfTarget "$(pwd)/trace.perf" &&
+
+	# Add 2 integers to the counter "test2" in each of 3 threads.
+	test-tool trace2 201counter 7 13 3 &&
+
+	perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual &&
+
+	# So we should have 3 per-thread events of 5 each.
+	have_counter_event "th01:ut_201" "th_counter" "test" "test2" 20 actual &&
+	have_counter_event "th02:ut_201" "th_counter" "test" "test2" 20 actual &&
+	have_counter_event "th03:ut_201" "th_counter" "test" "test2" 20 actual &&
+
+	# And we should have a single event with the total across all threads.
+	have_counter_event "main" "counter" "test" "test2" 60 actual
+'
+
 test_done

trace2.c

@@ -8,6 +8,7 @@
 #include "version.h"
 #include "trace2/tr2_cfg.h"
 #include "trace2/tr2_cmd_name.h"
+#include "trace2/tr2_ctr.h"
 #include "trace2/tr2_dst.h"
 #include "trace2/tr2_sid.h"
 #include "trace2/tr2_sysenv.h"
@@ -101,6 +102,22 @@ static void tr2_tgt_emit_a_timer(const struct tr2_timer_metadata *meta,
 			tgt_j->pfn_timer(meta, timer, is_final_data);
 }
 
+/*
+ * The signature of this function must match the pfn_counter
+ * method in the targets.
+ */
+static void tr2_tgt_emit_a_counter(const struct tr2_counter_metadata *meta,
+				   const struct tr2_counter *counter,
+				   int is_final_data)
+{
+	struct tr2_tgt *tgt_j;
+	int j;
+
+	for_each_wanted_builtin (j, tgt_j)
+		if (tgt_j->pfn_counter)
+			tgt_j->pfn_counter(meta, counter, is_final_data);
+}
+
 static int tr2main_exit_code;
 
 /*
@@ -132,20 +149,26 @@ static void tr2main_atexit_handler(void)
 	 * Some timers want per-thread details.  If the main thread
 	 * used one of those timers, emit the details now (before
 	 * we emit the aggregate timer values).
+	 *
+	 * Likewise for counters.
 	 */
 	tr2_emit_per_thread_timers(tr2_tgt_emit_a_timer);
+	tr2_emit_per_thread_counters(tr2_tgt_emit_a_counter);
 
 	/*
-	 * Add stopwatch timer data for the main thread to the final
-	 * totals.  And then emit the final timer values.
+	 * Add stopwatch timer and counter data for the main thread to
+	 * the final totals.  And then emit the final values.
 	 *
 	 * Technically, we shouldn't need to hold the lock to update
-	 * and output the final_timer_block (since all other threads
-	 * should be dead by now), but it doesn't hurt anything.
+	 * and output the final_timer_block and final_counter_block
+	 * (since all other threads should be dead by now), but it
+	 * doesn't hurt anything.
 	 */
 	tr2tls_lock();
 	tr2_update_final_timers();
+	tr2_update_final_counters();
 	tr2_emit_final_timers(tr2_tgt_emit_a_timer);
+	tr2_emit_final_counters(tr2_tgt_emit_a_counter);
 	tr2tls_unlock();
 
 	for_each_wanted_builtin (j, tgt_j)
@@ -582,16 +605,20 @@ void trace2_thread_exit_fl(const char *file, int line)
 	/*
 	 * Some timers want per-thread details.  If this thread used
 	 * one of those timers, emit the details now.
+	 *
+	 * Likewise for counters.
 	 */
 	tr2_emit_per_thread_timers(tr2_tgt_emit_a_timer);
+	tr2_emit_per_thread_counters(tr2_tgt_emit_a_counter);
 
 	/*
-	 * Add stopwatch timer data from the current (non-main) thread
-	 * to the final totals.  (We'll accumulate data for the main
-	 * thread later during "atexit".)
+	 * Add stopwatch timer and counter data from the current
+	 * (non-main) thread to the final totals.  (We'll accumulate
+	 * data for the main thread later during "atexit".)
 	 */
 	tr2tls_lock();
 	tr2_update_final_timers();
+	tr2_update_final_counters();
 	tr2tls_unlock();
 
 	for_each_wanted_builtin (j, tgt_j)
@@ -870,6 +897,17 @@ void trace2_timer_stop(enum trace2_timer_id tid)
 	tr2_stop_timer(tid);
 }
 
+void trace2_counter_add(enum trace2_counter_id cid, uint64_t value)
+{
+	if (!trace2_enabled)
+		return;
+
+	if (cid < 0 || cid >= TRACE2_NUMBER_OF_COUNTERS)
+		BUG("trace2_counter_add: invalid counter id: %d", cid);
+
+	tr2_counter_increment(cid, value);
+}
+
 const char *trace2_session_id(void)
 {
 	return tr2_sid_get();

trace2.h

@@ -52,6 +52,7 @@ struct json_writer;
  * [] trace2_data*      -- emit region/thread/repo data messages.
  * [] trace2_printf*    -- legacy trace[1] messages.
  * [] trace2_timer*     -- stopwatch timers (messages are deferred).
+ * [] trace2_counter*   -- global counters (messages are deferred).
  */
 
 /*
@@ -528,6 +529,42 @@ enum trace2_timer_id {
 void trace2_timer_start(enum trace2_timer_id tid);
 void trace2_timer_stop(enum trace2_timer_id tid);
 
+/*
+ * Define the set of global counters.
+ *
+ * We can add more at any time, but they must be defined at compile
+ * time (to avoid the need to dynamically allocate and synchronize
+ * them between different threads).
+ *
+ * These must start at 0 and be contiguous (because we use them
+ * elsewhere as array indexes).
+ *
+ * Any values added to this enum be also be added to the
+ * `tr2_counter_metadata[]` in `trace2/tr2_tr2_ctr.c`.
+ */
+enum trace2_counter_id {
+	/*
+	 * Define two counters for testing.  See `t/helper/test-trace2.c`.
+	 * These can be used for ad hoc testing, but should not be used
+	 * for permanent analysis code.
+	 */
+	TRACE2_COUNTER_ID_TEST1 = 0, /* emits summary event only */
+	TRACE2_COUNTER_ID_TEST2,     /* emits summary and thread events */
+
+	/* Add additional counter definitions before here. */
+	TRACE2_NUMBER_OF_COUNTERS
+};
+
+/*
+ * Increase the named global counter by value.
+ *
+ * Note that this adds `value` to the current thread's partial sum for
+ * this counter (without locking) and that the complete sum is not
+ * available until all threads have exited, so it does not return the
+ * new value of the counter.
+ */
+void trace2_counter_add(enum trace2_counter_id cid, uint64_t value);
+
 /*
  * Optional platform-specific code to dump information about the
  * current and any parent process(es).  This is intended to allow