From 16acadb5b2f30714b3b05a6c3887fda9fee5086e Mon Sep 17 00:00:00 2001 From: Sara Adams Date: Mon, 27 Nov 2023 06:40:08 -0800 Subject: [PATCH] [JSON Trace Profile] Add `tid` to counter series The JSON trace profile includes counter for data such as action count, CPU usage, memory usage. The code for writing the events to include these was refactored in https://github.com/bazelbuild/bazel/commit/a03674e6297ed5f6f740889cba8780d7c4ffe05c As part of that change the events written no longer include a `tid` (thread ID). However, each event in the JSON trace profile is expected to include a `tid`, as documented in https://docs.google.com/document/d/1CvAClvFfyA5R-PhYUmn5OOQtYMH4h6I0nSsKchNAySU/preview#heading=h.uxpopqvbjezh This change ensures the counter series events again have a `tid`, using the current thread's ID. This is consistent with the behavior that was present before the refactor. In response to https://github.com/bazelbuild/bazel/issues/18548#issuecomment-1823361627 Fixes https://github.com/EngFlow/bazel_invocation_analyzer/issues/113 Closes #20300. PiperOrigin-RevId: 585636103 Change-Id: I2aa1ff1e656324410d120ff5b6071028b0a5dce3 --- .../lib/profiler/CounterSeriesTraceData.java | 8 +++++++- .../devtools/build/lib/profiler/TraceEvent.java | 9 +++++++++ .../build/lib/profiler/ProfilerTest.java | 17 ++++++++++++----- 3 files changed, 28 insertions(+), 6 deletions(-) diff --git a/src/main/java/com/google/devtools/build/lib/profiler/CounterSeriesTraceData.java b/src/main/java/com/google/devtools/build/lib/profiler/CounterSeriesTraceData.java index b49d14b9caff06..fce0585f4c4ee9 100644 --- a/src/main/java/com/google/devtools/build/lib/profiler/CounterSeriesTraceData.java +++ b/src/main/java/com/google/devtools/build/lib/profiler/CounterSeriesTraceData.java @@ -15,6 +15,7 @@ import static java.util.Map.entry; +import com.google.common.annotations.VisibleForTesting; import com.google.common.base.Preconditions; import com.google.common.collect.ImmutableMap; import com.google.gson.stream.JsonWriter; @@ -30,11 +31,14 @@ * opposed to individual tasks such as executing an action). */ final class CounterSeriesTraceData implements TraceData { + @VisibleForTesting static final long PROCESS_ID = 1; private final Map counterSeriesMap; private final Duration profileStart; private final Duration bucketDuration; private final int len; + private final long threadId; private String displayName; + @Nullable private String colorName; /** @@ -63,6 +67,7 @@ final class CounterSeriesTraceData implements TraceData { } } this.len = len; + this.threadId = Thread.currentThread().getId(); this.counterSeriesMap = counterSeriesMap; this.profileStart = profileStart; this.bucketDuration = bucketDuration; @@ -115,7 +120,8 @@ public void writeTraceData(JsonWriter jsonWriter, long profileStartTimeNanos) th jsonWriter.beginObject(); jsonWriter.setIndent(""); jsonWriter.name("name").value(displayName); - jsonWriter.name("pid").value(1); + jsonWriter.name("pid").value(PROCESS_ID); + jsonWriter.name("tid").value(threadId); if (colorName != null) { jsonWriter.name("cname").value(colorName); } diff --git a/src/main/java/com/google/devtools/build/lib/profiler/TraceEvent.java b/src/main/java/com/google/devtools/build/lib/profiler/TraceEvent.java index 0f8d15ae74eafe..80e8bddeb6a18f 100644 --- a/src/main/java/com/google/devtools/build/lib/profiler/TraceEvent.java +++ b/src/main/java/com/google/devtools/build/lib/profiler/TraceEvent.java @@ -39,6 +39,7 @@ public static TraceEvent create( @Nullable String type, @Nullable Duration timestamp, @Nullable Duration duration, + long processId, long threadId, @Nullable ImmutableMap args, @Nullable String primaryOutputPath, @@ -50,6 +51,7 @@ public static TraceEvent create( type, timestamp, duration, + processId, threadId, args, primaryOutputPath, @@ -71,6 +73,8 @@ public static TraceEvent create( @Nullable public abstract Duration duration(); + public abstract long processId(); + public abstract long threadId(); @Nullable @@ -91,6 +95,7 @@ private static TraceEvent createFromJsonReader(JsonReader reader) throws IOExcep String name = null; Duration timestamp = null; Duration duration = null; + long processId = -1; long threadId = -1; String primaryOutputPath = null; String targetLabel = null; @@ -117,6 +122,9 @@ private static TraceEvent createFromJsonReader(JsonReader reader) throws IOExcep case "dur": duration = Duration.ofNanos(reader.nextLong() * 1000); break; + case "pid": + processId = reader.nextLong(); + break; case "tid": threadId = reader.nextLong(); break; @@ -141,6 +149,7 @@ private static TraceEvent createFromJsonReader(JsonReader reader) throws IOExcep type, timestamp, duration, + processId, threadId, args, primaryOutputPath, diff --git a/src/test/java/com/google/devtools/build/lib/profiler/ProfilerTest.java b/src/test/java/com/google/devtools/build/lib/profiler/ProfilerTest.java index d7cb7cf44bcb67..c83093f35286b4 100644 --- a/src/test/java/com/google/devtools/build/lib/profiler/ProfilerTest.java +++ b/src/test/java/com/google/devtools/build/lib/profiler/ProfilerTest.java @@ -1016,12 +1016,19 @@ public void testActionCacheHitsCounted() throws Exception { jsonProfile.getTraceEvents().stream() .filter(e -> "action count".equals(e.name())) .toArray(); + + assertThat(actionCountEvents).hasLength(2); + + TraceEvent first = (TraceEvent) actionCountEvents[0]; + assertThat(first.processId()).isEqualTo(CounterSeriesTraceData.PROCESS_ID); + assertThat(first.threadId()).isEqualTo(Thread.currentThread().getId()); // Two cache hit checks and one executed action. - assertThat(((TraceEvent) actionCountEvents[0]).args()) - .containsExactly("action", 1.0, "local action cache", 2.0); + assertThat(first.args()).containsExactly("action", 1.0, "local action cache", 2.0); + + TraceEvent second = (TraceEvent) actionCountEvents[1]; + assertThat(first.processId()).isEqualTo(CounterSeriesTraceData.PROCESS_ID); + assertThat(first.threadId()).isEqualTo(Thread.currentThread().getId()); // One of the cache hit checks spilled over and used half of the second bucket. - assertThat(((TraceEvent) actionCountEvents[1]).args()) - .containsExactly("local action cache", 0.5); - assertThat(actionCountEvents).hasLength(2); + assertThat(second.args()).containsExactly("local action cache", 0.5); } }