BES: Report upload wait time afterwards
It might be nicer to tell the user that we're going to wait, but that is
not currently possible. Instead, tell the user that Bazel waited for
upload to complete for a certain amount of time.
Updated test to avoid being too specific.
PiperOrigin-RevId: 249458848
diff --git a/src/main/java/com/google/devtools/build/lib/buildeventservice/BuildEventServiceModule.java b/src/main/java/com/google/devtools/build/lib/buildeventservice/BuildEventServiceModule.java
index 205031a..b422d48 100644
--- a/src/main/java/com/google/devtools/build/lib/buildeventservice/BuildEventServiceModule.java
+++ b/src/main/java/com/google/devtools/build/lib/buildeventservice/BuildEventServiceModule.java
@@ -16,6 +16,7 @@
import com.google.common.annotations.VisibleForTesting;
import com.google.common.base.Preconditions;
+import com.google.common.base.Stopwatch;
import com.google.common.base.Strings;
import com.google.common.base.Supplier;
import com.google.common.base.Suppliers;
@@ -129,7 +130,7 @@
@Nullable private ImmutableSet<BuildEventTransport> bepTransports;
@Nullable private String buildRequestId;
@Nullable private String invocationId;
- @Nullable private Reporter cmdLineReporter;
+ @Nullable private Reporter reporter;
@Nullable private BuildEventStreamer streamer;
@Nullable private ConnectivityStatusProvider connectivityProvider;
private static final String CONNECTIVITY_CACHE_KEY = "BES";
@@ -189,9 +190,10 @@
return;
}
+ Stopwatch stopwatch = Stopwatch.createStarted();
try {
- // TODO(b/234994611): Find a way to print a meaningful message when waiting. The current
- // infrastructure doesn't allow printing messages in the terminal in beforeCommand.
+ // TODO(b/234994611): It would be better to report before we wait, but the current
+ // infrastructure does not support that. At least we can report it afterwards.
ImmutableMap<BuildEventTransport, ListenableFuture<Void>> futureMap =
besOptions.besUploadMode == BesUploadMode.FULLY_ASYNC
? halfCloseFuturesWithTimeoutsMap
@@ -200,26 +202,43 @@
Futures.allAsList(futureMap.values()),
getMaxWaitForPreviousInvocation().getSeconds(),
TimeUnit.SECONDS);
+ long waitedMillis = stopwatch.elapsed().toMillis();
+ if (waitedMillis > 100) {
+ reporter.handle(
+ Event.info(
+ String.format(
+ "Waited for the background upload of the Build Event Protocol for "
+ + "%d.%03d seconds.",
+ waitedMillis / 1000, waitedMillis % 1000)));
+ }
} catch (TimeoutException exception) {
+ long waitedMillis = stopwatch.elapsed().toMillis();
String msg =
String.format(
- "Pending Build Event Protocol upload took more than %ds to finish. "
+ "The background upload of the Build Event Protocol for the previous invocation "
+ + "failed to complete in %d.%03d seconds. "
+ "Cancelling and starting a new invocation...",
- getMaxWaitForPreviousInvocation().getSeconds());
- cmdLineReporter.handle(Event.warn(msg));
+ waitedMillis / 1000, waitedMillis % 1000);
+ reporter.handle(Event.warn(msg));
googleLogger.atWarning().withCause(exception).log(msg);
} catch (ExecutionException e) {
+ String msg;
// Futures.withTimeout wraps the TimeoutException in an ExecutionException when the future
// times out.
- String previousExceptionMsg =
- isTimeoutException(e) ? "The Build Event Protocol upload timed out" : e.getMessage();
- String msg =
- String.format(
- "Previous invocation failed to finish Build Event Protocol upload "
- + "with the following exception: '%s'. "
- + "Ignoring the failure and starting a new invocation...",
- previousExceptionMsg);
- cmdLineReporter.handle(Event.warn(msg));
+ if (isTimeoutException(e)) {
+ msg =
+ "The background upload of the Build Event Protocol for the previous invocation "
+ + "failed due to a network timeout. Ignoring the failure and starting a new "
+ + "invocation...";
+ } else {
+ msg =
+ String.format(
+ "The background upload of the Build Event Protocol for the previous invocation "
+ + "failed with the following exception: '%s'. "
+ + "Ignoring the failure and starting a new invocation...",
+ e.getMessage());
+ }
+ reporter.handle(Event.warn(msg));
googleLogger.atWarning().withCause(e).log(msg);
} finally {
cancelPendingUploads();
@@ -230,7 +249,7 @@
public void beforeCommand(CommandEnvironment cmdEnv) {
this.invocationId = cmdEnv.getCommandId().toString();
this.buildRequestId = cmdEnv.getBuildRequestId();
- this.cmdLineReporter = cmdEnv.getReporter();
+ this.reporter = cmdEnv.getReporter();
for (BlazeModule module : cmdEnv.getRuntime().getBlazeModules()) {
if (module instanceof ConnectivityStatusProvider) {
@@ -300,7 +319,7 @@
// This event should probably be posted in a more general place (e.g. {@link BuildTool};
// however, so far the BES module is the only module that requires extra work after the build
// so we post it here until it's needed for other modules.
- cmdLineReporter.post(new AnnounceBuildEventTransportsEvent(bepTransports));
+ reporter.post(new AnnounceBuildEventTransportsEvent(bepTransports));
}
private void registerOutAndErrOutputStreams() {
@@ -374,7 +393,7 @@
}
private void reportWaitingForBesMessage(Instant startTime) {
- cmdLineReporter.handle(
+ reporter.handle(
Event.progress(
"Waiting for Build Event Protocol upload. Waited "
+ Duration.between(startTime, Instant.now()).getSeconds()
@@ -396,11 +415,11 @@
(bepTransport, closeFuture) ->
closeFuture.addListener(
() -> {
- cmdLineReporter.post(new BuildEventTransportClosedEvent(bepTransport));
+ reporter.post(new BuildEventTransportClosedEvent(bepTransport));
},
executor));
} else {
- cmdLineReporter.handle(Event.progress("Waiting for Build Event Protocol upload..."));
+ reporter.handle(Event.progress("Waiting for Build Event Protocol upload..."));
Instant startTime = Instant.now();
waitMessageFuture =
executor.scheduleAtFixedRate(
@@ -493,7 +512,7 @@
// When running asynchronously notify the UI immediately since we won't wait for the
// uploads to close.
for (BuildEventTransport bepTransport : bepTransports) {
- cmdLineReporter.post(new BuildEventTransportClosedEvent(bepTransport));
+ reporter.post(new BuildEventTransportClosedEvent(bepTransport));
}
return;
}
@@ -517,7 +536,7 @@
if (!Strings.isNullOrEmpty(besOptions.besBackend)) {
constructAndMaybeReportInvocationIdUrl();
} else if (!bepTransports.isEmpty()) {
- cmdLineReporter.handle(Event.info("Build Event Protocol files produced successfully."));
+ reporter.handle(Event.info("Build Event Protocol files produced successfully."));
}
}
@@ -532,20 +551,20 @@
this.bepTransports = null;
this.invocationId = null;
this.buildRequestId = null;
- this.cmdLineReporter = null;
+ this.reporter = null;
this.streamer = null;
}
private void constructAndMaybeReportInvocationIdUrl() {
if (!getInvocationIdPrefix().isEmpty()) {
- cmdLineReporter.handle(
+ reporter.handle(
Event.info("Streaming build results to: " + getInvocationIdPrefix() + invocationId));
}
}
private void constructAndMaybeReportBuildRequestIdUrl() {
if (!getBuildRequestIdPrefix().isEmpty()) {
- cmdLineReporter.handle(
+ reporter.handle(
Event.info(
"See "
+ getBuildRequestIdPrefix()
@@ -555,7 +574,7 @@
}
private void constructAndReportIds() {
- cmdLineReporter.handle(
+ reporter.handle(
Event.info(
String.format(
"Streaming Build Event Protocol to '%s' with build_request_id: '%s'"
@@ -580,7 +599,7 @@
+ "that are too big for the Build Event Service to handle.",
RUNS_PER_TEST_LIMIT);
reportError(
- cmdLineReporter,
+ reporter,
cmdEnv.getBlazeModuleEnvironment(),
msg,
new OptionsParsingException(msg),
@@ -597,7 +616,7 @@
String.format(
"Build Event Service uploads disabled due to a connectivity problem: %s",
status.toString());
- cmdLineReporter.handle(Event.warn(message));
+ reporter.handle(Event.warn(message));
googleLogger.atWarning().log(message);
return null;
}
@@ -607,7 +626,7 @@
besClient = getBesClient(besOptions, authTlsOptions);
} catch (IOException | OptionsParsingException e) {
reportError(
- cmdLineReporter,
+ reporter,
cmdEnv.getBlazeModuleEnvironment(),
e.getMessage(),
e,
@@ -662,7 +681,7 @@
// TODO(b/125216340): Consider making this a warning instead of an error once the
// associated bug has been resolved.
reportError(
- cmdLineReporter,
+ reporter,
cmdEnv.getBlazeModuleEnvironment(),
"Unable to write to '"
+ besStreamOptions.buildEventTextFile
@@ -692,7 +711,7 @@
// TODO(b/125216340): Consider making this a warning instead of an error once the
// associated bug has been resolved.
reportError(
- cmdLineReporter,
+ reporter,
cmdEnv.getBlazeModuleEnvironment(),
"Unable to write to '"
+ besStreamOptions.buildEventBinaryFile
@@ -721,7 +740,7 @@
// TODO(b/125216340): Consider making this a warning instead of an error once the
// associated bug has been resolved.
reportError(
- cmdLineReporter,
+ reporter,
cmdEnv.getBlazeModuleEnvironment(),
"Unable to write to '"
+ besStreamOptions.buildEventJsonFile
