experimental UI: honor --show_timestamps

In the experimental UI, also support the --show_timestamps option
which asks that for each event a timestamp be added to the the
output. Fixes #1436.

--
Change-Id: I8f9db958525edfbca12ed2c1f1396f25f865b897
Reviewed-on: https://bazel-review.googlesource.com/#/c/3916
MOS_MIGRATED_REVID=126165328

3 files changed, 33 insertions, 4 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 106995665f..340fa2b315 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
@@ -39,6 +39,9 @@ import com.google.devtools.build.lib.util.io.OutErr;
 import com.google.devtools.build.lib.vfs.Path;
 import com.google.devtools.build.lib.view.test.TestStatus.BlazeTestStatus;
 
+import org.joda.time.format.DateTimeFormat;
+import org.joda.time.format.DateTimeFormatter;
+
 import java.io.IOException;
 import java.io.OutputStream;
 import java.nio.charset.StandardCharsets;
@@ -57,6 +60,9 @@ public class ExperimentalEventHandler extends BlazeCommandEventHandler {
   /** Periodic update interval of a time-dependent progress bar if it cannot be updated in place */
   static final long LONG_REFRESH_MILLIS = 5000L;
 
+  private static final DateTimeFormatter TIMESTAMP_FORMAT =
+      DateTimeFormat.forPattern("(HH:mm:ss.SSS) ");
+
   private final long minimalDelayMillis;
   private final boolean cursorControl;
   private final Clock clock;
@@ -66,6 +72,7 @@ public class ExperimentalEventHandler extends BlazeCommandEventHandler {
   private final long minimalUpdateInterval;
   private final boolean showProgress;
   private final boolean progressInTermTitle;
+  private final boolean showTimestamp;
   private long lastRefreshMillis;
   private long mustRefreshAfterMillis;
   private int numLinesProgressBar;
@@ -85,6 +92,7 @@ public class ExperimentalEventHandler extends BlazeCommandEventHandler {
     this.terminalWidth = (options.terminalColumns > 0 ? options.terminalColumns : 80);
     this.showProgress = options.showProgress;
     this.progressInTermTitle = options.progressInTermTitle;
+    this.showTimestamp = options.showTimestamp;
     this.clock = clock;
     this.debugAllEvents = options.experimentalUiDebugAllEvents;
     // If we have cursor control, we try to fit in the terminal width to avoid having
@@ -199,6 +207,9 @@ public class ExperimentalEventHandler extends BlazeCommandEventHandler {
             terminal.writeString(event.getKind() + ": ");
             terminal.resetTerminal();
             incompleteLine = true;
+            if (showTimestamp) {
+              terminal.writeString(TIMESTAMP_FORMAT.print(clock.currentTimeMillis()));
+            }
             if (event.getLocation() != null) {
               terminal.writeString(event.getLocation() + ": ");
             }
@@ -292,7 +303,13 @@ public class ExperimentalEventHandler extends BlazeCommandEventHandler {
 
   @Subscribe
   public void buildComplete(BuildCompleteEvent event) {
-    stateTracker.buildComplete(event);
+    // The final progress bar will flow into the scroll-back buffer, to if treat
+    // it as an event and add a time stamp, if events are supposed to have a time stmap.
+    if (showTimestamp) {
+      stateTracker.buildComplete(event, TIMESTAMP_FORMAT.print(clock.currentTimeMillis()));
+    } else {
+      stateTracker.buildComplete(event);
+    }
     ignoreRefreshLimitOnce();
     refresh();
     buildComplete = true;
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 f5463f3916..ceee32143c 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
@@ -153,17 +153,22 @@ class ExperimentalStateTracker {
     executionProgressReceiver = event.getExecutionProgressReceiver();
   }
 
-  void buildComplete(BuildCompleteEvent event) {
+  void buildComplete(BuildCompleteEvent event, String additionalInfo) {
     if (event.getResult().getSuccess()) {
       status = "INFO";
-      additionalMessage = "Build completed successfully, " + actionsCompleted + " total actions";
+      additionalMessage =
+          additionalInfo + "Build completed successfully, " + actionsCompleted + " total actions";
     } else {
       ok = false;
       status = "FAILED";
-      additionalMessage = "Build did NOT complete successfully";
+      additionalMessage = additionalInfo + "Build did NOT complete successfully";
     }
   }
 
+  void buildComplete(BuildCompleteEvent event) {
+    buildComplete(event, "");
+  }
+
   synchronized void actionStarted(ActionStartedEvent event) {
     Action action = event.getAction();
     String name = action.getPrimaryOutput().getPath().getPathString();
diff --git a/src/test/shell/integration/experimental_ui_test.sh b/src/test/shell/integration/experimental_ui_test.sh
index 87b0cf94ee..ad6ff654db 100755
--- a/src/test/shell/integration/experimental_ui_test.sh
+++ b/src/test/shell/integration/experimental_ui_test.sh
@@ -133,6 +133,13 @@ function test_fail() {
   expect_log 'pkg:false.*'$'\x1b\[31m\x1b\[1m''.*FAIL'
 }
 
+function test_timestamp() {
+  bazel test --experimental_ui --show_timestamps pkg:true 2>$TEST_log \
+    || fail "bazel test failed"
+  # expect something that looks like HH:mm:ss
+  expect_log '[0-2][0-9]:[0-5][0-9]:[0-6][0-9]'
+}
+
 function test_info_spacing() {
   # Verify that the output of "bazel info" is suitable for backtick escapes,
   # in particular free carriage-return characters.