RealCommandRunner: allow periodic status updates during builds.

Use the new Subprocess::DoWork(int64_t) method to wait for at
most one second before updating the status in the Ninja terminal.

NOTE: A new output_test.py is added to check this feature, but
      since it is time-dependent, it tends to fail on Github CI
      so is disabled by default. It is possible to run it manually
      though on a lightly-loaded machine.

Author: digit-google

doc/manual.asciidoc

@@ -190,7 +190,8 @@ you don't need to pass `-j`.)
 Environment variables
 ~~~~~~~~~~~~~~~~~~~~~
 
-Ninja supports one environment variable to control its behavior:
+Ninja supports a few environment variables to control its behavior:
+
 `NINJA_STATUS`, the progress status printed before the rule being run.
 
 Several placeholders are available:
@@ -215,6 +216,12 @@ The default progress status is `"[%f/%t] "` (note the trailing space
 to separate from the build rule). Another example of possible progress status
 could be `"[%u/%r/%f] "`.
 
+`NINJA_STATUS_REFRESH_MILLIS`, the refresh timeout in milliseconds
+for status updates in interactive terminals. The default value is 1000,
+to allow time-sensitive formatters like `%w` to be updated during
+long build runs (e.g. when one or more build commands run for a long
+time).
+
 Extra tools
 ~~~~~~~~~~~
 

misc/output_test.py

@@ -16,6 +16,7 @@
 
 default_env = dict(os.environ)
 default_env.pop('NINJA_STATUS', None)
+default_env.pop('NINJA_STATUS_REFRESH_MILLIS', None)
 default_env.pop('CLICOLOR_FORCE', None)
 default_env['TERM'] = ''
 NINJA_PATH = os.path.abspath('./ninja')
@@ -310,6 +311,41 @@ def test_ninja_status_quiet(self) -> None:
         output = run(Output.BUILD_SIMPLE_ECHO, flags='--quiet')
         self.assertEqual(output, 'do thing\n')
 
+    @unittest.skip("Time-based test fails on Github CI")
+    def test_ninja_status_periodic_update(self) -> None:
+        b =  BuildDir('''\
+           rule sleep_then_print
+             command = sleep 2 && echo done
+             description = sleep2s
+
+           build all: sleep_then_print
+           ''')
+        with b:
+          env = default_env.copy()
+          env["NINJA_STATUS"] = "[%w] "
+          self.assertListEqual(
+            b.run('all', raw_output=True, env=env).replace("\r\n", "<CRLF>").split("\r"),
+            [
+              "",
+              "[00:00] sleep2s\x1b[K",
+              "[00:01] sleep2s\x1b[K",
+              "[00:02] sleep2s\x1b[K",
+              "[00:02] sleep2s\x1b[K<CRLF>done<CRLF>",
+            ])
+
+          env["NINJA_STATUS_REFRESH_MILLIS"] = "500"
+          self.assertListEqual(
+            b.run('all', raw_output=True, env=env).replace("\r\n", "<CRLF>").split("\r"),
+            [
+              "",
+              "[00:00] sleep2s\x1b[K",
+              "[00:00] sleep2s\x1b[K",
+              "[00:01] sleep2s\x1b[K",
+              "[00:01] sleep2s\x1b[K",
+              "[00:02] sleep2s\x1b[K",
+              "[00:02] sleep2s\x1b[K<CRLF>done<CRLF>",
+            ])
+
     def test_entering_directory_on_stdout(self) -> None:
         output = run(Output.BUILD_SIMPLE_ECHO, flags='-C$PWD', pipe=True)
         self.assertEqual(output.splitlines()[0][:25], "ninja: Entering directory")

src/build.cc

@@ -696,10 +696,13 @@ bool Builder::Build(string* err) {
 
   // Set up the command runner if we haven't done so already.
   if (!command_runner_.get()) {
-    if (config_.dry_run)
+    if (config_.dry_run) {
       command_runner_.reset(new DryRunCommandRunner);
-    else
-      command_runner_.reset(CommandRunner::factory(config_));
+    } else {
+      command_runner_.reset(CommandRunner::factory(config_, [this]() {
+        status_->Refresh(GetTimeMillis() - start_time_millis_);
+      }));
+    }
   }
 
   // We are about to start the build process.

src/build.h

@@ -16,6 +16,7 @@
 #define NINJA_BUILD_H_
 
 #include <cstdio>
+#include <functional>
 #include <map>
 #include <memory>
 #include <string>
@@ -151,6 +152,9 @@ struct CommandRunner {
   virtual size_t CanRunMore() const = 0;
   virtual bool StartCommand(Edge* edge) = 0;
 
+  // A callable value used to refresh the current Ninja status.
+  using StatusRefresher = std::function<void(void)>;
+
   /// The result of waiting for a command.
   struct Result {
     Result() : edge(NULL) {}
@@ -166,27 +170,30 @@ struct CommandRunner {
   virtual void Abort() {}
 
   /// Creates the RealCommandRunner
-  static CommandRunner* factory(const BuildConfig& config);
+  static CommandRunner* factory(const BuildConfig& config,
+                                StatusRefresher&& refresh_status);
 };
 
 /// Options (e.g. verbosity, parallelism) passed to a build.
 struct BuildConfig {
-  BuildConfig() : verbosity(NORMAL), dry_run(false), parallelism(1),
-                  failures_allowed(1), max_load_average(-0.0f) {}
+  BuildConfig() = default;
 
   enum Verbosity {
     QUIET,  // No output -- used when testing.
     NO_STATUS_UPDATE,  // just regular output but suppress status update
     NORMAL,  // regular output and status update
     VERBOSE
   };
-  Verbosity verbosity;
-  bool dry_run;
-  int parallelism;
-  int failures_allowed;
+  Verbosity verbosity = NORMAL;
+  bool dry_run = false;
+  int parallelism = 1;
+  int failures_allowed = 1;
   /// The maximum load average we must not exceed. A negative value
   /// means that we do not have any limit.
-  double max_load_average;
+  double max_load_average = -0.0f;
+  /// Number of milliseconds between status refreshes in interactive
+  /// terminals.
+  int status_refresh_millis = 1000;
   DepfileParserOptions depfile_parser_options;
 };
 

src/ninja.cc

@@ -1729,6 +1729,11 @@ NORETURN void real_main(int argc, char** argv) {
   Options options = {};
   options.input_file = "build.ninja";
 
+  const char* status_refresh_env = getenv("NINJA_STATUS_REFRESH_MILLIS");
+  if (status_refresh_env) {
+    config.status_refresh_millis = atoi(status_refresh_env);
+  }
+
   setvbuf(stdout, NULL, _IOLBF, BUFSIZ);
   const char* ninja_command = argv[0];
 

src/real_command_runner.cc

@@ -16,14 +16,17 @@
 #include "subprocess.h"
 
 struct RealCommandRunner : public CommandRunner {
-  explicit RealCommandRunner(const BuildConfig& config) : config_(config) {}
+  explicit RealCommandRunner(const BuildConfig& config,
+                             StatusRefresher&& refresh_status)
+      : config_(config), refresh_status_(std::move(refresh_status)) {}
   size_t CanRunMore() const override;
   bool StartCommand(Edge* edge) override;
   bool WaitForCommand(Result* result) override;
   std::vector<Edge*> GetActiveEdges() override;
   void Abort() override;
 
   const BuildConfig& config_;
+  StatusRefresher refresh_status_;
   SubprocessSet subprocs_;
   std::map<const Subprocess*, Edge*> subproc_to_edge_;
 };
@@ -75,9 +78,14 @@ bool RealCommandRunner::StartCommand(Edge* edge) {
 
 bool RealCommandRunner::WaitForCommand(Result* result) {
   Subprocess* subproc;
-  while ((subproc = subprocs_.NextFinished()) == NULL) {
-    bool interrupted = subprocs_.DoWork();
-    if (interrupted)
+  while ((subproc = subprocs_.NextFinished()) == nullptr) {
+    SubprocessSet::WorkResult ret =
+        subprocs_.DoWork(config_.status_refresh_millis);
+    if (ret == SubprocessSet::WorkResult::TIMEOUT) {
+      refresh_status_();
+      continue;
+    }
+    if (ret == SubprocessSet::WorkResult::INTERRUPTION)
       return false;
   }
 
@@ -93,6 +101,7 @@ bool RealCommandRunner::WaitForCommand(Result* result) {
   return true;
 }
 
-CommandRunner* CommandRunner::factory(const BuildConfig& config) {
-  return new RealCommandRunner(config);
+CommandRunner* CommandRunner::factory(const BuildConfig& config,
+                                      StatusRefresher&& refresh_status) {
+  return new RealCommandRunner(config, std::move(refresh_status));
 }