| OLD | NEW |
| 1 // Copyright (c) 2011, the Dart project authors. Please see the AUTHORS file | 1 // Copyright (c) 2011, the Dart project authors. Please see the AUTHORS file |
| 2 // for details. All rights reserved. Use of this source code is governed by a | 2 // for details. All rights reserved. Use of this source code is governed by a |
| 3 // BSD-style license that can be found in the LICENSE file. | 3 // BSD-style license that can be found in the LICENSE file. |
| 4 | 4 |
| 5 #include "vm/compiler_stats.h" | 5 #include "vm/compiler_stats.h" |
| 6 | 6 |
| 7 #include "vm/flags.h" | 7 #include "vm/flags.h" |
| 8 #include "vm/log.h" | 8 #include "vm/log.h" |
| 9 #include "vm/object_graph.h" | 9 #include "vm/object_graph.h" |
| 10 #include "vm/object_store.h" | 10 #include "vm/object_store.h" |
| 11 #include "vm/timer.h" | 11 #include "vm/timer.h" |
| 12 | 12 |
| 13 | 13 |
| 14 namespace dart { | 14 namespace dart { |
| 15 | 15 |
| 16 DEFINE_FLAG(bool, compiler_stats, false, "Compiler stat counters."); | 16 DEFINE_FLAG(bool, compiler_stats, false, "Compiler stat counters."); |
| 17 DEFINE_FLAG(bool, compiler_benchmark, false, | 17 DEFINE_FLAG(bool, |
| 18 compiler_benchmark, |
| 19 false, |
| 18 "Compiler stat counters for benchmark."); | 20 "Compiler stat counters for benchmark."); |
| 19 | 21 |
| 20 | 22 |
| 21 class TokenStreamVisitor : public ObjectVisitor { | 23 class TokenStreamVisitor : public ObjectVisitor { |
| 22 public: | 24 public: |
| 23 explicit TokenStreamVisitor(CompilerStats* compiler_stats) | 25 explicit TokenStreamVisitor(CompilerStats* compiler_stats) |
| 24 : obj_(Object::Handle()), | 26 : obj_(Object::Handle()), stats_(compiler_stats) {} |
| 25 stats_(compiler_stats) { | |
| 26 } | |
| 27 | 27 |
| 28 void VisitObject(RawObject* raw_obj) { | 28 void VisitObject(RawObject* raw_obj) { |
| 29 if (raw_obj->IsPseudoObject()) { | 29 if (raw_obj->IsPseudoObject()) { |
| 30 return; // Cannot be wrapped in handles. | 30 return; // Cannot be wrapped in handles. |
| 31 } | 31 } |
| 32 obj_ = raw_obj; | 32 obj_ = raw_obj; |
| 33 if (obj_.GetClassId() == TokenStream::kClassId) { | 33 if (obj_.GetClassId() == TokenStream::kClassId) { |
| 34 TokenStream::Iterator tkit(Thread::Current()->zone(), | 34 TokenStream::Iterator tkit( |
| 35 TokenStream::Cast(obj_), | 35 Thread::Current()->zone(), TokenStream::Cast(obj_), |
| 36 TokenPosition::kMinSource, | 36 TokenPosition::kMinSource, TokenStream::Iterator::kNoNewlines); |
| 37 TokenStream::Iterator::kNoNewlines); | |
| 38 Token::Kind kind = tkit.CurrentTokenKind(); | 37 Token::Kind kind = tkit.CurrentTokenKind(); |
| 39 while (kind != Token::kEOS) { | 38 while (kind != Token::kEOS) { |
| 40 ++stats_->num_tokens_total; | 39 ++stats_->num_tokens_total; |
| 41 tkit.Advance(); | 40 tkit.Advance(); |
| 42 kind = tkit.CurrentTokenKind(); | 41 kind = tkit.CurrentTokenKind(); |
| 43 } | 42 } |
| 44 } | 43 } |
| 45 } | 44 } |
| 46 | 45 |
| 47 private: | 46 private: |
| 48 Object& obj_; | 47 Object& obj_; |
| 49 CompilerStats* stats_; | 48 CompilerStats* stats_; |
| 50 }; | 49 }; |
| 51 | 50 |
| 52 | 51 |
| 53 CompilerStats::CompilerStats(Isolate* isolate) | 52 CompilerStats::CompilerStats(Isolate* isolate) |
| 54 : isolate_(isolate), | 53 : isolate_(isolate), |
| 55 #define INITIALIZE_TIMER(timer_name, description) \ | 54 #define INITIALIZE_TIMER(timer_name, description) timer_name(true, description), |
| 56 timer_name(true, description), | 55 STAT_TIMERS(INITIALIZE_TIMER) |
| 57 STAT_TIMERS(INITIALIZE_TIMER) | |
| 58 #undef INITIALIZE_TIMER | 56 #undef INITIALIZE_TIMER |
| 59 | 57 |
| 60 #define INITIALIZE_COUNTERS(counter_name) \ | 58 #define INITIALIZE_COUNTERS(counter_name) counter_name(0), |
| 61 counter_name(0), | 59 STAT_COUNTERS(INITIALIZE_COUNTERS) |
| 62 STAT_COUNTERS(INITIALIZE_COUNTERS) | |
| 63 #undef INITIALIZE_COUNTERS | 60 #undef INITIALIZE_COUNTERS |
| 64 text(NULL), | 61 text(NULL), |
| 65 use_benchmark_output(false) { | 62 use_benchmark_output(false) { |
| 66 } | 63 } |
| 67 | 64 |
| 68 | 65 |
| 69 #ifndef PRODUCT | 66 #ifndef PRODUCT |
| 70 | 67 |
| 71 | 68 |
| 72 // Used to aggregate stats. Must be atomic. | 69 // Used to aggregate stats. Must be atomic. |
| 73 void CompilerStats::Add(const CompilerStats& other) { | 70 void CompilerStats::Add(const CompilerStats& other) { |
| 74 #define ADD_TOTAL(timer_name, literal) \ | 71 #define ADD_TOTAL(timer_name, literal) timer_name.AddTotal(other.timer_name); |
| 75 timer_name.AddTotal(other.timer_name); | |
| 76 | 72 |
| 77 STAT_TIMERS(ADD_TOTAL) | 73 STAT_TIMERS(ADD_TOTAL) |
| 78 #undef ADD_TOTAL | 74 #undef ADD_TOTAL |
| 79 | 75 |
| 80 #define ADD_COUNTER(counter_name) \ | 76 #define ADD_COUNTER(counter_name) \ |
| 81 AtomicOperations::IncrementInt64By(&counter_name, other.counter_name); | 77 AtomicOperations::IncrementInt64By(&counter_name, other.counter_name); |
| 82 | 78 |
| 83 STAT_COUNTERS(ADD_COUNTER) | 79 STAT_COUNTERS(ADD_COUNTER) |
| 84 #undef ADD_COUNTER | 80 #undef ADD_COUNTER |
| 85 } | 81 } |
| 86 | 82 |
| 87 | 83 |
| 88 void CompilerStats::Clear() { | 84 void CompilerStats::Clear() { |
| 89 #define CLEAR_TIMER(timer_name, literal) \ | 85 #define CLEAR_TIMER(timer_name, literal) timer_name.Reset(); |
| 90 timer_name.Reset(); | |
| 91 | 86 |
| 92 STAT_TIMERS(CLEAR_TIMER) | 87 STAT_TIMERS(CLEAR_TIMER) |
| 93 #undef CLEAR_TIMER | 88 #undef CLEAR_TIMER |
| 94 | 89 |
| 95 #define CLEAR_COUNTER(counter_name) \ | 90 #define CLEAR_COUNTER(counter_name) counter_name = 0; |
| 96 counter_name = 0; | |
| 97 | 91 |
| 98 STAT_COUNTERS(CLEAR_COUNTER) | 92 STAT_COUNTERS(CLEAR_COUNTER) |
| 99 #undef CLEAR_COUNTER | 93 #undef CLEAR_COUNTER |
| 100 } | 94 } |
| 101 | 95 |
| 102 | 96 |
| 103 bool CompilerStats::IsCleared() const { | 97 bool CompilerStats::IsCleared() const { |
| 104 #define CHECK_TIMERS(timer_name, literal) \ | 98 #define CHECK_TIMERS(timer_name, literal) \ |
| 105 if (!timer_name.IsReset()) return false; | 99 if (!timer_name.IsReset()) return false; |
| 106 | 100 |
| (...skipping 77 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
| 184 // Compiler stats. | 178 // Compiler stats. |
| 185 int64_t codegen_usecs = codegen_timer.TotalElapsedTime(); | 179 int64_t codegen_usecs = codegen_timer.TotalElapsedTime(); |
| 186 int64_t compile_usecs = scan_usecs + parse_usecs + codegen_usecs; | 180 int64_t compile_usecs = scan_usecs + parse_usecs + codegen_usecs; |
| 187 int64_t compile_speed = | 181 int64_t compile_speed = |
| 188 compile_usecs > 0 ? (1000 * num_func_tokens_compiled / compile_usecs) : 0; | 182 compile_usecs > 0 ? (1000 * num_func_tokens_compiled / compile_usecs) : 0; |
| 189 log.Print("NumTokensCompiled: %" Pd64 " tokens\n", num_func_tokens_compiled); | 183 log.Print("NumTokensCompiled: %" Pd64 " tokens\n", num_func_tokens_compiled); |
| 190 log.Print("CompilerTime: %" Pd64 " ms\n", compile_usecs / 1000); | 184 log.Print("CompilerTime: %" Pd64 " ms\n", compile_usecs / 1000); |
| 191 | 185 |
| 192 log.Print("CompilerSpeed: %" Pd64 " tokens/ms\n", compile_speed); | 186 log.Print("CompilerSpeed: %" Pd64 " tokens/ms\n", compile_speed); |
| 193 log.Print("CodeSize: %" Pd64 " KB\n", total_code_size / 1024); | 187 log.Print("CodeSize: %" Pd64 " KB\n", total_code_size / 1024); |
| 194 int64_t code_density = total_instr_size > 0 ? | 188 int64_t code_density = |
| 195 (num_func_tokens_compiled * 1024) / total_instr_size : 0; | 189 total_instr_size > 0 |
| 190 ? (num_func_tokens_compiled * 1024) / total_instr_size |
| 191 : 0; |
| 196 | 192 |
| 197 log.Print("CodeDensity: %" Pd64 " tokens/KB\n", code_density); | 193 log.Print("CodeDensity: %" Pd64 " tokens/KB\n", code_density); |
| 198 log.Print("InstrSize: %" Pd64 " KB\n", total_instr_size / 1024); | 194 log.Print("InstrSize: %" Pd64 " KB\n", total_instr_size / 1024); |
| 199 log.Flush(); | 195 log.Flush(); |
| 200 char* benchmark_text = text; | 196 char* benchmark_text = text; |
| 201 text = NULL; | 197 text = NULL; |
| 202 return benchmark_text; | 198 return benchmark_text; |
| 203 } | 199 } |
| 204 | 200 |
| 205 | 201 |
| 206 char* CompilerStats::PrintToZone() { | 202 char* CompilerStats::PrintToZone() { |
| 207 if (!FLAG_compiler_stats) { | 203 if (!FLAG_compiler_stats) { |
| 208 return NULL; | 204 return NULL; |
| 209 } else if (use_benchmark_output) { | 205 } else if (use_benchmark_output) { |
| 210 return BenchmarkOutput(); | 206 return BenchmarkOutput(); |
| 211 } | 207 } |
| 212 | 208 |
| 213 Update(); | 209 Update(); |
| 214 | 210 |
| 215 Log log(PrintToStats); | 211 Log log(PrintToStats); |
| 216 LogBlock lb(Thread::Current(), &log); | 212 LogBlock lb(Thread::Current(), &log); |
| 217 | 213 |
| 218 log.Print("==== Compiler Stats for isolate '%s' ====\n", | 214 log.Print("==== Compiler Stats for isolate '%s' ====\n", |
| 219 isolate_->debugger_name()); | 215 isolate_->debugger_name()); |
| 220 log.Print("Number of tokens: %" Pd64 "\n", num_tokens_total); | 216 log.Print("Number of tokens: %" Pd64 "\n", num_tokens_total); |
| 221 log.Print("Source length: %" Pd64 " characters\n", src_length); | 217 log.Print("Source length: %" Pd64 " characters\n", src_length); |
| 222 log.Print("Number of source tokens: %" Pd64 "\n", num_tokens_scanned); | 218 log.Print("Number of source tokens: %" Pd64 "\n", num_tokens_scanned); |
| 223 | 219 |
| 224 int64_t num_local_functions = GrowableObjectArray::Handle( | 220 int64_t num_local_functions = |
| 225 isolate_->object_store()->closure_functions()).Length(); | 221 GrowableObjectArray::Handle(isolate_->object_store()->closure_functions()) |
| 222 .Length(); |
| 226 | 223 |
| 227 log.Print("==== Parser stats:\n"); | 224 log.Print("==== Parser stats:\n"); |
| 228 log.Print("Total tokens consumed: %" Pd64 "\n", num_tokens_consumed); | 225 log.Print("Total tokens consumed: %" Pd64 "\n", num_tokens_consumed); |
| 229 log.Print("Classes parsed: %" Pd64 "\n", num_classes_parsed); | 226 log.Print("Classes parsed: %" Pd64 "\n", num_classes_parsed); |
| 230 log.Print(" Tokens consumed: %" Pd64 "\n", num_class_tokens); | 227 log.Print(" Tokens consumed: %" Pd64 "\n", num_class_tokens); |
| 231 log.Print("Functions parsed: %" Pd64 "\n", num_functions_parsed); | 228 log.Print("Functions parsed: %" Pd64 "\n", num_functions_parsed); |
| 232 log.Print(" Tokens consumed: %" Pd64 "\n", num_func_tokens_compiled); | 229 log.Print(" Tokens consumed: %" Pd64 "\n", num_func_tokens_compiled); |
| 233 log.Print("Impl getter funcs: %" Pd64 "\n", num_implicit_final_getters); | 230 log.Print("Impl getter funcs: %" Pd64 "\n", num_implicit_final_getters); |
| 234 log.Print("Impl method extractors: %" Pd64 "\n", num_method_extractors); | 231 log.Print("Impl method extractors: %" Pd64 "\n", num_method_extractors); |
| 235 log.Print("Local functions: %" Pd64 "\n", num_local_functions); | 232 log.Print("Local functions: %" Pd64 "\n", num_local_functions); |
| 236 log.Print("Consts cached: %" Pd64 "\n", num_cached_consts); | 233 log.Print("Consts cached: %" Pd64 "\n", num_cached_consts); |
| 237 log.Print("Consts cache hits: %" Pd64 "\n", num_const_cache_hits); | 234 log.Print("Consts cache hits: %" Pd64 "\n", num_const_cache_hits); |
| 238 log.Print("Consts calcuated: %" Pd64 "\n", num_execute_const); | 235 log.Print("Consts calcuated: %" Pd64 "\n", num_execute_const); |
| 239 | 236 |
| 240 int64_t scan_usecs = scanner_timer.TotalElapsedTime(); | 237 int64_t scan_usecs = scanner_timer.TotalElapsedTime(); |
| 241 log.Print("Scanner time: %" Pd64 " ms\n", scan_usecs / 1000); | 238 log.Print("Scanner time: %" Pd64 " ms\n", scan_usecs / 1000); |
| 242 int64_t scan_speed = | 239 int64_t scan_speed = |
| 243 scan_usecs > 0 ? 1000 * num_tokens_consumed / scan_usecs : 0; | 240 scan_usecs > 0 ? 1000 * num_tokens_consumed / scan_usecs : 0; |
| 244 log.Print("Scanner speed: %" Pd64 " tokens/ms\n", scan_speed); | 241 log.Print("Scanner speed: %" Pd64 " tokens/ms\n", scan_speed); |
| 245 int64_t parse_usecs = parser_timer.TotalElapsedTime(); | 242 int64_t parse_usecs = parser_timer.TotalElapsedTime(); |
| 246 int64_t parse_speed = | 243 int64_t parse_speed = |
| 247 parse_usecs > 0 ? 1000 * num_tokens_consumed / parse_usecs : 0; | 244 parse_usecs > 0 ? 1000 * num_tokens_consumed / parse_usecs : 0; |
| 248 log.Print("Parser time: %" Pd64 " ms\n", parse_usecs / 1000); | 245 log.Print("Parser time: %" Pd64 " ms\n", parse_usecs / 1000); |
| 249 log.Print("Parser speed: %" Pd64 " tokens/ms\n", | 246 log.Print("Parser speed: %" Pd64 " tokens/ms\n", parse_speed); |
| 250 parse_speed); | |
| 251 | 247 |
| 252 int64_t codegen_usecs = codegen_timer.TotalElapsedTime(); | 248 int64_t codegen_usecs = codegen_timer.TotalElapsedTime(); |
| 253 | 249 |
| 254 log.Print("==== Backend stats:\n"); | 250 log.Print("==== Backend stats:\n"); |
| 255 log.Print("Code gen. time: %" Pd64 " ms\n", codegen_usecs / 1000); | 251 log.Print("Code gen. time: %" Pd64 " ms\n", codegen_usecs / 1000); |
| 256 int64_t graphbuilder_usecs = graphbuilder_timer.TotalElapsedTime(); | 252 int64_t graphbuilder_usecs = graphbuilder_timer.TotalElapsedTime(); |
| 257 log.Print(" Graph builder: %" Pd64 " ms\n", | 253 log.Print(" Graph builder: %" Pd64 " ms\n", |
| 258 graphbuilder_usecs / 1000); | 254 graphbuilder_usecs / 1000); |
| 259 int64_t ssa_usecs = ssa_timer.TotalElapsedTime(); | 255 int64_t ssa_usecs = ssa_timer.TotalElapsedTime(); |
| 260 log.Print(" Graph SSA: %" Pd64 " ms\n", ssa_usecs / 1000); | 256 log.Print(" Graph SSA: %" Pd64 " ms\n", ssa_usecs / 1000); |
| (...skipping 24 matching lines...) Expand all Loading... |
| 285 (graphoptimizer_usecs - graphinliner_usecs) / 1000); | 281 (graphoptimizer_usecs - graphinliner_usecs) / 1000); |
| 286 int64_t graphcompiler_usecs = graphcompiler_timer.TotalElapsedTime(); | 282 int64_t graphcompiler_usecs = graphcompiler_timer.TotalElapsedTime(); |
| 287 log.Print(" Graph compiler: %" Pd64 " ms\n", | 283 log.Print(" Graph compiler: %" Pd64 " ms\n", |
| 288 graphcompiler_usecs / 1000); | 284 graphcompiler_usecs / 1000); |
| 289 int64_t codefinalizer_usecs = codefinalizer_timer.TotalElapsedTime(); | 285 int64_t codefinalizer_usecs = codefinalizer_timer.TotalElapsedTime(); |
| 290 log.Print(" Code finalizer: %" Pd64 " ms\n", | 286 log.Print(" Code finalizer: %" Pd64 " ms\n", |
| 291 codefinalizer_usecs / 1000); | 287 codefinalizer_usecs / 1000); |
| 292 | 288 |
| 293 log.Print("==== Compiled code stats:\n"); | 289 log.Print("==== Compiled code stats:\n"); |
| 294 int64_t compile_usecs = scan_usecs + parse_usecs + codegen_usecs; | 290 int64_t compile_usecs = scan_usecs + parse_usecs + codegen_usecs; |
| 295 int64_t compile_speed = compile_usecs > 0 ? | 291 int64_t compile_speed = |
| 296 (1000 * num_func_tokens_compiled / compile_usecs) : 0; | 292 compile_usecs > 0 ? (1000 * num_func_tokens_compiled / compile_usecs) : 0; |
| 297 log.Print("Functions parsed: %" Pd64 "\n", num_functions_parsed); | 293 log.Print("Functions parsed: %" Pd64 "\n", num_functions_parsed); |
| 298 log.Print("Functions compiled: %" Pd64 "\n", num_functions_compiled); | 294 log.Print("Functions compiled: %" Pd64 "\n", num_functions_compiled); |
| 299 log.Print(" optimized: %" Pd64 "\n", num_functions_optimized); | 295 log.Print(" optimized: %" Pd64 "\n", num_functions_optimized); |
| 300 log.Print("Compiler time: %" Pd64 " ms\n", compile_usecs / 1000); | 296 log.Print("Compiler time: %" Pd64 " ms\n", compile_usecs / 1000); |
| 301 log.Print("Tokens compiled: %" Pd64 "\n", num_func_tokens_compiled); | 297 log.Print("Tokens compiled: %" Pd64 "\n", num_func_tokens_compiled); |
| 302 log.Print("Compilation speed: %" Pd64 " tokens/ms\n", compile_speed); | 298 log.Print("Compilation speed: %" Pd64 " tokens/ms\n", compile_speed); |
| 303 int64_t code_density = total_instr_size > 0 ? | 299 int64_t code_density = |
| 304 (num_func_tokens_compiled * 1024) / total_instr_size : 0; | 300 total_instr_size > 0 |
| 301 ? (num_func_tokens_compiled * 1024) / total_instr_size |
| 302 : 0; |
| 305 log.Print("Code density: %" Pd64 " tokens per KB\n", code_density); | 303 log.Print("Code density: %" Pd64 " tokens per KB\n", code_density); |
| 306 log.Print("Code size: %" Pd64 " KB\n", total_code_size / 1024); | 304 log.Print("Code size: %" Pd64 " KB\n", total_code_size / 1024); |
| 307 log.Print(" Instr size: %" Pd64 " KB\n", | 305 log.Print(" Instr size: %" Pd64 " KB\n", total_instr_size / 1024); |
| 308 total_instr_size / 1024); | |
| 309 log.Print(" Pc Desc size: %" Pd64 " KB\n", pc_desc_size / 1024); | 306 log.Print(" Pc Desc size: %" Pd64 " KB\n", pc_desc_size / 1024); |
| 310 log.Print(" VarDesc size: %" Pd64 " KB\n", vardesc_size / 1024); | 307 log.Print(" VarDesc size: %" Pd64 " KB\n", vardesc_size / 1024); |
| 311 log.Flush(); | 308 log.Flush(); |
| 312 char* stats_text = text; | 309 char* stats_text = text; |
| 313 text = NULL; | 310 text = NULL; |
| 314 return stats_text; | 311 return stats_text; |
| 315 } | 312 } |
| 316 | 313 |
| 317 #endif // !PRODUCT | 314 #endif // !PRODUCT |
| 318 | 315 |
| 319 } // namespace dart | 316 } // namespace dart |
| OLD | NEW |