A CriticalPathComponent's input discovery step is not categorized so there is a discrepancy in runtime and metrics provided. Now input discovery will be categorized as parse time.
RELNOTES: An action's discover inputs runtime metrics is now categorized as parse time on the CriticalPathComponent.
PiperOrigin-RevId: 281086930
diff --git a/src/main/java/com/google/devtools/build/lib/actions/DiscoveredInputsEvent.java b/src/main/java/com/google/devtools/build/lib/actions/DiscoveredInputsEvent.java
new file mode 100644
index 0000000..fd1a36b
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/actions/DiscoveredInputsEvent.java
@@ -0,0 +1,42 @@
+// Copyright 2019 The Bazel Authors. All rights reserved.
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+// http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+package com.google.devtools.build.lib.actions;
+
+import com.google.devtools.build.lib.events.ExtendedEventHandler;
+
+/** Event for passing SpawnMetrics for the discover inputs phase. */
+public class DiscoveredInputsEvent implements ExtendedEventHandler.ProgressLike {
+ private final SpawnMetrics metrics;
+ private final Action action;
+ private final long startTimeNanos;
+
+ public DiscoveredInputsEvent(SpawnMetrics metrics, Action action, long startTimeNanos) {
+ this.metrics = metrics;
+ this.action = action;
+ this.startTimeNanos = startTimeNanos;
+ }
+
+ public SpawnMetrics getMetrics() {
+ return metrics;
+ }
+
+ public Action getAction() {
+ return action;
+ }
+
+ public long getStartTimeNanos() {
+ return startTimeNanos;
+ }
+}
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 c6362324..d08a908 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
@@ -165,26 +165,26 @@
}
/**
- * An action can run multiple spawns. Those calls can be sequential or parallel. If it is a
- * sequence of calls we should aggregate the metrics by collecting all the SpawnResults, if they
- * are run in parallel we should keep the maximum runtime spawn. We will also set the
- * longestPhaseSpawnRunnerName to the longest running spawn runner name across all phases.
+ * An action can run multiple spawns. Those calls can be sequential or parallel. If action is a
+ * sequence of calls we aggregate the SpawnMetrics of all the SpawnResults. If there are multiples
+ * of the same action run in parallel, we keep the maximum runtime SpawnMetrics. We will also set
+ * the longestPhaseSpawnRunnerName to the longest running spawn runner name across all phases if
+ * it exists.
*/
- void addSpawnResult(SpawnResult spawnResult) {
+ void addSpawnResult(SpawnMetrics metrics, @Nullable String runnerName) {
if (this.phaseChange) {
this.totalSpawnMetrics =
SpawnMetrics.aggregateMetrics(
ImmutableList.of(this.totalSpawnMetrics, this.phaseMaxMetrics), true);
- this.phaseMaxMetrics = spawnResult.getMetrics();
+ this.phaseMaxMetrics = metrics;
this.phaseChange = false;
- } else if (spawnResult.getMetrics().totalTime().compareTo(this.phaseMaxMetrics.totalTime())
- > 0) {
- this.phaseMaxMetrics = spawnResult.getMetrics();
+ } else if (metrics.totalTime().compareTo(this.phaseMaxMetrics.totalTime()) > 0) {
+ this.phaseMaxMetrics = metrics;
}
- if (spawnResult.getMetrics().totalTime().compareTo(this.longestRunningTotalDuration) > 0) {
- this.longestPhaseSpawnRunnerName = spawnResult.getRunnerName();
- this.longestRunningTotalDuration = spawnResult.getMetrics().totalTime();
+ if (runnerName != null && metrics.totalTime().compareTo(this.longestRunningTotalDuration) > 0) {
+ this.longestPhaseSpawnRunnerName = runnerName;
+ this.longestRunningTotalDuration = metrics.totalTime();
}
}
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 632acd5..59411d3 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
@@ -30,6 +30,7 @@
import com.google.devtools.build.lib.actions.Actions;
import com.google.devtools.build.lib.actions.Artifact;
import com.google.devtools.build.lib.actions.CachedActionEvent;
+import com.google.devtools.build.lib.actions.DiscoveredInputsEvent;
import com.google.devtools.build.lib.actions.SpawnExecutedEvent;
import com.google.devtools.build.lib.actions.SpawnMetrics;
import com.google.devtools.build.lib.actions.SpawnResult;
@@ -132,6 +133,7 @@
return outputArtifactToComponent;
}
+ /** Changes the phase of the action */
@Subscribe
@AllowConcurrentEvents
public void nextCriticalPathPhase(SpawnExecutedEvent.ChangePhase phase) {
@@ -158,7 +160,7 @@
Preconditions.checkNotNull(outputArtifactToComponent.get(primaryOutput));
SpawnResult spawnResult = event.getSpawnResult();
- stats.addSpawnResult(spawnResult);
+ stats.addSpawnResult(spawnResult.getMetrics(), spawnResult.getRunnerName());
}
/** Returns the list of components using the most memory. */
@@ -194,8 +196,19 @@
.map((e) -> e.getValue());
}
+ /** Creates a CriticalPathComponent and adds the duration of input discovery and changes phase. */
+ @Subscribe
+ @AllowConcurrentEvents
+ public void discoverInputs(DiscoveredInputsEvent event) {
+ CriticalPathComponent stats =
+ tryAddComponent(createComponent(event.getAction(), event.getStartTimeNanos()));
+ stats.addSpawnResult(event.getMetrics(), null);
+ stats.changePhase();
+ }
+
/**
- * Record an action that has started to run.
+ * Record an action that has started to run. If the CriticalPathComponent has not been created,
+ * initialize it.
*
* @param event information about the started action
*/
@@ -277,8 +290,8 @@
@AllowConcurrentEvents
public void actionCached(CachedActionEvent event) {
Action action = event.getAction();
- CriticalPathComponent component
- = tryAddComponent(createComponent(action, event.getNanoTimeStart()));
+ CriticalPathComponent component =
+ tryAddComponent(createComponent(action, event.getNanoTimeStart()));
finalizeActionStat(event.getNanoTimeStart(), action, component);
}
diff --git a/src/main/java/com/google/devtools/build/lib/skyframe/ActionExecutionFunction.java b/src/main/java/com/google/devtools/build/lib/skyframe/ActionExecutionFunction.java
index 852a4d3..c685193 100644
--- a/src/main/java/com/google/devtools/build/lib/skyframe/ActionExecutionFunction.java
+++ b/src/main/java/com/google/devtools/build/lib/skyframe/ActionExecutionFunction.java
@@ -38,6 +38,7 @@
import com.google.devtools.build.lib.actions.AlreadyReportedActionExecutionException;
import com.google.devtools.build.lib.actions.Artifact;
import com.google.devtools.build.lib.actions.ArtifactPathResolver;
+import com.google.devtools.build.lib.actions.DiscoveredInputsEvent;
import com.google.devtools.build.lib.actions.FileArtifactValue;
import com.google.devtools.build.lib.actions.FilesetOutputSymlink;
import com.google.devtools.build.lib.actions.LostInputsActionExecutionException;
@@ -45,6 +46,7 @@
import com.google.devtools.build.lib.actions.MissingInputFileException;
import com.google.devtools.build.lib.actions.NotifyOnActionCacheHit;
import com.google.devtools.build.lib.actions.PackageRootResolver;
+import com.google.devtools.build.lib.actions.SpawnMetrics;
import com.google.devtools.build.lib.actionsketch.ActionSketch;
import com.google.devtools.build.lib.analysis.BlazeDirectories;
import com.google.devtools.build.lib.causes.Cause;
@@ -78,6 +80,7 @@
import com.google.devtools.build.skyframe.ValueOrException;
import com.google.devtools.build.skyframe.ValueOrException2;
import java.io.IOException;
+import java.time.Duration;
import java.util.ArrayList;
import java.util.Collection;
import java.util.Collections;
@@ -820,6 +823,10 @@
e,
action,
/*catastrophe=*/ false);
+ } finally {
+ state.discoveredInputsDuration =
+ state.discoveredInputsDuration.plus(
+ Duration.ofNanos(BlazeClock.nanoTime() - actionStartTime));
}
Preconditions.checkState(
env.valuesMissing() == (state.discoveredInputs == null),
@@ -855,6 +862,16 @@
// Set the MetadataHandler to accept output information.
metadataHandler.discardOutputMetadata();
}
+ // When discover inputs completes, post an event with the duration values.
+ env.getListener()
+ .post(
+ new DiscoveredInputsEvent(
+ new SpawnMetrics.Builder()
+ .setParseTime(state.discoveredInputsDuration)
+ .setTotalTime(state.discoveredInputsDuration)
+ .build(),
+ action,
+ actionStartTime));
}
try {
@@ -1332,6 +1349,7 @@
Token token = null;
Iterable<Artifact> discoveredInputs = null;
FileSystem actionFileSystem = null;
+ Duration discoveredInputsDuration = Duration.ZERO;
/**
* Stores the ArtifactNestedSetKeys created from the inputs of this actions. Objective: avoid
