diff --git a/src/main/java/com/google/devtools/build/lib/runtime/CriticalPathComponent.java b/src/main/java/com/google/devtools/build/lib/runtime/CriticalPathComponent.java index 2924ffb1bf77d5..c69619ff4ba7a1 100644 --- a/src/main/java/com/google/devtools/build/lib/runtime/CriticalPathComponent.java +++ b/src/main/java/com/google/devtools/build/lib/runtime/CriticalPathComponent.java @@ -97,7 +97,8 @@ public CriticalPathComponent(int id, Action action, long startNanos) { * with the total spawn metrics. To make sure not to add the last phase's duration multiple times, * only add if there is duration and reset the phase metrics once it has been aggregated. */ - public synchronized void finishActionExecution(long startNanos, long finishNanos) { + public synchronized void finishActionExecution( + long startNanos, long finishNanos, String finalizeReason) { if (isRunning || finishNanos - startNanos > getElapsedTimeNanos()) { this.startNanos = startNanos; this.finishNanos = finishNanos; @@ -106,6 +107,13 @@ public synchronized void finishActionExecution(long startNanos, long finishNanos // this component. aggregatedElapsedTime = Math.max(aggregatedElapsedTime, this.finishNanos - this.startNanos); isRunning = false; + if (longestPhaseSpawnRunnerName == null && !finalizeReason.isEmpty()) { + // This is probably not the best way to do it in face of getting called multiple times. + longestPhaseSpawnRunnerName = finalizeReason; + longestPhaseSpawnRunnerSubtype = ""; + longestRunningTotalDurationInMs = + (int) Duration.ofNanos(this.finishNanos - this.startNanos).toMillis(); + } } // If the phaseMaxMetrics has Duration, then we want to aggregate it to the total. diff --git a/src/main/java/com/google/devtools/build/lib/runtime/CriticalPathComputer.java b/src/main/java/com/google/devtools/build/lib/runtime/CriticalPathComputer.java index ca2a00852529a3..6479de7ec826a4 100644 --- a/src/main/java/com/google/devtools/build/lib/runtime/CriticalPathComputer.java +++ b/src/main/java/com/google/devtools/build/lib/runtime/CriticalPathComputer.java @@ -251,7 +251,7 @@ public void middlemanAction(ActionMiddlemanEvent event) throws InterruptedExcept Action action = event.getAction(); CriticalPathComponent component = tryAddComponent(createComponent(action, event.getNanoTimeStart())); - finalizeActionStat(event.getNanoTimeStart(), action, component); + finalizeActionStat(event.getNanoTimeStart(), action, component, "middleman action"); } /** @@ -312,7 +312,7 @@ public void actionCached(CachedActionEvent event) throws InterruptedException { Action action = event.getAction(); CriticalPathComponent component = tryAddComponent(createComponent(action, event.getNanoTimeStart())); - finalizeActionStat(event.getNanoTimeStart(), action, component); + finalizeActionStat(event.getNanoTimeStart(), action, component, "action cache hit"); } /** @@ -326,7 +326,7 @@ public void actionComplete(ActionCompletionEvent event) { CriticalPathComponent component = Preconditions.checkNotNull( outputArtifactToComponent.get(action.getPrimaryOutput()), action); - finalizeActionStat(event.getRelativeActionStartTime(), action, component); + finalizeActionStat(event.getRelativeActionStartTime(), action, component, ""); } /** @@ -339,7 +339,8 @@ public void actionRewound(ActionRewoundEvent event) { Action action = event.getFailedRewoundAction(); CriticalPathComponent component = Preconditions.checkNotNull(outputArtifactToComponent.get(action.getPrimaryOutput())); - component.finishActionExecution(event.getRelativeActionStartTime(), clock.nanoTime()); + component.finishActionExecution( + event.getRelativeActionStartTime(), clock.nanoTime(), "action rewound"); } /** Maximum critical path component found during the build. */ @@ -348,7 +349,7 @@ CriticalPathComponent getMaxCriticalPath() { } private void finalizeActionStat( - long startTimeNanos, Action action, CriticalPathComponent component) { + long startTimeNanos, Action action, CriticalPathComponent component, String finalizeReason) { long finishTimeNanos = clock.nanoTime(); for (Artifact input : action.getInputs().toList()) { addArtifactDependency(component, input, finishTimeNanos); @@ -359,7 +360,7 @@ private void finalizeActionStat( "Negative duration time for [%s] %s with start: %s, finish: %s.", action.getMnemonic(), action.getPrimaryOutput(), startTimeNanos, finishTimeNanos); } - component.finishActionExecution(startTimeNanos, finishTimeNanos); + component.finishActionExecution(startTimeNanos, finishTimeNanos, finalizeReason); maxCriticalPath.accumulateAndGet(component, SELECT_LONGER_COMPONENT); }