[PATCH v2 0/7] Trace2 timers and counters and some cleanup
- From
- Jeff Hostetler via GitGitGadget <gitgitgadget@gmail.com>
- Date
- Oct 12, 2022, 18:52 UTC
- Message-ID
- <pull.1373.v2.git.1665600750.gitgitgadget@gmail.com>
- In-Reply-To
- <pull.1373.git.1664900407.gitgitgadget@gmail.com>
Here is version 2 of this series to add timers and counters to Trace2.
Changes since V1:
* I dropped the commits concerning compiler errors in Clang 11.0.0 on MacOS. I've sent them to the mailing list in a separate series, since they had nothing to do with the main topic of this series.
* I moved the documentation changes earlier in the series to get it out of the way (and eliminate the need to update it later commits).
* After a long conversation on the mailing list, I redid the two thread-name commits to simplify and hopefully eliminate the remaining misunderstandings and/or short-comings of my previous attempt and explanations. We now use a "const char *" for the field in the thread-ctx that we format and detach from a strbuf during thread-start. The goal here is to move away from a modifyable strbuf in the thread-ctx itself (to avoid giving the appearance that a caller could modify the thread-name at some point, when that was not intended).
The last 2 commits add the stopwatch timers and the global counters and are unchanged from the previous version.
Jeff Hostetler (7): trace2: use size_t alloc,nr_open_regions in tr2tls_thread_ctx tr2tls: clarify TLS terminology api-trace2.txt: elminate section describing the public trace2 API trace2: rename the thread_name argument to trace2_thread_start trace2: convert ctx.thread_name from strbuf to pointer trace2: add stopwatch timers trace2: add global counter mechanism
Documentation/technical/api-trace2.txt | 190 +++++++++++++++++-------- Makefile | 2 + t/helper/test-trace2.c | 187 ++++++++++++++++++++++++ t/t0211-trace2-perf.sh | 95 +++++++++++++ t/t0211/scrub_perf.perl | 6 + trace2.c | 121 +++++++++++++++- trace2.h | 101 +++++++++++-- trace2/tr2_ctr.c | 101 +++++++++++++ trace2/tr2_ctr.h | 104 ++++++++++++++ trace2/tr2_tgt.h | 14 ++ trace2/tr2_tgt_event.c | 47 +++++- trace2/tr2_tgt_normal.c | 39 +++++ trace2/tr2_tgt_perf.c | 43 +++++- trace2/tr2_tls.c | 34 +++-- trace2/tr2_tls.h | 55 ++++--- trace2/tr2_tmr.c | 182 +++++++++++++++++++++++ trace2/tr2_tmr.h | 140 ++++++++++++++++++ 17 files changed, 1359 insertions(+), 102 deletions(-) create mode 100644 trace2/tr2_ctr.c create mode 100644 trace2/tr2_ctr.h create mode 100644 trace2/tr2_tmr.c create mode 100644 trace2/tr2_tmr.h
base-commit: 3dcec76d9df911ed8321007b1d197c1a206dc164 Published-As: https://github.com/gitgitgadget/git/releases/tag/pr-1373%2Fjeffhostetler%2Ftrace2-stopwatch-v4-v2 Fetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-1373/jeffhostetler/trace2-stopwatch-v4-v2 Pull-Request: https://github.com/gitgitgadget/git/pull/1373
Range-diff vs v1:
1: 870f29166ea < -: ----------- builtin/merge-file: fix compiler warning on MacOS with clang 11.0.0
2: 43c41f7035d < -: ----------- builtin/unpack-objects.c: fix compiler warning on MacOS with clang 11.0.0
3: 73704b6f660 = 1: 6e7e4f3187e trace2: use size_t alloc,nr_open_regions in tr2tls_thread_ctx
4: 7123886a804 = 2: 9dee7a75903 tr2tls: clarify TLS terminology
7: 77a4daf9a4b ! 3: 804dab9e1a7 api-trace2.txt: elminate section describing the public trace2 API
@@ Documentation/technical/api-trace2.txt: take a `va_list` argument.
-
-These messages are concerned with Git thread usage.
-
--e.g: `void trace2_thread_start(const char *name_hint)`.
+-e.g: `void trace2_thread_start(const char *thread_name)`.
-
-=== Region and Data Messages
-
5: 82f1672e180 ! 4: 637b422b860 trace2: rename trace2 thread_name argument as name_hint
@@ Metadata
Author: Jeff Hostetler <jeffhost@microsoft.com>
## Commit message ##
- trace2: rename trace2 thread_name argument as name_hint
+ trace2: rename the thread_name argument to trace2_thread_start
- Rename the `thread_name` argument in `tr2tls_create_self()`
- and `trace2_thread_start()` to be `name_hint` to make it clear
- that the passed argument is a hint that will be used to create
+ Rename the `thread_name` argument in `tr2tls_create_self()` and
+ `trace2_thread_start()` to be `thread_base_name` to make it clearer
+ that the passed argument is a component used in the construction of
the actual `struct tr2tls_thread_ctx.thread_name` variable.
- This should make it clearer in the API that the trace2 layer
- does not borrow the caller's string pointer/buffer, but rather
- that it will use that hint in formatting the actual thread's
- name. Previous discussion on the mailing list indicated that
- there was confusion about this point.
+ The base name will be used along with the thread id to create a
+ unique thread name.
This commit does not change how the `thread_name` field is
allocated or stored within the `tr2tls_thread_ctx` structure.
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
- ## Documentation/technical/api-trace2.txt ##
-@@ Documentation/technical/api-trace2.txt: e.g: `void trace2_child_start(struct child_process *cmd)`.
-
- These messages are concerned with Git thread usage.
-
--e.g: `void trace2_thread_start(const char *thread_name)`.
-+e.g: `void trace2_thread_start(const char *name_hint)`.
-
- === Region and Data Messages
-
-
## trace2.c ##
@@ trace2.c: void trace2_exec_result_fl(const char *file, int line, int exec_id, int code)
file, line, us_elapsed_absolute, exec_id, code);
}
-void trace2_thread_start_fl(const char *file, int line, const char *thread_name)
-+void trace2_thread_start_fl(const char *file, int line, const char *name_hint)
++void trace2_thread_start_fl(const char *file, int line, const char *thread_base_name)
{
struct tr2_tgt *tgt_j;
int j;
@@ trace2.c: void trace2_thread_start_fl(const char *file, int line, const char *th
trace2_region_enter_printf_fl(file, line, NULL, NULL, NULL,
"thread-proc on main: %s",
- thread_name);
-+ name_hint);
++ thread_base_name);
return;
}
@@ trace2.c: void trace2_thread_start_fl(const char *file, int line, const char *th
us_elapsed_absolute = tr2tls_absolute_elapsed(us_now);
- tr2tls_create_self(thread_name, us_now);
-+ tr2tls_create_self(name_hint, us_now);
++ tr2tls_create_self(thread_base_name, us_now);
for_each_wanted_builtin (j, tgt_j)
if (tgt_j->pfn_thread_start_fl)
@@ trace2.h: void trace2_exec_result_fl(const char *file, int line, int exec_id, in
*
- * Thread names should be descriptive, like "preload_index".
- * Thread names will be decorated with an instance number automatically.
-+ * The thread name hint should be descriptive, like "preload_index" or
++ * The thread base name should be descriptive, like "preload_index" or
+ * taken from the thread-proc function. A unique thread name will be
-+ * created from the hint and the thread id automatically.
++ * created from the given base name and the thread id automatically.
*/
void trace2_thread_start_fl(const char *file, int line,
- const char *thread_name);
-+ const char *name_hint);
++ const char *thread_base_name);
-#define trace2_thread_start(thread_name) \
- trace2_thread_start_fl(__FILE__, __LINE__, (thread_name))
-+#define trace2_thread_start(name_hint) \
-+ trace2_thread_start_fl(__FILE__, __LINE__, (name_hint))
++#define trace2_thread_start(thread_base_name) \
++ trace2_thread_start_fl(__FILE__, __LINE__, (thread_base_name))
/*
* Emit a 'thread_exit' event. This must be called from inside the
@@ trace2/tr2_tls.c: void tr2tls_start_process_clock(void)
}
-struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_name,
-+struct tr2tls_thread_ctx *tr2tls_create_self(const char *name_hint,
++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));
@@ trace2/tr2_tls.c: struct tr2tls_thread_ctx *tr2tls_create_self(const char *threa
if (ctx->thread_id)
strbuf_addf(&ctx->thread_name, "th%02d:", ctx->thread_id);
- strbuf_addstr(&ctx->thread_name, thread_name);
-+ strbuf_addstr(&ctx->thread_name, name_hint);
++ strbuf_addstr(&ctx->thread_name, thread_base_name);
if (ctx->thread_name.len > TR2_MAX_THREAD_NAME)
strbuf_setlen(&ctx->thread_name, TR2_MAX_THREAD_NAME);
@@ trace2/tr2_tls.h: struct tr2tls_thread_ctx {
+ * 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 "name hint" (which is usually based
-+ * upon the name of the thread-proc function). For example:
++ * 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="th10fsm-listen" }
+ * This helps to identify and distinguish messages from concurrent threads.
+ * The ctx.thread_name field is truncated if necessary to help with column
@@ trace2/tr2_tls.h: struct tr2tls_thread_ctx {
* current thread.
*/
-struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_name,
-+struct tr2tls_thread_ctx *tr2tls_create_self(const char *name_hint,
++struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_base_name,
uint64_t us_thread_start);
/*
6: 6492b6d2b98 ! 5: 4bf78e356e2 trace2: convert ctx.thread_name to flex array
@@ Metadata
Author: Jeff Hostetler <jeffhost@microsoft.com>
## Commit message ##
- trace2: convert ctx.thread_name to flex array
+ trace2: convert ctx.thread_name from strbuf to pointer
Convert the `tr2tls_thread_ctx.thread_name` field from a `strbuf`
- to a "flex array" at the end of the context structure.
+ to a "const char*" pointer.
The `thread_name` field is a constant string that is constructed when
the context is created. Using a (non-const) `strbuf` structure for it
caused some confusion in the past because it implied that someone
could rename a thread after it was created. That usage was not
- intended. Changing it to a "flex array" will hopefully make the
- intent more clear.
-
- Also, move the maximum thread_name truncation to tr2_tgt_perf.c
- because it is the only target that needs to worry about output column
- alignment.
+ intended. Change it to a const pointer to make the intent more clear.
Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
@@ trace2/tr2_tgt_event.c: static void event_fmt_prepare(const char *event_name, co
* In brief mode, only emit <time> on these 2 event types.
## trace2/tr2_tgt_perf.c ##
-@@ trace2/tr2_tgt_perf.c: static int tr2env_perf_be_brief;
-
- #define TR2FMT_PERF_FL_WIDTH (28)
- #define TR2FMT_PERF_MAX_EVENT_NAME (12)
-+#define TR2FMT_PERF_MAX_THREAD_NAME (24)
- #define TR2FMT_PERF_REPO_WIDTH (3)
- #define TR2FMT_PERF_CATEGORY_WIDTH (12)
-
@@ trace2/tr2_tgt_perf.c: 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,
+ strbuf_addf(buf, "%-*s | %-*s | ", TR2_MAX_THREAD_NAME,
- ctx->thread_name.buf, TR2FMT_PERF_MAX_EVENT_NAME,
-+ strbuf_addf(buf, "%-*.*s | %-*s | ",
-+ TR2FMT_PERF_MAX_THREAD_NAME,
-+ TR2FMT_PERF_MAX_THREAD_NAME,
-+ ctx->thread_name,
-+ TR2FMT_PERF_MAX_EVENT_NAME,
++ ctx->thread_name, TR2FMT_PERF_MAX_EVENT_NAME,
event_name);
len = buf->len + TR2FMT_PERF_REPO_WIDTH;
## trace2/tr2_tls.c ##
-@@ trace2/tr2_tls.c: void tr2tls_start_process_clock(void)
- struct tr2tls_thread_ctx *tr2tls_create_self(const char *name_hint,
+@@ trace2/tr2_tls.c: 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 tr2tls_thread_ctx *ctx;
-+ struct strbuf buf_name = STRBUF_INIT;
-+ int thread_id = tr2tls_locked_increment(&tr2_next_thread_id);
-+
-+ if (thread_id)
-+ strbuf_addf(&buf_name, "th%02d:", thread_id);
-+ strbuf_addstr(&buf_name, name_hint);
-+
-+ FLEX_ALLOC_MEM(ctx, thread_name, buf_name.buf, buf_name.len);
-+ strbuf_release(&buf_name);
-+
-+ ctx->thread_id = thread_id;
+ struct tr2tls_thread_ctx *ctx = xcalloc(1, sizeof(*ctx));
++ struct strbuf buf = STRBUF_INIT;
/*
* Implicitly "tr2tls_push_self()" to capture the thread's start
-@@ trace2/tr2_tls.c: struct tr2tls_thread_ctx *tr2tls_create_self(const char *name_hint,
- ctx->array_us_start = (uint64_t *)xcalloc(ctx->alloc, sizeof(uint64_t));
- ctx->array_us_start[ctx->nr_open_regions++] = us_thread_start;
+@@ trace2/tr2_tls.c: struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_base_name,
+
+ ctx->thread_id = tr2tls_locked_increment(&tr2_next_thread_id);
-- ctx->thread_id = tr2tls_locked_increment(&tr2_next_thread_id);
--
- strbuf_init(&ctx->thread_name, 0);
-- if (ctx->thread_id)
++ strbuf_init(&buf, 0);
+ if (ctx->thread_id)
- strbuf_addf(&ctx->thread_name, "th%02d:", ctx->thread_id);
-- strbuf_addstr(&ctx->thread_name, name_hint);
+- strbuf_addstr(&ctx->thread_name, thread_base_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);
- return ctx;
@@ trace2/tr2_tls.c: 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);
}
@@ trace2/tr2_tls.c: void tr2tls_pop_self(void)
## trace2/tr2_tls.h ##
@@
- * There is NO relation to "transport layer security".
- */
+ #define TR2_MAX_THREAD_NAME (24)
--/*
-- * Arbitry limit for thread names for column alignment.
-- */
--#define TR2_MAX_THREAD_NAME (24)
--
struct tr2tls_thread_ctx {
- struct strbuf thread_name;
++ const char *thread_name;
uint64_t *array_us_start;
size_t alloc;
size_t nr_open_regions; /* plays role of "nr" in ALLOC_GROW */
- int thread_id;
-+ char thread_name[FLEX_ARRAY];
- };
-
- /*
-@@ trace2/tr2_tls.h: struct tr2tls_thread_ctx {
- * upon the name of the thread-proc function). For example:
- * { .thread_id=10, .thread_name="th10fsm-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.
8: 19c7bba91ba ! 6: dd6d8e2841b trace2: add stopwatch timers
@@ trace2/tr2_tls.h: struct tr2tls_thread_ctx {
+ struct tr2_timer_block timer_block;
+ unsigned int used_any_timer:1;
+ unsigned int used_any_per_thread_timer:1;
- char thread_name[FLEX_ARRAY];
};
+ /*
@@ trace2/tr2_tls.h: int tr2tls_locked_increment(int *p);
*/
void tr2tls_start_process_clock(void);
9: 2bf7cb1f8d0 ! 7: cf012fcde37 trace2: add global counter mechanism
@@ trace2/tr2_tls.h: struct tr2tls_thread_ctx {
unsigned int used_any_per_thread_timer:1;
+ unsigned int used_any_counter:1;
+ unsigned int used_any_per_thread_counter:1;
- char thread_name[FLEX_ARRAY];
};
+ /*-- gitgitgadget