blob: b5108443b07803518a0c9bb7ae0b1a6b8ea09a92 [file] [log] [blame]
Elliott Hughes2faa5f12012-01-30 14:42:07 -08001/*
2 * Copyright (C) 2011 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
jeffhaoe343b762011-12-05 16:36:44 -080016
17#include "trace.h"
18
jeffhaoa9ef3fd2011-12-13 18:33:43 -080019#include <sys/uio.h>
20
Ian Rogerscf7f1912014-10-22 22:06:39 -070021#define ATRACE_TAG ATRACE_TAG_DALVIK
22#include "cutils/trace.h"
23
Jeff Hao0abc72e2013-08-13 13:45:14 -070024#include "base/stl_util.h"
Elliott Hughes76160052012-12-12 16:31:20 -080025#include "base/unix_file/fd_file.h"
jeffhaoe343b762011-12-05 16:36:44 -080026#include "class_linker.h"
Ian Rogers62d6c772013-02-27 08:32:07 -080027#include "common_throws.h"
jeffhaoa9ef3fd2011-12-13 18:33:43 -080028#include "debugger.h"
Ian Rogers4f6ad8a2013-03-18 15:27:28 -070029#include "dex_file-inl.h"
jeffhao725a9572012-11-13 18:20:12 -080030#include "instrumentation.h"
Brian Carlstromea46f952013-07-30 01:26:50 -070031#include "mirror/art_method-inl.h"
Ian Rogers4f6ad8a2013-03-18 15:27:28 -070032#include "mirror/class-inl.h"
Ian Rogers2dd0e2c2013-01-24 12:42:14 -080033#include "mirror/dex_cache.h"
34#include "mirror/object_array-inl.h"
Ian Rogers4f6ad8a2013-03-18 15:27:28 -070035#include "mirror/object-inl.h"
jeffhaoa9ef3fd2011-12-13 18:33:43 -080036#include "os.h"
Ian Rogers00f7d0e2012-07-19 15:28:27 -070037#include "scoped_thread_state_change.h"
Jeff Hao0abc72e2013-08-13 13:45:14 -070038#include "ScopedLocalRef.h"
jeffhaoe343b762011-12-05 16:36:44 -080039#include "thread.h"
Ian Rogers57b86d42012-03-27 16:05:41 -070040#include "thread_list.h"
Ian Rogers166db042013-07-26 12:05:57 -070041#if !defined(ART_USE_PORTABLE_COMPILER)
42#include "entrypoints/quick/quick_entrypoints.h"
43#endif
jeffhao2692b572011-12-16 15:42:28 -080044
45namespace art {
46
Elliott Hughese119a362012-05-22 17:37:06 -070047// File format:
48// header
49// record 0
50// record 1
51// ...
52//
53// Header format:
54// u4 magic ('SLOW')
55// u2 version
56// u2 offset to data
57// u8 start date/time in usec
58// u2 record size in bytes (version >= 2 only)
59// ... padding to 32 bytes
60//
61// Record format v1:
62// u1 thread ID
63// u4 method ID | method action
64// u4 time delta since start, in usec
65//
66// Record format v2:
67// u2 thread ID
68// u4 method ID | method action
69// u4 time delta since start, in usec
70//
71// Record format v3:
72// u2 thread ID
73// u4 method ID | method action
74// u4 time delta since start, in usec
75// u4 wall time since start, in usec (when clock == "dual" only)
76//
77// 32 bits of microseconds is 70 minutes.
78//
79// All values are stored in little-endian order.
80
Ian Rogers62d6c772013-02-27 08:32:07 -080081enum TraceAction {
Brian Carlstrom7934ac22013-07-26 10:54:15 -070082 kTraceMethodEnter = 0x00, // method entry
83 kTraceMethodExit = 0x01, // method exit
84 kTraceUnroll = 0x02, // method exited by exception unrolling
Ian Rogers62d6c772013-02-27 08:32:07 -080085 // 0x03 currently unused
Brian Carlstrom7934ac22013-07-26 10:54:15 -070086 kTraceMethodActionMask = 0x03, // two bits
Ian Rogers62d6c772013-02-27 08:32:07 -080087};
88
Jeff Hao0abc72e2013-08-13 13:45:14 -070089class BuildStackTraceVisitor : public StackVisitor {
90 public:
91 explicit BuildStackTraceVisitor(Thread* thread) : StackVisitor(thread, NULL),
Jeff Hao5ce4b172013-08-16 16:27:18 -070092 method_trace_(Trace::AllocStackTrace()) {}
Jeff Hao0abc72e2013-08-13 13:45:14 -070093
Ian Rogersef7d42f2014-01-06 12:55:46 -080094 bool VisitFrame() SHARED_LOCKS_REQUIRED(Locks::mutator_lock_) {
Ian Rogerse2f77e72013-08-13 19:19:40 -070095 mirror::ArtMethod* m = GetMethod();
Jeff Hao0abc72e2013-08-13 13:45:14 -070096 // Ignore runtime frames (in particular callee save).
97 if (!m->IsRuntimeMethod()) {
98 method_trace_->push_back(m);
99 }
100 return true;
101 }
102
103 // Returns a stack trace where the topmost frame corresponds with the first element of the vector.
Ian Rogerse2f77e72013-08-13 19:19:40 -0700104 std::vector<mirror::ArtMethod*>* GetStackTrace() const {
Jeff Hao0abc72e2013-08-13 13:45:14 -0700105 return method_trace_;
106 }
107
108 private:
Ian Rogerse2f77e72013-08-13 19:19:40 -0700109 std::vector<mirror::ArtMethod*>* const method_trace_;
Jeff Hao0abc72e2013-08-13 13:45:14 -0700110};
111
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800112static const char kTraceTokenChar = '*';
113static const uint16_t kTraceHeaderLength = 32;
114static const uint32_t kTraceMagicValue = 0x574f4c53;
115static const uint16_t kTraceVersionSingleClock = 2;
116static const uint16_t kTraceVersionDualClock = 3;
Brian Carlstrom7934ac22013-07-26 10:54:15 -0700117static const uint16_t kTraceRecordSizeSingleClock = 10; // using v2
118static const uint16_t kTraceRecordSizeDualClock = 14; // using v3 with two timestamps
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800119
Ian Rogerse63db272014-07-15 15:36:11 -0700120TraceClockSource Trace::default_clock_source_ = kDefaultTraceClockSource;
Elliott Hughese119a362012-05-22 17:37:06 -0700121
Jeff Hao0abc72e2013-08-13 13:45:14 -0700122Trace* volatile Trace::the_trace_ = NULL;
Jeff Hao0abc72e2013-08-13 13:45:14 -0700123pthread_t Trace::sampling_pthread_ = 0U;
Ian Rogers700a4022014-05-19 16:49:03 -0700124std::unique_ptr<std::vector<mirror::ArtMethod*>> Trace::temp_stack_trace_;
Ian Rogers62d6c772013-02-27 08:32:07 -0800125
Brian Carlstromea46f952013-07-30 01:26:50 -0700126static mirror::ArtMethod* DecodeTraceMethodId(uint32_t tmid) {
127 return reinterpret_cast<mirror::ArtMethod*>(tmid & ~kTraceMethodActionMask);
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800128}
Elliott Hughese119a362012-05-22 17:37:06 -0700129
Ian Rogers62d6c772013-02-27 08:32:07 -0800130static TraceAction DecodeTraceAction(uint32_t tmid) {
131 return static_cast<TraceAction>(tmid & kTraceMethodActionMask);
132}
133
Ian Rogersef7d42f2014-01-06 12:55:46 -0800134static uint32_t EncodeTraceMethodAndAction(mirror::ArtMethod* method,
Ian Rogers62d6c772013-02-27 08:32:07 -0800135 TraceAction action) {
Ian Rogersef7d42f2014-01-06 12:55:46 -0800136 uint32_t tmid = PointerToLowMemUInt32(method) | action;
Ian Rogers62d6c772013-02-27 08:32:07 -0800137 DCHECK_EQ(method, DecodeTraceMethodId(tmid));
138 return tmid;
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800139}
140
Jeff Hao5ce4b172013-08-16 16:27:18 -0700141std::vector<mirror::ArtMethod*>* Trace::AllocStackTrace() {
142 if (temp_stack_trace_.get() != NULL) {
143 return temp_stack_trace_.release();
144 } else {
145 return new std::vector<mirror::ArtMethod*>();
146 }
147}
148
149void Trace::FreeStackTrace(std::vector<mirror::ArtMethod*>* stack_trace) {
150 stack_trace->clear();
151 temp_stack_trace_.reset(stack_trace);
152}
153
Ian Rogerse63db272014-07-15 15:36:11 -0700154void Trace::SetDefaultClockSource(TraceClockSource clock_source) {
Ian Rogers62d6c772013-02-27 08:32:07 -0800155#if defined(HAVE_POSIX_CLOCKS)
156 default_clock_source_ = clock_source;
157#else
Ian Rogerse63db272014-07-15 15:36:11 -0700158 if (clock_source != kTraceClockSourceWall) {
Jeff Hao5ce4b172013-08-16 16:27:18 -0700159 LOG(WARNING) << "Ignoring tracing request to use CPU time.";
Ian Rogers62d6c772013-02-27 08:32:07 -0800160 }
161#endif
162}
163
Ian Rogerse63db272014-07-15 15:36:11 -0700164static uint16_t GetTraceVersion(TraceClockSource clock_source) {
165 return (clock_source == kTraceClockSourceDual) ? kTraceVersionDualClock
Ian Rogers62d6c772013-02-27 08:32:07 -0800166 : kTraceVersionSingleClock;
167}
168
Ian Rogerse63db272014-07-15 15:36:11 -0700169static uint16_t GetRecordSize(TraceClockSource clock_source) {
170 return (clock_source == kTraceClockSourceDual) ? kTraceRecordSizeDualClock
Ian Rogers62d6c772013-02-27 08:32:07 -0800171 : kTraceRecordSizeSingleClock;
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800172}
173
Elliott Hughese119a362012-05-22 17:37:06 -0700174bool Trace::UseThreadCpuClock() {
Ian Rogerse63db272014-07-15 15:36:11 -0700175 return (clock_source_ == kTraceClockSourceThreadCpu) ||
176 (clock_source_ == kTraceClockSourceDual);
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800177}
178
Elliott Hughese119a362012-05-22 17:37:06 -0700179bool Trace::UseWallClock() {
Ian Rogerse63db272014-07-15 15:36:11 -0700180 return (clock_source_ == kTraceClockSourceWall) ||
181 (clock_source_ == kTraceClockSourceDual);
Elliott Hughese119a362012-05-22 17:37:06 -0700182}
183
Jeff Haoc5d824a2014-07-28 18:35:38 -0700184void Trace::MeasureClockOverhead() {
185 if (UseThreadCpuClock()) {
Jeff Hao57dac6e2013-08-15 16:36:24 -0700186 Thread::Current()->GetCpuMicroTime();
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800187 }
Jeff Haoc5d824a2014-07-28 18:35:38 -0700188 if (UseWallClock()) {
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800189 MicroTime();
190 }
191}
192
Jeff Hao5ce4b172013-08-16 16:27:18 -0700193// Compute an average time taken to measure clocks.
Jeff Haoc5d824a2014-07-28 18:35:38 -0700194uint32_t Trace::GetClockOverheadNanoSeconds() {
Jeff Hao57dac6e2013-08-15 16:36:24 -0700195 Thread* self = Thread::Current();
196 uint64_t start = self->GetCpuMicroTime();
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800197
198 for (int i = 4000; i > 0; i--) {
Jeff Haoc5d824a2014-07-28 18:35:38 -0700199 MeasureClockOverhead();
200 MeasureClockOverhead();
201 MeasureClockOverhead();
202 MeasureClockOverhead();
203 MeasureClockOverhead();
204 MeasureClockOverhead();
205 MeasureClockOverhead();
206 MeasureClockOverhead();
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800207 }
208
Jeff Hao5ce4b172013-08-16 16:27:18 -0700209 uint64_t elapsed_us = self->GetCpuMicroTime() - start;
210 return static_cast<uint32_t>(elapsed_us / 32);
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800211}
212
Elliott Hughesffb465f2012-03-01 18:46:05 -0800213// TODO: put this somewhere with the big-endian equivalent used by JDWP.
214static void Append2LE(uint8_t* buf, uint16_t val) {
Jeff Hao5ce4b172013-08-16 16:27:18 -0700215 *buf++ = static_cast<uint8_t>(val);
216 *buf++ = static_cast<uint8_t>(val >> 8);
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800217}
218
Elliott Hughesffb465f2012-03-01 18:46:05 -0800219// TODO: put this somewhere with the big-endian equivalent used by JDWP.
220static void Append4LE(uint8_t* buf, uint32_t val) {
Jeff Hao5ce4b172013-08-16 16:27:18 -0700221 *buf++ = static_cast<uint8_t>(val);
222 *buf++ = static_cast<uint8_t>(val >> 8);
223 *buf++ = static_cast<uint8_t>(val >> 16);
224 *buf++ = static_cast<uint8_t>(val >> 24);
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800225}
226
Elliott Hughesffb465f2012-03-01 18:46:05 -0800227// TODO: put this somewhere with the big-endian equivalent used by JDWP.
228static void Append8LE(uint8_t* buf, uint64_t val) {
Jeff Hao5ce4b172013-08-16 16:27:18 -0700229 *buf++ = static_cast<uint8_t>(val);
230 *buf++ = static_cast<uint8_t>(val >> 8);
231 *buf++ = static_cast<uint8_t>(val >> 16);
232 *buf++ = static_cast<uint8_t>(val >> 24);
233 *buf++ = static_cast<uint8_t>(val >> 32);
234 *buf++ = static_cast<uint8_t>(val >> 40);
235 *buf++ = static_cast<uint8_t>(val >> 48);
236 *buf++ = static_cast<uint8_t>(val >> 56);
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800237}
238
Jeff Hao0abc72e2013-08-13 13:45:14 -0700239static void GetSample(Thread* thread, void* arg) SHARED_LOCKS_REQUIRED(Locks::mutator_lock_) {
240 BuildStackTraceVisitor build_trace_visitor(thread);
241 build_trace_visitor.WalkStack();
Ian Rogerse2f77e72013-08-13 19:19:40 -0700242 std::vector<mirror::ArtMethod*>* stack_trace = build_trace_visitor.GetStackTrace();
Jeff Hao0abc72e2013-08-13 13:45:14 -0700243 Trace* the_trace = reinterpret_cast<Trace*>(arg);
244 the_trace->CompareAndUpdateStackTrace(thread, stack_trace);
245}
246
Ian Rogers6a3c1fc2014-10-31 00:33:20 -0700247static void ClearThreadStackTraceAndClockBase(Thread* thread ATTRIBUTE_UNUSED,
248 void* arg ATTRIBUTE_UNUSED) {
Jeff Hao5ce4b172013-08-16 16:27:18 -0700249 thread->SetTraceClockBase(0);
250 std::vector<mirror::ArtMethod*>* stack_trace = thread->GetStackTraceSample();
251 thread->SetStackTraceSample(NULL);
252 delete stack_trace;
253}
254
Jeff Hao0abc72e2013-08-13 13:45:14 -0700255void Trace::CompareAndUpdateStackTrace(Thread* thread,
Ian Rogerse2f77e72013-08-13 19:19:40 -0700256 std::vector<mirror::ArtMethod*>* stack_trace) {
Jeff Hao0abc72e2013-08-13 13:45:14 -0700257 CHECK_EQ(pthread_self(), sampling_pthread_);
Jeff Hao5ce4b172013-08-16 16:27:18 -0700258 std::vector<mirror::ArtMethod*>* old_stack_trace = thread->GetStackTraceSample();
259 // Update the thread's stack trace sample.
260 thread->SetStackTraceSample(stack_trace);
Jeff Haoc1ff4b72013-08-19 11:33:10 -0700261 // Read timer clocks to use for all events in this trace.
262 uint32_t thread_clock_diff = 0;
263 uint32_t wall_clock_diff = 0;
264 ReadClocks(thread, &thread_clock_diff, &wall_clock_diff);
Jeff Hao5ce4b172013-08-16 16:27:18 -0700265 if (old_stack_trace == NULL) {
266 // If there's no previous stack trace sample for this thread, log an entry event for all
Jeff Hao0abc72e2013-08-13 13:45:14 -0700267 // methods in the trace.
Ian Rogerse2f77e72013-08-13 19:19:40 -0700268 for (std::vector<mirror::ArtMethod*>::reverse_iterator rit = stack_trace->rbegin();
Jeff Hao0abc72e2013-08-13 13:45:14 -0700269 rit != stack_trace->rend(); ++rit) {
Jeff Haoc1ff4b72013-08-19 11:33:10 -0700270 LogMethodTraceEvent(thread, *rit, instrumentation::Instrumentation::kMethodEntered,
271 thread_clock_diff, wall_clock_diff);
Jeff Hao0abc72e2013-08-13 13:45:14 -0700272 }
273 } else {
274 // If there's a previous stack trace for this thread, diff the traces and emit entry and exit
275 // events accordingly.
Ian Rogerse2f77e72013-08-13 19:19:40 -0700276 std::vector<mirror::ArtMethod*>::reverse_iterator old_rit = old_stack_trace->rbegin();
277 std::vector<mirror::ArtMethod*>::reverse_iterator rit = stack_trace->rbegin();
Jeff Hao0abc72e2013-08-13 13:45:14 -0700278 // Iterate bottom-up over both traces until there's a difference between them.
279 while (old_rit != old_stack_trace->rend() && rit != stack_trace->rend() && *old_rit == *rit) {
280 old_rit++;
281 rit++;
282 }
283 // Iterate top-down over the old trace until the point where they differ, emitting exit events.
Ian Rogerse2f77e72013-08-13 19:19:40 -0700284 for (std::vector<mirror::ArtMethod*>::iterator old_it = old_stack_trace->begin();
Jeff Hao0abc72e2013-08-13 13:45:14 -0700285 old_it != old_rit.base(); ++old_it) {
Jeff Haoc1ff4b72013-08-19 11:33:10 -0700286 LogMethodTraceEvent(thread, *old_it, instrumentation::Instrumentation::kMethodExited,
287 thread_clock_diff, wall_clock_diff);
Jeff Hao0abc72e2013-08-13 13:45:14 -0700288 }
289 // Iterate bottom-up over the new trace from the point where they differ, emitting entry events.
290 for (; rit != stack_trace->rend(); ++rit) {
Jeff Haoc1ff4b72013-08-19 11:33:10 -0700291 LogMethodTraceEvent(thread, *rit, instrumentation::Instrumentation::kMethodEntered,
292 thread_clock_diff, wall_clock_diff);
Jeff Hao0abc72e2013-08-13 13:45:14 -0700293 }
Jeff Hao5ce4b172013-08-16 16:27:18 -0700294 FreeStackTrace(old_stack_trace);
Jeff Hao0abc72e2013-08-13 13:45:14 -0700295 }
296}
297
298void* Trace::RunSamplingThread(void* arg) {
299 Runtime* runtime = Runtime::Current();
Ian Rogersef7d42f2014-01-06 12:55:46 -0800300 intptr_t interval_us = reinterpret_cast<intptr_t>(arg);
Jeff Hao4044bda2014-01-06 15:50:45 -0800301 CHECK_GE(interval_us, 0);
Jeff Hao0abc72e2013-08-13 13:45:14 -0700302 CHECK(runtime->AttachCurrentThread("Sampling Profiler", true, runtime->GetSystemThreadGroup(),
303 !runtime->IsCompiler()));
304
305 while (true) {
Jeff Hao23009dc2013-08-22 15:36:42 -0700306 usleep(interval_us);
Jeff Hao5ce4b172013-08-16 16:27:18 -0700307 ATRACE_BEGIN("Profile sampling");
Jeff Hao0abc72e2013-08-13 13:45:14 -0700308 Thread* self = Thread::Current();
309 Trace* the_trace;
310 {
311 MutexLock mu(self, *Locks::trace_lock_);
312 the_trace = the_trace_;
313 if (the_trace == NULL) {
314 break;
315 }
316 }
317
318 runtime->GetThreadList()->SuspendAll();
319 {
320 MutexLock mu(self, *Locks::thread_list_lock_);
321 runtime->GetThreadList()->ForEach(GetSample, the_trace);
322 }
323 runtime->GetThreadList()->ResumeAll();
Jeff Hao5ce4b172013-08-16 16:27:18 -0700324 ATRACE_END();
Jeff Hao0abc72e2013-08-13 13:45:14 -0700325 }
326
327 runtime->DetachCurrentThread();
328 return NULL;
329}
330
Ian Rogers62d6c772013-02-27 08:32:07 -0800331void Trace::Start(const char* trace_filename, int trace_fd, int buffer_size, int flags,
Jeff Hao23009dc2013-08-22 15:36:42 -0700332 bool direct_to_ddms, bool sampling_enabled, int interval_us) {
Ian Rogers62d6c772013-02-27 08:32:07 -0800333 Thread* self = Thread::Current();
334 {
335 MutexLock mu(self, *Locks::trace_lock_);
336 if (the_trace_ != NULL) {
337 LOG(ERROR) << "Trace already in progress, ignoring this request";
338 return;
339 }
jeffhaoe343b762011-12-05 16:36:44 -0800340 }
Jeff Haod063d912014-09-08 09:38:18 -0700341
342 // Check interval if sampling is enabled
343 if (sampling_enabled && interval_us <= 0) {
344 LOG(ERROR) << "Invalid sampling interval: " << interval_us;
345 ScopedObjectAccess soa(self);
346 ThrowRuntimeException("Invalid sampling interval: %d", interval_us);
347 return;
348 }
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800349
jeffhao2692b572011-12-16 15:42:28 -0800350 // Open trace file if not going directly to ddms.
Ian Rogers700a4022014-05-19 16:49:03 -0700351 std::unique_ptr<File> trace_file;
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800352 if (!direct_to_ddms) {
353 if (trace_fd < 0) {
Brian Carlstrom7571e8b2013-08-12 17:04:14 -0700354 trace_file.reset(OS::CreateEmptyFile(trace_filename));
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800355 } else {
Ian Rogers62d6c772013-02-27 08:32:07 -0800356 trace_file.reset(new File(trace_fd, "tracefile"));
Elliott Hughes76160052012-12-12 16:31:20 -0800357 trace_file->DisableAutoClose();
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800358 }
Ian Rogers62d6c772013-02-27 08:32:07 -0800359 if (trace_file.get() == NULL) {
jeffhaob5e81852012-03-12 11:15:45 -0700360 PLOG(ERROR) << "Unable to open trace file '" << trace_filename << "'";
Ian Rogers62d6c772013-02-27 08:32:07 -0800361 ScopedObjectAccess soa(self);
362 ThrowRuntimeException("Unable to open trace file '%s'", trace_filename);
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800363 return;
364 }
365 }
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800366
Jeff Haod063d912014-09-08 09:38:18 -0700367 Runtime* runtime = Runtime::Current();
Mathieu Chartier9ef78b52014-09-25 17:03:12 -0700368
369 // Enable count of allocs if specified in the flags.
370 bool enable_stats = false;
371
Jeff Haod063d912014-09-08 09:38:18 -0700372 runtime->GetThreadList()->SuspendAll();
373
jeffhao2692b572011-12-16 15:42:28 -0800374 // Create Trace object.
Ian Rogers62d6c772013-02-27 08:32:07 -0800375 {
376 MutexLock mu(self, *Locks::trace_lock_);
Brian Carlstromdf629502013-07-17 22:39:56 -0700377 if (the_trace_ != NULL) {
Ian Rogers62d6c772013-02-27 08:32:07 -0800378 LOG(ERROR) << "Trace already in progress, ignoring this request";
379 } else {
Mathieu Chartier9ef78b52014-09-25 17:03:12 -0700380 enable_stats = (flags && kTraceCountAllocs) != 0;
Jeff Hao23009dc2013-08-22 15:36:42 -0700381 the_trace_ = new Trace(trace_file.release(), buffer_size, flags, sampling_enabled);
Jeff Hao23009dc2013-08-22 15:36:42 -0700382 if (sampling_enabled) {
383 CHECK_PTHREAD_CALL(pthread_create, (&sampling_pthread_, NULL, &RunSamplingThread,
384 reinterpret_cast<void*>(interval_us)),
385 "Sampling profiler thread");
Jeff Hao0abc72e2013-08-13 13:45:14 -0700386 } else {
387 runtime->GetInstrumentation()->AddListener(the_trace_,
388 instrumentation::Instrumentation::kMethodEntered |
389 instrumentation::Instrumentation::kMethodExited |
390 instrumentation::Instrumentation::kMethodUnwind);
Sebastien Hertz138dbfc2013-12-04 18:15:25 +0100391 runtime->GetInstrumentation()->EnableMethodTracing();
Jeff Hao0abc72e2013-08-13 13:45:14 -0700392 }
Ian Rogers62d6c772013-02-27 08:32:07 -0800393 }
jeffhao0791adc2012-04-04 11:14:32 -0700394 }
Jeff Haod063d912014-09-08 09:38:18 -0700395
Ian Rogers62d6c772013-02-27 08:32:07 -0800396 runtime->GetThreadList()->ResumeAll();
Mathieu Chartier9ef78b52014-09-25 17:03:12 -0700397
398 // Can't call this when holding the mutator lock.
399 if (enable_stats) {
400 runtime->SetStatsEnabled(true);
401 }
jeffhao2692b572011-12-16 15:42:28 -0800402}
403
404void Trace::Stop() {
Mathieu Chartier9ef78b52014-09-25 17:03:12 -0700405 bool stop_alloc_counting = false;
Ian Rogers62d6c772013-02-27 08:32:07 -0800406 Runtime* runtime = Runtime::Current();
407 runtime->GetThreadList()->SuspendAll();
408 Trace* the_trace = NULL;
Jeff Hao0abc72e2013-08-13 13:45:14 -0700409 pthread_t sampling_pthread = 0U;
Ian Rogers62d6c772013-02-27 08:32:07 -0800410 {
411 MutexLock mu(Thread::Current(), *Locks::trace_lock_);
412 if (the_trace_ == NULL) {
413 LOG(ERROR) << "Trace stop requested, but no trace currently running";
414 } else {
415 the_trace = the_trace_;
416 the_trace_ = NULL;
Jeff Hao0abc72e2013-08-13 13:45:14 -0700417 sampling_pthread = sampling_pthread_;
Ian Rogers62d6c772013-02-27 08:32:07 -0800418 }
jeffhao2692b572011-12-16 15:42:28 -0800419 }
Ian Rogers62d6c772013-02-27 08:32:07 -0800420 if (the_trace != NULL) {
Mathieu Chartier9ef78b52014-09-25 17:03:12 -0700421 stop_alloc_counting = (the_trace->flags_ & kTraceCountAllocs) != 0;
Ian Rogers62d6c772013-02-27 08:32:07 -0800422 the_trace->FinishTracing();
Jeff Hao0abc72e2013-08-13 13:45:14 -0700423
Jeff Hao23009dc2013-08-22 15:36:42 -0700424 if (the_trace->sampling_enabled_) {
Jeff Hao5ce4b172013-08-16 16:27:18 -0700425 MutexLock mu(Thread::Current(), *Locks::thread_list_lock_);
426 runtime->GetThreadList()->ForEach(ClearThreadStackTraceAndClockBase, NULL);
427 } else {
Sebastien Hertz138dbfc2013-12-04 18:15:25 +0100428 runtime->GetInstrumentation()->DisableMethodTracing();
Jeff Hao0abc72e2013-08-13 13:45:14 -0700429 runtime->GetInstrumentation()->RemoveListener(the_trace,
430 instrumentation::Instrumentation::kMethodEntered |
431 instrumentation::Instrumentation::kMethodExited |
432 instrumentation::Instrumentation::kMethodUnwind);
433 }
Andreas Gampe4303ba92014-11-06 01:00:46 -0800434 if (the_trace->trace_file_.get() != nullptr) {
435 // Do not try to erase, so flush and close explicitly.
436 if (the_trace->trace_file_->Flush() != 0) {
437 PLOG(ERROR) << "Could not flush trace file.";
438 }
439 if (the_trace->trace_file_->Close() != 0) {
440 PLOG(ERROR) << "Could not close trace file.";
441 }
442 }
Ian Rogers62d6c772013-02-27 08:32:07 -0800443 delete the_trace;
444 }
445 runtime->GetThreadList()->ResumeAll();
Jeff Hao0abc72e2013-08-13 13:45:14 -0700446
Mathieu Chartier9ef78b52014-09-25 17:03:12 -0700447 if (stop_alloc_counting) {
448 // Can be racy since SetStatsEnabled is not guarded by any locks.
449 Runtime::Current()->SetStatsEnabled(false);
450 }
451
Jeff Hao23009dc2013-08-22 15:36:42 -0700452 if (sampling_pthread != 0U) {
Jeff Hao0abc72e2013-08-13 13:45:14 -0700453 CHECK_PTHREAD_CALL(pthread_join, (sampling_pthread, NULL), "sampling thread shutdown");
Jeff Haod063d912014-09-08 09:38:18 -0700454 sampling_pthread_ = 0U;
Jeff Hao0abc72e2013-08-13 13:45:14 -0700455 }
jeffhao2692b572011-12-16 15:42:28 -0800456}
457
jeffhaob5e81852012-03-12 11:15:45 -0700458void Trace::Shutdown() {
Jeff Hao64caa7d2013-08-29 11:18:01 -0700459 if (GetMethodTracingMode() != kTracingInactive) {
Ian Rogers62d6c772013-02-27 08:32:07 -0800460 Stop();
jeffhaob5e81852012-03-12 11:15:45 -0700461 }
jeffhaob5e81852012-03-12 11:15:45 -0700462}
463
Jeff Hao64caa7d2013-08-29 11:18:01 -0700464TracingMode Trace::GetMethodTracingMode() {
Ian Rogers62d6c772013-02-27 08:32:07 -0800465 MutexLock mu(Thread::Current(), *Locks::trace_lock_);
Jeff Hao64caa7d2013-08-29 11:18:01 -0700466 if (the_trace_ == NULL) {
467 return kTracingInactive;
468 } else if (the_trace_->sampling_enabled_) {
469 return kSampleProfilingActive;
470 } else {
471 return kMethodTracingActive;
472 }
Ian Rogers62d6c772013-02-27 08:32:07 -0800473}
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800474
Jeff Hao23009dc2013-08-22 15:36:42 -0700475Trace::Trace(File* trace_file, int buffer_size, int flags, bool sampling_enabled)
Ian Rogers62d6c772013-02-27 08:32:07 -0800476 : trace_file_(trace_file), buf_(new uint8_t[buffer_size]()), flags_(flags),
Jeff Hao23009dc2013-08-22 15:36:42 -0700477 sampling_enabled_(sampling_enabled), clock_source_(default_clock_source_),
Jeff Haoc5d824a2014-07-28 18:35:38 -0700478 buffer_size_(buffer_size), start_time_(MicroTime()),
479 clock_overhead_ns_(GetClockOverheadNanoSeconds()), cur_offset_(0), overflow_(false) {
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800480 // Set up the beginning of the trace.
Ian Rogers62d6c772013-02-27 08:32:07 -0800481 uint16_t trace_version = GetTraceVersion(clock_source_);
jeffhao2692b572011-12-16 15:42:28 -0800482 memset(buf_.get(), 0, kTraceHeaderLength);
483 Append4LE(buf_.get(), kTraceMagicValue);
Ian Rogers62d6c772013-02-27 08:32:07 -0800484 Append2LE(buf_.get() + 4, trace_version);
jeffhao2692b572011-12-16 15:42:28 -0800485 Append2LE(buf_.get() + 6, kTraceHeaderLength);
486 Append8LE(buf_.get() + 8, start_time_);
Ian Rogers62d6c772013-02-27 08:32:07 -0800487 if (trace_version >= kTraceVersionDualClock) {
488 uint16_t record_size = GetRecordSize(clock_source_);
489 Append2LE(buf_.get() + 16, record_size);
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800490 }
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800491
jeffhao2692b572011-12-16 15:42:28 -0800492 // Update current offset.
Ian Rogers8ab25ef2014-07-09 18:00:50 -0700493 cur_offset_.StoreRelaxed(kTraceHeaderLength);
Ian Rogers62d6c772013-02-27 08:32:07 -0800494}
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800495
Ian Rogerse63db272014-07-15 15:36:11 -0700496static void DumpBuf(uint8_t* buf, size_t buf_size, TraceClockSource clock_source)
Ian Rogers62d6c772013-02-27 08:32:07 -0800497 SHARED_LOCKS_REQUIRED(Locks::mutator_lock_) {
498 uint8_t* ptr = buf + kTraceHeaderLength;
499 uint8_t* end = buf + buf_size;
500
501 while (ptr < end) {
502 uint32_t tmid = ptr[2] | (ptr[3] << 8) | (ptr[4] << 16) | (ptr[5] << 24);
Brian Carlstromea46f952013-07-30 01:26:50 -0700503 mirror::ArtMethod* method = DecodeTraceMethodId(tmid);
Ian Rogers62d6c772013-02-27 08:32:07 -0800504 TraceAction action = DecodeTraceAction(tmid);
505 LOG(INFO) << PrettyMethod(method) << " " << static_cast<int>(action);
506 ptr += GetRecordSize(clock_source);
507 }
jeffhaoe343b762011-12-05 16:36:44 -0800508}
509
jeffhao2692b572011-12-16 15:42:28 -0800510void Trace::FinishTracing() {
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800511 // Compute elapsed time.
512 uint64_t elapsed = MicroTime() - start_time_;
513
Ian Rogers8ab25ef2014-07-09 18:00:50 -0700514 size_t final_offset = cur_offset_.LoadRelaxed();
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800515
Brian Carlstromea46f952013-07-30 01:26:50 -0700516 std::set<mirror::ArtMethod*> visited_methods;
Ian Rogers62d6c772013-02-27 08:32:07 -0800517 GetVisitedMethods(final_offset, &visited_methods);
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800518
519 std::ostringstream os;
520
521 os << StringPrintf("%cversion\n", kTraceTokenChar);
Ian Rogers62d6c772013-02-27 08:32:07 -0800522 os << StringPrintf("%d\n", GetTraceVersion(clock_source_));
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800523 os << StringPrintf("data-file-overflow=%s\n", overflow_ ? "true" : "false");
524 if (UseThreadCpuClock()) {
525 if (UseWallClock()) {
526 os << StringPrintf("clock=dual\n");
527 } else {
528 os << StringPrintf("clock=thread-cpu\n");
529 }
530 } else {
531 os << StringPrintf("clock=wall\n");
532 }
Ian Rogersef7d42f2014-01-06 12:55:46 -0800533 os << StringPrintf("elapsed-time-usec=%" PRIu64 "\n", elapsed);
Ian Rogers62d6c772013-02-27 08:32:07 -0800534 size_t num_records = (final_offset - kTraceHeaderLength) / GetRecordSize(clock_source_);
535 os << StringPrintf("num-method-calls=%zd\n", num_records);
Jeff Haoc5d824a2014-07-28 18:35:38 -0700536 os << StringPrintf("clock-call-overhead-nsec=%d\n", clock_overhead_ns_);
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800537 os << StringPrintf("vm=art\n");
jeffhao0791adc2012-04-04 11:14:32 -0700538 if ((flags_ & kTraceCountAllocs) != 0) {
539 os << StringPrintf("alloc-count=%d\n", Runtime::Current()->GetStat(KIND_ALLOCATED_OBJECTS));
540 os << StringPrintf("alloc-size=%d\n", Runtime::Current()->GetStat(KIND_ALLOCATED_BYTES));
541 os << StringPrintf("gc-count=%d\n", Runtime::Current()->GetStat(KIND_GC_INVOCATIONS));
542 }
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800543 os << StringPrintf("%cthreads\n", kTraceTokenChar);
544 DumpThreadList(os);
545 os << StringPrintf("%cmethods\n", kTraceTokenChar);
Ian Rogers62d6c772013-02-27 08:32:07 -0800546 DumpMethodList(os, visited_methods);
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800547 os << StringPrintf("%cend\n", kTraceTokenChar);
548
549 std::string header(os.str());
jeffhao2692b572011-12-16 15:42:28 -0800550 if (trace_file_.get() == NULL) {
Elliott Hughes7b9d9962012-04-20 18:48:18 -0700551 iovec iov[2];
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800552 iov[0].iov_base = reinterpret_cast<void*>(const_cast<char*>(header.c_str()));
553 iov[0].iov_len = header.length();
jeffhao2692b572011-12-16 15:42:28 -0800554 iov[1].iov_base = buf_.get();
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800555 iov[1].iov_len = final_offset;
556 Dbg::DdmSendChunkV(CHUNK_TYPE("MPSE"), iov, 2);
Ian Rogers62d6c772013-02-27 08:32:07 -0800557 const bool kDumpTraceInfo = false;
558 if (kDumpTraceInfo) {
559 LOG(INFO) << "Trace sent:\n" << header;
560 DumpBuf(buf_.get(), final_offset, clock_source_);
561 }
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800562 } else {
563 if (!trace_file_->WriteFully(header.c_str(), header.length()) ||
jeffhao2692b572011-12-16 15:42:28 -0800564 !trace_file_->WriteFully(buf_.get(), final_offset)) {
Elliott Hughes7b9d9962012-04-20 18:48:18 -0700565 std::string detail(StringPrintf("Trace data write failed: %s", strerror(errno)));
566 PLOG(ERROR) << detail;
Ian Rogers62d6c772013-02-27 08:32:07 -0800567 ThrowRuntimeException("%s", detail.c_str());
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800568 }
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800569 }
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800570}
571
Ian Rogers62d6c772013-02-27 08:32:07 -0800572void Trace::DexPcMoved(Thread* thread, mirror::Object* this_object,
Ian Rogersef7d42f2014-01-06 12:55:46 -0800573 mirror::ArtMethod* method, uint32_t new_dex_pc) {
Ian Rogers6a3c1fc2014-10-31 00:33:20 -0700574 UNUSED(thread, this_object, method, new_dex_pc);
Ian Rogers62d6c772013-02-27 08:32:07 -0800575 // We're not recorded to listen to this kind of event, so complain.
576 LOG(ERROR) << "Unexpected dex PC event in tracing " << PrettyMethod(method) << " " << new_dex_pc;
Andreas Gampec8ccf682014-09-29 20:07:43 -0700577}
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800578
Ian Rogers6a3c1fc2014-10-31 00:33:20 -0700579void Trace::FieldRead(Thread* thread, mirror::Object* this_object,
Sebastien Hertz3f52eaf2014-04-04 17:50:18 +0200580 mirror::ArtMethod* method, uint32_t dex_pc, mirror::ArtField* field)
581 SHARED_LOCKS_REQUIRED(Locks::mutator_lock_) {
Ian Rogers6a3c1fc2014-10-31 00:33:20 -0700582 UNUSED(thread, this_object, method, dex_pc, field);
Sebastien Hertz3f52eaf2014-04-04 17:50:18 +0200583 // We're not recorded to listen to this kind of event, so complain.
584 LOG(ERROR) << "Unexpected field read event in tracing " << PrettyMethod(method) << " " << dex_pc;
585}
586
Ian Rogers6a3c1fc2014-10-31 00:33:20 -0700587void Trace::FieldWritten(Thread* thread, mirror::Object* this_object,
Sebastien Hertz3f52eaf2014-04-04 17:50:18 +0200588 mirror::ArtMethod* method, uint32_t dex_pc, mirror::ArtField* field,
589 const JValue& field_value)
590 SHARED_LOCKS_REQUIRED(Locks::mutator_lock_) {
Ian Rogers6a3c1fc2014-10-31 00:33:20 -0700591 UNUSED(thread, this_object, method, dex_pc, field, field_value);
Sebastien Hertz3f52eaf2014-04-04 17:50:18 +0200592 // We're not recorded to listen to this kind of event, so complain.
593 LOG(ERROR) << "Unexpected field write event in tracing " << PrettyMethod(method) << " " << dex_pc;
594}
595
Ian Rogers6a3c1fc2014-10-31 00:33:20 -0700596void Trace::MethodEntered(Thread* thread, mirror::Object* this_object ATTRIBUTE_UNUSED,
597 mirror::ArtMethod* method, uint32_t dex_pc ATTRIBUTE_UNUSED) {
Jeff Haoc1ff4b72013-08-19 11:33:10 -0700598 uint32_t thread_clock_diff = 0;
599 uint32_t wall_clock_diff = 0;
600 ReadClocks(thread, &thread_clock_diff, &wall_clock_diff);
601 LogMethodTraceEvent(thread, method, instrumentation::Instrumentation::kMethodEntered,
602 thread_clock_diff, wall_clock_diff);
Ian Rogers62d6c772013-02-27 08:32:07 -0800603}
604
Ian Rogers6a3c1fc2014-10-31 00:33:20 -0700605void Trace::MethodExited(Thread* thread, mirror::Object* this_object ATTRIBUTE_UNUSED,
606 mirror::ArtMethod* method, uint32_t dex_pc ATTRIBUTE_UNUSED,
607 const JValue& return_value ATTRIBUTE_UNUSED) {
Jeff Haoc1ff4b72013-08-19 11:33:10 -0700608 uint32_t thread_clock_diff = 0;
609 uint32_t wall_clock_diff = 0;
610 ReadClocks(thread, &thread_clock_diff, &wall_clock_diff);
611 LogMethodTraceEvent(thread, method, instrumentation::Instrumentation::kMethodExited,
612 thread_clock_diff, wall_clock_diff);
Ian Rogers62d6c772013-02-27 08:32:07 -0800613}
614
Ian Rogers6a3c1fc2014-10-31 00:33:20 -0700615void Trace::MethodUnwind(Thread* thread, mirror::Object* this_object ATTRIBUTE_UNUSED,
616 mirror::ArtMethod* method, uint32_t dex_pc ATTRIBUTE_UNUSED) {
Jeff Haoc1ff4b72013-08-19 11:33:10 -0700617 uint32_t thread_clock_diff = 0;
618 uint32_t wall_clock_diff = 0;
619 ReadClocks(thread, &thread_clock_diff, &wall_clock_diff);
620 LogMethodTraceEvent(thread, method, instrumentation::Instrumentation::kMethodUnwind,
621 thread_clock_diff, wall_clock_diff);
Ian Rogers62d6c772013-02-27 08:32:07 -0800622}
623
624void Trace::ExceptionCaught(Thread* thread, const ThrowLocation& throw_location,
Brian Carlstromea46f952013-07-30 01:26:50 -0700625 mirror::ArtMethod* catch_method, uint32_t catch_dex_pc,
Ian Rogers62d6c772013-02-27 08:32:07 -0800626 mirror::Throwable* exception_object)
627 SHARED_LOCKS_REQUIRED(Locks::mutator_lock_) {
Ian Rogers6a3c1fc2014-10-31 00:33:20 -0700628 UNUSED(thread, throw_location, catch_method, catch_dex_pc, exception_object);
Ian Rogers62d6c772013-02-27 08:32:07 -0800629 LOG(ERROR) << "Unexpected exception caught event in tracing";
630}
631
Jeff Haoc1ff4b72013-08-19 11:33:10 -0700632void Trace::ReadClocks(Thread* thread, uint32_t* thread_clock_diff, uint32_t* wall_clock_diff) {
633 if (UseThreadCpuClock()) {
634 uint64_t clock_base = thread->GetTraceClockBase();
635 if (UNLIKELY(clock_base == 0)) {
636 // First event, record the base time in the map.
637 uint64_t time = thread->GetCpuMicroTime();
638 thread->SetTraceClockBase(time);
639 } else {
640 *thread_clock_diff = thread->GetCpuMicroTime() - clock_base;
641 }
642 }
643 if (UseWallClock()) {
644 *wall_clock_diff = MicroTime() - start_time_;
645 }
646}
647
Ian Rogersef7d42f2014-01-06 12:55:46 -0800648void Trace::LogMethodTraceEvent(Thread* thread, mirror::ArtMethod* method,
Jeff Haoc1ff4b72013-08-19 11:33:10 -0700649 instrumentation::Instrumentation::InstrumentationEvent event,
650 uint32_t thread_clock_diff, uint32_t wall_clock_diff) {
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800651 // Advance cur_offset_ atomically.
652 int32_t new_offset;
653 int32_t old_offset;
654 do {
Ian Rogers8ab25ef2014-07-09 18:00:50 -0700655 old_offset = cur_offset_.LoadRelaxed();
Ian Rogers62d6c772013-02-27 08:32:07 -0800656 new_offset = old_offset + GetRecordSize(clock_source_);
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800657 if (new_offset > buffer_size_) {
658 overflow_ = true;
659 return;
660 }
Ian Rogers54fb8fd2014-07-09 23:16:06 -0700661 } while (!cur_offset_.CompareExchangeWeakSequentiallyConsistent(old_offset, new_offset));
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800662
Ian Rogers62d6c772013-02-27 08:32:07 -0800663 TraceAction action = kTraceMethodEnter;
664 switch (event) {
665 case instrumentation::Instrumentation::kMethodEntered:
666 action = kTraceMethodEnter;
667 break;
668 case instrumentation::Instrumentation::kMethodExited:
669 action = kTraceMethodExit;
670 break;
671 case instrumentation::Instrumentation::kMethodUnwind:
672 action = kTraceUnroll;
673 break;
674 default:
675 UNIMPLEMENTED(FATAL) << "Unexpected event: " << event;
676 }
677
678 uint32_t method_value = EncodeTraceMethodAndAction(method, action);
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800679
680 // Write data
jeffhao2692b572011-12-16 15:42:28 -0800681 uint8_t* ptr = buf_.get() + old_offset;
Ian Rogers62d6c772013-02-27 08:32:07 -0800682 Append2LE(ptr, thread->GetTid());
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800683 Append4LE(ptr + 2, method_value);
684 ptr += 6;
685
686 if (UseThreadCpuClock()) {
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800687 Append4LE(ptr, thread_clock_diff);
688 ptr += 4;
689 }
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800690 if (UseWallClock()) {
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800691 Append4LE(ptr, wall_clock_diff);
692 }
693}
694
Ian Rogers62d6c772013-02-27 08:32:07 -0800695void Trace::GetVisitedMethods(size_t buf_size,
Brian Carlstromea46f952013-07-30 01:26:50 -0700696 std::set<mirror::ArtMethod*>* visited_methods) {
jeffhao2692b572011-12-16 15:42:28 -0800697 uint8_t* ptr = buf_.get() + kTraceHeaderLength;
Ian Rogers62d6c772013-02-27 08:32:07 -0800698 uint8_t* end = buf_.get() + buf_size;
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800699
700 while (ptr < end) {
Ian Rogers62d6c772013-02-27 08:32:07 -0800701 uint32_t tmid = ptr[2] | (ptr[3] << 8) | (ptr[4] << 16) | (ptr[5] << 24);
Brian Carlstromea46f952013-07-30 01:26:50 -0700702 mirror::ArtMethod* method = DecodeTraceMethodId(tmid);
Ian Rogers62d6c772013-02-27 08:32:07 -0800703 visited_methods->insert(method);
704 ptr += GetRecordSize(clock_source_);
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800705 }
706}
707
Mathieu Chartier02e25112013-08-14 16:14:24 -0700708void Trace::DumpMethodList(std::ostream& os, const std::set<mirror::ArtMethod*>& visited_methods) {
Mathieu Chartier02e25112013-08-14 16:14:24 -0700709 for (const auto& method : visited_methods) {
Ian Rogers0399dde2012-06-06 17:09:28 -0700710 os << StringPrintf("%p\t%s\t%s\t%s\t%s\n", method,
Mathieu Chartierbfd9a432014-05-21 17:43:44 -0700711 PrettyDescriptor(method->GetDeclaringClassDescriptor()).c_str(), method->GetName(),
712 method->GetSignature().ToString().c_str(), method->GetDeclaringClassSourceFile());
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800713 }
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800714}
715
716static void DumpThread(Thread* t, void* arg) {
Elliott Hughesffb465f2012-03-01 18:46:05 -0800717 std::ostream& os = *reinterpret_cast<std::ostream*>(arg);
718 std::string name;
719 t->GetThreadName(name);
720 os << t->GetTid() << "\t" << name << "\n";
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800721}
722
723void Trace::DumpThreadList(std::ostream& os) {
Ian Rogers81d425b2012-09-27 16:03:43 -0700724 Thread* self = Thread::Current();
Jeff Haoe094b872014-10-14 13:12:01 -0700725 for (auto it : exited_threads_) {
726 os << it.first << "\t" << it.second << "\n";
727 }
Ian Rogers81d425b2012-09-27 16:03:43 -0700728 Locks::thread_list_lock_->AssertNotHeld(self);
729 MutexLock mu(self, *Locks::thread_list_lock_);
jeffhaoa9ef3fd2011-12-13 18:33:43 -0800730 Runtime::Current()->GetThreadList()->ForEach(DumpThread, &os);
jeffhaoe343b762011-12-05 16:36:44 -0800731}
732
Jeff Haoe094b872014-10-14 13:12:01 -0700733void Trace::StoreExitingThreadInfo(Thread* thread) {
734 MutexLock mu(thread, *Locks::trace_lock_);
735 if (the_trace_ != nullptr) {
736 std::string name;
737 thread->GetThreadName(name);
Andreas Gampea1785c52014-11-25 20:40:08 -0800738 // The same thread/tid may be used multiple times. As SafeMap::Put does not allow to override
739 // a previous mapping, use SafeMap::Overwrite.
740 the_trace_->exited_threads_.Overwrite(thread->GetTid(), name);
Jeff Haoe094b872014-10-14 13:12:01 -0700741 }
742}
743
jeffhaoe343b762011-12-05 16:36:44 -0800744} // namespace art