Combine prefix event and payload stdout/stderr

...in a single event instead of relying on the synchronisation on the
reporter. In this way, it will be possible to focus on output of errors,
and also to deduplicate warnings.

Change-Id: I9669e8497ca6e22a01f3e285ec9ee42c1ecf3fb5
PiperOrigin-RevId: 208223882

8 files changed, 155 insertions, 31 deletions

diff --git a/src/main/java/com/google/devtools/build/lib/events/Event.java b/src/main/java/com/google/devtools/build/lib/events/Event.java
index 5bf5b1dd05..8835d17e06 100644
--- a/src/main/java/com/google/devtools/build/lib/events/Event.java
+++ b/src/main/java/com/google/devtools/build/lib/events/Event.java
@@ -31,6 +31,8 @@ public final class Event implements Serializable {
   private final EventKind kind;
   private final Location location;
   private final String message;
+  @Nullable private final String stdout;
+  @Nullable private final String stderr;
 
   /**
    * An alternative representation for message.
@@ -46,23 +48,40 @@ public final class Event implements Serializable {
 
   private final int hashCode;
 
-  private Event(EventKind kind, @Nullable Location location, String message, @Nullable String tag) {
+  private Event(
+      EventKind kind,
+      @Nullable Location location,
+      String message,
+      @Nullable String tag,
+      @Nullable String stdout,
+      @Nullable String stderr) {
     this.kind = Preconditions.checkNotNull(kind);
     this.location = location;
     this.message = Preconditions.checkNotNull(message);
     this.messageBytes = null;
     this.tag = tag;
-    this.hashCode = Objects.hash(kind, location, message, tag, Arrays.hashCode(messageBytes));
+    this.stdout = stdout;
+    this.stderr = stderr;
+    this.hashCode =
+        Objects.hash(kind, location, message, tag, Arrays.hashCode(messageBytes), stdout, stderr);
   }
 
   private Event(
-      EventKind kind, @Nullable Location location, byte[] messageBytes, @Nullable String tag) {
+      EventKind kind,
+      @Nullable Location location,
+      byte[] messageBytes,
+      @Nullable String tag,
+      @Nullable String stdout,
+      @Nullable String stderr) {
     this.kind = Preconditions.checkNotNull(kind);
     this.location = location;
     this.message = null;
     this.messageBytes = Preconditions.checkNotNull(messageBytes);
     this.tag = tag;
-    this.hashCode = Objects.hash(kind, location, message, tag, Arrays.hashCode(messageBytes));
+    this.stdout = stdout;
+    this.stderr = stderr;
+    this.hashCode =
+        Objects.hash(kind, location, message, tag, Arrays.hashCode(messageBytes), stdout, stderr);
   }
 
   public Event withTag(String tag) {
@@ -70,9 +89,17 @@ public final class Event implements Serializable {
       return this;
     }
     if (this.message != null) {
-      return new Event(this.kind, this.location, this.message, tag);
+      return new Event(this.kind, this.location, this.message, tag, this.stdout, this.stderr);
+    } else {
+      return new Event(this.kind, this.location, this.messageBytes, tag, this.stdout, this.stderr);
+    }
+  }
+
+  public Event withStdoutStderr(String stdout, String stderr) {
+    if (this.message != null) {
+      return new Event(this.kind, this.location, this.message, this.tag, stdout, stderr);
     } else {
-      return new Event(this.kind, this.location, this.messageBytes, tag);
+      return new Event(this.kind, this.location, this.messageBytes, this.tag, stdout, stderr);
     }
   }
 
@@ -97,6 +124,24 @@ public final class Event implements Serializable {
   }
 
   /**
+   * Get the stdout bytes associated with this event; typically, the event will report where the
+   * output originated from.
+   */
+  @Nullable
+  public String getStdOut() {
+    return stdout;
+  }
+
+  /**
+   * Get the stdout bytes associated with this event; typically, the event will report where the
+   * output originated from.
+   */
+  @Nullable
+  public String getStdErr() {
+    return stderr;
+  }
+
+  /**
    * Returns the location of this event, if any.  Returns null iff the event
    * wasn't associated with any particular location, for example, a progress
    * message.
@@ -133,6 +178,8 @@ public final class Event implements Serializable {
         && Objects.equals(this.location, that.location)
         && Objects.equals(this.tag, that.tag)
         && Objects.equals(this.message, that.message)
+        && Objects.equals(this.stdout, that.stdout)
+        && Objects.equals(this.stderr, that.stderr)
         && Arrays.equals(this.messageBytes, that.messageBytes);
   }
 
@@ -146,7 +193,7 @@ public final class Event implements Serializable {
   }
 
   public static Event of(EventKind kind, @Nullable Location location, String message) {
-    return new Event(kind, location, message, null);
+    return new Event(kind, location, message, null, null, null);
   }
 
   /**
@@ -155,42 +202,42 @@ public final class Event implements Serializable {
    * The bytes must be decodable as UTF-8 text.
    */
   public static Event of(EventKind kind, @Nullable Location location, byte[] messageBytes) {
-    return new Event(kind, location, messageBytes, null);
+    return new Event(kind, location, messageBytes, null, null, null);
   }
 
   /**
    * Reports an error.
    */
   public static Event error(@Nullable Location location, String message){
-    return new Event(EventKind.ERROR, location, message, null);
+    return new Event(EventKind.ERROR, location, message, null, null, null);
   }
 
   /**
    * Reports a warning.
    */
   public static Event warn(@Nullable Location location, String message) {
-    return new Event(EventKind.WARNING, location, message, null);
+    return new Event(EventKind.WARNING, location, message, null, null, null);
   }
 
   /**
    * Reports atemporal statements about the build, i.e. they're true for the duration of execution.
    */
   public static Event info(@Nullable Location location, String message) {
-    return new Event(EventKind.INFO, location, message, null);
+    return new Event(EventKind.INFO, location, message, null, null, null);
   }
 
   /**
    * Reports a temporal statement about the build.
    */
   public static Event progress(@Nullable Location location, String message) {
-    return new Event(EventKind.PROGRESS, location, message, null);
+    return new Event(EventKind.PROGRESS, location, message, null, null, null);
   }
 
   /**
    * Reports a debug message.
    */
   public static Event debug(@Nullable Location location, String message) {
-    return new Event(EventKind.DEBUG, location, message, null);
+    return new Event(EventKind.DEBUG, location, message, null, null, null);
   }
 
   /**
diff --git a/src/main/java/com/google/devtools/build/lib/events/EventCollector.java b/src/main/java/com/google/devtools/build/lib/events/EventCollector.java
index 46bf3adf3f..63c64a6b52 100644
--- a/src/main/java/com/google/devtools/build/lib/events/EventCollector.java
+++ b/src/main/java/com/google/devtools/build/lib/events/EventCollector.java
@@ -66,6 +66,12 @@ public final class EventCollector extends AbstractEventHandler implements Iterab
     if (getEventMask().contains(event.getKind())) {
       collected.add(event);
     }
+    if (event.getStdErr() != null) {
+      handle(Event.of(EventKind.STDERR, null, event.getStdErr()));
+    }
+    if (event.getStdOut() != null) {
+      handle(Event.of(EventKind.STDOUT, null, event.getStdOut()));
+    }
   }
 
   /**
diff --git a/src/main/java/com/google/devtools/build/lib/events/PrintingEventHandler.java b/src/main/java/com/google/devtools/build/lib/events/PrintingEventHandler.java
index fc16475694..fc57456d9c 100644
--- a/src/main/java/com/google/devtools/build/lib/events/PrintingEventHandler.java
+++ b/src/main/java/com/google/devtools/build/lib/events/PrintingEventHandler.java
@@ -81,7 +81,8 @@ public class PrintingEventHandler extends AbstractEventHandler
    */
   @Override
   public void handle(Event event) {
-    if (!getEventMask().contains(event.getKind())) {   
+    if (!getEventMask().contains(event.getKind())) {
+      handleFollowUpEvents(event);
       return;
     }
     try {
@@ -113,5 +114,16 @@ public class PrintingEventHandler extends AbstractEventHandler
        */
       outErr.printErrLn(e.getMessage());
     }
+    handleFollowUpEvents(event);
   }
+
+  private void handleFollowUpEvents(Event event) {
+    if (event.getStdErr() != null) {
+      handle(Event.of(EventKind.STDERR, null, event.getStdErr()));
+    }
+    if (event.getStdOut() != null) {
+      handle(Event.of(EventKind.STDOUT, null, event.getStdOut()));
+    }
+  }
+
 }
diff --git a/src/main/java/com/google/devtools/build/lib/runtime/BlazeCommandEventHandler.java b/src/main/java/com/google/devtools/build/lib/runtime/BlazeCommandEventHandler.java
index bceb04c833..5fe8b5130a 100644
--- a/src/main/java/com/google/devtools/build/lib/runtime/BlazeCommandEventHandler.java
+++ b/src/main/java/com/google/devtools/build/lib/runtime/BlazeCommandEventHandler.java
@@ -329,6 +329,13 @@ public class BlazeCommandEventHandler implements EventHandler {
 
     // Event messages go to stderr; results (e.g. 'blaze query') go to stdout.
     errPrintStream.println(buf);
+
+    if (event.getStdErr() != null) {
+      handle(Event.of(EventKind.STDERR, null, event.getStdErr()));
+    }
+    if (event.getStdOut() != null) {
+      handle(Event.of(EventKind.STDOUT, null, event.getStdOut()));
+    }
   }
 
   private void putOutput(OutputStream out, Event event) {
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 f68b3853d2..49ba57ba1b 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
@@ -319,6 +319,20 @@ public class ExperimentalEventHandler implements EventHandler {
         clearProgressBar();
         terminal.flush();
         outErr.getOutputStream().write((event + "\n").getBytes(StandardCharsets.UTF_8));
+        if (event.getStdOut() != null) {
+          outErr
+              .getOutputStream()
+              .write(
+                  ("... with STDOUT: " + event.getStdOut() + "\n")
+                      .getBytes(StandardCharsets.UTF_8));
+        }
+        if (event.getStdErr() != null) {
+          outErr
+              .getOutputStream()
+              .write(
+                  ("... with STDERR: " + event.getStdErr() + "\n")
+                      .getBytes(StandardCharsets.UTF_8));
+        }
         outErr.getOutputStream().flush();
         addProgressBar();
         terminal.flush();
@@ -336,10 +350,10 @@ public class ExperimentalEventHandler implements EventHandler {
               stream.flush();
             } else {
               byte[] message = event.getMessageBytes();
-              double cap = remainingCapacity(message.length);
-              if (cap < 0) {
+              if (remainingCapacity() < 0) {
                 return;
               }
+              double cap = remainingCapacity(message.length);
               if (cap < CAPACITY_LIMIT_OUT_ERR_EVENTS) {
                 // Have to ensure the message is not too large.
                 long allowedLength =
@@ -439,6 +453,12 @@ public class ExperimentalEventHandler implements EventHandler {
           case DEPCHECKER:
             break;
         }
+        if (event.getStdErr() != null) {
+          handle(Event.of(EventKind.STDERR, null, event.getStdErr()));
+        }
+        if (event.getStdOut() != null) {
+          handle(Event.of(EventKind.STDOUT, null, event.getStdOut()));
+        }
       }
     } catch (IOException e) {
       logger.warning("IO Error writing to output stream: " + e);
diff --git a/src/main/java/com/google/devtools/build/lib/runtime/FancyTerminalEventHandler.java b/src/main/java/com/google/devtools/build/lib/runtime/FancyTerminalEventHandler.java
index e482eb6054..90975de9a5 100644
--- a/src/main/java/com/google/devtools/build/lib/runtime/FancyTerminalEventHandler.java
+++ b/src/main/java/com/google/devtools/build/lib/runtime/FancyTerminalEventHandler.java
@@ -133,12 +133,14 @@ public class FancyTerminalEventHandler extends BlazeCommandEventHandler {
       return;
     }
     if (!eventMask.contains(event.getKind())) {
+      handleFollowUpEvents(event);
       return;
     }
     if (trySpecial
         && !EventKind.ERRORS_AND_WARNINGS_AND_OUTPUT.contains(event.getKind())
         && skipUntil.isAfter(Instant.now())) {
       // Short-circuit here to avoid wiping out previous terminal contents.
+      handleFollowUpEvents(event);
       return;
     }
 
@@ -235,8 +237,18 @@ public class FancyTerminalEventHandler extends BlazeCommandEventHandler {
       logger.warning("Terminal was closed during build: " + e);
       terminalClosed = true;
     }
+    handleFollowUpEvents(event);
   }
-  
+
+  private void handleFollowUpEvents(Event event) {
+    if (event.getStdErr() != null) {
+      handle(Event.of(EventKind.STDERR, null, event.getStdErr()));
+    }
+    if (event.getStdOut() != null) {
+      handle(Event.of(EventKind.STDOUT, null, event.getStdOut()));
+    }
+  }
+
   private String getExtraMessage() {
     synchronized (messageIterator) {
       if (messageIterator.hasNext()) {
diff --git a/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeActionExecutor.java b/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeActionExecutor.java
index 5ddabcce58..5fd47c7460 100644
--- a/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeActionExecutor.java
+++ b/src/main/java/com/google/devtools/build/lib/skyframe/SkyframeActionExecutor.java
@@ -81,7 +81,6 @@ import com.google.devtools.build.lib.profiler.SilentCloseable;
 import com.google.devtools.build.lib.rules.cpp.IncludeScannable;
 import com.google.devtools.build.lib.util.Pair;
 import com.google.devtools.build.lib.util.io.FileOutErr;
-import com.google.devtools.build.lib.util.io.OutErr;
 import com.google.devtools.build.lib.vfs.FileSystem;
 import com.google.devtools.build.lib.vfs.OutputService;
 import com.google.devtools.build.lib.vfs.Path;
@@ -1211,20 +1210,20 @@ public final class SkyframeActionExecutor {
    * @param outErrBuffer The OutErr that recorded the actions output
    */
   private void dumpRecordedOutErr(Event prefixEvent, FileOutErr outErrBuffer) {
-    // Synchronize this on the reporter, so that the output from multiple
-    // actions will not be interleaved.
-    synchronized (reporter) {
-      // Only print the output if we're not winding down.
-      if (isBuilderAborting()) {
-        return;
-      }
+    // Only print the output if we're not winding down.
+    if (isBuilderAborting()) {
+      return;
+    }
+    if (outErrBuffer != null && outErrBuffer.hasRecordedOutput()) {
+      // Bind the output to the prefix event.
+      // Note: here we temporarily (until the event is handled by the UI) read all
+      // output into memory; as the output of regular actions (as opposed to test runs) usually is
+      // short, so this should not be a problem. If it does turn out to be a problem, we have to
+      // pass the outErrbuffer instead.
+      reporter.handle(
+          prefixEvent.withStdoutStderr(outErrBuffer.outAsLatin1(), outErrBuffer.errAsLatin1()));
+    } else {
       reporter.handle(prefixEvent);
-
-      if (outErrBuffer != null && outErrBuffer.hasRecordedOutput()) {
-        OutErr outErr = this.reporter.getOutErr();
-        outErrBuffer.dumpOutAsLatin1(outErr.getOutputStream());
-        outErrBuffer.dumpErrAsLatin1(outErr.getErrorStream());
-      }
     }
   }
 
diff --git a/src/test/shell/integration/experimental_ui_test.sh b/src/test/shell/integration/experimental_ui_test.sh
index d73778de6a..2759243d8f 100755
--- a/src/test/shell/integration/experimental_ui_test.sh
+++ b/src/test/shell/integration/experimental_ui_test.sh
@@ -146,7 +146,17 @@ sh_test(
   deps = [":outputlib"],
 )
 EOF
+  mkdir -p error
+  cat > error/BUILD <<'EOF'
+genrule(
+  name = "failwitherror",
+  outs = ["fail.txt"],
+  cmd = "echo Here is the error message; exit 1",
+)
+EOF
   chmod -w pkg/*  # prevent accidental editing
+  # keep directories writable though, so that test clean up can work
+  chmod 755 error
 }
 
 #### TESTS #############################################################
@@ -330,6 +340,17 @@ function test_streamed {
   expect_log 'foobar'
 }
 
+function test_stdout_bundled {
+    # Verify that the error message is part of the error event
+    bazel build --experimental_ui --experimental_ui_debug_all_events \
+          error:failwitherror > "${TEST_log}" 2>&1 \
+    && fail "expected failure" || :
+    grep -A1 '^ERROR' "${TEST_log}" \
+        | grep -q "with STDOUT: Here is the error message" \
+        || fail "Error message not bundled"
+}
+
+
 function test_output_limit {
     # Verify that output limting works
     bazel clean --expunge