Skip to content

Commit

Permalink
Set runners for critical path where no spawn was actually executed.
Browse files Browse the repository at this point in the history
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
  • Loading branch information
larsrc-google authored and copybara-github committed Mar 6, 2023
1 parent 38ece3c commit d5b4c1b
Show file tree
Hide file tree
Showing 2 changed files with 16 additions and 7 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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.
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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");
}

/**
Expand Down Expand Up @@ -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");
}

/**
Expand All @@ -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, "");
}

/**
Expand All @@ -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. */
Expand All @@ -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);
Expand All @@ -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);
}

Expand Down

0 comments on commit d5b4c1b

Please sign in to comment.