summaryrefslogtreecommitdiff
path: root/trace2
diff options
context:
space:
mode:
Diffstat (limited to 'trace2')
-rw-r--r--trace2/tr2_cfg.c4
-rw-r--r--trace2/tr2_cmd_name.c3
-rw-r--r--trace2/tr2_ctr.c101
-rw-r--r--trace2/tr2_ctr.h104
-rw-r--r--trace2/tr2_dst.c4
-rw-r--r--trace2/tr2_sid.c4
-rw-r--r--trace2/tr2_sysenv.c2
-rw-r--r--trace2/tr2_tbuf.c2
-rw-r--r--trace2/tr2_tgt.h16
-rw-r--r--trace2/tr2_tgt_event.c50
-rw-r--r--trace2/tr2_tgt_normal.c42
-rw-r--r--trace2/tr2_tgt_perf.c46
-rw-r--r--trace2/tr2_tls.c38
-rw-r--r--trace2/tr2_tls.h55
-rw-r--r--trace2/tr2_tmr.c183
-rw-r--r--trace2/tr2_tmr.h140
16 files changed, 754 insertions, 40 deletions
diff --git a/trace2/tr2_cfg.c b/trace2/tr2_cfg.c
index ec9ac1a6ef..78cfc15d52 100644
--- a/trace2/tr2_cfg.c
+++ b/trace2/tr2_cfg.c
@@ -1,5 +1,7 @@
-#include "cache.h"
+#include "git-compat-util.h"
#include "config.h"
+#include "strbuf.h"
+#include "trace2.h"
#include "trace2/tr2_cfg.h"
#include "trace2/tr2_sysenv.h"
diff --git a/trace2/tr2_cmd_name.c b/trace2/tr2_cmd_name.c
index dd313204f5..b7b5a869b7 100644
--- a/trace2/tr2_cmd_name.c
+++ b/trace2/tr2_cmd_name.c
@@ -1,4 +1,5 @@
-#include "cache.h"
+#include "git-compat-util.h"
+#include "strbuf.h"
#include "trace2/tr2_cmd_name.h"
#define TR2_ENVVAR_PARENT_NAME "GIT_TRACE2_PARENT_NAME"
diff --git a/trace2/tr2_ctr.c b/trace2/tr2_ctr.c
new file mode 100644
index 0000000000..b342d3b1a3
--- /dev/null
+++ b/trace2/tr2_ctr.c
@@ -0,0 +1,101 @@
+#include "git-compat-util.h"
+#include "thread-utils.h"
+#include "trace2/tr2_tgt.h"
+#include "trace2/tr2_tls.h"
+#include "trace2/tr2_ctr.h"
+
+/*
+ * A global counter block to aggregrate values from the partial sums
+ * from each thread.
+ */
+static struct tr2_counter_block final_counter_block; /* access under tr2tls_mutex */
+
+/*
+ * Define metadata for each global counter.
+ *
+ * This array must match the "enum trace2_counter_id" and the values
+ * in "struct tr2_counter_block.counter[*]".
+ */
+static struct tr2_counter_metadata tr2_counter_metadata[TRACE2_NUMBER_OF_COUNTERS] = {
+ [TRACE2_COUNTER_ID_TEST1] = {
+ .category = "test",
+ .name = "test1",
+ .want_per_thread_events = 0,
+ },
+ [TRACE2_COUNTER_ID_TEST2] = {
+ .category = "test",
+ .name = "test2",
+ .want_per_thread_events = 1,
+ },
+
+ /* Add additional metadata before here. */
+};
+
+void tr2_counter_increment(enum trace2_counter_id cid, uint64_t value)
+{
+ struct tr2tls_thread_ctx *ctx = tr2tls_get_self();
+ struct tr2_counter *c = &ctx->counter_block.counter[cid];
+
+ c->value += value;
+
+ ctx->used_any_counter = 1;
+ if (tr2_counter_metadata[cid].want_per_thread_events)
+ ctx->used_any_per_thread_counter = 1;
+}
+
+void tr2_update_final_counters(void)
+{
+ struct tr2tls_thread_ctx *ctx = tr2tls_get_self();
+ enum trace2_counter_id cid;
+
+ if (!ctx->used_any_counter)
+ return;
+
+ /*
+ * Access `final_counter_block` requires holding `tr2tls_mutex`.
+ * We assume that our caller is holding the lock.
+ */
+
+ for (cid = 0; cid < TRACE2_NUMBER_OF_COUNTERS; cid++) {
+ struct tr2_counter *c_final = &final_counter_block.counter[cid];
+ const struct tr2_counter *c = &ctx->counter_block.counter[cid];
+
+ c_final->value += c->value;
+ }
+}
+
+void tr2_emit_per_thread_counters(tr2_tgt_evt_counter_t *fn_apply)
+{
+ struct tr2tls_thread_ctx *ctx = tr2tls_get_self();
+ enum trace2_counter_id cid;
+
+ if (!ctx->used_any_per_thread_counter)
+ return;
+
+ /*
+ * For each counter, if the counter wants per-thread events
+ * and this thread used it (the value is non-zero), emit it.
+ */
+ for (cid = 0; cid < TRACE2_NUMBER_OF_COUNTERS; cid++)
+ if (tr2_counter_metadata[cid].want_per_thread_events &&
+ ctx->counter_block.counter[cid].value)
+ fn_apply(&tr2_counter_metadata[cid],
+ &ctx->counter_block.counter[cid],
+ 0);
+}
+
+void tr2_emit_final_counters(tr2_tgt_evt_counter_t *fn_apply)
+{
+ enum trace2_counter_id cid;
+
+ /*
+ * Access `final_counter_block` requires holding `tr2tls_mutex`.
+ * We assume that our caller is holding the lock.
+ */
+
+ for (cid = 0; cid < TRACE2_NUMBER_OF_COUNTERS; cid++)
+ if (final_counter_block.counter[cid].value)
+ fn_apply(&tr2_counter_metadata[cid],
+ &final_counter_block.counter[cid],
+ 1);
+}
diff --git a/trace2/tr2_ctr.h b/trace2/tr2_ctr.h
new file mode 100644
index 0000000000..a2267ee990
--- /dev/null
+++ b/trace2/tr2_ctr.h
@@ -0,0 +1,104 @@
+#ifndef TR2_CTR_H
+#define TR2_CTR_H
+
+#include "trace2.h"
+#include "trace2/tr2_tgt.h"
+
+/*
+ * Define a mechanism to allow global "counters".
+ *
+ * Counters can be used count interesting activity that does not fit
+ * the "region and data" model, such as code called from many
+ * different regions and/or where you want to count a number of items,
+ * but don't have control of when the last item will be processed,
+ * such as counter the number of calls to `lstat()`.
+ *
+ * Counters differ from Trace2 "data" events. Data events are emitted
+ * immediately and are appropriate for documenting loop counters at
+ * the end of a region, for example. Counter values are accumulated
+ * during the program and final counter values are emitted at program
+ * exit.
+ *
+ * To make this model efficient, we define a compile-time fixed set of
+ * counters and counter ids using a fixed size "counter block" array
+ * in thread-local storage. This gives us constant time, lock-free
+ * access to each counter within each thread. This lets us avoid the
+ * complexities of dynamically allocating a counter and sharing that
+ * definition with other threads.
+ *
+ * Each thread uses the counter block in its thread-local storage to
+ * increment partial sums for each counter (without locking). When a
+ * thread exits, those partial sums are (under lock) added to the
+ * global final sum.
+ *
+ * Partial sums for each counter are optionally emitted when a thread
+ * exits.
+ *
+ * Final sums for each counter are emitted between the "exit" and
+ * "atexit" events.
+ *
+ * A parallel "counter metadata" table contains the "category" and
+ * "name" fields for each counter. This eliminates the need to
+ * include those args in the various counter APIs.
+ */
+
+/*
+ * The definition of an individual counter as used by an individual
+ * thread (and later in aggregation).
+ */
+struct tr2_counter {
+ uint64_t value;
+};
+
+/*
+ * Metadata for a counter.
+ */
+struct tr2_counter_metadata {
+ const char *category;
+ const char *name;
+
+ /*
+ * True if we should emit per-thread events for this counter
+ * when individual threads exit.
+ */
+ unsigned int want_per_thread_events:1;
+};
+
+/*
+ * A compile-time fixed block of counters to insert into thread-local
+ * storage. This wrapper is used to avoid quirks of C and the usual
+ * need to pass an array size argument.
+ */
+struct tr2_counter_block {
+ struct tr2_counter counter[TRACE2_NUMBER_OF_COUNTERS];
+};
+
+/*
+ * Private routines used by trace2.c to increment a counter for the
+ * current thread.
+ */
+void tr2_counter_increment(enum trace2_counter_id cid, uint64_t value);
+
+/*
+ * Add the current thread's counter data to the global totals.
+ * This is called during thread-exit.
+ *
+ * Caller must be holding the tr2tls_mutex.
+ */
+void tr2_update_final_counters(void);
+
+/*
+ * Emit per-thread counter data for the current thread.
+ * This is called during thread-exit.
+ */
+void tr2_emit_per_thread_counters(tr2_tgt_evt_counter_t *fn_apply);
+
+/*
+ * Emit global counter values.
+ * This is called during atexit handling.
+ *
+ * Caller must be holding the tr2tls_mutex.
+ */
+void tr2_emit_final_counters(tr2_tgt_evt_counter_t *fn_apply);
+
+#endif /* TR2_CTR_H */
diff --git a/trace2/tr2_dst.c b/trace2/tr2_dst.c
index 8a21dd2972..5be892cd5c 100644
--- a/trace2/tr2_dst.c
+++ b/trace2/tr2_dst.c
@@ -1,5 +1,7 @@
-#include "cache.h"
+#include "git-compat-util.h"
+#include "abspath.h"
#include "sigchain.h"
+#include "strbuf.h"
#include "trace2/tr2_dst.h"
#include "trace2/tr2_sid.h"
#include "trace2/tr2_sysenv.h"
diff --git a/trace2/tr2_sid.c b/trace2/tr2_sid.c
index dc6e75ef13..09c4ef0d17 100644
--- a/trace2/tr2_sid.c
+++ b/trace2/tr2_sid.c
@@ -1,4 +1,6 @@
-#include "cache.h"
+#include "git-compat-util.h"
+#include "hex.h"
+#include "strbuf.h"
#include "trace2/tr2_tbuf.h"
#include "trace2/tr2_sid.h"
diff --git a/trace2/tr2_sysenv.c b/trace2/tr2_sysenv.c
index a380dcf910..069786cb92 100644
--- a/trace2/tr2_sysenv.c
+++ b/trace2/tr2_sysenv.c
@@ -1,4 +1,4 @@
-#include "cache.h"
+#include "git-compat-util.h"
#include "config.h"
#include "dir.h"
#include "tr2_sysenv.h"
diff --git a/trace2/tr2_tbuf.c b/trace2/tr2_tbuf.c
index 2498482d9a..c3b3822ed7 100644
--- a/trace2/tr2_tbuf.c
+++ b/trace2/tr2_tbuf.c
@@ -1,4 +1,4 @@
-#include "cache.h"
+#include "git-compat-util.h"
#include "tr2_tbuf.h"
void tr2_tbuf_local_time(struct tr2_tbuf *tb)
diff --git a/trace2/tr2_tgt.h b/trace2/tr2_tgt.h
index 65f94e1574..bf8745c4f0 100644
--- a/trace2/tr2_tgt.h
+++ b/trace2/tr2_tgt.h
@@ -4,6 +4,12 @@
struct child_process;
struct repository;
struct json_writer;
+struct tr2_timer_metadata;
+struct tr2_timer;
+struct tr2_counter_metadata;
+struct tr2_counter;
+
+#define NS_TO_SEC(ns) ((double)(ns) / 1.0e9)
/*
* Function prototypes for a TRACE2 "target" vtable.
@@ -96,6 +102,14 @@ typedef void(tr2_tgt_evt_printf_va_fl_t)(const char *file, int line,
uint64_t us_elapsed_absolute,
const char *fmt, va_list ap);
+typedef void(tr2_tgt_evt_timer_t)(const struct tr2_timer_metadata *meta,
+ const struct tr2_timer *timer,
+ int is_final_data);
+
+typedef void(tr2_tgt_evt_counter_t)(const struct tr2_counter_metadata *meta,
+ const struct tr2_counter *counter,
+ int is_final_data);
+
/*
* "vtable" for a TRACE2 target. Use NULL if a target does not want
* to emit that message.
@@ -132,6 +146,8 @@ struct tr2_tgt {
tr2_tgt_evt_data_fl_t *pfn_data_fl;
tr2_tgt_evt_data_json_fl_t *pfn_data_json_fl;
tr2_tgt_evt_printf_va_fl_t *pfn_printf_va_fl;
+ tr2_tgt_evt_timer_t *pfn_timer;
+ tr2_tgt_evt_counter_t *pfn_counter;
};
/* clang-format on */
diff --git a/trace2/tr2_tgt_event.c b/trace2/tr2_tgt_event.c
index 37a3163be1..2af53e5d4d 100644
--- a/trace2/tr2_tgt_event.c
+++ b/trace2/tr2_tgt_event.c
@@ -1,6 +1,7 @@
-#include "cache.h"
+#include "git-compat-util.h"
#include "config.h"
#include "json-writer.h"
+#include "repository.h"
#include "run-command.h"
#include "version.h"
#include "trace2/tr2_dst.h"
@@ -9,6 +10,7 @@
#include "trace2/tr2_sysenv.h"
#include "trace2/tr2_tgt.h"
#include "trace2/tr2_tls.h"
+#include "trace2/tr2_tmr.h"
static struct tr2_dst tr2dst_event = {
.sysenv_var = TR2_SYSENV_EVENT,
@@ -90,7 +92,7 @@ static void event_fmt_prepare(const char *event_name, const char *file,
jw_object_string(jw, "event", event_name);
jw_object_string(jw, "sid", tr2_sid_get());
- jw_object_string(jw, "thread", ctx->thread_name.buf);
+ jw_object_string(jw, "thread", ctx->thread_name);
/*
* In brief mode, only emit <time> on these 2 event types.
@@ -617,6 +619,48 @@ static void fn_data_json_fl(const char *file, int line,
}
}
+static void fn_timer(const struct tr2_timer_metadata *meta,
+ const struct tr2_timer *timer,
+ int is_final_data)
+{
+ const char *event_name = is_final_data ? "timer" : "th_timer";
+ struct json_writer jw = JSON_WRITER_INIT;
+ double t_total = NS_TO_SEC(timer->total_ns);
+ double t_min = NS_TO_SEC(timer->min_ns);
+ double t_max = NS_TO_SEC(timer->max_ns);
+
+ jw_object_begin(&jw, 0);
+ event_fmt_prepare(event_name, __FILE__, __LINE__, NULL, &jw);
+ jw_object_string(&jw, "category", meta->category);
+ jw_object_string(&jw, "name", meta->name);
+ jw_object_intmax(&jw, "intervals", timer->interval_count);
+ jw_object_double(&jw, "t_total", 6, t_total);
+ jw_object_double(&jw, "t_min", 6, t_min);
+ jw_object_double(&jw, "t_max", 6, t_max);
+ jw_end(&jw);
+
+ tr2_dst_write_line(&tr2dst_event, &jw.json);
+ jw_release(&jw);
+}
+
+static void fn_counter(const struct tr2_counter_metadata *meta,
+ const struct tr2_counter *counter,
+ int is_final_data)
+{
+ const char *event_name = is_final_data ? "counter" : "th_counter";
+ struct json_writer jw = JSON_WRITER_INIT;
+
+ jw_object_begin(&jw, 0);
+ event_fmt_prepare(event_name, __FILE__, __LINE__, NULL, &jw);
+ jw_object_string(&jw, "category", meta->category);
+ jw_object_string(&jw, "name", meta->name);
+ jw_object_intmax(&jw, "count", counter->value);
+ jw_end(&jw);
+
+ tr2_dst_write_line(&tr2dst_event, &jw.json);
+ jw_release(&jw);
+}
+
struct tr2_tgt tr2_tgt_event = {
.pdst = &tr2dst_event,
@@ -648,4 +692,6 @@ struct tr2_tgt tr2_tgt_event = {
.pfn_data_fl = fn_data_fl,
.pfn_data_json_fl = fn_data_json_fl,
.pfn_printf_va_fl = NULL,
+ .pfn_timer = fn_timer,
+ .pfn_counter = fn_counter,
};
diff --git a/trace2/tr2_tgt_normal.c b/trace2/tr2_tgt_normal.c
index 69f8033077..1ebfb464d5 100644
--- a/trace2/tr2_tgt_normal.c
+++ b/trace2/tr2_tgt_normal.c
@@ -1,5 +1,6 @@
-#include "cache.h"
+#include "git-compat-util.h"
#include "config.h"
+#include "repository.h"
#include "run-command.h"
#include "quote.h"
#include "version.h"
@@ -8,6 +9,7 @@
#include "trace2/tr2_tbuf.h"
#include "trace2/tr2_tgt.h"
#include "trace2/tr2_tls.h"
+#include "trace2/tr2_tmr.h"
static struct tr2_dst tr2dst_normal = {
.sysenv_var = TR2_SYSENV_NORMAL,
@@ -329,6 +331,42 @@ static void fn_printf_va_fl(const char *file, int line,
strbuf_release(&buf_payload);
}
+static void fn_timer(const struct tr2_timer_metadata *meta,
+ const struct tr2_timer *timer,
+ int is_final_data)
+{
+ const char *event_name = is_final_data ? "timer" : "th_timer";
+ struct strbuf buf_payload = STRBUF_INIT;
+ double t_total = NS_TO_SEC(timer->total_ns);
+ double t_min = NS_TO_SEC(timer->min_ns);
+ double t_max = NS_TO_SEC(timer->max_ns);
+
+ strbuf_addf(&buf_payload, ("%s %s/%s"
+ " intervals:%"PRIu64
+ " total:%8.6f min:%8.6f max:%8.6f"),
+ event_name, meta->category, meta->name,
+ timer->interval_count,
+ t_total, t_min, t_max);
+
+ normal_io_write_fl(__FILE__, __LINE__, &buf_payload);
+ strbuf_release(&buf_payload);
+}
+
+static void fn_counter(const struct tr2_counter_metadata *meta,
+ const struct tr2_counter *counter,
+ int is_final_data)
+{
+ const char *event_name = is_final_data ? "counter" : "th_counter";
+ struct strbuf buf_payload = STRBUF_INIT;
+
+ strbuf_addf(&buf_payload, "%s %s/%s value:%"PRIu64,
+ event_name, meta->category, meta->name,
+ counter->value);
+
+ normal_io_write_fl(__FILE__, __LINE__, &buf_payload);
+ strbuf_release(&buf_payload);
+}
+
struct tr2_tgt tr2_tgt_normal = {
.pdst = &tr2dst_normal,
@@ -360,4 +398,6 @@ struct tr2_tgt tr2_tgt_normal = {
.pfn_data_fl = NULL,
.pfn_data_json_fl = NULL,
.pfn_printf_va_fl = fn_printf_va_fl,
+ .pfn_timer = fn_timer,
+ .pfn_counter = fn_counter,
};
diff --git a/trace2/tr2_tgt_perf.c b/trace2/tr2_tgt_perf.c
index 8cb792488c..328e483a05 100644
--- a/trace2/tr2_tgt_perf.c
+++ b/trace2/tr2_tgt_perf.c
@@ -1,5 +1,6 @@
-#include "cache.h"
+#include "git-compat-util.h"
#include "config.h"
+#include "repository.h"
#include "run-command.h"
#include "quote.h"
#include "version.h"
@@ -10,6 +11,7 @@
#include "trace2/tr2_tbuf.h"
#include "trace2/tr2_tgt.h"
#include "trace2/tr2_tls.h"
+#include "trace2/tr2_tmr.h"
static struct tr2_dst tr2dst_perf = {
.sysenv_var = TR2_SYSENV_PERF,
@@ -108,7 +110,7 @@ static void perf_fmt_prepare(const char *event_name,
strbuf_addf(buf, "d%d | ", tr2_sid_depth());
strbuf_addf(buf, "%-*s | %-*s | ", TR2_MAX_THREAD_NAME,
- ctx->thread_name.buf, TR2FMT_PERF_MAX_EVENT_NAME,
+ ctx->thread_name, TR2FMT_PERF_MAX_EVENT_NAME,
event_name);
len = buf->len + TR2FMT_PERF_REPO_WIDTH;
@@ -555,6 +557,44 @@ static void fn_printf_va_fl(const char *file, int line,
strbuf_release(&buf_payload);
}
+static void fn_timer(const struct tr2_timer_metadata *meta,
+ const struct tr2_timer *timer,
+ int is_final_data)
+{
+ const char *event_name = is_final_data ? "timer" : "th_timer";
+ struct strbuf buf_payload = STRBUF_INIT;
+ double t_total = NS_TO_SEC(timer->total_ns);
+ double t_min = NS_TO_SEC(timer->min_ns);
+ double t_max = NS_TO_SEC(timer->max_ns);
+
+ strbuf_addf(&buf_payload, ("name:%s"
+ " intervals:%"PRIu64
+ " total:%8.6f min:%8.6f max:%8.6f"),
+ meta->name,
+ timer->interval_count,
+ t_total, t_min, t_max);
+
+ perf_io_write_fl(__FILE__, __LINE__, event_name, NULL, NULL, NULL,
+ meta->category, &buf_payload);
+ strbuf_release(&buf_payload);
+}
+
+static void fn_counter(const struct tr2_counter_metadata *meta,
+ const struct tr2_counter *counter,
+ int is_final_data)
+{
+ const char *event_name = is_final_data ? "counter" : "th_counter";
+ struct strbuf buf_payload = STRBUF_INIT;
+
+ strbuf_addf(&buf_payload, "name:%s value:%"PRIu64,
+ meta->name,
+ counter->value);
+
+ perf_io_write_fl(__FILE__, __LINE__, event_name, NULL, NULL, NULL,
+ meta->category, &buf_payload);
+ strbuf_release(&buf_payload);
+}
+
struct tr2_tgt tr2_tgt_perf = {
.pdst = &tr2dst_perf,
@@ -586,4 +626,6 @@ struct tr2_tgt tr2_tgt_perf = {
.pfn_data_fl = fn_data_fl,
.pfn_data_json_fl = fn_data_json_fl,
.pfn_printf_va_fl = fn_printf_va_fl,
+ .pfn_timer = fn_timer,
+ .pfn_counter = fn_counter,
};
diff --git a/trace2/tr2_tls.c b/trace2/tr2_tls.c
index 7da94aba52..9f46ae12f5 100644
--- a/trace2/tr2_tls.c
+++ b/trace2/tr2_tls.c
@@ -1,5 +1,7 @@
-#include "cache.h"
+#include "git-compat-util.h"
+#include "alloc.h"
#include "thread-utils.h"
+#include "trace.h"
#include "trace2/tr2_tls.h"
/*
@@ -31,10 +33,11 @@ void tr2tls_start_process_clock(void)
tr2tls_us_start_process = getnanotime() / 1000;
}
-struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_name,
+struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_base_name,
uint64_t us_thread_start)
{
struct tr2tls_thread_ctx *ctx = xcalloc(1, sizeof(*ctx));
+ struct strbuf buf = STRBUF_INIT;
/*
* Implicitly "tr2tls_push_self()" to capture the thread's start
@@ -47,12 +50,13 @@ struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_name,
ctx->thread_id = tr2tls_locked_increment(&tr2_next_thread_id);
- strbuf_init(&ctx->thread_name, 0);
+ strbuf_init(&buf, 0);
if (ctx->thread_id)
- strbuf_addf(&ctx->thread_name, "th%02d:", ctx->thread_id);
- strbuf_addstr(&ctx->thread_name, thread_name);
- if (ctx->thread_name.len > TR2_MAX_THREAD_NAME)
- strbuf_setlen(&ctx->thread_name, TR2_MAX_THREAD_NAME);
+ strbuf_addf(&buf, "th%02d:", ctx->thread_id);
+ strbuf_addstr(&buf, thread_base_name);
+ if (buf.len > TR2_MAX_THREAD_NAME)
+ strbuf_setlen(&buf, TR2_MAX_THREAD_NAME);
+ ctx->thread_name = strbuf_detach(&buf, NULL);
pthread_setspecific(tr2tls_key, ctx);
@@ -69,9 +73,9 @@ struct tr2tls_thread_ctx *tr2tls_get_self(void)
ctx = pthread_getspecific(tr2tls_key);
/*
- * If the thread-proc did not call trace2_thread_start(), we won't
- * have any TLS data associated with the current thread. Fix it
- * here and silently continue.
+ * If the current thread's thread-proc did not call
+ * trace2_thread_start(), then the thread will not have any
+ * thread-local storage. Create it now and silently continue.
*/
if (!ctx)
ctx = tr2tls_create_self("unknown", getnanotime() / 1000);
@@ -95,7 +99,7 @@ void tr2tls_unset_self(void)
pthread_setspecific(tr2tls_key, NULL);
- strbuf_release(&ctx->thread_name);
+ free((char *)ctx->thread_name);
free(ctx->array_us_start);
free(ctx);
}
@@ -113,7 +117,7 @@ void tr2tls_pop_self(void)
struct tr2tls_thread_ctx *ctx = tr2tls_get_self();
if (!ctx->nr_open_regions)
- BUG("no open regions in thread '%s'", ctx->thread_name.buf);
+ BUG("no open regions in thread '%s'", ctx->thread_name);
ctx->nr_open_regions--;
}
@@ -179,3 +183,13 @@ int tr2tls_locked_increment(int *p)
return current_value;
}
+
+void tr2tls_lock(void)
+{
+ pthread_mutex_lock(&tr2tls_mutex);
+}
+
+void tr2tls_unlock(void)
+{
+ pthread_mutex_unlock(&tr2tls_mutex);
+}
diff --git a/trace2/tr2_tls.h b/trace2/tr2_tls.h
index b1e327a928..f9049805d4 100644
--- a/trace2/tr2_tls.h
+++ b/trace2/tr2_tls.h
@@ -2,6 +2,14 @@
#define TR2_TLS_H
#include "strbuf.h"
+#include "trace2/tr2_ctr.h"
+#include "trace2/tr2_tmr.h"
+
+/*
+ * Notice: the term "TLS" refers to "thread-local storage" in the
+ * Trace2 source files. This usage is borrowed from GCC and Windows.
+ * There is NO relation to "transport layer security".
+ */
/*
* Arbitry limit for thread names for column alignment.
@@ -9,33 +17,40 @@
#define TR2_MAX_THREAD_NAME (24)
struct tr2tls_thread_ctx {
- struct strbuf thread_name;
+ const char *thread_name;
uint64_t *array_us_start;
- int alloc;
- int nr_open_regions; /* plays role of "nr" in ALLOC_GROW */
+ size_t alloc;
+ size_t nr_open_regions; /* plays role of "nr" in ALLOC_GROW */
int thread_id;
+ struct tr2_timer_block timer_block;
+ struct tr2_counter_block counter_block;
+ unsigned int used_any_timer:1;
+ unsigned int used_any_per_thread_timer:1;
+ unsigned int used_any_counter:1;
+ unsigned int used_any_per_thread_counter:1;
};
/*
- * Create TLS data for the current thread. This gives us a place to
- * put per-thread data, such as thread start time, function nesting
- * and a per-thread label for our messages.
- *
- * We assume the first thread is "main". Other threads are given
- * non-zero thread-ids to help distinguish messages from concurrent
- * threads.
+ * Create thread-local storage for the current thread.
*
- * Truncate the thread name if necessary to help with column alignment
- * in printf-style messages.
+ * The first thread in the process will have:
+ * { .thread_id=0, .thread_name="main" }
+ * Subsequent threads are given a non-zero thread_id and a thread_name
+ * constructed from the id and a thread base name (which is usually just
+ * the name of the thread-proc function). For example:
+ * { .thread_id=10, .thread_name="th10:fsm-listen" }
+ * This helps to identify and distinguish messages from concurrent threads.
+ * The ctx.thread_name field is truncated if necessary to help with column
+ * alignment in printf-style messages.
*
* In this and all following functions the term "self" refers to the
* current thread.
*/
-struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_name,
+struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_base_name,
uint64_t us_thread_start);
/*
- * Get our TLS data.
+ * Get the thread-local storage pointer of the current thread.
*/
struct tr2tls_thread_ctx *tr2tls_get_self(void);
@@ -45,7 +60,7 @@ struct tr2tls_thread_ctx *tr2tls_get_self(void);
int tr2tls_is_main_thread(void);
/*
- * Free our TLS data.
+ * Free the current thread's thread-local storage.
*/
void tr2tls_unset_self(void);
@@ -81,12 +96,12 @@ uint64_t tr2tls_region_elasped_self(uint64_t us);
uint64_t tr2tls_absolute_elapsed(uint64_t us);
/*
- * Initialize the tr2 TLS system.
+ * Initialize thread-local storage for Trace2.
*/
void tr2tls_init(void);
/*
- * Free all tr2 TLS resources.
+ * Free all Trace2 thread-local storage resources.
*/
void tr2tls_release(void);
@@ -100,4 +115,10 @@ int tr2tls_locked_increment(int *p);
*/
void tr2tls_start_process_clock(void);
+/*
+ * Explicitly lock/unlock our mutex.
+ */
+void tr2tls_lock(void);
+void tr2tls_unlock(void);
+
#endif /* TR2_TLS_H */
diff --git a/trace2/tr2_tmr.c b/trace2/tr2_tmr.c
new file mode 100644
index 0000000000..31d0e4d1bd
--- /dev/null
+++ b/trace2/tr2_tmr.c
@@ -0,0 +1,183 @@
+#include "git-compat-util.h"
+#include "thread-utils.h"
+#include "trace2/tr2_tgt.h"
+#include "trace2/tr2_tls.h"
+#include "trace2/tr2_tmr.h"
+#include "trace.h"
+
+#define MY_MAX(a, b) ((a) > (b) ? (a) : (b))
+#define MY_MIN(a, b) ((a) < (b) ? (a) : (b))
+
+/*
+ * A global timer block to aggregate values from the partial sums from
+ * each thread.
+ */
+static struct tr2_timer_block final_timer_block; /* access under tr2tls_mutex */
+
+/*
+ * Define metadata for each stopwatch timer.
+ *
+ * This array must match "enum trace2_timer_id" and the values
+ * in "struct tr2_timer_block.timer[*]".
+ */
+static struct tr2_timer_metadata tr2_timer_metadata[TRACE2_NUMBER_OF_TIMERS] = {
+ [TRACE2_TIMER_ID_TEST1] = {
+ .category = "test",
+ .name = "test1",
+ .want_per_thread_events = 0,
+ },
+ [TRACE2_TIMER_ID_TEST2] = {
+ .category = "test",
+ .name = "test2",
+ .want_per_thread_events = 1,
+ },
+
+ /* Add additional metadata before here. */
+};
+
+void tr2_start_timer(enum trace2_timer_id tid)
+{
+ struct tr2tls_thread_ctx *ctx = tr2tls_get_self();
+ struct tr2_timer *t = &ctx->timer_block.timer[tid];
+
+ t->recursion_count++;
+ if (t->recursion_count > 1)
+ return; /* ignore recursive starts */
+
+ t->start_ns = getnanotime();
+}
+
+void tr2_stop_timer(enum trace2_timer_id tid)
+{
+ struct tr2tls_thread_ctx *ctx = tr2tls_get_self();
+ struct tr2_timer *t = &ctx->timer_block.timer[tid];
+ uint64_t ns_now;
+ uint64_t ns_interval;
+
+ assert(t->recursion_count > 0);
+
+ t->recursion_count--;
+ if (t->recursion_count)
+ return; /* still in recursive call(s) */
+
+ ns_now = getnanotime();
+ ns_interval = ns_now - t->start_ns;
+
+ t->total_ns += ns_interval;
+
+ /*
+ * min_ns was initialized to zero (in the xcalloc()) rather
+ * than UINT_MAX when the block of timers was allocated,
+ * so we should always set both the min_ns and max_ns values
+ * the first time that the timer is used.
+ */
+ if (!t->interval_count) {
+ t->min_ns = ns_interval;
+ t->max_ns = ns_interval;
+ } else {
+ t->min_ns = MY_MIN(ns_interval, t->min_ns);
+ t->max_ns = MY_MAX(ns_interval, t->max_ns);
+ }
+
+ t->interval_count++;
+
+ ctx->used_any_timer = 1;
+ if (tr2_timer_metadata[tid].want_per_thread_events)
+ ctx->used_any_per_thread_timer = 1;
+}
+
+void tr2_update_final_timers(void)
+{
+ struct tr2tls_thread_ctx *ctx = tr2tls_get_self();
+ enum trace2_timer_id tid;
+
+ if (!ctx->used_any_timer)
+ return;
+
+ /*
+ * Accessing `final_timer_block` requires holding `tr2tls_mutex`.
+ * We assume that our caller is holding the lock.
+ */
+
+ for (tid = 0; tid < TRACE2_NUMBER_OF_TIMERS; tid++) {
+ struct tr2_timer *t_final = &final_timer_block.timer[tid];
+ struct tr2_timer *t = &ctx->timer_block.timer[tid];
+
+ if (t->recursion_count) {
+ /*
+ * The current thread is exiting with
+ * timer[tid] still running.
+ *
+ * Technically, this is a bug, but I'm going
+ * to ignore it.
+ *
+ * I don't think it is worth calling die()
+ * for. I don't think it is worth killing the
+ * process for this bookkeeping error. We
+ * might want to call warning(), but I'm going
+ * to wait on that.
+ *
+ * The downside here is that total_ns won't
+ * include the current open interval (now -
+ * start_ns). I can live with that.
+ */
+ }
+
+ if (!t->interval_count)
+ continue; /* this timer was not used by this thread */
+
+ t_final->total_ns += t->total_ns;
+
+ /*
+ * final_timer_block.timer[tid].min_ns was initialized to
+ * was initialized to zero rather than UINT_MAX, so we should
+ * always set both the min_ns and max_ns values the first time
+ * that we add a partial sum into it.
+ */
+ if (!t_final->interval_count) {
+ t_final->min_ns = t->min_ns;
+ t_final->max_ns = t->max_ns;
+ } else {
+ t_final->min_ns = MY_MIN(t_final->min_ns, t->min_ns);
+ t_final->max_ns = MY_MAX(t_final->max_ns, t->max_ns);
+ }
+
+ t_final->interval_count += t->interval_count;
+ }
+}
+
+void tr2_emit_per_thread_timers(tr2_tgt_evt_timer_t *fn_apply)
+{
+ struct tr2tls_thread_ctx *ctx = tr2tls_get_self();
+ enum trace2_timer_id tid;
+
+ if (!ctx->used_any_per_thread_timer)
+ return;
+
+ /*
+ * For each timer, if the timer wants per-thread events and
+ * this thread used it, emit it.
+ */
+ for (tid = 0; tid < TRACE2_NUMBER_OF_TIMERS; tid++)
+ if (tr2_timer_metadata[tid].want_per_thread_events &&
+ ctx->timer_block.timer[tid].interval_count)
+ fn_apply(&tr2_timer_metadata[tid],
+ &ctx->timer_block.timer[tid],
+ 0);
+}
+
+void tr2_emit_final_timers(tr2_tgt_evt_timer_t *fn_apply)
+{
+ enum trace2_timer_id tid;
+
+ /*
+ * Accessing `final_timer_block` requires holding `tr2tls_mutex`.
+ * We assume that our caller is holding the lock.
+ */
+
+ for (tid = 0; tid < TRACE2_NUMBER_OF_TIMERS; tid++)
+ if (final_timer_block.timer[tid].interval_count)
+ fn_apply(&tr2_timer_metadata[tid],
+ &final_timer_block.timer[tid],
+ 1);
+}
diff --git a/trace2/tr2_tmr.h b/trace2/tr2_tmr.h
new file mode 100644
index 0000000000..d575357613
--- /dev/null
+++ b/trace2/tr2_tmr.h
@@ -0,0 +1,140 @@
+#ifndef TR2_TMR_H
+#define TR2_TMR_H
+
+#include "trace2.h"
+#include "trace2/tr2_tgt.h"
+
+/*
+ * Define a mechanism to allow "stopwatch" timers.
+ *
+ * Timers can be used to measure "interesting" activity that does not
+ * fit the "region" model, such as code called from many different
+ * regions (like zlib) and/or where data for individual calls are not
+ * interesting or are too numerous to be efficiently logged.
+ *
+ * Timer values are accumulated during program execution and emitted
+ * to the Trace2 logs at program exit.
+ *
+ * To make this model efficient, we define a compile-time fixed set of
+ * timers and timer ids using a "timer block" array in thread-local
+ * storage. This gives us constant time access to each timer within
+ * each thread, since we want start/stop operations to be as fast as
+ * possible. This lets us avoid the complexities of dynamically
+ * allocating a timer on the first use by a thread and/or possibly
+ * sharing that timer definition with other concurrent threads.
+ * However, this does require that we define time the set of timers at
+ * compile time.
+ *
+ * Each thread uses the timer block in its thread-local storage to
+ * compute partial sums for each timer (without locking). When a
+ * thread exits, those partial sums are (under lock) added to the
+ * global final sum.
+ *
+ * Using this "timer block" model costs ~48 bytes per timer per thread
+ * (we have about six uint64 fields per timer). This does increase
+ * the size of the thread-local storage block, but it is allocated (at
+ * thread create time) and not on the thread stack, so I'm not worried
+ * about the size.
+ *
+ * Partial sums for each timer are optionally emitted when a thread
+ * exits.
+ *
+ * Final sums for each timer are emitted between the "exit" and
+ * "atexit" events.
+ *
+ * A parallel "timer metadata" table contains the "category" and "name"
+ * fields for each timer. This eliminates the need to include those
+ * args in the various timer APIs.
+ */
+
+/*
+ * The definition of an individual timer and used by an individual
+ * thread.
+ */
+struct tr2_timer {
+ /*
+ * Total elapsed time for this timer in this thread in nanoseconds.
+ */
+ uint64_t total_ns;
+
+ /*
+ * The maximum and minimum interval values observed for this
+ * timer in this thread.
+ */
+ uint64_t min_ns;
+ uint64_t max_ns;
+
+ /*
+ * The value of the clock when this timer was started in this
+ * thread. (Undefined when the timer is not active in this
+ * thread.)
+ */
+ uint64_t start_ns;
+
+ /*
+ * Number of times that this timer has been started and stopped
+ * in this thread. (Recursive starts are ignored.)
+ */
+ uint64_t interval_count;
+
+ /*
+ * Number of nested starts on the stack in this thread. (We
+ * ignore recursive starts and use this to track the recursive
+ * calls.)
+ */
+ unsigned int recursion_count;
+};
+
+/*
+ * Metadata for a timer.
+ */
+struct tr2_timer_metadata {
+ const char *category;
+ const char *name;
+
+ /*
+ * True if we should emit per-thread events for this timer
+ * when individual threads exit.
+ */
+ unsigned int want_per_thread_events:1;
+};
+
+/*
+ * A compile-time fixed-size block of timers to insert into
+ * thread-local storage. This wrapper is used to avoid quirks
+ * of C and the usual need to pass an array size argument.
+ */
+struct tr2_timer_block {
+ struct tr2_timer timer[TRACE2_NUMBER_OF_TIMERS];
+};
+
+/*
+ * Private routines used by trace2.c to actually start/stop an
+ * individual timer in the current thread.
+ */
+void tr2_start_timer(enum trace2_timer_id tid);
+void tr2_stop_timer(enum trace2_timer_id tid);
+
+/*
+ * Add the current thread's timer data to the global totals.
+ * This is called during thread-exit.
+ *
+ * Caller must be holding the tr2tls_mutex.
+ */
+void tr2_update_final_timers(void);
+
+/*
+ * Emit per-thread timer data for the current thread.
+ * This is called during thread-exit.
+ */
+void tr2_emit_per_thread_timers(tr2_tgt_evt_timer_t *fn_apply);
+
+/*
+ * Emit global total timer values.
+ * This is called during atexit handling.
+ *
+ * Caller must be holding the tr2tls_mutex.
+ */
+void tr2_emit_final_timers(tr2_tgt_evt_timer_t *fn_apply);
+
+#endif /* TR2_TMR_H */