Skip to content

Commit

Permalink
Fix spitting out multiple "Build completed" messages.
Browse files Browse the repository at this point in the history
Also make these a proper event, so that `--ui_event_filters` is applied
properly.

Fixes bazelbuild#16085

RELNOTES[INC]:
This has the side effect of changing the message on unsuccessful builds from
```
FAILED: Build did NOT complete successfully (0 packages loaded)
```
to
```
ERROR: Build did NOT complete successfully
```
PiperOrigin-RevId: 484175656
Change-Id: I080ada6756734e5cdf236854101595949a57c083
  • Loading branch information
meisterT authored and copybara-github committed Oct 27, 2022
1 parent 7c0bdc2 commit c9f9b0b
Show file tree
Hide file tree
Showing 9 changed files with 89 additions and 82 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@
import com.google.devtools.build.lib.buildtool.buildevent.BuildCompleteEvent;
import com.google.devtools.build.lib.buildtool.buildevent.ExecutionProgressReceiverAvailableEvent;
import com.google.devtools.build.lib.clock.Clock;
import com.google.devtools.build.lib.events.Event;
import com.google.devtools.build.lib.pkgcache.LoadingPhaseCompleteEvent;
import com.google.devtools.build.lib.skyframe.ConfigurationPhaseStartedEvent;
import com.google.devtools.build.lib.skyframe.LoadingPhaseStartedEvent;
Expand All @@ -26,7 +27,6 @@
import com.google.devtools.build.lib.util.io.PositionAwareAnsiTerminalWriter;
import com.google.errorprone.annotations.CanIgnoreReturnValue;
import java.io.IOException;
import java.time.Instant;

/** Tracks the state of Skymeld builds and determines what to display at each state in the UI. */
final class SkymeldUiStateTracker extends UiStateTracker {
Expand Down Expand Up @@ -219,30 +219,9 @@ synchronized void progressReceiverAvailable(ExecutionProgressReceiverAvailableEv
}

@Override
void buildComplete(BuildCompleteEvent event) {
Event buildComplete(BuildCompleteEvent event) {
buildStatus = BuildStatus.BUILD_COMPLETED;
buildCompleteAt = Instant.ofEpochMilli(clock.currentTimeMillis());

if (event.getResult().getSuccess()) {
int actionsCompleted = this.actionsCompleted.get();
if (failedTests == 0) {
additionalMessage =
"Build completed successfully, "
+ actionsCompleted
+ pluralize(" total action", actionsCompleted);
} else {
additionalMessage =
"Build completed, "
+ failedTests
+ pluralize(" test", failedTests)
+ " FAILED, "
+ actionsCompleted
+ pluralize(" total action", actionsCompleted);
}
} else {
ok = false;
additionalMessage = "Build did NOT complete successfully";
}
return super.buildComplete(event);
}

@Override
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -582,15 +582,17 @@ public void buildComplete(BuildCompleteEvent event) {
// it as an event and add a timestamp, if events are supposed to have a timestamp.
boolean done = false;
synchronized (this) {
stateTracker.buildComplete(event);
handleInternal(stateTracker.buildComplete(event));
ignoreRefreshLimitOnce();
refresh();

// After a build has completed, only stop updating the UI if there is no more activities.
if (!stateTracker.hasActivities()) {
buildRunning = false;
done = true;
}

// Only refresh after we have determined whether we need to keep the progress bar up.
refresh();
}
if (done) {
stopUpdateThread();
Expand Down Expand Up @@ -1001,8 +1003,10 @@ private synchronized void addProgressBar() throws IOException {
TIMESTAMP_FORMAT.format(
Instant.ofEpochMilli(clock.currentTimeMillis()).atZone(ZoneId.systemDefault()));
}
stateTracker.writeProgressBar(terminalWriter, /*shortVersion=*/ !cursorControl, timestamp);
terminalWriter.newline();
if (stateTracker.hasActivities()) {
stateTracker.writeProgressBar(terminalWriter, /*shortVersion=*/ !cursorControl, timestamp);
terminalWriter.newline();
}
numLinesProgressBar = countingTerminalWriter.getWrittenLines();
if (progressInTermTitle) {
LoggingTerminalWriter stringWriter = new LoggingTerminalWriter(true);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -42,6 +42,7 @@
import com.google.devtools.build.lib.buildtool.buildevent.TestFilteringCompleteEvent;
import com.google.devtools.build.lib.clock.Clock;
import com.google.devtools.build.lib.cmdline.Label;
import com.google.devtools.build.lib.events.Event;
import com.google.devtools.build.lib.events.ExtendedEventHandler.FetchProgress;
import com.google.devtools.build.lib.pkgcache.LoadingPhaseCompleteEvent;
import com.google.devtools.build.lib.skyframe.ConfigurationPhaseStartedEvent;
Expand Down Expand Up @@ -87,7 +88,7 @@ class UiStateTracker {

private int sampleSize = 3;

private String status;
protected String status;
protected String additionalMessage;

protected final Clock clock;
Expand Down Expand Up @@ -454,31 +455,31 @@ synchronized void progressReceiverAvailable(ExecutionProgressReceiverAvailableEv
executionProgressReceiver = event.getExecutionProgressReceiver();
}

void buildComplete(BuildCompleteEvent event) {
Event buildComplete(BuildCompleteEvent event) {
buildComplete = true;
buildCompleteAt = Instant.ofEpochMilli(clock.currentTimeMillis());

status = null;
additionalMessage = "";
if (event.getResult().getSuccess()) {
status = "INFO";
int actionsCompleted = this.actionsCompleted.get();
if (failedTests == 0) {
additionalMessage =
return Event.info(
"Build completed successfully, "
+ actionsCompleted
+ pluralize(" total action", actionsCompleted);
+ pluralize(" total action", actionsCompleted));
} else {
additionalMessage =
return Event.info(
"Build completed, "
+ failedTests
+ pluralize(" test", failedTests)
+ " FAILED, "
+ actionsCompleted
+ pluralize(" total action", actionsCompleted);
+ pluralize(" total action", actionsCompleted));
}
} else {
ok = false;
status = "FAILED";
additionalMessage = "Build did NOT complete successfully";
return Event.error("Build did NOT complete successfully");
}
}

Expand Down Expand Up @@ -1324,7 +1325,9 @@ synchronized void writeProgressBar(
return;
}

writeExecutionProgress(terminalWriter, shortVersion);
if (!buildComplete) {
writeExecutionProgress(terminalWriter, shortVersion);
}

if (!shortVersion) {
reportOnDownloads(terminalWriter);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -149,7 +149,7 @@ public void buildCompleted_stateChanges() {
buildResult.setDetailedExitCode(DetailedExitCode.success());
clock.advanceMillis(SECONDS.toMillis(1));
buildResult.setStopTime(clock.currentTimeMillis());
uiStateTracker.buildComplete(new BuildCompleteEvent(buildResult));
var unused = uiStateTracker.buildComplete(new BuildCompleteEvent(buildResult));

assertThat(uiStateTracker.buildStatus).isEqualTo(BuildStatus.BUILD_COMPLETED);
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -26,6 +26,7 @@
import com.google.devtools.build.lib.events.Event;
import com.google.devtools.build.lib.events.EventKind;
import com.google.devtools.build.lib.testutil.ManualClock;
import com.google.devtools.build.lib.util.DetailedExitCode;
import com.google.devtools.build.lib.util.io.OutErr;
import com.google.testing.junit.testparameterinjector.TestParameter;
import com.google.testing.junit.testparameterinjector.TestParameterInjector;
Expand All @@ -45,6 +46,8 @@ public final class UiEventHandlerStdOutAndStdErrTest {

private static final BuildCompleteEvent BUILD_COMPLETE_EVENT =
new BuildCompleteEvent(new BuildResult(/*startTimeMillis=*/ 0));
private static final String BUILD_DID_NOT_COMPLETE_MESSAGE =
"\033[31m\033[1mERROR: \033[0mBuild did NOT complete successfully" + System.lineSeparator();

@TestParameter private TestedOutput testedOutput;

Expand Down Expand Up @@ -91,25 +94,54 @@ private void createUiEventHandler(UiOptions uiOptions) {
}

@Test
public void buildComplete_outputsNothing() {
public void buildComplete_outputsBuildFailedOnStderr() {
uiEventHandler.buildComplete(BUILD_COMPLETE_EVENT);
output.assertFlushed();

if (testedOutput == TestedOutput.STDOUT) {
output.assertFlushed();
} else {
output.assertFlushed(BUILD_DID_NOT_COMPLETE_MESSAGE);
}
}

@Test
public void buildComplete_flushesBufferedMessage() {
uiEventHandler.handle(output("hello"));
uiEventHandler.buildComplete(BUILD_COMPLETE_EVENT);

output.assertFlushed("hello");
if (testedOutput == TestedOutput.STDOUT) {
output.assertFlushed("hello");
} else {
output.assertFlushed("hello", System.lineSeparator() + BUILD_DID_NOT_COMPLETE_MESSAGE);
}
}

@Test
public void buildComplete_successfulBuild() {
uiEventHandler.handle(output(""));
var buildSuccessResult = new BuildResult(/*startTimeMillis=*/ 0);
buildSuccessResult.setDetailedExitCode(DetailedExitCode.success());
uiEventHandler.buildComplete(new BuildCompleteEvent(buildSuccessResult));

if (testedOutput == TestedOutput.STDOUT) {
output.assertFlushed();
} else {
output.assertFlushed(
"\033[32mINFO: \033[0mBuild completed successfully, 0 total actions"
+ System.lineSeparator());
}
}

@Test
public void buildComplete_emptyBuffer_outputsNothing() {
public void buildComplete_emptyBuffer_outputsBuildFailedOnStderr() {
uiEventHandler.handle(output(""));
uiEventHandler.buildComplete(BUILD_COMPLETE_EVENT);

output.assertFlushed();
if (testedOutput == TestedOutput.STDOUT) {
output.assertFlushed();
} else {
output.assertFlushed(BUILD_DID_NOT_COMPLETE_MESSAGE);
}
}

@Test
Expand All @@ -124,7 +156,11 @@ public void handleOutputEvent_concatenatesInBuffer() {
uiEventHandler.handle(output("there"));
uiEventHandler.buildComplete(BUILD_COMPLETE_EVENT);

output.assertFlushed("hello there");
if (testedOutput == TestedOutput.STDOUT) {
output.assertFlushed("hello there");
} else {
output.assertFlushed("hello there", System.lineSeparator() + BUILD_DID_NOT_COMPLETE_MESSAGE);
}
}

@Test
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -1360,7 +1360,7 @@ public void testMultipleBuildEventProtocolTransports() throws Exception {
new AnnounceBuildEventTransportsEvent(ImmutableList.of(transport1, transport2)));
stateTracker.buildEventTransportsAnnounced(
new AnnounceBuildEventTransportsEvent(ImmutableList.of(transport3)));
stateTracker.buildComplete(new BuildCompleteEvent(buildResult));
var unused = stateTracker.buildComplete(new BuildCompleteEvent(buildResult));

LoggingTerminalWriter terminalWriter = new LoggingTerminalWriter(true);

Expand All @@ -1371,8 +1371,6 @@ public void testMultipleBuildEventProtocolTransports() throws Exception {
assertThat(output, containsString("BuildEventTransport1"));
assertThat(output, containsString("BuildEventTransport2"));
assertThat(output, containsString("BuildEventTransport3"));
assertThat(output, containsString("success"));
assertThat(output, containsString("complete"));

clock.advanceMillis(TimeUnit.SECONDS.toMillis(1));
stateTracker.buildEventTransportClosed(new BuildEventTransportClosedEvent(transport1));
Expand All @@ -1383,8 +1381,6 @@ public void testMultipleBuildEventProtocolTransports() throws Exception {
assertThat(output, not(containsString("BuildEventTransport1")));
assertThat(output, containsString("BuildEventTransport2"));
assertThat(output, containsString("BuildEventTransport3"));
assertThat(output, containsString("success"));
assertThat(output, containsString("complete"));

clock.advanceMillis(TimeUnit.SECONDS.toMillis(1));
stateTracker.buildEventTransportClosed(new BuildEventTransportClosedEvent(transport3));
Expand All @@ -1395,8 +1391,6 @@ public void testMultipleBuildEventProtocolTransports() throws Exception {
assertThat(output, not(containsString("BuildEventTransport1")));
assertThat(output, containsString("BuildEventTransport2"));
assertThat(output, not(containsString("BuildEventTransport3")));
assertThat(output, containsString("success"));
assertThat(output, containsString("complete"));

clock.advanceMillis(TimeUnit.SECONDS.toMillis(1));
stateTracker.buildEventTransportClosed(new BuildEventTransportClosedEvent(transport2));
Expand All @@ -1407,8 +1401,6 @@ public void testMultipleBuildEventProtocolTransports() throws Exception {
assertThat(output, not(containsString("BuildEventTransport1")));
assertThat(output, not(containsString("BuildEventTransport2")));
assertThat(output, not(containsString("BuildEventTransport3")));
assertThat(output, containsString("success"));
assertThat(output, containsString("complete"));
assertThat(output.split("\\n")).hasLength(1);
}

Expand All @@ -1426,16 +1418,14 @@ public void testBuildEventTransportsOnNarrowTerminal() throws IOException {
stateTracker.buildStarted();
stateTracker.buildEventTransportsAnnounced(
new AnnounceBuildEventTransportsEvent(ImmutableList.of(transport1, transport2)));
stateTracker.buildComplete(new BuildCompleteEvent(buildResult));
var unused = stateTracker.buildComplete(new BuildCompleteEvent(buildResult));
clock.advanceMillis(TimeUnit.SECONDS.toMillis(1));
stateTracker.writeProgressBar(terminalWriter);
String output = terminalWriter.getTranscript();
assertThat(longestLine(output)).isAtMost(60);
assertThat(output, containsString("1s"));
assertThat(output, containsString("A".repeat(30) + "..."));
assertThat(output, containsString("BuildEventTransport"));
assertThat(output, containsString("success"));
assertThat(output, containsString("complete"));

clock.advanceMillis(TimeUnit.SECONDS.toMillis(1));
stateTracker.buildEventTransportClosed(new BuildEventTransportClosedEvent(transport2));
Expand All @@ -1446,8 +1436,6 @@ public void testBuildEventTransportsOnNarrowTerminal() throws IOException {
assertThat(output, containsString("2s"));
assertThat(output, containsString("A".repeat(30) + "..."));
assertThat(output, not(containsString("BuildEventTransport")));
assertThat(output, containsString("success"));
assertThat(output, containsString("complete"));
assertThat(output.split("\\n")).hasLength(2);
}

Expand Down Expand Up @@ -1526,7 +1514,7 @@ public void waitingRemoteCacheMessage_afterBuildComplete_visible() throws IOExce
BuildResult buildResult = new BuildResult(clock.currentTimeMillis());
buildResult.setDetailedExitCode(DetailedExitCode.success());
buildResult.setStopTime(clock.currentTimeMillis());
stateTracker.buildComplete(new BuildCompleteEvent(buildResult));
var unused = stateTracker.buildComplete(new BuildCompleteEvent(buildResult));
clock.advanceMillis(Duration.ofSeconds(2).toMillis());
LoggingTerminalWriter terminalWriter = new LoggingTerminalWriter(/*discardHighlight=*/ true);

Expand All @@ -1545,7 +1533,7 @@ public void waitingRemoteCacheMessage_multipleUploadEvents_countCorrectly() thro
BuildResult buildResult = new BuildResult(clock.currentTimeMillis());
buildResult.setDetailedExitCode(DetailedExitCode.success());
buildResult.setStopTime(clock.currentTimeMillis());
stateTracker.buildComplete(new BuildCompleteEvent(buildResult));
var unused = stateTracker.buildComplete(new BuildCompleteEvent(buildResult));
stateTracker.actionUploadStarted(ActionUploadStartedEvent.create(action, "b"));
stateTracker.actionUploadStarted(ActionUploadStartedEvent.create(action, "c"));
stateTracker.actionUploadFinished(ActionUploadFinishedEvent.create(action, "a"));
Expand Down
Loading

0 comments on commit c9f9b0b

Please sign in to comment.