Fix compiler stats

runtime/vm/compiler_stats.cc

Index: runtime/vm/compiler_stats.cc
diff --git a/runtime/vm/compiler_stats.cc b/runtime/vm/compiler_stats.cc
index 59d1dd4ab8b552dd4f2395f7e287b4de8205658f..f5266db2a05da556d4621dc4e9b0e73145f47092 100644
--- a/runtime/vm/compiler_stats.cc
+++ b/runtime/vm/compiler_stats.cc
@@ -5,6 +5,7 @@
 #include "vm/compiler_stats.h"
 
 #include "vm/flags.h"
+#include "vm/log.h"
 #include "vm/object_graph.h"
 #include "vm/timer.h"
 
@@ -14,16 +15,17 @@ namespace dart {
 DEFINE_FLAG(bool, compiler_stats, false, "Compiler stat counters.");
 
 
-class TokenStreamVisitor : public ObjectGraph::Visitor {
+class TokenStreamVisitor : public ObjectVisitor {
  public:
-  explicit TokenStreamVisitor(CompilerStats* compiler_stats)
-      : obj_(Object::Handle()), stats_(compiler_stats) {
+  TokenStreamVisitor(Isolate* isolate, CompilerStats* compiler_stats)
+      : ObjectVisitor(isolate),
+        obj_(Object::Handle()),
+        stats_(compiler_stats) {
   }
 
-  virtual Direction VisitObject(ObjectGraph::StackIterator* it) {
-    RawObject* raw_obj = it->Get();
+  void VisitObject(RawObject* raw_obj) {
     if (raw_obj->IsFreeListElement()) {
-      return kProceed;
+      return;
     }
     obj_ = raw_obj;
     if (obj_.GetClassId() == TokenStream::kClassId) {
@@ -42,7 +44,6 @@ class TokenStreamVisitor : public ObjectGraph::Visitor {
         kind = tkit.CurrentTokenKind();
       }
     }
-    return kProceed;
   }
 
  private:
@@ -71,24 +72,41 @@ CompilerStats::CompilerStats(Isolate* isolate)
       num_literal_tokens_total(0),
       num_ident_tokens_total(0),
       num_tokens_consumed(0),
-      num_token_checks(0),
-      num_tokens_lookahead(0),
       num_cached_consts(0),
       num_const_cache_hits(0),
-      num_classes_compiled(0),
+      num_classes_parsed(0),
+      num_class_tokens(0),
+      num_functions_parsed(0),
       num_functions_compiled(0),
+      num_functions_optimized(0),
+      num_func_tokens_compiled(0),
       num_implicit_final_getters(0),
+      num_method_extractors(0),
       src_length(0),
       total_code_size(0),
       total_instr_size(0),
       pc_desc_size(0),
-      vardesc_size(0) {
+      vardesc_size(0),
+      text(NULL) {
 }
 
 
-void CompilerStats::Print() {
+static void PrintToStats(const char* format, ...) {

[Ivan Posva, 2015/09/04 19:22:59]

Please ensure that format and parameters are valid by using PRINTF_ATTRIBUTE(1,
2).
Also a comment explaining that this is used to parameterize the Log below would
be helpful.

[hausner, 2015/09/04 20:45:20]

Done.

+  Thread* thread = Thread::Current();
+  Isolate* isolate = thread->isolate();
+  CompilerStats* stats = isolate->compiler_stats();
+  Zone* zone = thread->zone();
+  ASSERT(stats != NULL);
+  va_list args;
+  va_start(args, format);
+  stats->text = zone->VPrint(format, args);
+  va_end(args);
+}
+
+
+char* CompilerStats::PrintToZone() {
   if (!FLAG_compiler_stats) {
-    return;
+    return NULL;
   }
 
   // Traverse the heap and compute number of tokens in all
@@ -96,85 +114,97 @@ void CompilerStats::Print() {
   num_tokens_total = 0;
   num_literal_tokens_total = 0;
   num_ident_tokens_total = 0;
-  TokenStreamVisitor visitor(this);
-  ObjectGraph graph(isolate_);
-  graph.IterateObjects(&visitor);
+  TokenStreamVisitor visitor(isolate_, this);
+  isolate_->heap()->IterateObjects(&visitor);
+  Dart::vm_isolate()->heap()->IterateObjects(&visitor);
 
-  OS::Print("==== Compiler Stats for isolate '%s' ====\n",
+  Log log(PrintToStats);
+  LogBlock lb(isolate_, &log);
+
+  log.Print("==== Compiler Stats for isolate '%s' ====\n",
             isolate_->debugger_name());
-  OS::Print("Number of tokens:   %" Pd64 "\n", num_tokens_total);
-  OS::Print("  Literal tokens:   %" Pd64 "\n", num_literal_tokens_total);
-  OS::Print("  Ident tokens:     %" Pd64 "\n", num_ident_tokens_total);
-  OS::Print("Tokens consumed:    %" Pd64 " (%.2f times number of tokens)\n",
-            num_tokens_consumed,
-            (1.0 * num_tokens_consumed) / num_tokens_total);
-  OS::Print("Tokens checked:     %" Pd64 "  (%.2f times tokens consumed)\n",
-            num_token_checks, (1.0 * num_token_checks) / num_tokens_consumed);
-  OS::Print("Token lookahead:    %" Pd64 " (%" Pd64 "%% of tokens checked)\n",
-            num_tokens_lookahead,
-            (100 * num_tokens_lookahead) / num_token_checks);
-  OS::Print("Consts cached:      %" Pd64 "\n", num_cached_consts);
-  OS::Print("Consts cache hits:  %" Pd64 "\n", num_const_cache_hits);
-
-  OS::Print("Classes parsed:     %" Pd64 "\n", num_classes_compiled);
-  OS::Print("Functions compiled: %" Pd64 "\n", num_functions_compiled);
-  OS::Print("  Impl getters:     %" Pd64 "\n", num_implicit_final_getters);
-
-  OS::Print("Source length:      %" Pd64 " characters\n", src_length);
+  log.Print("Number of tokens:        %" Pd64 "\n", num_tokens_total);
+  log.Print("  Literal tokens:        %" Pd64 "\n", num_literal_tokens_total);
+  log.Print("  Ident tokens:          %" Pd64 "\n", num_ident_tokens_total);
+  log.Print("Source length:           %" Pd64 " characters\n", src_length);
+
+  log.Print("==== Parser stats:\n");
+  log.Print("Total tokens consumed:   %" Pd64 "\n", num_tokens_consumed);
+  log.Print("Classes parsed:          %" Pd64 "\n", num_classes_parsed);
+  log.Print("  Tokens consumed:       %" Pd64 "\n", num_class_tokens);
+  log.Print("Functions parsed:        %" Pd64 "\n", num_functions_parsed);
+  log.Print("  Tokens consumed:       %" Pd64 "\n", num_func_tokens_compiled);
+  log.Print("Impl getter funcs:       %" Pd64 "\n", num_implicit_final_getters);
+  log.Print("Impl method extractors:  %" Pd64 "\n", num_method_extractors);
+  log.Print("Consts cached:           %" Pd64 "\n", num_cached_consts);
+  log.Print("Consts cache hits:       %" Pd64 "\n", num_const_cache_hits);
+
   int64_t scan_usecs = scanner_timer.TotalElapsedTime();
-  OS::Print("Scanner time:       %" Pd64 " msecs\n",
-            scan_usecs / 1000);
+  log.Print("Scanner time:            %" Pd64 " msecs\n", scan_usecs / 1000);
   int64_t parse_usecs = parser_timer.TotalElapsedTime();
-  OS::Print("Parser time:        %" Pd64 " msecs\n",
-            parse_usecs / 1000);
+  log.Print("Parser time:             %" Pd64 " msecs\n", parse_usecs / 1000);
+  log.Print("Parser speed:            %" Pd64 " tokens per msec\n",
+            1000 * num_tokens_consumed / parse_usecs);
   int64_t codegen_usecs = codegen_timer.TotalElapsedTime();
-  OS::Print("Code gen. time:     %" Pd64 " msecs\n",
+
+  log.Print("==== Backend stats:\n");
+  log.Print("Code gen. time:          %" Pd64 " msecs\n",
             codegen_usecs / 1000);
   int64_t graphbuilder_usecs = graphbuilder_timer.TotalElapsedTime();
-  OS::Print("  Graph builder:    %" Pd64 " msecs\n", graphbuilder_usecs / 1000);
+  log.Print("  Graph builder:         %" Pd64 " msecs\n",
+            graphbuilder_usecs / 1000);
   int64_t ssa_usecs = ssa_timer.TotalElapsedTime();
-  OS::Print("  Graph SSA:        %" Pd64 " msecs\n", ssa_usecs / 1000);
+  log.Print("  Graph SSA:             %" Pd64 " msecs\n", ssa_usecs / 1000);
 
   int64_t graphinliner_usecs = graphinliner_timer.TotalElapsedTime();
-  OS::Print("  Graph inliner:    %" Pd64 " msecs\n", graphinliner_usecs / 1000);
+  log.Print("  Graph inliner:         %" Pd64 " msecs\n",
+            graphinliner_usecs / 1000);
   int64_t graphinliner_parse_usecs =
       graphinliner_parse_timer.TotalElapsedTime();
-  OS::Print("    Parsing:        %" Pd64 " msecs\n",
+  log.Print("    Parsing:             %" Pd64 " msecs\n",
             graphinliner_parse_usecs / 1000);
   int64_t graphinliner_build_usecs =
       graphinliner_build_timer.TotalElapsedTime();
-  OS::Print("    Building:       %" Pd64 " msecs\n",
+  log.Print("    Building:            %" Pd64 " msecs\n",
             graphinliner_build_usecs / 1000);
   int64_t graphinliner_ssa_usecs = graphinliner_ssa_timer.TotalElapsedTime();
-  OS::Print("    SSA:            %" Pd64 " msecs\n",
+  log.Print("    SSA:                 %" Pd64 " msecs\n",
             graphinliner_ssa_usecs / 1000);
   int64_t graphinliner_opt_usecs = graphinliner_opt_timer.TotalElapsedTime();
-  OS::Print("    Optimization:   %" Pd64 " msecs\n",
+  log.Print("    Optimization:        %" Pd64 " msecs\n",
             graphinliner_opt_usecs / 1000);
   int64_t graphinliner_subst_usecs =
       graphinliner_subst_timer.TotalElapsedTime();
-  OS::Print("    Substitution:   %" Pd64 " msecs\n",
+  log.Print("    Substitution:        %" Pd64 " msecs\n",
             graphinliner_subst_usecs / 1000);
-
   int64_t graphoptimizer_usecs = graphoptimizer_timer.TotalElapsedTime();
-  OS::Print("  Graph optimizer:  %" Pd64 " msecs\n",
+  log.Print("  Graph optimizer:       %" Pd64 " msecs\n",
             (graphoptimizer_usecs - graphinliner_usecs) / 1000);
   int64_t graphcompiler_usecs = graphcompiler_timer.TotalElapsedTime();
-  OS::Print("  Graph compiler:   %" Pd64 " msecs\n",
+  log.Print("  Graph compiler:        %" Pd64 " msecs\n",
             graphcompiler_usecs / 1000);
   int64_t codefinalizer_usecs = codefinalizer_timer.TotalElapsedTime();
-  OS::Print("  Code finalizer:   %" Pd64 " msecs\n",
+  log.Print("  Code finalizer:        %" Pd64 " msecs\n",
             codefinalizer_usecs / 1000);
-  OS::Print("Compilation speed:  %" Pd64 " tokens per msec\n",
-            (1000 * num_tokens_total) / (parse_usecs + codegen_usecs));
-  OS::Print("Code density:       %" Pd64 " tokens per KB\n",
-            (num_tokens_total * 1024) / total_instr_size);
-  OS::Print("Instr size:         %" Pd64 " KB\n",
-            total_instr_size / 1024);
-  OS::Print("Pc Desc size:       %" Pd64 " KB\n", pc_desc_size / 1024);
-  OS::Print("VarDesc size:       %" Pd64 " KB\n", vardesc_size / 1024);
 
-  OS::Print("Code size:          %" Pd64 " KB\n", total_code_size / 1024);
+  log.Print("==== Compiled code stats:\n");
+  log.Print("Functions parsed:        %" Pd64 "\n", num_functions_parsed);
+  log.Print("Functions compiled:      %" Pd64 "\n", num_functions_compiled);
+  log.Print("  optimized:             %" Pd64 "\n", num_functions_optimized);
+  log.Print("Tokens compiled:         %" Pd64 "\n", num_func_tokens_compiled);
+  log.Print("Compilation speed:       %" Pd64 " tokens per msec\n",
+            (1000 * num_func_tokens_compiled) / (parse_usecs + codegen_usecs));
+  log.Print("Code density:            %" Pd64 " tokens per KB\n",
+            (num_func_tokens_compiled * 1024) / total_instr_size);
+  log.Print("Code size:               %" Pd64 " KB\n", total_code_size / 1024);
+  log.Print("  Instr size:            %" Pd64 " KB\n",
+            total_instr_size / 1024);
+  log.Print("  Pc Desc size:          %" Pd64 " KB\n", pc_desc_size / 1024);
+  log.Print("  VarDesc size:          %" Pd64 " KB\n", vardesc_size / 1024);
+  log.Flush();
+  char* stats_text = text;
+  text = NULL;
+  return stats_text;
 }
 
 }  // namespace dart