Skip to content

Commit

Permalink
Properly report repo fetch progress during main repo mapping computation
Browse files Browse the repository at this point in the history
This ends up as simple as firing an event and letting UiEventHandler know that the build has started.

Fixes bazelbuild#16927.

Fixes bazelbuild#16338.

PiperOrigin-RevId: 511177491
Change-Id: I479b116cf896731b7238410ce14f7e249da6c390
  • Loading branch information
Wyverald authored and copybara-github committed Feb 21, 2023
1 parent 9b26a11 commit 51e6c38
Show file tree
Hide file tree
Showing 8 changed files with 127 additions and 40 deletions.
Original file line number Diff line number Diff line change
@@ -0,0 +1,21 @@
// Copyright 2023 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.buildtool.buildevent;

/**
* Event fired right before main repo mapping computation starts (between the two rounds of option
* parsing).
*/
public class MainRepoMappingComputationStartingEvent {}
Original file line number Diff line number Diff line change
Expand Up @@ -32,6 +32,7 @@
import com.google.devtools.build.lib.bugreport.Crash;
import com.google.devtools.build.lib.bugreport.CrashContext;
import com.google.devtools.build.lib.buildeventstream.BuildEventProtocolOptions;
import com.google.devtools.build.lib.buildtool.buildevent.MainRepoMappingComputationStartingEvent;
import com.google.devtools.build.lib.buildtool.buildevent.ProfilerStartedEvent;
import com.google.devtools.build.lib.clock.BlazeClock;
import com.google.devtools.build.lib.cmdline.RepositoryMapping;
Expand Down Expand Up @@ -547,6 +548,7 @@ private BlazeCommandResult execExclusively(

// Compute the repo mapping of the main repo and re-parse options so that we get correct
// values for label-typed options.
env.getEventBus().post(new MainRepoMappingComputationStartingEvent());
try {
RepositoryMapping mainRepoMapping =
env.getSkyframeExecutor().getMainRepoMapping(reporter);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -35,6 +35,7 @@ enum BuildStatus {
// We explicitly define a starting status, which can be used to determine what to display in
// cases before the build has started.
BUILD_NOT_STARTED,
COMPUTING_MAIN_REPO_MAPPING,
BUILD_STARTED,
TARGET_PATTERN_PARSING,
LOADING_COMPLETE,
Expand Down Expand Up @@ -77,6 +78,9 @@ synchronized void writeProgressBar(
switch (buildStatus) {
case BUILD_NOT_STARTED:
return;
case COMPUTING_MAIN_REPO_MAPPING:
writeBaseProgress("Computing main repo mapping", "", terminalWriter);
break;
case BUILD_STARTED:
writeBaseProgress("Loading", "", terminalWriter);
break;
Expand Down Expand Up @@ -151,6 +155,11 @@ void writeLoadingAnalysisPhaseProgress(
}
}

@Override
void mainRepoMappingComputationStarted() {
buildStatus = BuildStatus.COMPUTING_MAIN_REPO_MAPPING;
}

@Override
void buildStarted() {
buildStatus = BuildStatus.BUILD_STARTED;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -40,6 +40,7 @@
import com.google.devtools.build.lib.buildtool.buildevent.BuildCompleteEvent;
import com.google.devtools.build.lib.buildtool.buildevent.BuildStartingEvent;
import com.google.devtools.build.lib.buildtool.buildevent.ExecutionProgressReceiverAvailableEvent;
import com.google.devtools.build.lib.buildtool.buildevent.MainRepoMappingComputationStartingEvent;
import com.google.devtools.build.lib.buildtool.buildevent.TestFilteringCompleteEvent;
import com.google.devtools.build.lib.clock.Clock;
import com.google.devtools.build.lib.events.Event;
Expand Down Expand Up @@ -517,7 +518,7 @@ private void setEventKindColor(EventKind kind) throws IOException {
}

@Subscribe
public void buildStarted(BuildStartingEvent event) {
public void mainRepoMappingComputationStarted(MainRepoMappingComputationStartingEvent event) {
synchronized (this) {
buildRunning = true;
}
Expand All @@ -526,6 +527,16 @@ public void buildStarted(BuildStartingEvent event) {
// As a new phase started, inform immediately.
ignoreRefreshLimitOnce();
refresh();
startUpdateThread();
}

@Subscribe
public void buildStarted(BuildStartingEvent event) {
maybeAddDate();
stateTracker.buildStarted();
// As a new phase started, inform immediately.
ignoreRefreshLimitOnce();
refresh();
}

@Subscribe
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -409,6 +409,11 @@ void setProgressSampleSize(int sampleSize) {
this.sampleSize = Math.max(1, sampleSize);
}

void mainRepoMappingComputationStarted() {
status = "Computing main repo mapping";
additionalMessage = "";
}

void buildStarted() {
status = "Loading";
additionalMessage = "";
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -23,6 +23,7 @@
import com.google.devtools.build.lib.buildtool.BuildResult;
import com.google.devtools.build.lib.buildtool.buildevent.BuildCompleteEvent;
import com.google.devtools.build.lib.buildtool.buildevent.BuildStartingEvent;
import com.google.devtools.build.lib.buildtool.buildevent.MainRepoMappingComputationStartingEvent;
import com.google.devtools.build.lib.events.Event;
import com.google.devtools.build.lib.events.EventKind;
import com.google.devtools.build.lib.testutil.ManualClock;
Expand Down Expand Up @@ -73,23 +74,24 @@ private void createUiEventHandler(UiOptions uiOptions) {
OutErr outErr = null;
switch (testedOutput) {
case STDOUT:
outErr = OutErr.create(/*out=*/ output, /*err=*/ mock(OutputStream.class));
outErr = OutErr.create(/* out= */ output, /* err= */ mock(OutputStream.class));
eventKind = EventKind.STDOUT;
break;
case STDERR:
outErr = OutErr.create(/*out=*/ mock(OutputStream.class), /*err=*/ output);
outErr = OutErr.create(/* out= */ mock(OutputStream.class), /* err= */ output);
eventKind = EventKind.STDERR;
break;
}

uiEventHandler =
new UiEventHandler(outErr, uiOptions, new ManualClock(), /*workspacePathFragment=*/ null);
new UiEventHandler(outErr, uiOptions, new ManualClock(), /* workspacePathFragment= */ null);
uiEventHandler.mainRepoMappingComputationStarted(new MainRepoMappingComputationStartingEvent());
uiEventHandler.buildStarted(
BuildStartingEvent.create(
"outputFileSystemType",
/*usesInMemoryFileSystem=*/ false,
/* usesInMemoryFileSystem= */ false,
mock(BuildRequest.class),
/*workspace=*/ null,
/* workspace= */ null,
"/pwd"));
}

Expand Down Expand Up @@ -205,7 +207,7 @@ public void noChangeOnUnflushedWrite() {
uiOptions.eventFilters = ImmutableList.of();
createUiEventHandler(uiOptions);
if (testedOutput == TestedOutput.STDERR) {
assertThat(output.flushed).hasSize(1);
assertThat(output.flushed).hasSize(2);
output.flushed.clear();
}
// Unterminated strings are saved in memory and not pushed out at all.
Expand All @@ -226,9 +228,9 @@ public void buildCompleteMessageDoesntOverrideError() {
uiEventHandler.handle(Event.error("Show me this!"));
uiEventHandler.afterCommand(new AfterCommandEvent());

assertThat(output.flushed.size()).isEqualTo(4);
assertThat(output.flushed.get(2)).contains("Show me this!");
assertThat(output.flushed.get(3)).doesNotContain("\033[1A\033[K");
assertThat(output.flushed.size()).isEqualTo(5);
assertThat(output.flushed.get(3)).contains("Show me this!");
assertThat(output.flushed.get(4)).doesNotContain("\033[1A\033[K");
}

private Event output(String message) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -1289,59 +1289,89 @@ public void testSuffix() {
}

@Test
public void testDownloadShown() throws Exception {
// Verify that, whenever a single download is running in loading face, it is shown in the status
// bar.
public void testDownloadShown_duringLoading() throws Exception {
// Verify that, whenever a single download is running in loading phase, it is shown in the
// status bar.
ManualClock clock = new ManualClock();
clock.advanceMillis(TimeUnit.SECONDS.toMillis(1234));
UiStateTracker stateTracker = getUiStateTracker(clock, /*targetWidth=*/ 80);
clock.advance(Duration.ofSeconds(1234));
UiStateTracker stateTracker = getUiStateTracker(clock, /* targetWidth= */ 80);

URL url = new URL("http://example.org/first/dep");

stateTracker.buildStarted();
stateTracker.downloadProgress(new DownloadProgressEvent(url));
clock.advanceMillis(TimeUnit.SECONDS.toMillis(6));
clock.advance(Duration.ofSeconds(6));

LoggingTerminalWriter terminalWriter = new LoggingTerminalWriter(/*discardHighlight=*/ true);
LoggingTerminalWriter terminalWriter = new LoggingTerminalWriter(/* discardHighlight= */ true);
stateTracker.writeProgressBar(terminalWriter);
String output = terminalWriter.getTranscript();

assertWithMessage("Progress bar should contain '" + url.toString() + "', but was:\n" + output)
.that(output.contains(url.toString()))
.isTrue();
assertWithMessage("Progress bar should contain '6s', but was:\n" + output)
.that(output.contains("6s"))
.isTrue();
assertThat(output).contains(url.toString());
assertThat(output).contains("6s");

// Progress on the pending download should be reported appropriately
clock.advanceMillis(TimeUnit.SECONDS.toMillis(1));
clock.advance(Duration.ofSeconds(1));
stateTracker.downloadProgress(new DownloadProgressEvent(url, 256));

terminalWriter = new LoggingTerminalWriter(/*discardHighlight=*/ true);
terminalWriter = new LoggingTerminalWriter(/* discardHighlight= */ true);
stateTracker.writeProgressBar(terminalWriter);
output = terminalWriter.getTranscript();

assertWithMessage("Progress bar should contain '" + url.toString() + "', but was:\n" + output)
.that(output.contains(url.toString()))
.isTrue();
assertWithMessage("Progress bar should contain '7s', but was:\n" + output)
.that(output.contains("7s"))
.isTrue();
assertWithMessage("Progress bar should contain '256', but was:\n" + output)
.that(output.contains("256"))
.isTrue();
assertThat(output).contains(url.toString());
assertThat(output).contains("7s");
assertThat(output).contains("256");

// After finishing the download, it should no longer be reported.
clock.advanceMillis(TimeUnit.SECONDS.toMillis(1));
clock.advance(Duration.ofSeconds(1));
stateTracker.downloadProgress(new DownloadProgressEvent(url, 256, true));

terminalWriter = new LoggingTerminalWriter(/*discardHighlight=*/ true);
terminalWriter = new LoggingTerminalWriter(/* discardHighlight= */ true);
stateTracker.writeProgressBar(terminalWriter);
output = terminalWriter.getTranscript();

assertWithMessage("Progress bar should not contain url, but was:\n" + output)
.that(output.contains("example.org"))
.isFalse();
assertThat(output).doesNotContain("example.org");
}

@Test
public void testDownloadShown_duringMainRepoMappingComputation() throws Exception {
ManualClock clock = new ManualClock();
clock.advance(Duration.ofSeconds(1234));
UiStateTracker stateTracker = getUiStateTracker(clock, /* targetWidth= */ 80);

URL url = new URL("http://example.org/first/dep");

stateTracker.mainRepoMappingComputationStarted();
stateTracker.downloadProgress(new DownloadProgressEvent(url));
clock.advance(Duration.ofSeconds(6));

LoggingTerminalWriter terminalWriter = new LoggingTerminalWriter(/* discardHighlight= */ true);
stateTracker.writeProgressBar(terminalWriter);
String output = terminalWriter.getTranscript();

assertThat(output).contains(url.toString());
assertThat(output).contains("6s");

// Progress on the pending download should be reported appropriately
clock.advance(Duration.ofSeconds(1));
stateTracker.downloadProgress(new DownloadProgressEvent(url, 256));

terminalWriter = new LoggingTerminalWriter(/* discardHighlight= */ true);
stateTracker.writeProgressBar(terminalWriter);
output = terminalWriter.getTranscript();

assertThat(output).contains(url.toString());
assertThat(output).contains("7s");
assertThat(output).contains("256");

// After finishing the download, it should no longer be reported.
clock.advance(Duration.ofSeconds(1));
stateTracker.downloadProgress(new DownloadProgressEvent(url, 256, true));

terminalWriter = new LoggingTerminalWriter(/* discardHighlight= */ true);
stateTracker.writeProgressBar(terminalWriter);
output = terminalWriter.getTranscript();

assertThat(output).doesNotContain("example.org");
}

@Test
Expand All @@ -1350,7 +1380,7 @@ public void testDownloadOutputLength() throws Exception {
// Also verify that the length is respected, even if only a download sample is shown.
ManualClock clock = new ManualClock();
clock.advanceMillis(TimeUnit.SECONDS.toMillis(1234));
UiStateTracker stateTracker = getUiStateTracker(clock, /*targetWidth=*/ 60);
UiStateTracker stateTracker = getUiStateTracker(clock, /* targetWidth= */ 60);
URL url = new URL("http://example.org/some/really/very/very/long/path/filename.tar.gz");

stateTracker.buildStarted();
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -15,6 +15,8 @@
package com.google.devtools.build.lib.testutil;

import com.google.devtools.build.lib.clock.Clock;
import com.google.errorprone.annotations.CanIgnoreReturnValue;
import java.time.Duration;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicLong;

Expand Down Expand Up @@ -43,4 +45,9 @@ public long nanoTime() {
public long advanceMillis(long time) {
return currentTimeMillis.addAndGet(time);
}

@CanIgnoreReturnValue
public long advance(Duration duration) {
return advanceMillis(duration.toMillis());
}
}

0 comments on commit 51e6c38

Please sign in to comment.