Add way to print JIT related info at shutdown
Added a runtime option called -XX:DumpJITInfoOnShutdown with prints
various interesting JIT statistics during the shutdown of the runtime
if enabled.
Example of running EvaluateAndApplyChanges with the option:
I art : Code cache size=427KB data cache size=84KB num methods=1598
I art : Start Dumping histograms for 1598 iterations for JIT timings
I art : Compiling: Sum: 727.850ms 99% C.I. 135us-4402us Avg: 455.475us Max: 15567us
I art : Verifying: Sum: 191.074ms 99% C.I. 19us-1450.500us Avg: 119.570us Max: 5142us
I art : TrimMaps: Sum: 62.053ms 99% C.I. 13us-199.374us Avg: 38.831us Max: 10058us
I art : MakeExecutable: Sum: 11.153ms 99% C.I. 4us-47us Avg: 6.979us Max: 47us
I art : Initializing: Sum: 7.991ms 99% C.I. 1us-49.781us Avg: 5us Max: 4852us
I art : Done Dumping histograms
Bug: 17950037
Change-Id: I23538b24f947e5f6934f55579b8baa9d806eb3d5
diff --git a/runtime/jit/jit.cc b/runtime/jit/jit.cc
index 539c181..9b89459 100644
--- a/runtime/jit/jit.cc
+++ b/runtime/jit/jit.cc
@@ -40,16 +40,32 @@
options.GetOrDefault(RuntimeArgumentMap::JITCodeCacheCapacity);
jit_options->compile_threshold_ =
options.GetOrDefault(RuntimeArgumentMap::JITCompileThreshold);
+ jit_options->dump_info_on_shutdown_ =
+ options.Exists(RuntimeArgumentMap::DumpJITInfoOnShutdown);
return jit_options;
}
+void Jit::DumpInfo(std::ostream& os) {
+ os << "Code cache size=" << PrettySize(code_cache_->CodeCacheSize())
+ << " data cache size=" << PrettySize(code_cache_->DataCacheSize())
+ << " num methods=" << code_cache_->NumMethods()
+ << "\n";
+ cumulative_timings_.Dump(os);
+}
+
+void Jit::AddTimingLogger(const TimingLogger& logger) {
+ cumulative_timings_.AddLogger(logger);
+}
+
Jit::Jit()
: jit_library_handle_(nullptr), jit_compiler_handle_(nullptr), jit_load_(nullptr),
- jit_compile_method_(nullptr) {
+ jit_compile_method_(nullptr), dump_info_on_shutdown_(false),
+ cumulative_timings_("JIT timings") {
}
Jit* Jit::Create(JitOptions* options, std::string* error_msg) {
std::unique_ptr<Jit> jit(new Jit);
+ jit->dump_info_on_shutdown_ = options->DumpJitInfoOnShutdown();
if (!jit->LoadCompiler(error_msg)) {
return nullptr;
}
@@ -133,6 +149,9 @@
}
Jit::~Jit() {
+ if (dump_info_on_shutdown_) {
+ DumpInfo(LOG(INFO));
+ }
DeleteThreadPool();
if (jit_compiler_handle_ != nullptr) {
jit_unload_(jit_compiler_handle_);
diff --git a/runtime/jit/jit.h b/runtime/jit/jit.h
index b80015f..6b206d1 100644
--- a/runtime/jit/jit.h
+++ b/runtime/jit/jit.h
@@ -24,6 +24,7 @@
#include "atomic.h"
#include "base/macros.h"
#include "base/mutex.h"
+#include "base/timing_logger.h"
#include "gc_root.h"
#include "jni.h"
#include "object_callbacks.h"
@@ -61,6 +62,11 @@
return code_cache_.get();
}
void DeleteThreadPool();
+ // Dump interesting info: #methods compiled, code vs data size, compile / verify cumulative
+ // loggers.
+ void DumpInfo(std::ostream& os);
+ // Add a timing logger to cumulative_timings_.
+ void AddTimingLogger(const TimingLogger& logger);
private:
Jit();
@@ -73,6 +79,10 @@
void (*jit_unload_)(void*);
bool (*jit_compile_method_)(void*, mirror::ArtMethod*, Thread*);
+ // Performance monitoring.
+ bool dump_info_on_shutdown_;
+ CumulativeLogger cumulative_timings_;
+
std::unique_ptr<jit::JitInstrumentationCache> instrumentation_cache_;
std::unique_ptr<jit::JitCodeCache> code_cache_;
CompilerCallbacks* compiler_callbacks_; // Owned by the jit compiler.
@@ -87,12 +97,16 @@
size_t GetCodeCacheCapacity() const {
return code_cache_capacity_;
}
+ bool DumpJitInfoOnShutdown() const {
+ return dump_info_on_shutdown_;
+ }
private:
size_t code_cache_capacity_;
size_t compile_threshold_;
+ bool dump_info_on_shutdown_;
- JitOptions() : code_cache_capacity_(0), compile_threshold_(0) {
+ JitOptions() : code_cache_capacity_(0), compile_threshold_(0), dump_info_on_shutdown_(false) {
}
};
diff --git a/runtime/jit/jit_code_cache.cc b/runtime/jit/jit_code_cache.cc
index 4ae4d57..4d367e0 100644
--- a/runtime/jit/jit_code_cache.cc
+++ b/runtime/jit/jit_code_cache.cc
@@ -77,6 +77,7 @@
if (size > CodeCacheRemain()) {
return nullptr;
}
+ ++num_methods_; // TODO: This is hacky but works since each method has exactly one code region.
code_cache_ptr_ += size;
return code_cache_ptr_ - size;
}
diff --git a/runtime/parsed_options.cc b/runtime/parsed_options.cc
index 607569a..a53aeaa 100644
--- a/runtime/parsed_options.cc
+++ b/runtime/parsed_options.cc
@@ -136,6 +136,8 @@
.IntoKey(M::LongGCLogThreshold)
.Define("-XX:DumpGCPerformanceOnShutdown")
.IntoKey(M::DumpGCPerformanceOnShutdown)
+ .Define("-XX:DumpJITInfoOnShutdown")
+ .IntoKey(M::DumpJITInfoOnShutdown)
.Define("-XX:IgnoreMaxFootprint")
.IntoKey(M::IgnoreMaxFootprint)
.Define("-XX:LowMemoryMode")
@@ -620,6 +622,7 @@
UsageMessage(stream, " -XX:LongPauseLogThreshold=integervalue\n");
UsageMessage(stream, " -XX:LongGCLogThreshold=integervalue\n");
UsageMessage(stream, " -XX:DumpGCPerformanceOnShutdown\n");
+ UsageMessage(stream, " -XX:DumpJITInfoOnShutdown\n");
UsageMessage(stream, " -XX:IgnoreMaxFootprint\n");
UsageMessage(stream, " -XX:UseTLAB\n");
UsageMessage(stream, " -XX:BackgroundGC=none\n");
diff --git a/runtime/runtime_options.def b/runtime/runtime_options.def
index d072ffa..8775f8d 100644
--- a/runtime/runtime_options.def
+++ b/runtime/runtime_options.def
@@ -59,6 +59,7 @@
RUNTIME_OPTIONS_KEY (MillisecondsToNanoseconds, \
LongGCLogThreshold, gc::Heap::kDefaultLongGCLogThreshold)
RUNTIME_OPTIONS_KEY (Unit, DumpGCPerformanceOnShutdown)
+RUNTIME_OPTIONS_KEY (Unit, DumpJITInfoOnShutdown)
RUNTIME_OPTIONS_KEY (Unit, IgnoreMaxFootprint)
RUNTIME_OPTIONS_KEY (Unit, LowMemoryMode)
RUNTIME_OPTIONS_KEY (bool, UseTLAB, false)