Merge "Fix tracing"
diff --git a/runtime/trace.cc b/runtime/trace.cc
index d3b3af8..5a43b56 100644
--- a/runtime/trace.cc
+++ b/runtime/trace.cc
@@ -46,48 +46,8 @@
namespace art {
-// File format:
-// header
-// record 0
-// record 1
-// ...
-//
-// Header format:
-// u4 magic ('SLOW')
-// u2 version
-// u2 offset to data
-// u8 start date/time in usec
-// u2 record size in bytes (version >= 2 only)
-// ... padding to 32 bytes
-//
-// Record format v1:
-// u1 thread ID
-// u4 method ID | method action
-// u4 time delta since start, in usec
-//
-// Record format v2:
-// u2 thread ID
-// u4 method ID | method action
-// u4 time delta since start, in usec
-//
-// Record format v3:
-// u2 thread ID
-// u4 method ID | method action
-// u4 time delta since start, in usec
-// u4 wall time since start, in usec (when clock == "dual" only)
-//
-// 32 bits of microseconds is 70 minutes.
-//
-// All values are stored in little-endian order.
-
-enum TraceAction {
- kTraceMethodEnter = 0x00, // method entry
- kTraceMethodExit = 0x01, // method exit
- kTraceUnroll = 0x02, // method exited by exception unrolling
- // 0x03 currently unused
- kTraceMethodActionMask = 0x03, // two bits
-};
-
+static constexpr size_t TraceActionBits = MinimumBitsToStore(
+ static_cast<size_t>(kTraceMethodActionMask));
static constexpr uint8_t kOpNewMethod = 1U;
static constexpr uint8_t kOpNewThread = 2U;
@@ -120,8 +80,8 @@
static const uint32_t kTraceMagicValue = 0x574f4c53;
static const uint16_t kTraceVersionSingleClock = 2;
static const uint16_t kTraceVersionDualClock = 3;
-static const uint16_t kTraceRecordSizeSingleClock = 14; // using v2
-static const uint16_t kTraceRecordSizeDualClock = 18; // using v3 with two timestamps
+static const uint16_t kTraceRecordSizeSingleClock = 10; // using v2
+static const uint16_t kTraceRecordSizeDualClock = 14; // using v3 with two timestamps
TraceClockSource Trace::default_clock_source_ = kDefaultTraceClockSource;
@@ -132,26 +92,40 @@
// The key identifying the tracer to update instrumentation.
static constexpr const char* kTracerInstrumentationKey = "Tracer";
-static ArtMethod* DecodeTraceMethodId(uint64_t tmid) {
- return reinterpret_cast<ArtMethod*>(tmid & ~kTraceMethodActionMask);
-}
-
static TraceAction DecodeTraceAction(uint32_t tmid) {
return static_cast<TraceAction>(tmid & kTraceMethodActionMask);
}
-static uint64_t EncodeTraceMethodAndAction(ArtMethod* method, TraceAction action) {
- auto tmid = static_cast<uint64_t>(reinterpret_cast<uintptr_t>(method)) | action;
- DCHECK_EQ(method, DecodeTraceMethodId(tmid));
+ArtMethod* Trace::DecodeTraceMethod(uint32_t tmid) {
+ MutexLock mu(Thread::Current(), *unique_methods_lock_);
+ return unique_methods_[tmid >> TraceActionBits];
+}
+
+uint32_t Trace::EncodeTraceMethod(ArtMethod* method) {
+ MutexLock mu(Thread::Current(), *unique_methods_lock_);
+ uint32_t idx;
+ auto it = art_method_id_map_.find(method);
+ if (it != art_method_id_map_.end()) {
+ idx = it->second;
+ } else {
+ unique_methods_.push_back(method);
+ idx = unique_methods_.size() - 1;
+ art_method_id_map_.emplace(method, idx);
+ }
+ DCHECK_LT(idx, unique_methods_.size());
+ DCHECK_EQ(unique_methods_[idx], method);
+ return idx;
+}
+
+uint32_t Trace::EncodeTraceMethodAndAction(ArtMethod* method, TraceAction action) {
+ uint32_t tmid = (EncodeTraceMethod(method) << TraceActionBits) | action;
+ DCHECK_EQ(method, DecodeTraceMethod(tmid));
return tmid;
}
std::vector<ArtMethod*>* Trace::AllocStackTrace() {
- if (temp_stack_trace_.get() != nullptr) {
- return temp_stack_trace_.release();
- } else {
- return new std::vector<ArtMethod*>();
- }
+ return (temp_stack_trace_.get() != nullptr) ? temp_stack_trace_.release() :
+ new std::vector<ArtMethod*>();
}
void Trace::FreeStackTrace(std::vector<ArtMethod*>* stack_trace) {
@@ -272,24 +246,22 @@
if (old_stack_trace == nullptr) {
// If there's no previous stack trace sample for this thread, log an entry event for all
// methods in the trace.
- for (std::vector<ArtMethod*>::reverse_iterator rit = stack_trace->rbegin();
- rit != stack_trace->rend(); ++rit) {
+ for (auto rit = stack_trace->rbegin(); rit != stack_trace->rend(); ++rit) {
LogMethodTraceEvent(thread, *rit, instrumentation::Instrumentation::kMethodEntered,
thread_clock_diff, wall_clock_diff);
}
} else {
// If there's a previous stack trace for this thread, diff the traces and emit entry and exit
// events accordingly.
- std::vector<ArtMethod*>::reverse_iterator old_rit = old_stack_trace->rbegin();
- std::vector<ArtMethod*>::reverse_iterator rit = stack_trace->rbegin();
+ auto old_rit = old_stack_trace->rbegin();
+ auto 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<ArtMethod*>::iterator old_it = old_stack_trace->begin();
- old_it != old_rit.base(); ++old_it) {
+ for (auto old_it = old_stack_trace->begin(); old_it != old_rit.base(); ++old_it) {
LogMethodTraceEvent(thread, *old_it, instrumentation::Instrumentation::kMethodExited,
thread_clock_diff, wall_clock_diff);
}
@@ -608,7 +580,8 @@
clock_source_(default_clock_source_),
buffer_size_(std::max(kMinBufSize, buffer_size)),
start_time_(MicroTime()), clock_overhead_ns_(GetClockOverheadNanoSeconds()), cur_offset_(0),
- overflow_(false), interval_us_(0), streaming_lock_(nullptr) {
+ overflow_(false), interval_us_(0), streaming_lock_(nullptr),
+ unique_methods_lock_(new Mutex("unique methods lock")) {
uint16_t trace_version = GetTraceVersion(clock_source_);
if (output_mode == TraceOutputMode::kStreaming) {
trace_version |= 0xF0U;
@@ -647,14 +620,13 @@
return ret;
}
-static void DumpBuf(uint8_t* buf, size_t buf_size, TraceClockSource clock_source)
- SHARED_LOCKS_REQUIRED(Locks::mutator_lock_) {
+void Trace::DumpBuf(uint8_t* buf, size_t buf_size, TraceClockSource clock_source) {
uint8_t* ptr = buf + kTraceHeaderLength;
uint8_t* end = buf + buf_size;
while (ptr < end) {
- uint64_t tmid = ReadBytes(ptr + 2, sizeof(tmid));
- ArtMethod* method = DecodeTraceMethodId(tmid);
+ uint32_t tmid = ReadBytes(ptr + 2, sizeof(tmid));
+ ArtMethod* method = DecodeTraceMethod(tmid);
TraceAction action = DecodeTraceAction(tmid);
LOG(INFO) << PrettyMethod(method) << " " << static_cast<int>(action);
ptr += GetRecordSize(clock_source);
@@ -683,9 +655,7 @@
GetVisitedMethodsFromBitSets(seen_methods_, &visited_methods);
// Clean up.
- for (auto& e : seen_methods_) {
- delete e.second;
- }
+ STLDeleteValues(&seen_methods_);
} else {
final_offset = cur_offset_.LoadRelaxed();
GetVisitedMethods(final_offset, &visited_methods);
@@ -877,10 +847,10 @@
return false;
}
-static std::string GetMethodLine(ArtMethod* method)
- SHARED_LOCKS_REQUIRED(Locks::mutator_lock_) {
+std::string Trace::GetMethodLine(ArtMethod* method) {
method = method->GetInterfaceMethodIfProxy(sizeof(void*));
- return StringPrintf("%p\t%s\t%s\t%s\t%s\n", method,
+ return StringPrintf("%p\t%s\t%s\t%s\t%s\n",
+ reinterpret_cast<void*>((EncodeTraceMethod(method) << TraceActionBits)),
PrettyDescriptor(method->GetDeclaringClassDescriptor()).c_str(), method->GetName(),
method->GetSignature().ToString().c_str(), method->GetDeclaringClassSourceFile());
}
@@ -945,11 +915,11 @@
UNIMPLEMENTED(FATAL) << "Unexpected event: " << event;
}
- uint64_t method_value = EncodeTraceMethodAndAction(method, action);
+ uint32_t method_value = EncodeTraceMethodAndAction(method, action);
// Write data
uint8_t* ptr;
- static constexpr size_t kPacketSize = 18U; // The maximum size of data in a packet.
+ static constexpr size_t kPacketSize = 14U; // The maximum size of data in a packet.
uint8_t stack_buf[kPacketSize]; // Space to store a packet when in streaming mode.
if (trace_output_mode_ == TraceOutputMode::kStreaming) {
ptr = stack_buf;
@@ -958,8 +928,8 @@
}
Append2LE(ptr, thread->GetTid());
- Append8LE(ptr + 2, method_value);
- ptr += 10;
+ Append4LE(ptr + 2, method_value);
+ ptr += 6;
if (UseThreadCpuClock()) {
Append4LE(ptr, thread_clock_diff);
@@ -968,7 +938,7 @@
if (UseWallClock()) {
Append4LE(ptr, wall_clock_diff);
}
- static_assert(kPacketSize == 2 + 8 + 4 + 4, "Packet size incorrect.");
+ static_assert(kPacketSize == 2 + 4 + 4 + 4, "Packet size incorrect.");
if (trace_output_mode_ == TraceOutputMode::kStreaming) {
MutexLock mu(Thread::Current(), *streaming_lock_); // To serialize writing.
@@ -1004,8 +974,8 @@
uint8_t* end = buf_.get() + buf_size;
while (ptr < end) {
- uint64_t tmid = ReadBytes(ptr + 2, sizeof(tmid));
- ArtMethod* method = DecodeTraceMethodId(tmid);
+ uint32_t tmid = ReadBytes(ptr + 2, sizeof(tmid));
+ ArtMethod* method = DecodeTraceMethod(tmid);
visited_methods->insert(method);
ptr += GetRecordSize(clock_source_);
}
diff --git a/runtime/trace.h b/runtime/trace.h
index 1539c06..7bc495a 100644
--- a/runtime/trace.h
+++ b/runtime/trace.h
@@ -23,6 +23,7 @@
#include <ostream>
#include <set>
#include <string>
+#include <unordered_map>
#include <vector>
#include "atomic.h"
@@ -51,6 +52,48 @@
kSampleProfilingActive,
};
+// File format:
+// header
+// record 0
+// record 1
+// ...
+//
+// Header format:
+// u4 magic ('SLOW')
+// u2 version
+// u2 offset to data
+// u8 start date/time in usec
+// u2 record size in bytes (version >= 2 only)
+// ... padding to 32 bytes
+//
+// Record format v1:
+// u1 thread ID
+// u4 method ID | method action
+// u4 time delta since start, in usec
+//
+// Record format v2:
+// u2 thread ID
+// u4 method ID | method action
+// u4 time delta since start, in usec
+//
+// Record format v3:
+// u2 thread ID
+// u4 method ID | method action
+// u4 time delta since start, in usec
+// u4 wall time since start, in usec (when clock == "dual" only)
+//
+// 32 bits of microseconds is 70 minutes.
+//
+// All values are stored in little-endian order.
+
+enum TraceAction {
+ kTraceMethodEnter = 0x00, // method entry
+ kTraceMethodExit = 0x01, // method exit
+ kTraceUnroll = 0x02, // method exited by exception unrolling
+ // 0x03 currently unused
+ kTraceMethodActionMask = 0x03, // two bits
+};
+
class Trace FINAL : public instrumentation::InstrumentationListener {
public:
enum TraceFlag {
@@ -173,6 +216,16 @@
void WriteToBuf(const uint8_t* src, size_t src_size)
EXCLUSIVE_LOCKS_REQUIRED(streaming_lock_);
+ uint32_t EncodeTraceMethod(ArtMethod* method) LOCKS_EXCLUDED(unique_methods_lock_);
+ uint32_t EncodeTraceMethodAndAction(ArtMethod* method, TraceAction action)
+ LOCKS_EXCLUDED(unique_methods_lock_);
+ ArtMethod* DecodeTraceMethod(uint32_t tmid) LOCKS_EXCLUDED(unique_methods_lock_);
+ std::string GetMethodLine(ArtMethod* method) LOCKS_EXCLUDED(unique_methods_lock_)
+ SHARED_LOCKS_REQUIRED(Locks::mutator_lock_);
+
+ void DumpBuf(uint8_t* buf, size_t buf_size, TraceClockSource clock_source)
+ SHARED_LOCKS_REQUIRED(Locks::mutator_lock_);
+
// Singleton instance of the Trace or null when no method tracing is active.
static Trace* volatile the_trace_ GUARDED_BY(Locks::trace_lock_);
@@ -229,6 +282,12 @@
std::map<mirror::DexCache*, DexIndexBitSet*> seen_methods_;
std::unique_ptr<ThreadIDBitSet> seen_threads_;
+ // Bijective map from ArtMethod* to index.
+ // Map from ArtMethod* to index in unique_methods_;
+ Mutex* unique_methods_lock_ DEFAULT_MUTEX_ACQUIRED_AFTER;
+ std::unordered_map<ArtMethod*, uint32_t> art_method_id_map_ GUARDED_BY(unique_methods_lock_);
+ std::vector<ArtMethod*> unique_methods_ GUARDED_BY(unique_methods_lock_);
+
DISALLOW_COPY_AND_ASSIGN(Trace);
};
