Implement cumulative timings for CompilerDriver.
Change-Id: I3b04de7f2717273f356b8120f68d69e2379bab2f
diff --git a/compiler/dex/frontend.cc b/compiler/dex/frontend.cc
index f5bb85a..364a8bc 100644
--- a/compiler/dex/frontend.cc
+++ b/compiler/dex/frontend.cc
@@ -141,24 +141,25 @@
CompilationUnit::~CompilationUnit() {
}
-// TODO: Add a cumulative version of logging, and combine with dex2oat --dump-timing
void CompilationUnit::StartTimingSplit(const char* label) {
- if (enable_debug & (1 << kDebugTimings)) {
+ if (compiler_driver->GetDumpPasses()) {
timings.StartSplit(label);
}
}
void CompilationUnit::NewTimingSplit(const char* label) {
- if (enable_debug & (1 << kDebugTimings)) {
+ if (compiler_driver->GetDumpPasses()) {
timings.NewSplit(label);
}
}
void CompilationUnit::EndTiming() {
- if (enable_debug & (1 << kDebugTimings)) {
+ if (compiler_driver->GetDumpPasses()) {
timings.EndSplit();
- LOG(INFO) << "TIMINGS " << PrettyMethod(method_idx, *dex_file);
- LOG(INFO) << Dumpable<TimingLogger>(timings);
+ if (enable_debug & (1 << kDebugTimings)) {
+ LOG(INFO) << "TIMINGS " << PrettyMethod(method_idx, *dex_file);
+ LOG(INFO) << Dumpable<TimingLogger>(timings);
+ }
}
}
@@ -316,6 +317,9 @@
}
cu.EndTiming();
+ compiler.GetTimingsLogger().Start();
+ compiler.GetTimingsLogger().AddLogger(cu.timings);
+ compiler.GetTimingsLogger().End();
return result;
}
diff --git a/compiler/driver/compiler_driver.cc b/compiler/driver/compiler_driver.cc
index 5edc8b6..714dc4c 100644
--- a/compiler/driver/compiler_driver.cc
+++ b/compiler/driver/compiler_driver.cc
@@ -341,7 +341,7 @@
CompilerBackend compiler_backend, InstructionSet instruction_set,
InstructionSetFeatures instruction_set_features,
bool image, DescriptorSet* image_classes, size_t thread_count,
- bool dump_stats)
+ bool dump_stats, bool dump_passes, CumulativeLogger* timer)
: verified_methods_data_(verified_methods_data),
method_inliner_map_(method_inliner_map),
compiler_backend_(compiler_backend),
@@ -356,6 +356,8 @@
start_ns_(0),
stats_(new AOTCompilationStats),
dump_stats_(dump_stats),
+ dump_passes_(dump_passes),
+ timings_logger_(timer),
compiler_library_(NULL),
compiler_(NULL),
compiler_context_(NULL),
diff --git a/compiler/driver/compiler_driver.h b/compiler/driver/compiler_driver.h
index 9e31624..aabdf2f 100644
--- a/compiler/driver/compiler_driver.h
+++ b/compiler/driver/compiler_driver.h
@@ -22,6 +22,7 @@
#include <vector>
#include "base/mutex.h"
+#include "base/timing_logger.h"
#include "class_reference.h"
#include "compiled_class.h"
#include "compiled_method.h"
@@ -97,7 +98,8 @@
CompilerBackend compiler_backend, InstructionSet instruction_set,
InstructionSetFeatures instruction_set_features,
bool image, DescriptorSet* image_classes,
- size_t thread_count, bool dump_stats);
+ size_t thread_count, bool dump_stats, bool dump_passes,
+ CumulativeLogger* timer);
~CompilerDriver();
@@ -267,6 +269,14 @@
return thread_count_;
}
+ bool GetDumpPasses() const {
+ return dump_passes_;
+ }
+
+ CumulativeLogger& GetTimingsLogger() const {
+ return *timings_logger_;
+ }
+
class PatchInformation {
public:
const DexFile& GetDexFile() const {
@@ -436,6 +446,9 @@
UniquePtr<AOTCompilationStats> stats_;
bool dump_stats_;
+ const bool dump_passes_;
+
+ CumulativeLogger* const timings_logger_;
typedef void (*CompilerCallbackFn)(CompilerDriver& driver);
typedef MutexLock* (*CompilerMutexLockFn)(CompilerDriver& driver);
diff --git a/compiler/oat_test.cc b/compiler/oat_test.cc
index 2434262..12d8212 100644
--- a/compiler/oat_test.cc
+++ b/compiler/oat_test.cc
@@ -82,10 +82,11 @@
verified_methods_data_.reset(new VerifiedMethodsData);
method_inliner_map_.reset(compiler_backend == kQuick ? new DexFileToMethodInlinerMap : nullptr);
callbacks_.Reset(verified_methods_data_.get(), method_inliner_map_.get());
+ CumulativeLogger timer("Compilation times");
compiler_driver_.reset(new CompilerDriver(verified_methods_data_.get(),
method_inliner_map_.get(),
compiler_backend, insn_set,
- insn_features, false, NULL, 2, true));
+ insn_features, false, NULL, 2, true, true, &timer));
jobject class_loader = NULL;
if (kCompile) {
TimingLogger timings("OatTest::WriteRead", false, false);
diff --git a/dex2oat/dex2oat.cc b/dex2oat/dex2oat.cc
index 26fac23..20fafe2 100644
--- a/dex2oat/dex2oat.cc
+++ b/dex2oat/dex2oat.cc
@@ -249,7 +249,9 @@
bool image,
UniquePtr<CompilerDriver::DescriptorSet>& image_classes,
bool dump_stats,
- TimingLogger& timings) {
+ bool dump_passes,
+ TimingLogger& timings,
+ CumulativeLogger& compiler_phases_timings) {
// SirtRef and ClassLoader creation needs to come after Runtime::Create
jobject class_loader = NULL;
Thread* self = Thread::Current();
@@ -276,7 +278,9 @@
image,
image_classes.release(),
thread_count_,
- dump_stats));
+ dump_stats,
+ dump_passes,
+ &compiler_phases_timings));
if (compiler_backend_ == kPortable) {
driver->SetBitcodeFileName(bitcode_filename);
@@ -650,6 +654,7 @@
static int dex2oat(int argc, char** argv) {
TimingLogger timings("compiler", false, false);
+ CumulativeLogger compiler_phases_timings("compilation times");
InitLogging(argv);
@@ -703,6 +708,7 @@
bool is_host = false;
bool dump_stats = false;
bool dump_timing = false;
+ bool dump_passes = false;
bool dump_slow_timing = kIsDebugBuild;
bool watch_dog_enabled = !kIsTargetBuild;
@@ -796,6 +802,8 @@
runtime_args.push_back(argv[i]);
} else if (option == "--dump-timing") {
dump_timing = true;
+ } else if (option == "--dump-passes") {
+ dump_passes = true;
} else if (option == "--dump-stats") {
dump_stats = true;
} else {
@@ -1067,7 +1075,9 @@
image,
image_classes,
dump_stats,
- timings));
+ dump_passes,
+ timings,
+ compiler_phases_timings));
if (compiler.get() == NULL) {
LOG(ERROR) << "Failed to create oat file: " << oat_location;
@@ -1143,6 +1153,9 @@
if (dump_timing || (dump_slow_timing && timings.GetTotalNs() > MsToNs(1000))) {
LOG(INFO) << Dumpable<TimingLogger>(timings);
}
+ if (dump_passes) {
+ LOG(INFO) << Dumpable<CumulativeLogger>(compiler.get()->GetTimingsLogger());
+ }
return EXIT_SUCCESS;
}
@@ -1185,6 +1198,9 @@
if (dump_timing || (dump_slow_timing && timings.GetTotalNs() > MsToNs(1000))) {
LOG(INFO) << Dumpable<TimingLogger>(timings);
}
+ if (dump_passes) {
+ LOG(INFO) << Dumpable<CumulativeLogger>(compiler_phases_timings);
+ }
// Everything was successfully written, do an explicit exit here to avoid running Runtime
// destructors that take time (bug 10645725) unless we're a debug build or running on valgrind.
diff --git a/runtime/common_test.h b/runtime/common_test.h
index ee95d5b..a75a513 100644
--- a/runtime/common_test.h
+++ b/runtime/common_test.h
@@ -474,12 +474,13 @@
}
}
class_linker_->FixupDexCaches(runtime_->GetResolutionMethod());
+ CumulativeLogger timer("Compilation times");
compiler_driver_.reset(new CompilerDriver(verified_methods_data_.get(),
method_inliner_map_.get(),
compiler_backend, instruction_set,
instruction_set_features,
true, new CompilerDriver::DescriptorSet,
- 2, true));
+ 2, true, true, &timer));
}
// We typically don't generate an image in unit tests, disable this optimization by default.
compiler_driver_->SetSupportBootImageFixup(false);
