Skip to content

Commit

Permalink
[JSON Trace Profile] Add tid to counter series
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.

PiperOrigin-RevId: 585636103
Change-Id: I2aa1ff1e656324410d120ff5b6071028b0a5dce3
  • Loading branch information
saraadams authored and Copybara-Service committed Nov 27, 2023
1 parent e843bc6 commit 16acadb
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 @@ -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);
}
}

0 comments on commit 16acadb

Please sign in to comment.