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/timer.h" | 10 #include "vm/timer.h" |
11 | 11 |
12 | 12 |
13 namespace dart { | 13 namespace dart { |
14 | 14 |
15 DEFINE_FLAG(bool, compiler_stats, false, "Compiler stat counters."); | 15 DEFINE_FLAG(bool, compiler_stats, false, "Compiler stat counters."); |
| 16 DEFINE_FLAG(bool, compiler_benchmark, false, |
| 17 "Compiler stat counters for benchmark."); |
16 | 18 |
17 | 19 |
18 class TokenStreamVisitor : public ObjectVisitor { | 20 class TokenStreamVisitor : public ObjectVisitor { |
19 public: | 21 public: |
20 TokenStreamVisitor(Isolate* isolate, CompilerStats* compiler_stats) | 22 TokenStreamVisitor(Isolate* isolate, CompilerStats* compiler_stats) |
21 : ObjectVisitor(isolate), | 23 : ObjectVisitor(isolate), |
22 obj_(Object::Handle()), | 24 obj_(Object::Handle()), |
23 stats_(compiler_stats) { | 25 stats_(compiler_stats) { |
24 } | 26 } |
25 | 27 |
(...skipping 38 matching lines...) Expand 10 before | Expand all | Expand 10 after Loading... |
64 graphinliner_build_timer(true, "inliner building timer"), | 66 graphinliner_build_timer(true, "inliner building timer"), |
65 graphinliner_ssa_timer(true, "inliner SSA timer"), | 67 graphinliner_ssa_timer(true, "inliner SSA timer"), |
66 graphinliner_opt_timer(true, "inliner optimization timer"), | 68 graphinliner_opt_timer(true, "inliner optimization timer"), |
67 graphinliner_subst_timer(true, "inliner substitution timer"), | 69 graphinliner_subst_timer(true, "inliner substitution timer"), |
68 graphoptimizer_timer(true, "flow graph optimizer timer"), | 70 graphoptimizer_timer(true, "flow graph optimizer timer"), |
69 graphcompiler_timer(true, "flow graph compiler timer"), | 71 graphcompiler_timer(true, "flow graph compiler timer"), |
70 codefinalizer_timer(true, "code finalization timer"), | 72 codefinalizer_timer(true, "code finalization timer"), |
71 num_tokens_total(0), | 73 num_tokens_total(0), |
72 num_literal_tokens_total(0), | 74 num_literal_tokens_total(0), |
73 num_ident_tokens_total(0), | 75 num_ident_tokens_total(0), |
| 76 num_tokens_scanned(0), |
74 num_tokens_consumed(0), | 77 num_tokens_consumed(0), |
75 num_cached_consts(0), | 78 num_cached_consts(0), |
76 num_const_cache_hits(0), | 79 num_const_cache_hits(0), |
77 num_classes_parsed(0), | 80 num_classes_parsed(0), |
78 num_class_tokens(0), | 81 num_class_tokens(0), |
79 num_functions_parsed(0), | 82 num_functions_parsed(0), |
80 num_functions_compiled(0), | 83 num_functions_compiled(0), |
81 num_functions_optimized(0), | 84 num_functions_optimized(0), |
82 num_func_tokens_compiled(0), | 85 num_func_tokens_compiled(0), |
83 num_implicit_final_getters(0), | 86 num_implicit_final_getters(0), |
84 num_method_extractors(0), | 87 num_method_extractors(0), |
85 src_length(0), | 88 src_length(0), |
86 total_code_size(0), | 89 total_code_size(0), |
87 total_instr_size(0), | 90 total_instr_size(0), |
88 pc_desc_size(0), | 91 pc_desc_size(0), |
89 vardesc_size(0), | 92 vardesc_size(0), |
90 text(NULL) { | 93 text(NULL), |
| 94 use_benchmark_output(false) { |
91 } | 95 } |
92 | 96 |
93 | 97 |
94 // This function is used as a callback in the log object to which the | 98 // This function is used as a callback in the log object to which the |
95 // compiler stats are printed. It will be called only once, to print | 99 // compiler stats are printed. It will be called only once, to print |
96 // the accumulated text when all of the compiler stats values are | 100 // the accumulated text when all of the compiler stats values are |
97 // added to the log. | 101 // added to the log. |
98 static void PrintToStats(const char* format, ...) PRINTF_ATTRIBUTE(1, 2); | 102 static void PrintToStats(const char* format, ...) PRINTF_ATTRIBUTE(1, 2); |
99 static void PrintToStats(const char* format, ...) { | 103 static void PrintToStats(const char* format, ...) { |
100 Thread* thread = Thread::Current(); | 104 Thread* thread = Thread::Current(); |
101 Isolate* isolate = thread->isolate(); | 105 Isolate* isolate = thread->isolate(); |
102 CompilerStats* stats = isolate->compiler_stats(); | 106 CompilerStats* stats = isolate->compiler_stats(); |
103 Zone* zone = thread->zone(); | 107 Zone* zone = thread->zone(); |
104 ASSERT(stats != NULL); | 108 ASSERT(stats != NULL); |
105 va_list args; | 109 va_list args; |
106 va_start(args, format); | 110 va_start(args, format); |
107 stats->text = zone->VPrint(format, args); | 111 stats->text = zone->VPrint(format, args); |
108 va_end(args); | 112 va_end(args); |
109 } | 113 } |
110 | 114 |
111 | 115 |
112 char* CompilerStats::PrintToZone() { | 116 void CompilerStats::Update() { |
113 if (!FLAG_compiler_stats) { | |
114 return NULL; | |
115 } | |
116 | |
117 // Traverse the heap and compute number of tokens in all | 117 // Traverse the heap and compute number of tokens in all |
118 // TokenStream objects. | 118 // TokenStream objects. |
119 num_tokens_total = 0; | 119 num_tokens_total = 0; |
120 num_literal_tokens_total = 0; | 120 num_literal_tokens_total = 0; |
121 num_ident_tokens_total = 0; | 121 num_ident_tokens_total = 0; |
122 TokenStreamVisitor visitor(isolate_, this); | 122 TokenStreamVisitor visitor(isolate_, this); |
123 isolate_->heap()->IterateObjects(&visitor); | 123 isolate_->heap()->IterateObjects(&visitor); |
124 Dart::vm_isolate()->heap()->IterateObjects(&visitor); | 124 Dart::vm_isolate()->heap()->IterateObjects(&visitor); |
| 125 } |
| 126 |
| 127 |
| 128 void CompilerStats::EnableBenchmark() { |
| 129 FLAG_compiler_stats = true; |
| 130 use_benchmark_output = true; |
| 131 } |
| 132 |
| 133 |
| 134 // Generate output for Golem benchmark harness. If the output format |
| 135 // changes, the parsing function in Golem must be updated. |
| 136 char* CompilerStats::BenchmarkOutput() { |
| 137 Update(); |
| 138 Log log(PrintToStats); |
| 139 LogBlock lb(Thread::Current(), &log); |
| 140 log.Print("NumberOfTokens: %" Pd64 "\n", num_tokens_total); |
| 141 log.Print("NumClassesParsed: %" Pd64 "\n", num_classes_parsed); |
| 142 log.Print("NumFunctionsCompiled: %" Pd64 "\n", num_functions_compiled); |
| 143 log.Print("NumFunctionsOptimized: %" Pd64 "\n", num_functions_optimized); |
| 144 log.Print("NumFunctionsParsed: %" Pd64 "\n", num_functions_parsed); |
| 145 |
| 146 // Scanner stats. |
| 147 int64_t scan_usecs = scanner_timer.TotalElapsedTime(); |
| 148 int64_t scan_speed = |
| 149 scan_usecs > 0 ? 1000 * num_tokens_scanned / scan_usecs : 0; |
| 150 log.Print("NumTokensScanned: %" Pd64 " tokens\n", num_tokens_scanned); |
| 151 log.Print("ScannerTime: %" Pd64 " ms\n", scan_usecs / 1000); |
| 152 log.Print("ScannerSpeed: %" Pd64 " tokens/ms\n", scan_speed); |
| 153 |
| 154 // Parser stats. |
| 155 int64_t parse_usecs = parser_timer.TotalElapsedTime(); |
| 156 int64_t parse_speed = |
| 157 parse_usecs > 0 ? 1000 * num_tokens_consumed / parse_usecs : 0; |
| 158 log.Print("NumTokensParsed: %" Pd64 " tokens\n", num_tokens_consumed); |
| 159 log.Print("ParserTime: %" Pd64 " ms\n", parse_usecs / 1000); |
| 160 log.Print("ParserSpeed: %" Pd64 " tokens/ms\n", parse_speed); |
| 161 |
| 162 // Compiler stats. |
| 163 int64_t codegen_usecs = codegen_timer.TotalElapsedTime(); |
| 164 int64_t compile_usecs = scan_usecs+ parse_usecs + codegen_usecs; |
| 165 log.Print("NumTokensCompiled: %" Pd64 " tokens\n", num_func_tokens_compiled); |
| 166 log.Print("CompilerTime: %" Pd64 " ms\n", compile_usecs / 1000); |
| 167 |
| 168 log.Print("CompilerSpeed: %" Pd64 " tokens/ms\n", |
| 169 compile_usecs > 0 ? |
| 170 (1000 * num_func_tokens_compiled / compile_usecs) : 0); |
| 171 log.Print("CodeSize: %" Pd64 " KB\n", total_code_size / 1024); |
| 172 log.Print("CodeDensity: %" Pd64 " tokens/KB\n", |
| 173 (1024 * num_func_tokens_compiled) / total_instr_size); |
| 174 log.Print("InstrSize: %" Pd64 " KB\n", total_instr_size / 1024); |
| 175 log.Flush(); |
| 176 char* benchmark_text = text; |
| 177 text = NULL; |
| 178 return benchmark_text; |
| 179 } |
| 180 |
| 181 |
| 182 char* CompilerStats::PrintToZone() { |
| 183 if (!FLAG_compiler_stats) { |
| 184 return NULL; |
| 185 } else if (use_benchmark_output) { |
| 186 return BenchmarkOutput(); |
| 187 } |
| 188 |
| 189 Update(); |
125 | 190 |
126 Log log(PrintToStats); | 191 Log log(PrintToStats); |
127 LogBlock lb(Thread::Current(), &log); | 192 LogBlock lb(Thread::Current(), &log); |
128 | 193 |
129 log.Print("==== Compiler Stats for isolate '%s' ====\n", | 194 log.Print("==== Compiler Stats for isolate '%s' ====\n", |
130 isolate_->debugger_name()); | 195 isolate_->debugger_name()); |
131 log.Print("Number of tokens: %" Pd64 "\n", num_tokens_total); | 196 log.Print("Number of tokens: %" Pd64 "\n", num_tokens_total); |
132 log.Print(" Literal tokens: %" Pd64 "\n", num_literal_tokens_total); | 197 log.Print(" Literal tokens: %" Pd64 "\n", num_literal_tokens_total); |
133 log.Print(" Ident tokens: %" Pd64 "\n", num_ident_tokens_total); | 198 log.Print(" Ident tokens: %" Pd64 "\n", num_ident_tokens_total); |
134 log.Print("Source length: %" Pd64 " characters\n", src_length); | 199 log.Print("Source length: %" Pd64 " characters\n", src_length); |
| 200 log.Print("Number of source tokens: %" Pd64 "\n", num_tokens_scanned); |
135 | 201 |
136 log.Print("==== Parser stats:\n"); | 202 log.Print("==== Parser stats:\n"); |
137 log.Print("Total tokens consumed: %" Pd64 "\n", num_tokens_consumed); | 203 log.Print("Total tokens consumed: %" Pd64 "\n", num_tokens_consumed); |
138 log.Print("Classes parsed: %" Pd64 "\n", num_classes_parsed); | 204 log.Print("Classes parsed: %" Pd64 "\n", num_classes_parsed); |
139 log.Print(" Tokens consumed: %" Pd64 "\n", num_class_tokens); | 205 log.Print(" Tokens consumed: %" Pd64 "\n", num_class_tokens); |
140 log.Print("Functions parsed: %" Pd64 "\n", num_functions_parsed); | 206 log.Print("Functions parsed: %" Pd64 "\n", num_functions_parsed); |
141 log.Print(" Tokens consumed: %" Pd64 "\n", num_func_tokens_compiled); | 207 log.Print(" Tokens consumed: %" Pd64 "\n", num_func_tokens_compiled); |
142 log.Print("Impl getter funcs: %" Pd64 "\n", num_implicit_final_getters); | 208 log.Print("Impl getter funcs: %" Pd64 "\n", num_implicit_final_getters); |
143 log.Print("Impl method extractors: %" Pd64 "\n", num_method_extractors); | 209 log.Print("Impl method extractors: %" Pd64 "\n", num_method_extractors); |
144 log.Print("Consts cached: %" Pd64 "\n", num_cached_consts); | 210 log.Print("Consts cached: %" Pd64 "\n", num_cached_consts); |
145 log.Print("Consts cache hits: %" Pd64 "\n", num_const_cache_hits); | 211 log.Print("Consts cache hits: %" Pd64 "\n", num_const_cache_hits); |
146 | 212 |
147 int64_t scan_usecs = scanner_timer.TotalElapsedTime(); | 213 int64_t scan_usecs = scanner_timer.TotalElapsedTime(); |
148 log.Print("Scanner time: %" Pd64 " msecs\n", scan_usecs / 1000); | 214 log.Print("Scanner time: %" Pd64 " ms\n", scan_usecs / 1000); |
| 215 int64_t scan_speed = |
| 216 scan_usecs > 0 ? 1000 * num_tokens_consumed / scan_usecs : 0; |
| 217 log.Print("Scanner speed: %" Pd64 " tokens/ms\n", scan_speed); |
149 int64_t parse_usecs = parser_timer.TotalElapsedTime(); | 218 int64_t parse_usecs = parser_timer.TotalElapsedTime(); |
150 log.Print("Parser time: %" Pd64 " msecs\n", parse_usecs / 1000); | 219 int64_t parse_speed = |
151 log.Print("Parser speed: %" Pd64 " tokens per msec\n", | 220 parse_usecs > 0 ? 1000 * num_tokens_consumed / parse_usecs : 0; |
152 1000 * num_tokens_consumed / parse_usecs); | 221 log.Print("Parser time: %" Pd64 " ms\n", parse_usecs / 1000); |
| 222 log.Print("Parser speed: %" Pd64 " tokens/ms\n", |
| 223 parse_speed); |
| 224 |
153 int64_t codegen_usecs = codegen_timer.TotalElapsedTime(); | 225 int64_t codegen_usecs = codegen_timer.TotalElapsedTime(); |
154 | 226 |
155 log.Print("==== Backend stats:\n"); | 227 log.Print("==== Backend stats:\n"); |
156 log.Print("Code gen. time: %" Pd64 " msecs\n", | 228 log.Print("Code gen. time: %" Pd64 " ms\n", |
157 codegen_usecs / 1000); | 229 codegen_usecs / 1000); |
158 int64_t graphbuilder_usecs = graphbuilder_timer.TotalElapsedTime(); | 230 int64_t graphbuilder_usecs = graphbuilder_timer.TotalElapsedTime(); |
159 log.Print(" Graph builder: %" Pd64 " msecs\n", | 231 log.Print(" Graph builder: %" Pd64 " ms\n", |
160 graphbuilder_usecs / 1000); | 232 graphbuilder_usecs / 1000); |
161 int64_t ssa_usecs = ssa_timer.TotalElapsedTime(); | 233 int64_t ssa_usecs = ssa_timer.TotalElapsedTime(); |
162 log.Print(" Graph SSA: %" Pd64 " msecs\n", ssa_usecs / 1000); | 234 log.Print(" Graph SSA: %" Pd64 " ms\n", ssa_usecs / 1000); |
163 | 235 |
164 int64_t graphinliner_usecs = graphinliner_timer.TotalElapsedTime(); | 236 int64_t graphinliner_usecs = graphinliner_timer.TotalElapsedTime(); |
165 log.Print(" Graph inliner: %" Pd64 " msecs\n", | 237 log.Print(" Graph inliner: %" Pd64 " ms\n", |
166 graphinliner_usecs / 1000); | 238 graphinliner_usecs / 1000); |
167 int64_t graphinliner_parse_usecs = | 239 int64_t graphinliner_parse_usecs = |
168 graphinliner_parse_timer.TotalElapsedTime(); | 240 graphinliner_parse_timer.TotalElapsedTime(); |
169 log.Print(" Parsing: %" Pd64 " msecs\n", | 241 log.Print(" Parsing: %" Pd64 " ms\n", |
170 graphinliner_parse_usecs / 1000); | 242 graphinliner_parse_usecs / 1000); |
171 int64_t graphinliner_build_usecs = | 243 int64_t graphinliner_build_usecs = |
172 graphinliner_build_timer.TotalElapsedTime(); | 244 graphinliner_build_timer.TotalElapsedTime(); |
173 log.Print(" Building: %" Pd64 " msecs\n", | 245 log.Print(" Building: %" Pd64 " ms\n", |
174 graphinliner_build_usecs / 1000); | 246 graphinliner_build_usecs / 1000); |
175 int64_t graphinliner_ssa_usecs = graphinliner_ssa_timer.TotalElapsedTime(); | 247 int64_t graphinliner_ssa_usecs = graphinliner_ssa_timer.TotalElapsedTime(); |
176 log.Print(" SSA: %" Pd64 " msecs\n", | 248 log.Print(" SSA: %" Pd64 " ms\n", |
177 graphinliner_ssa_usecs / 1000); | 249 graphinliner_ssa_usecs / 1000); |
178 int64_t graphinliner_opt_usecs = graphinliner_opt_timer.TotalElapsedTime(); | 250 int64_t graphinliner_opt_usecs = graphinliner_opt_timer.TotalElapsedTime(); |
179 log.Print(" Optimization: %" Pd64 " msecs\n", | 251 log.Print(" Optimization: %" Pd64 " ms\n", |
180 graphinliner_opt_usecs / 1000); | 252 graphinliner_opt_usecs / 1000); |
181 int64_t graphinliner_subst_usecs = | 253 int64_t graphinliner_subst_usecs = |
182 graphinliner_subst_timer.TotalElapsedTime(); | 254 graphinliner_subst_timer.TotalElapsedTime(); |
183 log.Print(" Substitution: %" Pd64 " msecs\n", | 255 log.Print(" Substitution: %" Pd64 " ms\n", |
184 graphinliner_subst_usecs / 1000); | 256 graphinliner_subst_usecs / 1000); |
185 int64_t graphoptimizer_usecs = graphoptimizer_timer.TotalElapsedTime(); | 257 int64_t graphoptimizer_usecs = graphoptimizer_timer.TotalElapsedTime(); |
186 log.Print(" Graph optimizer: %" Pd64 " msecs\n", | 258 log.Print(" Graph optimizer: %" Pd64 " ms\n", |
187 (graphoptimizer_usecs - graphinliner_usecs) / 1000); | 259 (graphoptimizer_usecs - graphinliner_usecs) / 1000); |
188 int64_t graphcompiler_usecs = graphcompiler_timer.TotalElapsedTime(); | 260 int64_t graphcompiler_usecs = graphcompiler_timer.TotalElapsedTime(); |
189 log.Print(" Graph compiler: %" Pd64 " msecs\n", | 261 log.Print(" Graph compiler: %" Pd64 " ms\n", |
190 graphcompiler_usecs / 1000); | 262 graphcompiler_usecs / 1000); |
191 int64_t codefinalizer_usecs = codefinalizer_timer.TotalElapsedTime(); | 263 int64_t codefinalizer_usecs = codefinalizer_timer.TotalElapsedTime(); |
192 log.Print(" Code finalizer: %" Pd64 " msecs\n", | 264 log.Print(" Code finalizer: %" Pd64 " ms\n", |
193 codefinalizer_usecs / 1000); | 265 codefinalizer_usecs / 1000); |
194 | 266 |
195 log.Print("==== Compiled code stats:\n"); | 267 log.Print("==== Compiled code stats:\n"); |
| 268 int64_t compile_usecs = scan_usecs + parse_usecs + codegen_usecs; |
196 log.Print("Functions parsed: %" Pd64 "\n", num_functions_parsed); | 269 log.Print("Functions parsed: %" Pd64 "\n", num_functions_parsed); |
197 log.Print("Functions compiled: %" Pd64 "\n", num_functions_compiled); | 270 log.Print("Functions compiled: %" Pd64 "\n", num_functions_compiled); |
198 log.Print(" optimized: %" Pd64 "\n", num_functions_optimized); | 271 log.Print(" optimized: %" Pd64 "\n", num_functions_optimized); |
| 272 log.Print("Compiler time: %" Pd64 " ms\n", compile_usecs / 1000); |
199 log.Print("Tokens compiled: %" Pd64 "\n", num_func_tokens_compiled); | 273 log.Print("Tokens compiled: %" Pd64 "\n", num_func_tokens_compiled); |
200 log.Print("Compilation speed: %" Pd64 " tokens per msec\n", | 274 log.Print("Compilation speed: %" Pd64 " tokens/ms\n", |
201 (1000 * num_func_tokens_compiled) / (parse_usecs + codegen_usecs)); | 275 (1000 * num_func_tokens_compiled) / compile_usecs); |
202 log.Print("Code density: %" Pd64 " tokens per KB\n", | 276 log.Print("Code density: %" Pd64 " tokens per KB\n", |
203 (num_func_tokens_compiled * 1024) / total_instr_size); | 277 (num_func_tokens_compiled * 1024) / total_instr_size); |
204 log.Print("Code size: %" Pd64 " KB\n", total_code_size / 1024); | 278 log.Print("Code size: %" Pd64 " KB\n", total_code_size / 1024); |
205 log.Print(" Instr size: %" Pd64 " KB\n", | 279 log.Print(" Instr size: %" Pd64 " KB\n", |
206 total_instr_size / 1024); | 280 total_instr_size / 1024); |
207 log.Print(" Pc Desc size: %" Pd64 " KB\n", pc_desc_size / 1024); | 281 log.Print(" Pc Desc size: %" Pd64 " KB\n", pc_desc_size / 1024); |
208 log.Print(" VarDesc size: %" Pd64 " KB\n", vardesc_size / 1024); | 282 log.Print(" VarDesc size: %" Pd64 " KB\n", vardesc_size / 1024); |
209 log.Flush(); | 283 log.Flush(); |
210 char* stats_text = text; | 284 char* stats_text = text; |
211 text = NULL; | 285 text = NULL; |
212 return stats_text; | 286 return stats_text; |
213 } | 287 } |
214 | 288 |
215 } // namespace dart | 289 } // namespace dart |
OLD | NEW |