| // Copyright (c) 2011, the Dart project authors. Please see the AUTHORS file |
| // for details. All rights reserved. Use of this source code is governed by a |
| // BSD-style license that can be found in the LICENSE file. |
| |
| #include "vm/compiler_stats.h" |
| |
| #include "vm/flags.h" |
| #include "vm/log.h" |
| #include "vm/object_graph.h" |
| #include "vm/object_store.h" |
| #include "vm/timer.h" |
| |
| |
| namespace dart { |
| |
| DEFINE_FLAG(bool, compiler_stats, false, "Compiler stat counters."); |
| DEFINE_FLAG(bool, |
| compiler_benchmark, |
| false, |
| "Compiler stat counters for benchmark."); |
| |
| |
| class TokenStreamVisitor : public ObjectVisitor { |
| public: |
| explicit TokenStreamVisitor(CompilerStats* compiler_stats) |
| : obj_(Object::Handle()), stats_(compiler_stats) {} |
| |
| void VisitObject(RawObject* raw_obj) { |
| if (raw_obj->IsPseudoObject()) { |
| return; // Cannot be wrapped in handles. |
| } |
| obj_ = raw_obj; |
| if (obj_.GetClassId() == TokenStream::kClassId) { |
| TokenStream::Iterator tkit( |
| Thread::Current()->zone(), TokenStream::Cast(obj_), |
| TokenPosition::kMinSource, TokenStream::Iterator::kNoNewlines); |
| Token::Kind kind = tkit.CurrentTokenKind(); |
| while (kind != Token::kEOS) { |
| ++stats_->num_tokens_total; |
| tkit.Advance(); |
| kind = tkit.CurrentTokenKind(); |
| } |
| } |
| } |
| |
| private: |
| Object& obj_; |
| CompilerStats* stats_; |
| }; |
| |
| |
| CompilerStats::CompilerStats(Isolate* isolate) |
| : isolate_(isolate), |
| #define INITIALIZE_TIMER(timer_name, description) timer_name(true, description), |
| STAT_TIMERS(INITIALIZE_TIMER) |
| #undef INITIALIZE_TIMER |
| |
| #define INITIALIZE_COUNTERS(counter_name) counter_name(0), |
| STAT_COUNTERS(INITIALIZE_COUNTERS) |
| #undef INITIALIZE_COUNTERS |
| text(NULL), |
| use_benchmark_output(false) { |
| } |
| |
| |
| #ifndef PRODUCT |
| |
| |
| // Used to aggregate stats. Must be atomic. |
| void CompilerStats::Add(const CompilerStats& other) { |
| #define ADD_TOTAL(timer_name, literal) timer_name.AddTotal(other.timer_name); |
| |
| STAT_TIMERS(ADD_TOTAL) |
| #undef ADD_TOTAL |
| |
| #define ADD_COUNTER(counter_name) \ |
| AtomicOperations::IncrementInt64By(&counter_name, other.counter_name); |
| |
| STAT_COUNTERS(ADD_COUNTER) |
| #undef ADD_COUNTER |
| } |
| |
| |
| void CompilerStats::Clear() { |
| #define CLEAR_TIMER(timer_name, literal) timer_name.Reset(); |
| |
| STAT_TIMERS(CLEAR_TIMER) |
| #undef CLEAR_TIMER |
| |
| #define CLEAR_COUNTER(counter_name) counter_name = 0; |
| |
| STAT_COUNTERS(CLEAR_COUNTER) |
| #undef CLEAR_COUNTER |
| } |
| |
| |
| bool CompilerStats::IsCleared() const { |
| #define CHECK_TIMERS(timer_name, literal) \ |
| if (!timer_name.IsReset()) return false; |
| |
| STAT_TIMERS(CHECK_TIMERS) |
| #undef CHECK_TIMERS |
| |
| #define CHECK_COUNTERS(counter_name) \ |
| if (counter_name != 0) return false; |
| |
| STAT_COUNTERS(CHECK_COUNTERS) |
| #undef CHECK_COUNTERS |
| return true; |
| } |
| |
| |
| // This function is used as a callback in the log object to which the |
| // compiler stats are printed. It will be called only once, to print |
| // the accumulated text when all of the compiler stats values are |
| // added to the log. |
| static void PrintToStats(const char* format, ...) PRINTF_ATTRIBUTE(1, 2); |
| static void PrintToStats(const char* format, ...) { |
| Thread* thread = Thread::Current(); |
| Isolate* isolate = thread->isolate(); |
| CompilerStats* stats = isolate->aggregate_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); |
| } |
| |
| |
| void CompilerStats::Update() { |
| // Traverse the heap and compute number of tokens in all |
| // TokenStream objects. |
| num_tokens_total = 0; |
| TokenStreamVisitor visitor(this); |
| isolate_->heap()->IterateObjects(&visitor); |
| Dart::vm_isolate()->heap()->IterateObjects(&visitor); |
| } |
| |
| |
| void CompilerStats::EnableBenchmark() { |
| FLAG_compiler_stats = true; |
| use_benchmark_output = true; |
| } |
| |
| |
| // Generate output for Golem benchmark harness. If the output format |
| // changes, the parsing function in Golem must be updated. |
| char* CompilerStats::BenchmarkOutput() { |
| Update(); |
| Log log(PrintToStats); |
| LogBlock lb(Thread::Current(), &log); |
| log.Print("==== Compiler Stats for isolate '%s' ====\n", |
| isolate_->debugger_name()); |
| |
| log.Print("NumberOfTokens: %" Pd64 "\n", num_tokens_total); |
| log.Print("NumClassesParsed: %" Pd64 "\n", num_classes_parsed); |
| log.Print("NumFunctionsCompiled: %" Pd64 "\n", num_functions_compiled); |
| log.Print("NumFunctionsOptimized: %" Pd64 "\n", num_functions_optimized); |
| log.Print("NumFunctionsParsed: %" Pd64 "\n", num_functions_parsed); |
| |
| // Scanner stats. |
| int64_t scan_usecs = scanner_timer.TotalElapsedTime(); |
| int64_t scan_speed = |
| scan_usecs > 0 ? 1000 * num_tokens_scanned / scan_usecs : 0; |
| log.Print("NumTokensScanned: %" Pd64 " tokens\n", num_tokens_scanned); |
| log.Print("ScannerTime: %" Pd64 " ms\n", scan_usecs / 1000); |
| log.Print("ScannerSpeed: %" Pd64 " tokens/ms\n", scan_speed); |
| |
| // Parser stats. |
| int64_t parse_usecs = parser_timer.TotalElapsedTime(); |
| int64_t parse_speed = |
| parse_usecs > 0 ? 1000 * num_tokens_consumed / parse_usecs : 0; |
| log.Print("NumTokensParsed: %" Pd64 " tokens\n", num_tokens_consumed); |
| log.Print("ParserTime: %" Pd64 " ms\n", parse_usecs / 1000); |
| log.Print("ParserSpeed: %" Pd64 " tokens/ms\n", parse_speed); |
| |
| // Compiler stats. |
| int64_t codegen_usecs = codegen_timer.TotalElapsedTime(); |
| int64_t compile_usecs = scan_usecs + parse_usecs + codegen_usecs; |
| int64_t compile_speed = |
| compile_usecs > 0 ? (1000 * num_func_tokens_compiled / compile_usecs) : 0; |
| log.Print("NumTokensCompiled: %" Pd64 " tokens\n", num_func_tokens_compiled); |
| log.Print("CompilerTime: %" Pd64 " ms\n", compile_usecs / 1000); |
| |
| log.Print("CompilerSpeed: %" Pd64 " tokens/ms\n", compile_speed); |
| log.Print("CodeSize: %" Pd64 " KB\n", total_code_size / 1024); |
| int64_t code_density = |
| total_instr_size > 0 |
| ? (num_func_tokens_compiled * 1024) / total_instr_size |
| : 0; |
| |
| log.Print("CodeDensity: %" Pd64 " tokens/KB\n", code_density); |
| log.Print("InstrSize: %" Pd64 " KB\n", total_instr_size / 1024); |
| log.Flush(); |
| char* benchmark_text = text; |
| text = NULL; |
| return benchmark_text; |
| } |
| |
| |
| char* CompilerStats::PrintToZone() { |
| if (!FLAG_compiler_stats) { |
| return NULL; |
| } else if (use_benchmark_output) { |
| return BenchmarkOutput(); |
| } |
| |
| Update(); |
| |
| Log log(PrintToStats); |
| LogBlock lb(Thread::Current(), &log); |
| |
| log.Print("==== Compiler Stats for isolate '%s' ====\n", |
| isolate_->debugger_name()); |
| log.Print("Number of tokens: %" Pd64 "\n", num_tokens_total); |
| log.Print("Source length: %" Pd64 " characters\n", src_length); |
| log.Print("Number of source tokens: %" Pd64 "\n", num_tokens_scanned); |
| |
| int64_t num_local_functions = |
| GrowableObjectArray::Handle(isolate_->object_store()->closure_functions()) |
| .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("Local functions: %" Pd64 "\n", num_local_functions); |
| log.Print("Consts cached: %" Pd64 "\n", num_cached_consts); |
| log.Print("Consts cache hits: %" Pd64 "\n", num_const_cache_hits); |
| log.Print("Consts calcuated: %" Pd64 "\n", num_execute_const); |
| |
| int64_t scan_usecs = scanner_timer.TotalElapsedTime(); |
| log.Print("Scanner time: %" Pd64 " ms\n", scan_usecs / 1000); |
| int64_t scan_speed = |
| scan_usecs > 0 ? 1000 * num_tokens_consumed / scan_usecs : 0; |
| log.Print("Scanner speed: %" Pd64 " tokens/ms\n", scan_speed); |
| int64_t parse_usecs = parser_timer.TotalElapsedTime(); |
| int64_t parse_speed = |
| parse_usecs > 0 ? 1000 * num_tokens_consumed / parse_usecs : 0; |
| log.Print("Parser time: %" Pd64 " ms\n", parse_usecs / 1000); |
| log.Print("Parser speed: %" Pd64 " tokens/ms\n", parse_speed); |
| |
| int64_t codegen_usecs = codegen_timer.TotalElapsedTime(); |
| |
| log.Print("==== Backend stats:\n"); |
| log.Print("Code gen. time: %" Pd64 " ms\n", codegen_usecs / 1000); |
| int64_t graphbuilder_usecs = graphbuilder_timer.TotalElapsedTime(); |
| log.Print(" Graph builder: %" Pd64 " ms\n", |
| graphbuilder_usecs / 1000); |
| int64_t ssa_usecs = ssa_timer.TotalElapsedTime(); |
| log.Print(" Graph SSA: %" Pd64 " ms\n", ssa_usecs / 1000); |
| |
| int64_t graphinliner_usecs = graphinliner_timer.TotalElapsedTime(); |
| log.Print(" Graph inliner: %" Pd64 " ms\n", |
| graphinliner_usecs / 1000); |
| int64_t graphinliner_parse_usecs = |
| graphinliner_parse_timer.TotalElapsedTime(); |
| log.Print(" Parsing: %" Pd64 " ms\n", |
| graphinliner_parse_usecs / 1000); |
| int64_t graphinliner_build_usecs = |
| graphinliner_build_timer.TotalElapsedTime(); |
| log.Print(" Building: %" Pd64 " ms\n", |
| graphinliner_build_usecs / 1000); |
| int64_t graphinliner_ssa_usecs = graphinliner_ssa_timer.TotalElapsedTime(); |
| log.Print(" SSA: %" Pd64 " ms\n", |
| graphinliner_ssa_usecs / 1000); |
| int64_t graphinliner_opt_usecs = graphinliner_opt_timer.TotalElapsedTime(); |
| log.Print(" Optimization: %" Pd64 " ms\n", |
| graphinliner_opt_usecs / 1000); |
| int64_t graphinliner_subst_usecs = |
| graphinliner_subst_timer.TotalElapsedTime(); |
| log.Print(" Substitution: %" Pd64 " ms\n", |
| graphinliner_subst_usecs / 1000); |
| int64_t graphoptimizer_usecs = graphoptimizer_timer.TotalElapsedTime(); |
| log.Print(" Graph optimizer: %" Pd64 " ms\n", |
| (graphoptimizer_usecs - graphinliner_usecs) / 1000); |
| int64_t graphcompiler_usecs = graphcompiler_timer.TotalElapsedTime(); |
| log.Print(" Graph compiler: %" Pd64 " ms\n", |
| graphcompiler_usecs / 1000); |
| int64_t codefinalizer_usecs = codefinalizer_timer.TotalElapsedTime(); |
| log.Print(" Code finalizer: %" Pd64 " ms\n", |
| codefinalizer_usecs / 1000); |
| |
| log.Print("==== Compiled code stats:\n"); |
| int64_t compile_usecs = scan_usecs + parse_usecs + codegen_usecs; |
| int64_t compile_speed = |
| compile_usecs > 0 ? (1000 * num_func_tokens_compiled / compile_usecs) : 0; |
| 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("Compiler time: %" Pd64 " ms\n", compile_usecs / 1000); |
| log.Print("Tokens compiled: %" Pd64 "\n", num_func_tokens_compiled); |
| log.Print("Compilation speed: %" Pd64 " tokens/ms\n", compile_speed); |
| int64_t code_density = |
| total_instr_size > 0 |
| ? (num_func_tokens_compiled * 1024) / total_instr_size |
| : 0; |
| log.Print("Code density: %" Pd64 " tokens per KB\n", code_density); |
| 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; |
| } |
| |
| #endif // !PRODUCT |
| |
| } // namespace dart |