print edges per second

prints the rate of finished edges per second to the console,
for instance with NINJA_STATUS="[%s/%t %o(%c)/s] ":

[132/1922 16.1(14)/s]

16.1 is the average for all processed files (here 132 since start)
14 is the average of the last n files while n is the number specifies by
-j (or its default)

9 files changed, 100 insertions, 16 deletions

diff --git a/src/build.cc b/src/build.cc
index 0fc387c..48e5c4b 100644
--- a/src/build.cc
+++ b/src/build.cc
@@ -37,7 +37,9 @@ BuildStatus::BuildStatus(const BuildConfig& config)
     : config_(config),
       start_time_millis_(GetTimeMillis()),
       started_edges_(0), finished_edges_(0), total_edges_(0),
-      have_blank_line_(true), progress_status_format_(NULL) {
+      have_blank_line_(true), progress_status_format_(NULL),
+      overall_rate_(), current_rate_(),
+      current_rate_average_count_(config.parallelism) {
 #ifndef _WIN32
   const char* term = getenv("TERM");
   smart_terminal_ = isatty(1) && term && string(term) != "dumb";
@@ -171,6 +173,25 @@ string BuildStatus::FormatProgressStatus(const char* progress_status_format) con
         out += buf;
         break;
 
+      // Overall finished edges per second.
+      case 'o':
+        overall_rate_.UpdateRate(finished_edges_, finished_edges_);
+        overall_rate_.snprinfRate(buf, "%.1f");
+        out += buf;
+        break;
+
+      // Current rate, average over the last '-j' jobs.
+      case 'c':
+        // TODO use sliding window?
+        if (finished_edges_ > current_rate_.last_update() &&
+            finished_edges_ - current_rate_.last_update() == current_rate_average_count_) {
+          current_rate_.UpdateRate(current_rate_average_count_, finished_edges_);
+          current_rate_.Restart();
+        }
+        current_rate_.snprinfRate(buf, "%.0f");
+        out += buf;
+        break;
+
       default: {
         Fatal("unknown placeholder '%%%c' in $NINJA_STATUS", *s);
         return "";
@@ -208,6 +229,10 @@ void BuildStatus::PrintStatus(Edge* edge) {
 #endif
   }
 
+  if (finished_edges_ == 0) {
+    overall_rate_.Restart();
+    current_rate_.Restart();
+  }
   to_print = FormatProgressStatus(progress_status_format_) + to_print;
 
   if (smart_terminal_ && !force_full_command) {
@@ -770,3 +795,4 @@ void Builder::FinishEdge(Edge* edge, bool success, const string& output) {
   if (success && log_)
     log_->RecordCommand(edge, start_time, end_time, restat_mtime);
 }
+
diff --git a/src/build.h b/src/build.h
index c9ee4ac..4859c29 100644
--- a/src/build.h
+++ b/src/build.h
@@ -24,6 +24,7 @@
 using namespace std;
 
 #include "exit_status.h"
+#include "metrics.h"
 #include "util.h"  // int64_t
 
 struct BuildLog;
@@ -191,9 +192,43 @@ struct BuildStatus {
   /// The custom progress status format to use.
   const char* progress_status_format_;
 
+  struct RateInfo {
+    RateInfo() : last_update_(0), rate_(-1) {}
+
+    double rate() const { return rate_; }
+    int last_update() const { return last_update_; }
+    void Restart() { return stopwatch_.Restart(); }
+
+    double UpdateRate(int edges, int update_hint) {
+      if (update_hint != last_update_) {
+        rate_ = edges / stopwatch_.Elapsed() + 0.5;
+        last_update_ = update_hint;
+      }
+      return rate_;
+    }
+
+    template<class T>
+    void snprinfRate(T buf, const char* format) {
+      if (rate_ == -1)
+        snprintf(buf, sizeof(buf), "?");
+      else
+        snprintf(buf, sizeof(buf), format, rate_);
+    }
+
+  private:
+    Stopwatch stopwatch_;
+    int last_update_;
+    double rate_;
+  };
+
+  mutable RateInfo overall_rate_;
+  mutable RateInfo current_rate_;
+  const int current_rate_average_count_;
+
 #ifdef _WIN32
   void* console_;
 #endif
 };
 
 #endif  // NINJA_BUILD_H_
+
diff --git a/src/build_log_perftest.cc b/src/build_log_perftest.cc
index 02f4c60..5755079 100644
--- a/src/build_log_perftest.cc
+++ b/src/build_log_perftest.cc
@@ -20,6 +20,7 @@
 #include "manifest_parser.h"
 #include "state.h"
 #include "util.h"
+#include "metrics.h"
 
 const char kTestFilename[] = "BuildLogPerfTest-tempfile";
 
diff --git a/src/canon_perftest.cc b/src/canon_perftest.cc
index 6248937..d0ed397 100644
--- a/src/canon_perftest.cc
+++ b/src/canon_perftest.cc
@@ -16,6 +16,7 @@
 #include <string.h>
 
 #include "util.h"
+#include "metrics.h"
 
 const char kPath[] =
     "../../third_party/WebKit/Source/WebCore/"
diff --git a/src/metrics.cc b/src/metrics.cc
index fb44868..8407717 100644
--- a/src/metrics.cc
+++ b/src/metrics.cc
@@ -72,6 +72,7 @@ int64_t TimerToMicros(int64_t dt) {
 
 }  // anonymous namespace
 
+
 ScopedMetric::ScopedMetric(Metric* metric) {
   metric_ = metric;
   if (!metric_)
@@ -113,3 +114,12 @@ void Metrics::Report() {
            metric->count, avg, total);
   }
 }
+
+uint64_t Stopwatch::Now() const {
+  return TimerToMicros(HighResTimer());
+}
+
+int64_t GetTimeMillis() {
+  return 1000 * TimerToMicros(HighResTimer());
+}
+
diff --git a/src/metrics.h b/src/metrics.h
index af6e9a2..dae6b9f 100644
--- a/src/metrics.h
+++ b/src/metrics.h
@@ -33,6 +33,7 @@ struct Metric {
   int64_t sum;
 };
 
+
 /// A scoped object for recording a metric across the body of a function.
 /// Used by the METRIC_RECORD macro.
 struct ScopedMetric {
@@ -57,6 +58,30 @@ private:
   vector<Metric*> metrics_;
 };
 
+/// Get the current time as relative to some epoch.
+/// Epoch varies between platforms; only useful for measuring elapsed
+/// time.
+int64_t GetTimeMillis();
+
+
+/// A simple stopwatch which retruns the time
+// in seconds since Restart() was called
+class Stopwatch
+{
+public:
+  Stopwatch() : started_(0) {}
+
+  /// Seconds since Restart() call
+  double Elapsed() const { return 1e-6 * (Now() - started_); }
+
+  void Restart() { started_ = Now(); }
+
+private:
+  uint64_t started_;
+  uint64_t Now() const;
+};
+
+
 /// The primary interface to metrics.  Use METRIC_RECORD("foobar") at the top
 /// of a function to get timing stats recorded for each call of the function.
 #define METRIC_RECORD(name)                                             \
diff --git a/src/parser_perftest.cc b/src/parser_perftest.cc
index b1d5bf0..b215221 100644
--- a/src/parser_perftest.cc
+++ b/src/parser_perftest.cc
@@ -17,6 +17,7 @@
 
 #include "depfile_parser.h"
 #include "util.h"
+#include "metrics.h"
 
 int main(int argc, char* argv[]) {
   if (argc < 2) {
diff --git a/src/util.cc b/src/util.cc
index d8d7fb3..ab3275a 100644
--- a/src/util.cc
+++ b/src/util.cc
@@ -204,16 +204,6 @@ void SetCloseOnExec(int fd) {
 #endif  // ! _WIN32
 }
 
-int64_t GetTimeMillis() {
-#ifdef _WIN32
-  // GetTickCount64 is only available on Vista or later.
-  return GetTickCount();
-#else
-  timeval now;
-  gettimeofday(&now, NULL);
-  return ((int64_t)now.tv_sec * 1000) + (now.tv_usec / 1000);
-#endif
-}
 
 const char* SpellcheckStringV(const string& text,
                               const vector<const char*>& words) {
diff --git a/src/util.h b/src/util.h
index 82f4850..b108c25 100644
--- a/src/util.h
+++ b/src/util.h
@@ -53,11 +53,6 @@ int ReadFile(const string& path, string* contents, string* err);
 /// Mark a file descriptor to not be inherited on exec()s.
 void SetCloseOnExec(int fd);
 
-/// Get the current time as relative to some epoch.
-/// Epoch varies between platforms; only useful for measuring elapsed
-/// time.
-int64_t GetTimeMillis();
-
 /// Given a misspelled string and a list of correct spellings, returns
 /// the closest match or NULL if there is no close enough match.
 const char* SpellcheckStringV(const string& text, const vector<const char*>& words);