Trace2 stopwatch timers and global counters #1099

gitgitgadget · 2021-12-20T16:39:09Z

On the Git mailing list, Ævar Arnfjörð Bjarmason wrote (reply to this):

On Mon, Dec 20 2021, Jeff Hostetler via GitGitGadget wrote: > From: Jeff Hostetler <jeffhost@microsoft.com> > > Use a 'char *' to hold the thread name rather than a 'struct strbuf'. > The thread name is set when the thread is created and should not be > be modified afterwards. Replace the strbuf with an allocated pointer > to make that more clear. > > This was discussed in: https://lore.kernel.org/all/xmqqa6kdwo24.fsf@gitster.g/ > > Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com> > --- > trace2/tr2_tgt_event.c | 2 +- > trace2/tr2_tgt_perf.c | 2 +- > trace2/tr2_tls.c | 16 +++++++++------- > trace2/tr2_tls.h | 2 +- > 4 files changed, 12 insertions(+), 10 deletions(-) > > diff --git a/trace2/tr2_tgt_event.c b/trace2/tr2_tgt_event.c > index 3a0014417cc..ca48d00aebc 100644 > --- a/trace2/tr2_tgt_event.c > +++ b/trace2/tr2_tgt_event.c > @@ -88,7 +88,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. > diff --git a/trace2/tr2_tgt_perf.c b/trace2/tr2_tgt_perf.c > index e4acca13d64..c3e57fcb3c0 100644 > --- a/trace2/tr2_tgt_perf.c > +++ b/trace2/tr2_tgt_perf.c > @@ -106,7 +106,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; > diff --git a/trace2/tr2_tls.c b/trace2/tr2_tls.c > index 7da94aba522..cd8b9f2f0a0 100644 > --- a/trace2/tr2_tls.c > +++ b/trace2/tr2_tls.c > @@ -35,6 +35,7 @@ struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_name, > uint64_t us_thread_start) > { > struct tr2tls_thread_ctx *ctx = xcalloc(1, sizeof(*ctx)); > + struct strbuf buf_name = STRBUF_INIT; > > /* > * Implicitly "tr2tls_push_self()" to capture the thread's start > @@ -47,12 +48,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); > 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_name, "th%02d:", ctx->thread_id); > + strbuf_addstr(&buf_name, thread_name); > + if (buf_name.len > TR2_MAX_THREAD_NAME) > + strbuf_setlen(&buf_name, TR2_MAX_THREAD_NAME); > + > + ctx->thread_name = strbuf_detach(&buf_name, NULL); > > pthread_setspecific(tr2tls_key, ctx); > > @@ -95,7 +97,7 @@ void tr2tls_unset_self(void) > > pthread_setspecific(tr2tls_key, NULL); > > - strbuf_release(&ctx->thread_name); > + free(ctx->thread_name); > free(ctx->array_us_start); > free(ctx); > } > @@ -113,7 +115,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--; > } > diff --git a/trace2/tr2_tls.h b/trace2/tr2_tls.h > index a90bd639d48..d968da6a679 100644 > --- a/trace2/tr2_tls.h > +++ b/trace2/tr2_tls.h > @@ -9,7 +9,7 @@ > #define TR2_MAX_THREAD_NAME (24) > > struct tr2tls_thread_ctx { > - struct strbuf thread_name; > + char *thread_name; > uint64_t *array_us_start; > size_t alloc; > size_t nr_open_regions; /* plays role of "nr" in ALLOC_GROW */ Junio's suggestion in the linked E-Mail was to make this a "const char *". Narrowly, I don't see why not just add a "const" to the "struct strbuf *" instead. But less narrowly if we're not going to change it why malloc a new one at all? Can't we just use the "const char *" passed into tr2tls_create_self(), and for the "th%02d:" case have the code that's formatting it handle that case? I.e. have the things that use it as a "%s" now call a function that formats things as a function of the "ctx->thread_id" (which may be 0) and limit it by TR2_MAX_THREAD_NAME?

On the Git mailing list, Jeff Hostetler wrote (reply to this):

On 12/20/21 11:31 AM, Ævar Arnfjörð Bjarmason wrote: > > On Mon, Dec 20 2021, Jeff Hostetler via GitGitGadget wrote: > >> From: Jeff Hostetler <jeffhost@microsoft.com> >> >> Use a 'char *' to hold the thread name rather than a 'struct strbuf'. >> The thread name is set when the thread is created and should not be >> be modified afterwards. Replace the strbuf with an allocated pointer >> to make that more clear. >> >> This was discussed in: https://lore.kernel.org/all/xmqqa6kdwo24.fsf@gitster.g/ >>... >> diff --git a/trace2/tr2_tls.c b/trace2/tr2_tls.c >> index 7da94aba522..cd8b9f2f0a0 100644 >> --- a/trace2/tr2_tls.c >> +++ b/trace2/tr2_tls.c >> @@ -35,6 +35,7 @@ struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_name, >> uint64_t us_thread_start) >> { >> struct tr2tls_thread_ctx *ctx = xcalloc(1, sizeof(*ctx)); >> + struct strbuf buf_name = STRBUF_INIT; >> >> /* >> * Implicitly "tr2tls_push_self()" to capture the thread's start >> @@ -47,12 +48,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); >> 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_name, "th%02d:", ctx->thread_id); >> + strbuf_addstr(&buf_name, thread_name); >> + if (buf_name.len > TR2_MAX_THREAD_NAME) >> + strbuf_setlen(&buf_name, TR2_MAX_THREAD_NAME); >> + >> + ctx->thread_name = strbuf_detach(&buf_name, NULL); >> >> pthread_setspecific(tr2tls_key, ctx); >> >>.. >> diff --git a/trace2/tr2_tls.h b/trace2/tr2_tls.h >> index a90bd639d48..d968da6a679 100644 >> --- a/trace2/tr2_tls.h >> +++ b/trace2/tr2_tls.h >> @@ -9,7 +9,7 @@ >> #define TR2_MAX_THREAD_NAME (24) >> >> struct tr2tls_thread_ctx { >> - struct strbuf thread_name; >> + char *thread_name; >> uint64_t *array_us_start; >> size_t alloc; >> size_t nr_open_regions; /* plays role of "nr" in ALLOC_GROW */ > > Junio's suggestion in the linked E-Mail was to make this a "const char *". Yes, it was. To me a "const char *" in a structure means that the structure does not own the pointer and must not free it. Whereas as "char *" means that the structure might own it and should maybe free it when the structure is freed. My usage here is that the structure does own it (because it took it from the temporary strbuf using strbuf_detach()) and so it must free it. Therefore it should not be "const". This has nothing to do with whether or not we allow the thread name to be changed after the fact. (We don't, but that is a different issue). > > Narrowly, I don't see why not just add a "const" to the "struct strbuf > *" instead. Adding "const" to a strbuf would be wrong in this case, since the structure owns the strbuf and needs to strbuf_release the contained buffer and (now) free the strbuf pointer, right? This also makes things confusing -- all callers of tr2tls_create_self() would now be responsible for allocating a strbuf to pass in -- and who would own those. This would also create opportunities for mistakes if they pass in the address of a stack-based strbuf, right? This is being used to initialize thread-based data, so the caller can't just use a "function local static" or a "global static" strbuf. > > But less narrowly if we're not going to change it why malloc a new one > at all? Can't we just use the "const char *" passed into > tr2tls_create_self(), and for the "th%02d:" case have the code that's > formatting it handle that case? > > I.e. have the things that use it as a "%s" now call a function that > formats things as a function of the "ctx->thread_id" (which may be 0) > and limit it by TR2_MAX_THREAD_NAME? > This would be less efficient, right? That thread name is included in *EVERY* _perf and _event message emitted. If we were to change the design to have basically a callback to get the formatted value based on the `ctx` or `cts->thread_id` and dynamically formatting the name, then we would have to hit that callback once (or twice) for every Trace2 message, right? That would be much slower than just having a fixed string (formatted when the thread is created) that we can just use. And even if we said that the callback could cache the result (like we do when we lookup env vars), where would it cache it? It would have to cache it in the `ctx`, which is where it currently is and without any of the unnecessary overhead, right? I think you're assuming that callers of `tr2tls_create_self()` always pass a literal string such that that string value is always safe to reference later. Nothing would prevent a caller from passing the address of a stack buffer. It is not safe to assume that that string pointer will always be valid, such as after the thread exits. It is better for _create_self() to copy the given string (whether we format it immediately or not) than to assume that the pointer will always be valid, right? So I don't think we should deviate from the patch that I submitted. Jeff

On the Git mailing list, Ævar Arnfjörð Bjarmason wrote (reply to this):

On Mon, Dec 20 2021, Jeff Hostetler wrote: > On 12/20/21 11:31 AM, Ævar Arnfjörð Bjarmason wrote: >> On Mon, Dec 20 2021, Jeff Hostetler via GitGitGadget wrote: >> >>> From: Jeff Hostetler <jeffhost@microsoft.com> >>> >>> Use a 'char *' to hold the thread name rather than a 'struct strbuf'. >>> The thread name is set when the thread is created and should not be >>> be modified afterwards. Replace the strbuf with an allocated pointer >>> to make that more clear. >>> >>> This was discussed in: https://lore.kernel.org/all/xmqqa6kdwo24.fsf@gitster.g/ >>>... >>> diff --git a/trace2/tr2_tls.c b/trace2/tr2_tls.c >>> index 7da94aba522..cd8b9f2f0a0 100644 >>> --- a/trace2/tr2_tls.c >>> +++ b/trace2/tr2_tls.c >>> @@ -35,6 +35,7 @@ struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_name, >>> uint64_t us_thread_start) >>> { >>> struct tr2tls_thread_ctx *ctx = xcalloc(1, sizeof(*ctx)); >>> + struct strbuf buf_name = STRBUF_INIT; >>> /* >>> * Implicitly "tr2tls_push_self()" to capture the thread's start >>> @@ -47,12 +48,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); >>> 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_name, "th%02d:", ctx->thread_id); >>> + strbuf_addstr(&buf_name, thread_name); >>> + if (buf_name.len > TR2_MAX_THREAD_NAME) >>> + strbuf_setlen(&buf_name, TR2_MAX_THREAD_NAME); >>> + >>> + ctx->thread_name = strbuf_detach(&buf_name, NULL); >>> pthread_setspecific(tr2tls_key, ctx); >>> >>>.. >>> diff --git a/trace2/tr2_tls.h b/trace2/tr2_tls.h >>> index a90bd639d48..d968da6a679 100644 >>> --- a/trace2/tr2_tls.h >>> +++ b/trace2/tr2_tls.h >>> @@ -9,7 +9,7 @@ >>> #define TR2_MAX_THREAD_NAME (24) >>> struct tr2tls_thread_ctx { >>> - struct strbuf thread_name; >>> + char *thread_name; >>> uint64_t *array_us_start; >>> size_t alloc; >>> size_t nr_open_regions; /* plays role of "nr" in ALLOC_GROW */ >> Junio's suggestion in the linked E-Mail was to make this a "const >> char *". > > Yes, it was. To me a "const char *" in a structure means that > the structure does not own the pointer and must not free it. > Whereas as "char *" means that the structure might own it and > should maybe free it when the structure is freed. My usage here > is that the structure does own it (because it took it from the > temporary strbuf using strbuf_detach()) and so it must free it. > Therefore it should not be "const". This has nothing to do with > whether or not we allow the thread name to be changed after the > fact. (We don't, but that is a different issue). We use the pattern of having a "const char *" that's really a "char *" with a cast to free() in many existing APIs for this scenario. Maybe the cast for free would be more correct here, see my recent 9081a421a6d (checkout: fix "branch info" memory leaks, 2021-11-16) & the discussion it referencese. I.e. in that case we didn't go for the "free((char *)ptr)" cast as it was a private API. >> Narrowly, I don't see why not just add a "const" to the "struct >> strbuf >> *" instead. > > Adding "const" to a strbuf would be wrong in this case, since the > structure owns the strbuf and needs to strbuf_release the contained > buffer and (now) free the strbuf pointer, right? > > This also makes things confusing -- all callers of tr2tls_create_self() > would now be responsible for allocating a strbuf to pass in -- and who > would own those. This would also create opportunities for mistakes if > they pass in the address of a stack-based strbuf, right? > > This is being used to initialize thread-based data, so the caller > can't just use a "function local static" or a "global static" strbuf. Right, I meant that in the context of who/where you'd have your casts. >> But less narrowly if we're not going to change it why malloc a new >> one >> at all? Can't we just use the "const char *" passed into >> tr2tls_create_self(), and for the "th%02d:" case have the code that's >> formatting it handle that case? >> I.e. have the things that use it as a "%s" now call a function that >> formats things as a function of the "ctx->thread_id" (which may be 0) >> and limit it by TR2_MAX_THREAD_NAME? >> > > This would be less efficient, right? That thread name is included in > *EVERY* _perf and _event message emitted. If we were to change the > design to have basically a callback to get the formatted value based > on the `ctx` or `cts->thread_id` and dynamically formatting the name, > then we would have to hit that callback once (or twice) for every Trace2 > message, right? That would be much slower than just having a fixed > string (formatted when the thread is created) that we can just use. > And even if we said that the callback could cache the result (like > we do when we lookup env vars), where would it cache it? It would have > to cache it in the `ctx`, which is where it currently is and without > any of the unnecessary overhead, right? Aren't we per https://lore.kernel.org/git/211220.86czlrurm6.gmgdl@evledraar.gmail.com/ doing a lot of that formatting (and sometimes allocation) anyway in a way that's easily avoidable for the "perf" backend? And for tr2_tgt_event.c we'll call jw_object_string(), which calls append_quoted_string() for each event. That'll be re-quoting (presumably always needlessly) the thread_name every time. So just deferring a single strbuf_addf() doesn't seem like it would slow things down. > I think you're assuming that callers of `tr2tls_create_self()` always > pass a literal string such that that string value is always safe to > reference later. Nothing would prevent a caller from passing the > address of a stack buffer. It is not safe to assume that that string > pointer will always be valid, such as after the thread exits. It is > better for _create_self() to copy the given string (whether we format > it immediately or not) than to assume that the pointer will always be > valid, right? Sure, if that's the API we can xstrdup() it, and/or xstrfmt() it etc. as we're doing now. > So I don't think we should deviate from the patch that I submitted. I'm not saying anything needs to change here, these were really just read-through suggestion, but I think per the above (about the casts & optimization) that some of your assumptions here may not hold.

On the Git mailing list, Junio C Hamano wrote (reply to this):

Ævar Arnfjörð Bjarmason <avarab@gmail.com> writes: >> struct tr2tls_thread_ctx { >> - struct strbuf thread_name; >> + char *thread_name; >> uint64_t *array_us_start; >> size_t alloc; >> size_t nr_open_regions; /* plays role of "nr" in ALLOC_GROW */ > > Junio's suggestion in the linked E-Mail was to make this a "const char *". Sorry, but in that linked E-Mail, I wasn't picking between "const char *" and "char *" at all. What I cared was *not* to keep a long-term constant string in a member whose type is "struct strbuf".

On the Git mailing list, Jeff Hostetler wrote (reply to this):

On 12/20/21 2:35 PM, Ævar Arnfjörð Bjarmason wrote: > > On Mon, Dec 20 2021, Jeff Hostetler wrote: > >> On 12/20/21 11:31 AM, Ævar Arnfjörð Bjarmason wrote: >>> On Mon, Dec 20 2021, Jeff Hostetler via GitGitGadget wrote: >>> >>>> From: Jeff Hostetler <jeffhost@microsoft.com> >>>> >> >> Yes, it was. To me a "const char *" in a structure means that >> the structure does not own the pointer and must not free it. >> Whereas as "char *" means that the structure might own it and >> should maybe free it when the structure is freed. My usage here >> is that the structure does own it (because it took it from the >> temporary strbuf using strbuf_detach()) and so it must free it. >> Therefore it should not be "const". This has nothing to do with >> whether or not we allow the thread name to be changed after the >> fact. (We don't, but that is a different issue). > > We use the pattern of having a "const char *" that's really a "char *" > with a cast to free() in many existing APIs for this scenario. As I mention later in this thread, I'm going to convert the field into a flex-array, so most of the discussion in this part of the thread no longer applies.

gitgitgadget · 2021-12-21T07:26:28Z

On the Git mailing list, Junio C Hamano wrote (reply to this):

"Jeff Hostetler via GitGitGadget" <gitgitgadget@gmail.com> writes: > From: Jeff Hostetler <jeffhost@microsoft.com> > > Use a 'char *' to hold the thread name rather than a 'struct strbuf'. > The thread name is set when the thread is created and should not be > be modified afterwards. Replace the strbuf with an allocated pointer > to make that more clear. Sounds good. Use of strbuf is perfectly fine while you compute the final value of the string, but as a more permanent location to store the result, it often is unsuitable (and strbuf_split_buf() is a prime example of how *not* to design your API function around the type). > diff --git a/trace2/tr2_tls.c b/trace2/tr2_tls.c > index 7da94aba522..cd8b9f2f0a0 100644 > --- a/trace2/tr2_tls.c > +++ b/trace2/tr2_tls.c > @@ -35,6 +35,7 @@ struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_name, > uint64_t us_thread_start) > { > struct tr2tls_thread_ctx *ctx = xcalloc(1, sizeof(*ctx)); > + struct strbuf buf_name = STRBUF_INIT; > > /* > * Implicitly "tr2tls_push_self()" to capture the thread's start > @@ -47,12 +48,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); > 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_name, "th%02d:", ctx->thread_id); > + strbuf_addstr(&buf_name, thread_name); > + if (buf_name.len > TR2_MAX_THREAD_NAME) > + strbuf_setlen(&buf_name, TR2_MAX_THREAD_NAME); > + > + ctx->thread_name = strbuf_detach(&buf_name, NULL); This is not exactly a new problem, but if we use a mechanism to allow arbitrary long string (like composing with strbuf and detaching the resulting string as is), instead of having a fixed name[] array embedded in the ctx structure, I wonder if applying the maximum length this early makes sense. Such a truncation would allow more than one ctx structures to share the same name, which somehow feels error prone, inviting a mistake to use .thread_name member as an identifier, when its only intended use is to give a human-readable and not necessarily unique label. Of course, if the maximum is reasonably low, like a few dozen bytes, it may even make sense to embed an array of the fixed size and not worry about an extra pointer. > diff --git a/trace2/tr2_tls.h b/trace2/tr2_tls.h > index a90bd639d48..d968da6a679 100644 > --- a/trace2/tr2_tls.h > +++ b/trace2/tr2_tls.h > @@ -9,7 +9,7 @@ > #define TR2_MAX_THREAD_NAME (24) > > struct tr2tls_thread_ctx { > - struct strbuf thread_name; > + char *thread_name; That is, something like char thread_name[TR2_MAX_THREAD_NAME + 1]; perhaps with moving it to the end of the struct to avoid padding waste, would make more sense than the posted patch, if we accept an early truncation and information loss. The other extreme would also make equally more sense than the posted patch. Just grab strbuf_detach() result without truncation and point at it with "char *thread_name" here, and if the output layer wants to limit the names to some reasonable length, deal with the TR2_MAX_THREAD_NAME at that layer, without losing information too early. It might be a much bigger surgery, I am afraid, because the users of ctx->thread_name (and old ctx->thread_name.buf) all are relying on the string being shorter than TR2_MAX_THREAD_NAME. > uint64_t *array_us_start; > size_t alloc; > size_t nr_open_regions; /* plays role of "nr" in ALLOC_GROW */

On the Git mailing list, Jeff Hostetler wrote (reply to this):

On 12/21/21 2:22 AM, Junio C Hamano wrote: > "Jeff Hostetler via GitGitGadget" <gitgitgadget@gmail.com> writes: > >> From: Jeff Hostetler <jeffhost@microsoft.com> >> >> Use a 'char *' to hold the thread name rather than a 'struct strbuf'. >> The thread name is set when the thread is created and should not be >> be modified afterwards. Replace the strbuf with an allocated pointer >> to make that more clear. > > Sounds good. Use of strbuf is perfectly fine while you compute the > final value of the string, but as a more permanent location to store > the result, it often is unsuitable (and strbuf_split_buf() is a prime > example of how *not* to design your API function around the type). > >> diff --git a/trace2/tr2_tls.c b/trace2/tr2_tls.c >> index 7da94aba522..cd8b9f2f0a0 100644 >> --- a/trace2/tr2_tls.c >> +++ b/trace2/tr2_tls.c >> @@ -35,6 +35,7 @@ struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_name, >> uint64_t us_thread_start) >> { >> struct tr2tls_thread_ctx *ctx = xcalloc(1, sizeof(*ctx)); >> + struct strbuf buf_name = STRBUF_INIT; >> >> /* >> * Implicitly "tr2tls_push_self()" to capture the thread's start >> @@ -47,12 +48,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); >> 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_name, "th%02d:", ctx->thread_id); >> + strbuf_addstr(&buf_name, thread_name); >> + if (buf_name.len > TR2_MAX_THREAD_NAME) >> + strbuf_setlen(&buf_name, TR2_MAX_THREAD_NAME); >> + >> + ctx->thread_name = strbuf_detach(&buf_name, NULL); > > This is not exactly a new problem, but if we use a mechanism to > allow arbitrary long string (like composing with strbuf and > detaching the resulting string as is), instead of having a fixed > name[] array embedded in the ctx structure, I wonder if applying the > maximum length this early makes sense. Such a truncation would > allow more than one ctx structures to share the same name, which > somehow feels error prone, inviting a mistake to use .thread_name > member as an identifier, when its only intended use is to give a > human-readable and not necessarily unique label. Of course, if the > maximum is reasonably low, like a few dozen bytes, it may even make > sense to embed an array of the fixed size and not worry about an > extra pointer. > I'll convert it to a flex-array at the bottom of the CTX structure and then defer the truncation to the _perf target (which only does that to keep the columns lined up). That will simplify things considerably. Thanks Jeff

On the Git mailing list, Junio C Hamano wrote (reply to this):

Jeff Hostetler <git@jeffhostetler.com> writes: > I'll convert it to a flex-array at the bottom of the CTX structure > and then defer the truncation to the _perf target (which only does > that to keep the columns lined up). > > That will simplify things considerably. I am not sure if the complexity of flex-array is worth it. You have been storing an up-to-24-byte human readable name by embedding a strbuf that has two size_t plus a pointer (i.e. 24-bytes even on Windows), and the posted patch changes it to a pointer plus a on-heap allocation with malloc() overhead. An embedded fixed-size thread_name[TR2_MAX_THREAD_NAME+1] member may be the simplest thing to do, I suspect.

gitgitgadget · 2021-12-29T01:17:51Z

On the Git mailing list, Ævar Arnfjörð Bjarmason wrote (reply to this):

On Tue, Dec 28 2021, Jeff Hostetler via GitGitGadget wrote: > From: Jeff Hostetler <jeffhost@microsoft.com> > > Move the thread name to a flex array at the bottom of the Trace2 > thread local storage data and get rid of the strbuf. > > Let the flex array have the full computed value of the thread name > without truncation. > > Change the PERF target to truncate the thread name so that the columns > still line up. This commit message really doesn't help in explaining what we're trying to do here and why it's needed. I'm not saying it's not, but why not a strbuf, why a flex array? The diff below also shows changes unrelated to this. I tried this local fixup on top of this series which works, so I wonder if we're just trying to get rid of the strbuf to signal that this shouldn't change why not just strbuf_detach() and keep a "const char *thread_name"? diff --git a/trace2/tr2_tls.c b/trace2/tr2_tls.c index 28ea55863d1..35d49b27b2e 100644 --- a/trace2/tr2_tls.c +++ b/trace2/tr2_tls.c @@ -48,7 +48,7 @@ void tr2tls_start_process_clock(void) struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_name, uint64_t us_thread_start) { - struct tr2tls_thread_ctx *ctx; + struct tr2tls_thread_ctx *ctx = xcalloc(1, sizeof(struct tr2tls_thread_ctx)); struct strbuf buf_name = STRBUF_INIT; int thread_id = tr2tls_locked_increment(&tr2_next_thread_id); @@ -56,8 +56,7 @@ struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_name, strbuf_addf(&buf_name, "th%02d:", thread_id); strbuf_addstr(&buf_name, thread_name); - FLEX_ALLOC_MEM(ctx, thread_name, buf_name.buf, buf_name.len); - strbuf_release(&buf_name); + ctx->thread_name = strbuf_detach(&buf_name, NULL); ctx->thread_id = thread_id; @@ -188,6 +187,7 @@ void tr2tls_release(void) while (ctx) { struct tr2tls_thread_ctx *next = ctx->next_ctx; + free((char *)ctx->thread_name); free(ctx->array_us_start); free(ctx); diff --git a/trace2/tr2_tls.h b/trace2/tr2_tls.h index 503829bbd44..bc6c6f12e38 100644 --- a/trace2/tr2_tls.h +++ b/trace2/tr2_tls.h @@ -6,6 +6,7 @@ #include "trace2/tr2_tmr.h" struct tr2tls_thread_ctx { + const char *thread_name; struct tr2tls_thread_ctx *next_ctx; uint64_t *array_us_start; size_t alloc; @@ -14,8 +15,6 @@ struct tr2tls_thread_ctx { struct tr2_timer_block timers; struct tr2_counter_block counters; - - char thread_name[FLEX_ARRAY]; }; /* > [...] > index 7da94aba522..ed99a234b95 100644 > --- a/trace2/tr2_tls.c > +++ b/trace2/tr2_tls.c > @@ -34,7 +34,18 @@ void tr2tls_start_process_clock(void) > struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_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); Here's the looks-to-be-unrelated to this strbuf conversion code I mentioned above. > + > + if (thread_id) > + strbuf_addf(&buf_name, "th%02d:", thread_id); > + strbuf_addstr(&buf_name, thread_name); > + > + FLEX_ALLOC_MEM(ctx, thread_name, buf_name.buf, buf_name.len); > + strbuf_release(&buf_name); > + > + ctx->thread_id = thread_id; > > /* > [...]

On the Git mailing list, Jeff Hostetler wrote (reply to this):

On 12/28/21 8:11 PM, Ævar Arnfjörð Bjarmason wrote: > > On Tue, Dec 28 2021, Jeff Hostetler via GitGitGadget wrote: > >> From: Jeff Hostetler <jeffhost@microsoft.com> >> >> Move the thread name to a flex array at the bottom of the Trace2 >> thread local storage data and get rid of the strbuf. >> >> Let the flex array have the full computed value of the thread name >> without truncation. >> >> Change the PERF target to truncate the thread name so that the columns >> still line up. > > This commit message really doesn't help in explaining what we're trying > to do here and why it's needed. I'm not saying it's not, but why not a > strbuf, why a flex array? The diff below also shows changes unrelated to > this. > > I tried this local fixup on top of this series which works, so I wonder > if we're just trying to get rid of the strbuf to signal that this > shouldn't change why not just strbuf_detach() and keep a "const char > *thread_name"? > > diff --git a/trace2/tr2_tls.c b/trace2/tr2_tls.c > index 28ea55863d1..35d49b27b2e 100644 > --- a/trace2/tr2_tls.c > +++ b/trace2/tr2_tls.c > @@ -48,7 +48,7 @@ void tr2tls_start_process_clock(void) > struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_name, > uint64_t us_thread_start) > { > - struct tr2tls_thread_ctx *ctx; > + struct tr2tls_thread_ctx *ctx = xcalloc(1, sizeof(struct tr2tls_thread_ctx)); > struct strbuf buf_name = STRBUF_INIT; > int thread_id = tr2tls_locked_increment(&tr2_next_thread_id); > > @@ -56,8 +56,7 @@ struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_name, > strbuf_addf(&buf_name, "th%02d:", thread_id); > strbuf_addstr(&buf_name, thread_name); > > - FLEX_ALLOC_MEM(ctx, thread_name, buf_name.buf, buf_name.len); > - strbuf_release(&buf_name); > + ctx->thread_name = strbuf_detach(&buf_name, NULL); > > ctx->thread_id = thread_id; > > @@ -188,6 +187,7 @@ void tr2tls_release(void) > while (ctx) { > struct tr2tls_thread_ctx *next = ctx->next_ctx; > > + free((char *)ctx->thread_name); > free(ctx->array_us_start); > free(ctx); > > diff --git a/trace2/tr2_tls.h b/trace2/tr2_tls.h > index 503829bbd44..bc6c6f12e38 100644 > --- a/trace2/tr2_tls.h > +++ b/trace2/tr2_tls.h > @@ -6,6 +6,7 @@ > #include "trace2/tr2_tmr.h" > > struct tr2tls_thread_ctx { > + const char *thread_name; > struct tr2tls_thread_ctx *next_ctx; > uint64_t *array_us_start; > size_t alloc; > @@ -14,8 +15,6 @@ struct tr2tls_thread_ctx { > > struct tr2_timer_block timers; > struct tr2_counter_block counters; > - > - char thread_name[FLEX_ARRAY]; > }; > > /* I have to admit that I really don't know how to please you. In V1 I converted the "strbuf" to a "char *" inside the structure because there was concern that one might assume that the thread name could be changed after the thread was created. You complained that I made it a "char *" rather than a "const char *". I explained pointer ownership and you completely ignored that. You explained that I should just "cast away the const during the free" because other places in the code use that "anti-pattern". You also complained that I didn't use a callback to get the thread name dynamically rather than having a string field in the thread's TLS. I explained that it was faster to compute it once than to generate it on every logging call. You ignored that and hinted that the message formatting in each of the target destinations would make that cost irrelevant. I convert the field to a flex-array to avoid all of the allocation and ownership issues and now you send me a "fixup" patch that undoes the flex-array change and makes it look mostly like my previous version -- but WITH the "const" and the "cast" (that I've already talked about in this paragraph). So, where does this leave us? I'm really trying to "assume good intentions" here, but we've spent way toooooooo long discussing this thread_name field. It's starting to feel like you're going to just keep nagging me about this field until I make it look exactly like you would have written it. So, sorry to rant, but I don't know what else to say about this field. It is especially troubling that this "issue" has taken so much time -- time that would be better spent actually looking at the new timers and counters feature. > >> [...] >> index 7da94aba522..ed99a234b95 100644 >> --- a/trace2/tr2_tls.c >> +++ b/trace2/tr2_tls.c >> @@ -34,7 +34,18 @@ void tr2tls_start_process_clock(void) >> struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_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); > > Here's the looks-to-be-unrelated to this strbuf conversion code I > mentioned above. In the flex-array version, we defer the alloc of "ctx" until after we have computed the thread name -- we to do that so that we know the length of the thread name (and thus the size of the flex-array). To do that we need to know the thread id that we will be formatting into the thread name. And to do that we need to reserve a thread id -- which is a global and requires a lock. So the call to tr2tls_locked_increment() (as well as the formatting of the name itself) was moved up to the top of the function rather than after the "ctx" was allocated. > >> + >> + if (thread_id) >> + strbuf_addf(&buf_name, "th%02d:", thread_id); >> + strbuf_addstr(&buf_name, thread_name); >> + >> + FLEX_ALLOC_MEM(ctx, thread_name, buf_name.buf, buf_name.len); >> + strbuf_release(&buf_name); >> + >> + ctx->thread_id = thread_id; >> >> /* >> [...] Jeff

gitgitgadget · 2021-12-29T01:56:44Z

On the Git mailing list, Ævar Arnfjörð Bjarmason wrote (reply to this):

On Tue, Dec 28 2021, Jeff Hostetler via GitGitGadget wrote: > From: Jeff Hostetler <jeffhost@microsoft.com> > > Teach the message formatter in the Trace2 perf target to accept an > optional thread name argument. This will override the thread name > inherited from the thread local storage data block. > > This will be used in a future commit for global events that should > not be tied to a particular thread, such as a global stopwatch timer. We already have a "ctx", and that "ctx" has a "thread_name", but here and in the preceding commit we're adding a "thread_name" to every caller of these functions in case we'd like to override it. Wouldn't it make more sense to just pass a "ctx" to these functions? One of them already takes it, here's an (obviously incomplete) fixup on top of your series to make the one that doesn't take a "ctx", and for the only non-NULL users of "thread_name" to just use a trivial helper to pass in a "ctx" with a new "thread_name", then to swap it back. It would make for a smaller diffstat for this already large series, or we could do exactly what we're doing now, but avoid the churn of adjusting every caller by introducing a new sister function for those who want this parameter to be non-NULL. (The below patch is "broken" in that __FILE__ and __LINE__ need to be passed in as parameters, but this is just a trivial change for show/commentary) diff --git a/trace2/tr2_tgt_event.c b/trace2/tr2_tgt_event.c index b9eb2cdb77a..7aaec83dff7 100644 --- a/trace2/tr2_tgt_event.c +++ b/trace2/tr2_tgt_event.c @@ -82,16 +82,15 @@ static void fn_term(void) static void event_fmt_prepare(const char *event_name, const char *file, int line, const struct repository *repo, struct json_writer *jw, - const char *thread_name_override) + struct tr2tls_thread_ctx *ctx) { struct tr2_tbuf tb_now; + if (!ctx) + ctx = tr2tls_get_self(); jw_object_string(jw, "event", event_name); jw_object_string(jw, "sid", tr2_sid_get()); - jw_object_string(jw, "thread", - ((thread_name_override && *thread_name_override) - ? thread_name_override - : tr2tls_get_self()->thread_name)); + jw_object_string(jw, "thread", ctx->thread_name); /* * In brief mode, only emit <time> on these 2 event types. @@ -111,6 +110,20 @@ static void event_fmt_prepare(const char *event_name, const char *file, jw_object_intmax(jw, "repo", repo->trace2_repo_id); } +static void event_fmt_prepare_tn(const char *event_name, const char *file, + int line, const struct repository *repo, + struct json_writer *jw, + const char *thread_name) +{ + struct tr2tls_thread_ctx *ctx = tr2tls_get_self(); + const char *tmp; + + tmp = ctx->thread_name; + ctx->thread_name = thread_name; + event_fmt_prepare(event_name, __FILE__, __LINE__, NULL, jw, ctx); + ctx->thread_name = tmp; +} + static void fn_too_many_files_fl(const char *file, int line) { const char *event_name = "too_many_files"; @@ -629,7 +642,7 @@ static void fn_timer(uint64_t us_elapsed_absolute, 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); + event_fmt_prepare_tn(event_name, __FILE__, __LINE__, NULL, &jw, thread_name); jw_object_double(&jw, "t_abs", 6, t_abs); jw_object_string(&jw, "name", timer_name); jw_object_intmax(&jw, "count", interval_count); @@ -654,7 +667,7 @@ static void fn_counter(uint64_t us_elapsed_absolute, 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); + event_fmt_prepare_tn(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);

On the Git mailing list, Jeff Hostetler wrote (reply to this):

On 12/28/21 8:48 PM, Ævar Arnfjörð Bjarmason wrote: > > On Tue, Dec 28 2021, Jeff Hostetler via GitGitGadget wrote: > >> From: Jeff Hostetler <jeffhost@microsoft.com> >> >> Teach the message formatter in the Trace2 perf target to accept an >> optional thread name argument. This will override the thread name >> inherited from the thread local storage data block. >> >> This will be used in a future commit for global events that should >> not be tied to a particular thread, such as a global stopwatch timer. > > We already have a "ctx", and that "ctx" has a "thread_name", but here > and in the preceding commit we're adding a "thread_name" to every caller > of these functions in case we'd like to override it. > > Wouldn't it make more sense to just pass a "ctx" to these functions? One > of them already takes it, here's an (obviously incomplete) fixup on top > of your series to make the one that doesn't take a "ctx", and for the > only non-NULL users of "thread_name" to just use a trivial helper to > pass in a "ctx" with a new "thread_name", then to swap it back. > > It would make for a smaller diffstat for this already large series, or > we could do exactly what we're doing now, but avoid the churn of > adjusting every caller by introducing a new sister function for those > who want this parameter to be non-NULL. I suppose it is possible to have a helper version of `event_fmt_prepare()` that takes the extra argument and fixup the existing function to call it with NULL. I'll see if that makes sense. [...] > > +static void event_fmt_prepare_tn(const char *event_name, const char *file, > + int line, const struct repository *repo, > + struct json_writer *jw, > + const char *thread_name) > +{ > + struct tr2tls_thread_ctx *ctx = tr2tls_get_self(); > + const char *tmp; > + > + tmp = ctx->thread_name; > + ctx->thread_name = thread_name; > + event_fmt_prepare(event_name, __FILE__, __LINE__, NULL, jw, ctx); > + ctx->thread_name = tmp; > +} [...] This only works if we agree that thread name is a pointer inside the structure and not a flex-array. Personally, I think this is trying to do things backwards by temporarily changing the ctx->thread_name field. I think it would be better to `event_fmt_prepare_tn()` do the actual work with the supplied thread name and have the existing `event_fmt_prepare()` just call it with ctx->thread_name. Then we don't need to hack up the ctx. I'll see if this makes the diffs a little cleaner. Jeff

gitgitgadget · 2021-12-29T00:53:51Z

On the Git mailing list, Ævar Arnfjörð Bjarmason wrote (reply to this):

On Tue, Dec 28 2021, Jeff Hostetler via GitGitGadget wrote: > From: Jeff Hostetler <jeffhost@microsoft.com> > > Use "size_t" rather than "int" for the "alloc" and "nr_open_regions" > fields in the "tr2tls_thread_ctx". These are used by ALLOC_GROW(). > > This was discussed in: https://lore.kernel.org/all/YULF3hoaDxA9ENdO@nand.local/ Let's keep commit messages self-contained when possible. It's fine to reference on-list discussion (and I often do), but in this case all that's being referenced just seems to be Taylor saying we might as well change this while we're at it. So I'd think a short sentence saying we generally prefer "size_t" for these these days and we might as well change it here while we're at it would suffice over the ML link. > Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com> > --- > trace2/tr2_tls.h | 4 ++-- > 1 file changed, 2 insertions(+), 2 deletions(-) > > diff --git a/trace2/tr2_tls.h b/trace2/tr2_tls.h > index b1e327a928e..a90bd639d48 100644 > --- a/trace2/tr2_tls.h > +++ b/trace2/tr2_tls.h > @@ -11,8 +11,8 @@ > struct tr2tls_thread_ctx { > struct strbuf 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; > };

-Original file line number
+Diff line change
@@ Expand Up / @@ -23,6 +23,7 @@ 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)
@@ Expand Down Expand Up / @@ -105,9 +106,9 @@ 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,
-    		    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, event_name);
     	len = buf->len + TR2FMT_PERF_REPO_WIDTH;
     	if (repo)
@@ Expand Down @@

-Original file line number
+Diff line change
@@ Expand Up / @@ -3,17 +3,12 @@ @@
     #include "strbuf.h"
-    /*
-     * Arbitry limit for thread names for column alignment.
-     */
-    #define TR2_MAX_THREAD_NAME (24)
     struct tr2tls_thread_ctx {
-    	struct strbuf 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;
+    	char thread_name[FLEX_ARRAY];
     };
     /*
@@ Expand All / @@ -25,9 +20,6 @@ struct tr2tls_thread_ctx { @@
      * 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.
-     *
      * In this and all following functions the term "self" refers to the
      * current thread.
      */
@@ Expand Down @@

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Trace2 stopwatch timers and global counters #1099

Diff view

Diff view

There are no files selected for viewing

gitgitgadget bot Dec 20, 2021

gitgitgadget bot Dec 20, 2021

gitgitgadget bot Dec 20, 2021

gitgitgadget bot Dec 21, 2021

gitgitgadget bot Dec 22, 2021

gitgitgadget bot Dec 21, 2021

gitgitgadget bot Dec 22, 2021

gitgitgadget bot Dec 22, 2021

gitgitgadget bot Dec 29, 2021

gitgitgadget bot Dec 29, 2021

gitgitgadget bot Dec 29, 2021

gitgitgadget bot Dec 29, 2021

gitgitgadget bot Dec 29, 2021

Trace2 stopwatch timers and global counters #1099

Trace2 stopwatch timers and global counters #1099

Diff view

Diff view

There are no files selected for viewing

gitgitgadget bot Dec 20, 2021

Choose a reason for hiding this comment

gitgitgadget bot Dec 20, 2021

Choose a reason for hiding this comment

gitgitgadget bot Dec 20, 2021

Choose a reason for hiding this comment

gitgitgadget bot Dec 21, 2021

Choose a reason for hiding this comment

gitgitgadget bot Dec 22, 2021

Choose a reason for hiding this comment

gitgitgadget bot Dec 21, 2021

Choose a reason for hiding this comment

gitgitgadget bot Dec 22, 2021

Choose a reason for hiding this comment

gitgitgadget bot Dec 22, 2021

Choose a reason for hiding this comment

gitgitgadget bot Dec 29, 2021

Choose a reason for hiding this comment

gitgitgadget bot Dec 29, 2021

Choose a reason for hiding this comment

gitgitgadget bot Dec 29, 2021

Choose a reason for hiding this comment

gitgitgadget bot Dec 29, 2021

Choose a reason for hiding this comment

gitgitgadget bot Dec 29, 2021

Choose a reason for hiding this comment