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/object_graph.h" | 9 #include "vm/object_graph.h" |
9 #include "vm/timer.h" | 10 #include "vm/timer.h" |
10 | 11 |
11 | 12 |
12 namespace dart { | 13 namespace dart { |
13 | 14 |
14 DEFINE_FLAG(bool, compiler_stats, false, "Compiler stat counters."); | 15 DEFINE_FLAG(bool, compiler_stats, false, "Compiler stat counters."); |
15 | 16 |
16 | 17 |
17 class TokenStreamVisitor : public ObjectGraph::Visitor { | 18 class TokenStreamVisitor : public ObjectVisitor { |
18 public: | 19 public: |
19 explicit TokenStreamVisitor(CompilerStats* compiler_stats) | 20 TokenStreamVisitor(Isolate* isolate, CompilerStats* compiler_stats) |
20 : obj_(Object::Handle()), stats_(compiler_stats) { | 21 : ObjectVisitor(isolate), |
| 22 obj_(Object::Handle()), |
| 23 stats_(compiler_stats) { |
21 } | 24 } |
22 | 25 |
23 virtual Direction VisitObject(ObjectGraph::StackIterator* it) { | 26 void VisitObject(RawObject* raw_obj) { |
24 RawObject* raw_obj = it->Get(); | |
25 if (raw_obj->IsFreeListElement()) { | 27 if (raw_obj->IsFreeListElement()) { |
26 return kProceed; | 28 return; |
27 } | 29 } |
28 obj_ = raw_obj; | 30 obj_ = raw_obj; |
29 if (obj_.GetClassId() == TokenStream::kClassId) { | 31 if (obj_.GetClassId() == TokenStream::kClassId) { |
30 TokenStream::Iterator tkit(TokenStream::Cast(obj_), | 32 TokenStream::Iterator tkit(TokenStream::Cast(obj_), |
31 0, | 33 0, |
32 TokenStream::Iterator::kNoNewlines); | 34 TokenStream::Iterator::kNoNewlines); |
33 Token::Kind kind = tkit.CurrentTokenKind(); | 35 Token::Kind kind = tkit.CurrentTokenKind(); |
34 while (kind != Token::kEOS) { | 36 while (kind != Token::kEOS) { |
35 ++stats_->num_tokens_total; | 37 ++stats_->num_tokens_total; |
36 if (kind == Token::kIDENT) { | 38 if (kind == Token::kIDENT) { |
37 ++stats_->num_ident_tokens_total; | 39 ++stats_->num_ident_tokens_total; |
38 } else if (Token::NeedsLiteralToken(kind)) { | 40 } else if (Token::NeedsLiteralToken(kind)) { |
39 ++stats_->num_literal_tokens_total; | 41 ++stats_->num_literal_tokens_total; |
40 } | 42 } |
41 tkit.Advance(); | 43 tkit.Advance(); |
42 kind = tkit.CurrentTokenKind(); | 44 kind = tkit.CurrentTokenKind(); |
43 } | 45 } |
44 } | 46 } |
45 return kProceed; | |
46 } | 47 } |
47 | 48 |
48 private: | 49 private: |
49 Object& obj_; | 50 Object& obj_; |
50 CompilerStats* stats_; | 51 CompilerStats* stats_; |
51 }; | 52 }; |
52 | 53 |
53 | 54 |
54 CompilerStats::CompilerStats(Isolate* isolate) | 55 CompilerStats::CompilerStats(Isolate* isolate) |
55 : isolate_(isolate), | 56 : isolate_(isolate), |
56 parser_timer(true, "parser timer"), | 57 parser_timer(true, "parser timer"), |
57 scanner_timer(true, "scanner timer"), | 58 scanner_timer(true, "scanner timer"), |
58 codegen_timer(true, "codegen timer"), | 59 codegen_timer(true, "codegen timer"), |
59 graphbuilder_timer(true, "flow graph builder timer"), | 60 graphbuilder_timer(true, "flow graph builder timer"), |
60 ssa_timer(true, "flow graph SSA timer"), | 61 ssa_timer(true, "flow graph SSA timer"), |
61 graphinliner_timer(true, "flow graph inliner timer"), | 62 graphinliner_timer(true, "flow graph inliner timer"), |
62 graphinliner_parse_timer(true, "inliner parsing timer"), | 63 graphinliner_parse_timer(true, "inliner parsing timer"), |
63 graphinliner_build_timer(true, "inliner building timer"), | 64 graphinliner_build_timer(true, "inliner building timer"), |
64 graphinliner_ssa_timer(true, "inliner SSA timer"), | 65 graphinliner_ssa_timer(true, "inliner SSA timer"), |
65 graphinliner_opt_timer(true, "inliner optimization timer"), | 66 graphinliner_opt_timer(true, "inliner optimization timer"), |
66 graphinliner_subst_timer(true, "inliner substitution timer"), | 67 graphinliner_subst_timer(true, "inliner substitution timer"), |
67 graphoptimizer_timer(true, "flow graph optimizer timer"), | 68 graphoptimizer_timer(true, "flow graph optimizer timer"), |
68 graphcompiler_timer(true, "flow graph compiler timer"), | 69 graphcompiler_timer(true, "flow graph compiler timer"), |
69 codefinalizer_timer(true, "code finalization timer"), | 70 codefinalizer_timer(true, "code finalization timer"), |
70 num_tokens_total(0), | 71 num_tokens_total(0), |
71 num_literal_tokens_total(0), | 72 num_literal_tokens_total(0), |
72 num_ident_tokens_total(0), | 73 num_ident_tokens_total(0), |
73 num_tokens_consumed(0), | 74 num_tokens_consumed(0), |
74 num_token_checks(0), | |
75 num_tokens_lookahead(0), | |
76 num_cached_consts(0), | 75 num_cached_consts(0), |
77 num_const_cache_hits(0), | 76 num_const_cache_hits(0), |
78 num_classes_compiled(0), | 77 num_classes_parsed(0), |
| 78 num_class_tokens(0), |
| 79 num_functions_parsed(0), |
79 num_functions_compiled(0), | 80 num_functions_compiled(0), |
| 81 num_functions_optimized(0), |
| 82 num_func_tokens_compiled(0), |
80 num_implicit_final_getters(0), | 83 num_implicit_final_getters(0), |
| 84 num_method_extractors(0), |
81 src_length(0), | 85 src_length(0), |
82 total_code_size(0), | 86 total_code_size(0), |
83 total_instr_size(0), | 87 total_instr_size(0), |
84 pc_desc_size(0), | 88 pc_desc_size(0), |
85 vardesc_size(0) { | 89 vardesc_size(0), |
| 90 text(NULL) { |
86 } | 91 } |
87 | 92 |
88 | 93 |
89 void CompilerStats::Print() { | 94 // 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 |
| 96 // the accumulated text when all of the compiler stats values are |
| 97 // added to the log. |
| 98 static void PrintToStats(const char* format, ...) PRINTF_ATTRIBUTE(1, 2); |
| 99 static void PrintToStats(const char* format, ...) { |
| 100 Thread* thread = Thread::Current(); |
| 101 Isolate* isolate = thread->isolate(); |
| 102 CompilerStats* stats = isolate->compiler_stats(); |
| 103 Zone* zone = thread->zone(); |
| 104 ASSERT(stats != NULL); |
| 105 va_list args; |
| 106 va_start(args, format); |
| 107 stats->text = zone->VPrint(format, args); |
| 108 va_end(args); |
| 109 } |
| 110 |
| 111 |
| 112 char* CompilerStats::PrintToZone() { |
90 if (!FLAG_compiler_stats) { | 113 if (!FLAG_compiler_stats) { |
91 return; | 114 return NULL; |
92 } | 115 } |
93 | 116 |
94 // Traverse the heap and compute number of tokens in all | 117 // Traverse the heap and compute number of tokens in all |
95 // TokenStream objects. | 118 // TokenStream objects. |
96 num_tokens_total = 0; | 119 num_tokens_total = 0; |
97 num_literal_tokens_total = 0; | 120 num_literal_tokens_total = 0; |
98 num_ident_tokens_total = 0; | 121 num_ident_tokens_total = 0; |
99 TokenStreamVisitor visitor(this); | 122 TokenStreamVisitor visitor(isolate_, this); |
100 ObjectGraph graph(isolate_); | 123 isolate_->heap()->IterateObjects(&visitor); |
101 graph.IterateObjects(&visitor); | 124 Dart::vm_isolate()->heap()->IterateObjects(&visitor); |
102 | 125 |
103 OS::Print("==== Compiler Stats for isolate '%s' ====\n", | 126 Log log(PrintToStats); |
| 127 LogBlock lb(isolate_, &log); |
| 128 |
| 129 log.Print("==== Compiler Stats for isolate '%s' ====\n", |
104 isolate_->debugger_name()); | 130 isolate_->debugger_name()); |
105 OS::Print("Number of tokens: %" Pd64 "\n", num_tokens_total); | 131 log.Print("Number of tokens: %" Pd64 "\n", num_tokens_total); |
106 OS::Print(" Literal tokens: %" Pd64 "\n", num_literal_tokens_total); | 132 log.Print(" Literal tokens: %" Pd64 "\n", num_literal_tokens_total); |
107 OS::Print(" Ident tokens: %" Pd64 "\n", num_ident_tokens_total); | 133 log.Print(" Ident tokens: %" Pd64 "\n", num_ident_tokens_total); |
108 OS::Print("Tokens consumed: %" Pd64 " (%.2f times number of tokens)\n", | 134 log.Print("Source length: %" Pd64 " characters\n", src_length); |
109 num_tokens_consumed, | |
110 (1.0 * num_tokens_consumed) / num_tokens_total); | |
111 OS::Print("Tokens checked: %" Pd64 " (%.2f times tokens consumed)\n", | |
112 num_token_checks, (1.0 * num_token_checks) / num_tokens_consumed); | |
113 OS::Print("Token lookahead: %" Pd64 " (%" Pd64 "%% of tokens checked)\n", | |
114 num_tokens_lookahead, | |
115 (100 * num_tokens_lookahead) / num_token_checks); | |
116 OS::Print("Consts cached: %" Pd64 "\n", num_cached_consts); | |
117 OS::Print("Consts cache hits: %" Pd64 "\n", num_const_cache_hits); | |
118 | 135 |
119 OS::Print("Classes parsed: %" Pd64 "\n", num_classes_compiled); | 136 log.Print("==== Parser stats:\n"); |
120 OS::Print("Functions compiled: %" Pd64 "\n", num_functions_compiled); | 137 log.Print("Total tokens consumed: %" Pd64 "\n", num_tokens_consumed); |
121 OS::Print(" Impl getters: %" Pd64 "\n", num_implicit_final_getters); | 138 log.Print("Classes parsed: %" Pd64 "\n", num_classes_parsed); |
| 139 log.Print(" Tokens consumed: %" Pd64 "\n", num_class_tokens); |
| 140 log.Print("Functions parsed: %" Pd64 "\n", num_functions_parsed); |
| 141 log.Print(" Tokens consumed: %" Pd64 "\n", num_func_tokens_compiled); |
| 142 log.Print("Impl getter funcs: %" Pd64 "\n", num_implicit_final_getters); |
| 143 log.Print("Impl method extractors: %" Pd64 "\n", num_method_extractors); |
| 144 log.Print("Consts cached: %" Pd64 "\n", num_cached_consts); |
| 145 log.Print("Consts cache hits: %" Pd64 "\n", num_const_cache_hits); |
122 | 146 |
123 OS::Print("Source length: %" Pd64 " characters\n", src_length); | |
124 int64_t scan_usecs = scanner_timer.TotalElapsedTime(); | 147 int64_t scan_usecs = scanner_timer.TotalElapsedTime(); |
125 OS::Print("Scanner time: %" Pd64 " msecs\n", | 148 log.Print("Scanner time: %" Pd64 " msecs\n", scan_usecs / 1000); |
126 scan_usecs / 1000); | |
127 int64_t parse_usecs = parser_timer.TotalElapsedTime(); | 149 int64_t parse_usecs = parser_timer.TotalElapsedTime(); |
128 OS::Print("Parser time: %" Pd64 " msecs\n", | 150 log.Print("Parser time: %" Pd64 " msecs\n", parse_usecs / 1000); |
129 parse_usecs / 1000); | 151 log.Print("Parser speed: %" Pd64 " tokens per msec\n", |
| 152 1000 * num_tokens_consumed / parse_usecs); |
130 int64_t codegen_usecs = codegen_timer.TotalElapsedTime(); | 153 int64_t codegen_usecs = codegen_timer.TotalElapsedTime(); |
131 OS::Print("Code gen. time: %" Pd64 " msecs\n", | 154 |
| 155 log.Print("==== Backend stats:\n"); |
| 156 log.Print("Code gen. time: %" Pd64 " msecs\n", |
132 codegen_usecs / 1000); | 157 codegen_usecs / 1000); |
133 int64_t graphbuilder_usecs = graphbuilder_timer.TotalElapsedTime(); | 158 int64_t graphbuilder_usecs = graphbuilder_timer.TotalElapsedTime(); |
134 OS::Print(" Graph builder: %" Pd64 " msecs\n", graphbuilder_usecs / 1000); | 159 log.Print(" Graph builder: %" Pd64 " msecs\n", |
| 160 graphbuilder_usecs / 1000); |
135 int64_t ssa_usecs = ssa_timer.TotalElapsedTime(); | 161 int64_t ssa_usecs = ssa_timer.TotalElapsedTime(); |
136 OS::Print(" Graph SSA: %" Pd64 " msecs\n", ssa_usecs / 1000); | 162 log.Print(" Graph SSA: %" Pd64 " msecs\n", ssa_usecs / 1000); |
137 | 163 |
138 int64_t graphinliner_usecs = graphinliner_timer.TotalElapsedTime(); | 164 int64_t graphinliner_usecs = graphinliner_timer.TotalElapsedTime(); |
139 OS::Print(" Graph inliner: %" Pd64 " msecs\n", graphinliner_usecs / 1000); | 165 log.Print(" Graph inliner: %" Pd64 " msecs\n", |
| 166 graphinliner_usecs / 1000); |
140 int64_t graphinliner_parse_usecs = | 167 int64_t graphinliner_parse_usecs = |
141 graphinliner_parse_timer.TotalElapsedTime(); | 168 graphinliner_parse_timer.TotalElapsedTime(); |
142 OS::Print(" Parsing: %" Pd64 " msecs\n", | 169 log.Print(" Parsing: %" Pd64 " msecs\n", |
143 graphinliner_parse_usecs / 1000); | 170 graphinliner_parse_usecs / 1000); |
144 int64_t graphinliner_build_usecs = | 171 int64_t graphinliner_build_usecs = |
145 graphinliner_build_timer.TotalElapsedTime(); | 172 graphinliner_build_timer.TotalElapsedTime(); |
146 OS::Print(" Building: %" Pd64 " msecs\n", | 173 log.Print(" Building: %" Pd64 " msecs\n", |
147 graphinliner_build_usecs / 1000); | 174 graphinliner_build_usecs / 1000); |
148 int64_t graphinliner_ssa_usecs = graphinliner_ssa_timer.TotalElapsedTime(); | 175 int64_t graphinliner_ssa_usecs = graphinliner_ssa_timer.TotalElapsedTime(); |
149 OS::Print(" SSA: %" Pd64 " msecs\n", | 176 log.Print(" SSA: %" Pd64 " msecs\n", |
150 graphinliner_ssa_usecs / 1000); | 177 graphinliner_ssa_usecs / 1000); |
151 int64_t graphinliner_opt_usecs = graphinliner_opt_timer.TotalElapsedTime(); | 178 int64_t graphinliner_opt_usecs = graphinliner_opt_timer.TotalElapsedTime(); |
152 OS::Print(" Optimization: %" Pd64 " msecs\n", | 179 log.Print(" Optimization: %" Pd64 " msecs\n", |
153 graphinliner_opt_usecs / 1000); | 180 graphinliner_opt_usecs / 1000); |
154 int64_t graphinliner_subst_usecs = | 181 int64_t graphinliner_subst_usecs = |
155 graphinliner_subst_timer.TotalElapsedTime(); | 182 graphinliner_subst_timer.TotalElapsedTime(); |
156 OS::Print(" Substitution: %" Pd64 " msecs\n", | 183 log.Print(" Substitution: %" Pd64 " msecs\n", |
157 graphinliner_subst_usecs / 1000); | 184 graphinliner_subst_usecs / 1000); |
158 | |
159 int64_t graphoptimizer_usecs = graphoptimizer_timer.TotalElapsedTime(); | 185 int64_t graphoptimizer_usecs = graphoptimizer_timer.TotalElapsedTime(); |
160 OS::Print(" Graph optimizer: %" Pd64 " msecs\n", | 186 log.Print(" Graph optimizer: %" Pd64 " msecs\n", |
161 (graphoptimizer_usecs - graphinliner_usecs) / 1000); | 187 (graphoptimizer_usecs - graphinliner_usecs) / 1000); |
162 int64_t graphcompiler_usecs = graphcompiler_timer.TotalElapsedTime(); | 188 int64_t graphcompiler_usecs = graphcompiler_timer.TotalElapsedTime(); |
163 OS::Print(" Graph compiler: %" Pd64 " msecs\n", | 189 log.Print(" Graph compiler: %" Pd64 " msecs\n", |
164 graphcompiler_usecs / 1000); | 190 graphcompiler_usecs / 1000); |
165 int64_t codefinalizer_usecs = codefinalizer_timer.TotalElapsedTime(); | 191 int64_t codefinalizer_usecs = codefinalizer_timer.TotalElapsedTime(); |
166 OS::Print(" Code finalizer: %" Pd64 " msecs\n", | 192 log.Print(" Code finalizer: %" Pd64 " msecs\n", |
167 codefinalizer_usecs / 1000); | 193 codefinalizer_usecs / 1000); |
168 OS::Print("Compilation speed: %" Pd64 " tokens per msec\n", | 194 |
169 (1000 * num_tokens_total) / (parse_usecs + codegen_usecs)); | 195 log.Print("==== Compiled code stats:\n"); |
170 OS::Print("Code density: %" Pd64 " tokens per KB\n", | 196 log.Print("Functions parsed: %" Pd64 "\n", num_functions_parsed); |
171 (num_tokens_total * 1024) / total_instr_size); | 197 log.Print("Functions compiled: %" Pd64 "\n", num_functions_compiled); |
172 OS::Print("Instr size: %" Pd64 " KB\n", | 198 log.Print(" optimized: %" Pd64 "\n", num_functions_optimized); |
| 199 log.Print("Tokens compiled: %" Pd64 "\n", num_func_tokens_compiled); |
| 200 log.Print("Compilation speed: %" Pd64 " tokens per msec\n", |
| 201 (1000 * num_func_tokens_compiled) / (parse_usecs + codegen_usecs)); |
| 202 log.Print("Code density: %" Pd64 " tokens per KB\n", |
| 203 (num_func_tokens_compiled * 1024) / total_instr_size); |
| 204 log.Print("Code size: %" Pd64 " KB\n", total_code_size / 1024); |
| 205 log.Print(" Instr size: %" Pd64 " KB\n", |
173 total_instr_size / 1024); | 206 total_instr_size / 1024); |
174 OS::Print("Pc Desc size: %" Pd64 " KB\n", pc_desc_size / 1024); | 207 log.Print(" Pc Desc size: %" Pd64 " KB\n", pc_desc_size / 1024); |
175 OS::Print("VarDesc size: %" Pd64 " KB\n", vardesc_size / 1024); | 208 log.Print(" VarDesc size: %" Pd64 " KB\n", vardesc_size / 1024); |
176 | 209 log.Flush(); |
177 OS::Print("Code size: %" Pd64 " KB\n", total_code_size / 1024); | 210 char* stats_text = text; |
| 211 text = NULL; |
| 212 return stats_text; |
178 } | 213 } |
179 | 214 |
180 } // namespace dart | 215 } // namespace dart |
OLD | NEW |