From 09adb348446ffc41f0c4da5c6a8dc97a27dcfd88 Mon Sep 17 00:00:00 2001 From: Googler Date: Fri, 24 Mar 2023 06:01:54 -0700 Subject: [PATCH] [Skymeld] Make the execution timer more precise. We do so by only starting the timer when the first execution phase activity starts, instead of making it account for all loading + analysis + execution like the current behavior. PiperOrigin-RevId: 519123420 Change-Id: Ie75b3dcdf79fff19ce75d83372d2e7c90ada0972 --- .../build/lib/buildtool/BuildTool.java | 9 ++--- .../build/lib/buildtool/ExecutionTool.java | 33 ++++++++++++++----- 2 files changed, 30 insertions(+), 12 deletions(-) diff --git a/src/main/java/com/google/devtools/build/lib/buildtool/BuildTool.java b/src/main/java/com/google/devtools/build/lib/buildtool/BuildTool.java index f5c062de51e0e5..8a3cb26ee4b82b 100644 --- a/src/main/java/com/google/devtools/build/lib/buildtool/BuildTool.java +++ b/src/main/java/com/google/devtools/build/lib/buildtool/BuildTool.java @@ -324,8 +324,8 @@ private void buildTargetsWithMergedAnalysisExecution( if (request.getBuildOptions().performAnalysisPhase) { ExecutionTool executionTool = new ExecutionTool(env, request); - // This timer measures time for loading + analysis + execution. - Stopwatch timer = Stopwatch.createStarted(); + // This timer measures time from the first execution activity to the last. + Stopwatch executionTimer = Stopwatch.createUnstarted(); // TODO(b/199053098): implement support for --nobuild. AnalysisAndExecutionResult analysisAndExecutionResult; @@ -337,7 +337,7 @@ private void buildTargetsWithMergedAnalysisExecution( request, buildOptions, loadingResult, - () -> executionTool.prepareForExecution(request.getId()), + () -> executionTool.prepareForExecution(request.getId(), executionTimer), result::setBuildConfiguration, new BuildDriverKeyTestContext() { @Override @@ -372,7 +372,8 @@ public boolean forceExclusiveIfLocalTestsInParallel() { hasCatastrophe = true; throw e; } finally { - executionTool.unconditionalExecutionPhaseFinalizations(timer, env.getSkyframeExecutor()); + executionTool.unconditionalExecutionPhaseFinalizations( + executionTimer, env.getSkyframeExecutor()); // For the --noskymeld code path, this is done after the analysis phase. BuildResultListener buildResultListener = env.getBuildResultListener(); diff --git a/src/main/java/com/google/devtools/build/lib/buildtool/ExecutionTool.java b/src/main/java/com/google/devtools/build/lib/buildtool/ExecutionTool.java index 8641716278ddde..65c7f2a9e8dff0 100644 --- a/src/main/java/com/google/devtools/build/lib/buildtool/ExecutionTool.java +++ b/src/main/java/com/google/devtools/build/lib/buildtool/ExecutionTool.java @@ -113,7 +113,6 @@ import java.util.Optional; import java.util.Set; import java.util.UUID; -import java.util.concurrent.TimeUnit; import java.util.concurrent.atomic.AtomicBoolean; import javax.annotation.Nullable; @@ -248,8 +247,10 @@ TestActionContext getTestActionContext() { * *

TODO(b/213040766): Write tests for these setup steps. */ - public void prepareForExecution(UUID buildId) - throws AbruptExitException, BuildFailedException, InterruptedException, + public void prepareForExecution(UUID buildId, Stopwatch executionTimer) + throws AbruptExitException, + BuildFailedException, + InterruptedException, InvalidConfigurationException { init(); BuildRequestOptions buildRequestOptions = request.getBuildOptions(); @@ -327,7 +328,8 @@ public void prepareForExecution(UUID buildId) env.getReporter(), executor, request, skyframeBuilder.getActionCacheChecker()); } - env.getEventBus().register(new ExecutionProgressReceiverSetup(skyframeExecutor, env)); + env.getEventBus() + .register(new ExecutionProgressReceiverSetup(skyframeExecutor, env, executionTimer)); // TODO(leba): Add watchdog support. for (ExecutorLifecycleListener executorLifecycleListener : executorLifecycleListeners) { try (SilentCloseable c = @@ -558,7 +560,7 @@ void nonCatastrophicFinalizations( * catastrophe or not. */ void unconditionalExecutionPhaseFinalizations( - Stopwatch timer, SkyframeExecutor skyframeExecutor) { + Stopwatch executionTimer, SkyframeExecutor skyframeExecutor) { // These may flush logs, which may help if there is a catastrophic failure. for (ExecutorLifecycleListener executorLifecycleListener : executorLifecycleListeners) { executorLifecycleListener.executionPhaseEnding(); @@ -568,8 +570,16 @@ void unconditionalExecutionPhaseFinalizations( // a catastrophic failure. Posting these is consistent with other behavior. env.getEventBus().post(skyframeExecutor.createExecutionFinishedEvent()); - env.getEventBus() - .post(new ExecutionPhaseCompleteEvent(timer.stop().elapsed(TimeUnit.MILLISECONDS))); + // With Skymeld, the timer is started with the first execution activity in the build and ends + // when the build is done. A running timer indicates that some execution activity happened. + // + // Sometimes there's no execution in the build: e.g. when there's only 1 target, and we fail at + // the analysis phase. In such a case, we shouldn't send out this event. This is consistent with + // the noskymeld behavior. + if (executionTimer.isRunning()) { + env.getEventBus() + .post(new ExecutionPhaseCompleteEvent(executionTimer.stop().elapsed().toMillis())); + } } private void prepare(PackageRoots packageRoots) throws AbruptExitException, InterruptedException { @@ -983,11 +993,17 @@ private static AbruptExitException createExitException( private static class ExecutionProgressReceiverSetup { private final SkyframeExecutor skyframeExecutor; private final CommandEnvironment env; + + private final Stopwatch executionUnstartedTimer; private final AtomicBoolean activated = new AtomicBoolean(false); - ExecutionProgressReceiverSetup(SkyframeExecutor skyframeExecutor, CommandEnvironment env) { + ExecutionProgressReceiverSetup( + SkyframeExecutor skyframeExecutor, + CommandEnvironment env, + Stopwatch executionUnstartedTimer) { this.skyframeExecutor = skyframeExecutor; this.env = env; + this.executionUnstartedTimer = executionUnstartedTimer; } @Subscribe @@ -1009,6 +1025,7 @@ public void setupExecutionProgressReceiver(SomeExecutionStartedEvent unused) { skyframeExecutor.setActionExecutionProgressReportingObjects( executionProgressReceiver, executionProgressReceiver, statusReporter); skyframeExecutor.setExecutionProgressReceiver(executionProgressReceiver); + executionUnstartedTimer.start(); env.getEventBus().unregister(this); }