Update method tracing to use per-thread buffer
Method tracing in streaming mode uses a global buffer to record method
entry / exit events and uses locks to synchronize across threads. Taking
a lock for each event is expensive and makes the method tracing slow.
This CL changes it to use a per-thread buffer so that each thread
accesses its own buffer. This also allows us to fast path method trace
events in JITed code in the future. The changes in this CL:
1. Add a per-thread buffer which is initialized lazily on the first
method trace event.
2. When the per-thread buffer is initialized we record the information
about the thread. This means we no longer need the bitmap we used
to record the thread info when a new thread is seen.
3. The data from the buffer is flushed to file:
1. When a thread detaches, so we can flush any recorded data
2. When the buffer is full
3. When we stop tracing.
The per-thread buffer is always accessed by the thread that owns it
except when we record the method enter events for on stack methods. It
is safe to access other thread's buffer since everything is suspended at
that point.
This CL also adds a test to check that the generated trace is in the
expected format.
Bug: 259258187
Test: art/testrunner.py -t 2246
Change-Id: I074bf2edb8c884dec0c9a7a9c37b4ef0ec7892a8
diff --git a/runtime/entrypoints_order_test.cc b/runtime/entrypoints_order_test.cc
index bd822c1..50fa0ab 100644
--- a/runtime/entrypoints_order_test.cc
+++ b/runtime/entrypoints_order_test.cc
@@ -135,10 +135,14 @@
EXPECT_OFFSET_DIFFP(Thread, tlsPtr_, thread_local_mark_stack, async_exception, sizeof(void*));
EXPECT_OFFSET_DIFFP(Thread, tlsPtr_, async_exception, top_reflective_handle_scope,
sizeof(void*));
+ EXPECT_OFFSET_DIFFP(
+ Thread, tlsPtr_, top_reflective_handle_scope, method_trace_buffer, sizeof(void*));
+ EXPECT_OFFSET_DIFFP(
+ Thread, tlsPtr_, method_trace_buffer, method_trace_buffer_index, sizeof(void*));
// The first field after tlsPtr_ is forced to a 16 byte alignment so it might have some space.
auto offset_tlsptr_end = OFFSETOF_MEMBER(Thread, tlsPtr_) +
sizeof(decltype(reinterpret_cast<Thread*>(16)->tlsPtr_));
- CHECKED(offset_tlsptr_end - OFFSETOF_MEMBER(Thread, tlsPtr_.top_reflective_handle_scope) ==
+ CHECKED(offset_tlsptr_end - OFFSETOF_MEMBER(Thread, tlsPtr_.method_trace_buffer_index) ==
sizeof(void*),
"async_exception last field");
}
diff --git a/runtime/thread.cc b/runtime/thread.cc
index 751bd09..000078f 100644
--- a/runtime/thread.cc
+++ b/runtime/thread.cc
@@ -113,6 +113,7 @@
#include "stack_map.h"
#include "thread-inl.h"
#include "thread_list.h"
+#include "trace.h"
#include "verifier/method_verifier.h"
#include "verify_object.h"
#include "well_known_classes-inl.h"
@@ -2558,6 +2559,10 @@
if (tlsPtr_.opeer != nullptr) {
ScopedObjectAccess soa(self);
+ if (UNLIKELY(self->GetMethodTraceBuffer() != nullptr)) {
+ Trace::FlushThreadBuffer(self);
+ self->ResetMethodTraceBuffer();
+ }
// We may need to call user-supplied managed code, do this before final clean-up.
HandleUncaughtExceptions();
RemoveFromThreadGroup();
@@ -2634,6 +2639,10 @@
SetCachedThreadName(nullptr); // Deallocate name.
delete tlsPtr_.deps_or_stack_trace_sample.stack_trace_sample;
+ if (tlsPtr_.method_trace_buffer != nullptr) {
+ delete[] tlsPtr_.method_trace_buffer;
+ }
+
Runtime::Current()->GetHeap()->AssertThreadLocalBuffersAreRevoked(this);
TearDownAlternateSignalStack();
diff --git a/runtime/thread.h b/runtime/thread.h
index 2613b15..6c74dd9 100644
--- a/runtime/thread.h
+++ b/runtime/thread.h
@@ -1206,6 +1206,22 @@
tlsPtr_.deps_or_stack_trace_sample.verifier_deps = verifier_deps;
}
+ uintptr_t* GetMethodTraceBuffer() { return tlsPtr_.method_trace_buffer; }
+
+ size_t* GetMethodTraceIndexPtr() { return &tlsPtr_.method_trace_buffer_index; }
+
+ uintptr_t* SetMethodTraceBuffer(uintptr_t* buffer) {
+ return tlsPtr_.method_trace_buffer = buffer;
+ }
+
+ void ResetMethodTraceBuffer() {
+ if (tlsPtr_.method_trace_buffer != nullptr) {
+ delete[] tlsPtr_.method_trace_buffer;
+ }
+ tlsPtr_.method_trace_buffer = nullptr;
+ tlsPtr_.method_trace_buffer_index = 0;
+ }
+
uint64_t GetTraceClockBase() const {
return tls64_.trace_clock_base;
}
@@ -1940,7 +1956,9 @@
method_verifier(nullptr),
thread_local_mark_stack(nullptr),
async_exception(nullptr),
- top_reflective_handle_scope(nullptr) {
+ top_reflective_handle_scope(nullptr),
+ method_trace_buffer(nullptr),
+ method_trace_buffer_index(0) {
std::fill(held_mutexes, held_mutexes + kLockLevelCount, nullptr);
}
@@ -2103,6 +2121,12 @@
// Top of the linked-list for reflective-handle scopes or null if none.
BaseReflectiveHandleScope* top_reflective_handle_scope;
+
+ // Pointer to a thread-local buffer for method tracing.
+ uintptr_t* method_trace_buffer;
+
+ // The index of the next free entry in method_trace_buffer.
+ size_t method_trace_buffer_index;
} tlsPtr_;
// Small thread-local cache to be used from the interpreter.
diff --git a/runtime/trace.cc b/runtime/trace.cc
index 93eec3e..0f93742 100644
--- a/runtime/trace.cc
+++ b/runtime/trace.cc
@@ -528,6 +528,11 @@
}
}
+void Trace::FlushThreadBuffer(Thread* self) {
+ MutexLock mu(self, *Locks::trace_lock_);
+ the_trace_->FlushStreamingBuffer(self);
+}
+
void Trace::Abort() {
// Do not write anything anymore.
StopTracing(false, false);
@@ -561,6 +566,10 @@
}
static constexpr size_t kMinBufSize = 18U; // Trace header is up to 18B.
+// Size of per-thread buffer size. The value is chosen arbitrarily. This value
+// should be greater than kMinBufSize.
+static constexpr size_t kPerThreadBufSize = 512 * 1024;
+static_assert(kPerThreadBufSize > kMinBufSize);
Trace::Trace(File* trace_file,
size_t buffer_size,
@@ -569,11 +578,16 @@
TraceMode trace_mode)
: trace_file_(trace_file),
buf_(new uint8_t[std::max(kMinBufSize, buffer_size)]()),
- flags_(flags), trace_output_mode_(output_mode), trace_mode_(trace_mode),
+ flags_(flags),
+ trace_output_mode_(output_mode),
+ trace_mode_(trace_mode),
clock_source_(default_clock_source_),
buffer_size_(std::max(kMinBufSize, buffer_size)),
- start_time_(MicroTime()), clock_overhead_ns_(GetClockOverheadNanoSeconds()),
- overflow_(false), interval_us_(0), streaming_lock_(nullptr),
+ start_time_(MicroTime()),
+ clock_overhead_ns_(GetClockOverheadNanoSeconds()),
+ overflow_(false),
+ interval_us_(0),
+ streaming_lock_(nullptr),
unique_methods_lock_(new Mutex("unique methods lock", kTracingUniqueMethodsLock)) {
CHECK_IMPLIES(trace_file == nullptr, output_mode == TraceOutputMode::kDDMS);
@@ -597,7 +611,12 @@
if (output_mode == TraceOutputMode::kStreaming) {
streaming_lock_ = new Mutex("tracing lock", LockLevel::kTracingStreamingLock);
- seen_threads_.reset(new ThreadIDBitSet());
+ // Flush the header information to the file. We use a per thread buffer, so
+ // it is easier to just write the header information directly to file.
+ if (!trace_file_->WriteFully(buf_.get(), kTraceHeaderLength)) {
+ PLOG(WARNING) << "Failed streaming a tracing event.";
+ }
+ cur_offset_.store(0, std::memory_order_relaxed);
}
}
@@ -677,20 +696,30 @@
std::string header(os.str());
if (trace_output_mode_ == TraceOutputMode::kStreaming) {
- // Protect access to buf_ and satisfy sanitizer for calls to WriteBuf / FlushBuf.
- MutexLock mu(Thread::Current(), *streaming_lock_);
+ // Flush thread specific buffer from all threads.
+ {
+ MutexLock tl_lock(Thread::Current(), *Locks::thread_list_lock_);
+ for (Thread* thread : Runtime::Current()->GetThreadList()->GetList()) {
+ if (thread->GetMethodTraceBuffer() != nullptr) {
+ FlushStreamingBuffer(thread);
+ thread->ResetMethodTraceBuffer();
+ }
+ }
+ }
+ // It is expected that this method is called when all other threads are suspended, so there
+ // cannot be any writes to trace_file_ after finish tracing.
// Write a special token to mark the end of trace records and the start of
// trace summary.
uint8_t buf[7];
Append2LE(buf, 0);
buf[2] = kOpTraceSummary;
Append4LE(buf + 3, static_cast<uint32_t>(header.length()));
- WriteToBuf(buf, sizeof(buf));
// Write the trace summary. The summary is identical to the file header when
// the output mode is not streaming (except for methods).
- WriteToBuf(reinterpret_cast<const uint8_t*>(header.c_str()), header.length());
- // Flush the buffer, which may include some trace records before the summary.
- FlushBuf();
+ if (!trace_file_->WriteFully(buf, sizeof(buf)) ||
+ !trace_file_->WriteFully(header.c_str(), header.length())) {
+ PLOG(WARNING) << "Failed streaming a tracing event.";
+ }
} else {
if (trace_file_.get() == nullptr) {
std::vector<uint8_t> data;
@@ -831,18 +860,6 @@
return false;
}
-bool Trace::RegisterThread(Thread* thread) {
- pid_t tid = thread->GetTid();
- CHECK_LT(0U, static_cast<uint32_t>(tid));
- CHECK_LT(static_cast<uint32_t>(tid), kMaxThreadIdNumber);
-
- if (!(*seen_threads_)[tid]) {
- seen_threads_->set(tid);
- return true;
- }
- return false;
-}
-
std::string Trace::GetMethodLine(ArtMethod* method) {
method = method->GetInterfaceMethodIfProxy(kRuntimePointerSize);
return StringPrintf("%#x\t%s\t%s\t%s\t%s\n", (EncodeTraceMethod(method) << TraceActionBits),
@@ -850,54 +867,155 @@
method->GetSignature().ToString().c_str(), method->GetDeclaringClassSourceFile());
}
-void Trace::WriteToBuf(const uint8_t* src, size_t src_size) {
- // Updates to cur_offset_ are done under the streaming_lock_ here as in streaming mode.
- int32_t old_offset = cur_offset_.load(std::memory_order_relaxed);
- int32_t new_offset = old_offset + static_cast<int32_t>(src_size);
- if (dchecked_integral_cast<size_t>(new_offset) > buffer_size_) {
- // Flush buffer.
- if (!trace_file_->WriteFully(buf_.get(), old_offset)) {
- PLOG(WARNING) << "Failed streaming a tracing event.";
- }
+void Trace::RecordStreamingMethodEvent(Thread* thread,
+ ArtMethod* method,
+ TraceAction action,
+ uint32_t thread_clock_diff,
+ uint32_t wall_clock_diff) {
+ uintptr_t* method_trace_buffer = thread->GetMethodTraceBuffer();
+ size_t* current_offset = thread->GetMethodTraceIndexPtr();
+ // Initialize the buffer lazily. It's just simpler to keep the creation at one place.
+ if (method_trace_buffer == nullptr) {
+ method_trace_buffer = new uintptr_t[std::max(kMinBufSize, kPerThreadBufSize)]();
+ thread->SetMethodTraceBuffer(method_trace_buffer);
+ *current_offset = 0;
- // Check whether the data is too large for the buffer, then write immediately.
- if (src_size >= buffer_size_) {
- if (!trace_file_->WriteFully(src, src_size)) {
+ // This is the first event from this thread, so first record information about the thread.
+ std::string thread_name;
+ thread->GetThreadName(thread_name);
+ static constexpr size_t kThreadNameHeaderSize = 7;
+ uint8_t header[kThreadNameHeaderSize];
+ Append2LE(header, 0);
+ header[2] = kOpNewThread;
+ // We use only 16 bits to encode thread id. On Android, we don't expect to use more than
+ // 16-bits for a Tid. For 32-bit platforms it is always ensured we use less than 16 bits.
+ // See __check_max_thread_id in bionic for more details. Even on 64-bit the max threads
+ // is currently less than 65536.
+ // TODO(mythria): On host, we know thread ids can be greater than 16 bits. Consider adding
+ // a map similar to method ids.
+ DCHECK(!kIsTargetBuild || thread->GetTid() < (1 << 16));
+ Append2LE(header + 3, static_cast<uint16_t>(thread->GetTid()));
+ Append2LE(header + 5, static_cast<uint16_t>(thread_name.length()));
+
+ {
+ MutexLock mu(Thread::Current(), *streaming_lock_);
+ if (!trace_file_->WriteFully(header, kThreadNameHeaderSize) ||
+ !trace_file_->WriteFully(reinterpret_cast<const uint8_t*>(thread_name.c_str()),
+ thread_name.length())) {
PLOG(WARNING) << "Failed streaming a tracing event.";
}
- cur_offset_.store(0, std::memory_order_relaxed); // Buffer is empty now.
- return;
+ }
+ }
+
+ size_t required_entries = (clock_source_ == TraceClockSource::kDual) ? 4 : 3;
+ if (*current_offset + required_entries >= kPerThreadBufSize) {
+ // We don't have space for further entries. Flush the contents of the buffer and reuse the
+ // buffer to store contents. Reset the index to the start of the buffer.
+ FlushStreamingBuffer(thread);
+ *current_offset = 0;
+ }
+
+ // Record entry in per-thread trace buffer.
+ method_trace_buffer[*current_offset] = reinterpret_cast<uintptr_t>(method);
+ *current_offset += 1;
+ // TODO(mythria): We only need two bits to record the action. Consider merging
+ // it with the method entry to save space.
+ method_trace_buffer[*current_offset] = action;
+ *current_offset += 1;
+ if (UseThreadCpuClock()) {
+ method_trace_buffer[*current_offset] = thread_clock_diff;
+ *current_offset += 1;
+ }
+ if (UseWallClock()) {
+ method_trace_buffer[*current_offset] = wall_clock_diff;
+ *current_offset += 1;
+ }
+}
+
+void Trace::WriteToBuf(uint8_t* header,
+ size_t header_size,
+ std::string data,
+ size_t* current_index,
+ uint8_t* buffer,
+ size_t buffer_size) {
+ EnsureSpace(buffer, current_index, buffer_size, header_size);
+ memcpy(buffer + *current_index, header, header_size);
+ *current_index += header_size;
+
+ EnsureSpace(buffer, current_index, buffer_size, data.length());
+ if (data.length() < buffer_size) {
+ memcpy(buffer + *current_index, reinterpret_cast<const uint8_t*>(data.c_str()), data.length());
+ *current_index += data.length();
+ } else {
+ // The data is larger than buffer, so write directly to the file. EnsureSpace should have
+ // flushed any data in the buffer.
+ DCHECK_EQ(*current_index, 0U);
+ if (!trace_file_->WriteFully(reinterpret_cast<const uint8_t*>(data.c_str()), data.length())) {
+ PLOG(WARNING) << "Failed streaming a tracing event.";
+ }
+ }
+}
+
+void Trace::FlushStreamingBuffer(Thread* thread) {
+ // Take a streaming_lock_ to serialize writes across threads. We also need to allocate a unique
+ // method id for each method. We do that by maintaining a map from id to method for each newly
+ // seen method (see RegisterMethod). streaming_lock_ also is required to serialize these.
+ MutexLock mu(Thread::Current(), *streaming_lock_);
+ uintptr_t* method_trace_buffer = thread->GetMethodTraceBuffer();
+ // Create a temporary buffer to encode the trace events from the specified thread.
+ size_t buffer_size = kPerThreadBufSize;
+ size_t current_index = 0;
+ std::unique_ptr<uint8_t[]> buffer(new uint8_t[std::max(kMinBufSize, buffer_size)]);
+
+ size_t num_entries = *(thread->GetMethodTraceIndexPtr());
+ for (size_t entry_index = 0; entry_index < num_entries;) {
+ ArtMethod* method = reinterpret_cast<ArtMethod*>(method_trace_buffer[entry_index++]);
+ TraceAction action = DecodeTraceAction(method_trace_buffer[entry_index++]);
+ uint32_t thread_time = 0;
+ uint32_t wall_time = 0;
+ if (UseThreadCpuClock()) {
+ thread_time = method_trace_buffer[entry_index++];
+ }
+ if (UseWallClock()) {
+ wall_time = method_trace_buffer[entry_index++];
}
- old_offset = 0;
- new_offset = static_cast<int32_t>(src_size);
+ // If we haven't seen this method before record information about the method.
+ if (RegisterMethod(method)) {
+ // Write a special block with the name.
+ std::string method_line(GetMethodLine(method));
+ static constexpr size_t kMethodNameHeaderSize = 5;
+ uint8_t method_header[kMethodNameHeaderSize];
+ DCHECK_LT(kMethodNameHeaderSize, kPerThreadBufSize);
+ Append2LE(method_header, 0);
+ method_header[2] = kOpNewMethod;
+ Append2LE(method_header + 3, static_cast<uint16_t>(method_line.length()));
+ WriteToBuf(method_header,
+ kMethodNameHeaderSize,
+ method_line,
+ ¤t_index,
+ buffer.get(),
+ buffer_size);
+ }
+
+ const size_t record_size = GetRecordSize(clock_source_);
+ DCHECK_LT(record_size, kPerThreadBufSize);
+ EnsureSpace(buffer.get(), ¤t_index, buffer_size, record_size);
+ EncodeEventEntry(buffer.get() + current_index, thread, method, action, thread_time, wall_time);
+ current_index += record_size;
}
- cur_offset_.store(new_offset, std::memory_order_relaxed);
- // Fill in data.
- memcpy(buf_.get() + old_offset, src, src_size);
+
+ // Flush the contents of buffer to file.
+ if (!trace_file_->WriteFully(buffer.get(), current_index)) {
+ PLOG(WARNING) << "Failed streaming a tracing event.";
+ }
}
-void Trace::FlushBuf() {
- // Updates to cur_offset_ are done under the streaming_lock_ here as in streaming mode.
- int32_t offset = cur_offset_.load(std::memory_order_relaxed);
- if (!trace_file_->WriteFully(buf_.get(), offset)) {
- PLOG(WARNING) << "Failed flush the remaining data in streaming.";
- }
- cur_offset_.store(0, std::memory_order_relaxed);
-}
-
-void Trace::LogMethodTraceEvent(Thread* thread, ArtMethod* method,
- instrumentation::Instrumentation::InstrumentationEvent event,
- uint32_t thread_clock_diff, uint32_t wall_clock_diff) {
- // This method is called in both tracing modes (method and
- // sampling). In sampling mode, this method is only called by the
- // sampling thread. In method tracing mode, it can be called
- // concurrently.
-
- // Ensure we always use the non-obsolete version of the method so that entry/exit events have the
- // same pointer value.
- method = method->GetNonObsoleteMethod();
-
+void Trace::RecordMethodEvent(Thread* thread,
+ ArtMethod* method,
+ TraceAction action,
+ uint32_t thread_clock_diff,
+ uint32_t wall_clock_diff) {
// Advance cur_offset_ atomically.
int32_t new_offset;
int32_t old_offset = 0;
@@ -905,20 +1023,40 @@
// In the non-streaming case, we do a busy loop here trying to get
// an offset to write our record and advance cur_offset_ for the
// next use.
- if (trace_output_mode_ != TraceOutputMode::kStreaming) {
- // Although multiple threads can call this method concurrently,
- // the compare_exchange_weak here is still atomic (by definition).
- // A succeeding update is visible to other cores when they pass
- // through this point.
- old_offset = cur_offset_.load(std::memory_order_relaxed); // Speculative read
- do {
- new_offset = old_offset + GetRecordSize(clock_source_);
- if (static_cast<size_t>(new_offset) > buffer_size_) {
- overflow_ = true;
- return;
- }
- } while (!cur_offset_.compare_exchange_weak(old_offset, new_offset, std::memory_order_relaxed));
- }
+ // Although multiple threads can call this method concurrently,
+ // the compare_exchange_weak here is still atomic (by definition).
+ // A succeeding update is visible to other cores when they pass
+ // through this point.
+ old_offset = cur_offset_.load(std::memory_order_relaxed); // Speculative read
+ do {
+ new_offset = old_offset + GetRecordSize(clock_source_);
+ if (static_cast<size_t>(new_offset) > buffer_size_) {
+ overflow_ = true;
+ return;
+ }
+ } while (!cur_offset_.compare_exchange_weak(old_offset, new_offset, std::memory_order_relaxed));
+
+ // Write data into the tracing buffer (if not streaming) or into a
+ // small buffer on the stack (if streaming) which we'll put into the
+ // tracing buffer below.
+ //
+ // These writes to the tracing buffer are synchronised with the
+ // future reads that (only) occur under FinishTracing(). The callers
+ // of FinishTracing() acquire locks and (implicitly) synchronise
+ // the buffer memory.
+ uint8_t* ptr;
+ ptr = buf_.get() + old_offset;
+ EncodeEventEntry(ptr, thread, method, action, thread_clock_diff, wall_clock_diff);
+}
+
+void Trace::LogMethodTraceEvent(Thread* thread,
+ ArtMethod* method,
+ instrumentation::Instrumentation::InstrumentationEvent event,
+ uint32_t thread_clock_diff,
+ uint32_t wall_clock_diff) {
+ // This method is called in both tracing modes (method and sampling). In sampling mode, this
+ // method is only called by the sampling thread. In method tracing mode, it can be called
+ // concurrently.
TraceAction action = kTraceMethodEnter;
switch (event) {
@@ -935,25 +1073,25 @@
UNIMPLEMENTED(FATAL) << "Unexpected event: " << event;
}
- uint32_t method_value = EncodeTraceMethodAndAction(method, action);
+ // Ensure we always use the non-obsolete version of the method so that entry/exit events have the
+ // same pointer value.
+ method = method->GetNonObsoleteMethod();
- // Write data into the tracing buffer (if not streaming) or into a
- // small buffer on the stack (if streaming) which we'll put into the
- // tracing buffer below.
- //
- // These writes to the tracing buffer are synchronised with the
- // future reads that (only) occur under FinishTracing(). The callers
- // of FinishTracing() acquire locks and (implicitly) synchronise
- // the buffer memory.
- uint8_t* ptr;
- 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;
+ RecordStreamingMethodEvent(thread, method, action, thread_clock_diff, wall_clock_diff);
} else {
- ptr = buf_.get() + old_offset;
+ RecordMethodEvent(thread, method, action, thread_clock_diff, wall_clock_diff);
}
+}
+void Trace::EncodeEventEntry(uint8_t* ptr,
+ Thread* thread,
+ ArtMethod* method,
+ TraceAction action,
+ uint32_t thread_clock_diff,
+ uint32_t wall_clock_diff) {
+ static constexpr size_t kPacketSize = 14U; // The maximum size of data in a packet.
+ uint32_t method_value = EncodeTraceMethodAndAction(method, action);
Append2LE(ptr, thread->GetTid());
Append4LE(ptr + 2, method_value);
ptr += 6;
@@ -966,33 +1104,20 @@
Append4LE(ptr, wall_clock_diff);
}
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.
- if (RegisterMethod(method)) {
- // Write a special block with the name.
- std::string method_line(GetMethodLine(method));
- uint8_t buf2[5];
- Append2LE(buf2, 0);
- buf2[2] = kOpNewMethod;
- Append2LE(buf2 + 3, static_cast<uint16_t>(method_line.length()));
- WriteToBuf(buf2, sizeof(buf2));
- WriteToBuf(reinterpret_cast<const uint8_t*>(method_line.c_str()), method_line.length());
- }
- if (RegisterThread(thread)) {
- // It might be better to postpone this. Threads might not have received names...
- std::string thread_name;
- thread->GetThreadName(thread_name);
- uint8_t buf2[7];
- Append2LE(buf2, 0);
- buf2[2] = kOpNewThread;
- Append2LE(buf2 + 3, static_cast<uint16_t>(thread->GetTid()));
- Append2LE(buf2 + 5, static_cast<uint16_t>(thread_name.length()));
- WriteToBuf(buf2, sizeof(buf2));
- WriteToBuf(reinterpret_cast<const uint8_t*>(thread_name.c_str()), thread_name.length());
- }
- WriteToBuf(stack_buf, sizeof(stack_buf));
+void Trace::EnsureSpace(uint8_t* buffer,
+ size_t* current_index,
+ size_t buffer_size,
+ size_t required_size) {
+ if (*current_index + required_size < buffer_size) {
+ return;
}
+
+ if (!trace_file_->WriteFully(buffer, *current_index)) {
+ PLOG(WARNING) << "Failed streaming a tracing event.";
+ }
+ *current_index = 0;
}
void Trace::GetVisitedMethods(size_t buf_size,
diff --git a/runtime/trace.h b/runtime/trace.h
index 54799fe..dc3649f 100644
--- a/runtime/trace.h
+++ b/runtime/trace.h
@@ -49,9 +49,6 @@
using DexIndexBitSet = std::bitset<65536>;
-constexpr size_t kMaxThreadIdNumber = kIsTargetBuild ? 0x10000U : 0x400000U;
-using ThreadIDBitSet = std::bitset<kMaxThreadIdNumber>;
-
enum TracingMode {
kTracingInactive,
kMethodTracingActive, // Trace activity synchronous with method progress.
@@ -166,6 +163,10 @@
REQUIRES(!Locks::mutator_lock_, !Locks::thread_list_lock_, !Locks::trace_lock_);
static TracingMode GetMethodTracingMode() REQUIRES(!Locks::trace_lock_);
+ // Flush the per-thread buffer. This is called when the thread is about to detach.
+ static void FlushThreadBuffer(Thread* thread) REQUIRES_SHARED(Locks::mutator_lock_)
+ REQUIRES(!Locks::trace_lock_) NO_THREAD_SAFETY_ANALYSIS;
+
bool UseWallClock();
bool UseThreadCpuClock();
void MeasureClockOverhead();
@@ -274,13 +275,55 @@
bool RegisterThread(Thread* thread)
REQUIRES(streaming_lock_);
- // Copy a temporary buffer to the main buffer. Used for streaming. Exposed here for lock
- // annotation.
- void WriteToBuf(const uint8_t* src, size_t src_size)
- REQUIRES(streaming_lock_);
- // Flush the main buffer to file. Used for streaming. Exposed here for lock annotation.
- void FlushBuf()
- REQUIRES(streaming_lock_);
+ void RecordMethodEvent(Thread* thread,
+ ArtMethod* method,
+ TraceAction action,
+ uint32_t thread_clock_diff,
+ uint32_t wall_clock_diff) REQUIRES(!unique_methods_lock_);
+
+ // Encodes event in non-streaming mode. This assumes that there is enough space reserved to
+ // encode the entry.
+ void EncodeEventEntry(uint8_t* ptr,
+ Thread* thread,
+ ArtMethod* method,
+ TraceAction action,
+ uint32_t thread_clock_diff,
+ uint32_t wall_clock_diff) REQUIRES(!unique_methods_lock_);
+
+ // These methods are used to encode events in streaming mode.
+
+ // This records the method event in the per-thread buffer if there is sufficient space for the
+ // entire record. If the buffer is full then it just flushes the buffer and then records the
+ // entry.
+ void RecordStreamingMethodEvent(Thread* thread,
+ ArtMethod* method,
+ TraceAction action,
+ uint32_t thread_clock_diff,
+ uint32_t wall_clock_diff) REQUIRES_SHARED(Locks::mutator_lock_)
+ REQUIRES(!unique_methods_lock_) REQUIRES(!streaming_lock_);
+ // This encodes all the events in the per-thread trace buffer and writes it to the trace file.
+ // This acquires streaming lock to prevent any other threads writing concurrently. It is required
+ // to serialize these since each method is encoded with a unique id which is assigned when the
+ // method is seen for the first time in the recoreded events. So we need to serialize these
+ // flushes across threads.
+ void FlushStreamingBuffer(Thread* thread) REQUIRES_SHARED(Locks::mutator_lock_)
+ REQUIRES(!unique_methods_lock_) REQUIRES(!streaming_lock_);
+ // Ensures there is sufficient space in the buffer to record the requested_size. If there is not
+ // enough sufficient space the current contents of the buffer are written to the file and
+ // current_index is reset to 0. This doesn't check if buffer_size is big enough to hold the
+ // requested size.
+ void EnsureSpace(uint8_t* buffer,
+ size_t* current_index,
+ size_t buffer_size,
+ size_t required_size);
+ // Writes header followed by data to the buffer at the current_index. This also updates the
+ // current_index to point to the next entry.
+ void WriteToBuf(uint8_t* header,
+ size_t header_size,
+ std::string data,
+ size_t* current_index,
+ uint8_t* buffer,
+ size_t buffer_size);
uint32_t EncodeTraceMethod(ArtMethod* method) REQUIRES(!unique_methods_lock_);
uint32_t EncodeTraceMethodAndAction(ArtMethod* method, TraceAction action)
@@ -368,7 +411,6 @@
// Streaming mode data.
Mutex* streaming_lock_;
std::map<const DexFile*, DexIndexBitSet*> seen_methods_ GUARDED_BY(streaming_lock_);
- std::unique_ptr<ThreadIDBitSet> seen_threads_ GUARDED_BY(streaming_lock_);
// Bijective map from ArtMethod* to index.
// Map from ArtMethod* to index in unique_methods_;
diff --git a/test/2246-trace-stream/Android.bp b/test/2246-trace-stream/Android.bp
new file mode 100644
index 0000000..bef9deb
--- /dev/null
+++ b/test/2246-trace-stream/Android.bp
@@ -0,0 +1,40 @@
+// Generated by `regen-test-files`. Do not edit manually.
+
+// Build rules for ART run-test `2246-trace-stream`.
+
+package {
+ // See: http://go/android-license-faq
+ // A large-scale-change added 'default_applicable_licenses' to import
+ // all of the 'license_kinds' from "art_license"
+ // to get the below license kinds:
+ // SPDX-license-identifier-Apache-2.0
+ default_applicable_licenses: ["art_license"],
+}
+
+// Test's Dex code.
+java_test {
+ name: "art-run-test-2246-trace-stream",
+ defaults: ["art-run-test-defaults"],
+ test_config_template: ":art-run-test-target-no-test-suite-tag-template",
+ srcs: ["src/**/*.java"],
+ data: [
+ ":art-run-test-2246-trace-stream-expected-stdout",
+ ":art-run-test-2246-trace-stream-expected-stderr",
+ ],
+}
+
+// Test's expected standard output.
+genrule {
+ name: "art-run-test-2246-trace-stream-expected-stdout",
+ out: ["art-run-test-2246-trace-stream-expected-stdout.txt"],
+ srcs: ["expected-stdout.txt"],
+ cmd: "cp -f $(in) $(out)",
+}
+
+// Test's expected standard error.
+genrule {
+ name: "art-run-test-2246-trace-stream-expected-stderr",
+ out: ["art-run-test-2246-trace-stream-expected-stderr.txt"],
+ srcs: ["expected-stderr.txt"],
+ cmd: "cp -f $(in) $(out)",
+}
diff --git a/test/2246-trace-stream/expected-stderr.txt b/test/2246-trace-stream/expected-stderr.txt
new file mode 100644
index 0000000..e69de29
--- /dev/null
+++ b/test/2246-trace-stream/expected-stderr.txt
diff --git a/test/2246-trace-stream/expected-stdout.txt b/test/2246-trace-stream/expected-stdout.txt
new file mode 100644
index 0000000..0ee77f6
--- /dev/null
+++ b/test/2246-trace-stream/expected-stdout.txt
@@ -0,0 +1,72 @@
+.>> TestThread2246 java.lang.Thread run ()V Thread.java
+..>> TestThread2246 Main$$ExternalSyntheticLambda0 run ()V D8$$SyntheticClass
+...>> TestThread2246 Main lambda$main$0 ()V Main.java
+....>> TestThread2246 Main <init> ()V Main.java
+.....>> TestThread2246 java.lang.Object <init> ()V Object.java
+.....<< TestThread2246 java.lang.Object <init> ()V Object.java
+....<< TestThread2246 Main <init> ()V Main.java
+....>> TestThread2246 Main doSomeWork ()V Main.java
+.....>> TestThread2246 Main callOuterFunction ()V Main.java
+......>> TestThread2246 Main callLeafFunction ()V Main.java
+......<< TestThread2246 Main callLeafFunction ()V Main.java
+.....<< TestThread2246 Main callOuterFunction ()V Main.java
+.....>> TestThread2246 Main callLeafFunction ()V Main.java
+.....<< TestThread2246 Main callLeafFunction ()V Main.java
+....<< TestThread2246 Main doSomeWork ()V Main.java
+...<< TestThread2246 Main lambda$main$0 ()V Main.java
+..<< TestThread2246 Main$$ExternalSyntheticLambda0 run ()V D8$$SyntheticClass
+.<< TestThread2246 java.lang.Thread run ()V Thread.java
+.>> main Main main ([Ljava/lang/String;)V Main.java
+..>> main Main$VMDebug startMethodTracing (Ljava/lang/String;Ljava/io/FileDescriptor;IIZIZ)V Main.java
+...>> main java.lang.reflect.Method invoke (Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object; Method.java
+....>> main dalvik.system.VMDebug startMethodTracing (Ljava/lang/String;Ljava/io/FileDescriptor;IIZIZ)V VMDebug.java
+.....>> main dalvik.system.VMDebug startMethodTracingFd (Ljava/lang/String;IIIZIZ)V VMDebug.java
+.....<< main dalvik.system.VMDebug startMethodTracingFd (Ljava/lang/String;IIIZIZ)V VMDebug.java
+....<< main dalvik.system.VMDebug startMethodTracing (Ljava/lang/String;Ljava/io/FileDescriptor;IIZIZ)V VMDebug.java
+...<< main java.lang.reflect.Method invoke (Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object; Method.java
+..<< main Main$VMDebug startMethodTracing (Ljava/lang/String;Ljava/io/FileDescriptor;IIZIZ)V Main.java
+..>> main java.lang.Thread start ()V Thread.java
+...>> main java.lang.ThreadGroup add (Ljava/lang/Thread;)V ThreadGroup.java
+...<< main java.lang.ThreadGroup add (Ljava/lang/Thread;)V ThreadGroup.java
+...>> main java.lang.Thread nativeCreate (Ljava/lang/Thread;JZ)V Thread.java
+...<< main java.lang.Thread nativeCreate (Ljava/lang/Thread;JZ)V Thread.java
+..<< main java.lang.Thread start ()V Thread.java
+..>> main java.lang.Thread join ()V Thread.java
+...>> main java.lang.Thread join (J)V Thread.java
+....>> main java.lang.System currentTimeMillis ()J System.java
+....<< main java.lang.System currentTimeMillis ()J System.java
+....>> main java.lang.Thread isAlive ()Z Thread.java
+....<< main java.lang.Thread isAlive ()Z Thread.java
+....>> main java.lang.Object wait (J)V Object.java
+.....>> main java.lang.Object wait (JI)V Object.java
+.....<< main java.lang.Object wait (JI)V Object.java
+....<< main java.lang.Object wait (J)V Object.java
+....>> main java.lang.Thread isAlive ()Z Thread.java
+....<< main java.lang.Thread isAlive ()Z Thread.java
+...<< main java.lang.Thread join (J)V Thread.java
+..<< main java.lang.Thread join ()V Thread.java
+..>> main Main doSomeWork ()V Main.java
+...>> main Main callOuterFunction ()V Main.java
+....>> main Main callLeafFunction ()V Main.java
+....<< main Main callLeafFunction ()V Main.java
+...<< main Main callOuterFunction ()V Main.java
+...>> main Main callLeafFunction ()V Main.java
+...<< main Main callLeafFunction ()V Main.java
+..<< main Main doSomeWork ()V Main.java
+..>> main Main doSomeWorkThrow ()V Main.java
+...>> main Main callThrowFunction ()V Main.java
+....>> main java.lang.Exception <init> (Ljava/lang/String;)V Exception.java
+.....>> main java.lang.Throwable <init> (Ljava/lang/String;)V Throwable.java
+......>> main java.lang.Object <init> ()V Object.java
+......<< main java.lang.Object <init> ()V Object.java
+......>> main java.util.Collections emptyList ()Ljava/util/List; Collections.java
+......<< main java.util.Collections emptyList ()Ljava/util/List; Collections.java
+......>> main java.lang.Throwable fillInStackTrace ()Ljava/lang/Throwable; Throwable.java
+.......>> main java.lang.Throwable nativeFillInStackTrace ()Ljava/lang/Object; Throwable.java
+.......<< main java.lang.Throwable nativeFillInStackTrace ()Ljava/lang/Object; Throwable.java
+......<< main java.lang.Throwable fillInStackTrace ()Ljava/lang/Throwable; Throwable.java
+.....<< main java.lang.Throwable <init> (Ljava/lang/String;)V Throwable.java
+....<< main java.lang.Exception <init> (Ljava/lang/String;)V Exception.java
+...<<E main Main callThrowFunction ()V Main.java
+..<< main Main doSomeWorkThrow ()V Main.java
+..>> main Main$VMDebug stopMethodTracing ()V Main.java
diff --git a/test/2246-trace-stream/info.txt b/test/2246-trace-stream/info.txt
new file mode 100644
index 0000000..fa93a97
--- /dev/null
+++ b/test/2246-trace-stream/info.txt
@@ -0,0 +1,2 @@
+Tests streaming method tracing. It verifies the format of the generated file is
+as expected.
diff --git a/test/2246-trace-stream/run.py b/test/2246-trace-stream/run.py
new file mode 100644
index 0000000..6881d71
--- /dev/null
+++ b/test/2246-trace-stream/run.py
@@ -0,0 +1,22 @@
+#!/bin/bash
+#
+# Copyright (C) 2017 The Android Open Source Project
+#
+# Licensed under the Apache License, Version 2.0 (the "License");
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+# http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an "AS IS" BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+
+def run(ctx, args):
+ # The expected output is different in debuggable and non debuggable. Just
+ # enable debuggable for now.
+ # TODO(mythria): Also add tests for non-debuggable mode.
+ ctx.default_run(args, Xcompiler_option=["--debuggable"])
diff --git a/test/2246-trace-stream/src/Main.java b/test/2246-trace-stream/src/Main.java
new file mode 100644
index 0000000..39f3216
--- /dev/null
+++ b/test/2246-trace-stream/src/Main.java
@@ -0,0 +1,160 @@
+/*
+ * Copyright (C) 2022 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+import java.io.File;
+import java.io.FileDescriptor;
+import java.io.FileOutputStream;
+import java.io.IOException;
+import java.lang.reflect.Method;
+
+public class Main {
+ private static final String TEMP_FILE_NAME_PREFIX = "test";
+ private static final String TEMP_FILE_NAME_SUFFIX = ".trace";
+ private static File file;
+
+ public static void main(String[] args) throws Exception {
+ String name = System.getProperty("java.vm.name");
+ if (!"Dalvik".equals(name)) {
+ System.out.println("This test is not supported on " + name);
+ return;
+ }
+ file = createTempFile();
+ FileOutputStream out_file = new FileOutputStream(file);
+ Main m = new Main();
+ Thread t = new Thread(() -> {
+ Main m1 = new Main();
+ m1.doSomeWork();
+ }, "TestThread2246");
+ try {
+ if (VMDebug.getMethodTracingMode() != 0) {
+ VMDebug.stopMethodTracing();
+ }
+
+ VMDebug.startMethodTracing(file.getPath(), out_file.getFD(), 0, 0, false, 0, true);
+ t.start();
+ t.join();
+ m.doSomeWork();
+ m.doSomeWorkThrow();
+ VMDebug.stopMethodTracing();
+ out_file.close();
+ m.CheckTraceFileFormat(file);
+ } finally {
+ if (out_file != null) {
+ out_file.close();
+ }
+ }
+ }
+
+ private void CheckTraceFileFormat(File trace_file) throws Exception {
+ StreamTraceParser parser = new StreamTraceParser(trace_file);
+ parser.validateTraceHeader(StreamTraceParser.TRACE_VERSION_DUAL_CLOCK);
+ boolean has_entries = true;
+ boolean seen_stop_tracing_method = false;
+ while (has_entries) {
+ int header_type = parser.GetEntryHeader();
+ switch (header_type) {
+ case 1:
+ parser.ProcessMethodInfoEntry();
+ break;
+ case 2:
+ parser.ProcessThreadInfoEntry();
+ break;
+ case 3:
+ // TODO(mythria): Add test to also check format of trace summary.
+ has_entries = false;
+ break;
+ default:
+ String event_string = parser.ProcessEventEntry(header_type);
+ // Ignore events after method tracing was stopped. The code that is executed
+ // later could be non-deterministic.
+ if (!seen_stop_tracing_method) {
+ System.out.println(event_string);
+ }
+ if (event_string.contains("Main$VMDebug stopMethodTracing")) {
+ seen_stop_tracing_method = true;
+ }
+ }
+ }
+ parser.closeFile();
+ }
+
+ private static File createTempFile() throws Exception {
+ try {
+ return File.createTempFile(TEMP_FILE_NAME_PREFIX, TEMP_FILE_NAME_SUFFIX);
+ } catch (IOException e) {
+ System.setProperty("java.io.tmpdir", "/data/local/tmp");
+ try {
+ return File.createTempFile(TEMP_FILE_NAME_PREFIX, TEMP_FILE_NAME_SUFFIX);
+ } catch (IOException e2) {
+ System.setProperty("java.io.tmpdir", "/sdcard");
+ return File.createTempFile(TEMP_FILE_NAME_PREFIX, TEMP_FILE_NAME_SUFFIX);
+ }
+ }
+ }
+
+ public void callOuterFunction() {
+ callLeafFunction();
+ }
+
+ public void callLeafFunction() {}
+
+ public void doSomeWork() {
+ callOuterFunction();
+ callLeafFunction();
+ }
+
+ public void callThrowFunction() throws Exception {
+ throw new Exception("test");
+ }
+
+ public void doSomeWorkThrow() {
+ try {
+ callThrowFunction();
+ } catch (Exception e) {
+ }
+ }
+
+ private static class VMDebug {
+ private static final Method startMethodTracingMethod;
+ private static final Method stopMethodTracingMethod;
+ private static final Method getMethodTracingModeMethod;
+ static {
+ try {
+ Class<?> c = Class.forName("dalvik.system.VMDebug");
+ startMethodTracingMethod = c.getDeclaredMethod("startMethodTracing", String.class,
+ FileDescriptor.class, Integer.TYPE, Integer.TYPE, Boolean.TYPE,
+ Integer.TYPE, Boolean.TYPE);
+ stopMethodTracingMethod = c.getDeclaredMethod("stopMethodTracing");
+ getMethodTracingModeMethod = c.getDeclaredMethod("getMethodTracingMode");
+ } catch (Exception e) {
+ throw new RuntimeException(e);
+ }
+ }
+
+ public static void startMethodTracing(String filename, FileDescriptor fd, int bufferSize,
+ int flags, boolean samplingEnabled, int intervalUs, boolean streaming)
+ throws Exception {
+ startMethodTracingMethod.invoke(
+ null, filename, fd, bufferSize, flags, samplingEnabled, intervalUs, streaming);
+ }
+ public static void stopMethodTracing() throws Exception {
+ stopMethodTracingMethod.invoke(null);
+ }
+ public static int getMethodTracingMode() throws Exception {
+ return (int) getMethodTracingModeMethod.invoke(null);
+ }
+ }
+}
diff --git a/test/2246-trace-stream/src/StreamTraceParser.java b/test/2246-trace-stream/src/StreamTraceParser.java
new file mode 100644
index 0000000..8995342
--- /dev/null
+++ b/test/2246-trace-stream/src/StreamTraceParser.java
@@ -0,0 +1,166 @@
+/*
+ * Copyright (C) 2022 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+import java.io.DataInputStream;
+import java.io.File;
+import java.io.FileInputStream;
+import java.io.IOException;
+import java.nio.charset.StandardCharsets;
+import java.util.HashMap;
+
+public class StreamTraceParser {
+ public static final int MAGIC_NUMBER = 0x574f4c53;
+ public static final int DUAL_CLOCK_VERSION = 3;
+ public static final int TRACE_VERSION_DUAL_CLOCK = 0xF3;
+
+ public StreamTraceParser(File file) throws IOException {
+ dataStream = new DataInputStream(new FileInputStream(file));
+ method_id_map = new HashMap<Integer, String>();
+ thread_id_map = new HashMap<Integer, String>();
+ }
+
+ public void closeFile() throws IOException {
+ dataStream.close();
+ }
+
+ public String readString(int num_bytes) throws IOException {
+ byte[] buffer = new byte[num_bytes];
+ dataStream.readFully(buffer);
+ return new String(buffer, StandardCharsets.UTF_8);
+ }
+
+ public int readNumber(int num_bytes) throws IOException {
+ int number = 0;
+ for (int i = 0; i < num_bytes; i++) {
+ number += dataStream.readUnsignedByte() << (i * 8);
+ }
+ return number;
+ }
+
+ public void validateTraceHeader(int expected_version) throws Exception {
+ // Read 4-byte magic_number
+ int magic_number = readNumber(4);
+ if (magic_number != MAGIC_NUMBER) {
+ throw new Exception("Magic number doesn't match. Expected "
+ + Integer.toHexString(MAGIC_NUMBER) + " Got "
+ + Integer.toHexString(magic_number));
+ }
+ // Read 2-byte version
+ int version = readNumber(2);
+ if (version != expected_version) {
+ throw new Exception(
+ "Unexpected version. Expected " + expected_version + " Got " + version);
+ }
+ trace_format_version = version & 0xF;
+ // Read 2-byte header_length length
+ int header_length = readNumber(2);
+ // Read 8-byte starting time - Ignore timestamps since they are not deterministic
+ dataStream.skipBytes(8);
+ // 4 byte magic_number + 2 byte version + 2 byte offset + 8 byte timestamp
+ int num_bytes_read = 16;
+ if (version >= DUAL_CLOCK_VERSION) {
+ // Read 2-byte record size.
+ // TODO(mythria): Check why this is needed. We can derive record_size from version. Not
+ // sure why this is needed.
+ record_size = readNumber(2);
+ num_bytes_read += 2;
+ }
+ // Skip any padding
+ if (header_length > num_bytes_read) {
+ dataStream.skipBytes(header_length - num_bytes_read);
+ }
+ }
+
+ public int GetEntryHeader() throws IOException {
+ // Read 2-byte thread-id. On host thread-ids can be greater than 16-bit.
+ int thread_id = readNumber(2);
+ if (thread_id != 0) {
+ return thread_id;
+ }
+ // Read 1-byte header type
+ return readNumber(1);
+ }
+
+ public void ProcessMethodInfoEntry() throws IOException {
+ // Read 2-byte method info size
+ int header_length = readNumber(2);
+ // Read header_size data.
+ String method_info = readString(header_length);
+ String[] tokens = method_info.split("\t", 2);
+ // Get method_id and record method_id -> method_name map.
+ int method_id = Integer.decode(tokens[0]);
+ String method_line = tokens[1].replace('\t', ' ');
+ method_line = method_line.substring(0, method_line.length() - 1);
+ method_id_map.put(method_id, method_line);
+ }
+
+ public void ProcessThreadInfoEntry() throws IOException {
+ // Read 2-byte thread id
+ int thread_id = readNumber(2);
+ // Read 2-byte thread info size
+ int header_length = readNumber(2);
+ // Read header_size data.
+ String thread_info = readString(header_length);
+ thread_id_map.put(thread_id, thread_info);
+ }
+
+ public String eventTypeToString(int event_type) {
+ String str = "";
+ for (int i = 0; i < nesting_level; i++) {
+ str += ".";
+ }
+ switch (event_type) {
+ case 0:
+ nesting_level++;
+ str += ".>>";
+ break;
+ case 1:
+ nesting_level--;
+ str += "<<";
+ break;
+ case 2:
+ nesting_level--;
+ str += "<<E";
+ break;
+ default:
+ str += "??";
+ }
+ return str;
+ }
+
+ public String ProcessEventEntry(int thread_id) throws IOException {
+ // Read 4-byte method value
+ int method_and_event = readNumber(4);
+ int method_id = method_and_event & ~0x3;
+ int event_type = method_and_event & 0x3;
+
+ String str = eventTypeToString(event_type) + " " + thread_id_map.get(thread_id) + " "
+ + method_id_map.get(method_id);
+ // Depending on the version skip either one or two timestamps.
+ // TODO(mythria): Probably add a check that time stamps are always greater than initial
+ // timestamp.
+ int num_bytes_timestamp = (trace_format_version == 2) ? 4 : 8;
+ dataStream.skipBytes(num_bytes_timestamp);
+ return str;
+ }
+
+ DataInputStream dataStream;
+ HashMap<Integer, String> method_id_map;
+ HashMap<Integer, String> thread_id_map;
+ int record_size = 0;
+ int trace_format_version = 0;
+ int nesting_level = 0;
+}