Enhance quiet mode.

Quiet mode (-q) is documented as "Don't print output on success." But
this doesn't apply to many categories of output. In particular, warning
output is still printed. If the build produces warnings, scripts that
consume the output of GN commands like "desc" can get corrupted output
and these lines need to be manually filtered.

This patch extends quiet mode to buffer the output until an error is
hit. If the run produces an error, this output is printed to standard
out as normal. If the run succeeds, this output is discarded. This
implements the spirit of quite mode more completely and allows cleaner
programmatic consumption of the output.

Also fixes an existing issue where Python error output would be
discarded in quiet mode.

In this patch we lose a fflush() at the end of the implementation of the
print() function call. We could special-case this to flush in the
non-quiet case, but I don't think the flush is necessary any more for
normal usage (this was more relevant when doing initial development).

Change-Id: Ibef6ed2c23e130e8336c16fbab9aad4dff63e131
Reviewed-on: https://gn-review.googlesource.com/c/gn/+/22680
Commit-Queue: David Turner <digit@google.com>
Reviewed-by: Tate Wyatt <wyatttate545@gmail.com>
Reviewed-by: Takuto Ikuta <tikuta@google.com>
Reviewed-by: David Turner <digit@google.com>
Reviewed-by: Matt Stark <msta@google.com>

AUTHORS

@@ -14,6 +14,7 @@ IBM Inc. <*@*.ibm.com>
 Loongson Technology Corporation Limited. <*@loongson.cn>
 MIPS Technologies, Inc. <*@mips.com>
 NVIDIA Corporation <*@nvidia.com>
+OpenAI <*@openai.com>
 Opera Software ASA <*@opera.com>
 Red Hat Inc. <*@redhat.com>
 The Chromium Authors <*@chromium.org>

docs/reference.md

@@ -3206,7 +3206,8 @@
 
 ```
   Prints all arguments to the console separated by spaces. A newline is
-  automatically appended to the end.
+  automatically appended to the end. In quiet mode (-q command-line parameter)
+  the output will be buffered and only printed if there is a fatal error.
 
   This function is intended for debugging. Note that build files are run in
   parallel so you may get interleaved prints. A buildfile may also be executed

src/gn/err.cc

@@ -8,6 +8,7 @@
 
 #include <atomic>
 #include <mutex>
+#include <string_view>
 
 #include "base/command_line.h"
 #include "base/strings/string_number_conversions.h"
@@ -81,11 +82,22 @@ void FillRangeOnLine(const LocationRange& range,
     line->at(i) = '-';
 }
 
+void OutputErrString(bool is_fatal,
+                     std::string_view output,
+                     TextDecoration dec = DECORATION_NONE) {
+  if (is_fatal) {
+    OutputString(output, dec);
+  } else {
+    OutputLogString(output, dec);
+  }
+}
+
 // The line length is used to clip the maximum length of the markers we'll
 // make if the error spans more than one line (like unterminated literals).
 void OutputHighlighedPosition(const Location& location,
                               const Err::RangeList& ranges,
-                              size_t line_length) {
+                              size_t line_length,
+                              bool is_fatal) {
   // Make a buffer of the line in spaces.
   std::string highlight;
   highlight.resize(line_length);
@@ -107,7 +119,7 @@ void OutputHighlighedPosition(const Location& location,
     highlight.resize(highlight.size() - 1);
 
   highlight += "\n";
-  OutputString(highlight, DECORATION_BLUE);
+  OutputErrString(is_fatal, highlight, DECORATION_BLUE);
 }
 
 }  // namespace
@@ -167,6 +179,7 @@ Err& Err::operator=(const Err& other) {
 }
 
 bool Err::PrintToStdout() const {
+  FlushBufferedOutput();
   return InternalPrintToStdout(false, true);
 }
 
@@ -187,7 +200,8 @@ bool Err::InternalPrintToStdout(bool is_sub_err, bool is_fatal) const {
       int printed = ++g_num_errors_printed;
       if (printed > limit) {
         if (printed == limit + 1) {
-          OutputString(
+          OutputErrString(
+              is_fatal,
               "Too many errors/warnings. Suppressing further messages.\n"
               "You can change the limit by passing --error-limit=<number>.\n",
               DECORATION_RED);
@@ -199,7 +213,7 @@ bool Err::InternalPrintToStdout(bool is_sub_err, bool is_fatal) const {
     if (is_fatal)
       OutputString("ERROR ", DECORATION_RED);
     else
-      OutputString("WARNING ", DECORATION_MAGENTA);
+      OutputLogString("WARNING ", DECORATION_MAGENTA);
   }
 
   // File name and location.
@@ -221,21 +235,23 @@ bool Err::InternalPrintToStdout(bool is_sub_err, bool is_fatal) const {
   std::string colon;
   if (!loc_str.empty() || !toolchain_str.empty())
     colon = ": ";
-  OutputString(loc_str + toolchain_str + colon + info_->message + "\n");
+  OutputErrString(is_fatal,
+                  loc_str + toolchain_str + colon + info_->message + "\n");
 
   // Quoted line.
   if (input_file) {
     std::string line =
         GetNthLine(input_file->contents(), info_->location.line_number());
     if (!base::ContainsOnlyChars(line, base::kWhitespaceASCII)) {
-      OutputString(line + "\n", DECORATION_DIM);
-      OutputHighlighedPosition(info_->location, info_->ranges, line.size());
+      OutputErrString(is_fatal, line + "\n", DECORATION_DIM);
+      OutputHighlighedPosition(info_->location, info_->ranges, line.size(),
+                               is_fatal);
     }
   }
 
   // Optional help text.
   if (!info_->help_text.empty())
-    OutputString(info_->help_text + "\n");
+    OutputErrString(is_fatal, info_->help_text + "\n");
 
   // Sub errors.
   for (const auto& sub_err : info_->sub_errs)

src/gn/functions.cc

@@ -24,6 +24,7 @@
 #include "gn/scheduler.h"
 #include "gn/scope.h"
 #include "gn/settings.h"
+#include "gn/standard_out.h"
 #include "gn/template.h"
 #include "gn/token.h"
 #include "gn/value.h"
@@ -951,7 +952,8 @@ const char kPrint_Help[] =
     R"(print: Prints to the console.
 
   Prints all arguments to the console separated by spaces. A newline is
-  automatically appended to the end.
+  automatically appended to the end. In quiet mode (-q command-line parameter)
+  the output will be buffered and only printed if there is a fatal error.
 
   This function is intended for debugging. Note that build files are run in
   parallel so you may get interleaved prints. A buildfile may also be executed
@@ -983,8 +985,7 @@ Value RunPrint(Scope* scope,
   if (cb) {
     cb(output);
   } else {
-    printf("%s", output.c_str());
-    fflush(stdout);
+    OutputLogString(output);
   }
 
   return Value();
@@ -1045,8 +1046,7 @@ Value RunPrintStackTrace(Scope* scope,
   if (cb) {
     cb(output);
   } else {
-    printf("%s", output.c_str());
-    fflush(stdout);
+    OutputLogString(output);
   }
 
   return Value();

src/gn/gn_main.cc

@@ -70,6 +70,12 @@ int main(int argc, char** argv) {
   commands::CommandInfoMap::const_iterator found_command =
       command_map.find(command);
 
+  // Buffer nonfatal log output if requested. This must be set up before
+  // starting any worker threads.
+  if (cmdline.HasSwitch(switches::kQuiet)) {
+    BufferLogOutput();
+  }
+
   int retval;
   if (found_command != command_map.end()) {
     MsgLoop msg_loop;
@@ -84,5 +90,10 @@ int main(int argc, char** argv) {
     retval = 1;
   }
 
+  if (retval != 0) {
+    // Failed, print out log info we buffered.
+    FlushBufferedOutput();
+  }
+
   exit(retval);  // Don't free memory, it can be really slow!
 }

src/gn/invoke_python.cc

@@ -46,7 +46,7 @@ bool InvokePython(const BuildSettings* build_settings,
     return false;
   }
 
-  if (!quiet) {
+  if (!quiet || exit_code != 0) {
     printf("%s", output.c_str());
     fprintf(stderr, "%s", stderr_output.c_str());
   }

src/gn/scheduler.cc

@@ -174,8 +174,8 @@ void Scheduler::SuppressOutputForTesting(bool suppress) {
 
 void Scheduler::LogOnMainThread(const std::string& verb,
                                 const std::string& msg) {
-  OutputString(verb, DECORATION_YELLOW);
-  OutputString(" " + msg + "\n");
+  OutputLogString(verb, DECORATION_YELLOW);
+  OutputLogString(" " + msg + "\n");
 }
 
 void Scheduler::FailWithErrorOnMainThread(const Err& err) {

src/gn/scheduler.h

@@ -154,6 +154,10 @@ class Scheduler {
   Scheduler& operator=(const Scheduler&) = delete;
 };
 
+// Global instance. Normally initialized by the Setup class. This is guaranteed
+// non-null during normal build operations, but can be null for certain early
+// code in command dispatch or during other non-run things like the help
+// function.
 extern Scheduler* g_scheduler;
 
 #endif  // TOOLS_GN_SCHEDULER_H_

src/gn/setup.cc

@@ -557,7 +557,7 @@ bool Setup::RunPostMessageLoop(const base::CommandLine& cmdline) {
       return false;
     }
     err.PrintNonfatalToStdout();
-    OutputString(
+    OutputLogString(
         "\nThe build continued as if that argument was "
         "unspecified.\n\n");
     // Nonfatal error.

src/gn/standard_out.cc

@@ -6,6 +6,7 @@
 
 #include <stddef.h>
 
+#include <mutex>
 #include <string_view>
 #include <vector>
 
@@ -95,18 +96,11 @@ void OutputMarkdownDec(TextDecoration dec) {
 #endif
 }
 
-}  // namespace
-
-bool IsColorEnabled() {
-  EnsureInitialized();
-  return is_console;
-}
-
 #if defined(OS_WIN)
 
-void OutputString(std::string_view output,
-                  TextDecoration dec,
-                  HtmlEscaping escaping) {
+void WriteOutputString(std::string_view output,
+                       TextDecoration dec,
+                       HtmlEscaping escaping) {
   EnsureInitialized();
   DWORD written = 0;
 
@@ -167,9 +161,9 @@ void OutputString(std::string_view output,
 
 #else
 
-void OutputString(std::string_view output,
-                  TextDecoration dec,
-                  HtmlEscaping escaping) {
+void WriteOutputString(std::string_view output,
+                       TextDecoration dec,
+                       HtmlEscaping escaping) {
   EnsureInitialized();
   if (is_markdown) {
     OutputMarkdownDec(dec);
@@ -223,6 +217,98 @@ void OutputString(std::string_view output,
 
 #endif
 
+// Collects buffered log output for quiet mode.
+class QuietModeBuffer {
+ public:
+  void Append(std::string_view output,
+              TextDecoration decoration,
+              HtmlEscaping escaping) {
+    {
+      std::lock_guard<std::mutex> lock(lock_);
+      if (!is_flushed_) {
+        output_buffer_.push_back({std::string(output), decoration, escaping});
+        return;
+      }
+      // Otherwise fall-through to printing to stdout outside the lock.
+    }
+    WriteOutputString(output, decoration, escaping);
+  }
+
+  // Outputs any queued output to the standard out.
+  void Flush() {
+    // Do everything inside the lock so we guarantee we flush all previous
+    // output before writing something else from another thread. Flushing will
+    // only happen in error cases so this will not be performance-critical.
+    std::lock_guard<std::mutex> lock(lock_);
+
+    if (is_flushed_)
+      return;
+    is_flushed_ = true;
+
+    for (const BufferedOutput& output : output_buffer_) {
+      WriteOutputString(output.output, output.decoration, output.escaping);
+    }
+    output_buffer_.clear();
+  }
+
+ private:
+  struct BufferedOutput {
+    std::string output;
+    TextDecoration decoration;
+    HtmlEscaping escaping;
+  };
+
+  std::mutex lock_;
+
+  // Set when we're in quiet mode but then flush the output. This means that
+  // future output should go directly to the terminal (this solves the problem
+  // of safely turning "off" quiet mode when we hit an error because
+  // quiet_mode_buffer isn't threadsafe).
+  bool is_flushed_ = false;
+
+  std::vector<BufferedOutput> output_buffer_;
+};
+
+// Non-null while buffering standard output. Deliberately leaked on shutdown.
+QuietModeBuffer* quiet_mode_buffer = nullptr;
+
+}  // namespace
+
+bool IsColorEnabled() {
+  EnsureInitialized();
+  return is_console;
+}
+
+void OutputString(std::string_view output,
+                  TextDecoration dec,
+                  HtmlEscaping escaping) {
+  WriteOutputString(output, dec, escaping);
+}
+
+void OutputLogString(std::string_view output,
+                     TextDecoration dec,
+                     HtmlEscaping escaping) {
+  if (quiet_mode_buffer) {
+    quiet_mode_buffer->Append(output, dec, escaping);
+    return;
+  }
+  WriteOutputString(output, dec, escaping);
+}
+
+void BufferLogOutput() {
+  if (quiet_mode_buffer) {
+    DCHECK(false);  // Expecting to only be called once.
+    return;
+  }
+  quiet_mode_buffer = new QuietModeBuffer();
+}
+
+void FlushBufferedOutput() {
+  if (quiet_mode_buffer) {
+    quiet_mode_buffer->Flush();
+  }
+}
+
 void PrintSectionHelp(const std::string& line,
                       const std::string& topic,
                       const std::string& tag) {

src/gn/standard_out.h

@@ -29,6 +29,21 @@ void OutputString(std::string_view output,
                   TextDecoration dec = DECORATION_NONE,
                   HtmlEscaping = DEFAULT_ESCAPING);
 
+// Use for nonfatal warnings and log messages printed out during execution.
+//
+// Like OutputString() but in quiet mode this will buffer the output and only
+// print it if there was a failure. Use for things that are neither errors nor
+// the "main output" of the application.
+void OutputLogString(std::string_view output,
+                     TextDecoration dec = DECORATION_NONE,
+                     HtmlEscaping = DEFAULT_ESCAPING);
+
+// Enable or flush to stdout the for quiet mode from OutputLogString().
+// BufferLogOutput() is not threadsafe and is expected to be called from early
+// process init before we've created any worker thread.
+void BufferLogOutput();
+void FlushBufferedOutput();
+
 // If printing markdown, this generates table-of-contents entries with
 // links to the actual help; otherwise, prints a one-line description.
 void PrintSectionHelp(const std::string& line,