Fix finish phase time calculation.
The last event in the JSON profile is not necessary the latest event.
This bug lead to sometimes negative finish phase times.
RELNOTES: None
Closes
package com.google.devtools.build.lib.profiler;
import com.google.auto.value.AutoValue;
-import com.google.common.collect.Iterables;
import com.google.devtools.build.lib.profiler.statistics.PhaseSummaryStatistics;
import com.google.gson.stream.JsonReader;
import com.google.gson.stream.JsonToken;
@@ -26,6 +25,7 @@ import java.io.IOException;
import java.io.InputStream;
import java.io.InputStreamReader;
import java.nio.charset.StandardCharsets;
+import java.time.Duration;
import java.util.List;
import java.util.zip.GZIPInputStream;
import javax.annotation.Nullable;
@@ -59,7 +59,17 @@ public final class JsonProfile {
traceEvents = TraceEvent.parseTraceEvents(reader);
phaseSummaryStatistics = new PhaseSummaryStatistics();
TraceEvent lastPhaseEvent = null;
+ Duration maxEndTime = Duration.ZERO;
for (TraceEvent traceEvent : traceEvents) {
+ if (traceEvent.timestamp() != null) {
+ Duration curEndTime = traceEvent.timestamp();
+ if (traceEvent.duration() != null) {
+ curEndTime = curEndTime.plus(traceEvent.duration());
+ }
+ if (curEndTime.compareTo(maxEndTime) > 0) {
+ maxEndTime = curEndTime;
+ }
+ }
if (ProfilerTask.PHASE.description.equals(traceEvent.category())) {
if (lastPhaseEvent != null) {
phaseSummaryStatistics.addProfilePhase(
@@ -70,12 +80,10 @@ public final class JsonProfile {
}
}
if (lastPhaseEvent != null) {
- TraceEvent lastEvent = Iterables.getLast(traceEvents);
phaseSummaryStatistics.addProfilePhase(
ProfilePhase.getPhaseFromDescription(lastPhaseEvent.name()),
- lastEvent.timestamp().minus(lastPhaseEvent.timestamp()));
+ maxEndTime.minus(lastPhaseEvent.timestamp()));
}
-
} else {
reader.skipValue();
}
