[v3,0/8] Trace2 timers and counters and some cleanup

Message

Philippe Blain via GitGitGadget Oct. 20, 2022, 6:28 p.m. UTC

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 (8):
  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: improve thread-name documentation in the thread-context
  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                       |  16 +++
 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, 1361 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-v3
Fetch-It-Via: git fetch https://github.com/gitgitgadget/git pr-1373/jeffhostetler/trace2-stopwatch-v4-v3
Pull-Request: https://github.com/gitgitgadget/git/pull/1373

Range-diff vs v2:

 1:  6e7e4f3187e = 1:  6e7e4f3187e trace2: use size_t alloc,nr_open_regions in tr2tls_thread_ctx
 2:  9dee7a75903 = 2:  9dee7a75903 tr2tls: clarify TLS terminology
 3:  804dab9e1a7 = 3:  804dab9e1a7 api-trace2.txt: elminate section describing the public trace2 API
 4:  637b422b860 ! 4:  9adf9cee1a9 trace2: rename the thread_name argument to trace2_thread_start
     @@ trace2/tr2_tls.c: struct tr2tls_thread_ctx *tr2tls_create_self(const char *threa
      
       ## trace2/tr2_tls.h ##
      @@ trace2/tr2_tls.h: struct tr2tls_thread_ctx {
     - /*
     -  * Create thread-local storage for the current thread.
     -  *
     -- * We assume the first thread is "main".  Other threads are given
     -- * non-zero thread-ids to help distinguish messages from concurrent
     -- * threads.
     -- *
     -- * 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="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.
        */
 -:  ----------- > 5:  8cb206b7632 trace2: improve thread-name documentation in the thread-context
 5:  4bf78e356e2 = 6:  8a89e1aa238 trace2: convert ctx.thread_name from strbuf to pointer
 6:  dd6d8e2841b ! 7:  8e701109976 trace2: add stopwatch timers
     @@ trace2/tr2_tgt.h
       struct json_writer;
      +struct tr2_timer_metadata;
      +struct tr2_timer;
     ++
     ++#define NS_PER_SEC_D ((double)1000*1000*1000)
       
       /*
        * Function prototypes for a TRACE2 "target" vtable.
     @@ trace2/tr2_tgt_event.c: static void fn_data_json_fl(const char *file, int line,
      +{
      +	const char *event_name = is_final_data ? "timer" : "th_timer";
      +	struct json_writer jw = JSON_WRITER_INIT;
     -+	double t_total = ((double)timer->total_ns) / 1000000000.0;
     -+	double t_min = ((double)timer->min_ns) / 1000000000.0;
     -+	double t_max = ((double)timer->max_ns) / 1000000000.0;
     ++	double t_total = ((double)timer->total_ns) / NS_PER_SEC_D;
     ++	double t_min = ((double)timer->min_ns) / NS_PER_SEC_D;
     ++	double t_max = ((double)timer->max_ns) / NS_PER_SEC_D;
      +
      +	jw_object_begin(&jw, 0);
      +	event_fmt_prepare(event_name, __FILE__, __LINE__, NULL, &jw);
     @@ trace2/tr2_tgt_normal.c: static void fn_printf_va_fl(const char *file, int line,
      +{
      +	const char *event_name = is_final_data ? "timer" : "th_timer";
      +	struct strbuf buf_payload = STRBUF_INIT;
     -+	double t_total = ((double)timer->total_ns) / 1000000000.0;
     -+	double t_min = ((double)timer->min_ns) / 1000000000.0;
     -+	double t_max = ((double)timer->max_ns) / 1000000000.0;
     ++	double t_total = ((double)timer->total_ns) / NS_PER_SEC_D;
     ++	double t_min = ((double)timer->min_ns) / NS_PER_SEC_D;
     ++	double t_max = ((double)timer->max_ns) / NS_PER_SEC_D;
      +
      +	strbuf_addf(&buf_payload, ("%s %s/%s"
      +				   " intervals:%"PRIu64
     @@ trace2/tr2_tgt_perf.c: static void fn_printf_va_fl(const char *file, int line,
      +{
      +	const char *event_name = is_final_data ? "timer" : "th_timer";
      +	struct strbuf buf_payload = STRBUF_INIT;
     -+	double t_total = ((double)timer->total_ns) / 1000000000.0;
     -+	double t_min = ((double)timer->min_ns) / 1000000000.0;
     -+	double t_max = ((double)timer->max_ns) / 1000000000.0;
     ++	double t_total = ((double)timer->total_ns) / NS_PER_SEC_D;
     ++	double t_min = ((double)timer->min_ns) / NS_PER_SEC_D;
     ++	double t_max = ((double)timer->max_ns) / NS_PER_SEC_D;
      +
      +	strbuf_addf(&buf_payload, ("name:%s"
      +				   " intervals:%"PRIu64
 7:  cf012fcde37 ! 8:  5cd8bdde884 trace2: add global counter mechanism
     @@ trace2/tr2_tgt.h: struct repository;
      +struct tr2_counter_metadata;
      +struct tr2_counter;
       
     - /*
     -  * Function prototypes for a TRACE2 "target" vtable.
     + #define NS_PER_SEC_D ((double)1000*1000*1000)
     + 
      @@ trace2/tr2_tgt.h: typedef void(tr2_tgt_evt_timer_t)(const struct tr2_timer_metadata *meta,
       				  const struct tr2_timer *timer,
       				  int is_final_data);