Remote: Display download progress when actions are downloading outputs from remote cache.
Normally, when executing action with remote cache/execution, the UI only display the "remote"/"remote-cache" strategy:
```
[500 / 1000] 500 actions, 3 running
[Sched] Executing genrule //:test-1;
Executing genrule //:test-2; 2s remote
Executing genrule //:test-3; 3s remote ...
```
However, it doesn't tell users what is happening under the hood. #13555 fixed the confusion which the UI display the action is scheduling while it is actually downloading the outputs.
With this change, Bazel will display the downloads if action is downloading outputs. e.g.
```
[500 / 1000] 500 actions, 3 running
[Sched] Executing genrule //:test-1; 1s remote
Executing genrule //:test-2; Downloading 2.out, 20.1 KiB / 100 KiB; 2s remote
Executing genrule //:test-3; 3s remote ...
```
Add a generic `ActionProgressEvent` which can be reported within action execution to display detailed execution progress for that action.
Closes #13557.
PiperOrigin-RevId: 383224334
diff --git a/src/main/java/com/google/devtools/build/lib/actions/ActionProgressEvent.java b/src/main/java/com/google/devtools/build/lib/actions/ActionProgressEvent.java
new file mode 100644
index 0000000..72e4502
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/actions/ActionProgressEvent.java
@@ -0,0 +1,39 @@
+// Copyright 2021 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.auto.value.AutoValue;
+import com.google.devtools.build.lib.events.ExtendedEventHandler.ProgressLike;
+
+/** Notifications for the progress of an in-flight action. */
+@AutoValue
+public abstract class ActionProgressEvent implements ProgressLike {
+
+ public static ActionProgressEvent create(
+ ActionExecutionMetadata action, String progressId, String progress, boolean finished) {
+ return new AutoValue_ActionProgressEvent(action, progressId, progress, finished);
+ }
+
+ /** Gets the metadata associated with the action being scheduled. */
+ public abstract ActionExecutionMetadata action();
+
+ /** The id that uniquely determines the progress among all progress events within an action. */
+ public abstract String progressId();
+
+ /** Human readable description of the progress. */
+ public abstract String progress();
+
+ /** Whether the download progress reported about is finished already. */
+ public abstract boolean finished();
+}
diff --git a/src/main/java/com/google/devtools/build/lib/exec/AbstractSpawnStrategy.java b/src/main/java/com/google/devtools/build/lib/exec/AbstractSpawnStrategy.java
index 390ca1e..a56b839 100644
--- a/src/main/java/com/google/devtools/build/lib/exec/AbstractSpawnStrategy.java
+++ b/src/main/java/com/google/devtools/build/lib/exec/AbstractSpawnStrategy.java
@@ -328,7 +328,6 @@
return;
}
- // TODO(ulfjack): We should report more details to the UI.
ExtendedEventHandler eventHandler = actionExecutionContext.getEventHandler();
progress.postTo(eventHandler, action);
}
diff --git a/src/main/java/com/google/devtools/build/lib/exec/BUILD b/src/main/java/com/google/devtools/build/lib/exec/BUILD
index 62e9e8c..50abdb5 100644
--- a/src/main/java/com/google/devtools/build/lib/exec/BUILD
+++ b/src/main/java/com/google/devtools/build/lib/exec/BUILD
@@ -269,6 +269,7 @@
srcs = [
"SpawnCheckingCacheEvent.java",
"SpawnExecutingEvent.java",
+ "SpawnProgressEvent.java",
"SpawnRunner.java",
"SpawnSchedulingEvent.java",
],
diff --git a/src/main/java/com/google/devtools/build/lib/exec/SpawnProgressEvent.java b/src/main/java/com/google/devtools/build/lib/exec/SpawnProgressEvent.java
new file mode 100644
index 0000000..9ddde03
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/exec/SpawnProgressEvent.java
@@ -0,0 +1,43 @@
+// Copyright 2021 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.exec;
+
+import com.google.auto.value.AutoValue;
+import com.google.devtools.build.lib.actions.ActionExecutionMetadata;
+import com.google.devtools.build.lib.actions.ActionProgressEvent;
+import com.google.devtools.build.lib.events.ExtendedEventHandler;
+import com.google.devtools.build.lib.exec.SpawnRunner.ProgressStatus;
+
+/** The {@link SpawnRunner} is making some progress. */
+@AutoValue
+public abstract class SpawnProgressEvent implements ProgressStatus {
+
+ public static SpawnProgressEvent create(String resourceId, String progress, boolean finished) {
+ return new AutoValue_SpawnProgressEvent(resourceId, progress, finished);
+ }
+
+ /** The id that uniquely determines the progress among all progress events for this spawn. */
+ abstract String progressId();
+
+ /** Human readable description of the progress. */
+ abstract String progress();
+
+ /** Whether the progress reported about is finished already. */
+ abstract boolean finished();
+
+ @Override
+ public void postTo(ExtendedEventHandler eventHandler, ActionExecutionMetadata action) {
+ eventHandler.post(ActionProgressEvent.create(action, progressId(), progress(), finished()));
+ }
+}
diff --git a/src/main/java/com/google/devtools/build/lib/remote/RemoteCache.java b/src/main/java/com/google/devtools/build/lib/remote/RemoteCache.java
index 2ac8029..d978ad6 100644
--- a/src/main/java/com/google/devtools/build/lib/remote/RemoteCache.java
+++ b/src/main/java/com/google/devtools/build/lib/remote/RemoteCache.java
@@ -15,6 +15,8 @@
import static com.google.common.util.concurrent.Futures.immediateFuture;
import static com.google.common.util.concurrent.MoreExecutors.directExecutor;
+import static com.google.devtools.build.lib.remote.common.ProgressStatusListener.NO_ACTION;
+import static com.google.devtools.build.lib.remote.util.Utils.bytesCountToDisplayString;
import static com.google.devtools.build.lib.remote.util.Utils.getFromFuture;
import build.bazel.remote.execution.v2.Action;
@@ -50,6 +52,7 @@
import com.google.devtools.build.lib.actions.UserExecException;
import com.google.devtools.build.lib.actions.cache.MetadataInjector;
import com.google.devtools.build.lib.concurrent.ThreadSafety;
+import com.google.devtools.build.lib.exec.SpawnProgressEvent;
import com.google.devtools.build.lib.exec.SpawnRunner.SpawnExecutionContext;
import com.google.devtools.build.lib.profiler.Profiler;
import com.google.devtools.build.lib.profiler.SilentCloseable;
@@ -58,6 +61,7 @@
import com.google.devtools.build.lib.remote.RemoteCache.ActionResultMetadata.SymlinkMetadata;
import com.google.devtools.build.lib.remote.common.LazyFileOutputStream;
import com.google.devtools.build.lib.remote.common.OutputDigestMismatchException;
+import com.google.devtools.build.lib.remote.common.ProgressStatusListener;
import com.google.devtools.build.lib.remote.common.RemoteActionExecutionContext;
import com.google.devtools.build.lib.remote.common.RemoteActionFileArtifactValue;
import com.google.devtools.build.lib.remote.common.RemoteCacheClient;
@@ -91,6 +95,9 @@
import java.util.List;
import java.util.Map;
import java.util.Map.Entry;
+import java.util.concurrent.atomic.AtomicLong;
+import java.util.regex.Matcher;
+import java.util.regex.Pattern;
import java.util.stream.Collectors;
import java.util.stream.Stream;
import javax.annotation.Nullable;
@@ -314,6 +321,50 @@
return actualPath.getParentDirectory().getRelative(actualPath.getBaseName() + ".tmp");
}
+ static class DownloadProgressReporter {
+ private static final Pattern PATTERN = Pattern.compile("^bazel-out/[^/]+/[^/]+/");
+ private final ProgressStatusListener listener;
+ private final String id;
+ private final String file;
+ private final String totalSize;
+ private final AtomicLong downloadedBytes = new AtomicLong(0);
+
+ DownloadProgressReporter(ProgressStatusListener listener, String file, long totalSize) {
+ this.listener = listener;
+ this.id = file;
+ this.totalSize = bytesCountToDisplayString(totalSize);
+
+ Matcher matcher = PATTERN.matcher(file);
+ this.file = matcher.replaceFirst("");
+ }
+
+ void started() {
+ reportProgress(false, false);
+ }
+
+ void downloadedBytes(int count) {
+ downloadedBytes.addAndGet(count);
+ reportProgress(true, false);
+ }
+
+ void finished() {
+ reportProgress(true, true);
+ }
+
+ private void reportProgress(boolean includeBytes, boolean finished) {
+ String progress;
+ if (includeBytes) {
+ progress =
+ String.format(
+ "Downloading %s, %s / %s",
+ file, bytesCountToDisplayString(downloadedBytes.get()), totalSize);
+ } else {
+ progress = String.format("Downloading %s", file);
+ }
+ listener.onProgressStatus(SpawnProgressEvent.create(id, progress, finished));
+ }
+ }
+
/**
* Download the output files and directory trees of a remotely executed action to the local
* machine, as well stdin / stdout to the given files.
@@ -330,7 +381,8 @@
RemotePathResolver remotePathResolver,
ActionResult result,
FileOutErr origOutErr,
- OutputFilesLocker outputFilesLocker)
+ OutputFilesLocker outputFilesLocker,
+ ProgressStatusListener progressStatusListener)
throws ExecException, IOException, InterruptedException {
ActionResultMetadata metadata = parseActionResultMetadata(context, remotePathResolver, result);
@@ -347,7 +399,11 @@
context,
remotePathResolver.localPathToOutputPath(file.path()),
toTmpDownloadPath(file.path()),
- file.digest());
+ file.digest(),
+ new DownloadProgressReporter(
+ progressStatusListener,
+ remotePathResolver.localPathToOutputPath(file.path()),
+ file.digest().getSizeBytes()));
return Futures.transform(download, (d) -> file, directExecutor());
} catch (IOException e) {
return Futures.<FileMetadata>immediateFailedFuture(e);
@@ -499,10 +555,14 @@
}
public ListenableFuture<Void> downloadFile(
- RemoteActionExecutionContext context, String outputPath, Path localPath, Digest digest)
+ RemoteActionExecutionContext context,
+ String outputPath,
+ Path localPath,
+ Digest digest,
+ DownloadProgressReporter reporter)
throws IOException {
SettableFuture<Void> outerF = SettableFuture.create();
- ListenableFuture<Void> f = downloadFile(context, localPath, digest);
+ ListenableFuture<Void> f = downloadFile(context, localPath, digest, reporter);
Futures.addCallback(
f,
new FutureCallback<Void>() {
@@ -529,6 +589,16 @@
/** Downloads a file (that is not a directory). The content is fetched from the digest. */
public ListenableFuture<Void> downloadFile(
RemoteActionExecutionContext context, Path path, Digest digest) throws IOException {
+ return downloadFile(context, path, digest, new DownloadProgressReporter(NO_ACTION, "", 0));
+ }
+
+ /** Downloads a file (that is not a directory). The content is fetched from the digest. */
+ public ListenableFuture<Void> downloadFile(
+ RemoteActionExecutionContext context,
+ Path path,
+ Digest digest,
+ DownloadProgressReporter reporter)
+ throws IOException {
Preconditions.checkNotNull(path.getParentDirectory()).createDirectoryAndParents();
if (digest.getSizeBytes() == 0) {
// Handle empty file locally.
@@ -549,7 +619,9 @@
return COMPLETED_SUCCESS;
}
- OutputStream out = new LazyFileOutputStream(path);
+ reporter.started();
+ OutputStream out = new ReportingOutputStream(new LazyFileOutputStream(path), reporter);
+
SettableFuture<Void> outerF = SettableFuture.create();
ListenableFuture<Void> f = cacheProtocol.downloadBlob(context, digest, out);
Futures.addCallback(
@@ -560,6 +632,7 @@
try {
out.close();
outerF.set(null);
+ reporter.finished();
} catch (IOException e) {
outerF.setException(e);
} catch (RuntimeException e) {
@@ -572,6 +645,7 @@
public void onFailure(Throwable t) {
try {
out.close();
+ reporter.finished();
} catch (IOException e) {
if (t != e) {
t.addSuppressed(e);
@@ -1100,6 +1174,49 @@
.build();
}
+ /**
+ * An {@link OutputStream} that reports all the write operations with {@link
+ * DownloadProgressReporter}.
+ */
+ private static class ReportingOutputStream extends OutputStream {
+
+ private final OutputStream out;
+ private final DownloadProgressReporter reporter;
+
+ ReportingOutputStream(OutputStream out, DownloadProgressReporter reporter) {
+ this.out = out;
+ this.reporter = reporter;
+ }
+
+ @Override
+ public void write(byte[] b) throws IOException {
+ out.write(b);
+ reporter.downloadedBytes(b.length);
+ }
+
+ @Override
+ public void write(byte[] b, int off, int len) throws IOException {
+ out.write(b, off, len);
+ reporter.downloadedBytes(len);
+ }
+
+ @Override
+ public void write(int b) throws IOException {
+ out.write(b);
+ reporter.downloadedBytes(1);
+ }
+
+ @Override
+ public void flush() throws IOException {
+ out.flush();
+ }
+
+ @Override
+ public void close() throws IOException {
+ out.close();
+ }
+ }
+
/** In-memory representation of action result metadata. */
static class ActionResultMetadata {
diff --git a/src/main/java/com/google/devtools/build/lib/remote/RemoteExecutionService.java b/src/main/java/com/google/devtools/build/lib/remote/RemoteExecutionService.java
index 6196a7c..22e7086 100644
--- a/src/main/java/com/google/devtools/build/lib/remote/RemoteExecutionService.java
+++ b/src/main/java/com/google/devtools/build/lib/remote/RemoteExecutionService.java
@@ -386,7 +386,8 @@
remotePathResolver,
result.actionResult,
action.spawnExecutionContext.getFileOutErr(),
- action.spawnExecutionContext::lockOutputFiles);
+ action.spawnExecutionContext::lockOutputFiles,
+ action.spawnExecutionContext::report);
} else {
PathFragment inMemoryOutputPath = getInMemoryOutputPath(action.spawn);
inMemoryOutput =
diff --git a/src/main/java/com/google/devtools/build/lib/remote/common/ProgressStatusListener.java b/src/main/java/com/google/devtools/build/lib/remote/common/ProgressStatusListener.java
new file mode 100644
index 0000000..df5a8be
--- /dev/null
+++ b/src/main/java/com/google/devtools/build/lib/remote/common/ProgressStatusListener.java
@@ -0,0 +1,29 @@
+// Copyright 2021 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.remote.common;
+
+import com.google.devtools.build.lib.exec.SpawnRunner.ProgressStatus;
+
+/** An interface that is used to receive {@link ProgressStatus} updates during spawn execution. */
+@FunctionalInterface
+public interface ProgressStatusListener {
+
+ void onProgressStatus(ProgressStatus progress);
+
+ /** A {@link ProgressStatusListener} that does nothing. */
+ ProgressStatusListener NO_ACTION =
+ progress -> {
+ // Intentionally left empty
+ };
+}
diff --git a/src/main/java/com/google/devtools/build/lib/remote/util/Utils.java b/src/main/java/com/google/devtools/build/lib/remote/util/Utils.java
index 1a2d809..acacffd 100644
--- a/src/main/java/com/google/devtools/build/lib/remote/util/Utils.java
+++ b/src/main/java/com/google/devtools/build/lib/remote/util/Utils.java
@@ -22,6 +22,7 @@
import com.google.common.base.Ascii;
import com.google.common.base.Preconditions;
import com.google.common.base.Throwables;
+import com.google.common.collect.ImmutableList;
import com.google.common.collect.ImmutableSet;
import com.google.common.util.concurrent.AsyncCallable;
import com.google.common.util.concurrent.FluentFuture;
@@ -61,6 +62,7 @@
import java.io.ByteArrayOutputStream;
import java.io.IOException;
import java.io.OutputStream;
+import java.text.DecimalFormat;
import java.util.Arrays;
import java.util.Collection;
import java.util.Locale;
@@ -509,4 +511,30 @@
throw new AssertionError(e);
}
}
+
+ private static final ImmutableList<String> UNITS = ImmutableList.of("KiB", "MiB", "GiB", "TiB");
+
+ /**
+ * Converts the number of bytes to a human readable string, e.g. 1024 -> 1 KiB.
+ *
+ * <p>Negative numbers are not allowed.
+ */
+ public static String bytesCountToDisplayString(long bytes) {
+ Preconditions.checkArgument(bytes >= 0);
+
+ if (bytes < 1024) {
+ return bytes + " B";
+ }
+
+ int unitIndex = 0;
+ long value = bytes;
+ while ((unitIndex + 1) < UNITS.size() && value >= (1 << 20)) {
+ value >>= 10;
+ unitIndex++;
+ }
+
+ // Format as single digit decimal number, but skipping the trailing .0.
+ DecimalFormat fmt = new DecimalFormat("0.#");
+ return String.format("%s %s", fmt.format(value / 1024.0), UNITS.get(unitIndex));
+ }
}
diff --git a/src/main/java/com/google/devtools/build/lib/runtime/UiEventHandler.java b/src/main/java/com/google/devtools/build/lib/runtime/UiEventHandler.java
index cb52575..1c56e04 100644
--- a/src/main/java/com/google/devtools/build/lib/runtime/UiEventHandler.java
+++ b/src/main/java/com/google/devtools/build/lib/runtime/UiEventHandler.java
@@ -20,6 +20,7 @@
import com.google.common.primitives.Bytes;
import com.google.common.util.concurrent.Uninterruptibles;
import com.google.devtools.build.lib.actions.ActionCompletionEvent;
+import com.google.devtools.build.lib.actions.ActionProgressEvent;
import com.google.devtools.build.lib.actions.ActionScanningCompletedEvent;
import com.google.devtools.build.lib.actions.ActionStartedEvent;
import com.google.devtools.build.lib.actions.CachingActionEvent;
@@ -695,6 +696,13 @@
@Subscribe
@AllowConcurrentEvents
+ public void actionProgress(ActionProgressEvent event) {
+ stateTracker.actionProgress(event);
+ refresh();
+ }
+
+ @Subscribe
+ @AllowConcurrentEvents
public void actionCompletion(ActionScanningCompletedEvent event) {
stateTracker.actionCompletion(event);
refreshSoon();
diff --git a/src/main/java/com/google/devtools/build/lib/runtime/UiStateTracker.java b/src/main/java/com/google/devtools/build/lib/runtime/UiStateTracker.java
index 4fa6985..c709eb3 100644
--- a/src/main/java/com/google/devtools/build/lib/runtime/UiStateTracker.java
+++ b/src/main/java/com/google/devtools/build/lib/runtime/UiStateTracker.java
@@ -25,6 +25,7 @@
import com.google.devtools.build.lib.actions.Action;
import com.google.devtools.build.lib.actions.ActionCompletionEvent;
import com.google.devtools.build.lib.actions.ActionExecutionMetadata;
+import com.google.devtools.build.lib.actions.ActionProgressEvent;
import com.google.devtools.build.lib.actions.ActionScanningCompletedEvent;
import com.google.devtools.build.lib.actions.ActionStartedEvent;
import com.google.devtools.build.lib.actions.Artifact;
@@ -58,6 +59,7 @@
import java.util.Comparator;
import java.util.Deque;
import java.util.HashSet;
+import java.util.LinkedHashMap;
import java.util.List;
import java.util.Map;
import java.util.PriorityQueue;
@@ -215,6 +217,19 @@
*/
int runningStrategiesBitmap = 0;
+ private static class ProgressState {
+ final String id;
+ final long nanoStartTime;
+ ActionProgressEvent latestEvent;
+
+ private ProgressState(String id, long nanoStartTime) {
+ this.id = id;
+ this.nanoStartTime = nanoStartTime;
+ }
+ }
+
+ private final LinkedHashMap<String, ProgressState> runningProgresses = new LinkedHashMap<>();
+
/** Starts tracking the state of an action. */
ActionState(ActionExecutionMetadata action, long nanoStartTime) {
this.action = action;
@@ -304,6 +319,20 @@
nanoStartTime = nanoChangeTime;
}
+ /** Handles the progress event for the action. */
+ synchronized void onProgressEvent(ActionProgressEvent event, long nanoChangeTime) {
+ String id = event.progressId();
+ if (event.finished()) {
+ // a progress is finished, clean it up
+ runningProgresses.remove(id);
+ return;
+ }
+
+ ProgressState state =
+ runningProgresses.computeIfAbsent(id, key -> new ProgressState(key, nanoChangeTime));
+ state.latestEvent = event;
+ }
+
/** Generates a human-readable description of this action's state. */
synchronized String describe() {
if (runningStrategiesBitmap != 0) {
@@ -539,6 +568,13 @@
getActionState(action, actionId, now).setRunning(event.getStrategy(), now);
}
+ void actionProgress(ActionProgressEvent event) {
+ ActionExecutionMetadata action = event.action();
+ Artifact actionId = event.action().getPrimaryOutput();
+ long now = clock.nanoTime();
+ getActionState(action, actionId, now).onProgressEvent(event, now);
+ }
+
void actionCompletion(ActionScanningCompletedEvent event) {
Action action = event.getAction();
Artifact actionId = action.getPrimaryOutput();
@@ -668,6 +704,29 @@
return message.append(allReported ? "]" : postfix).toString();
}
+ private String describeActionProgress(ActionState action, int desiredWidth) {
+ if (action.runningProgresses.isEmpty()) {
+ return "";
+ }
+
+ ActionState.ProgressState state =
+ action.runningProgresses.entrySet().iterator().next().getValue();
+ ActionProgressEvent event = state.latestEvent;
+ String message = event.progress();
+ if (message.isEmpty()) {
+ message = state.id;
+ }
+
+ message = "; " + message;
+
+ if (desiredWidth <= 0 || message.length() <= desiredWidth) {
+ return message;
+ }
+
+ message = message.substring(0, desiredWidth - ELLIPSIS.length()) + ELLIPSIS;
+ return message;
+ }
+
// Describe an action by a string of the desired length; if describing that action includes
// describing other actions, add those to the to set of actions to skip in further samples of
// actions.
@@ -721,9 +780,24 @@
message = action.prettyPrint();
}
- if (desiredWidth <= 0) {
- return prefix + message + postfix;
+ String progress = describeActionProgress(actionState, 0);
+
+ if (desiredWidth <= 0
+ || (prefix.length() + message.length() + progress.length() + postfix.length())
+ <= desiredWidth) {
+ return prefix + message + progress + postfix;
}
+
+ // We have to shorten the progress to fit into the line.
+ int remainingWidthForProgress =
+ desiredWidth - prefix.length() - message.length() - postfix.length();
+ int minWidthForProgress = 7; // "; " + at least two character + "..."
+ if (remainingWidthForProgress >= minWidthForProgress) {
+ progress = describeActionProgress(actionState, remainingWidthForProgress);
+ return prefix + message + progress + postfix;
+ }
+
+ // We have to skip the progress to fit into the line.
if (prefix.length() + message.length() + postfix.length() <= desiredWidth) {
return prefix + message + postfix;
}