From 8eb566fee272831e992ad3028be2572bcfccf74a Mon Sep 17 00:00:00 2001
From: Evan Martin <martine@danga.com>
Date: Sat, 8 Jan 2011 15:13:07 -0800
Subject: [PATCH] compute edge timing

---
 src/build.cc | 36 ++++++++++++++++++++++++++++--------
 1 file changed, 28 insertions(+), 8 deletions(-)

diff --git a/src/build.cc b/src/build.cc
index 0aa1d10..bf897a3 100644
--- a/src/build.cc
+++ b/src/build.cc
@@ -1,6 +1,7 @@
 #include "build.h"
 
 #include <stdio.h>
+#include <sys/time.h>
 
 #include "build_log.h"
 #include "graph.h"
@@ -16,6 +17,9 @@ struct BuildStatus {
   time_t last_update_;
   int finished_edges_, total_edges_;
 
+  typedef map<Edge*, timeval> RunningEdgeMap;
+  RunningEdgeMap running_edges_;
+
   BuildConfig::Verbosity verbosity_;
 };
 
@@ -28,6 +32,13 @@ void BuildStatus::PlanHasTotalEdges(int total) {
 }
 
 void BuildStatus::BuildEdgeStarted(Edge* edge) {
+  timeval now;
+  gettimeofday(&now, NULL);
+  running_edges_.insert(make_pair(edge, now));
+
+  if (edge->rule_ == &State::kPhonyRule)
+    return;
+
   string desc = edge->GetDescription();
   if (verbosity_ != BuildConfig::QUIET) {
     if (verbosity_ != BuildConfig::VERBOSE && !desc.empty())
@@ -38,13 +49,21 @@ void BuildStatus::BuildEdgeStarted(Edge* edge) {
 }
 
 void BuildStatus::BuildEdgeFinished(Edge* edge) {
+  timeval now;
+  gettimeofday(&now, NULL);
   ++finished_edges_;
-  time_t now = time(NULL);
-  if (now - last_update_ > 5) {
+
+  if (now.tv_sec - last_update_ > 5) {
     printf("%.1f%% %d/%d\n", finished_edges_ * 100 / (float)total_edges_,
            finished_edges_, total_edges_);
-    last_update_ = now;
+    last_update_ = now.tv_sec;
   }
+
+  RunningEdgeMap::iterator i = running_edges_.find(edge);
+  timeval delta;
+  timersub(&now, &i->second, &delta);
+  printf("%dms\n", (int)((delta.tv_sec * 1000) + (delta.tv_usec / 1000)));
+  running_edges_.erase(i);
 }
 
 bool Plan::AddTarget(Node* node, string* err) {
@@ -289,13 +308,11 @@ bool Builder::Build(string* err) {
       if (!edge)
         break;
 
-      if (edge->rule_ == &State::kPhonyRule) {
-        FinishEdge(edge);
-        continue;
-      }
-
       if (!StartEdge(edge, err))
         return false;
+
+      if (edge->rule_ == &State::kPhonyRule)
+        FinishEdge(edge);
     }
 
     bool success;
@@ -319,6 +336,9 @@ bool Builder::Build(string* err) {
 bool Builder::StartEdge(Edge* edge, string* err) {
   status_->BuildEdgeStarted(edge);
 
+  if (edge->rule_ == &State::kPhonyRule)
+    return true;
+
   // Create directories necessary for outputs.
   // XXX: this will block; do we care?
   for (vector<Node*>::iterator i = edge->outputs_.begin();
-- 
2.7.4