diff options
3 files changed, 204 insertions, 23 deletions
diff --git a/src/main/java/com/google/devtools/build/lib/runtime/ExperimentalEventHandler.java b/src/main/java/com/google/devtools/build/lib/runtime/ExperimentalEventHandler.java index db0c557d00..57e3775351 100644 --- a/src/main/java/com/google/devtools/build/lib/runtime/ExperimentalEventHandler.java +++ b/src/main/java/com/google/devtools/build/lib/runtime/ExperimentalEventHandler.java @@ -75,7 +75,16 @@ public class ExperimentalEventHandler extends BlazeCommandEventHandler { this.terminalWidth = (options.terminalColumns > 0 ? options.terminalColumns : 80); this.clock = clock; this.debugAllEvents = options.experimentalUiDebugAllEvents; - this.stateTracker = new ExperimentalStateTracker(clock); + // If we have cursor control, we try to fit in the terminal width to avoid having + // to wrap the progress bar. We will wrap the progress bar to terminalWidth - 1 + // characters to avoid depending on knowing whether the underlying terminal does the + // line feed already when reaching the last character of the line, or only once an + // additional character is written. Another column is lost for the continuation character + // in the wrapping process. + this.stateTracker = + this.cursorControl + ? new ExperimentalStateTracker(clock, this.terminalWidth - 2) + : new ExperimentalStateTracker(clock); this.numLinesProgressBar = 0; this.minimalDelayMillis = Math.round(options.showProgressRateLimit * 1000); this.minimalUpdateInterval = Math.max(this.minimalDelayMillis, MAXIMAL_UPDATE_DELAY_MILLIS); diff --git a/src/main/java/com/google/devtools/build/lib/runtime/ExperimentalStateTracker.java b/src/main/java/com/google/devtools/build/lib/runtime/ExperimentalStateTracker.java index 85dd5189b4..c8fab64cd5 100644 --- a/src/main/java/com/google/devtools/build/lib/runtime/ExperimentalStateTracker.java +++ b/src/main/java/com/google/devtools/build/lib/runtime/ExperimentalStateTracker.java @@ -22,11 +22,13 @@ 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.TestFilteringCompleteEvent; +import com.google.devtools.build.lib.cmdline.Label; import com.google.devtools.build.lib.pkgcache.LoadingPhaseCompleteEvent; import com.google.devtools.build.lib.skyframe.LoadingPhaseStartedEvent; import com.google.devtools.build.lib.skyframe.LoadingProgressReceiver; import com.google.devtools.build.lib.util.Clock; import com.google.devtools.build.lib.util.io.AnsiTerminalWriter; +import com.google.devtools.build.lib.util.io.PositionAwareAnsiTerminalWriter; import com.google.devtools.build.lib.view.test.TestStatus.BlazeTestStatus; import java.io.IOException; @@ -42,12 +44,17 @@ class ExperimentalStateTracker { static final int SAMPLE_SIZE = 3; static final long SHOW_TIME_THRESHOLD_SECONDS = 3; + static final String ELLIPSIS = "..."; private String status; private String additionalMessage; private final Clock clock; + // Desired maximal width of the progress bar, if positive. + // Non-positive values indicate not to aim for a particular width. + private final int targetWidth; + // currently running actions, using the path of the primary // output as unique identifier. private final Deque<String> runningActions; @@ -64,12 +71,17 @@ class ExperimentalStateTracker { private ExecutionProgressReceiver executionProgressReceiver; private LoadingProgressReceiver loadingProgressReceiver; - ExperimentalStateTracker(Clock clock) { + ExperimentalStateTracker(Clock clock, int targetWidth) { this.runningActions = new ArrayDeque<>(); this.actions = new TreeMap<>(); this.actionNanoStartTimes = new TreeMap<>(); this.ok = true; this.clock = clock; + this.targetWidth = targetWidth; + } + + ExperimentalStateTracker(Clock clock) { + this(clock, 0); } void buildStarted(BuildStartingEvent event) { @@ -133,31 +145,95 @@ class ExperimentalStateTracker { } } - private String describeAction(String name, long nanoTime) { + /** + * From a string, take a suffix of at most the given length. + */ + private String suffix(String s, int len) { + int startPos = s.length() - len; + if (startPos <= 0) { + return s; + } + return s.substring(startPos); + } + + /** + * If possible come up with a human-readable description of the label + * that fits within the given width; a non-positive width indicates not + * no restriction at all. + */ + private String shortenedLabelString(Label label, int width) { + if (width <= 0) { + return label.toString(); + } + String name = label.toString(); + if (name.length() <= width) { + return name; + } + name = suffix(name, width - ELLIPSIS.length()); + int slashPos = name.indexOf('/'); + if (slashPos >= 0) { + return ELLIPSIS + name.substring(slashPos); + } + int colonPos = name.indexOf(':'); + if (slashPos >= 0) { + return ELLIPSIS + name.substring(colonPos); + } + // no reasonable place found to shorten; as last resort, just truncate + if (3 * ELLIPSIS.length() <= width) { + return ELLIPSIS + suffix(label.toString(), width - ELLIPSIS.length()); + } + return label.toString(); + } + + private String describeAction(String name, long nanoTime, int desiredWidth) { Action action = actions.get(name); + + String postfix = ""; + long nanoRuntime = nanoTime - actionNanoStartTimes.get(name); + long runtimeSeconds = nanoRuntime / 1000000000; + if (runtimeSeconds > SHOW_TIME_THRESHOLD_SECONDS) { + postfix = " " + runtimeSeconds + "s"; + } + String message = action.getProgressMessage(); if (message == null) { message = action.prettyPrint(); } - long nanoRuntime = nanoTime - actionNanoStartTimes.get(name); - long runtimeSeconds = nanoRuntime / 1000000000; - if (runtimeSeconds > SHOW_TIME_THRESHOLD_SECONDS) { - message = message + " " + runtimeSeconds + "s"; + + if (desiredWidth <= 0) { + return message + postfix; + } + if (message.length() + postfix.length() <= desiredWidth) { + return message + postfix; } - return message; + if (action.getOwner() != null) { + if (action.getOwner().getLabel() != null) { + String shortLabel = + shortenedLabelString(action.getOwner().getLabel(), desiredWidth - postfix.length()); + if (shortLabel.length() + postfix.length() <= desiredWidth) { + return shortLabel + postfix; + } + } + } + if (3 * ELLIPSIS.length() <= desiredWidth) { + message = ELLIPSIS + suffix(message, desiredWidth - ELLIPSIS.length() - postfix.length()); + } + return message + postfix; } private void sampleOldestActions(AnsiTerminalWriter terminalWriter) throws IOException { int count = 0; long nanoTime = clock.nanoTime(); + int actionCount = runningActions.size(); for (String action : runningActions) { count++; - terminalWriter.newline().append(" " + describeAction(action, nanoTime)); + int width = (count >= SAMPLE_SIZE && count < actionCount) ? targetWidth - 8 : targetWidth - 4; + terminalWriter.newline().append(" " + describeAction(action, nanoTime, width)); if (count >= SAMPLE_SIZE) { break; } } - if (count < runningActions.size()) { + if (count < actionCount) { terminalWriter.append(" ..."); } } @@ -202,14 +278,19 @@ class ExperimentalStateTracker { * Maybe add a note about the last test that passed. Return true, if the note was added (and * hence a line break is appropriate if more data is to come. If a null value is provided for * the terminal writer, only return wether a note would be added. + * + * The width parameter gives advice on to which length the the description of the test should + * the shortened to, if possible. */ - private boolean maybeShowRecentTest(AnsiTerminalWriter terminalWriter, boolean shortVersion) - throws IOException { + private boolean maybeShowRecentTest( + AnsiTerminalWriter terminalWriter, boolean shortVersion, int width) throws IOException { + final String prefix = "; last test: "; if (!shortVersion && mostRecentTest != null) { if (terminalWriter != null) { terminalWriter .normal() - .append("; recent test: " + mostRecentTest.getTarget().getLabel().toString()); + .append(prefix + shortenedLabelString( + mostRecentTest.getTarget().getLabel(), width - prefix.length())); } return true; } else { @@ -217,8 +298,10 @@ class ExperimentalStateTracker { } } - synchronized void writeProgressBar(AnsiTerminalWriter terminalWriter, boolean shortVersion) + synchronized void writeProgressBar(AnsiTerminalWriter rawTerminalWriter, boolean shortVersion) throws IOException { + PositionAwareAnsiTerminalWriter terminalWriter = + new PositionAwareAnsiTerminalWriter(rawTerminalWriter); if (status != null) { if (ok) { terminalWriter.okStatus(); @@ -249,29 +332,41 @@ class ExperimentalStateTracker { terminalWriter.append(";"); } if (runningActions.size() == 0) { - terminalWriter.normal().append(" no actions running"); - maybeShowRecentTest(terminalWriter, shortVersion); + terminalWriter.normal().append(" no action"); + maybeShowRecentTest(terminalWriter, shortVersion, targetWidth - terminalWriter.getPosition()); } else if (runningActions.size() == 1) { - String statusMessage = describeAction(runningActions.peekFirst(), clock.nanoTime()); - if (maybeShowRecentTest(null, shortVersion)) { + if (maybeShowRecentTest(null, shortVersion, targetWidth - terminalWriter.getPosition())) { // As we will break lines anyway, also show the number of running actions, to keep // things stay roughly in the same place (also compensating for the missing plural-s // in the word action). - terminalWriter.normal().append(" 1 action running"); - maybeShowRecentTest(terminalWriter, shortVersion); + terminalWriter.normal().append(" 1 action"); + maybeShowRecentTest( + terminalWriter, shortVersion, targetWidth - terminalWriter.getPosition()); + String statusMessage = + describeAction(runningActions.peekFirst(), clock.nanoTime(), targetWidth - 4); terminalWriter.normal().newline().append(" " + statusMessage); } else { + String statusMessage = + describeAction( + runningActions.peekFirst(), + clock.nanoTime(), + targetWidth - terminalWriter.getPosition() - 1); terminalWriter.normal().append(" " + statusMessage); } } else { if (shortVersion) { - String statusMessage = describeAction(runningActions.peekFirst(), clock.nanoTime()); + String statusMessage = + describeAction( + runningActions.peekFirst(), + clock.nanoTime(), + targetWidth - terminalWriter.getPosition()); statusMessage += " ... (" + runningActions.size() + " actions)"; terminalWriter.normal().append(" " + statusMessage); } else { - String statusMessage = "" + runningActions.size() + " actions running"; + String statusMessage = "" + runningActions.size() + " actions"; terminalWriter.normal().append(" " + statusMessage); - maybeShowRecentTest(terminalWriter, shortVersion); + maybeShowRecentTest( + terminalWriter, shortVersion, targetWidth - terminalWriter.getPosition()); sampleOldestActions(terminalWriter); } } diff --git a/src/test/java/com/google/devtools/build/lib/runtime/ExperimentalStateTrackerTest.java b/src/test/java/com/google/devtools/build/lib/runtime/ExperimentalStateTrackerTest.java index 874ccc125c..9a12eb1345 100644 --- a/src/test/java/com/google/devtools/build/lib/runtime/ExperimentalStateTrackerTest.java +++ b/src/test/java/com/google/devtools/build/lib/runtime/ExperimentalStateTrackerTest.java @@ -57,6 +57,14 @@ public class ExperimentalStateTrackerTest extends FoundationTestCase { return action; } + private int longestLine(String output) { + int maxLength = 0; + for (String line : output.split("\n")) { + maxLength = Math.max(maxLength, line.length()); + } + return maxLength; + } + @Test public void testActionVisible() throws IOException { // If there is only one action running, it should be visible @@ -270,4 +278,73 @@ public class ExperimentalStateTrackerTest extends FoundationTestCase { "Label " + labelA.toString() + " should be present in progress bar: " + output, output.contains(labelA.toString())); } + + private void doTestOutputLength(boolean withTest, int actions) throws Exception { + // If we target 70 characters, then there should be enough space to both, + // keep the line limit, and show the local part of the running actions and + // the passed test. + ManualClock clock = new ManualClock(); + ExperimentalStateTracker stateTracker = new ExperimentalStateTracker(clock, 70); + + Action foobuildAction = mockAction( + "Building //src/some/very/long/path/long/long/long/long/long/long/long/foo/foobuild.jar", + "//src/some/very/long/path/long/long/long/long/long/long/long/foo:foobuild"); + Action bazbuildAction = mockAction( + "Building //src/some/very/long/path/long/long/long/long/long/long/long/baz/bazbuild.jar", + "//src/some/very/long/path/long/long/long/long/long/long/long/baz:bazbuild"); + + Label bartestLabel = Label.parseAbsolute( + "//src/another/very/long/long/path/long/long/long/long/long/long/long/long/bars:bartest"); + ConfiguredTarget bartestTarget = Mockito.mock(ConfiguredTarget.class); + when(bartestTarget.getLabel()).thenReturn(bartestLabel); + + TestFilteringCompleteEvent filteringComplete = Mockito.mock(TestFilteringCompleteEvent.class); + when(filteringComplete.getTestTargets()).thenReturn(ImmutableSet.of(bartestTarget)); + + TestSummary testSummary = Mockito.mock(TestSummary.class); + when(testSummary.getStatus()).thenReturn(BlazeTestStatus.PASSED); + when(testSummary.getTarget()).thenReturn(bartestTarget); + + if (actions >= 1) { + stateTracker.actionStarted(new ActionStartedEvent(foobuildAction, 123456789)); + } + if (actions >= 2) { + stateTracker.actionStarted(new ActionStartedEvent(bazbuildAction, 123456900)); + } + if (withTest) { + stateTracker.testFilteringComplete(filteringComplete); + stateTracker.testSummary(testSummary); + } + + LoggingTerminalWriter terminalWriter = new LoggingTerminalWriter(/*discardHighlight=*/ true); + stateTracker.writeProgressBar(terminalWriter); + String output = terminalWriter.getTranscript(); + + assertTrue( + "Only lines with at most 70 chars should be present in the output:\n" + output, + longestLine(output) <= 70); + if (actions >= 1) { + assertTrue( + "Running action 'foobuild' should be mentioned in output:\n" + output, + output.contains("foobuild")); + } + if (actions >= 2) { + assertTrue( + "Running action 'bazbuild' should be mentioned in output:\n" + output, + output.contains("bazbuild")); + } + if (withTest) { + assertTrue( + "Passed test ':bartest' should be mentioned in output:\n" + output, + output.contains(":bartest")); + } + } + + @Test + public void testOutputLength() throws Exception { + for (int i = 0; i < 3; i++) { + doTestOutputLength(true, i); + doTestOutputLength(false, i); + } + } } |