From patchwork Tue Dec 28 19:36:34 2021
Content-Type: text/plain; charset="utf-8"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
X-Patchwork-Submitter: Jeff Hostetler <jeffhost@microsoft.com>
X-Patchwork-Id: 12700556
Return-Path: <git-owner@kernel.org>
X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on
	aws-us-west-2-korg-lkml-1.web.codeaurora.org
Received: from vger.kernel.org (vger.kernel.org [23.128.96.18])
	by smtp.lore.kernel.org (Postfix) with ESMTP id C9AB6C433EF
	for <git@archiver.kernel.org>; Tue, 28 Dec 2021 19:36:47 +0000 (UTC)
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
        id S237173AbhL1Tgq (ORCPT <rfc822;git@archiver.kernel.org>);
        Tue, 28 Dec 2021 14:36:46 -0500
Received: from lindbergh.monkeyblade.net ([23.128.96.19]:39964 "EHLO
        lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
        with ESMTP id S235996AbhL1Tgq (ORCPT <rfc822;git@vger.kernel.org>);
        Tue, 28 Dec 2021 14:36:46 -0500
Received: from mail-wr1-x432.google.com (mail-wr1-x432.google.com
 [IPv6:2a00:1450:4864:20::432])
        by lindbergh.monkeyblade.net (Postfix) with ESMTPS id C86C7C061574
        for <git@vger.kernel.org>; Tue, 28 Dec 2021 11:36:45 -0800 (PST)
Received: by mail-wr1-x432.google.com with SMTP id w20so31164887wra.9
        for <git@vger.kernel.org>; Tue, 28 Dec 2021 11:36:45 -0800 (PST)
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
        d=gmail.com; s=20210112;
        h=message-id:in-reply-to:references:from:date:subject:fcc
         :content-transfer-encoding:mime-version:to:cc;
        bh=KwlOealDsYSlT3vr/iAxRQ7tZPRCqQeJ/p6VpI0LNjY=;
        b=DPyCII7CX32P4LvzU+YJotQb0o5D2q2YPpGqLt7rcjOTSKtoXWc6GjaqE5z8fOqJyR
         ON8iC0MSolVrAKOFQq5c8H07kmzQg2QhYJzF7BneMSfSt9NkRi6bdau9T1ovHTLaLWV3
         YRr7GT3ZDQmWYfOgdXz548U8rcfvsbgqz2M6m72bVrT8g43RhfRMGc64b3dobohKFGVA
         MEcS4H6kYEIq6VXST83AVXzqnlMC1T2ERHhS7onrEO5AqYq89aF9iEeRMxi4KaPdgTKX
         kd2fQjduDdvim6rIBm2Vii56VvisWuDkU35tzx1qvQ1EJhmUA+l6C8AMV/n40H4NlOuy
         UTyw==
X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
        d=1e100.net; s=20210112;
        h=x-gm-message-state:message-id:in-reply-to:references:from:date
         :subject:fcc:content-transfer-encoding:mime-version:to:cc;
        bh=KwlOealDsYSlT3vr/iAxRQ7tZPRCqQeJ/p6VpI0LNjY=;
        b=ctUCaUawjK8g+vw0/DjUGUaa383Y3dlLsoFLz+mdfC8jlTCzEvEQblJxojnk4gtQ3u
         HFgRkiifmht/nbnNzdkskDETt50Fe3jllQm8VJvAToil/ymlj5DD1GPZyyDeDASstil9
         OPeOE2EOonMQCUVvX2GtEGperj22alcwEOc0QYmVcLBFSVZSF2fzaAYZWhy7Zs9JXoBG
         UhK89ZvgH0mblamwKlB4S0RUTTCfXyxOiNj381kc7jvk6zgaegbiQaZpVwYh4CYt/HHQ
         gQYZdPonk/aFrM++iBMnKUqUbCy8e1cPL+pKAIfuxhwcXwcIPDJd7M/VcR37EQG6SBOq
         V/vQ==
X-Gm-Message-State: AOAM5300iJfgjtq/M6XRqMXqNNOSBZkdAusUcNIzKMcEZuN4GhRGtMFw
        jahRsyMdv/puwLxYil3CPk9h2I7VpNw=
X-Google-Smtp-Source: 
 ABdhPJyRpdXG8ZTFIW8c6hvLgA4zQhtnNZIju2gvEBaqUaqx8KLYuQlHXguQm+Me8WeBcOVZHw5rHA==
X-Received: by 2002:adf:f70b:: with SMTP id
 r11mr18231277wrp.496.1640720204252;
        Tue, 28 Dec 2021 11:36:44 -0800 (PST)
Received: from [127.0.0.1] ([13.74.141.28])
        by smtp.gmail.com with ESMTPSA id
 m3sm18902719wrv.95.2021.12.28.11.36.43
        (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256);
        Tue, 28 Dec 2021 11:36:44 -0800 (PST)
Message-Id: 
 <96f6896a13e68263b96827e0c66f20178fb9dfd1.1640720202.git.gitgitgadget@gmail.com>
In-Reply-To: <pull.1099.v2.git.1640720202.gitgitgadget@gmail.com>
References: <pull.1099.git.1640012469.gitgitgadget@gmail.com>
        <pull.1099.v2.git.1640720202.gitgitgadget@gmail.com>
Date: Tue, 28 Dec 2021 19:36:34 +0000
Subject: [PATCH v2 1/9] trace2: use size_t alloc,nr_open_regions in
 tr2tls_thread_ctx
Fcc: Sent
MIME-Version: 1.0
To: git@vger.kernel.org
Cc: =?utf-8?b?w4Z2YXIgQXJuZmrDtnLDsA==?= Bjarmason  <avarab@gmail.com>,
 Jeff Hostetler <git@jeffhostetler.com>, Derrick Stolee <stolee@gmail.com>,
 Matheus Tavares <matheus.bernardino@usp.br>, Johannes Sixt <j6t@kdbg.org>,
 Jeff Hostetler <jeffhost@microsoft.com>,
 Jeff Hostetler <jeffhost@microsoft.com>
Precedence: bulk
List-ID: <git.vger.kernel.org>
X-Mailing-List: git@vger.kernel.org
From: Jeff Hostetler <jeffhost@microsoft.com>

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/

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;
 };
 

From patchwork Tue Dec 28 19:36:35 2021
Content-Type: text/plain; charset="utf-8"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
X-Patchwork-Submitter: Jeff Hostetler <jeffhost@microsoft.com>
X-Patchwork-Id: 12700557
Return-Path: <git-owner@kernel.org>
X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on
	aws-us-west-2-korg-lkml-1.web.codeaurora.org
Received: from vger.kernel.org (vger.kernel.org [23.128.96.18])
	by smtp.lore.kernel.org (Postfix) with ESMTP id 04870C433F5
	for <git@archiver.kernel.org>; Tue, 28 Dec 2021 19:36:55 +0000 (UTC)
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
        id S237179AbhL1Tgr (ORCPT <rfc822;git@archiver.kernel.org>);
        Tue, 28 Dec 2021 14:36:47 -0500
Received: from lindbergh.monkeyblade.net ([23.128.96.19]:39968 "EHLO
        lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
        with ESMTP id S237175AbhL1Tgr (ORCPT <rfc822;git@vger.kernel.org>);
        Tue, 28 Dec 2021 14:36:47 -0500
Received: from mail-wr1-x431.google.com (mail-wr1-x431.google.com
 [IPv6:2a00:1450:4864:20::431])
        by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 751ABC061574
        for <git@vger.kernel.org>; Tue, 28 Dec 2021 11:36:46 -0800 (PST)
Received: by mail-wr1-x431.google.com with SMTP id s1so40171101wra.6
        for <git@vger.kernel.org>; Tue, 28 Dec 2021 11:36:46 -0800 (PST)
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
        d=gmail.com; s=20210112;
        h=message-id:in-reply-to:references:from:date:subject:fcc
         :content-transfer-encoding:mime-version:to:cc;
        bh=GFBd797eHYnH0eNzK9O41oTMilucb0iYBWz2vFrtEVo=;
        b=NEYDXU57NWPsDqKP4Nr5VNQOYV56+3dXHGlNYLi5QDYuvaAX54x0kQT6aCrIY+JbEO
         wSAPOovTra8v6omRyimND2hcBeoJu09OhUGDoGPW1lKU+mNOUKlF6KNntiS9U7L+GPoD
         7hkjujBSQ2fGUB6H/z4g+1SocfuCTHAWTzbQ+TAWNA5MQOx2ywXdjcFGnfqf9YoUmGiK
         lmLx3AkXYYWWzLLaWv8arNoxidVAlnEi4OBbnUrjLhWP5ygMba4uidTdZqWkb5/1sFx3
         1vY0yMyeNpTTuadW293jT03+/pF6HFEaTC4ImKwgXDwM4aGhLgJPVESnQYmrPJ2TKjha
         QkYQ==
X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
        d=1e100.net; s=20210112;
        h=x-gm-message-state:message-id:in-reply-to:references:from:date
         :subject:fcc:content-transfer-encoding:mime-version:to:cc;
        bh=GFBd797eHYnH0eNzK9O41oTMilucb0iYBWz2vFrtEVo=;
        b=7dfgc52IFugQk5R3NxYxNiGa4nFA47n630icpVj5uKq3paDBSovWaHp7u5MRoyi2HA
         JV1w5MHPKtzV8YZLECcQ+dRuxCPYRShZj9IA4MyeZJJSXWKiInhenSsKXReBtBSdkbtP
         2GBxcYYNWONYAXC7GQkCrCzoeoimGteZliKXsh0F6BoRyILMgzlhXq94HECGaN1otOzO
         n2eWIt1xbf1av1NZ1WW3B7CW8ROTyXg0X5WVbd6/T1z/LhT1DNTLozwCZ5v8rDqvRKhi
         A1JNNhvL7yVbMyNVDVToa2TZuXG2t3e4RtKEkJNxgr01jxZgz2kGznF+afZrZGoHRvQN
         5ymw==
X-Gm-Message-State: AOAM533mxc45GkiCTiJuAcMoqH9Vzu9TMs2o0WxoX+QZlWBLPwGdjnub
        r9vvHJ2PO+TJEge1SIxRfedkh/hf7R8=
X-Google-Smtp-Source: 
 ABdhPJzbL+4KOj2HAufKYwOevV3vNbQLXllZELME/GYyOI5fIsqgABIbc4pDltXx/nlN15EphUl66Q==
X-Received: by 2002:a5d:6e8c:: with SMTP id
 k12mr17189356wrz.664.1640720204832;
        Tue, 28 Dec 2021 11:36:44 -0800 (PST)
Received: from [127.0.0.1] ([13.74.141.28])
        by smtp.gmail.com with ESMTPSA id
 o38sm17688444wms.11.2021.12.28.11.36.44
        (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256);
        Tue, 28 Dec 2021 11:36:44 -0800 (PST)
Message-Id: 
 <ff8df1b148ec486f565a59cb8a227bfa2ef48313.1640720202.git.gitgitgadget@gmail.com>
In-Reply-To: <pull.1099.v2.git.1640720202.gitgitgadget@gmail.com>
References: <pull.1099.git.1640012469.gitgitgadget@gmail.com>
        <pull.1099.v2.git.1640720202.gitgitgadget@gmail.com>
Date: Tue, 28 Dec 2021 19:36:35 +0000
Subject: [PATCH v2 2/9] trace2: convert tr2tls_thread_ctx.thread_name from
 strbuf to flex array
Fcc: Sent
MIME-Version: 1.0
To: git@vger.kernel.org
Cc: =?utf-8?b?w4Z2YXIgQXJuZmrDtnLDsA==?= Bjarmason  <avarab@gmail.com>,
 Jeff Hostetler <git@jeffhostetler.com>, Derrick Stolee <stolee@gmail.com>,
 Matheus Tavares <matheus.bernardino@usp.br>, Johannes Sixt <j6t@kdbg.org>,
 Jeff Hostetler <jeffhost@microsoft.com>,
 Jeff Hostetler <jeffhost@microsoft.com>
Precedence: bulk
List-ID: <git.vger.kernel.org>
X-Mailing-List: git@vger.kernel.org
From: Jeff Hostetler <jeffhost@microsoft.com>

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.

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 trace2/tr2_tgt_event.c |  2 +-
 trace2/tr2_tgt_perf.c  |  7 ++++---
 trace2/tr2_tls.c       | 25 +++++++++++++------------
 trace2/tr2_tls.h       | 10 +---------
 4 files changed, 19 insertions(+), 25 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..fd6cce3efe5 100644
--- a/trace2/tr2_tgt_perf.c
+++ b/trace2/tr2_tgt_perf.c
@@ -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)
 
@@ -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)
diff --git a/trace2/tr2_tls.c b/trace2/tr2_tls.c
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);
+
+	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;
 
 	/*
 	 * Implicitly "tr2tls_push_self()" to capture the thread's start
@@ -45,15 +56,6 @@ struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_name,
 	ctx->array_us_start = (uint64_t *)xcalloc(ctx->alloc, sizeof(uint64_t));
 	ctx->array_us_start[ctx->nr_open_regions++] = us_thread_start;
 
-	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);
-
 	pthread_setspecific(tr2tls_key, ctx);
 
 	return ctx;
@@ -95,7 +97,6 @@ void tr2tls_unset_self(void)
 
 	pthread_setspecific(tr2tls_key, NULL);
 
-	strbuf_release(&ctx->thread_name);
 	free(ctx->array_us_start);
 	free(ctx);
 }
@@ -113,7 +114,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..64d97c5ac03 100644
--- a/trace2/tr2_tls.h
+++ b/trace2/tr2_tls.h
@@ -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;
 	size_t alloc;
 	size_t nr_open_regions; /* plays role of "nr" in ALLOC_GROW */
 	int thread_id;
+	char thread_name[FLEX_ARRAY];
 };
 
 /*
@@ -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.
  */

From patchwork Tue Dec 28 19:36:36 2021
Content-Type: text/plain; charset="utf-8"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
X-Patchwork-Submitter: Jeff Hostetler <jeffhost@microsoft.com>
X-Patchwork-Id: 12700558
Return-Path: <git-owner@kernel.org>
X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on
	aws-us-west-2-korg-lkml-1.web.codeaurora.org
Received: from vger.kernel.org (vger.kernel.org [23.128.96.18])
	by smtp.lore.kernel.org (Postfix) with ESMTP id 313E5C4332F
	for <git@archiver.kernel.org>; Tue, 28 Dec 2021 19:36:55 +0000 (UTC)
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
        id S237187AbhL1Tgt (ORCPT <rfc822;git@archiver.kernel.org>);
        Tue, 28 Dec 2021 14:36:49 -0500
Received: from lindbergh.monkeyblade.net ([23.128.96.19]:39976 "EHLO
        lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
        with ESMTP id S237176AbhL1Tgr (ORCPT <rfc822;git@vger.kernel.org>);
        Tue, 28 Dec 2021 14:36:47 -0500
Received: from mail-wr1-x433.google.com (mail-wr1-x433.google.com
 [IPv6:2a00:1450:4864:20::433])
        by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 1C149C06173F
        for <git@vger.kernel.org>; Tue, 28 Dec 2021 11:36:47 -0800 (PST)
Received: by mail-wr1-x433.google.com with SMTP id r17so40172477wrc.3
        for <git@vger.kernel.org>; Tue, 28 Dec 2021 11:36:47 -0800 (PST)
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
        d=gmail.com; s=20210112;
        h=message-id:in-reply-to:references:from:date:subject:fcc
         :content-transfer-encoding:mime-version:to:cc;
        bh=Ug8oqNMEumg2bBDk4UGGbUWbZGOzVorpz7gFeUis3PE=;
        b=GEpDMhkEOBmHOE/e1/UE+JfUbaVzXn6zUf2TmuL6CA9Vh54Auft0XvzWBAgKdNH7dq
         2OAQj2inf1krIxbhgChNC4Pswyl3DWV2ajWc/KFK+WhtxCGZ7tI0D5aoiIpWjLPDScZQ
         ncasS5Rwc9/4eXdlljmfBmYeOuXaH1TWJD0TiTkvyTR/6rtH+/yo923RRK9/nUj3gdnj
         4fYVMfYvk9vqOlRe12HuKVuARDK5+WAOR8FnKTXPtU6UH1WXP+1jJFkR8ANL6YC059xn
         /3jN0DqcZbpxSe5aV5XygScjBBZ+JhFX3H8RG3BacAXUetIfcy6b+oU3TlX0wgMrY4e3
         OahA==
X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
        d=1e100.net; s=20210112;
        h=x-gm-message-state:message-id:in-reply-to:references:from:date
         :subject:fcc:content-transfer-encoding:mime-version:to:cc;
        bh=Ug8oqNMEumg2bBDk4UGGbUWbZGOzVorpz7gFeUis3PE=;
        b=qHg/xcgj0nUl81KOl3CWKJVW2OhMjBNUru5SrV7q0TiZSajrPUpdi9504ZhLzxngbE
         FJbB5WjauM3suAZR01lLCWqnWkJQKnbmo+EBWGZ8p42nA78Km2p77paMt5o33SEisenW
         uITi8xzBd52Z1VtD3M78GmWiO5V2E97sPB3MfnPyDcv9d6pwfqLlV6wwDXWaBu+w/U6v
         ggNgdcQ9fzz9rnsShf9mk3mH9GXSxrlGisCl2+i6w7uwWEwgtXqp5igJmWs05Se1++l9
         TTI3Lo3PebOu2nYX/xzcGnVgo7BG/RU/0yF09p8+Df/iVu0v+0naOWe3Vbr4HOv49P90
         CTsQ==
X-Gm-Message-State: AOAM532rGRf5zo/x2Uqv1vjiEzieTwbNfxuNP6eYho83HJAmN4SyuH62
        4Ak0f4OfudBcJlLZi1hp2Z5NkBV+wcI=
X-Google-Smtp-Source: 
 ABdhPJwaY1WULCC5K2S8/IJikABizLDhWjv/lxxC9FZ4cB/b1UeMzJRINB8Y6HbZyzqsjTrZtGmPww==
X-Received: by 2002:a5d:64a1:: with SMTP id m1mr17265991wrp.503.1640720205447;
        Tue, 28 Dec 2021 11:36:45 -0800 (PST)
Received: from [127.0.0.1] ([13.74.141.28])
        by smtp.gmail.com with ESMTPSA id
 u3sm24420079wrs.0.2021.12.28.11.36.44
        (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256);
        Tue, 28 Dec 2021 11:36:45 -0800 (PST)
Message-Id: 
 <11c8d8cdf1a9c0e4f840a295c7401014404e119d.1640720202.git.gitgitgadget@gmail.com>
In-Reply-To: <pull.1099.v2.git.1640720202.gitgitgadget@gmail.com>
References: <pull.1099.git.1640012469.gitgitgadget@gmail.com>
        <pull.1099.v2.git.1640720202.gitgitgadget@gmail.com>
Date: Tue, 28 Dec 2021 19:36:36 +0000
Subject: [PATCH v2 3/9] trace2: defer free of thread local storage until
 program exit.
Fcc: Sent
MIME-Version: 1.0
To: git@vger.kernel.org
Cc: =?utf-8?b?w4Z2YXIgQXJuZmrDtnLDsA==?= Bjarmason  <avarab@gmail.com>,
 Jeff Hostetler <git@jeffhostetler.com>, Derrick Stolee <stolee@gmail.com>,
 Matheus Tavares <matheus.bernardino@usp.br>, Johannes Sixt <j6t@kdbg.org>,
 Jeff Hostetler <jeffhost@microsoft.com>,
 Jeff Hostetler <jeffhost@microsoft.com>
Precedence: bulk
List-ID: <git.vger.kernel.org>
X-Mailing-List: git@vger.kernel.org
From: Jeff Hostetler <jeffhost@microsoft.com>

From: Jeff Hostetler <jeffhost@microsoft.com>

Defer freeing of the Trace2 per-thread thread local storage until
program exit.  Create a global list to own them.

Trace2 thread local storage data is allocated when a thread is created
and associated with that thread.  Previously, that storage was deleted
when the thread exited.  Now at thread exit, we simply disassociate
the data from the thread and let the global list manage the cleanup.

This will be used by a later commit when we add "counters" and
stopwatch-style "timers" to the Trace2 API.  We will add those fields
to the thread local storage block and allow each thread to efficiently
(without locks) accumulate counter and timer data.  At program exit,
the main thread will run thru the global list and compute and report
totals before freeing the list.

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 trace2/tr2_tls.c | 38 +++++++++++++++++++++++++++++++-------
 trace2/tr2_tls.h |  3 ++-
 2 files changed, 33 insertions(+), 8 deletions(-)

diff --git a/trace2/tr2_tls.c b/trace2/tr2_tls.c
index ed99a234b95..78538d5e522 100644
--- a/trace2/tr2_tls.c
+++ b/trace2/tr2_tls.c
@@ -15,6 +15,18 @@ static uint64_t tr2tls_us_start_process;
 static pthread_mutex_t tr2tls_mutex;
 static pthread_key_t tr2tls_key;
 
+/*
+ * This list owns all of the thread-specific CTX data.
+ *
+ * While a thread is alive it is associated with a CTX (owned by this
+ * list) and that CTX is installed in the thread's TLS data area.
+ * When a thread exits, it is disassociated from its CTX, but the (now
+ * dormant) CTX is held in this list until program exit.
+ *
+ * Similarly, `tr2tls_thread_main` points to a CTX contained within
+ * this list.
+ */
+static struct tr2tls_thread_ctx *tr2tls_ctx_list; /* modify under lock */
 static int tr2_next_thread_id; /* modify under lock */
 
 void tr2tls_start_process_clock(void)
@@ -56,6 +68,14 @@ struct tr2tls_thread_ctx *tr2tls_create_self(const char *thread_name,
 	ctx->array_us_start = (uint64_t *)xcalloc(ctx->alloc, sizeof(uint64_t));
 	ctx->array_us_start[ctx->nr_open_regions++] = us_thread_start;
 
+	/*
+	 * Link this CTX into the CTX list and make it the head.
+	 */
+	pthread_mutex_lock(&tr2tls_mutex);
+	ctx->next_ctx = tr2tls_ctx_list;
+	tr2tls_ctx_list = ctx;
+	pthread_mutex_unlock(&tr2tls_mutex);
+
 	pthread_setspecific(tr2tls_key, ctx);
 
 	return ctx;
@@ -91,14 +111,7 @@ int tr2tls_is_main_thread(void)
 
 void tr2tls_unset_self(void)
 {
-	struct tr2tls_thread_ctx *ctx;
-
-	ctx = tr2tls_get_self();
-
 	pthread_setspecific(tr2tls_key, NULL);
-
-	free(ctx->array_us_start);
-	free(ctx);
 }
 
 void tr2tls_push_self(uint64_t us_now)
@@ -162,11 +175,22 @@ void tr2tls_init(void)
 
 void tr2tls_release(void)
 {
+	struct tr2tls_thread_ctx *ctx = tr2tls_ctx_list;
+
 	tr2tls_unset_self();
 	tr2tls_thread_main = NULL;
 
 	pthread_mutex_destroy(&tr2tls_mutex);
 	pthread_key_delete(tr2tls_key);
+
+	while (ctx) {
+		struct tr2tls_thread_ctx *next = ctx->next_ctx;
+
+		free(ctx->array_us_start);
+		free(ctx);
+
+		ctx = next;
+	}
 }
 
 int tr2tls_locked_increment(int *p)
diff --git a/trace2/tr2_tls.h b/trace2/tr2_tls.h
index 64d97c5ac03..889010ec1ff 100644
--- a/trace2/tr2_tls.h
+++ b/trace2/tr2_tls.h
@@ -4,6 +4,7 @@
 #include "strbuf.h"
 
 struct tr2tls_thread_ctx {
+	struct tr2tls_thread_ctx *next_ctx;
 	uint64_t *array_us_start;
 	size_t alloc;
 	size_t nr_open_regions; /* plays role of "nr" in ALLOC_GROW */
@@ -37,7 +38,7 @@ struct tr2tls_thread_ctx *tr2tls_get_self(void);
 int tr2tls_is_main_thread(void);
 
 /*
- * Free our TLS data.
+ * Disassociate thread's TLS CTX data from the thread.
  */
 void tr2tls_unset_self(void);
 

From patchwork Tue Dec 28 19:36:37 2021
Content-Type: text/plain; charset="utf-8"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
X-Patchwork-Submitter: Jeff Hostetler <jeffhost@microsoft.com>
X-Patchwork-Id: 12700560
Return-Path: <git-owner@kernel.org>
X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on
	aws-us-west-2-korg-lkml-1.web.codeaurora.org
Received: from vger.kernel.org (vger.kernel.org [23.128.96.18])
	by smtp.lore.kernel.org (Postfix) with ESMTP id 42A7FC433EF
	for <git@archiver.kernel.org>; Tue, 28 Dec 2021 19:36:55 +0000 (UTC)
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
        id S237194AbhL1Tgw (ORCPT <rfc822;git@archiver.kernel.org>);
        Tue, 28 Dec 2021 14:36:52 -0500
Received: from lindbergh.monkeyblade.net ([23.128.96.19]:39978 "EHLO
        lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
        with ESMTP id S237183AbhL1Tgs (ORCPT <rfc822;git@vger.kernel.org>);
        Tue, 28 Dec 2021 14:36:48 -0500
Received: from mail-wr1-x429.google.com (mail-wr1-x429.google.com
 [IPv6:2a00:1450:4864:20::429])
        by lindbergh.monkeyblade.net (Postfix) with ESMTPS id BC6B3C061574
        for <git@vger.kernel.org>; Tue, 28 Dec 2021 11:36:47 -0800 (PST)
Received: by mail-wr1-x429.google.com with SMTP id r17so40172527wrc.3
        for <git@vger.kernel.org>; Tue, 28 Dec 2021 11:36:47 -0800 (PST)
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
        d=gmail.com; s=20210112;
        h=message-id:in-reply-to:references:from:date:subject:fcc
         :content-transfer-encoding:mime-version:to:cc;
        bh=QPndysMS5d9HtSVD2Y4SedG3uUuo8ie3ZHyRfzHOZ4w=;
        b=YLB1u/C64wM6mAEKKrVcHLoov2pruFKwbzDN5rkxkvxIFpKAfg02fi+nGwTeKZnhub
         Zqs2FO9qRoWLIdKui73b4fvrkYzkd6J8kUVI+DRxPO9z5EXewtOyNWwfzsJlWV/RzEOl
         rytwlV3O00G3EJmC118mx/IZRfnTeei9YOEVXmD23LhPaJiNrRqrxwaIE9U3A2bsyERp
         QSt0GYWcj2+37tZZReSU3BhdTtQnFp5N6L0ukRKiNoJdRZ9mNoqmP1ROB2s7MkeMf3p8
         L8L/nYun2lJA4VC7ix0Y6PplhhwCTgHoQHBHzSKz3aPsk7Iq5atDc9usHkzRlQS785+V
         nB0g==
X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
        d=1e100.net; s=20210112;
        h=x-gm-message-state:message-id:in-reply-to:references:from:date
         :subject:fcc:content-transfer-encoding:mime-version:to:cc;
        bh=QPndysMS5d9HtSVD2Y4SedG3uUuo8ie3ZHyRfzHOZ4w=;
        b=5t18jpl9bEwGEFxp4ifJl+OhKV2j+Qj6BnAaQoi2jk+764RZrp8VQGcB7A6mTUVX9q
         Uh2+mPaAP0g7NZHV0OLqU5KcTYkFGiI4YqM/GCuCaJhPU6mknqt7Obvj93B2tcd/Z8TP
         i3mUqWZxYwQ+dQO+JMucyxVy4UlBmZVslBZ5nXtzpseohVH40wPziY/eIr6wiyU7t/GN
         2BEignDGWp2p8UZuKbfU40IPueWfBIKh2XAF9maLJO9Mzky3k7hWritSjqgDZrF8EyZ0
         Wacri8bkedNQDUPoucqVez1k+gkyCUvDDyhgJVBBPsaAxjb+VXihTMSUbtjH2uL73TF3
         qx9g==
X-Gm-Message-State: AOAM531Hv70sOCEzNHBNzvG7idWWIveZhH2RMtB0b0rphDgFaOKcqjEZ
        SZ7iExvl5HYBbzecRzCuPokoiJ5/kCU=
X-Google-Smtp-Source: 
 ABdhPJyKwryZi8Ckc5QirvABuA3kOs8spBvO5BcYzmaLveFp54nsrEPWjyVvL1+aMIRGWISA2el36w==
X-Received: by 2002:a5d:66d2:: with SMTP id
 k18mr17882988wrw.430.1640720206152;
        Tue, 28 Dec 2021 11:36:46 -0800 (PST)
Received: from [127.0.0.1] ([13.74.141.28])
        by smtp.gmail.com with ESMTPSA id
 a198sm19074377wmd.42.2021.12.28.11.36.45
        (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256);
        Tue, 28 Dec 2021 11:36:45 -0800 (PST)
Message-Id: 
 <531a1ee45c2ff6dfd61f83ccbafc31465f0d9e80.1640720202.git.gitgitgadget@gmail.com>
In-Reply-To: <pull.1099.v2.git.1640720202.gitgitgadget@gmail.com>
References: <pull.1099.git.1640012469.gitgitgadget@gmail.com>
        <pull.1099.v2.git.1640720202.gitgitgadget@gmail.com>
Date: Tue, 28 Dec 2021 19:36:37 +0000
Subject: [PATCH v2 4/9] trace2: add thread-name override to event target
Fcc: Sent
MIME-Version: 1.0
To: git@vger.kernel.org
Cc: =?utf-8?b?w4Z2YXIgQXJuZmrDtnLDsA==?= Bjarmason  <avarab@gmail.com>,
 Jeff Hostetler <git@jeffhostetler.com>, Derrick Stolee <stolee@gmail.com>,
 Matheus Tavares <matheus.bernardino@usp.br>, Johannes Sixt <j6t@kdbg.org>,
 Jeff Hostetler <jeffhost@microsoft.com>,
 Jeff Hostetler <jeffhost@microsoft.com>
Precedence: bulk
List-ID: <git.vger.kernel.org>
X-Mailing-List: git@vger.kernel.org
From: Jeff Hostetler <jeffhost@microsoft.com>

From: Jeff Hostetler <jeffhost@microsoft.com>

Teach the message formatter in the Trace2 event target to take an
optional thread-name argument.  This overrides the thread name
inherited from the thread local storage data.

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
that aggregates data from all threads.

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 trace2/tr2_tgt_event.c | 59 ++++++++++++++++++++++--------------------
 1 file changed, 31 insertions(+), 28 deletions(-)

diff --git a/trace2/tr2_tgt_event.c b/trace2/tr2_tgt_event.c
index ca48d00aebc..4ce50944298 100644
--- a/trace2/tr2_tgt_event.c
+++ b/trace2/tr2_tgt_event.c
@@ -81,14 +81,17 @@ 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)
+			      struct json_writer *jw,
+			      const char *thread_name_override)
 {
-	struct tr2tls_thread_ctx *ctx = tr2tls_get_self();
 	struct tr2_tbuf tb_now;
 
 	jw_object_string(jw, "event", event_name);
 	jw_object_string(jw, "sid", tr2_sid_get());
-	jw_object_string(jw, "thread", ctx->thread_name);
+	jw_object_string(jw, "thread",
+			 ((thread_name_override && *thread_name_override)
+			  ? thread_name_override
+			  : tr2tls_get_self()->thread_name));
 
 	/*
 	 * In brief mode, only emit <time> on these 2 event types.
@@ -114,7 +117,7 @@ static void fn_too_many_files_fl(const char *file, int line)
 	struct json_writer jw = JSON_WRITER_INIT;
 
 	jw_object_begin(&jw, 0);
-	event_fmt_prepare(event_name, file, line, NULL, &jw);
+	event_fmt_prepare(event_name, file, line, NULL, &jw, NULL);
 	jw_end(&jw);
 
 	tr2_dst_write_line(&tr2dst_event, &jw.json);
@@ -127,7 +130,7 @@ static void fn_version_fl(const char *file, int line)
 	struct json_writer jw = JSON_WRITER_INIT;
 
 	jw_object_begin(&jw, 0);
-	event_fmt_prepare(event_name, file, line, NULL, &jw);
+	event_fmt_prepare(event_name, file, line, NULL, &jw, NULL);
 	jw_object_string(&jw, "evt", TR2_EVENT_VERSION);
 	jw_object_string(&jw, "exe", git_version_string);
 	jw_end(&jw);
@@ -147,7 +150,7 @@ static void fn_start_fl(const char *file, int line,
 	double t_abs = (double)us_elapsed_absolute / 1000000.0;
 
 	jw_object_begin(&jw, 0);
-	event_fmt_prepare(event_name, file, line, NULL, &jw);
+	event_fmt_prepare(event_name, file, line, NULL, &jw, NULL);
 	jw_object_double(&jw, "t_abs", 6, t_abs);
 	jw_object_inline_begin_array(&jw, "argv");
 	jw_array_argv(&jw, argv);
@@ -166,7 +169,7 @@ static void fn_exit_fl(const char *file, int line, 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);
+	event_fmt_prepare(event_name, file, line, NULL, &jw, NULL);
 	jw_object_double(&jw, "t_abs", 6, t_abs);
 	jw_object_intmax(&jw, "code", code);
 	jw_end(&jw);
@@ -182,7 +185,7 @@ static void fn_signal(uint64_t us_elapsed_absolute, int signo)
 	double t_abs = (double)us_elapsed_absolute / 1000000.0;
 
 	jw_object_begin(&jw, 0);
-	event_fmt_prepare(event_name, __FILE__, __LINE__, NULL, &jw);
+	event_fmt_prepare(event_name, __FILE__, __LINE__, NULL, &jw, NULL);
 	jw_object_double(&jw, "t_abs", 6, t_abs);
 	jw_object_intmax(&jw, "signo", signo);
 	jw_end(&jw);
@@ -198,7 +201,7 @@ static void fn_atexit(uint64_t us_elapsed_absolute, int code)
 	double t_abs = (double)us_elapsed_absolute / 1000000.0;
 
 	jw_object_begin(&jw, 0);
-	event_fmt_prepare(event_name, __FILE__, __LINE__, NULL, &jw);
+	event_fmt_prepare(event_name, __FILE__, __LINE__, NULL, &jw, NULL);
 	jw_object_double(&jw, "t_abs", 6, t_abs);
 	jw_object_intmax(&jw, "code", code);
 	jw_end(&jw);
@@ -231,7 +234,7 @@ static void fn_error_va_fl(const char *file, int line, const char *fmt,
 	struct json_writer jw = JSON_WRITER_INIT;
 
 	jw_object_begin(&jw, 0);
-	event_fmt_prepare(event_name, file, line, NULL, &jw);
+	event_fmt_prepare(event_name, file, line, NULL, &jw, NULL);
 	maybe_add_string_va(&jw, "msg", fmt, ap);
 	/*
 	 * Also emit the format string as a field in case
@@ -253,7 +256,7 @@ static void fn_command_path_fl(const char *file, int line, const char *pathname)
 	struct json_writer jw = JSON_WRITER_INIT;
 
 	jw_object_begin(&jw, 0);
-	event_fmt_prepare(event_name, file, line, NULL, &jw);
+	event_fmt_prepare(event_name, file, line, NULL, &jw, NULL);
 	jw_object_string(&jw, "path", pathname);
 	jw_end(&jw);
 
@@ -268,7 +271,7 @@ static void fn_command_ancestry_fl(const char *file, int line, const char **pare
 	struct json_writer jw = JSON_WRITER_INIT;
 
 	jw_object_begin(&jw, 0);
-	event_fmt_prepare(event_name, file, line, NULL, &jw);
+	event_fmt_prepare(event_name, file, line, NULL, &jw, NULL);
 	jw_object_inline_begin_array(&jw, "ancestry");
 
 	while ((parent_name = *parent_names++))
@@ -288,7 +291,7 @@ static void fn_command_name_fl(const char *file, int line, const char *name,
 	struct json_writer jw = JSON_WRITER_INIT;
 
 	jw_object_begin(&jw, 0);
-	event_fmt_prepare(event_name, file, line, NULL, &jw);
+	event_fmt_prepare(event_name, file, line, NULL, &jw, NULL);
 	jw_object_string(&jw, "name", name);
 	if (hierarchy && *hierarchy)
 		jw_object_string(&jw, "hierarchy", hierarchy);
@@ -304,7 +307,7 @@ static void fn_command_mode_fl(const char *file, int line, const char *mode)
 	struct json_writer jw = JSON_WRITER_INIT;
 
 	jw_object_begin(&jw, 0);
-	event_fmt_prepare(event_name, file, line, NULL, &jw);
+	event_fmt_prepare(event_name, file, line, NULL, &jw, NULL);
 	jw_object_string(&jw, "name", mode);
 	jw_end(&jw);
 
@@ -319,7 +322,7 @@ static void fn_alias_fl(const char *file, int line, const char *alias,
 	struct json_writer jw = JSON_WRITER_INIT;
 
 	jw_object_begin(&jw, 0);
-	event_fmt_prepare(event_name, file, line, NULL, &jw);
+	event_fmt_prepare(event_name, file, line, NULL, &jw, NULL);
 	jw_object_string(&jw, "alias", alias);
 	jw_object_inline_begin_array(&jw, "argv");
 	jw_array_argv(&jw, argv);
@@ -338,7 +341,7 @@ static void fn_child_start_fl(const char *file, int line,
 	struct json_writer jw = JSON_WRITER_INIT;
 
 	jw_object_begin(&jw, 0);
-	event_fmt_prepare(event_name, file, line, NULL, &jw);
+	event_fmt_prepare(event_name, file, line, NULL, &jw, NULL);
 	jw_object_intmax(&jw, "child_id", cmd->trace2_child_id);
 	if (cmd->trace2_hook_name) {
 		jw_object_string(&jw, "child_class", "hook");
@@ -371,7 +374,7 @@ static void fn_child_exit_fl(const char *file, int line,
 	double t_rel = (double)us_elapsed_child / 1000000.0;
 
 	jw_object_begin(&jw, 0);
-	event_fmt_prepare(event_name, file, line, NULL, &jw);
+	event_fmt_prepare(event_name, file, line, NULL, &jw, NULL);
 	jw_object_intmax(&jw, "child_id", cid);
 	jw_object_intmax(&jw, "pid", pid);
 	jw_object_intmax(&jw, "code", code);
@@ -392,7 +395,7 @@ static void fn_child_ready_fl(const char *file, int line,
 	double t_rel = (double)us_elapsed_child / 1000000.0;
 
 	jw_object_begin(&jw, 0);
-	event_fmt_prepare(event_name, file, line, NULL, &jw);
+	event_fmt_prepare(event_name, file, line, NULL, &jw, NULL);
 	jw_object_intmax(&jw, "child_id", cid);
 	jw_object_intmax(&jw, "pid", pid);
 	jw_object_string(&jw, "ready", ready);
@@ -411,7 +414,7 @@ static void fn_thread_start_fl(const char *file, int line,
 	struct json_writer jw = JSON_WRITER_INIT;
 
 	jw_object_begin(&jw, 0);
-	event_fmt_prepare(event_name, file, line, NULL, &jw);
+	event_fmt_prepare(event_name, file, line, NULL, &jw, NULL);
 	jw_end(&jw);
 
 	tr2_dst_write_line(&tr2dst_event, &jw.json);
@@ -427,7 +430,7 @@ static void fn_thread_exit_fl(const char *file, int line,
 	double t_rel = (double)us_elapsed_thread / 1000000.0;
 
 	jw_object_begin(&jw, 0);
-	event_fmt_prepare(event_name, file, line, NULL, &jw);
+	event_fmt_prepare(event_name, file, line, NULL, &jw, NULL);
 	jw_object_double(&jw, "t_rel", 6, t_rel);
 	jw_end(&jw);
 
@@ -442,7 +445,7 @@ static void fn_exec_fl(const char *file, int line, uint64_t us_elapsed_absolute,
 	struct json_writer jw = JSON_WRITER_INIT;
 
 	jw_object_begin(&jw, 0);
-	event_fmt_prepare(event_name, file, line, NULL, &jw);
+	event_fmt_prepare(event_name, file, line, NULL, &jw, NULL);
 	jw_object_intmax(&jw, "exec_id", exec_id);
 	if (exe)
 		jw_object_string(&jw, "exe", exe);
@@ -463,7 +466,7 @@ static void fn_exec_result_fl(const char *file, int line,
 	struct json_writer jw = JSON_WRITER_INIT;
 
 	jw_object_begin(&jw, 0);
-	event_fmt_prepare(event_name, file, line, NULL, &jw);
+	event_fmt_prepare(event_name, file, line, NULL, &jw, NULL);
 	jw_object_intmax(&jw, "exec_id", exec_id);
 	jw_object_intmax(&jw, "code", code);
 	jw_end(&jw);
@@ -479,7 +482,7 @@ static void fn_param_fl(const char *file, int line, const char *param,
 	struct json_writer jw = JSON_WRITER_INIT;
 
 	jw_object_begin(&jw, 0);
-	event_fmt_prepare(event_name, file, line, NULL, &jw);
+	event_fmt_prepare(event_name, file, line, NULL, &jw, NULL);
 	jw_object_string(&jw, "param", param);
 	jw_object_string(&jw, "value", value);
 	jw_end(&jw);
@@ -495,7 +498,7 @@ static void fn_repo_fl(const char *file, int line,
 	struct json_writer jw = JSON_WRITER_INIT;
 
 	jw_object_begin(&jw, 0);
-	event_fmt_prepare(event_name, file, line, repo, &jw);
+	event_fmt_prepare(event_name, file, line, repo, &jw, NULL);
 	jw_object_string(&jw, "worktree", repo->worktree);
 	jw_end(&jw);
 
@@ -516,7 +519,7 @@ static void fn_region_enter_printf_va_fl(const char *file, int line,
 		struct json_writer jw = JSON_WRITER_INIT;
 
 		jw_object_begin(&jw, 0);
-		event_fmt_prepare(event_name, file, line, repo, &jw);
+		event_fmt_prepare(event_name, file, line, repo, &jw, NULL);
 		jw_object_intmax(&jw, "nesting", ctx->nr_open_regions);
 		if (category)
 			jw_object_string(&jw, "category", category);
@@ -542,7 +545,7 @@ static void fn_region_leave_printf_va_fl(
 		double t_rel = (double)us_elapsed_region / 1000000.0;
 
 		jw_object_begin(&jw, 0);
-		event_fmt_prepare(event_name, file, line, repo, &jw);
+		event_fmt_prepare(event_name, file, line, repo, &jw, NULL);
 		jw_object_double(&jw, "t_rel", 6, t_rel);
 		jw_object_intmax(&jw, "nesting", ctx->nr_open_regions);
 		if (category)
@@ -570,7 +573,7 @@ static void fn_data_fl(const char *file, int line, uint64_t us_elapsed_absolute,
 		double t_rel = (double)us_elapsed_region / 1000000.0;
 
 		jw_object_begin(&jw, 0);
-		event_fmt_prepare(event_name, file, line, repo, &jw);
+		event_fmt_prepare(event_name, file, line, repo, &jw, NULL);
 		jw_object_double(&jw, "t_abs", 6, t_abs);
 		jw_object_double(&jw, "t_rel", 6, t_rel);
 		jw_object_intmax(&jw, "nesting", ctx->nr_open_regions);
@@ -598,7 +601,7 @@ static void fn_data_json_fl(const char *file, int line,
 		double t_rel = (double)us_elapsed_region / 1000000.0;
 
 		jw_object_begin(&jw, 0);
-		event_fmt_prepare(event_name, file, line, repo, &jw);
+		event_fmt_prepare(event_name, file, line, repo, &jw, NULL);
 		jw_object_double(&jw, "t_abs", 6, t_abs);
 		jw_object_double(&jw, "t_rel", 6, t_rel);
 		jw_object_intmax(&jw, "nesting", ctx->nr_open_regions);

From patchwork Tue Dec 28 19:36:38 2021
Content-Type: text/plain; charset="utf-8"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
X-Patchwork-Submitter: Jeff Hostetler <jeffhost@microsoft.com>
X-Patchwork-Id: 12700562
Return-Path: <git-owner@kernel.org>
X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on
	aws-us-west-2-korg-lkml-1.web.codeaurora.org
Received: from vger.kernel.org (vger.kernel.org [23.128.96.18])
	by smtp.lore.kernel.org (Postfix) with ESMTP id 3BB9AC43219
	for <git@archiver.kernel.org>; Tue, 28 Dec 2021 19:36:58 +0000 (UTC)
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
        id S237210AbhL1Tgz (ORCPT <rfc822;git@archiver.kernel.org>);
        Tue, 28 Dec 2021 14:36:55 -0500
Received: from lindbergh.monkeyblade.net ([23.128.96.19]:39982 "EHLO
        lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
        with ESMTP id S237186AbhL1Tgs (ORCPT <rfc822;git@vger.kernel.org>);
        Tue, 28 Dec 2021 14:36:48 -0500
Received: from mail-wr1-x436.google.com (mail-wr1-x436.google.com
 [IPv6:2a00:1450:4864:20::436])
        by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 784D8C06173E
        for <git@vger.kernel.org>; Tue, 28 Dec 2021 11:36:48 -0800 (PST)
Received: by mail-wr1-x436.google.com with SMTP id i22so40104134wrb.13
        for <git@vger.kernel.org>; Tue, 28 Dec 2021 11:36:48 -0800 (PST)
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
        d=gmail.com; s=20210112;
        h=message-id:in-reply-to:references:from:date:subject:fcc
         :content-transfer-encoding:mime-version:to:cc;
        bh=LZo6Ali+pIOKbprOs1+/5JSDHn5wDx3xLyDit3UzAJ0=;
        b=k4HDnXLjmV+skYG9F/ui6i4tal0sZFXoFlKL8ligjLJ92uVuctJYBQhMw9HpeuqcAp
         uXXv/sGeF5PPBIhjpFFATkGxSfMBb8PJhFgmZZHQXy8zV8nhTBxKYNwkieTL3Wfi2F1J
         O1GJNvtzzYUW02BwLOa80QNenHH0EUiKX7tXAq5/+FzQ16tGvLeyBaNc+etuwykXQgIm
         ij7h+6gpSDXJFva5B25XQzeIB+kBasr5abnPgc7x9Y7PyTPdvXlWHavuV5HSls0JQoWn
         aUKKhLgO0It+WTVNhC6bTCPzt8x81x0qG/bEdt4PJuUeZnCmvYTIahnZeHzkgseVv7R8
         DZrA==
X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
        d=1e100.net; s=20210112;
        h=x-gm-message-state:message-id:in-reply-to:references:from:date
         :subject:fcc:content-transfer-encoding:mime-version:to:cc;
        bh=LZo6Ali+pIOKbprOs1+/5JSDHn5wDx3xLyDit3UzAJ0=;
        b=jbP6h5aj2EuiBs/JvegJf3ZKut98IbBJWADS8IrlARAEvn8WlUyir6Rk/F2G+pF8Qc
         0Vc5ekuHe9NXWgWjOqj3OWxiqyenbj0frw7sjeHnGz6tkC3HN+dQGQ17eJXi3ENJDq+y
         sUAMSkbOKtHAQyFSZHtSVKGN8RuDmpQKxGRfSoJJT2PkRmkdt6ywoRik3U7mei9Y56m8
         cUEabF5miFJCeM/7MukbLUCLtrky3coSdgyrxnHLgprw12l11lxb35O9D5vBpx6iny9z
         EQC7Zyy7WsJFkoL0tSpeBdN0Vn19LbOhjX7/ISj2/cFw2lpvrA3TGwfmz1Kqa1CfNNqd
         GCpA==
X-Gm-Message-State: AOAM531GcUu2Y0iflZ8v0udYkgyOF8iZceogqqFXM/q6U6k73nunkHmF
        YinaMNrE5cc9bFmJ77WLK01xo9d/1NM=
X-Google-Smtp-Source: 
 ABdhPJykhEXl4gh8EGEduejNvUC+2zvODaRwJq1vU3h96BqkZJfXmUUFElg1sGaYN4zM7bThOhT6bQ==
X-Received: by 2002:adf:f001:: with SMTP id j1mr17143443wro.431.1640720206810;
        Tue, 28 Dec 2021 11:36:46 -0800 (PST)
Received: from [127.0.0.1] ([13.74.141.28])
        by smtp.gmail.com with ESMTPSA id
 a22sm19388627wme.19.2021.12.28.11.36.46
        (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256);
        Tue, 28 Dec 2021 11:36:46 -0800 (PST)
Message-Id: 
 <82c445b75f1002bcfa0a770bd47038a747d98970.1640720202.git.gitgitgadget@gmail.com>
In-Reply-To: <pull.1099.v2.git.1640720202.gitgitgadget@gmail.com>
References: <pull.1099.git.1640012469.gitgitgadget@gmail.com>
        <pull.1099.v2.git.1640720202.gitgitgadget@gmail.com>
Date: Tue, 28 Dec 2021 19:36:38 +0000
Subject: [PATCH v2 5/9] trace2: add thread-name override to perf target
Fcc: Sent
MIME-Version: 1.0
To: git@vger.kernel.org
Cc: =?utf-8?b?w4Z2YXIgQXJuZmrDtnLDsA==?= Bjarmason  <avarab@gmail.com>,
 Jeff Hostetler <git@jeffhostetler.com>, Derrick Stolee <stolee@gmail.com>,
 Matheus Tavares <matheus.bernardino@usp.br>, Johannes Sixt <j6t@kdbg.org>,
 Jeff Hostetler <jeffhost@microsoft.com>,
 Jeff Hostetler <jeffhost@microsoft.com>
Precedence: bulk
List-ID: <git.vger.kernel.org>
X-Mailing-List: git@vger.kernel.org
From: Jeff Hostetler <jeffhost@microsoft.com>

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.

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 trace2/tr2_tgt_perf.c | 64 +++++++++++++++++++++++--------------------
 1 file changed, 35 insertions(+), 29 deletions(-)

diff --git a/trace2/tr2_tgt_perf.c b/trace2/tr2_tgt_perf.c
index fd6cce3efe5..c008fd08ae8 100644
--- a/trace2/tr2_tgt_perf.c
+++ b/trace2/tr2_tgt_perf.c
@@ -65,9 +65,14 @@ static void perf_fmt_prepare(const char *event_name,
 			     int line, const struct repository *repo,
 			     uint64_t *p_us_elapsed_absolute,
 			     uint64_t *p_us_elapsed_relative,
-			     const char *category, struct strbuf *buf)
+			     const char *category, struct strbuf *buf,
+			     const char *thread_name_override)
 {
 	int len;
+	const char *thread_name =
+		((thread_name_override && *thread_name_override)
+		 ? thread_name_override
+		 : ctx->thread_name);
 
 	strbuf_setlen(buf, 0);
 
@@ -107,7 +112,7 @@ static void perf_fmt_prepare(const char *event_name,
 
 	strbuf_addf(buf, "d%d | ", tr2_sid_depth());
 	strbuf_addf(buf, "%-*.*s | %-*s | ", TR2FMT_PERF_MAX_THREAD_NAME,
-		    TR2FMT_PERF_MAX_THREAD_NAME, ctx->thread_name,
+		    TR2FMT_PERF_MAX_THREAD_NAME, thread_name,
 		    TR2FMT_PERF_MAX_EVENT_NAME, event_name);
 
 	len = buf->len + TR2FMT_PERF_REPO_WIDTH;
@@ -141,14 +146,15 @@ static void perf_io_write_fl(const char *file, int line, const char *event_name,
 			     uint64_t *p_us_elapsed_absolute,
 			     uint64_t *p_us_elapsed_relative,
 			     const char *category,
-			     const struct strbuf *buf_payload)
+			     const struct strbuf *buf_payload,
+			     const char *thread_name_override)
 {
 	struct tr2tls_thread_ctx *ctx = tr2tls_get_self();
 	struct strbuf buf_line = STRBUF_INIT;
 
 	perf_fmt_prepare(event_name, ctx, file, line, repo,
 			 p_us_elapsed_absolute, p_us_elapsed_relative, category,
-			 &buf_line);
+			 &buf_line, thread_name_override);
 	strbuf_addbuf(&buf_line, buf_payload);
 	tr2_dst_write_line(&tr2dst_perf, &buf_line);
 	strbuf_release(&buf_line);
@@ -162,7 +168,7 @@ static void fn_version_fl(const char *file, int line)
 	strbuf_addstr(&buf_payload, git_version_string);
 
 	perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
-			 &buf_payload);
+			 &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -175,7 +181,7 @@ static void fn_start_fl(const char *file, int line,
 	sq_append_quote_argv_pretty(&buf_payload, argv);
 
 	perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
-			 NULL, NULL, &buf_payload);
+			 NULL, NULL, &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -188,7 +194,7 @@ static void fn_exit_fl(const char *file, int line, uint64_t us_elapsed_absolute,
 	strbuf_addf(&buf_payload, "code:%d", code);
 
 	perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
-			 NULL, NULL, &buf_payload);
+			 NULL, NULL, &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -200,7 +206,7 @@ static void fn_signal(uint64_t us_elapsed_absolute, int signo)
 	strbuf_addf(&buf_payload, "signo:%d", signo);
 
 	perf_io_write_fl(__FILE__, __LINE__, event_name, NULL,
-			 &us_elapsed_absolute, NULL, NULL, &buf_payload);
+			 &us_elapsed_absolute, NULL, NULL, &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -212,7 +218,7 @@ static void fn_atexit(uint64_t us_elapsed_absolute, int code)
 	strbuf_addf(&buf_payload, "code:%d", code);
 
 	perf_io_write_fl(__FILE__, __LINE__, event_name, NULL,
-			 &us_elapsed_absolute, NULL, NULL, &buf_payload);
+			 &us_elapsed_absolute, NULL, NULL, &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -238,7 +244,7 @@ static void fn_error_va_fl(const char *file, int line, const char *fmt,
 	maybe_append_string_va(&buf_payload, fmt, ap);
 
 	perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
-			 &buf_payload);
+			 &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -250,7 +256,7 @@ static void fn_command_path_fl(const char *file, int line, const char *pathname)
 	strbuf_addstr(&buf_payload, pathname);
 
 	perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
-			 &buf_payload);
+			 &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -265,7 +271,7 @@ static void fn_command_ancestry_fl(const char *file, int line, const char **pare
 	strbuf_addch(&buf_payload, ']');
 
 	perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
-			 &buf_payload);
+			 &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -280,7 +286,7 @@ static void fn_command_name_fl(const char *file, int line, const char *name,
 		strbuf_addf(&buf_payload, " (%s)", hierarchy);
 
 	perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
-			 &buf_payload);
+			 &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -292,7 +298,7 @@ static void fn_command_mode_fl(const char *file, int line, const char *mode)
 	strbuf_addstr(&buf_payload, mode);
 
 	perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
-			 &buf_payload);
+			 &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -307,7 +313,7 @@ static void fn_alias_fl(const char *file, int line, const char *alias,
 	strbuf_addch(&buf_payload, ']');
 
 	perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
-			 &buf_payload);
+			 &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -343,7 +349,7 @@ static void fn_child_start_fl(const char *file, int line,
 	strbuf_addch(&buf_payload, ']');
 
 	perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
-			 NULL, NULL, &buf_payload);
+			 NULL, NULL, &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -357,7 +363,7 @@ static void fn_child_exit_fl(const char *file, int line,
 	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);
+			 &us_elapsed_child, NULL, &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -371,7 +377,7 @@ static void fn_child_ready_fl(const char *file, int line,
 	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);
+			 &us_elapsed_child, NULL, &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -382,7 +388,7 @@ static void fn_thread_start_fl(const char *file, int line,
 	struct strbuf buf_payload = STRBUF_INIT;
 
 	perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
-			 NULL, NULL, &buf_payload);
+			 NULL, NULL, &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -394,7 +400,7 @@ static void fn_thread_exit_fl(const char *file, int line,
 	struct strbuf buf_payload = STRBUF_INIT;
 
 	perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
-			 &us_elapsed_thread, NULL, &buf_payload);
+			 &us_elapsed_thread, NULL, &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -415,7 +421,7 @@ static void fn_exec_fl(const char *file, int line, uint64_t us_elapsed_absolute,
 	strbuf_addch(&buf_payload, ']');
 
 	perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
-			 NULL, NULL, &buf_payload);
+			 NULL, NULL, &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -431,7 +437,7 @@ static void fn_exec_result_fl(const char *file, int line,
 		strbuf_addf(&buf_payload, " err:%s", strerror(code));
 
 	perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
-			 NULL, NULL, &buf_payload);
+			 NULL, NULL, &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -444,7 +450,7 @@ static void fn_param_fl(const char *file, int line, const char *param,
 	strbuf_addf(&buf_payload, "%s:%s", param, value);
 
 	perf_io_write_fl(file, line, event_name, NULL, NULL, NULL, NULL,
-			 &buf_payload);
+			 &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -458,7 +464,7 @@ static void fn_repo_fl(const char *file, int line,
 	sq_quote_buf_pretty(&buf_payload, repo->worktree);
 
 	perf_io_write_fl(file, line, event_name, repo, NULL, NULL, NULL,
-			 &buf_payload);
+			 &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -480,7 +486,7 @@ static void fn_region_enter_printf_va_fl(const char *file, int line,
 	}
 
 	perf_io_write_fl(file, line, event_name, repo, &us_elapsed_absolute,
-			 NULL, category, &buf_payload);
+			 NULL, category, &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -500,7 +506,7 @@ static void fn_region_leave_printf_va_fl(
 	}
 
 	perf_io_write_fl(file, line, event_name, repo, &us_elapsed_absolute,
-			 &us_elapsed_region, category, &buf_payload);
+			 &us_elapsed_region, category, &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -515,7 +521,7 @@ static void fn_data_fl(const char *file, int line, uint64_t us_elapsed_absolute,
 	strbuf_addf(&buf_payload, "%s:%s", key, value);
 
 	perf_io_write_fl(file, line, event_name, repo, &us_elapsed_absolute,
-			 &us_elapsed_region, category, &buf_payload);
+			 &us_elapsed_region, category, &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -531,7 +537,7 @@ static void fn_data_json_fl(const char *file, int line,
 	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);
+			 &us_elapsed_region, category, &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 
@@ -545,7 +551,7 @@ static void fn_printf_va_fl(const char *file, int line,
 	maybe_append_string_va(&buf_payload, fmt, ap);
 
 	perf_io_write_fl(file, line, event_name, NULL, &us_elapsed_absolute,
-			 NULL, NULL, &buf_payload);
+			 NULL, NULL, &buf_payload, NULL);
 	strbuf_release(&buf_payload);
 }
 

From patchwork Tue Dec 28 19:36:39 2021
Content-Type: text/plain; charset="utf-8"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
X-Patchwork-Submitter: Jeff Hostetler <jeffhost@microsoft.com>
X-Patchwork-Id: 12700563
Return-Path: <git-owner@kernel.org>
X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on
	aws-us-west-2-korg-lkml-1.web.codeaurora.org
Received: from vger.kernel.org (vger.kernel.org [23.128.96.18])
	by smtp.lore.kernel.org (Postfix) with ESMTP id 71B5CC433F5
	for <git@archiver.kernel.org>; Tue, 28 Dec 2021 19:36:59 +0000 (UTC)
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
        id S237198AbhL1Tg5 (ORCPT <rfc822;git@archiver.kernel.org>);
        Tue, 28 Dec 2021 14:36:57 -0500
Received: from lindbergh.monkeyblade.net ([23.128.96.19]:39990 "EHLO
        lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
        with ESMTP id S237176AbhL1Tgt (ORCPT <rfc822;git@vger.kernel.org>);
        Tue, 28 Dec 2021 14:36:49 -0500
Received: from mail-wr1-x436.google.com (mail-wr1-x436.google.com
 [IPv6:2a00:1450:4864:20::436])
        by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 34682C06173F
        for <git@vger.kernel.org>; Tue, 28 Dec 2021 11:36:49 -0800 (PST)
Received: by mail-wr1-x436.google.com with SMTP id a9so40081291wrr.8
        for <git@vger.kernel.org>; Tue, 28 Dec 2021 11:36:49 -0800 (PST)
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
        d=gmail.com; s=20210112;
        h=message-id:in-reply-to:references:from:date:subject:fcc
         :content-transfer-encoding:mime-version:to:cc;
        bh=MzyQ7sKYS6t8DnWeU9JqW61Cri7RU8Dnj0m1yVwcC+M=;
        b=QLmG9tJ+plBFn/je+WSo1A6JtYy25X4fkFIk7Cxw6N0EGHPMYpeB81/S3KdgN2LWn8
         OcMIbIxWzLkn3Qq16pKpE9aWZLT4E+IGxxRrDitBku1zypL6tt2VVFVK1rxrOoGiq83j
         PZZ6+Fv7HM/8pgIYPlE6rErRZayzMtG8b1q2BDtV0ZQvbdzspfcTeiY4B8ZMVWSJDXGn
         vq0S28XGBXtjm9y9xaigbJa0OESS8eOjCXRFMtuTAE376jtN5L5XrnUMuE2mRuwNV7Dm
         qCB6Mk4ybgPwsEhhQ32R5giKCEGplWDiUsQ8DPj+ETpEGT/gBUdX9aAOmNHusi+tQjuY
         BbXQ==
X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
        d=1e100.net; s=20210112;
        h=x-gm-message-state:message-id:in-reply-to:references:from:date
         :subject:fcc:content-transfer-encoding:mime-version:to:cc;
        bh=MzyQ7sKYS6t8DnWeU9JqW61Cri7RU8Dnj0m1yVwcC+M=;
        b=73rFF5YimLeEP9gci/Z5zJGz9GGzPxXn8yHHt08F4JKbGR87zif84Ynr0pJVI16dul
         SU6RymP6EDyrqcYB5y2xqHIYbhA86Rhp55bMkbIQ2s/bU8vCX1sCKMkGdX/u6ujHuyBu
         eq7ExtRrgFuMjF6v1z+Fq71ZT3wxNApKG7XOqkERtcxVXHkcSI6KU/Szx5mUqj1QCD2B
         O5mSFI2yask3/yvaQ9B72Y1KAHEX/ERtKbO2pWaOvEmEWa10nYlm9dmuka/DtpuYiS9V
         HieRFLI3NIeQa/BwFBERn0i78FaDL+mdoSti96LEX5qBOm+mD+hrMt77SreT8xOzZvn8
         5GDw==
X-Gm-Message-State: AOAM533ObrTdZ4ABlFXE5apBBaBI8n3c2VxT3X7fyN4BCpweHrMz/BxW
        XdQk6IejlAY+Iu9vPYFciEcOPNB3WLA=
X-Google-Smtp-Source: 
 ABdhPJwaY1HCFe6138AMTlW0kg1UDiutRLM7N2hZqqBsyo7sYHQfJtMehgvac6rqbffmG//eYKCHwQ==
X-Received: by 2002:a5d:548a:: with SMTP id
 h10mr17740920wrv.221.1640720207581;
        Tue, 28 Dec 2021 11:36:47 -0800 (PST)
Received: from [127.0.0.1] ([13.74.141.28])
        by smtp.gmail.com with ESMTPSA id
 u11sm10808140wmq.41.2021.12.28.11.36.47
        (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256);
        Tue, 28 Dec 2021 11:36:47 -0800 (PST)
Message-Id: 
 <62a5c8b035671e8b5df6121660e657ba216d90fc.1640720202.git.gitgitgadget@gmail.com>
In-Reply-To: <pull.1099.v2.git.1640720202.gitgitgadget@gmail.com>
References: <pull.1099.git.1640012469.gitgitgadget@gmail.com>
        <pull.1099.v2.git.1640720202.gitgitgadget@gmail.com>
Date: Tue, 28 Dec 2021 19:36:39 +0000
Subject: [PATCH v2 6/9] trace2: add timer events to perf and event target
 formats
Fcc: Sent
MIME-Version: 1.0
To: git@vger.kernel.org
Cc: =?utf-8?b?w4Z2YXIgQXJuZmrDtnLDsA==?= Bjarmason  <avarab@gmail.com>,
 Jeff Hostetler <git@jeffhostetler.com>, Derrick Stolee <stolee@gmail.com>,
 Matheus Tavares <matheus.bernardino@usp.br>, Johannes Sixt <j6t@kdbg.org>,
 Jeff Hostetler <jeffhost@microsoft.com>,
 Jeff Hostetler <jeffhost@microsoft.com>
Precedence: bulk
List-ID: <git.vger.kernel.org>
X-Mailing-List: git@vger.kernel.org
From: Jeff Hostetler <jeffhost@microsoft.com>

From: Jeff Hostetler <jeffhost@microsoft.com>

Teach Trace2 "perf" and "event" formats to handle "timer" events for
stopwatch timers.  Update API documentation accordingly.

In a future commit, stopwatch timers will be added to the Trace2 API
and it will emit these "timer" events.

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 Documentation/technical/api-trace2.txt | 23 ++++++++++++++++++++
 trace2/tr2_tgt.h                       | 25 ++++++++++++++++++++++
 trace2/tr2_tgt_event.c                 | 29 ++++++++++++++++++++++++++
 trace2/tr2_tgt_normal.c                |  1 +
 trace2/tr2_tgt_perf.c                  | 27 ++++++++++++++++++++++++
 5 files changed, 105 insertions(+)

diff --git a/Documentation/technical/api-trace2.txt b/Documentation/technical/api-trace2.txt
index bb13ca3db8b..351d140879e 100644
--- a/Documentation/technical/api-trace2.txt
+++ b/Documentation/technical/api-trace2.txt
@@ -815,6 +815,29 @@ The "value" field may be an integer or a string.
 }
 ------------
 
+`"timer"`::
+	This event is generated at the end of the program and contains
+	statistics for a global stopwatch timer.
++
+------------
+{
+	"event":"timer",
+	...
+	"name":"test",      # timer name
+	"count":42,         # number of start+stop intervals
+	"ns_total":1234,    # sum of all intervals in nanoseconds
+	"ns_min":11,        # shortest interval in nanoseconds
+	"ns_max":789,       # longest interval in nanoseconds
+}
+------------
++
+Stopwatch timer data is independently collected by each thread and then
+aggregated for the whole program, so the total time reported here
+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.
+
 == 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 65f94e15748..a41f91d09b5 100644
--- a/trace2/tr2_tgt.h
+++ b/trace2/tr2_tgt.h
@@ -96,6 +96,30 @@ 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);
 
+/*
+ * Stopwatch timer event.  This function writes the previously accumulated
+ * stopwatch timer values to the event streams.  Unlike other Trace2 API
+ * events, this is decoupled from the data collection.
+ *
+ * This does not take a (file,line) pair because a timer event reports
+ * the cumulative time spend in the timer over a series of intervals
+ * -- it does not represent a single usage (like region or data events
+ * do).
+ *
+ * The thread name is optional.  If non-null it will override the
+ * value inherited from the caller's thread local storage.  This
+ * allows timer data to be aggregated and reported without associating
+ * it to a specific thread.
+ */
+typedef void(tr2_tgt_evt_timer_t)(uint64_t us_elapsed_absolute,
+				  const char *thread_name,
+				  const char *category,
+				  const char *timer_name,
+				  uint64_t interval_count,
+				  uint64_t ns_total_time,
+				  uint64_t ns_min_time,
+				  uint64_t ns_max_time);
+
 /*
  * "vtable" for a TRACE2 target.  Use NULL if a target does not want
  * to emit that message.
@@ -132,6 +156,7 @@ 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;
 };
 /* clang-format on */
 
diff --git a/trace2/tr2_tgt_event.c b/trace2/tr2_tgt_event.c
index 4ce50944298..fe89e80bb1a 100644
--- a/trace2/tr2_tgt_event.c
+++ b/trace2/tr2_tgt_event.c
@@ -615,6 +615,34 @@ static void fn_data_json_fl(const char *file, int line,
 	}
 }
 
+static void fn_timer(uint64_t us_elapsed_absolute,
+		     const char *thread_name,
+		     const char *category,
+		     const char *timer_name,
+		     uint64_t interval_count,
+		     uint64_t ns_total_time,
+		     uint64_t ns_min_time,
+		     uint64_t ns_max_time)
+{
+	const char *event_name = "timer";
+	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", timer_name);
+	jw_object_intmax(&jw, "count", interval_count);
+	jw_object_intmax(&jw, "ns_total", ns_total_time);
+	jw_object_intmax(&jw, "ns_min", ns_min_time);
+	jw_object_intmax(&jw, "ns_max", ns_max_time);
+
+	jw_end(&jw);
+
+	tr2_dst_write_line(&tr2dst_event, &jw.json);
+	jw_release(&jw);
+}
+
 struct tr2_tgt tr2_tgt_event = {
 	&tr2dst_event,
 
@@ -646,4 +674,5 @@ struct tr2_tgt tr2_tgt_event = {
 	fn_data_fl,
 	fn_data_json_fl,
 	NULL, /* printf */
+	fn_timer,
 };
diff --git a/trace2/tr2_tgt_normal.c b/trace2/tr2_tgt_normal.c
index 58d9e430f05..23a7e78dcaa 100644
--- a/trace2/tr2_tgt_normal.c
+++ b/trace2/tr2_tgt_normal.c
@@ -355,4 +355,5 @@ struct tr2_tgt tr2_tgt_normal = {
 	NULL, /* data */
 	NULL, /* data_json */
 	fn_printf_va_fl,
+	NULL, /* timer */
 };
diff --git a/trace2/tr2_tgt_perf.c b/trace2/tr2_tgt_perf.c
index c008fd08ae8..c07ffad1a32 100644
--- a/trace2/tr2_tgt_perf.c
+++ b/trace2/tr2_tgt_perf.c
@@ -555,6 +555,32 @@ static void fn_printf_va_fl(const char *file, int line,
 	strbuf_release(&buf_payload);
 }
 
+static void fn_timer(uint64_t us_elapsed_absolute,
+		     const char *thread_name,
+		     const char *category,
+		     const char *timer_name,
+		     uint64_t interval_count,
+		     uint64_t ns_total_time,
+		     uint64_t ns_min_time,
+		     uint64_t ns_max_time)
+{
+	const char *event_name = "timer";
+	struct strbuf buf_payload = STRBUF_INIT;
+
+	strbuf_addf(&buf_payload, ("name:%s"
+				   " count:%"PRIu64
+				   " ns_total:%"PRIu64
+				   " ns_min:%"PRIu64
+				   " ns_max:%"PRIu64),
+		    timer_name, interval_count, ns_total_time, ns_min_time,
+		    ns_max_time);
+
+	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,
 
@@ -586,4 +612,5 @@ struct tr2_tgt tr2_tgt_perf = {
 	fn_data_fl,
 	fn_data_json_fl,
 	fn_printf_va_fl,
+	fn_timer,
 };

From patchwork Tue Dec 28 19:36:40 2021
Content-Type: text/plain; charset="utf-8"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
X-Patchwork-Submitter: Jeff Hostetler <jeffhost@microsoft.com>
X-Patchwork-Id: 12700561
Return-Path: <git-owner@kernel.org>
X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on
	aws-us-west-2-korg-lkml-1.web.codeaurora.org
Received: from vger.kernel.org (vger.kernel.org [23.128.96.18])
	by smtp.lore.kernel.org (Postfix) with ESMTP id BDD29C43217
	for <git@archiver.kernel.org>; Tue, 28 Dec 2021 19:36:56 +0000 (UTC)
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
        id S237199AbhL1Tgy (ORCPT <rfc822;git@archiver.kernel.org>);
        Tue, 28 Dec 2021 14:36:54 -0500
Received: from lindbergh.monkeyblade.net ([23.128.96.19]:39992 "EHLO
        lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
        with ESMTP id S237188AbhL1Tgu (ORCPT <rfc822;git@vger.kernel.org>);
        Tue, 28 Dec 2021 14:36:50 -0500
Received: from mail-wm1-x330.google.com (mail-wm1-x330.google.com
 [IPv6:2a00:1450:4864:20::330])
        by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 462D6C061401
        for <git@vger.kernel.org>; Tue, 28 Dec 2021 11:36:50 -0800 (PST)
Received: by mail-wm1-x330.google.com with SMTP id
 k66-20020a1ca145000000b00345fa984108so4910499wme.2
        for <git@vger.kernel.org>; Tue, 28 Dec 2021 11:36:50 -0800 (PST)
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
        d=gmail.com; s=20210112;
        h=message-id:in-reply-to:references:from:date:subject:fcc
         :content-transfer-encoding:mime-version:to:cc;
        bh=za68XYXAFUj6noC+YZubY4Y/ExNV01Jz4Plsu1PLgcI=;
        b=bOn+yIMWdrDEc5eBC/OEaJ4oWGJ+w2m//idHfpd8AiEzDdzOP+aJNfuW9feXq4CVxK
         fEYP9wvCEYb+Jw+126pet3F4+Md9ofwDMx9FODZOTgJnKNNvmTrfi+xPFSIlzrrFLXNV
         yThJpxZ68b+OiOIUYtclIPdy8PVfDf03IWGho3FPgsByj07095nXUTprW1IAy7fJKKsI
         fzEvJOS2WdRSi5hUoAJyWF+RSdwn68wtf33oXpNSc5VfElgrZ9gPc6piU/IBt5YylLBf
         UNc4OuWWDlDmUErxahdxUi+dONnKmO5LeE1KrBNI7/2TzMyBOt+sLOpxixPUuERyjWwZ
         Nevg==
X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
        d=1e100.net; s=20210112;
        h=x-gm-message-state:message-id:in-reply-to:references:from:date
         :subject:fcc:content-transfer-encoding:mime-version:to:cc;
        bh=za68XYXAFUj6noC+YZubY4Y/ExNV01Jz4Plsu1PLgcI=;
        b=Vs5irX6BWkp9njL9XZnsLARP7FqURVt9oeAuFPKHb2sebDHvrAUmpEDOjJzDe/V351
         OTRk2huBYvSIlNplZoMuTjAhNTQE2i8ry0swWdLpM04YLhVCwpXtbb2yFx92Z8LjkLia
         a39y5Au8Oe3SsYxzBtRwma3Q5BcWVUKcRXBW0BURoE6M9ApuTFDwMvmrB+w3+in12NeX
         SAAXXFMFDk5cc/pWR98PA99xtU9HCNmbyeIisL76siiXEeN1CxrAo7LWTCVEj3PUkWZb
         6XbBespiMHFYMihNXwOR+R34B8uRjPzWoKYNBrqbCWo/UmpqbrXmBSosI5N9yBrZiEFW
         3NBg==
X-Gm-Message-State: AOAM533gn2yEyn640Rxk9kyL6+32Jb0JLf7v3d3E4FrS56plsXOyia40
        ec4WLBL/IHqS9SJGLgGVUiKmgJSdqgQ=
X-Google-Smtp-Source: 
 ABdhPJwSgceNdqQ3BwOgQU8udY64C+lw1j1qdDRZ3RVKF01jzBZEucz3cOXnIGD+GJBnuUbu73MbLw==
X-Received: by 2002:a1c:f418:: with SMTP id z24mr18905005wma.95.1640720208310;
        Tue, 28 Dec 2021 11:36:48 -0800 (PST)
Received: from [127.0.0.1] ([13.74.141.28])
        by smtp.gmail.com with ESMTPSA id
 w17sm20256021wmc.14.2021.12.28.11.36.47
        (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256);
        Tue, 28 Dec 2021 11:36:48 -0800 (PST)
Message-Id: 
 <36e57a22d70ce04240cbe7de143b73928203bcb2.1640720202.git.gitgitgadget@gmail.com>
In-Reply-To: <pull.1099.v2.git.1640720202.gitgitgadget@gmail.com>
References: <pull.1099.git.1640012469.gitgitgadget@gmail.com>
        <pull.1099.v2.git.1640720202.gitgitgadget@gmail.com>
Date: Tue, 28 Dec 2021 19:36:40 +0000
Subject: [PATCH v2 7/9] trace2: add stopwatch timers
Fcc: Sent
MIME-Version: 1.0
To: git@vger.kernel.org
Cc: =?utf-8?b?w4Z2YXIgQXJuZmrDtnLDsA==?= Bjarmason  <avarab@gmail.com>,
 Jeff Hostetler <git@jeffhostetler.com>, Derrick Stolee <stolee@gmail.com>,
 Matheus Tavares <matheus.bernardino@usp.br>, Johannes Sixt <j6t@kdbg.org>,
 Jeff Hostetler <jeffhost@microsoft.com>,
 Jeff Hostetler <jeffhost@microsoft.com>
Precedence: bulk
List-ID: <git.vger.kernel.org>
X-Mailing-List: git@vger.kernel.org
From: Jeff Hostetler <jeffhost@microsoft.com>

From: Jeff Hostetler <jeffhost@microsoft.com>

Add a stopwatch timer mechanism to Git.

Timers are an alternative to regions.  Timers can capture a series of
intervals, such as calls to a library routine or a span of code.  They
are intended for code that is not necessarily associated with a
particular phase of the command.

Timer data is accumulated throughout the command and a timer "summary"
event is logged (one per timer) at program exit.

Optionally, timer data may also be reported by thread for certain
timers.  (See trace2/tr2_tmr.c:tr2_timer_def_block[].)

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 Documentation/technical/api-trace2.txt |  48 +++++++++
 Makefile                               |   1 +
 t/helper/test-trace2.c                 |  97 +++++++++++++++++
 t/t0211-trace2-perf.sh                 |  46 ++++++++
 t/t0212-trace2-event.sh                |  45 ++++++++
 trace2.c                               |  56 ++++++++++
 trace2.h                               |  42 ++++++++
 trace2/tr2_tls.c                       |  29 ++++++
 trace2/tr2_tls.h                       |  18 ++++
 trace2/tr2_tmr.c                       | 136 ++++++++++++++++++++++++
 trace2/tr2_tmr.h                       | 139 +++++++++++++++++++++++++
 11 files changed, 657 insertions(+)
 create mode 100644 trace2/tr2_tmr.c
 create mode 100644 trace2/tr2_tmr.h

diff --git a/Documentation/technical/api-trace2.txt b/Documentation/technical/api-trace2.txt
index 351d140879e..616001bcbb0 100644
--- a/Documentation/technical/api-trace2.txt
+++ b/Documentation/technical/api-trace2.txt
@@ -1230,6 +1230,54 @@ at offset 508.
 This example also shows that thread names are assigned in a racy manner
 as each thread starts and allocates TLS storage.
 
+Timer Events::
+
+	Trace2 also provides global stopwatch timers as an alternative
+	to regions.  These make it possible to measure the time spent
+	in a span of code or a library routine called from many places
+	and not	associated with a single phase of the overall command.
++
+At the end of the program, a single summary timer event is emitted; this
+aggregates timer usage across all threads.  These events have "summary"
+as their thread name.
++
+For some timers, individual (per-thread) timer events are also generated.
+These may be helpful in understanding how work is balanced between threads
+in some circumstances.
++
+Timers are defined in `enum trace2_timer_id` in trace2.h and in
+`trace2/tr2_tmr.c:tr2_timer_def_block[]`.
++
+----------------
+static void *unpack_compressed_entry(struct packed_git *p,
+				    struct pack_window **w_curs,
+				    off_t curpos,
+				    unsigned long size)
+{
+	...
+	trace2_timer_start(TRACE2_TIMER_ID__TEST1);
+	git_inflate_init(&stream);
+	...
+	git_inflate_end(&stream);
+	trace2_timer_stop(TRACE2_TIMER_ID__TEST1);
+	...
+}
+----------------
++
+----------------
+$ export GIT_TRACE2_PERF_BRIEF=1
+$ export GIT_TRACE2_PERF=~/log.perf
+$ git status
+...
+$ cat ~/log.perf
+...
+d0 | summary                  | timer        |     |  0.111026 |           | test         | name:test1 count:4 ns_total:393000 ns_min:6000 ns_max:302000
+d0 | main                     | atexit       |     |  0.111026 |           |              | code:0
+----------------
++
+In this example, the "test1" timer was started 4 times and ran for
+0.000393 seconds.
+
 == Future Work
 
 === Relationship to the Existing Trace Api (api-trace.txt)
diff --git a/Makefile b/Makefile
index ed75ed422b5..8b657f0162a 100644
--- a/Makefile
+++ b/Makefile
@@ -1022,6 +1022,7 @@ LIB_OBJS += trace2/tr2_cfg.o
 LIB_OBJS += trace2/tr2_cmd_name.o
 LIB_OBJS += trace2/tr2_dst.o
 LIB_OBJS += trace2/tr2_sid.o
+LIB_OBJS += trace2/tr2_tmr.o
 LIB_OBJS += trace2/tr2_sysenv.o
 LIB_OBJS += trace2/tr2_tbuf.o
 LIB_OBJS += trace2/tr2_tgt_event.o
diff --git a/t/helper/test-trace2.c b/t/helper/test-trace2.c
index f93633f895a..51d022422bf 100644
--- a/t/helper/test-trace2.c
+++ b/t/helper/test-trace2.c
@@ -206,6 +206,101 @@ static int ut_007bug(int argc, const char **argv)
 	BUG("the bug message");
 }
 
+/*
+ * Single-threaded timer test.  Create several intervals using the
+ * TEST1 timer.  The test script can verify that an aggregate Trace2
+ * "timer" event is emitted indicating that we started+stopped the
+ * timer the requested number of times.
+ */
+static int ut_008timer(int argc, const char **argv)
+{
+	const char *usage_error =
+		"expect <count> <ms_delay>";
+
+	int count = 0;
+	int delay = 0;
+	int k;
+
+	if (argc != 2)
+		die("%s", usage_error);
+	if (get_i(&count, argv[0]))
+		die("%s", usage_error);
+	if (get_i(&delay, argv[1]))
+		die("%s", usage_error);
+
+	for (k = 0; k < count; k++) {
+		trace2_timer_start(TRACE2_TIMER_ID_TEST1);
+		sleep_millisec(delay);
+		trace2_timer_stop(TRACE2_TIMER_ID_TEST1);
+	}
+
+	return 0;
+}
+
+struct ut_009_data {
+	int count;
+	int delay;
+};
+
+static void *ut_009timer_thread_proc(void *_ut_009_data)
+{
+	struct ut_009_data *data = _ut_009_data;
+	int k;
+
+	trace2_thread_start("ut_009");
+
+	for (k = 0; k < data->count; k++) {
+		trace2_timer_start(TRACE2_TIMER_ID_TEST2);
+		sleep_millisec(data->delay);
+		trace2_timer_stop(TRACE2_TIMER_ID_TEST2);
+	}
+
+	trace2_thread_exit();
+	return NULL;
+}
+
+/*
+ * Multi-threaded timer test.  Create several threads that each create
+ * several intervals using the TEST2 timer.  The test script can verify
+ * that an individual Trace2 "timer" event for each thread and an
+ * aggregate "timer" event are generated.
+ */
+static int ut_009timer(int argc, const char **argv)
+{
+	const char *usage_error =
+		"expect <count> <ms_delay> <threads>";
+
+	struct ut_009_data data = { 0, 0 };
+	int nr_threads = 0;
+	int k;
+	pthread_t *pids = NULL;
+
+	if (argc != 3)
+		die("%s", usage_error);
+	if (get_i(&data.count, argv[0]))
+		die("%s", usage_error);
+	if (get_i(&data.delay, argv[1]))
+		die("%s", usage_error);
+	if (get_i(&nr_threads, argv[2]))
+		die("%s", usage_error);
+
+	CALLOC_ARRAY(pids, nr_threads);
+
+	for (k = 0; k < nr_threads; k++) {
+		if (pthread_create(&pids[k], NULL, ut_009timer_thread_proc, &data))
+			die("failed to create thread[%d]", k);
+	}
+
+	for (k = 0; k < nr_threads; k++) {
+		if (pthread_join(pids[k], NULL))
+			die("failed to join thread[%d]", k);
+	}
+
+	free(pids);
+
+	return 0;
+}
+
 /*
  * Usage:
  *     test-tool trace2 <ut_name_1> <ut_usage_1>
@@ -223,6 +318,8 @@ static struct unit_test ut_table[] = {
 	{ ut_005exec,     "005exec",   "<git_command_args>" },
 	{ ut_006data,     "006data",   "[<category> <key> <value>]+" },
 	{ ut_007bug,      "007bug",    "" },
+	{ ut_008timer,    "008timer",  "<count> <ms_delay>" },
+	{ ut_009timer,    "009timer",  "<count> <ms_delay> <threads>" },
 };
 /* clang-format on */
 
diff --git a/t/t0211-trace2-perf.sh b/t/t0211-trace2-perf.sh
index 22d0845544e..381c3eea458 100755
--- a/t/t0211-trace2-perf.sh
+++ b/t/t0211-trace2-perf.sh
@@ -173,4 +173,50 @@ test_expect_success 'using global config, perf stream, return code 0' '
 	test_cmp expect actual
 '
 
+# Exercise the stopwatch timer "test" in a loop and confirm that it was
+# we have as many start/stop intervals as expected.  We cannot really test
+# the actual (total, min, max) timer values, so we assume they are good,
+# but we can test the keys for them.
+
+have_timer_event () {
+	thread=$1
+	name=$2
+	count=$3
+	file=$4
+
+	pattern="d0|${thread}|timer||_T_ABS_||test"
+	pattern="${pattern}|name:${name}"
+	pattern="${pattern} count:${count}"
+	pattern="${pattern} ns_total:.*"
+	pattern="${pattern} ns_min:.*"
+	pattern="${pattern} ns_max:.*"
+
+	grep "${pattern}" ${file}
+
+	return $?
+}
+
+test_expect_success 'test stopwatch timers - summary only' '
+	test_when_finished "rm trace.perf actual" &&
+	test_config_global trace2.perfBrief 1 &&
+	test_config_global trace2.perfTarget "$(pwd)/trace.perf" &&
+	test-tool trace2 008timer 5 10 &&
+	perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual &&
+
+	have_timer_event "summary" "test1" 5 actual
+'
+
+test_expect_success 'test stopwatch timers - summary and threads' '
+	test_when_finished "rm trace.perf actual" &&
+	test_config_global trace2.perfBrief 1 &&
+	test_config_global trace2.perfTarget "$(pwd)/trace.perf" &&
+	test-tool trace2 009timer 5 10 3 &&
+	perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual &&
+
+	have_timer_event "th01:ut_009" "test2" 5 actual &&
+	have_timer_event "th02:ut_009" "test2" 5 actual &&
+	have_timer_event "th03:ut_009" "test2" 5 actual &&
+	have_timer_event "summary" "test2" 15 actual
+'
+
 test_done
diff --git a/t/t0212-trace2-event.sh b/t/t0212-trace2-event.sh
index 6d3374ff773..277688fdbc4 100755
--- a/t/t0212-trace2-event.sh
+++ b/t/t0212-trace2-event.sh
@@ -323,4 +323,49 @@ test_expect_success 'discard traces when there are too many files' '
 	head -n2 trace_target_dir/git-trace2-discard | tail -n1 | grep \"event\":\"too_many_files\"
 '
 
+# Exercise the stopwatch timer "test" in a loop and confirm that it was
+# we have as many start/stop intervals as expected.  We cannot really test
+# the (t_timer, t_min, t_max) timer values, so we assume they are good.
+#
+
+have_timer_event () {
+	thread=$1
+	name=$2
+	count=$3
+	file=$4
+
+	pattern="\"event\":\"timer\""
+	pattern="${pattern}.*\"thread\":\"${thread}\""
+	pattern="${pattern}.*\"name\":\"${name}\""
+	pattern="${pattern}.*\"count\":${count}"
+	pattern="${pattern}.*\"ns_total\":[0-9]*"
+	pattern="${pattern}.*\"ns_min\":[0-9]*"
+	pattern="${pattern}.*\"ns_max\":[0-9]*"
+
+	grep "${pattern}" ${file}
+
+	return $?
+}
+
+test_expect_success 'test stopwatch timers - global, single-thread' '
+	test_when_finished "rm trace.event" &&
+	test_config_global trace2.eventBrief 1 &&
+	test_config_global trace2.eventTarget "$(pwd)/trace.event" &&
+	test-tool trace2 008timer 5 10 &&
+
+	have_timer_event "summary" "test1" 5 trace.event
+'
+
+test_expect_success 'test stopwatch timers - global+threads' '
+	test_when_finished "rm trace.event" &&
+	test_config_global trace2.eventBrief 1 &&
+	test_config_global trace2.eventTarget "$(pwd)/trace.event" &&
+	test-tool trace2 009timer 5 10 3 &&
+
+	have_timer_event "th01:ut_009" "test2" 5 trace.event &&
+	have_timer_event "th02:ut_009" "test2" 5 trace.event &&
+	have_timer_event "th03:ut_009" "test2" 5 trace.event &&
+	have_timer_event "summary" "test2" 15 trace.event
+'
+
 test_done
diff --git a/trace2.c b/trace2.c
index b2d471526fd..23289dd6eb4 100644
--- a/trace2.c
+++ b/trace2.c
@@ -13,6 +13,7 @@
 #include "trace2/tr2_sysenv.h"
 #include "trace2/tr2_tgt.h"
 #include "trace2/tr2_tls.h"
+#include "trace2/tr2_tmr.h"
 
 static int trace2_enabled;
 
@@ -83,6 +84,36 @@ static void tr2_tgt_disable_builtins(void)
 		tgt_j->pfn_term();
 }
 
+static void tr2main_emit_summary_timers(uint64_t us_elapsed_absolute)
+{
+	struct tr2_tgt *tgt_j;
+	int j;
+	struct tr2_timer_block merged = { { { 0 } } };
+
+	tr2_summarize_timers(&merged);
+
+	/*
+	 * Emit "summary" timer events for each composite timer value
+	 * that had activity.
+	 */
+	for_each_wanted_builtin (j, tgt_j)
+		if (tgt_j->pfn_timer)
+			tr2_emit_timer_block(tgt_j->pfn_timer,
+					     us_elapsed_absolute,
+					     &merged, "summary");
+}
+
+static void tr2main_emit_thread_timers(uint64_t us_elapsed_absolute)
+{
+	struct tr2_tgt *tgt_j;
+	int j;
+
+	for_each_wanted_builtin (j, tgt_j)
+		if (tgt_j->pfn_timer)
+			tr2_emit_timers_by_thread(tgt_j->pfn_timer,
+						  us_elapsed_absolute);
+}
+
 static int tr2main_exit_code;
 
 /*
@@ -110,6 +141,9 @@ static void tr2main_atexit_handler(void)
 	 */
 	tr2tls_pop_unwind_self();
 
+	tr2main_emit_thread_timers(us_elapsed_absolute);
+	tr2main_emit_summary_timers(us_elapsed_absolute);
+
 	for_each_wanted_builtin (j, tgt_j)
 		if (tgt_j->pfn_atexit)
 			tgt_j->pfn_atexit(us_elapsed_absolute,
@@ -841,3 +875,25 @@ const char *trace2_session_id(void)
 {
 	return tr2_sid_get();
 }
+
+void trace2_timer_start(enum trace2_timer_id tid)
+{
+	if (!trace2_enabled)
+		return;
+
+	if (tid < 0 || tid >= TRACE2_NUMBER_OF_TIMERS)
+		BUG("trace2_timer_start: invalid timer id: %d", tid);
+
+	tr2_start_timer(tid);
+}
+
+void trace2_timer_stop(enum trace2_timer_id tid)
+{
+	if (!trace2_enabled)
+		return;
+
+	if (tid < 0 || tid >= TRACE2_NUMBER_OF_TIMERS)
+		BUG("trace2_timer_stop: invalid timer id: %d", tid);
+
+	tr2_stop_timer(tid);
+}
diff --git a/trace2.h b/trace2.h
index 0cc7b5f5312..22da5c5516c 100644
--- a/trace2.h
+++ b/trace2.h
@@ -51,6 +51,7 @@ struct json_writer;
  * [] trace2_region*    -- emit region nesting messages.
  * [] trace2_data*      -- emit region/thread/repo data messages.
  * [] trace2_printf*    -- legacy trace[1] messages.
+ * [] trace2_timer*     -- start/stop stopwatch timer (messages are deferred).
  */
 
 /*
@@ -531,4 +532,45 @@ void trace2_collect_process_info(enum trace2_process_info_reason reason);
 
 const char *trace2_session_id(void);
 
+/*
+ * Define the set of stopwatch timers.
+ *
+ * We can add more at any time, but they must be defined at compile
+ * time (to avoid the need to dynamically allocate and synchronize
+ * them between different threads).
+ *
+ * These must start at 0 and be contiguous (because we use them
+ * elsewhere as array indexes).
+ *
+ * Any values added to this enum must also be added to the timer definitions
+ * array.  See `trace2/tr2_tmr.c:tr2_timer_def_block[]`.
+ */
+enum trace2_timer_id {
+	/*
+	 * Define two timers for testing.  See `t/helper/test-trace2.c`.
+	 * These can be used for ad hoc testing, but should not be used
+	 * for permanent analysis code.
+	 */
+	TRACE2_TIMER_ID_TEST1 = 0, /* emits summary event only */
+	TRACE2_TIMER_ID_TEST2,     /* emits summary and thread events */
+
+
+	/* Add additional timer definitions before here. */
+	TRACE2_NUMBER_OF_TIMERS
+};
+
+/*
+ * Start/Stop a stopwatch timer in the current thread.
+ *
+ * The time spent in each start/stop interval will be accumulated and
+ * a "timer" event will be emitted when the program exits.
+ *
+ * Note: Since the stopwatch API routines do not generate individual
+ * events, they do not take (file, line) arguments.  Similarly, the
+ * category and timer name values are defined at compile-time in the
+ * timer definitions array, so they are not needed here in the API.
+ */
+void trace2_timer_start(enum trace2_timer_id tid);
+void trace2_timer_stop(enum trace2_timer_id tid);
+
 #endif /* TRACE2_H */
diff --git a/trace2/tr2_tls.c b/trace2/tr2_tls.c
index 78538d5e522..675f6aeef31 100644
--- a/trace2/tr2_tls.c
+++ b/trace2/tr2_tls.c
@@ -1,6 +1,7 @@
 #include "cache.h"
 #include "thread-utils.h"
 #include "trace2/tr2_tls.h"
+#include "trace2/tr2_tmr.h"
 
 /*
  * Initialize size of the thread stack for nested regions.
@@ -204,3 +205,31 @@ int tr2tls_locked_increment(int *p)
 
 	return current_value;
 }
+
+void tr2_summarize_timers(struct tr2_timer_block *merged)
+{
+	struct tr2tls_thread_ctx *ctx = tr2tls_ctx_list;
+
+	while (ctx) {
+		struct tr2tls_thread_ctx *next = ctx->next_ctx;
+
+		tr2_merge_timer_block(merged, &ctx->timers);
+
+		ctx = next;
+	}
+}
+
+void tr2_emit_timers_by_thread(tr2_tgt_evt_timer_t *pfn,
+			       uint64_t us_elapsed_absolute)
+{
+	struct tr2tls_thread_ctx *ctx = tr2tls_ctx_list;
+
+	while (ctx) {
+		struct tr2tls_thread_ctx *next = ctx->next_ctx;
+
+		tr2_emit_timer_block(pfn, us_elapsed_absolute, &ctx->timers,
+				     ctx->thread_name);
+
+		ctx = next;
+	}
+}
diff --git a/trace2/tr2_tls.h b/trace2/tr2_tls.h
index 889010ec1ff..72e37beb1e7 100644
--- a/trace2/tr2_tls.h
+++ b/trace2/tr2_tls.h
@@ -2,6 +2,7 @@
 #define TR2_TLS_H
 
 #include "strbuf.h"
+#include "trace2/tr2_tmr.h"
 
 struct tr2tls_thread_ctx {
 	struct tr2tls_thread_ctx *next_ctx;
@@ -9,9 +10,26 @@ struct tr2tls_thread_ctx {
 	size_t alloc;
 	size_t nr_open_regions; /* plays role of "nr" in ALLOC_GROW */
 	int thread_id;
+
+	struct tr2_timer_block timers;
+
 	char thread_name[FLEX_ARRAY];
 };
 
+/*
+ * Iterate over the global list of threads and aggregate the timer
+ * data into the given timer block.  The resulting block will contain
+ * the global summary of timer usage.
+ */
+void tr2_summarize_timers(struct tr2_timer_block *merged);
+
+/*
+ * Iterate over the global list of threads and emit "per-thread"
+ * timer data.
+ */
+void tr2_emit_timers_by_thread(tr2_tgt_evt_timer_t *pfn,
+			       uint64_t us_elapsed_absolute);
+
 /*
  * Create TLS data for the current thread.  This gives us a place to
  * put per-thread data, such as thread start time, function nesting
diff --git a/trace2/tr2_tmr.c b/trace2/tr2_tmr.c
new file mode 100644
index 00000000000..c7edcfd55fb
--- /dev/null
+++ b/trace2/tr2_tmr.c
@@ -0,0 +1,136 @@
+#include "cache.h"
+#include "thread-utils.h"
+#include "trace2/tr2_tls.h"
+#include "trace2/tr2_tmr.h"
+
+#define MY_MAX(a, b) ((a) > (b) ? (a) : (b))
+#define MY_MIN(a, b) ((a) < (b) ? (a) : (b))
+
+/*
+ * Define metadata for each stopwatch timer.  This list must match the
+ * set defined in "enum trace2_timer_id".
+ */
+struct tr2_timer_def {
+	const char *category;
+	const char *name;
+
+	unsigned int want_thread_events:1;
+};
+
+static struct tr2_timer_def tr2_timer_def_block[TRACE2_NUMBER_OF_TIMERS] = {
+	[TRACE2_TIMER_ID_TEST1] = { "test", "test1", 0 },
+	[TRACE2_TIMER_ID_TEST2] = { "test", "test2", 1 },
+};
+
+void tr2_start_timer(enum trace2_timer_id tid)
+{
+	struct tr2tls_thread_ctx *ctx = tr2tls_get_self();
+	struct tr2_timer *t = &ctx->timers.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->timers.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 "(unsigned)-1" 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++;
+}
+
+void tr2_merge_timer_block(struct tr2_timer_block *merged,
+			   const struct tr2_timer_block *src)
+{
+	enum trace2_timer_id tid;
+
+	for (tid = 0; tid < TRACE2_NUMBER_OF_TIMERS; tid++) {
+		struct tr2_timer *t_merged = &merged->timer[tid];
+		const struct tr2_timer *t = &src->timer[tid];
+
+		t_merged->is_aggregate = 1;
+
+		if (t->recursion_count) {
+			/*
+			 * A thread exited with a stopwatch running.
+			 *
+			 * NEEDSWORK: should we assert or throw a warning
+			 * for the open interval.  I'm going to ignore it
+			 * and keep going because we may have valid data
+			 * for previously closed intervals on this timer.
+			 *
+			 * That is, I'm going to ignore the value of
+			 * "now - start_ns".
+			 */
+		}
+
+		if (!t->interval_count)
+			continue; /* this timer was not used by this thread. */
+
+		t_merged->total_ns += t->total_ns;
+
+		if (!t_merged->interval_count) {
+			t_merged->min_ns = t->min_ns;
+			t_merged->max_ns = t->max_ns;
+		} else {
+			t_merged->min_ns = MY_MIN(t->min_ns, t_merged->min_ns);
+			t_merged->max_ns = MY_MAX(t->max_ns, t_merged->max_ns);
+		}
+
+		t_merged->interval_count += t->interval_count;
+	}
+
+	merged->is_aggregate = 1;
+}
+
+void tr2_emit_timer_block(tr2_tgt_evt_timer_t *pfn,
+			  uint64_t us_elapsed_absolute,
+			  const struct tr2_timer_block *blk,
+			  const char *thread_name)
+{
+	enum trace2_timer_id tid;
+
+	for (tid = 0; tid < TRACE2_NUMBER_OF_TIMERS; tid++) {
+		const struct tr2_timer *t = &blk->timer[tid];
+		const struct tr2_timer_def *d = &tr2_timer_def_block[tid];
+
+		if (!t->interval_count)
+			continue; /* timer was not used */
+
+		if (!d->want_thread_events && !t->is_aggregate)
+			continue; /* per-thread events not wanted */
+
+		pfn(us_elapsed_absolute, thread_name, d->category, d->name,
+		    t->interval_count, t->total_ns, t->min_ns, t->max_ns);
+	}
+}
diff --git a/trace2/tr2_tmr.h b/trace2/tr2_tmr.h
new file mode 100644
index 00000000000..1963e6ac475
--- /dev/null
+++ b/trace2/tr2_tmr.h
@@ -0,0 +1,139 @@
+#ifndef TR2_TM_H
+#define TR2_TM_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.  This lets us avoid the complexities of
+ * dynamically allocating a timer on demand and sharing that
+ * definition with other threads.
+ *
+ * Timer values are stored in a fixed size "timer block" inside thread
+ * local storage.  This allows data to be collected on a
+ * thread-by-thread basis without locking.
+ *
+ * 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.  Using an array of timers in this block gives us
+ * constant time access to each timer within each thread, so we don't
+ * need to do expensive lookups (like hashmaps) to start/stop a timer.
+ *
+ * We define (at compile time) a set of "timer ids" to access the
+ * various timers inside the fixed size "timer block".  See
+ * `trace2_timer_id` in `trace2/trace2.h`.
+ *
+ * Timer definitions also include "category", "name", and similar
+ * fields.  These are defined in a parallel table in `tr2_tmr.c` and
+ * eliminate the need to include those args in the various timer APIs.
+ *
+ * Timer results are summarized and emitted by the main thread at
+ * program exit by iterating over the global list of thread local
+ * storage data blocks.
+ */
+
+/*
+ * 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.)
+	 */
+	size_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;
+
+	/*
+	 * Has data from multiple threads been combined into this object.
+	 */
+	unsigned int is_aggregate:1;
+};
+
+/*
+ * A compile-time fixed-size block of timers to insert into thread
+ * local storage.
+ *
+ * We use this simple wrapper around the array of timer instances to
+ * avoid C syntax quirks and the need to pass around an additional size_t
+ * argument.
+ */
+struct tr2_timer_block {
+	struct tr2_timer timer[TRACE2_NUMBER_OF_TIMERS];
+
+	/*
+	 * Has data from multiple threads been combined into this block.
+	 */
+	unsigned int is_aggregate:1;
+};
+
+/*
+ * 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);
+
+/*
+ * Accumulate timer data for all of the individual timers in the source
+ * block into the corresponding timers in the merged block.
+ *
+ * This will aggregate data from one block (from an individual thread)
+ * into the merge block.
+ */
+void tr2_merge_timer_block(struct tr2_timer_block *merged,
+			   const struct tr2_timer_block *src);
+
+/*
+ * Send stopwatch data for all of the timers in this block to the
+ * trace target destination.
+ *
+ * This will generate an event record for each timer in the block that
+ * had activity during the program's execution.  (If this is called
+ * with a per-thread block, we emit the per-thread data; if called
+ * with a aggregate block, we emit summary data.)
+ */
+void tr2_emit_timer_block(tr2_tgt_evt_timer_t *pfn,
+			  uint64_t us_elapsed_absolute,
+			  const struct tr2_timer_block *blk,
+			  const char *thread_name);
+
+#endif /* TR2_TM_H */

From patchwork Tue Dec 28 19:36:41 2021
Content-Type: text/plain; charset="utf-8"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
X-Patchwork-Submitter: Jeff Hostetler <jeffhost@microsoft.com>
X-Patchwork-Id: 12700564
Return-Path: <git-owner@kernel.org>
X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on
	aws-us-west-2-korg-lkml-1.web.codeaurora.org
Received: from vger.kernel.org (vger.kernel.org [23.128.96.18])
	by smtp.lore.kernel.org (Postfix) with ESMTP id B44F4C433EF
	for <git@archiver.kernel.org>; Tue, 28 Dec 2021 19:37:00 +0000 (UTC)
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
        id S237201AbhL1Tg6 (ORCPT <rfc822;git@archiver.kernel.org>);
        Tue, 28 Dec 2021 14:36:58 -0500
Received: from lindbergh.monkeyblade.net ([23.128.96.19]:39994 "EHLO
        lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
        with ESMTP id S237189AbhL1Tgu (ORCPT <rfc822;git@vger.kernel.org>);
        Tue, 28 Dec 2021 14:36:50 -0500
Received: from mail-wr1-x42b.google.com (mail-wr1-x42b.google.com
 [IPv6:2a00:1450:4864:20::42b])
        by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 78415C061746
        for <git@vger.kernel.org>; Tue, 28 Dec 2021 11:36:50 -0800 (PST)
Received: by mail-wr1-x42b.google.com with SMTP id w20so31165142wra.9
        for <git@vger.kernel.org>; Tue, 28 Dec 2021 11:36:50 -0800 (PST)
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
        d=gmail.com; s=20210112;
        h=message-id:in-reply-to:references:from:date:subject:fcc
         :content-transfer-encoding:mime-version:to:cc;
        bh=1tgR+lkbjnipk/1V/6W39iDTeFiIJi4O4RDuvV39PEQ=;
        b=A09t9P007DiPosGiwL9FDKh845kohUHNU+Mh5XhQJWFZ5QrCkCBzp/aPaE2gCG/vVE
         iebuvdowJ3w7zGTQzMmNaRIRGjWkAhLueFhdL9jppKC6sAyNOd9UjRNZdp+hA4pkfNst
         k/BEejCgsiNy0w/0tSqmQiCLlToVmxE2OS9AuaqT+g9cPp0Ev1i5fv6lnoPBliCgkwpt
         HYcYFFPT9rzTT9xR/2RrpgjvLlhPE0tJlKj+OMcxgJBzGh2IHXNzvY0BH6D1+Os+guSR
         b0deGIwtsByeeTl12JhoxWx4l54rxn8x2YyZwIRArk5ne9/hJXsJe9VoRJZOK3VND8rr
         RziA==
X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
        d=1e100.net; s=20210112;
        h=x-gm-message-state:message-id:in-reply-to:references:from:date
         :subject:fcc:content-transfer-encoding:mime-version:to:cc;
        bh=1tgR+lkbjnipk/1V/6W39iDTeFiIJi4O4RDuvV39PEQ=;
        b=g3uZIsBCBjZbIHnQnY1g8XDnUf1J8pi480ONcLA8S3kP7CM0DiVfS+BgoNlFxLlyEb
         6ZiAt5sDw4l8AfTaqHO7ugWJ5WvSdSpYPM7A7RstFMIcO7BQfYmMAUoY6cuPTsK15SXV
         cbJYr3Q5vmKox18x2mhCQ+ku+ix+4sEWky7cnVg3tRzKF8yC6A2Z5oLQ0TqKLWIszVbh
         J6CkOywOlbGw0cWp2WpeJNAQjYddsQI08hpqBleOB9C/fN67lzdK8rv22PLcs7bFObzP
         ymWe6IKCmqR91kxoMvDri9I3N+kKWJAKjxZFcDetGFieoYaT2IE4Ce5C65+F8ie8Dqtd
         Zkgg==
X-Gm-Message-State: AOAM5335wpbuJ4JDGPH01ZYHhJuPuMQ4dmIi9O8q7TAjN3XKdidAF9CE
        p7Iee9tjiqmIbkXfuSzD8PpdEHHwweU=
X-Google-Smtp-Source: 
 ABdhPJz00FCz7VEkt+XciTpgFY5bIdgfWufNJHOkiRJm/2CljZ7280MoRfowYoCqwi0g6kVcGNjkCQ==
X-Received: by 2002:a05:6000:1818:: with SMTP id
 m24mr7197716wrh.549.1640720208880;
        Tue, 28 Dec 2021 11:36:48 -0800 (PST)
Received: from [127.0.0.1] ([13.74.141.28])
        by smtp.gmail.com with ESMTPSA id
 r62sm18876717wmr.35.2021.12.28.11.36.48
        (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256);
        Tue, 28 Dec 2021 11:36:48 -0800 (PST)
Message-Id: 
 <0ef23190759710451bf912a38fbc420d4452800b.1640720202.git.gitgitgadget@gmail.com>
In-Reply-To: <pull.1099.v2.git.1640720202.gitgitgadget@gmail.com>
References: <pull.1099.git.1640012469.gitgitgadget@gmail.com>
        <pull.1099.v2.git.1640720202.gitgitgadget@gmail.com>
Date: Tue, 28 Dec 2021 19:36:41 +0000
Subject: [PATCH v2 8/9] trace2: add counter events to perf and event target
 formats
Fcc: Sent
MIME-Version: 1.0
To: git@vger.kernel.org
Cc: =?utf-8?b?w4Z2YXIgQXJuZmrDtnLDsA==?= Bjarmason  <avarab@gmail.com>,
 Jeff Hostetler <git@jeffhostetler.com>, Derrick Stolee <stolee@gmail.com>,
 Matheus Tavares <matheus.bernardino@usp.br>, Johannes Sixt <j6t@kdbg.org>,
 Jeff Hostetler <jeffhost@microsoft.com>,
 Jeff Hostetler <jeffhost@microsoft.com>
Precedence: bulk
List-ID: <git.vger.kernel.org>
X-Mailing-List: git@vger.kernel.org
From: Jeff Hostetler <jeffhost@microsoft.com>

From: Jeff Hostetler <jeffhost@microsoft.com>

Teach Trace2 "perf" and "event" formats to handle "counter" events
for global counters.  Update the API documentation accordingly.

In a future commit, global counters will be added to the Trace2 API
and it will emit these "counter" events at program exit.

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 Documentation/technical/api-trace2.txt | 19 +++++++++++++++++++
 trace2/tr2_tgt.h                       | 14 ++++++++++++++
 trace2/tr2_tgt_event.c                 | 23 +++++++++++++++++++++++
 trace2/tr2_tgt_normal.c                |  1 +
 trace2/tr2_tgt_perf.c                  | 18 ++++++++++++++++++
 5 files changed, 75 insertions(+)

diff --git a/Documentation/technical/api-trace2.txt b/Documentation/technical/api-trace2.txt
index 616001bcbb0..bdba0f92280 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 a41f91d09b5..66f34b9258f 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 ns_min_time,
 				  uint64_t ns_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 fe89e80bb1a..907bff80827 100644
--- a/trace2/tr2_tgt_event.c
+++ b/trace2/tr2_tgt_event.c
@@ -643,6 +643,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,
 
@@ -675,4 +697,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 c07ffad1a32..911cf6e6eab 100644
--- a/trace2/tr2_tgt_perf.c
+++ b/trace2/tr2_tgt_perf.c
@@ -581,6 +581,23 @@ 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 value:%"PRIu64, counter_name, 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,
 
@@ -613,4 +630,5 @@ struct tr2_tgt tr2_tgt_perf = {
 	fn_data_json_fl,
 	fn_printf_va_fl,
 	fn_timer,
+	fn_counter,
 };

From patchwork Tue Dec 28 19:36:42 2021
Content-Type: text/plain; charset="utf-8"
MIME-Version: 1.0
Content-Transfer-Encoding: 7bit
X-Patchwork-Submitter: Jeff Hostetler <jeffhost@microsoft.com>
X-Patchwork-Id: 12700565
Return-Path: <git-owner@kernel.org>
X-Spam-Checker-Version: SpamAssassin 3.4.0 (2014-02-07) on
	aws-us-west-2-korg-lkml-1.web.codeaurora.org
Received: from vger.kernel.org (vger.kernel.org [23.128.96.18])
	by smtp.lore.kernel.org (Postfix) with ESMTP id 41F0BC433EF
	for <git@archiver.kernel.org>; Tue, 28 Dec 2021 19:37:03 +0000 (UTC)
Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand
        id S232919AbhL1ThC (ORCPT <rfc822;git@archiver.kernel.org>);
        Tue, 28 Dec 2021 14:37:02 -0500
Received: from lindbergh.monkeyblade.net ([23.128.96.19]:40002 "EHLO
        lindbergh.monkeyblade.net" rhost-flags-OK-OK-OK-OK) by vger.kernel.org
        with ESMTP id S237191AbhL1Tgw (ORCPT <rfc822;git@vger.kernel.org>);
        Tue, 28 Dec 2021 14:36:52 -0500
Received: from mail-wr1-x42d.google.com (mail-wr1-x42d.google.com
 [IPv6:2a00:1450:4864:20::42d])
        by lindbergh.monkeyblade.net (Postfix) with ESMTPS id 6750CC061747
        for <git@vger.kernel.org>; Tue, 28 Dec 2021 11:36:51 -0800 (PST)
Received: by mail-wr1-x42d.google.com with SMTP id s1so40171399wra.6
        for <git@vger.kernel.org>; Tue, 28 Dec 2021 11:36:51 -0800 (PST)
DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
        d=gmail.com; s=20210112;
        h=message-id:in-reply-to:references:from:date:subject:fcc
         :content-transfer-encoding:mime-version:to:cc;
        bh=O6tS3yPo6TcsoBnkL0dTAbJuWIxyk24bsF/NbJhiAwU=;
        b=CV0qXdvaRvPyTj6E88T/0vPIKQ3b/lL/fx7pO3lvIvI5bSVH2OXm2Wy58qhECqUtz3
         pg7NxLUH7pp2PzKEW1RQ3r7XDiCuD40+wICJrVTtkH6haFwMiR8G+9UjD1jJpfz3ythP
         L+nAQ/SSGhC5VNlS/h4lUDh5Paf31yIQjRr+BabewY+g6qSlB1IGAP9O7uXEyahZjDA+
         wQoh+Lko1OfhzoNGcbDjWRRjRij7c0HHAgRrEsACY7tTppkk8C46NEIJ7JvXjHcx1aWO
         gvaSJFyX1Ga0RLiMMHrQe4aHxeJ7GcN+yU4tdlLf0LN4i8KfqTJ286ut1m2/Wb1Glbr/
         QDoQ==
X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed;
        d=1e100.net; s=20210112;
        h=x-gm-message-state:message-id:in-reply-to:references:from:date
         :subject:fcc:content-transfer-encoding:mime-version:to:cc;
        bh=O6tS3yPo6TcsoBnkL0dTAbJuWIxyk24bsF/NbJhiAwU=;
        b=Xos0TOAWt3ePvlzbIIh+DLZC6CcYbt5QW2s3pVYMYeOYuBAmbaHP99xdKt9NM0C2Xs
         X+Nb/UgPOhwZepw1Oz86i41CyoNcd5m3dgxRq5AP0cvVuwb3ky9ltHu8L3TkkjqgBoEK
         v0hXpeqvYFX+S9eQ+6AY9VAnNEhsUPggkVRji02MKnPg6lYOwdDKyPoLX/WU39z0mrcM
         bsPNgzmSBnTYnNQF6YRAqMmfXu+TI5aPgF8qWJ9Qk89iijSiY98Mq5yHya7LI1kkXO5H
         kVILVV7avLHWOUYWg8C3VjVgLiYkcvdZUm/mP2YVDPI2enrVyGurGoJywHBjKpp6i7jk
         tpSA==
X-Gm-Message-State: AOAM530DRDmSddNECnpPDafmSA5Jsfr3k/Yq40W2oItqj0qT6pt6bPZp
        AwDl5BKXK9kH1sJXyMKjZpB47RdLRAw=
X-Google-Smtp-Source: 
 ABdhPJxferIorfEml42odFf8D/kSVxrfmob0MdlP0tW9zlIAjtiv/4tb7lHAfchnJp+qtMnkq7hILw==
X-Received: by 2002:a05:6000:16c4:: with SMTP id
 h4mr17546764wrf.312.1640720209552;
        Tue, 28 Dec 2021 11:36:49 -0800 (PST)
Received: from [127.0.0.1] ([13.74.141.28])
        by smtp.gmail.com with ESMTPSA id
 l26sm18529226wrz.44.2021.12.28.11.36.49
        (version=TLS1_3 cipher=TLS_AES_256_GCM_SHA384 bits=256/256);
        Tue, 28 Dec 2021 11:36:49 -0800 (PST)
Message-Id: 
 <4d6155e4e4c2c600084d892999ebc4579623dc83.1640720202.git.gitgitgadget@gmail.com>
In-Reply-To: <pull.1099.v2.git.1640720202.gitgitgadget@gmail.com>
References: <pull.1099.git.1640012469.gitgitgadget@gmail.com>
        <pull.1099.v2.git.1640720202.gitgitgadget@gmail.com>
Date: Tue, 28 Dec 2021 19:36:42 +0000
Subject: [PATCH v2 9/9] trace2: add global counters
Fcc: Sent
MIME-Version: 1.0
To: git@vger.kernel.org
Cc: =?utf-8?b?w4Z2YXIgQXJuZmrDtnLDsA==?= Bjarmason  <avarab@gmail.com>,
 Jeff Hostetler <git@jeffhostetler.com>, Derrick Stolee <stolee@gmail.com>,
 Matheus Tavares <matheus.bernardino@usp.br>, Johannes Sixt <j6t@kdbg.org>,
 Jeff Hostetler <jeffhost@microsoft.com>,
 Jeff Hostetler <jeffhost@microsoft.com>
Precedence: bulk
List-ID: <git.vger.kernel.org>
X-Mailing-List: git@vger.kernel.org
From: Jeff Hostetler <jeffhost@microsoft.com>

From: Jeff Hostetler <jeffhost@microsoft.com>

Add global counters to Trace2.

Create a mechanism in Trace2 to count an activity and emit a single
"counter" event at the end of the program.  This is an alternative
to the existing "data" events that are emitted immediately.

Create an array of counters (indexed by `enum trace2_counter_id`)
to allow various activites to be tracked as desired.

Preload the array with two counters for testing purposes.

Create unit tests to demonstrate and verify.

Signed-off-by: Jeff Hostetler <jeffhost@microsoft.com>
---
 Documentation/technical/api-trace2.txt | 67 ++++++++++++++++++++
 Makefile                               |  1 +
 t/helper/test-trace2.c                 | 88 +++++++++++++++++++++++++-
 t/t0211-trace2-perf.sh                 | 42 ++++++++++++
 t/t0212-trace2-event.sh                | 41 ++++++++++++
 trace2.c                               | 50 +++++++++++++++
 trace2.h                               | 33 ++++++++++
 trace2/tr2_ctr.c                       | 67 ++++++++++++++++++++
 trace2/tr2_ctr.h                       | 79 +++++++++++++++++++++++
 trace2/tr2_tls.c                       | 29 +++++++++
 trace2/tr2_tls.h                       | 16 +++++
 11 files changed, 512 insertions(+), 1 deletion(-)
 create mode 100644 trace2/tr2_ctr.c
 create mode 100644 trace2/tr2_ctr.h

diff --git a/Documentation/technical/api-trace2.txt b/Documentation/technical/api-trace2.txt
index bdba0f92280..a3ea867ff92 100644
--- a/Documentation/technical/api-trace2.txt
+++ b/Documentation/technical/api-trace2.txt
@@ -1297,6 +1297,73 @@ d0 | main                     | atexit       |     |  0.111026 |           |
 In this example, the "test1" timer was started 4 times and ran for
 0.000393 seconds.
 
+Counter Events::
+
+	Trace2 also provides global counters as an alternative to regions
+	and data events.  These make it possible to count an activity of
+	interest, such a call to a library routine, during the program
+	and get a single counter event at the end.
++
+At the end of the program, a single summary event is emitted; this
+value is aggregated across all threads.  These events have "summary"
+as their thread name.
++
+For some counters, individual (per-thread) counter events are also
+generated.  This may be helpful in understanding how work is balanced
+between threads in some circumstances.
++
+----------------
+static void *load_cache_entries_thread(void *_data)
+{
+	struct load_cache_entries_thread_data *p = _data;
+	int i;
+
+	trace2_thread_start("load_cache_entries");
+	...
+	trace2_thread_exit();
+}
+
+static unsigned long load_cache_entry_block(struct index_state *istate,
+			struct mem_pool *ce_mem_pool, int offset, int nr, const char *mmap,
+			unsigned long start_offset, const struct cache_entry *previous_ce)
+{
+	int i;
+	unsigned long src_offset = start_offset;
+
+	trace2_counter_increment(TRACE2_COUNTER_ID_TEST2, nr);
+
+	for (i = offset; i < offset + nr; i++) {
+		...
+	}
+}
+----------------
++
+----------------
+$ export GIT_TRACE2_PERF_BRIEF=1
+$ export GIT_TRACE2_PERF=~/log.perf
+$ git status
+...
+$ cat ~/log.perf
+...
+d0 | main                     | exit         |     | 53.977680 |           |              | code:0
+d0 | th12:load_cache_entries  | counter      |     | 53.977708 |           | test         | name:test2 value:193220
+d0 | th11:load_cache_entries  | counter      |     | 53.977708 |           | test         | name:test2 value:193221
+d0 | th10:load_cache_entries  | counter      |     | 53.977708 |           | test         | name:test2 value:193221
+d0 | th09:load_cache_entries  | counter      |     | 53.977708 |           | test         | name:test2 value:193221
+d0 | th08:load_cache_entries  | counter      |     | 53.977708 |           | test         | name:test2 value:193221
+d0 | th07:load_cache_entries  | counter      |     | 53.977708 |           | test         | name:test2 value:193221
+d0 | th06:load_cache_entries  | counter      |     | 53.977708 |           | test         | name:test2 value:193221
+d0 | th05:load_cache_entries  | counter      |     | 53.977708 |           | test         | name:test2 value:193221
+d0 | th04:load_cache_entries  | counter      |     | 53.977708 |           | test         | name:test2 value:193221
+d0 | th03:load_cache_entries  | counter      |     | 53.977708 |           | test         | name:test2 value:193221
+d0 | th02:load_cache_entries  | counter      |     | 53.977708 |           | test         | name:test2 value:193221
+d0 | summary                  | counter      |     | 53.977708 |           | test         | name:test2 value:2125430
+d0 | main                     | atexit       |     | 53.977708 |           |              | code:0
+----------------
++
+This example shows the value computed by each of the 11
+`load_cache_entries` threads and the total across all threads.
+
 == Future Work
 
 === Relationship to the Existing Trace Api (api-trace.txt)
diff --git a/Makefile b/Makefile
index 8b657f0162a..cc5bd8593f1 100644
--- a/Makefile
+++ b/Makefile
@@ -1020,6 +1020,7 @@ LIB_OBJS += trace.o
 LIB_OBJS += trace2.o
 LIB_OBJS += trace2/tr2_cfg.o
 LIB_OBJS += trace2/tr2_cmd_name.o
+LIB_OBJS += trace2/tr2_ctr.o
 LIB_OBJS += trace2/tr2_dst.o
 LIB_OBJS += trace2/tr2_sid.o
 LIB_OBJS += trace2/tr2_tmr.o
diff --git a/t/helper/test-trace2.c b/t/helper/test-trace2.c
index 51d022422bf..a7dbecfda9a 100644
--- a/t/helper/test-trace2.c
+++ b/t/helper/test-trace2.c
@@ -270,7 +270,7 @@ static int ut_009timer(int argc, const char **argv)
 	const char *usage_error =
 		"expect <count> <ms_delay> <threads>";
 
-	struct ut_009_data data = { 0, 0 };
+	struct ut_009_data data = { 0 };
 	int nr_threads = 0;
 	int k;
 	pthread_t *pids = NULL;
@@ -301,6 +301,90 @@ static int ut_009timer(int argc, const char **argv)
 	return 0;
 }
 
+/*
+ * Single-threaded counter test.  Add several values to the TEST1 counter.
+ * The test script can verify that an aggregate Trace2 "counter" event is
+ * emitted containing the sum of the values provided.
+ */
+static int ut_010counter(int argc, const char **argv)
+{
+	const char *usage_error =
+		"expect <v1> [<v2> [...]]";
+	int value;
+	int k;
+
+	if (argc < 1)
+		die("%s", usage_error);
+
+	for (k = 0; k < argc; k++) {
+		if (get_i(&value, argv[k]))
+			die("invalid value[%s] -- %s",
+			    argv[k], usage_error);
+		trace2_counter_add(TRACE2_COUNTER_ID_TEST1, value);
+	}
+
+	return 0;
+}
+
+struct ut_011_data {
+	int v1, v2;
+};
+
+static void *ut_011counter_thread_proc(void *_ut_011_data)
+{
+	struct ut_011_data *data = _ut_011_data;
+
+	trace2_thread_start("ut_011");
+
+	trace2_counter_add(TRACE2_COUNTER_ID_TEST2, data->v1);
+	trace2_counter_add(TRACE2_COUNTER_ID_TEST2, data->v2);
+
+	trace2_thread_exit();
+	return NULL;
+}
+
+/*
+ * Multi-threaded counter test.  Create several threads that each
+ * increment the TEST2 global counter.  The test script can verify
+ * that an individual Trace2 "counter" event for each thread and an
+ * aggregate "counter" event are generated.
+ */
+static int ut_011counter(int argc, const char **argv)
+{
+	const char *usage_error =
+		"expect <v1> <v2> <threads>";
+
+	struct ut_011_data data = { 0, 0 };
+	int nr_threads = 0;
+	int k;
+	pthread_t *pids = NULL;
+
+	if (argc != 3)
+		die("%s", usage_error);
+	if (get_i(&data.v1, argv[0]))
+		die("%s", usage_error);
+	if (get_i(&data.v2, argv[1]))
+		die("%s", usage_error);
+	if (get_i(&nr_threads, argv[2]))
+		die("%s", usage_error);
+
+	CALLOC_ARRAY(pids, nr_threads);
+
+	for (k = 0; k < nr_threads; k++) {
+		if (pthread_create(&pids[k], NULL, ut_011counter_thread_proc, &data))
+			die("failed to create thread[%d]", k);
+	}
+
+	for (k = 0; k < nr_threads; k++) {
+		if (pthread_join(pids[k], NULL))
+			die("failed to join thread[%d]", k);
+	}
+
+	free(pids);
+
+	return 0;
+}
+
 /*
  * Usage:
  *     test-tool trace2 <ut_name_1> <ut_usage_1>
@@ -320,6 +404,8 @@ static struct unit_test ut_table[] = {
 	{ ut_007bug,      "007bug",    "" },
 	{ ut_008timer,    "008timer",  "<count> <ms_delay>" },
 	{ ut_009timer,    "009timer",  "<count> <ms_delay> <threads>" },
+	{ ut_010counter,  "010counter","<v1> [<v2> [<v3> [...]]]" },
+	{ ut_011counter,  "011counter","<v1> <v2> <threads>" },
 };
 /* clang-format on */
 
diff --git a/t/t0211-trace2-perf.sh b/t/t0211-trace2-perf.sh
index 381c3eea458..5f9a3533ce4 100755
--- a/t/t0211-trace2-perf.sh
+++ b/t/t0211-trace2-perf.sh
@@ -219,4 +219,46 @@ test_expect_success 'test stopwatch timers - summary and threads' '
 	have_timer_event "summary" "test2" 15 actual
 '
 
+# Exercise the global counter "test" in a loop and confirm that we get an
+# event with the sum.
+#
+
+have_counter_event () {
+	thread=$1
+	name=$2
+	value=$3
+	file=$4
+
+	pattern="d0|${thread}|counter||_T_ABS_||test"
+	pattern="${pattern}|name:${name}"
+	pattern="${pattern} value:${value}"
+
+	grep "${pattern}" ${file}
+
+	return $?
+}
+
+test_expect_success 'test global counters - global, single-thead' '
+	test_when_finished "rm trace.perf actual" &&
+	test_config_global trace2.perfBrief 1 &&
+	test_config_global trace2.perfTarget "$(pwd)/trace.perf" &&
+	test-tool trace2 010counter 2 3 5 7 11 13  &&
+	perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual &&
+
+	have_counter_event "summary" "test1" 41 actual
+'
+
+test_expect_success 'test global counters - global+threads' '
+	test_when_finished "rm trace.perf actual" &&
+	test_config_global trace2.perfBrief 1 &&
+	test_config_global trace2.perfTarget "$(pwd)/trace.perf" &&
+	test-tool trace2 011counter 5 10 3 &&
+	perl "$TEST_DIRECTORY/t0211/scrub_perf.perl" <trace.perf >actual &&
+
+	have_counter_event "th01:ut_011" "test2" 15 actual &&
+	have_counter_event "th02:ut_011" "test2" 15 actual &&
+	have_counter_event "th03:ut_011" "test2" 15 actual &&
+	have_counter_event "summary" "test2" 45 actual
+'
+
 test_done
diff --git a/t/t0212-trace2-event.sh b/t/t0212-trace2-event.sh
index 277688fdbc4..9e76ef5caa7 100755
--- a/t/t0212-trace2-event.sh
+++ b/t/t0212-trace2-event.sh
@@ -368,4 +368,45 @@ test_expect_success 'test stopwatch timers - global+threads' '
 	have_timer_event "summary" "test2" 15 trace.event
 '
 
+# Exercise the global counter in a loop and confirm that we get the
+# expected sum in an event record.
+#
+
+have_counter_event () {
+	thread=$1
+	name=$2
+	value=$3
+	file=$4
+
+	pattern="\"event\":\"counter\""
+	pattern="${pattern}.*\"thread\":\"${thread}\""
+	pattern="${pattern}.*\"name\":\"${name}\""
+	pattern="${pattern}.*\"value\":${value}"
+
+	grep "${pattern}" ${file}
+
+	return $?
+}
+
+test_expect_success 'test global counter - global, single-thread' '
+	test_when_finished "rm trace.event" &&
+	test_config_global trace2.eventBrief 1 &&
+	test_config_global trace2.eventTarget "$(pwd)/trace.event" &&
+	test-tool trace2 010counter 2 3 5 7 11 13 &&
+
+	have_counter_event "summary" "test1" 41 trace.event
+'
+
+test_expect_success 'test global counter - global+threads' '
+	test_when_finished "rm trace.event" &&
+	test_config_global trace2.eventBrief 1 &&
+	test_config_global trace2.eventTarget "$(pwd)/trace.event" &&
+	test-tool trace2 011counter 5 10 3 &&
+
+	have_counter_event "th01:ut_011" "test2" 15 trace.event &&
+	have_counter_event "th02:ut_011" "test2" 15 trace.event &&
+	have_counter_event "th03:ut_011" "test2" 15 trace.event &&
+	have_counter_event "summary" "test2" 45 trace.event
+'
+
 test_done
diff --git a/trace2.c b/trace2.c
index 23289dd6eb4..aa6ed6dd3ee 100644
--- a/trace2.c
+++ b/trace2.c
@@ -8,6 +8,7 @@
 #include "version.h"
 #include "trace2/tr2_cfg.h"
 #include "trace2/tr2_cmd_name.h"
+#include "trace2/tr2_ctr.h"
 #include "trace2/tr2_dst.h"
 #include "trace2/tr2_sid.h"
 #include "trace2/tr2_sysenv.h"
@@ -114,6 +115,41 @@ static void tr2main_emit_thread_timers(uint64_t us_elapsed_absolute)
 						  us_elapsed_absolute);
 }
 
+static void tr2main_emit_summary_counters(uint64_t us_elapsed_absolute)
+{
+	struct tr2_tgt *tgt_j;
+	int j;
+	struct tr2_counter_block merged = { { { 0 } } };
+
+	/*
+	 * Sum across all of the per-thread counter data into
+	 * a single composite block of counter values.
+	 */
+	tr2tls_aggregate_counter_blocks(&merged);
+
+	/*
+	 * Emit "summary" counter events for each composite counter value
+	 * that had activity.
+	 */
+	for_each_wanted_builtin (j, tgt_j)
+		if (tgt_j->pfn_counter)
+			tr2_emit_counter_block(tgt_j->pfn_counter,
+					       us_elapsed_absolute,
+					       &merged, "summary");
+}
+
+static void tr2main_emit_thread_counters(uint64_t us_elapsed_absolute)
+{
+	struct tr2_tgt *tgt_j;
+	int j;
+
+	for_each_wanted_builtin (j, tgt_j)
+		if (tgt_j->pfn_counter)
+			tr2tls_emit_counter_blocks_by_thread(
+				tgt_j->pfn_counter,
+				us_elapsed_absolute);
+}
+
 static int tr2main_exit_code;
 
 /*
@@ -144,6 +180,9 @@ static void tr2main_atexit_handler(void)
 	tr2main_emit_thread_timers(us_elapsed_absolute);
 	tr2main_emit_summary_timers(us_elapsed_absolute);
 
+	tr2main_emit_thread_counters(us_elapsed_absolute);
+	tr2main_emit_summary_counters(us_elapsed_absolute);
+
 	for_each_wanted_builtin (j, tgt_j)
 		if (tgt_j->pfn_atexit)
 			tgt_j->pfn_atexit(us_elapsed_absolute,
@@ -897,3 +936,14 @@ void trace2_timer_stop(enum trace2_timer_id tid)
 
 	tr2_stop_timer(tid);
 }
+
+void trace2_counter_add(enum trace2_counter_id cid, uint64_t value)
+{
+	if (!trace2_enabled)
+		return;
+
+	if (cid < 0 || cid >= TRACE2_NUMBER_OF_COUNTERS)
+		BUG("invalid counter id: %d", cid);
+
+	tr2_counter_increment(cid, value);
+}
diff --git a/trace2.h b/trace2.h
index 22da5c5516c..d4ed602c19a 100644
--- a/trace2.h
+++ b/trace2.h
@@ -52,6 +52,7 @@ struct json_writer;
  * [] trace2_data*      -- emit region/thread/repo data messages.
  * [] trace2_printf*    -- legacy trace[1] messages.
  * [] trace2_timer*     -- start/stop stopwatch timer (messages are deferred).
+ * [] trace2_counter*   -- global counters (messages are deferrred).
  */
 
 /*
@@ -573,4 +574,36 @@ enum trace2_timer_id {
 void trace2_timer_start(enum trace2_timer_id tid);
 void trace2_timer_stop(enum trace2_timer_id tid);
 
+/*
+ * Define the set of global counters.
+ *
+ * We can add more at any time, but they must be defined at compile
+ * time (to avoid the need to dynamically allocate and synchronize
+ * them between different threads).
+ *
+ * These must start at 0 and be contiguous (because we them elsewhere
+ * as array indexes).
+ *
+ * Any value added to this enum must also be added to the counter
+ * definitions array.  See `trace2/tr2_ctr.c:tr2_counter_def_block[]`.
+ */
+enum trace2_counter_id {
+	/*
+	 * Define two counters for testing.  See `t/helper/test-trace2.c`.
+	 * These can be used for ad hoc testing, but should not be used
+	 * for permanent analysis code.
+	 */
+	TRACE2_COUNTER_ID_TEST1 = 0, /* emits summary event only */
+	TRACE2_COUNTER_ID_TEST2,     /* emits summary and thread events */
+
+
+	/* Add additional counter definitions before here. */
+	TRACE2_NUMBER_OF_COUNTERS
+};
+
+/*
+ * Increment global counter by value.
+ */
+void trace2_counter_add(enum trace2_counter_id cid, uint64_t value);
+
 #endif /* TRACE2_H */
diff --git a/trace2/tr2_ctr.c b/trace2/tr2_ctr.c
new file mode 100644
index 00000000000..ce80ceb5476
--- /dev/null
+++ b/trace2/tr2_ctr.c
@@ -0,0 +1,67 @@
+#include "cache.h"
+#include "thread-utils.h"
+#include "trace2/tr2_tls.h"
+#include "trace2/tr2_ctr.h"
+
+/*
+ * Define metadata for each global counter.  This list must match the
+ * set defined in "enum trace2_counter_id".
+ */
+struct tr2_counter_def {
+	const char *category;
+	const char *name;
+
+	unsigned int want_thread_events:1;
+};
+
+static struct tr2_counter_def tr2_counter_def_block[TRACE2_NUMBER_OF_COUNTERS] = {
+	[TRACE2_COUNTER_ID_TEST1] = { "test", "test1", 0 },
+	[TRACE2_COUNTER_ID_TEST2] = { "test", "test2", 1 },
+};
+
+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->counters.counter[cid];
+
+	c->value += value;
+}
+
+void tr2_merge_counter_block(struct tr2_counter_block *merged,
+			     const struct tr2_counter_block *src)
+{
+	enum trace2_counter_id cid;
+
+	for (cid = 0; cid < TRACE2_NUMBER_OF_COUNTERS; cid++) {
+		struct tr2_counter *c_merged = &merged->counter[cid];
+		const struct tr2_counter *c = &src->counter[cid];
+
+		c_merged->is_aggregate = 1;
+
+		c_merged->value += c->value;
+	}
+
+	merged->is_aggregate = 1;
+}
+
+void tr2_emit_counter_block(tr2_tgt_evt_counter_t *pfn,
+			    uint64_t us_elapsed_absolute,
+			    const struct tr2_counter_block *blk,
+			    const char *thread_name)
+{
+	enum trace2_counter_id cid;
+
+	for (cid = 0; cid < TRACE2_NUMBER_OF_COUNTERS; cid++) {
+		const struct tr2_counter *c = &blk->counter[cid];
+		const struct tr2_counter_def *d = &tr2_counter_def_block[cid];
+
+		if (!c->value)
+			continue; /* counter was not used */
+
+		if (!d->want_thread_events && !c->is_aggregate)
+			continue; /* per-thread events not wanted */
+
+		pfn(us_elapsed_absolute, thread_name, d->category, d->name,
+		    c->value);
+	}
+}
diff --git a/trace2/tr2_ctr.h b/trace2/tr2_ctr.h
new file mode 100644
index 00000000000..fd6fbef89a2
--- /dev/null
+++ b/trace2/tr2_ctr.h
@@ -0,0 +1,79 @@
+#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 and
+ * etc.  Counter values are accumulated during the program and the final
+ * counter value event is emitted at program exit.
+ *
+ * To make this model efficient, we define a compile-time fixed set
+ * of counters and counter ids.  This lets us avoid the complexities
+ * of dynamically allocating a counter and sharing that definition
+ * with other threads.
+ *
+ * We define (at compile time) a set of "counter ids" to access the
+ * various counters inside of a fixed size "counter block".
+ *
+ * A counter defintion table provides the counter category and name
+ * so we can eliminate those arguments from the public counter API.
+ * These are defined in a parallel tabel in `tr2_ctr.c`.
+ *
+ * Each thread has a private block of counters in its thread local
+ * storage data so no locks are required for a thread to increment
+ * it's version of the counter.  At program exit, the counter blocks
+ * from all of the per-thread counters are added together to give the
+ * final summary value for the each global counter.
+ */
+
+/*
+ * The definition of an individual counter.
+ */
+struct tr2_counter {
+	uint64_t value;
+
+	unsigned int is_aggregate:1;
+};
+
+/*
+ * Compile time fixed block of all defined counters.
+ */
+struct tr2_counter_block {
+	struct tr2_counter counter[TRACE2_NUMBER_OF_COUNTERS];
+
+	unsigned int is_aggregate:1;
+};
+
+/*
+ * Add "value" to the global counter.
+ */
+void tr2_counter_increment(enum trace2_counter_id cid, uint64_t value);
+
+/*
+ * Accumulate counter data from the source block into the merged block.
+ */
+void tr2_merge_counter_block(struct tr2_counter_block *merged,
+			       const struct tr2_counter_block *src);
+
+/*
+ * Send counter data for all counters in this block to the target.
+ *
+ * This will generate an event record for each counter that had activity.
+ */
+void tr2_emit_counter_block(tr2_tgt_evt_counter_t *pfn,
+			    uint64_t us_elapsed_absolute,
+			    const struct tr2_counter_block *blk,
+			    const char *thread_name);
+
+#endif /* TR2_CTR_H */
diff --git a/trace2/tr2_tls.c b/trace2/tr2_tls.c
index 675f6aeef31..28ea55863d1 100644
--- a/trace2/tr2_tls.c
+++ b/trace2/tr2_tls.c
@@ -1,5 +1,6 @@
 #include "cache.h"
 #include "thread-utils.h"
+#include "trace2/tr2_ctr.h"
 #include "trace2/tr2_tls.h"
 #include "trace2/tr2_tmr.h"
 
@@ -233,3 +234,31 @@ void tr2_emit_timers_by_thread(tr2_tgt_evt_timer_t *pfn,
 		ctx = next;
 	}
 }
+
+void tr2tls_aggregate_counter_blocks(struct tr2_counter_block *merged)
+{
+	struct tr2tls_thread_ctx *ctx = tr2tls_ctx_list;
+
+	while (ctx) {
+		struct tr2tls_thread_ctx *next = ctx->next_ctx;
+
+		tr2_merge_counter_block(merged, &ctx->counters);
+
+		ctx = next;
+	}
+}
+
+void tr2tls_emit_counter_blocks_by_thread(tr2_tgt_evt_counter_t *pfn,
+					  uint64_t us_elapsed_absolute)
+{
+	struct tr2tls_thread_ctx *ctx = tr2tls_ctx_list;
+
+	while (ctx) {
+		struct tr2tls_thread_ctx *next = ctx->next_ctx;
+
+		tr2_emit_counter_block(pfn, us_elapsed_absolute, &ctx->counters,
+				       ctx->thread_name);
+
+		ctx = next;
+	}
+}
diff --git a/trace2/tr2_tls.h b/trace2/tr2_tls.h
index 72e37beb1e7..503829bbd44 100644
--- a/trace2/tr2_tls.h
+++ b/trace2/tr2_tls.h
@@ -2,6 +2,7 @@
 #define TR2_TLS_H
 
 #include "strbuf.h"
+#include "trace2/tr2_ctr.h"
 #include "trace2/tr2_tmr.h"
 
 struct tr2tls_thread_ctx {
@@ -12,10 +13,25 @@ struct tr2tls_thread_ctx {
 	int thread_id;
 
 	struct tr2_timer_block timers;
+	struct tr2_counter_block counters;
 
 	char thread_name[FLEX_ARRAY];
 };
 
+/*
+ * Iterate over the global list of threads and aggregate the
+ * counter data into the given counter block.  The resulting block
+ * will contain the global counter sums.
+ */
+void tr2tls_aggregate_counter_blocks(struct tr2_counter_block *merged);
+
+/*
+ * Iterate over the global list of threads and emit "per-thread"
+ * counter data for each.
+ */
+void tr2tls_emit_counter_blocks_by_thread(tr2_tgt_evt_counter_t *pfn,
+					  uint64_t us_elapsed_absolute);
+
 /*
  * Iterate over the global list of threads and aggregate the timer
  * data into the given timer block.  The resulting block will contain