Skip to content

Commit

Permalink
[Skymeld] Make the execution timer more precise.
Browse files Browse the repository at this point in the history
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
  • Loading branch information
joeleba authored and copybara-github committed Mar 24, 2023
1 parent aa4f358 commit 09adb34
Show file tree
Hide file tree
Showing 2 changed files with 30 additions and 12 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -337,7 +337,7 @@ private void buildTargetsWithMergedAnalysisExecution(
request,
buildOptions,
loadingResult,
() -> executionTool.prepareForExecution(request.getId()),
() -> executionTool.prepareForExecution(request.getId(), executionTimer),
result::setBuildConfiguration,
new BuildDriverKeyTestContext() {
@Override
Expand Down Expand Up @@ -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();
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;

Expand Down Expand Up @@ -248,8 +247,10 @@ TestActionContext getTestActionContext() {
*
* <p>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();
Expand Down Expand Up @@ -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 =
Expand Down Expand Up @@ -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();
Expand All @@ -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 {
Expand Down Expand Up @@ -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
Expand All @@ -1009,6 +1025,7 @@ public void setupExecutionProgressReceiver(SomeExecutionStartedEvent unused) {
skyframeExecutor.setActionExecutionProgressReportingObjects(
executionProgressReceiver, executionProgressReceiver, statusReporter);
skyframeExecutor.setExecutionProgressReceiver(executionProgressReceiver);
executionUnstartedTimer.start();

env.getEventBus().unregister(this);
}
Expand Down

0 comments on commit 09adb34

Please sign in to comment.