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 |