[C++] Add an option to show timing stats

7 files changed, 94 insertions, 6 deletions

diff --git a/Makefile b/Makefile
index 8e0ed77..46d7730 100644
--- a/Makefile
+++ b/Makefile
@@ -30,6 +30,7 @@ CXX_SRCS:= \
 	string_pool.cc \
 	stringprintf.cc \
 	strutil.cc \
+	time.cc \
 	value.cc \
 	var.cc
 CXX_TEST_SRCS:= \
diff --git a/flags.cc b/flags.cc
index de95408..bf19f14 100644
--- a/flags.cc
+++ b/flags.cc
@@ -16,4 +16,5 @@
 
 #include "flags.h"
 
+bool g_enable_stat_logs;
 bool g_is_dry_run;
diff --git a/flags.h b/flags.h
index a2e806a..c6452c6 100644
--- a/flags.h
+++ b/flags.h
@@ -16,5 +16,6 @@
 #define FLAGS_H_
 
 extern bool g_is_dry_run;
+extern bool g_enable_stat_logs;
 
 #endif  // FLAGS_H_
diff --git a/log.h b/log.h
index ee16a21..6ff26ab 100644
--- a/log.h
+++ b/log.h
@@ -20,6 +20,7 @@
 #include <stdlib.h>
 #include <string.h>
 
+#include "flags.h"
 #include "stringprintf.h"
 
 #ifdef NOLOG
@@ -30,6 +31,11 @@
   } while(0)
 #endif
 
+#define LOG_STAT(args...) do {                                      \
+    if (g_enable_stat_logs)                                         \
+      fprintf(stderr, "*kati*: %s\n", StringPrintf(args).c_str());  \
+  } while(0)
+
 #define PERROR(...) do {                                            \
     fprintf(stderr, "%s: %s\n", StringPrintf(__VA_ARGS__).c_str(),  \
             strerror(errno));                                       \
diff --git a/main.cc b/main.cc
index 3b503fa..314df7e 100644
--- a/main.cc
+++ b/main.cc
@@ -33,6 +33,7 @@
 #include "string_piece.h"
 #include "stringprintf.h"
 #include "strutil.h"
+#include "time.h"
 #include "var.h"
 
 static const char* g_makefile;
@@ -49,6 +50,8 @@ static void ParseCommandLine(int argc, char* argv[],
       g_is_syntax_check_only = true;
     } else if (!strcmp(arg, "-i")) {
       g_is_dry_run = true;
+    } else if (!strcmp(arg, "--kati_stats")) {
+      g_enable_stat_logs = true;
     } else if (arg[0] == '-') {
       ERROR("Unknown flag: %s", arg);
     } else {
@@ -160,14 +163,20 @@ static int Run(const vector<StringPiece>& targets,
                new SimpleVar(make_shared<string>(
                    StringPrintf(" %s", g_makefile)), VarOrigin::FILE));
 
-  Makefile* mk = cache_mgr->ReadMakefile(g_makefile);
-  for (AST* ast : mk->asts()) {
-    LOG("%s", ast->DebugString().c_str());
-    ast->Eval(ev);
+  {
+    ScopedTimeReporter tr("eval time");
+    Makefile* mk = cache_mgr->ReadMakefile(g_makefile);
+    for (AST* ast : mk->asts()) {
+      LOG("%s", ast->DebugString().c_str());
+      ast->Eval(ev);
+    }
   }
 
   vector<DepNode*> nodes;
-  MakeDep(ev, ev->rules(), ev->rule_vars(), targets, &nodes);
+  {
+    ScopedTimeReporter tr("make dep time");
+    MakeDep(ev, ev->rules(), ev->rule_vars(), targets, &nodes);
+  }
 
   for (const auto& p : ev->exports()) {
     const string& name = p.first.as_string();
@@ -185,7 +194,10 @@ static int Run(const vector<StringPiece>& targets,
   if (g_is_syntax_check_only)
     return 0;
 
-  Exec(nodes, ev);
+  {
+    ScopedTimeReporter tr("exec time");
+    Exec(nodes, ev);
+  }
 
   for (AST* ast : bootstrap_asts)
     delete ast;
diff --git a/time.cc b/time.cc
new file mode 100644
index 0000000..784e4c2
--- /dev/null
+++ b/time.cc
@@ -0,0 +1,37 @@
+// Copyright 2015 Google Inc. All rights reserved
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//      http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+// +build ignore
+
+#include "time.h"
+
+#include <sys/time.h>
+
+#include "log.h"
+
+double GetTime() {
+  struct timeval tv;
+  if (gettimeofday(&tv, NULL) < 0)
+    PERROR("gettimeofday");
+  return tv.tv_sec + tv.tv_usec * 0.001 * 0.001;
+}
+
+ScopedTimeReporter::ScopedTimeReporter(const char* name)
+    : name_(name), start_(GetTime()) {
+}
+
+ScopedTimeReporter::~ScopedTimeReporter() {
+  double elapsed = GetTime() - start_;
+  LOG_STAT("%s: %f", name_, elapsed);
+}
diff --git a/time.h b/time.h
new file mode 100644
index 0000000..08aa0c1
--- /dev/null
+++ b/time.h
@@ -0,0 +1,30 @@
+// Copyright 2015 Google Inc. All rights reserved
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//      http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+
+#ifndef TIME_H_
+#define TIME_H_
+
+double GetTime();
+
+struct ScopedTimeReporter {
+ public:
+  explicit ScopedTimeReporter(const char* name);
+  ~ScopedTimeReporter();
+
+ private:
+  const char* name_;
+  double start_;
+};
+
+#endif  // TIME_H_