| Message ID | 3e39c8172f5de572c7b67f381d51631623a41762.1640012469.git.gitgitgadget@gmail.com (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
| Series | Trace2 stopwatch timers and global counters | expand |
On Mon, Dec 20 2021, Jeff Hostetler via GitGitGadget wrote: > From: Jeff Hostetler <jeffhost@microsoft.com> > [...] > diff --git a/trace2/tr2_tgt_event.c b/trace2/tr2_tgt_event.c > index 9b3905b920c..ca36d44dfd7 100644 > --- a/trace2/tr2_tgt_event.c > +++ b/trace2/tr2_tgt_event.c > @@ -23,7 +23,7 @@ static struct tr2_dst tr2dst_event = { TR2_SYSENV_EVENT, 0, 0, 0, 0 }; > * Verison 1: original version > * Version 2: added "too_many_files" event > * Version 3: added "child_ready" event > - * Version 4: added "timer" event > + * Version 4: added "timer" and "counter" events > */ > #define TR2_EVENT_VERSION "4" > Nit on series structure: Earlier we bumped the version to 4, but here we're changing existing version 4 behavior. Would be better IMO just bump it at the end (if at all needed, per: https://lore.kernel.org/git/211201.86zgpk9u3t.gmgdl@evledraar.gmail.com/) > +static void fn_counter(uint64_t us_elapsed_absolute, > + const char *thread_name, > + const char *category, > + const char *counter_name, > + uint64_t value) > +{ > + const char *event_name = "counter"; > + struct strbuf buf_payload = STRBUF_INIT; > + > + strbuf_addf(&buf_payload, "name:%s", counter_name); > + strbuf_addf(&buf_payload, " value:%"PRIu64, value); Odd to have these be two seperate strbuf_addf()... > + > + perf_io_write_fl(__FILE__, __LINE__, event_name, NULL, > + &us_elapsed_absolute, NULL, > + category, &buf_payload, thread_name); > + strbuf_release(&buf_payload); ...but more generally, and I see from e.g. the existing fn_version_fl that you're just using existing patterns, but it seems odd not to have a trivial varargs fmt helper for perf_io_write_fl that would avoid the whole strbuf/addf/release dance. I did a quick experiment to do that, patch on "master" below. A lot of the boilerplate could be simplified by factoring out the sq_quote_buf_pretty() case, and even this approach (re)allocs in a way that looks avoidable in many cases if perf_fmt_prepare() were improved (but it looks like it nedes its if/while loops in some cases still): diff --git a/trace2/tr2_tgt_perf.c b/trace2/tr2_tgt_perf.c index 2ff9cf70835..bcbb0d8a250 100644 --- a/trace2/tr2_tgt_perf.c +++ b/trace2/tr2_tgt_perf.c @@ -153,16 +153,33 @@ static void perf_io_write_fl(const char *file, int line, const char *event_name, strbuf_release(&buf_line); } +__attribute__((format (printf, 8, 9))) +static void perf_io_write_fl_fmt(const char *file, int line, const char *event_name, + const struct repository *repo, + uint64_t *p_us_elapsed_absolute, + uint64_t *p_us_elapsed_relative, + const char *category, + const char *fmt, ...) +{ + va_list ap; + struct strbuf sb = STRBUF_INIT; + + va_start(ap, fmt); + strbuf_vaddf(&sb, fmt, ap); + va_end(ap); + + perf_io_write_fl(file, line, event_name, repo, p_us_elapsed_absolute, + p_us_elapsed_relative, category, &sb); + + strbuf_release(&sb); +} + static void fn_version_fl(const char *file, int line) { const char *event_name = "version"; - struct strbuf buf_payload = STRBUF_INIT; - - strbuf_addstr(&buf_payload, git_version_string); - perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL, - &buf_payload); - strbuf_release(&buf_payload); + perf_io_write_fl_fmt(file, line, event_name, NULL, NULL, NULL, NULL, + "%s", git_version_string); } static void fn_start_fl(const char *file, int line, @@ -182,37 +199,25 @@ static void fn_exit_fl(const char *file, int line, uint64_t us_elapsed_absolute, int code) { const char *event_name = "exit"; - struct strbuf buf_payload = STRBUF_INIT; - strbuf_addf(&buf_payload, "code:%d", code); - - perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute, - NULL, NULL, &buf_payload); - strbuf_release(&buf_payload); + perf_io_write_fl_fmt(file, line, event_name, NULL, &us_elapsed_absolute, + NULL, NULL, "code:%d", code); } static void fn_signal(uint64_t us_elapsed_absolute, int signo) { const char *event_name = "signal"; - struct strbuf buf_payload = STRBUF_INIT; - strbuf_addf(&buf_payload, "signo:%d", signo); - - perf_io_write_fl(__FILE__, __LINE__, event_name, NULL, - &us_elapsed_absolute, NULL, NULL, &buf_payload); - strbuf_release(&buf_payload); + perf_io_write_fl_fmt(__FILE__, __LINE__, event_name, NULL, + &us_elapsed_absolute, NULL, NULL, "signo:%d", signo); } static void fn_atexit(uint64_t us_elapsed_absolute, int code) { const char *event_name = "atexit"; - struct strbuf buf_payload = STRBUF_INIT; - - strbuf_addf(&buf_payload, "code:%d", code); - perf_io_write_fl(__FILE__, __LINE__, event_name, NULL, - &us_elapsed_absolute, NULL, NULL, &buf_payload); - strbuf_release(&buf_payload); + perf_io_write_fl_fmt(__FILE__, __LINE__, event_name, NULL, + &us_elapsed_absolute, NULL, NULL, "code:%d", code); } static void maybe_append_string_va(struct strbuf *buf, const char *fmt, @@ -244,13 +249,9 @@ static void fn_error_va_fl(const char *file, int line, const char *fmt, static void fn_command_path_fl(const char *file, int line, const char *pathname) { const char *event_name = "cmd_path"; - struct strbuf buf_payload = STRBUF_INIT; - - strbuf_addstr(&buf_payload, pathname); - perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL, - &buf_payload); - strbuf_release(&buf_payload); + perf_io_write_fl_fmt(file, line, event_name, NULL, NULL, NULL, NULL, + "%s", pathname); } static void fn_command_ancestry_fl(const char *file, int line, const char **parent_names) @@ -286,13 +287,9 @@ static void fn_command_name_fl(const char *file, int line, const char *name, static void fn_command_mode_fl(const char *file, int line, const char *mode) { const char *event_name = "cmd_mode"; - struct strbuf buf_payload = STRBUF_INIT; - - strbuf_addstr(&buf_payload, mode); - perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL, - &buf_payload); - strbuf_release(&buf_payload); + perf_io_write_fl_fmt(file, line, event_name, NULL, NULL, NULL, NULL, + "%s", mode); } static void fn_alias_fl(const char *file, int line, const char *alias, @@ -351,13 +348,10 @@ static void fn_child_exit_fl(const char *file, int line, int code, uint64_t us_elapsed_child) { const char *event_name = "child_exit"; - struct strbuf buf_payload = STRBUF_INIT; - strbuf_addf(&buf_payload, "[ch%d] pid:%d code:%d", cid, pid, code); - - perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute, - &us_elapsed_child, NULL, &buf_payload); - strbuf_release(&buf_payload); + perf_io_write_fl_fmt(file, line, event_name, NULL, &us_elapsed_absolute, + &us_elapsed_child, NULL, "[ch%d] pid:%d code:%d", + cid, pid, code); } static void fn_child_ready_fl(const char *file, int line, @@ -365,24 +359,19 @@ static void fn_child_ready_fl(const char *file, int line, const char *ready, uint64_t us_elapsed_child) { const char *event_name = "child_ready"; - struct strbuf buf_payload = STRBUF_INIT; - - strbuf_addf(&buf_payload, "[ch%d] pid:%d ready:%s", cid, pid, ready); - perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute, - &us_elapsed_child, NULL, &buf_payload); - strbuf_release(&buf_payload); + perf_io_write_fl_fmt(file, line, event_name, NULL, &us_elapsed_absolute, + &us_elapsed_child, NULL, + "[ch%d] pid:%d ready:%s", cid, pid, ready); } static void fn_thread_start_fl(const char *file, int line, uint64_t us_elapsed_absolute) { const char *event_name = "thread_start"; - struct strbuf buf_payload = STRBUF_INIT; - perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute, - NULL, NULL, &buf_payload); - strbuf_release(&buf_payload); + perf_io_write_fl_fmt(file, line, event_name, NULL, &us_elapsed_absolute, + NULL, NULL, "%s", ""); /* TODO: No payload, support NULL? */ } static void fn_thread_exit_fl(const char *file, int line, @@ -390,11 +379,9 @@ static void fn_thread_exit_fl(const char *file, int line, uint64_t us_elapsed_thread) { const char *event_name = "thread_exit"; - struct strbuf buf_payload = STRBUF_INIT; - perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute, - &us_elapsed_thread, NULL, &buf_payload); - strbuf_release(&buf_payload); + perf_io_write_fl_fmt(file, line, event_name, NULL, &us_elapsed_absolute, + &us_elapsed_thread, NULL, "%s", ""); /* TODO: No payload, support NULL ? */ } static void fn_exec_fl(const char *file, int line, uint64_t us_elapsed_absolute, @@ -438,13 +425,9 @@ static void fn_param_fl(const char *file, int line, const char *param, const char *value) { const char *event_name = "def_param"; - struct strbuf buf_payload = STRBUF_INIT; - - strbuf_addf(&buf_payload, "%s:%s", param, value); - perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL, - &buf_payload); - strbuf_release(&buf_payload); + perf_io_write_fl_fmt(file, line, event_name, NULL, NULL, NULL, NULL, + "%s:%s", param, value); } static void fn_repo_fl(const char *file, int line, @@ -525,13 +508,10 @@ static void fn_data_json_fl(const char *file, int line, const struct json_writer *value) { const char *event_name = "data_json"; - struct strbuf buf_payload = STRBUF_INIT; - - strbuf_addf(&buf_payload, "%s:%s", key, value->json.buf); - perf_io_write_fl(file, line, event_name, repo, &us_elapsed_absolute, - &us_elapsed_region, category, &buf_payload); - strbuf_release(&buf_payload); + perf_io_write_fl_fmt(file, line, event_name, repo, &us_elapsed_absolute, + &us_elapsed_region, category, + "%s:%s", key, value->json.buf); } static void fn_printf_va_fl(const char *file, int line,
On 12/20/21 11:51 AM, Ævar Arnfjörð Bjarmason wrote: > > On Mon, Dec 20 2021, Jeff Hostetler via GitGitGadget wrote: > >> From: Jeff Hostetler <jeffhost@microsoft.com> >> [...] > >> +static void fn_counter(uint64_t us_elapsed_absolute, >> + const char *thread_name, >> + const char *category, >> + const char *counter_name, >> + uint64_t value) >> +{ >> + const char *event_name = "counter"; >> + struct strbuf buf_payload = STRBUF_INIT; >> + >> + strbuf_addf(&buf_payload, "name:%s", counter_name); >> + strbuf_addf(&buf_payload, " value:%"PRIu64, value); > > Odd to have these be two seperate strbuf_addf()... yeah, i'll combine. and in the body of fn_timer in 6/9. > ....but more generally, and I see from e.g. the existing fn_version_fl > that you're just using existing patterns, but it seems odd not to have a > trivial varargs fmt helper for perf_io_write_fl that would avoid the > whole strbuf/addf/release dance. [...] yeah, cut-n-paste was used here and i was maintaining consistency with the other functions -- rather than inventing something new and refactoring stuff that didn't need be refactored in the middle of an on-going patch series. > I did a quick experiment to do that, patch on "master" below. A lot of > the boilerplate could be simplified by factoring out the > sq_quote_buf_pretty() case, and even this approach (re)allocs in a way > that looks avoidable in many cases if perf_fmt_prepare() were improved > (but it looks like it nedes its if/while loops in some cases still): > [...] > > +__attribute__((format (printf, 8, 9))) > +static void perf_io_write_fl_fmt(const char *file, int line, const char *event_name, > + const struct repository *repo, > + uint64_t *p_us_elapsed_absolute, > + uint64_t *p_us_elapsed_relative, > + const char *category, > + const char *fmt, ...) > +{ > + va_list ap; > + struct strbuf sb = STRBUF_INIT; > + > + va_start(ap, fmt); > + strbuf_vaddf(&sb, fmt, ap); > + va_end(ap); > + > + perf_io_write_fl(file, line, event_name, repo, p_us_elapsed_absolute, > + p_us_elapsed_relative, category, &sb); > + > + strbuf_release(&sb); > +} > + > static void fn_version_fl(const char *file, int line) > { > const char *event_name = "version"; > - struct strbuf buf_payload = STRBUF_INIT; > - > - strbuf_addstr(&buf_payload, git_version_string); > > - perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL, > - &buf_payload); > - strbuf_release(&buf_payload); > + perf_io_write_fl_fmt(file, line, event_name, NULL, NULL, NULL, NULL, > + "%s", git_version_string); > } [...] Yes, it might be nice to have a _fmt() version as you suggest and simplify many of the existing fn_*() function bodies. It seems like I keep saying this today, but can we discuss that in a new top-level topic and not down inside commit 8/9 of this series? Thanks, Jeff
diff --git a/Documentation/technical/api-trace2.txt b/Documentation/technical/api-trace2.txt index 03a61332a2d..bb116dc85db 100644 --- a/Documentation/technical/api-trace2.txt +++ b/Documentation/technical/api-trace2.txt @@ -838,6 +838,25 @@ may exceed the "atexit" elapsed time of the program. Timer events may represent an individual thread or a summation across the entire program. Summation events will have a unique thread name. +`"counter"`:: + This event is generated at the end of the program and contains + the value of a global counter. ++ +------------ +{ + "event":"counter", + ... + "name":"test", # counter name + "value":42, # value of the counter +} +------------ ++ +A global counter can be incremented throughout the execution of the +program. It will be reported in a "counter" event just prior to exit. ++ +Counter events may represent an individual thread or a summation across +the entire program. Summation events will have a unique thread name. + == Example Trace2 API Usage Here is a hypothetical usage of the Trace2 API showing the intended diff --git a/trace2/tr2_tgt.h b/trace2/tr2_tgt.h index 1f548eb4b93..33a2bb99199 100644 --- a/trace2/tr2_tgt.h +++ b/trace2/tr2_tgt.h @@ -120,6 +120,19 @@ typedef void(tr2_tgt_evt_timer_t)(uint64_t us_elapsed_absolute, uint64_t us_min_time, uint64_t us_max_time); +/* + * Item counter event. + * + * This also does not take a (file,line) pair. + * + * The thread name is optional. + */ +typedef void(tr2_tgt_evt_counter_t)(uint64_t us_elapsed_absolute, + const char *thread_name, + const char *category, + const char *counter_name, + uint64_t value); + /* * "vtable" for a TRACE2 target. Use NULL if a target does not want * to emit that message. @@ -157,6 +170,7 @@ struct tr2_tgt { 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 9b3905b920c..ca36d44dfd7 100644 --- a/trace2/tr2_tgt_event.c +++ b/trace2/tr2_tgt_event.c @@ -23,7 +23,7 @@ static struct tr2_dst tr2dst_event = { TR2_SYSENV_EVENT, 0, 0, 0, 0 }; * Verison 1: original version * Version 2: added "too_many_files" event * Version 3: added "child_ready" event - * Version 4: added "timer" event + * Version 4: added "timer" and "counter" events */ #define TR2_EVENT_VERSION "4" @@ -652,6 +652,28 @@ static void fn_timer(uint64_t us_elapsed_absolute, jw_release(&jw); } +static void fn_counter(uint64_t us_elapsed_absolute, + const char *thread_name, + const char *category, + const char *counter_name, + uint64_t value) +{ + const char *event_name = "counter"; + struct json_writer jw = JSON_WRITER_INIT; + double t_abs = (double)us_elapsed_absolute / 1000000.0; + + jw_object_begin(&jw, 0); + event_fmt_prepare(event_name, __FILE__, __LINE__, NULL, &jw, thread_name); + jw_object_double(&jw, "t_abs", 6, t_abs); + jw_object_string(&jw, "name", counter_name); + jw_object_intmax(&jw, "value", value); + + jw_end(&jw); + + tr2_dst_write_line(&tr2dst_event, &jw.json); + jw_release(&jw); +} + struct tr2_tgt tr2_tgt_event = { &tr2dst_event, @@ -684,4 +706,5 @@ struct tr2_tgt tr2_tgt_event = { fn_data_json_fl, NULL, /* printf */ fn_timer, + fn_counter, }; diff --git a/trace2/tr2_tgt_normal.c b/trace2/tr2_tgt_normal.c index 23a7e78dcaa..1778232f6e9 100644 --- a/trace2/tr2_tgt_normal.c +++ b/trace2/tr2_tgt_normal.c @@ -356,4 +356,5 @@ struct tr2_tgt tr2_tgt_normal = { NULL, /* data_json */ fn_printf_va_fl, NULL, /* timer */ + NULL, /* counter */ }; diff --git a/trace2/tr2_tgt_perf.c b/trace2/tr2_tgt_perf.c index 7597cb52ed5..eb4577ec40b 100644 --- a/trace2/tr2_tgt_perf.c +++ b/trace2/tr2_tgt_perf.c @@ -582,6 +582,24 @@ static void fn_timer(uint64_t us_elapsed_absolute, strbuf_release(&buf_payload); } +static void fn_counter(uint64_t us_elapsed_absolute, + const char *thread_name, + const char *category, + const char *counter_name, + uint64_t value) +{ + const char *event_name = "counter"; + struct strbuf buf_payload = STRBUF_INIT; + + strbuf_addf(&buf_payload, "name:%s", counter_name); + strbuf_addf(&buf_payload, " value:%"PRIu64, value); + + perf_io_write_fl(__FILE__, __LINE__, event_name, NULL, + &us_elapsed_absolute, NULL, + category, &buf_payload, thread_name); + strbuf_release(&buf_payload); +} + struct tr2_tgt tr2_tgt_perf = { &tr2dst_perf, @@ -614,4 +632,5 @@ struct tr2_tgt tr2_tgt_perf = { fn_data_json_fl, fn_printf_va_fl, fn_timer, + fn_counter, };