From a5b9882492fd13fe05459f886668b134718aa811 Mon Sep 17 00:00:00 2001
From: Googler <larsrc@google.com>
Date: Mon, 6 Mar 2023 07:32:57 -0800
Subject: [PATCH] Set runners for critical path where no spawn was actually
 executed.

Not entirely sure that this does the right thing in all circumstances. Is it possible that an actual spawn runner's update could happen after the call to `finishActionExecution`? What happens around action rewinding? Could we do something about the fileset and symlinking actions that only come through `actionComplete`? That even happens for all actions, so it should not be considered for "non-runner name". Should the runners that are not "real" runners be indicated in some way, in brackets or something?

PiperOrigin-RevId: 514405743
Change-Id: I0323f930a0e3ee475fd07d39c375edcfc542fc96
---
 .../build/lib/runtime/CriticalPathComponent.java    | 10 +++++++++-
 .../build/lib/runtime/CriticalPathComputer.java     | 13 +++++++------
 2 files changed, 16 insertions(+), 7 deletions(-)

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);
   }