Merge "Refactor java.lang.reflect implementation" into dalvik-dev
diff --git a/compiler/driver/compiler_driver.cc b/compiler/driver/compiler_driver.cc
index 82f51f2..b8727fe 100644
--- a/compiler/driver/compiler_driver.cc
+++ b/compiler/driver/compiler_driver.cc
@@ -64,7 +64,7 @@
if (x == 0 && y == 0) {
return;
}
- LOG(INFO) << Percentage(x, y) << "% of " << str << " for " << (x + y) << " cases";
+ VLOG(compiler) << Percentage(x, y) << "% of " << str << " for " << (x + y) << " cases";
}
class AOTCompilationStats {
@@ -724,7 +724,7 @@
std::pair<CompilerDriver::DescriptorSet::iterator, bool> result =
image_classes->insert(descriptor);
if (result.second) {
- LOG(INFO) << "Adding " << descriptor << " to image classes";
+ VLOG(compiler) << "Adding " << descriptor << " to image classes";
} else {
return;
}
@@ -2070,7 +2070,7 @@
}
}
if (!is_black_listed) {
- LOG(INFO) << "Initializing: " << descriptor;
+ VLOG(compiler) << "Initializing: " << descriptor;
if (StringPiece(descriptor) == "Ljava/lang/Void;") {
// Hand initialize j.l.Void to avoid Dex file operations in un-started runtime.
mirror::ObjectArray<mirror::ArtField>* fields = klass->GetSFields();
diff --git a/compiler/oat_writer.cc b/compiler/oat_writer.cc
index f813843..f9d6e41 100644
--- a/compiler/oat_writer.cc
+++ b/compiler/oat_writer.cc
@@ -464,7 +464,7 @@
if (kIsDebugBuild) {
uint32_t size_total = 0;
#define DO_STAT(x) \
- LOG(INFO) << #x "=" << PrettySize(x) << " (" << x << "B)"; \
+ VLOG(compiler) << #x "=" << PrettySize(x) << " (" << x << "B)"; \
size_total += x;
DO_STAT(size_dex_file_alignment_);
@@ -495,7 +495,7 @@
DO_STAT(size_oat_class_method_offsets_);
#undef DO_STAT
- LOG(INFO) << "size_total=" << PrettySize(size_total) << " (" << size_total << "B)"; \
+ VLOG(compiler) << "size_total=" << PrettySize(size_total) << " (" << size_total << "B)"; \
CHECK_EQ(file_offset + size_total, static_cast<uint32_t>(out.Seek(0, kSeekCurrent)));
CHECK_EQ(size_, size_total);
}
diff --git a/dex2oat/dex2oat.cc b/dex2oat/dex2oat.cc
index c372d00..ac2c1a9 100644
--- a/dex2oat/dex2oat.cc
+++ b/dex2oat/dex2oat.cc
@@ -164,7 +164,7 @@
~Dex2Oat() {
delete runtime_;
- LOG(INFO) << "dex2oat took " << PrettyDuration(NanoTime() - start_ns_)
+ VLOG(compiler) << "dex2oat took " << PrettyDuration(NanoTime() - start_ns_)
<< " (threads: " << thread_count_ << ")";
}
@@ -923,7 +923,7 @@
}
if (num_methods <= Runtime::Current()->GetNumDexMethodsThreshold()) {
Runtime::Current()->SetCompilerFilter(Runtime::kSpeed);
- LOG(INFO) << "Below method threshold, compiling anyways";
+ VLOG(compiler) << "Below method threshold, compiling anyways";
}
}
@@ -945,7 +945,7 @@
return EXIT_FAILURE;
}
- LOG(INFO) << "Oat file written successfully (unstripped): " << oat_location;
+ VLOG(compiler) << "Oat file written successfully (unstripped): " << oat_location;
// Notes on the interleaving of creating the image and oat file to
// ensure the references between the two are correct.
@@ -1009,7 +1009,7 @@
if (!image_creation_success) {
return EXIT_FAILURE;
}
- LOG(INFO) << "Image written successfully: " << image_filename;
+ VLOG(compiler) << "Image written successfully: " << image_filename;
}
if (is_host) {
@@ -1037,7 +1037,7 @@
CHECK(write_ok);
}
oat_file.reset(out.release());
- LOG(INFO) << "Oat file copied successfully (stripped): " << oat_stripped;
+ VLOG(compiler) << "Oat file copied successfully (stripped): " << oat_stripped;
}
#if ART_USE_PORTABLE_COMPILER // We currently only generate symbols on Portable
@@ -1049,7 +1049,7 @@
// We wrote the oat file successfully, and want to keep it.
- LOG(INFO) << "Oat file written successfully (stripped): " << oat_location;
+ VLOG(compiler) << "Oat file written successfully (stripped): " << oat_location;
#endif // ART_USE_PORTABLE_COMPILER
timings.EndSplit();
diff --git a/runtime/base/logging.h b/runtime/base/logging.h
index ade8d34..8e40da0 100644
--- a/runtime/base/logging.h
+++ b/runtime/base/logging.h
@@ -125,6 +125,7 @@
#define VLOG_IS_ON(module) UNLIKELY(::art::gLogVerbosity.module)
#define VLOG(module) if (VLOG_IS_ON(module)) ::art::LogMessage(__FILE__, __LINE__, INFO, -1).stream()
+#define VLOG_STREAM(module) ::art::LogMessage(__FILE__, __LINE__, INFO, -1).stream()
//
// Implementation details beyond this point.
@@ -306,6 +307,7 @@
// and the "-verbose:" command line argument.
struct LogVerbosity {
bool class_linker; // Enabled with "-verbose:class".
+ bool verifier;
bool compiler;
bool heap;
bool gc;
diff --git a/runtime/runtime.cc b/runtime/runtime.cc
index 7b12870..a30403d 100644
--- a/runtime/runtime.cc
+++ b/runtime/runtime.cc
@@ -364,6 +364,7 @@
parsed->sea_ir_mode_ = false;
// gLogVerbosity.class_linker = true; // TODO: don't check this in!
// gLogVerbosity.compiler = true; // TODO: don't check this in!
+// gLogVerbosity.verifier = true; // TODO: don't check this in!
// gLogVerbosity.heap = true; // TODO: don't check this in!
// gLogVerbosity.gc = true; // TODO: don't check this in!
// gLogVerbosity.jdwp = true; // TODO: don't check this in!
@@ -521,6 +522,8 @@
for (size_t i = 0; i < verbose_options.size(); ++i) {
if (verbose_options[i] == "class") {
gLogVerbosity.class_linker = true;
+ } else if (verbose_options[i] == "verifier") {
+ gLogVerbosity.verifier = true;
} else if (verbose_options[i] == "compiler") {
gLogVerbosity.compiler = true;
} else if (verbose_options[i] == "heap") {
diff --git a/runtime/trace.cc b/runtime/trace.cc
index 84df6a9..1ccd387 100644
--- a/runtime/trace.cc
+++ b/runtime/trace.cc
@@ -18,6 +18,7 @@
#include <sys/uio.h>
+#include "base/stl_util.h"
#include "base/unix_file/fd_file.h"
#include "class_linker.h"
#include "common_throws.h"
@@ -32,6 +33,7 @@
#include "object_utils.h"
#include "os.h"
#include "scoped_thread_state_change.h"
+#include "ScopedLocalRef.h"
#include "thread.h"
#include "thread_list.h"
#if !defined(ART_USE_PORTABLE_COMPILER)
@@ -82,6 +84,29 @@
kTraceMethodActionMask = 0x03, // two bits
};
+class BuildStackTraceVisitor : public StackVisitor {
+ public:
+ explicit BuildStackTraceVisitor(Thread* thread) : StackVisitor(thread, NULL),
+ method_trace_(new std::vector<mirror::AbstractMethod*>) {}
+
+ bool VisitFrame() {
+ mirror::AbstractMethod* m = GetMethod();
+ // Ignore runtime frames (in particular callee save).
+ if (!m->IsRuntimeMethod()) {
+ method_trace_->push_back(m);
+ }
+ return true;
+ }
+
+ // Returns a stack trace where the topmost frame corresponds with the first element of the vector.
+ std::vector<mirror::AbstractMethod*>* GetStackTrace() const {
+ return method_trace_;
+ }
+
+ private:
+ std::vector<mirror::AbstractMethod*>* const method_trace_;
+};
+
static const char kTraceTokenChar = '*';
static const uint16_t kTraceHeaderLength = 32;
static const uint32_t kTraceMagicValue = 0x574f4c53;
@@ -96,7 +121,11 @@
ProfilerClockSource Trace::default_clock_source_ = kProfilerClockSourceWall;
#endif
-Trace* Trace::the_trace_ = NULL;
+Trace* volatile Trace::the_trace_ = NULL;
+// TODO: Add way to enable sampling and set interval through gui.
+bool Trace::sampling_enabled_ = true;
+uint32_t Trace::sampling_interval_us_ = 10000;
+pthread_t Trace::sampling_pthread_ = 0U;
static mirror::ArtMethod* DecodeTraceMethodId(uint32_t tmid) {
return reinterpret_cast<mirror::ArtMethod*>(tmid & ~kTraceMethodActionMask);
@@ -196,6 +225,82 @@
*buf++ = (uint8_t) (val >> 56);
}
+static void GetSample(Thread* thread, void* arg) SHARED_LOCKS_REQUIRED(Locks::mutator_lock_) {
+ BuildStackTraceVisitor build_trace_visitor(thread);
+ build_trace_visitor.WalkStack();
+ std::vector<mirror::AbstractMethod*>* stack_trace = build_trace_visitor.GetStackTrace();
+ Trace* the_trace = reinterpret_cast<Trace*>(arg);
+ the_trace->CompareAndUpdateStackTrace(thread, stack_trace);
+}
+
+void Trace::CompareAndUpdateStackTrace(Thread* thread,
+ std::vector<mirror::AbstractMethod*>* stack_trace) {
+ CHECK_EQ(pthread_self(), sampling_pthread_);
+ SafeMap<Thread*, std::vector<mirror::AbstractMethod*>*>::iterator map_it = thread_stack_trace_map_.find(thread);
+ if (map_it == thread_stack_trace_map_.end()) {
+ // If there's no existing stack trace in the map for this thread, log an entry event for all
+ // methods in the trace.
+ thread_stack_trace_map_.Put(thread, stack_trace);
+ for (std::vector<mirror::AbstractMethod*>::reverse_iterator rit = stack_trace->rbegin();
+ rit != stack_trace->rend(); ++rit) {
+ LogMethodTraceEvent(thread, *rit, instrumentation::Instrumentation::kMethodEntered);
+ }
+ } else {
+ // If there's a previous stack trace for this thread, diff the traces and emit entry and exit
+ // events accordingly.
+ std::vector<mirror::AbstractMethod*>* old_stack_trace = map_it->second;
+ thread_stack_trace_map_.Overwrite(thread, stack_trace);
+ std::vector<mirror::AbstractMethod*>::reverse_iterator old_rit = old_stack_trace->rbegin();
+ std::vector<mirror::AbstractMethod*>::reverse_iterator rit = stack_trace->rbegin();
+
+ // Iterate bottom-up over both traces until there's a difference between them.
+ while (old_rit != old_stack_trace->rend() && rit != stack_trace->rend() && *old_rit == *rit) {
+ old_rit++;
+ rit++;
+ }
+ // Iterate top-down over the old trace until the point where they differ, emitting exit events.
+ for (std::vector<mirror::AbstractMethod*>::iterator old_it = old_stack_trace->begin();
+ old_it != old_rit.base(); ++old_it) {
+ LogMethodTraceEvent(thread, *old_it, instrumentation::Instrumentation::kMethodExited);
+ }
+ // Iterate bottom-up over the new trace from the point where they differ, emitting entry events.
+ for (; rit != stack_trace->rend(); ++rit) {
+ LogMethodTraceEvent(thread, *rit, instrumentation::Instrumentation::kMethodEntered);
+ }
+ delete old_stack_trace;
+ }
+}
+
+void* Trace::RunSamplingThread(void* arg) {
+ Runtime* runtime = Runtime::Current();
+ CHECK(runtime->AttachCurrentThread("Sampling Profiler", true, runtime->GetSystemThreadGroup(),
+ !runtime->IsCompiler()));
+
+ while (true) {
+ usleep(sampling_interval_us_);
+
+ Thread* self = Thread::Current();
+ Trace* the_trace;
+ {
+ MutexLock mu(self, *Locks::trace_lock_);
+ the_trace = the_trace_;
+ if (the_trace == NULL) {
+ break;
+ }
+ }
+
+ runtime->GetThreadList()->SuspendAll();
+ {
+ MutexLock mu(self, *Locks::thread_list_lock_);
+ runtime->GetThreadList()->ForEach(GetSample, the_trace);
+ }
+ runtime->GetThreadList()->ResumeAll();
+ }
+
+ runtime->DetachCurrentThread();
+ return NULL;
+}
+
void Trace::Start(const char* trace_filename, int trace_fd, int buffer_size, int flags,
bool direct_to_ddms) {
Thread* self = Thread::Current();
@@ -240,10 +345,15 @@
runtime->SetStatsEnabled(true);
}
- runtime->GetInstrumentation()->AddListener(the_trace_,
- instrumentation::Instrumentation::kMethodEntered |
- instrumentation::Instrumentation::kMethodExited |
- instrumentation::Instrumentation::kMethodUnwind);
+ if (sampling_enabled_) {
+ CHECK_PTHREAD_CALL(pthread_create, (&sampling_pthread_, NULL, &RunSamplingThread, NULL),
+ "Sampling profiler thread");
+ } else {
+ runtime->GetInstrumentation()->AddListener(the_trace_,
+ instrumentation::Instrumentation::kMethodEntered |
+ instrumentation::Instrumentation::kMethodExited |
+ instrumentation::Instrumentation::kMethodUnwind);
+ }
}
}
runtime->GetThreadList()->ResumeAll();
@@ -253,6 +363,7 @@
Runtime* runtime = Runtime::Current();
runtime->GetThreadList()->SuspendAll();
Trace* the_trace = NULL;
+ pthread_t sampling_pthread = 0U;
{
MutexLock mu(Thread::Current(), *Locks::trace_lock_);
if (the_trace_ == NULL) {
@@ -260,17 +371,26 @@
} else {
the_trace = the_trace_;
the_trace_ = NULL;
+ sampling_pthread = sampling_pthread_;
+ sampling_pthread_ = 0U;
}
}
if (the_trace != NULL) {
the_trace->FinishTracing();
- runtime->GetInstrumentation()->RemoveListener(the_trace,
- instrumentation::Instrumentation::kMethodEntered |
- instrumentation::Instrumentation::kMethodExited |
- instrumentation::Instrumentation::kMethodUnwind);
+
+ if (!sampling_enabled_) {
+ runtime->GetInstrumentation()->RemoveListener(the_trace,
+ instrumentation::Instrumentation::kMethodEntered |
+ instrumentation::Instrumentation::kMethodExited |
+ instrumentation::Instrumentation::kMethodUnwind);
+ }
delete the_trace;
}
runtime->GetThreadList()->ResumeAll();
+
+ if (sampling_enabled_ && sampling_pthread != 0U) {
+ CHECK_PTHREAD_CALL(pthread_join, (sampling_pthread, NULL), "sampling thread shutdown");
+ }
}
void Trace::Shutdown() {
@@ -304,6 +424,11 @@
cur_offset_ = kTraceHeaderLength;
}
+Trace::~Trace() {
+ CHECK_EQ(sampling_pthread_, static_cast<pthread_t>(0U));
+ STLDeleteValues(&thread_stack_trace_map_);
+}
+
static void DumpBuf(uint8_t* buf, size_t buf_size, ProfilerClockSource clock_source)
SHARED_LOCKS_REQUIRED(Locks::mutator_lock_) {
uint8_t* ptr = buf + kTraceHeaderLength;
diff --git a/runtime/trace.h b/runtime/trace.h
index ae583ca..7746362 100644
--- a/runtime/trace.h
+++ b/runtime/trace.h
@@ -20,6 +20,7 @@
#include <ostream>
#include <set>
#include <string>
+#include <vector>
#include "base/macros.h"
#include "globals.h"
@@ -62,6 +63,9 @@
bool UseWallClock();
bool UseThreadCpuClock();
+ void CompareAndUpdateStackTrace(Thread* thread, std::vector<mirror::AbstractMethod*>* stack_trace)
+ SHARED_LOCKS_REQUIRED(Locks::mutator_lock_);
+
virtual void MethodEntered(Thread* thread, mirror::Object* this_object,
const mirror::ArtMethod* method, uint32_t dex_pc)
SHARED_LOCKS_REQUIRED(Locks::mutator_lock_);
@@ -79,9 +83,13 @@
mirror::Throwable* exception_object)
SHARED_LOCKS_REQUIRED(Locks::mutator_lock_);
+ ~Trace();
+
private:
explicit Trace(File* trace_file, int buffer_size, int flags);
+ static void* RunSamplingThread(void* arg) LOCKS_EXCLUDED(Locks::trace_lock_);
+
void FinishTracing() SHARED_LOCKS_REQUIRED(Locks::mutator_lock_);
void LogMethodTraceEvent(Thread* thread, const mirror::ArtMethod* method,
@@ -94,11 +102,23 @@
void DumpThreadList(std::ostream& os) LOCKS_EXCLUDED(Locks::thread_list_lock_);
// Singleton instance of the Trace or NULL when no method tracing is active.
- static Trace* the_trace_ GUARDED_BY(Locks::trace_lock_);
+ static Trace* volatile the_trace_ GUARDED_BY(Locks::trace_lock_);
// The default profiler clock source.
static ProfilerClockSource default_clock_source_;
+ // True if traceview should sample instead of instrumenting method entry/exit.
+ static bool sampling_enabled_;
+
+ // Sampling interval in microseconds.
+ static uint32_t sampling_interval_us_;
+
+ // Sampling thread, non-zero when sampling.
+ static pthread_t sampling_pthread_;
+
+ // Maps a thread to its most recent stack trace sample.
+ SafeMap<Thread*, std::vector<mirror::AbstractMethod*>*> thread_stack_trace_map_;
+
// Maps a thread to its clock base.
SafeMap<Thread*, uint64_t> thread_clock_base_map_;
diff --git a/runtime/verifier/method_verifier.cc b/runtime/verifier/method_verifier.cc
index 0216844..dcc9f90 100644
--- a/runtime/verifier/method_verifier.cc
+++ b/runtime/verifier/method_verifier.cc
@@ -45,6 +45,7 @@
namespace verifier {
static const bool gDebugVerify = false;
+// TODO: Add a constant to method_verifier to turn on verbose logging?
void PcToRegisterLineTable::Init(RegisterTrackingMode mode, InstructionFlags* flags,
uint32_t insns_size, uint16_t registers_size,
@@ -231,26 +232,28 @@
MethodVerifier::FailureKind result = kNoFailure;
uint64_t start_ns = NanoTime();
- MethodVerifier verifier(dex_file, dex_cache, class_loader, class_def_idx, code_item, method_idx,
- method, method_access_flags, true, allow_soft_failures);
- if (verifier.Verify()) {
+ MethodVerifier verifier_(dex_file, dex_cache, class_loader, class_def_idx, code_item, method_idx,
+ method, method_access_flags, true, allow_soft_failures);
+ if (verifier_.Verify()) {
// Verification completed, however failures may be pending that didn't cause the verification
// to hard fail.
- CHECK(!verifier.have_pending_hard_failure_);
- if (verifier.failures_.size() != 0) {
- verifier.DumpFailures(LOG(INFO) << "Soft verification failures in "
- << PrettyMethod(method_idx, *dex_file) << "\n");
+ CHECK(!verifier_.have_pending_hard_failure_);
+ if (verifier_.failures_.size() != 0) {
+ if (VLOG_IS_ON(verifier)) {
+ verifier_.DumpFailures(VLOG_STREAM(verifier) << "Soft verification failures in "
+ << PrettyMethod(method_idx, *dex_file) << "\n");
+ }
result = kSoftFailure;
}
} else {
// Bad method data.
- CHECK_NE(verifier.failures_.size(), 0U);
- CHECK(verifier.have_pending_hard_failure_);
- verifier.DumpFailures(LOG(INFO) << "Verification error in "
+ CHECK_NE(verifier_.failures_.size(), 0U);
+ CHECK(verifier_.have_pending_hard_failure_);
+ verifier_.DumpFailures(LOG(INFO) << "Verification error in "
<< PrettyMethod(method_idx, *dex_file) << "\n");
if (gDebugVerify) {
- std::cout << "\n" << verifier.info_messages_.str();
- verifier.Dump(std::cout);
+ std::cout << "\n" << verifier_.info_messages_.str();
+ verifier_.Dump(std::cout);
}
result = kHardFailure;
}
@@ -1079,8 +1082,10 @@
std::ostream& MethodVerifier::DumpFailures(std::ostream& os) {
DCHECK_EQ(failures_.size(), failure_messages_.size());
- for (size_t i = 0; i < failures_.size(); ++i) {
- os << failure_messages_[i]->str() << "\n";
+ if (VLOG_IS_ON(verifier)) {
+ for (size_t i = 0; i < failures_.size(); ++i) {
+ os << failure_messages_[i]->str() << "\n";
+ }
}
return os;
}
@@ -3386,7 +3391,7 @@
dex_cache_,
class_loader_);
if (field == NULL) {
- LOG(INFO) << "Unable to resolve static field " << field_idx << " ("
+ VLOG(verifier) << "Unable to resolve static field " << field_idx << " ("
<< dex_file_->GetFieldName(field_id) << ") in "
<< dex_file_->GetFieldDeclaringClassDescriptor(field_id);
DCHECK(Thread::Current()->IsExceptionPending());
@@ -3423,7 +3428,7 @@
dex_cache_,
class_loader_);
if (field == NULL) {
- LOG(INFO) << "Unable to resolve instance field " << field_idx << " ("
+ VLOG(verifier) << "Unable to resolve instance field " << field_idx << " ("
<< dex_file_->GetFieldName(field_id) << ") in "
<< dex_file_->GetFieldDeclaringClassDescriptor(field_id);
DCHECK(Thread::Current()->IsExceptionPending());
