Skip to content

Commit

Permalink
Move postprocess of action profile events to writer thread to reduce …
Browse files Browse the repository at this point in the history 
…contention.

PiperOrigin-RevId: 721758048
Change-Id: Ife8f1567eebadb6a9062a36b5bd02fea7b254666
  • Loading branch information
@coeuvre @copybara-github
coeuvre authored and copybara-github committed Jan 31, 2025
1 parent 47f3253 commit 3d96b45
Show file tree
Hide file tree
Showing 2 changed files with 108 additions and 54 deletions.
3 changes: 2 additions & 1 deletion src/main/java/com/google/devtools/build/lib/profiler/CounterSeriesTraceData.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -44,6 +44,7 @@ final class CounterSeriesTraceData implements TraceData {
* map. However, colors the remaining series are picked arbitrarily by the Trace renderer.
*/
CounterSeriesTraceData(
long threadId,
Map<CounterSeriesTask, double[]> counterSeriesMap,
Duration profileStart,
Duration bucketDuration) {
Expand All @@ -63,7 +64,7 @@ final class CounterSeriesTraceData implements TraceData {
}
}
this.len = len;
this.threadId = Thread.currentThread().getId();
this.threadId = threadId;
this.counterSeriesMap = counterSeriesMap;
this.profileStart = profileStart;
this.bucketDuration = bucketDuration;
Expand Down
159 changes: 106 additions & 53 deletions src/main/java/com/google/devtools/build/lib/profiler/Profiler.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -228,6 +228,35 @@ public void writeTraceData(JsonWriter jsonWriter, long profileStartTimeNanos)
? ThreadMetadata.CRITICAL_PATH_THREAD_ID
: threadId);
jsonWriter.endObject();

countActions();
}

private void countActions() {
long endTimeNanos = startTimeNanos + durationNanos;
if (instance.countAction(type)) {
TimeSeries actionCountTimeSeries = instance.actionCountTimeSeriesRef.get();
if (actionCountTimeSeries != null) {
actionCountTimeSeries.addRange(
Duration.ofNanos(startTimeNanos), Duration.ofNanos(endTimeNanos));
}
}

if (type == ProfilerTask.ACTION_CHECK) {
TimeSeries actionCacheCountTimeSeries = instance.actionCacheCountTimeSeriesRef.get();
if (actionCacheCountTimeSeries != null) {
actionCacheCountTimeSeries.addRange(
Duration.ofNanos(startTimeNanos), Duration.ofNanos(endTimeNanos));
}
}

if (type == ProfilerTask.LOCAL_ACTION_COUNTS) {
TimeSeries localActionCountTimeSeries = instance.localActionCountTimeSeriesRef.get();
if (localActionCountTimeSeries != null) {
localActionCountTimeSeries.addRange(
Duration.ofNanos(startTimeNanos), Duration.ofNanos(endTimeNanos));
}
}
}
}

Expand Down Expand Up @@ -524,41 +553,81 @@ public synchronized Iterable<SlowTask> getSlowestTasks() {
}

private void collectActionCounts() {
Duration endTime = Duration.ofNanos(clock.nanoTime());
int len = (int) endTime.minus(actionCountStartTime).dividedBy(ACTION_COUNT_BUCKET_DURATION) + 1;
Map<CounterSeriesTask, double[]> counterSeriesMap = new LinkedHashMap<>();
TimeSeries actionCountTimeSeries = actionCountTimeSeriesRef.get();
if (actionCountTimeSeries != null) {
double[] actionCountValues = actionCountTimeSeries.toDoubleArray(len);
actionCountTimeSeriesRef.set(null);
counterSeriesMap.put(
new CounterSeriesTask("action count", "action", /* color= */ null), actionCountValues);
}
TimeSeries actionCacheCountTimeSeries = actionCacheCountTimeSeriesRef.get();
if (actionCacheCountTimeSeries != null) {
double[] actionCacheCountValues = actionCacheCountTimeSeries.toDoubleArray(len);
actionCacheCountTimeSeriesRef.set(null);
counterSeriesMap.put(
new CounterSeriesTask("action cache count", "local action cache", /* color= */ null),
actionCacheCountValues);
}
if (!counterSeriesMap.isEmpty()) {
instance.logCounters(counterSeriesMap, actionCountStartTime, ACTION_COUNT_BUCKET_DURATION);
}
long threadId = Thread.currentThread().getId();
var traceData =
new TraceData() {
@Override
public void writeTraceData(JsonWriter jsonWriter, long profileStartTimeNanos)
throws IOException {
Duration endTime = Duration.ofNanos(clock.nanoTime());
int len =
(int) endTime.minus(actionCountStartTime).dividedBy(ACTION_COUNT_BUCKET_DURATION)
+ 1;
Map<CounterSeriesTask, double[]> counterSeriesMap = new LinkedHashMap<>();
TimeSeries actionCountTimeSeries = actionCountTimeSeriesRef.get();
if (actionCountTimeSeries != null) {
double[] actionCountValues = actionCountTimeSeries.toDoubleArray(len);
actionCountTimeSeriesRef.set(null);
counterSeriesMap.put(
new CounterSeriesTask("action count", "action", /* color= */ null),
actionCountValues);
}
TimeSeries actionCacheCountTimeSeries = actionCacheCountTimeSeriesRef.get();
if (actionCacheCountTimeSeries != null) {
double[] actionCacheCountValues = actionCacheCountTimeSeries.toDoubleArray(len);
actionCacheCountTimeSeriesRef.set(null);
counterSeriesMap.put(
new CounterSeriesTask(
"action cache count", "local action cache", /* color= */ null),
actionCacheCountValues);
}
if (!counterSeriesMap.isEmpty()) {
logCounters(
jsonWriter,
profileStartTimeNanos,
counterSeriesMap,
actionCountStartTime,
ACTION_COUNT_BUCKET_DURATION);
}

Map<CounterSeriesTask, double[]> localCounterSeriesMap = new LinkedHashMap<>();
TimeSeries localActionCountTimeSeries = localActionCountTimeSeriesRef.get();
if (localActionCountTimeSeries != null) {
double[] localActionCountValues = localActionCountTimeSeries.toDoubleArray(len);
localActionCountTimeSeriesRef.set(null);
localCounterSeriesMap.put(
new CounterSeriesTask(
"action count (local)",
"local action",
CounterSeriesTask.Color.DETAILED_MEMORY_DUMP),
localActionCountValues);
}
if (hasNonZeroValues(localCounterSeriesMap)) {
logCounters(
jsonWriter,
profileStartTimeNanos,
localCounterSeriesMap,
actionCountStartTime,
ACTION_COUNT_BUCKET_DURATION);
}
}

Map<CounterSeriesTask, double[]> localCounterSeriesMap = new LinkedHashMap<>();
TimeSeries localActionCountTimeSeries = localActionCountTimeSeriesRef.get();
if (localActionCountTimeSeries != null) {
double[] localActionCountValues = localActionCountTimeSeries.toDoubleArray(len);
localActionCountTimeSeriesRef.set(null);
localCounterSeriesMap.put(
new CounterSeriesTask(
"action count (local)", "local action", CounterSeriesTask.Color.DETAILED_MEMORY_DUMP),
localActionCountValues);
}
if (hasNonZeroValues(localCounterSeriesMap)) {
instance.logCounters(
localCounterSeriesMap, actionCountStartTime, ACTION_COUNT_BUCKET_DURATION);
private void logCounters(
JsonWriter jsonWriter,
long profileStartTimeNanos,
Map<CounterSeriesTask, double[]> counterSeriesMap,
Duration profileStart,
Duration bucketDuration)
throws IOException {
var counterSeriesTraceData =
new CounterSeriesTraceData(
threadId, counterSeriesMap, profileStart, bucketDuration);
counterSeriesTraceData.writeTraceData(jsonWriter, profileStartTimeNanos);
}
};
JsonTraceFileWriter writer = writerRef.get();
if (writer != null) {
writer.enqueue(traceData);
}
}

Expand Down Expand Up @@ -656,7 +725,8 @@ public void logCounters(
JsonTraceFileWriter currentWriter = writerRef.get();
if (isActive() && currentWriter != null) {
CounterSeriesTraceData counterSeriesTraceData =
new CounterSeriesTraceData(counterSeriesMap, profileStart, bucketDuration);
new CounterSeriesTraceData(
Thread.currentThread().threadId(), counterSeriesMap, profileStart, bucketDuration);
currentWriter.enqueue(counterSeriesTraceData);
}
}
Expand Down Expand Up @@ -696,8 +766,7 @@ private void logTask(long startTimeNanos, long duration, ProfilerTask type, Stri
currentWriter.enqueue(data);
}

SlowestTaskAggregator aggregator = slowestTasks[type.ordinal()];

SlowestTaskAggregator aggregator = slowestTasks[data.type.ordinal()];
if (aggregator != null) {
aggregator.add(data);
}
Expand Down Expand Up @@ -929,23 +998,7 @@ private void recordTask(TaskData data) {
if (writer != null) {
writer.enqueue(data);
}
long endTimeNanos = data.startTimeNanos + data.durationNanos;
TimeSeries actionCountTimeSeries = actionCountTimeSeriesRef.get();
TimeSeries actionCacheCountTimeSeries = actionCacheCountTimeSeriesRef.get();
TimeSeries localActionCountTimeSeries = localActionCountTimeSeriesRef.get();
if (actionCountTimeSeries != null && countAction(data.type)) {
actionCountTimeSeries.addRange(
Duration.ofNanos(data.startTimeNanos), Duration.ofNanos(endTimeNanos));
}
if (actionCacheCountTimeSeries != null && data.type == ProfilerTask.ACTION_CHECK) {
actionCacheCountTimeSeries.addRange(
Duration.ofNanos(data.startTimeNanos), Duration.ofNanos(endTimeNanos));
}

if (localActionCountTimeSeries != null && data.type == ProfilerTask.LOCAL_ACTION_COUNTS) {
localActionCountTimeSeries.addRange(
Duration.ofNanos(data.startTimeNanos), Duration.ofNanos(endTimeNanos));
}
SlowestTaskAggregator aggregator = slowestTasks[data.type.ordinal()];
if (aggregator != null) {
aggregator.add(data);
Expand Down

0 comments on commit 3d96b45

Please sign in to comment.