blob: d3e4b02689e40d69ecb9a534b0d27ada4160ccbd [file] [log] [blame]
// 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/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:
TokenStreamVisitor(Isolate* isolate, CompilerStats* compiler_stats)
: ObjectVisitor(isolate),
obj_(Object::Handle()),
stats_(compiler_stats) {
}
void VisitObject(RawObject* raw_obj) {
if (raw_obj->IsFreeListElement()) {
return;
}
obj_ = raw_obj;
if (obj_.GetClassId() == TokenStream::kClassId) {
TokenStream::Iterator tkit(TokenStream::Cast(obj_),
0,
TokenStream::Iterator::kNoNewlines);
Token::Kind kind = tkit.CurrentTokenKind();
while (kind != Token::kEOS) {
++stats_->num_tokens_total;
if (kind == Token::kIDENT) {
++stats_->num_ident_tokens_total;
} else if (Token::NeedsLiteralToken(kind)) {
++stats_->num_literal_tokens_total;
}
tkit.Advance();
kind = tkit.CurrentTokenKind();
}
}
}
private:
Object& obj_;
CompilerStats* stats_;
};
CompilerStats::CompilerStats(Isolate* isolate)
: isolate_(isolate),
parser_timer(true, "parser timer"),
scanner_timer(true, "scanner timer"),
codegen_timer(true, "codegen timer"),
graphbuilder_timer(true, "flow graph builder timer"),
ssa_timer(true, "flow graph SSA timer"),
graphinliner_timer(true, "flow graph inliner timer"),
graphinliner_parse_timer(true, "inliner parsing timer"),
graphinliner_build_timer(true, "inliner building timer"),
graphinliner_ssa_timer(true, "inliner SSA timer"),
graphinliner_opt_timer(true, "inliner optimization timer"),
graphinliner_subst_timer(true, "inliner substitution timer"),
graphoptimizer_timer(true, "flow graph optimizer timer"),
graphcompiler_timer(true, "flow graph compiler timer"),
codefinalizer_timer(true, "code finalization timer"),
num_tokens_total(0),
num_literal_tokens_total(0),
num_ident_tokens_total(0),
num_tokens_scanned(0),
num_tokens_consumed(0),
num_cached_consts(0),
num_const_cache_hits(0),
num_classes_parsed(0),
num_class_tokens(0),
num_functions_parsed(0),
num_functions_compiled(0),
num_functions_optimized(0),
num_func_tokens_compiled(0),
num_implicit_final_getters(0),
num_method_extractors(0),
src_length(0),
total_code_size(0),
total_instr_size(0),
pc_desc_size(0),
vardesc_size(0),
text(NULL),
use_benchmark_output(false) {
}
// 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->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;
num_literal_tokens_total = 0;
num_ident_tokens_total = 0;
TokenStreamVisitor visitor(isolate_, 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(" Literal tokens: %" Pd64 "\n", num_literal_tokens_total);
log.Print(" Ident tokens: %" Pd64 "\n", num_ident_tokens_total);
log.Print("Source length: %" Pd64 " characters\n", src_length);
log.Print("Number of source tokens: %" Pd64 "\n", num_tokens_scanned);
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("Consts cached: %" Pd64 "\n", num_cached_consts);
log.Print("Consts cache hits: %" Pd64 "\n", num_const_cache_hits);
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;
}
} // namespace dart