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 bce296d3f18d60..b73f322a2b6cc6 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 @@ -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 counterSeriesMap, Duration profileStart, Duration bucketDuration) { @@ -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; diff --git a/src/main/java/com/google/devtools/build/lib/profiler/Profiler.java b/src/main/java/com/google/devtools/build/lib/profiler/Profiler.java index 52ab47cd7b4ded..ae56396db4d4ed 100644 --- a/src/main/java/com/google/devtools/build/lib/profiler/Profiler.java +++ b/src/main/java/com/google/devtools/build/lib/profiler/Profiler.java @@ -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)); + } + } } } @@ -524,41 +553,81 @@ public synchronized Iterable getSlowestTasks() { } private void collectActionCounts() { - Duration endTime = Duration.ofNanos(clock.nanoTime()); - int len = (int) endTime.minus(actionCountStartTime).dividedBy(ACTION_COUNT_BUCKET_DURATION) + 1; - Map 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 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 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 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 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); } } @@ -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); } } @@ -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); } @@ -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);