Skip to content

Commit

Permalink
[7.0.0] [JSON Trace Profile] Add tid to counter series (#20324)
Browse files Browse the repository at this point in the history
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
a03674e
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
#18548 (comment)
Fixes EngFlow/bazel_invocation_analyzer#113

Closes #20300.

Commit
16acadb

PiperOrigin-RevId: 585636103
Change-Id: I2aa1ff1e656324410d120ff5b6071028b0a5dce3

Co-authored-by: Sara Adams <sara@engflow.com>
  • Loading branch information
bazel-io and saraadams committed Nov 27, 2023
1 parent 4260c15 commit 2d97001
Show file tree
Hide file tree
Showing 3 changed files with 28 additions and 6 deletions.
Expand Up @@ -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;
Expand All @@ -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<ProfilerTask, double[]> counterSeriesMap;
private final Duration profileStart;
private final Duration bucketDuration;
private final int len;
private final long threadId;
private String displayName;

@Nullable private String colorName;

/**
Expand Down Expand Up @@ -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;
Expand Down Expand Up @@ -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);
}
Expand Down
Expand Up @@ -39,6 +39,7 @@ public static TraceEvent create(
@Nullable String type,
@Nullable Duration timestamp,
@Nullable Duration duration,
long processId,
long threadId,
@Nullable ImmutableMap<String, Object> args,
@Nullable String primaryOutputPath,
Expand All @@ -50,6 +51,7 @@ public static TraceEvent create(
type,
timestamp,
duration,
processId,
threadId,
args,
primaryOutputPath,
Expand All @@ -71,6 +73,8 @@ public static TraceEvent create(
@Nullable
public abstract Duration duration();

public abstract long processId();

public abstract long threadId();

@Nullable
Expand All @@ -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;
Expand All @@ -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;
Expand All @@ -141,6 +149,7 @@ private static TraceEvent createFromJsonReader(JsonReader reader) throws IOExcep
type,
timestamp,
duration,
processId,
threadId,
args,
primaryOutputPath,
Expand Down
Expand Up @@ -1012,12 +1012,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);
}
}

0 comments on commit 2d97001

Please sign in to comment.