• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1 /*
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  */
16 
17 #include "trace.h"
18 
19 #include <sys/uio.h>
20 #include <unistd.h>
21 
22 #include "android-base/macros.h"
23 #include "android-base/stringprintf.h"
24 #include "art_method-inl.h"
25 #include "base/casts.h"
26 #include "base/leb128.h"
27 #include "base/os.h"
28 #include "base/pointer_size.h"
29 #include "base/stl_util.h"
30 #include "base/systrace.h"
31 #include "base/time_utils.h"
32 #include "base/unix_file/fd_file.h"
33 #include "base/utils.h"
34 #include "class_linker.h"
35 #include "common_throws.h"
36 #include "debugger.h"
37 #include "dex/descriptors_names.h"
38 #include "dex/dex_file-inl.h"
39 #include "entrypoints/quick/quick_entrypoints.h"
40 #include "gc/scoped_gc_critical_section.h"
41 #include "instrumentation.h"
42 #include "jit/jit.h"
43 #include "jit/jit_code_cache.h"
44 #include "mirror/class-inl.h"
45 #include "mirror/dex_cache-inl.h"
46 #include "mirror/object-inl.h"
47 #include "mirror/object_array-inl.h"
48 #include "nativehelper/scoped_local_ref.h"
49 #include "scoped_thread_state_change-inl.h"
50 #include "stack.h"
51 #include "thread.h"
52 #include "thread_list.h"
53 
54 namespace art HIDDEN {
55 
56 struct MethodTraceRecord {
57   ArtMethod* method;
58   TraceAction action;
59   uint32_t wall_clock_time;
60   uint32_t thread_cpu_time;
61 };
62 
63 using android::base::StringPrintf;
64 
65 static constexpr size_t TraceActionBits = MinimumBitsToStore(
66     static_cast<size_t>(kTraceMethodActionMask));
67 static constexpr uint8_t kOpNewMethod = 1U;
68 static constexpr uint8_t kOpNewThread = 2U;
69 static constexpr uint8_t kOpTraceSummary = 3U;
70 
71 static const char     kTraceTokenChar             = '*';
72 static const uint16_t kTraceHeaderLength          = 32;
73 static const uint32_t kTraceMagicValue            = 0x574f4c53;
74 static const uint16_t kTraceVersionSingleClock    = 2;
75 static const uint16_t kTraceVersionDualClock      = 3;
76 static const uint16_t kTraceRecordSizeSingleClock = 10;  // using v2
77 static const uint16_t kTraceRecordSizeDualClock   = 14;  // using v3 with two timestamps
78 static const size_t kNumTracePoolBuffers = 32;
79 
80 // Packet type encoding for the new method tracing format.
81 static const int kThreadInfoHeaderV2 = 0;
82 static const int kMethodInfoHeaderV2 = 1;
83 static const int kEntryHeaderV2 = 2;
84 static const int kSummaryHeaderV2 = 3;
85 
86 // Packet sizes for the new method trace format.
87 static const uint16_t kTraceHeaderLengthV2 = 32;
88 static const uint16_t kTraceRecordSizeSingleClockV2 = 6;
89 static const uint16_t kTraceRecordSizeDualClockV2 = kTraceRecordSizeSingleClockV2 + 2;
90 static const uint16_t kEntryHeaderSizeSingleClockV2 = 21;
91 static const uint16_t kEntryHeaderSizeDualClockV2 = kEntryHeaderSizeSingleClockV2 + 4;
92 
93 static const uint16_t kTraceVersionSingleClockV2 = 4;
94 static const uint16_t kTraceVersionDualClockV2 = 5;
95 
96 static constexpr size_t kMinBufSize = 18U;  // Trace header is up to 18B.
97 // Size of per-thread buffer size. The value is chosen arbitrarily. This value
98 // should be greater than kMinBufSize.
99 static constexpr size_t kPerThreadBufSize = 512 * 1024;
100 static_assert(kPerThreadBufSize > kMinBufSize);
101 // On average we need 12 bytes for encoding an entry. We typically use two
102 // entries in per-thread buffer, the scaling factor is 6.
103 static constexpr size_t kScalingFactorEncodedEntries = 6;
104 
105 TraceClockSource Trace::default_clock_source_ = kDefaultTraceClockSource;
106 
107 Trace* volatile Trace::the_trace_ = nullptr;
108 pthread_t Trace::sampling_pthread_ = 0U;
109 std::unique_ptr<std::vector<ArtMethod*>> Trace::temp_stack_trace_;
110 
111 // The key identifying the tracer to update instrumentation.
112 static constexpr const char* kTracerInstrumentationKey = "Tracer";
113 
DecodeTraceAction(uint32_t tmid)114 static TraceAction DecodeTraceAction(uint32_t tmid) {
115   return static_cast<TraceAction>(tmid & kTraceMethodActionMask);
116 }
117 
118 namespace {
119 // Scaling factor to convert timestamp counter into wall clock time reported in micro seconds.
120 // This is initialized at the start of tracing using the timestamp counter update frequency.
121 // See InitializeTimestampCounters for more details.
122 double tsc_to_microsec_scaling_factor = -1.0;
123 
GetTimestamp()124 uint64_t GetTimestamp() {
125   uint64_t t = 0;
126 #if defined(__arm__)
127   // On ARM 32 bit, we don't always have access to the timestamp counters from user space. There is
128   // no easy way to check if it is safe to read the timestamp counters. There is HWCAP_EVTSTRM which
129   // is set when generic timer is available but not necessarily from the user space. Kernel disables
130   // access to generic timer when there are known problems on the target CPUs. Sometimes access is
131   // disabled only for 32-bit processes even when 64-bit processes can accesses the timer from user
132   // space. These are not reflected in the HWCAP_EVTSTRM capability.So just fallback to
133   // clock_gettime on these processes. See b/289178149 for more discussion.
134   t = MicroTime();
135 #elif defined(__aarch64__)
136   // See Arm Architecture Registers  Armv8 section System Registers
137   asm volatile("mrs %0, cntvct_el0" : "=r"(t));
138 #elif defined(__i386__) || defined(__x86_64__)
139   // rdtsc returns two 32-bit values in rax and rdx even on 64-bit architectures.
140   unsigned int lo, hi;
141   asm volatile("rdtsc" : "=a"(lo), "=d"(hi));
142   t = (static_cast<uint64_t>(hi) << 32) | lo;
143 #elif defined(__riscv)
144   asm volatile("rdtime %0" : "=r"(t));
145 #else
146   t = MicroTime();
147 #endif
148   return t;
149 }
150 
151 #if defined(__i386__) || defined(__x86_64__) || defined(__aarch64__)
152 // Here we compute the scaling factor by sleeping for a millisecond. Alternatively, we could
153 // generate raw timestamp counter and also time using clock_gettime at the start and the end of the
154 // trace. We can compute the frequency of timestamp counter upadtes in the post processing step
155 // using these two samples. However, that would require a change in Android Studio which is the main
156 // consumer of these profiles. For now, just compute the frequency of tsc updates here.
computeScalingFactor()157 double computeScalingFactor() {
158   uint64_t start = MicroTime();
159   uint64_t start_tsc = GetTimestamp();
160   // Sleep for one millisecond.
161   usleep(1000);
162   uint64_t diff_tsc = GetTimestamp() - start_tsc;
163   uint64_t diff_time = MicroTime() - start;
164   double scaling_factor = static_cast<double>(diff_time) / diff_tsc;
165   DCHECK(scaling_factor > 0.0) << scaling_factor;
166   return scaling_factor;
167 }
168 #endif
169 
170 #if defined(__i386__) || defined(__x86_64__)
GetScalingFactorForX86()171 double GetScalingFactorForX86() {
172   uint32_t eax, ebx, ecx;
173   asm volatile("cpuid" : "=a"(eax), "=b"(ebx), "=c"(ecx) : "a"(0x0), "c"(0));
174   if (eax < 0x15) {
175     // There is no 15H - Timestamp counter and core crystal clock information
176     // leaf. Just compute the frequency.
177     return computeScalingFactor();
178   }
179 
180   // From Intel architecture-instruction-set-extensions-programming-reference:
181   // EBX[31:0]/EAX[31:0] indicates the ratio of the TSC frequency and the
182   // core crystal clock frequency.
183   // If EBX[31:0] is 0, the TSC and "core crystal clock" ratio is not enumerated.
184   // If ECX is 0, the nominal core crystal clock frequency is not enumerated.
185   // "TSC frequency" = "core crystal clock frequency" * EBX/EAX.
186   // The core crystal clock may differ from the reference clock, bus clock, or core clock
187   // frequencies.
188   // EAX Bits 31 - 00: An unsigned integer which is the denominator of the
189   //                   TSC/"core crystal clock" ratio.
190   // EBX Bits 31 - 00: An unsigned integer which is the numerator of the
191   //                   TSC/"core crystal clock" ratio.
192   // ECX Bits 31 - 00: An unsigned integer which is the nominal frequency of the core
193   //                   crystal clock in Hz.
194   // EDX Bits 31 - 00: Reserved = 0.
195   asm volatile("cpuid" : "=a"(eax), "=b"(ebx), "=c"(ecx) : "a"(0x15), "c"(0));
196   if (ebx == 0 || ecx == 0) {
197     return computeScalingFactor();
198   }
199   double coreCrystalFreq = ecx;
200   // frequency = coreCrystalFreq * (ebx / eax)
201   // scaling_factor = seconds_to_microseconds / frequency
202   //                = seconds_to_microseconds * eax / (coreCrystalFreq * ebx)
203   double seconds_to_microseconds = 1000 * 1000;
204   double scaling_factor = (seconds_to_microseconds * eax) / (coreCrystalFreq * ebx);
205   return scaling_factor;
206 }
207 #endif
208 
InitializeTimestampCounters()209 void InitializeTimestampCounters() {
210   // It is sufficient to initialize this once for the entire execution. Just return if it is
211   // already initialized.
212   if (tsc_to_microsec_scaling_factor > 0.0) {
213     return;
214   }
215 
216 #if defined(__arm__)
217   // On ARM 32 bit, we don't always have access to the timestamp counters from
218   // user space. Seem comment in GetTimestamp for more details.
219   tsc_to_microsec_scaling_factor = 1.0;
220 #elif defined(__aarch64__)
221   double seconds_to_microseconds = 1000 * 1000;
222   uint64_t freq = 0;
223   // See Arm Architecture Registers  Armv8 section System Registers
224   asm volatile("mrs %0,  cntfrq_el0" : "=r"(freq));
225   if (freq == 0) {
226     // It is expected that cntfrq_el0 is correctly setup during system initialization but some
227     // devices don't do this. In such cases fall back to computing the frequency. See b/315139000.
228     tsc_to_microsec_scaling_factor = computeScalingFactor();
229   } else {
230     tsc_to_microsec_scaling_factor = seconds_to_microseconds / static_cast<double>(freq);
231   }
232 #elif defined(__i386__) || defined(__x86_64__)
233   tsc_to_microsec_scaling_factor = GetScalingFactorForX86();
234 #else
235   tsc_to_microsec_scaling_factor = 1.0;
236 #endif
237 }
238 
GetMicroTime(uint64_t counter)239 ALWAYS_INLINE uint64_t GetMicroTime(uint64_t counter) {
240   DCHECK(tsc_to_microsec_scaling_factor > 0.0) << tsc_to_microsec_scaling_factor;
241   return tsc_to_microsec_scaling_factor * counter;
242 }
243 
GetClockSourceFromFlags(int flags)244 TraceClockSource GetClockSourceFromFlags(int flags) {
245   bool need_wall = flags & Trace::TraceFlag::kTraceClockSourceWallClock;
246   bool need_thread_cpu = flags & Trace::TraceFlag::kTraceClockSourceThreadCpu;
247   if (need_wall && need_thread_cpu) {
248     return TraceClockSource::kDual;
249   } else if (need_wall) {
250     return TraceClockSource::kWall;
251   } else if (need_thread_cpu) {
252     return TraceClockSource::kThreadCpu;
253   } else {
254     return kDefaultTraceClockSource;
255   }
256 }
257 
GetTraceFormatVersionFromFlags(int flags)258 int GetTraceFormatVersionFromFlags(int flags) {
259   int version = (flags & Trace::kTraceFormatVersionFlagMask) >> Trace::kTraceFormatVersionShift;
260   return version;
261 }
262 
263 }  // namespace
264 
HasMethodEncoding(ArtMethod * method)265 bool TraceWriter::HasMethodEncoding(ArtMethod* method) {
266   return art_method_id_map_.find(method) != art_method_id_map_.end();
267 }
268 
GetMethodEncoding(ArtMethod * method)269 std::pair<uint32_t, bool> TraceWriter::GetMethodEncoding(ArtMethod* method) {
270   auto it = art_method_id_map_.find(method);
271   if (it != art_method_id_map_.end()) {
272     return std::pair<uint32_t, bool>(it->second, false);
273   } else {
274     uint32_t idx = current_method_index_;
275     art_method_id_map_.emplace(method, idx);
276     current_method_index_++;
277     return std::pair<uint32_t, bool>(idx, true);
278   }
279 }
280 
GetThreadEncoding(pid_t thread_id)281 uint16_t TraceWriter::GetThreadEncoding(pid_t thread_id) {
282   auto it = thread_id_map_.find(thread_id);
283   if (it != thread_id_map_.end()) {
284     return it->second;
285   }
286 
287   uint16_t idx = current_thread_index_;
288   thread_id_map_.emplace(thread_id, current_thread_index_);
289   DCHECK_LT(current_thread_index_, (1 << 16) - 2);
290   current_thread_index_++;
291   return idx;
292 }
293 
294 class TraceWriterTask : public SelfDeletingTask {
295  public:
TraceWriterTask(TraceWriter * trace_writer,int index,uintptr_t * buffer,size_t cur_offset,size_t thread_id)296   TraceWriterTask(
297       TraceWriter* trace_writer, int index, uintptr_t* buffer, size_t cur_offset, size_t thread_id)
298       : trace_writer_(trace_writer),
299         index_(index),
300         buffer_(buffer),
301         cur_offset_(cur_offset),
302         thread_id_(thread_id) {}
303 
Run(Thread * self ATTRIBUTE_UNUSED)304   void Run(Thread* self ATTRIBUTE_UNUSED) override {
305     ProcessBuffer(buffer_, cur_offset_, thread_id_);
306     if (index_ == -1) {
307       // This was a temporary buffer we allocated since there are no free buffers and it wasn't
308       // safe to wait for one. This should only happen when we have fewer buffers than the number
309       // of threads.
310       delete[] buffer_;
311     }
312     trace_writer_->ReleaseBuffer(index_);
313   }
314 
315   virtual void ProcessBuffer(uintptr_t* buffer, size_t cur_offset, size_t thread_id) = 0;
316 
GetTraceWriter()317   TraceWriter* GetTraceWriter() { return trace_writer_; }
318 
319  private:
320   TraceWriter* trace_writer_;
321   int index_;
322   uintptr_t* buffer_;
323   size_t cur_offset_;
324   size_t thread_id_;
325 };
326 
327 class TraceEntriesWriterTask final : public TraceWriterTask {
328  public:
TraceEntriesWriterTask(TraceWriter * trace_writer,int index,uintptr_t * buffer,size_t cur_offset,size_t tid)329   TraceEntriesWriterTask(
330       TraceWriter* trace_writer, int index, uintptr_t* buffer, size_t cur_offset, size_t tid)
331       : TraceWriterTask(trace_writer, index, buffer, cur_offset, tid) {}
332 
ProcessBuffer(uintptr_t * buffer,size_t cur_offset,size_t thread_id)333   void ProcessBuffer(uintptr_t* buffer, size_t cur_offset, size_t thread_id) override {
334     std::unordered_map<ArtMethod*, std::string> method_infos;
335     TraceWriter* trace_writer = GetTraceWriter();
336     if (trace_writer->GetTraceFormatVersion() == Trace::kFormatV1) {
337       ScopedObjectAccess soa(Thread::Current());
338       trace_writer->PreProcessTraceForMethodInfos(buffer, cur_offset, method_infos);
339     }
340     trace_writer->FlushBuffer(buffer, cur_offset, thread_id, method_infos);
341   }
342 };
343 
344 class MethodInfoWriterTask final : public TraceWriterTask {
345  public:
MethodInfoWriterTask(TraceWriter * trace_writer,int index,uintptr_t * buffer,size_t cur_offset)346   MethodInfoWriterTask(TraceWriter* trace_writer, int index, uintptr_t* buffer, size_t cur_offset)
347       : TraceWriterTask(trace_writer, index, buffer, cur_offset, 0) {}
348 
ProcessBuffer(uintptr_t * buffer,size_t cur_offset,size_t thread_id)349   void ProcessBuffer(uintptr_t* buffer,
350                      size_t cur_offset,
351                      [[maybe_unused]] size_t thread_id) override {
352     GetTraceWriter()->WriteToFile(reinterpret_cast<uint8_t*>(buffer), cur_offset);
353   }
354 };
355 
AllocStackTrace()356 std::vector<ArtMethod*>* Trace::AllocStackTrace() {
357   return (temp_stack_trace_.get() != nullptr)  ? temp_stack_trace_.release() :
358       new std::vector<ArtMethod*>();
359 }
360 
FreeStackTrace(std::vector<ArtMethod * > * stack_trace)361 void Trace::FreeStackTrace(std::vector<ArtMethod*>* stack_trace) {
362   stack_trace->clear();
363   temp_stack_trace_.reset(stack_trace);
364 }
365 
SetDefaultClockSource(TraceClockSource clock_source)366 void Trace::SetDefaultClockSource(TraceClockSource clock_source) {
367 #if defined(__linux__)
368   default_clock_source_ = clock_source;
369 #else
370   if (clock_source != TraceClockSource::kWall) {
371     LOG(WARNING) << "Ignoring tracing request to use CPU time.";
372   }
373 #endif
374 }
375 
GetTraceVersion(TraceClockSource clock_source,int version)376 static uint16_t GetTraceVersion(TraceClockSource clock_source, int version) {
377   if (version == Trace::kFormatV1) {
378     return (clock_source == TraceClockSource::kDual) ? kTraceVersionDualClock :
379                                                        kTraceVersionSingleClock;
380   } else {
381     return (clock_source == TraceClockSource::kDual) ? kTraceVersionDualClockV2 :
382                                                        kTraceVersionSingleClockV2;
383   }
384 }
385 
GetRecordSize(TraceClockSource clock_source,int version)386 static uint16_t GetRecordSize(TraceClockSource clock_source, int version) {
387   if (version == Trace::kFormatV1) {
388     return (clock_source == TraceClockSource::kDual) ? kTraceRecordSizeDualClock :
389                                                        kTraceRecordSizeSingleClock;
390   } else {
391     return (clock_source == TraceClockSource::kDual) ? kTraceRecordSizeDualClockV2 :
392                                                        kTraceRecordSizeSingleClockV2;
393   }
394 }
395 
GetNumEntries(TraceClockSource clock_source)396 static uint16_t GetNumEntries(TraceClockSource clock_source) {
397   return (clock_source == TraceClockSource::kDual) ? kNumEntriesForDualClock
398                                                    : kNumEntriesForWallClock;
399 }
400 
UseThreadCpuClock(TraceClockSource clock_source)401 bool UseThreadCpuClock(TraceClockSource clock_source) {
402   return (clock_source == TraceClockSource::kThreadCpu) ||
403          (clock_source == TraceClockSource::kDual);
404 }
405 
UseWallClock(TraceClockSource clock_source)406 bool UseWallClock(TraceClockSource clock_source) {
407   return (clock_source == TraceClockSource::kWall) || (clock_source == TraceClockSource::kDual);
408 }
409 
UseFastTraceListeners(TraceClockSource clock_source)410 bool UseFastTraceListeners(TraceClockSource clock_source) {
411   // Thread cpu clocks needs a kernel call, so we don't directly support them in JITed code.
412   bool is_fast_trace = !UseThreadCpuClock(clock_source);
413 #if defined(__arm__)
414   // On ARM 32 bit, we don't always have access to the timestamp counters from
415   // user space. See comment in GetTimestamp for more details.
416   is_fast_trace = false;
417 #endif
418   return is_fast_trace;
419 }
420 
MeasureClockOverhead()421 void Trace::MeasureClockOverhead() {
422   if (UseThreadCpuClock(clock_source_)) {
423     Thread::Current()->GetCpuMicroTime();
424   }
425   if (UseWallClock(clock_source_)) {
426     GetTimestamp();
427   }
428 }
429 
430 // Compute an average time taken to measure clocks.
GetClockOverheadNanoSeconds()431 uint32_t Trace::GetClockOverheadNanoSeconds() {
432   Thread* self = Thread::Current();
433   uint64_t start = self->GetCpuMicroTime();
434 
435   for (int i = 4000; i > 0; i--) {
436     MeasureClockOverhead();
437     MeasureClockOverhead();
438     MeasureClockOverhead();
439     MeasureClockOverhead();
440     MeasureClockOverhead();
441     MeasureClockOverhead();
442     MeasureClockOverhead();
443     MeasureClockOverhead();
444   }
445 
446   uint64_t elapsed_us = self->GetCpuMicroTime() - start;
447   return static_cast<uint32_t>(elapsed_us / 32);
448 }
449 
450 // TODO: put this somewhere with the big-endian equivalent used by JDWP.
Append2LE(uint8_t * buf,uint16_t val)451 static void Append2LE(uint8_t* buf, uint16_t val) {
452   *buf++ = static_cast<uint8_t>(val);
453   *buf++ = static_cast<uint8_t>(val >> 8);
454 }
455 
456 // TODO: put this somewhere with the big-endian equivalent used by JDWP.
Append4LE(uint8_t * buf,uint32_t val)457 static void Append4LE(uint8_t* buf, uint32_t val) {
458   *buf++ = static_cast<uint8_t>(val);
459   *buf++ = static_cast<uint8_t>(val >> 8);
460   *buf++ = static_cast<uint8_t>(val >> 16);
461   *buf++ = static_cast<uint8_t>(val >> 24);
462 }
463 
464 // TODO: put this somewhere with the big-endian equivalent used by JDWP.
Append8LE(uint8_t * buf,uint64_t val)465 static void Append8LE(uint8_t* buf, uint64_t val) {
466   *buf++ = static_cast<uint8_t>(val);
467   *buf++ = static_cast<uint8_t>(val >> 8);
468   *buf++ = static_cast<uint8_t>(val >> 16);
469   *buf++ = static_cast<uint8_t>(val >> 24);
470   *buf++ = static_cast<uint8_t>(val >> 32);
471   *buf++ = static_cast<uint8_t>(val >> 40);
472   *buf++ = static_cast<uint8_t>(val >> 48);
473   *buf++ = static_cast<uint8_t>(val >> 56);
474 }
475 
GetSample(Thread * thread,void * arg)476 static void GetSample(Thread* thread, void* arg) REQUIRES_SHARED(Locks::mutator_lock_) {
477   std::vector<ArtMethod*>* const stack_trace = Trace::AllocStackTrace();
478   StackVisitor::WalkStack(
479       [&](const art::StackVisitor* stack_visitor) REQUIRES_SHARED(Locks::mutator_lock_) {
480         ArtMethod* m = stack_visitor->GetMethod();
481         // Ignore runtime frames (in particular callee save).
482         if (!m->IsRuntimeMethod()) {
483           stack_trace->push_back(m);
484         }
485         return true;
486       },
487       thread,
488       /* context= */ nullptr,
489       art::StackVisitor::StackWalkKind::kIncludeInlinedFrames);
490   Trace* the_trace = reinterpret_cast<Trace*>(arg);
491   the_trace->CompareAndUpdateStackTrace(thread, stack_trace);
492 }
493 
ClearThreadStackTraceAndClockBase(Thread * thread,void * arg)494 static void ClearThreadStackTraceAndClockBase(Thread* thread, [[maybe_unused]] void* arg) {
495   thread->SetTraceClockBase(0);
496   std::vector<ArtMethod*>* stack_trace = thread->GetStackTraceSample();
497   thread->SetStackTraceSample(nullptr);
498   delete stack_trace;
499 }
500 
CompareAndUpdateStackTrace(Thread * thread,std::vector<ArtMethod * > * stack_trace)501 void Trace::CompareAndUpdateStackTrace(Thread* thread,
502                                        std::vector<ArtMethod*>* stack_trace) {
503   CHECK_EQ(pthread_self(), sampling_pthread_);
504   std::vector<ArtMethod*>* old_stack_trace = thread->GetStackTraceSample();
505   // Update the thread's stack trace sample.
506   thread->SetStackTraceSample(stack_trace);
507   // Read timer clocks to use for all events in this trace.
508   uint32_t thread_clock_diff = 0;
509   uint64_t timestamp_counter = 0;
510   ReadClocks(thread, &thread_clock_diff, &timestamp_counter);
511   if (old_stack_trace == nullptr) {
512     // If there's no previous stack trace sample for this thread, log an entry event for all
513     // methods in the trace.
514     for (auto rit = stack_trace->rbegin(); rit != stack_trace->rend(); ++rit) {
515       LogMethodTraceEvent(thread, *rit, kTraceMethodEnter, thread_clock_diff, timestamp_counter);
516     }
517   } else {
518     // If there's a previous stack trace for this thread, diff the traces and emit entry and exit
519     // events accordingly.
520     auto old_rit = old_stack_trace->rbegin();
521     auto rit = stack_trace->rbegin();
522     // Iterate bottom-up over both traces until there's a difference between them.
523     while (old_rit != old_stack_trace->rend() && rit != stack_trace->rend() && *old_rit == *rit) {
524       old_rit++;
525       rit++;
526     }
527     // Iterate top-down over the old trace until the point where they differ, emitting exit events.
528     for (auto old_it = old_stack_trace->begin(); old_it != old_rit.base(); ++old_it) {
529       LogMethodTraceEvent(thread, *old_it, kTraceMethodExit, thread_clock_diff, timestamp_counter);
530     }
531     // Iterate bottom-up over the new trace from the point where they differ, emitting entry events.
532     for (; rit != stack_trace->rend(); ++rit) {
533       LogMethodTraceEvent(thread, *rit, kTraceMethodEnter, thread_clock_diff, timestamp_counter);
534     }
535     FreeStackTrace(old_stack_trace);
536   }
537 }
538 
RunSamplingThread(void * arg)539 void* Trace::RunSamplingThread(void* arg) {
540   Runtime* runtime = Runtime::Current();
541   intptr_t interval_us = reinterpret_cast<intptr_t>(arg);
542   CHECK_GE(interval_us, 0);
543   CHECK(runtime->AttachCurrentThread("Sampling Profiler", true, runtime->GetSystemThreadGroup(),
544                                      !runtime->IsAotCompiler()));
545 
546   while (true) {
547     usleep(interval_us);
548     ScopedTrace trace("Profile sampling");
549     Thread* self = Thread::Current();
550     Trace* the_trace;
551     {
552       MutexLock mu(self, *Locks::trace_lock_);
553       the_trace = the_trace_;
554       if (the_trace_->stop_tracing_) {
555         break;
556       }
557     }
558     {
559       // Avoid a deadlock between a thread doing garbage collection
560       // and the profile sampling thread, by blocking GC when sampling
561       // thread stacks (see b/73624630).
562       gc::ScopedGCCriticalSection gcs(self,
563                                       art::gc::kGcCauseInstrumentation,
564                                       art::gc::kCollectorTypeInstrumentation);
565       ScopedSuspendAll ssa(__FUNCTION__);
566       MutexLock mu(self, *Locks::thread_list_lock_);
567       runtime->GetThreadList()->ForEach(GetSample, the_trace);
568     }
569   }
570 
571   runtime->DetachCurrentThread();
572   return nullptr;
573 }
574 
575 // Visitor used to record all methods currently loaded in the runtime. This is done at the start of
576 // method tracing.
577 class RecordMethodInfoClassVisitor : public ClassVisitor {
578  public:
RecordMethodInfoClassVisitor(Trace * trace)579   explicit RecordMethodInfoClassVisitor(Trace* trace)
580       : trace_(trace), offset_(0), buffer_(nullptr) {}
581 
operator ()(ObjPtr<mirror::Class> klass)582   bool operator()(ObjPtr<mirror::Class> klass) override REQUIRES(Locks::mutator_lock_) {
583     // We use a buffer to aggregate method infos from different classes to avoid multiple small
584     // writes to the file. The RecordMethodInfo handles the overflows by enqueueing a task to
585     // flush the old buffer and allocates a new buffer.
586     trace_->GetTraceWriter()->RecordMethodInfoV2(klass.Ptr(), &buffer_, &offset_);
587     return true;  // Visit all classes.
588   }
589 
FlushBuffer()590   void FlushBuffer() REQUIRES_SHARED(Locks::mutator_lock_) {
591     // Flushes any data in the buffer to the file. Called at the end of visit to write any
592     // remaining data to the file.
593     trace_->GetTraceWriter()->AddMethodInfoWriteTask(
594         buffer_, offset_, Thread::Current()->GetTid(), true);
595   }
596 
597  private:
598   Trace* const trace_;
599   // Use a buffer to aggregate method infos of all classes to avoid multiple smaller writes to file.
600   size_t offset_ = 0;
601   uint8_t* buffer_ = nullptr;
602 };
603 
ClassPrepare(Handle<mirror::Class> temp_klass,Handle<mirror::Class> klass)604 void Trace::ClassPrepare([[maybe_unused]] Handle<mirror::Class> temp_klass,
605                          Handle<mirror::Class> klass) {
606   MutexLock mu(Thread::Current(), *Locks::trace_lock_);
607   if (the_trace_ == nullptr) {
608     return;
609   }
610   size_t offset = 0;
611   size_t tid = Thread::Current()->GetTid();
612   uint8_t* buffer = nullptr;
613   // Write the method infos of the newly loaded class.
614   the_trace_->GetTraceWriter()->RecordMethodInfoV2(klass.Get(), &buffer, &offset);
615   the_trace_->GetTraceWriter()->AddMethodInfoWriteTask(buffer, offset, tid, true);
616 }
617 
AddMethodInfoWriteTask(uint8_t * buffer,size_t offset,size_t tid,bool release)618 uint8_t* TraceWriter::AddMethodInfoWriteTask(uint8_t* buffer,
619                                              size_t offset,
620                                              size_t tid,
621                                              bool release) {
622   int old_index = GetMethodTraceIndex(reinterpret_cast<uintptr_t*>(buffer));
623   uintptr_t* new_buf = nullptr;
624   thread_pool_->AddTask(
625       Thread::Current(),
626       new MethodInfoWriterTask(this, old_index, reinterpret_cast<uintptr_t*>(buffer), offset));
627   if (!release) {
628     new_buf = AcquireTraceBuffer(tid);
629   }
630   return reinterpret_cast<uint8_t*>(new_buf);
631 }
632 
WriteToFile(uint8_t * buffer,size_t offset)633 void TraceWriter::WriteToFile(uint8_t* buffer, size_t offset) {
634   MutexLock mu(Thread::Current(), trace_writer_lock_);
635   if (!trace_file_->WriteFully(buffer, offset)) {
636     PLOG(WARNING) << "Failed streaming a tracing event.";
637   }
638 }
639 
RecordMethodInfoV2(mirror::Class * klass,uint8_t ** buffer,size_t * offset)640 void TraceWriter::RecordMethodInfoV2(mirror::Class* klass, uint8_t** buffer, size_t* offset) {
641   // For the v1 format, we record methods when we first execute them.
642   DCHECK_EQ(trace_format_version_, Trace::kFormatV2);
643 
644   auto methods = klass->GetMethods(kRuntimePointerSize);
645   if (methods.empty()) {
646     return;
647   }
648 
649   size_t tid = Thread::Current()->GetTid();
650   size_t buffer_size = kPerThreadBufSize * sizeof(uintptr_t);
651   size_t index = *offset;
652   uint8_t* buf = *buffer;
653   if (buf == nullptr) {
654     buf = reinterpret_cast<uint8_t*>(AcquireTraceBuffer(tid));
655   }
656 
657   std::string class_name_current = klass->PrettyDescriptor();
658   const char* source_file_current = klass->GetSourceFile();
659   for (ArtMethod& method : klass->GetMethods(kRuntimePointerSize)) {
660     if (!method.IsInvokable()) {
661       continue;
662     }
663 
664     std::string class_name;
665     const char* source_file;
666     if (method.IsCopied()) {
667       // For copied methods use method's declaring class which may not be the current class.
668       class_name = method.GetDeclaringClass()->PrettyDescriptor();
669       source_file = method.GetDeclaringClass()->GetSourceFile();
670     } else {
671       DCHECK(klass == method.GetDeclaringClass());
672       class_name = class_name_current;
673       source_file = source_file_current;
674     }
675     int class_name_len = class_name.length();
676     int source_file_len = strlen(source_file);
677 
678     uint64_t method_id = reinterpret_cast<uint64_t>(&method);
679     // TODO(mythria): Change how we report method infos in V2 to reduce the
680     // repetition of the information about class and the source file.
681     const char* name = method.GetName();
682     int name_len = strlen(name);
683     std::string signature = method.GetSignature().ToString();
684     int signature_len = signature.length();
685     // We need 3 tabs in between and a \n at the end and hence 4 additional characters.
686     int method_info_length = class_name_len + name_len + signature_len + source_file_len + 4;
687     // 1 byte header + 8 bytes method id + 2 bytes method_info_length
688     int header_length = 11;
689     if (index + header_length + method_info_length >= buffer_size) {
690       buf = AddMethodInfoWriteTask(buf, index, tid, false);
691       index = 0;
692     }
693     // Write the header to the buffer
694     buf[index] = kMethodInfoHeaderV2;
695     Append8LE(buf + index + 1, method_id);
696     Append2LE(buf + index + 9, method_info_length);
697     index += header_length;
698 
699     // Copy method line into the buffer
700     memcpy(buf + index, class_name.c_str(), class_name_len);
701     buf[index + class_name_len] = '\t';
702     index += class_name_len + 1;
703     memcpy(buf + index, name, name_len);
704     buf[index + name_len] = '\t';
705     index += name_len + 1;
706     memcpy(buf + index, signature.c_str(), signature_len);
707     buf[index + signature_len] = '\t';
708     index += signature_len + 1;
709     memcpy(buf + index, source_file, source_file_len);
710     buf[index + source_file_len] = '\n';
711     index += source_file_len + 1;
712   }
713   *offset = index;
714   *buffer = buf;
715 }
716 
Start(const char * trace_filename,size_t buffer_size,int flags,TraceOutputMode output_mode,TraceMode trace_mode,int interval_us)717 void Trace::Start(const char* trace_filename,
718                   size_t buffer_size,
719                   int flags,
720                   TraceOutputMode output_mode,
721                   TraceMode trace_mode,
722                   int interval_us) {
723   std::unique_ptr<File> file(OS::CreateEmptyFileWriteOnly(trace_filename));
724   if (file == nullptr) {
725     std::string msg = android::base::StringPrintf("Unable to open trace file '%s'", trace_filename);
726     PLOG(ERROR) << msg;
727     ScopedObjectAccess soa(Thread::Current());
728     Thread::Current()->ThrowNewException("Ljava/lang/RuntimeException;", msg.c_str());
729     return;
730   }
731   Start(std::move(file), buffer_size, flags, output_mode, trace_mode, interval_us);
732 }
733 
Start(int trace_fd,size_t buffer_size,int flags,TraceOutputMode output_mode,TraceMode trace_mode,int interval_us)734 void Trace::Start(int trace_fd,
735                   size_t buffer_size,
736                   int flags,
737                   TraceOutputMode output_mode,
738                   TraceMode trace_mode,
739                   int interval_us) {
740   if (trace_fd < 0) {
741     std::string msg = android::base::StringPrintf("Unable to start tracing with invalid fd %d",
742                                                   trace_fd);
743     LOG(ERROR) << msg;
744     ScopedObjectAccess soa(Thread::Current());
745     Thread::Current()->ThrowNewException("Ljava/lang/RuntimeException;", msg.c_str());
746     return;
747   }
748   std::unique_ptr<File> file(new File(trace_fd, /* path= */ "tracefile", /* check_usage= */ true));
749   Start(std::move(file), buffer_size, flags, output_mode, trace_mode, interval_us);
750 }
751 
StartDDMS(size_t buffer_size,int flags,TraceMode trace_mode,int interval_us)752 void Trace::StartDDMS(size_t buffer_size,
753                       int flags,
754                       TraceMode trace_mode,
755                       int interval_us) {
756   Start(std::unique_ptr<File>(),
757         buffer_size,
758         flags,
759         TraceOutputMode::kDDMS,
760         trace_mode,
761         interval_us);
762 }
763 
Start(std::unique_ptr<File> && trace_file_in,size_t buffer_size,int flags,TraceOutputMode output_mode,TraceMode trace_mode,int interval_us)764 void Trace::Start(std::unique_ptr<File>&& trace_file_in,
765                   size_t buffer_size,
766                   int flags,
767                   TraceOutputMode output_mode,
768                   TraceMode trace_mode,
769                   int interval_us) {
770   // We own trace_file now and are responsible for closing it. To account for error situations, use
771   // a specialized unique_ptr to ensure we close it on the way out (if it hasn't been passed to a
772   // Trace instance).
773   auto deleter = [](File* file) {
774     if (file != nullptr) {
775       file->MarkUnchecked();  // Don't deal with flushing requirements.
776       [[maybe_unused]] int result = file->Close();
777       delete file;
778     }
779   };
780   std::unique_ptr<File, decltype(deleter)> trace_file(trace_file_in.release(), deleter);
781 
782   Thread* self = Thread::Current();
783   {
784     MutexLock mu(self, *Locks::trace_lock_);
785     if (the_trace_ != nullptr) {
786       LOG(ERROR) << "Trace already in progress, ignoring this request";
787       return;
788     }
789   }
790 
791   // Check interval if sampling is enabled
792   if (trace_mode == TraceMode::kSampling && interval_us <= 0) {
793     LOG(ERROR) << "Invalid sampling interval: " << interval_us;
794     ScopedObjectAccess soa(self);
795     ThrowRuntimeException("Invalid sampling interval: %d", interval_us);
796     return;
797   }
798 
799   // Initialize the frequency of timestamp counter updates here. This is needed
800   // to get wallclock time from timestamp counter values.
801   InitializeTimestampCounters();
802 
803   Runtime* runtime = Runtime::Current();
804 
805   // Enable count of allocs if specified in the flags.
806   bool enable_stats = false;
807 
808   // Create Trace object.
809   {
810     // Suspend JIT here since we are switching runtime to debuggable. Debuggable runtimes cannot use
811     // JITed code from before so we need to invalidated all JITed code here. Enter suspend JIT scope
812     // to prevent any races with ongoing JIT compilations.
813     jit::ScopedJitSuspend suspend_jit;
814     // Required since EnableMethodTracing calls ConfigureStubs which visits class linker classes.
815     gc::ScopedGCCriticalSection gcs(self,
816                                     gc::kGcCauseInstrumentation,
817                                     gc::kCollectorTypeInstrumentation);
818     ScopedSuspendAll ssa(__FUNCTION__);
819     MutexLock mu(self, *Locks::trace_lock_);
820     if (the_trace_ != nullptr) {
821       LOG(ERROR) << "Trace already in progress, ignoring this request";
822     } else {
823       enable_stats = (flags & kTraceCountAllocs) != 0;
824       int trace_format_version = GetTraceFormatVersionFromFlags(flags);
825       the_trace_ = new Trace(trace_file.release(), buffer_size, flags, output_mode, trace_mode);
826       if (trace_format_version == Trace::kFormatV2) {
827         // Record all the methods that are currently loaded. We log all methods when any new class
828         // is loaded. This will allow us to process the trace entries without requiring a mutator
829         // lock.
830         RecordMethodInfoClassVisitor visitor(the_trace_);
831         runtime->GetClassLinker()->VisitClasses(&visitor);
832         visitor.FlushBuffer();
833       }
834       if (trace_mode == TraceMode::kSampling) {
835         CHECK_PTHREAD_CALL(pthread_create, (&sampling_pthread_, nullptr, &RunSamplingThread,
836                                             reinterpret_cast<void*>(interval_us)),
837                                             "Sampling profiler thread");
838         the_trace_->interval_us_ = interval_us;
839       } else {
840         if (!runtime->IsJavaDebuggable()) {
841           art::jit::Jit* jit = runtime->GetJit();
842           if (jit != nullptr) {
843             jit->GetCodeCache()->InvalidateAllCompiledCode();
844             jit->GetCodeCache()->TransitionToDebuggable();
845             jit->GetJitCompiler()->SetDebuggableCompilerOption(true);
846           }
847           runtime->SetRuntimeDebugState(art::Runtime::RuntimeDebugState::kJavaDebuggable);
848           runtime->GetInstrumentation()->UpdateEntrypointsForDebuggable();
849           runtime->DeoptimizeBootImage();
850         }
851         if (trace_format_version == Trace::kFormatV2) {
852           // Add ClassLoadCallback to record methods on class load.
853           runtime->GetRuntimeCallbacks()->AddClassLoadCallback(the_trace_);
854         }
855         runtime->GetInstrumentation()->AddListener(
856             the_trace_,
857             instrumentation::Instrumentation::kMethodEntered |
858                 instrumentation::Instrumentation::kMethodExited |
859                 instrumentation::Instrumentation::kMethodUnwind,
860             UseFastTraceListeners(the_trace_->GetClockSource()));
861         runtime->GetInstrumentation()->EnableMethodTracing(kTracerInstrumentationKey,
862                                                            the_trace_,
863                                                            /*needs_interpreter=*/false);
864       }
865     }
866   }
867 
868   // Can't call this when holding the mutator lock.
869   if (enable_stats) {
870     runtime->SetStatsEnabled(true);
871   }
872 }
873 
StopTracing(bool flush_entries)874 void Trace::StopTracing(bool flush_entries) {
875   Runtime* const runtime = Runtime::Current();
876   Thread* const self = Thread::Current();
877 
878   pthread_t sampling_pthread = 0U;
879   {
880     MutexLock mu(self, *Locks::trace_lock_);
881     if (the_trace_ == nullptr) {
882       LOG(ERROR) << "Trace stop requested, but no trace currently running";
883       return;
884     }
885     // Tell sampling_pthread_ to stop tracing.
886     the_trace_->stop_tracing_ = true;
887     sampling_pthread = sampling_pthread_;
888   }
889 
890   // Make sure that we join before we delete the trace since we don't want to have
891   // the sampling thread access a stale pointer. This finishes since the sampling thread exits when
892   // the_trace_ is null.
893   if (sampling_pthread != 0U) {
894     CHECK_PTHREAD_CALL(pthread_join, (sampling_pthread, nullptr), "sampling thread shutdown");
895   }
896 
897   // Wakeup any threads waiting for a buffer and abort allocating a buffer.
898   the_trace_->trace_writer_->StopTracing();
899 
900   // Make a copy of the_trace_, so it can be flushed later. We want to reset
901   // the_trace_ to nullptr in suspend all scope to prevent any races
902   Trace* the_trace = the_trace_;
903   bool stop_alloc_counting = (the_trace->flags_ & Trace::kTraceCountAllocs) != 0;
904   // Stop the trace sources adding more entries to the trace buffer and synchronise stores.
905   {
906     gc::ScopedGCCriticalSection gcs(
907         self, gc::kGcCauseInstrumentation, gc::kCollectorTypeInstrumentation);
908     jit::ScopedJitSuspend suspend_jit;
909     ScopedSuspendAll ssa(__FUNCTION__);
910 
911     if (the_trace->trace_mode_ == TraceMode::kSampling) {
912       MutexLock mu(self, *Locks::thread_list_lock_);
913       runtime->GetThreadList()->ForEach(ClearThreadStackTraceAndClockBase, nullptr);
914     } else {
915         runtime->GetRuntimeCallbacks()->RemoveClassLoadCallback(the_trace_);
916         runtime->GetInstrumentation()->RemoveListener(
917             the_trace,
918             instrumentation::Instrumentation::kMethodEntered |
919                 instrumentation::Instrumentation::kMethodExited |
920                 instrumentation::Instrumentation::kMethodUnwind,
921             UseFastTraceListeners(the_trace_->GetClockSource()));
922         runtime->GetInstrumentation()->DisableMethodTracing(kTracerInstrumentationKey);
923     }
924 
925     // Flush thread specific buffer from all threads before resetting the_trace_ to nullptr.
926     // We also flush the buffer when destroying a thread which expects the_trace_ to be valid so
927     // make sure that the per-thread buffer is reset before resetting the_trace_.
928     {
929       MutexLock mu(self, *Locks::trace_lock_);
930       MutexLock tl_lock(Thread::Current(), *Locks::thread_list_lock_);
931       // Flush the per-thread buffers and reset the trace inside the trace_lock_ to avoid any
932       // race if the thread is detaching and trying to flush the buffer too. Since we hold the
933       // trace_lock_ both here and when flushing on a thread detach only one of them will succeed
934       // in actually flushing the buffer.
935       for (Thread* thread : Runtime::Current()->GetThreadList()->GetList()) {
936         if (thread->GetMethodTraceBuffer() != nullptr) {
937           // We may have pending requests to flush the data. So just enqueue a
938           // request to flush the current buffer so all the requests are
939           // processed in order.
940           the_trace->trace_writer_->FlushBuffer(
941               thread, /* is_sync= */ false, /* free_buffer= */ true);
942         }
943       }
944       the_trace_ = nullptr;
945       sampling_pthread_ = 0U;
946     }
947   }
948 
949   // At this point, code may read buf_ as its writers are shutdown
950   // and the ScopedSuspendAll above has ensured all stores to buf_
951   // are now visible.
952   the_trace->trace_writer_->FinishTracing(the_trace->flags_, flush_entries);
953   delete the_trace;
954 
955   if (stop_alloc_counting) {
956     // Can be racy since SetStatsEnabled is not guarded by any locks.
957     runtime->SetStatsEnabled(false);
958   }
959 }
960 
RemoveListeners()961 void Trace::RemoveListeners() {
962   Thread* self = Thread::Current();
963   // This is expected to be called in SuspendAll scope.
964   DCHECK(Locks::mutator_lock_->IsExclusiveHeld(self));
965   MutexLock mu(self, *Locks::trace_lock_);
966   Runtime* runtime = Runtime::Current();
967   runtime->GetRuntimeCallbacks()->RemoveClassLoadCallback(the_trace_);
968   runtime->GetInstrumentation()->RemoveListener(
969       the_trace_,
970       instrumentation::Instrumentation::kMethodEntered |
971       instrumentation::Instrumentation::kMethodExited |
972       instrumentation::Instrumentation::kMethodUnwind,
973       UseFastTraceListeners(the_trace_->GetClockSource()));
974 }
975 
FlushThreadBuffer(Thread * self)976 void Trace::FlushThreadBuffer(Thread* self) {
977   MutexLock mu(self, *Locks::trace_lock_);
978   // Check if we still need to flush inside the trace_lock_. If we are stopping tracing it is
979   // possible we already deleted the trace and flushed the buffer too.
980   if (the_trace_ == nullptr) {
981     DCHECK_EQ(self->GetMethodTraceBuffer(), nullptr);
982     return;
983   }
984   the_trace_->trace_writer_->FlushBuffer(self, /* is_sync= */ false, /* free_buffer= */ true);
985 }
986 
ReleaseThreadBuffer(Thread * self)987 void Trace::ReleaseThreadBuffer(Thread* self) {
988   MutexLock mu(self, *Locks::trace_lock_);
989   // Check if we still need to flush inside the trace_lock_. If we are stopping tracing it is
990   // possible we already deleted the trace and flushed the buffer too.
991   if (the_trace_ == nullptr) {
992     DCHECK_EQ(self->GetMethodTraceBuffer(), nullptr);
993     return;
994   }
995   the_trace_->trace_writer_->ReleaseBufferForThread(self);
996 }
997 
Abort()998 void Trace::Abort() {
999   // Do not write anything anymore.
1000   StopTracing(/* flush_entries= */ false);
1001 }
1002 
Stop()1003 void Trace::Stop() {
1004   // Finish writing.
1005   StopTracing(/* flush_entries= */ true);
1006 }
1007 
Shutdown()1008 void Trace::Shutdown() {
1009   if (GetMethodTracingMode() != kTracingInactive) {
1010     Stop();
1011   }
1012 }
1013 
GetMethodTracingMode()1014 TracingMode Trace::GetMethodTracingMode() {
1015   MutexLock mu(Thread::Current(), *Locks::trace_lock_);
1016   if (the_trace_ == nullptr) {
1017     return kTracingInactive;
1018   } else {
1019     switch (the_trace_->trace_mode_) {
1020       case TraceMode::kSampling:
1021         return kSampleProfilingActive;
1022       case TraceMode::kMethodTracing:
1023         return kMethodTracingActive;
1024     }
1025     LOG(FATAL) << "Unreachable";
1026     UNREACHABLE();
1027   }
1028 }
1029 
TraceWriter(File * trace_file,TraceOutputMode output_mode,TraceClockSource clock_source,size_t buffer_size,int num_trace_buffers,int trace_format_version,uint32_t clock_overhead_ns)1030 TraceWriter::TraceWriter(File* trace_file,
1031                          TraceOutputMode output_mode,
1032                          TraceClockSource clock_source,
1033                          size_t buffer_size,
1034                          int num_trace_buffers,
1035                          int trace_format_version,
1036                          uint32_t clock_overhead_ns)
1037     : trace_file_(trace_file),
1038       trace_output_mode_(output_mode),
1039       clock_source_(clock_source),
1040       buf_(new uint8_t[std::max(kMinBufSize, buffer_size)]()),
1041       buffer_size_(std::max(kMinBufSize, buffer_size)),
1042       trace_format_version_(trace_format_version),
1043       start_time_(GetMicroTime(GetTimestamp())),
1044       overflow_(false),
1045       num_records_(0),
1046       clock_overhead_ns_(clock_overhead_ns),
1047       owner_tids_(num_trace_buffers),
1048       buffer_pool_lock_("tracing buffer pool lock", kDefaultMutexLevel),
1049       buffer_available_("buffer available condition", buffer_pool_lock_),
1050       num_waiters_zero_cond_("Num waiters zero", buffer_pool_lock_),
1051       num_waiters_for_buffer_(0),
1052       trace_writer_lock_("trace writer lock", LockLevel::kTracingStreamingLock) {
1053   // We initialize the start_time_ from the timestamp counter. This may not match
1054   // with the monotonic timer but we only use this time to calculate the elapsed
1055   // time from this point which should be the same for both cases.
1056   // We record monotonic time at the start of the trace, because Android Studio
1057   // fetches the monotonic timer from other places and matches these times to
1058   // construct a cpu profile. See b/318052824 for more context.
1059   uint64_t start_time_monotonic = start_time_ + (MicroTime() - GetMicroTime(GetTimestamp()));
1060   uint16_t trace_version = GetTraceVersion(clock_source_, trace_format_version_);
1061   if (output_mode == TraceOutputMode::kStreaming) {
1062     trace_version |= 0xF0U;
1063   }
1064 
1065   // Set up the beginning of the trace.
1066   if (trace_format_version_ == Trace::kFormatV1) {
1067     memset(buf_.get(), 0, kTraceHeaderLength);
1068     Append4LE(buf_.get(), kTraceMagicValue);
1069     Append2LE(buf_.get() + 4, trace_version);
1070     Append2LE(buf_.get() + 6, kTraceHeaderLength);
1071     Append8LE(buf_.get() + 8, start_time_monotonic);
1072     if (trace_version >= kTraceVersionDualClock) {
1073       uint16_t record_size = GetRecordSize(clock_source_, trace_format_version_);
1074       Append2LE(buf_.get() + 16, record_size);
1075     }
1076     static_assert(18 <= kMinBufSize, "Minimum buffer size not large enough for trace header");
1077 
1078     cur_offset_ = kTraceHeaderLength;
1079   } else {
1080     memset(buf_.get(), 0, kTraceHeaderLengthV2);
1081     Append4LE(buf_.get(), kTraceMagicValue);
1082     Append2LE(buf_.get() + 4, trace_version);
1083     Append8LE(buf_.get() + 6, start_time_monotonic);
1084     cur_offset_ = kTraceHeaderLengthV2;
1085   }
1086 
1087   if (output_mode == TraceOutputMode::kStreaming) {
1088     // Flush the header information to the file. We use a per thread buffer, so
1089     // it is easier to just write the header information directly to file.
1090     if (!trace_file_->WriteFully(buf_.get(), kTraceHeaderLength)) {
1091       PLOG(WARNING) << "Failed streaming a tracing event.";
1092     }
1093     cur_offset_ = 0;
1094   }
1095   // Thread index of 0 is a special identifier used to distinguish between trace
1096   // event entries and thread / method info entries.
1097   current_thread_index_ = 1;
1098 
1099   // Don't create threadpool for a zygote. This would cause slowdown when forking because we need
1100   // to stop and start this thread pool. Method tracing on zygote isn't a frequent use case and
1101   // it is okay to flush on the main thread in such cases.
1102   if (!Runtime::Current()->IsZygote()) {
1103     thread_pool_.reset(TraceWriterThreadPool::Create("Trace writer pool"));
1104     thread_pool_->StartWorkers(Thread::Current());
1105   }
1106 
1107   // Initialize the pool of per-thread buffers.
1108   InitializeTraceBuffers();
1109 }
1110 
Trace(File * trace_file,size_t buffer_size,int flags,TraceOutputMode output_mode,TraceMode trace_mode)1111 Trace::Trace(File* trace_file,
1112              size_t buffer_size,
1113              int flags,
1114              TraceOutputMode output_mode,
1115              TraceMode trace_mode)
1116     : flags_(flags),
1117       trace_mode_(trace_mode),
1118       clock_source_(GetClockSourceFromFlags(flags)),
1119       interval_us_(0),
1120       stop_tracing_(false) {
1121   CHECK_IMPLIES(trace_file == nullptr, output_mode == TraceOutputMode::kDDMS);
1122 
1123   int trace_format_version = GetTraceFormatVersionFromFlags(flags_);
1124   // In streaming mode, we only need a buffer big enough to store data per each
1125   // thread buffer. In non-streaming mode this is specified by the user and we
1126   // stop tracing when the buffer is full.
1127   size_t buf_size = (output_mode == TraceOutputMode::kStreaming) ?
1128                         kPerThreadBufSize * kScalingFactorEncodedEntries :
1129                         buffer_size;
1130   trace_writer_.reset(new TraceWriter(trace_file,
1131                                       output_mode,
1132                                       clock_source_,
1133                                       buf_size,
1134                                       kNumTracePoolBuffers,
1135                                       trace_format_version,
1136                                       GetClockOverheadNanoSeconds()));
1137 }
1138 
FinishTracing(int flags,bool flush_entries)1139 void TraceWriter::FinishTracing(int flags, bool flush_entries) {
1140   Thread* self = Thread::Current();
1141   if (flush_entries) {
1142     if (thread_pool_ != nullptr) {
1143       // Wait for any workers to be created. If we are stopping tracing as a part of runtime
1144       // shutdown, any unstarted workers can create problems if they try attaching while shutting
1145       // down.
1146       thread_pool_->WaitForWorkersToBeCreated();
1147       // Wait for any outstanding writer tasks to finish. Let the thread pool worker finish the
1148       // tasks to avoid any re-ordering when processing tasks.
1149       thread_pool_->Wait(self, /* do_work= */ false, /* may_hold_locks= */ true);
1150       DCHECK_EQ(thread_pool_->GetTaskCount(self), 0u);
1151       thread_pool_->StopWorkers(self);
1152     }
1153 
1154     size_t final_offset = 0;
1155     if (trace_output_mode_ != TraceOutputMode::kStreaming) {
1156       MutexLock mu(Thread::Current(), trace_writer_lock_);
1157       final_offset = cur_offset_;
1158     }
1159 
1160     // Compute elapsed time.
1161     uint64_t elapsed = GetMicroTime(GetTimestamp()) - start_time_;
1162 
1163     std::ostringstream os;
1164 
1165     os << StringPrintf("%cversion\n", kTraceTokenChar);
1166     os << StringPrintf("%d\n", GetTraceVersion(clock_source_, trace_format_version_));
1167     os << StringPrintf("data-file-overflow=%s\n", overflow_ ? "true" : "false");
1168     if (UseThreadCpuClock(clock_source_)) {
1169       if (UseWallClock(clock_source_)) {
1170         os << StringPrintf("clock=dual\n");
1171       } else {
1172         os << StringPrintf("clock=thread-cpu\n");
1173       }
1174     } else {
1175       os << StringPrintf("clock=wall\n");
1176     }
1177     os << StringPrintf("elapsed-time-usec=%" PRIu64 "\n", elapsed);
1178     if (trace_output_mode_ != TraceOutputMode::kStreaming) {
1179       os << StringPrintf("num-method-calls=%zd\n", num_records_);
1180     }
1181     os << StringPrintf("clock-call-overhead-nsec=%d\n", clock_overhead_ns_);
1182     os << StringPrintf("vm=art\n");
1183     os << StringPrintf("pid=%d\n", getpid());
1184     if ((flags & Trace::kTraceCountAllocs) != 0) {
1185       os << "alloc-count=" << Runtime::Current()->GetStat(KIND_ALLOCATED_OBJECTS) << "\n";
1186       os << "alloc-size=" << Runtime::Current()->GetStat(KIND_ALLOCATED_BYTES) << "\n";
1187       os << "gc-count=" <<  Runtime::Current()->GetStat(KIND_GC_INVOCATIONS) << "\n";
1188     }
1189 
1190     if (trace_format_version_ == Trace::kFormatV1) {
1191       os << StringPrintf("%cthreads\n", kTraceTokenChar);
1192       DumpThreadList(os);
1193       os << StringPrintf("%cmethods\n", kTraceTokenChar);
1194       DumpMethodList(os);
1195     }
1196     os << StringPrintf("%cend\n", kTraceTokenChar);
1197     std::string header(os.str());
1198 
1199     if (trace_output_mode_ == TraceOutputMode::kStreaming) {
1200       DCHECK_NE(trace_file_.get(), nullptr);
1201       // It is expected that this method is called when all other threads are suspended, so there
1202       // cannot be any writes to trace_file_ after finish tracing.
1203       // Write a special token to mark the end of trace records and the start of
1204       // trace summary.
1205       if (trace_format_version_ == Trace::kFormatV1) {
1206         uint8_t buf[7];
1207         Append2LE(buf, 0);
1208         buf[2] = kOpTraceSummary;
1209         Append4LE(buf + 3, static_cast<uint32_t>(header.length()));
1210         // Write the trace summary. The summary is identical to the file header when
1211         // the output mode is not streaming (except for methods).
1212         if (!trace_file_->WriteFully(buf, sizeof(buf)) ||
1213             !trace_file_->WriteFully(header.c_str(), header.length())) {
1214           PLOG(WARNING) << "Failed streaming a tracing event.";
1215         }
1216       } else {
1217         uint8_t buf[3];
1218         buf[0] = kSummaryHeaderV2;
1219         Append2LE(buf + 1, static_cast<uint32_t>(header.length()));
1220         // Write the trace summary. Reports information about tracing mode, number of records and
1221         // clock overhead in plain text format.
1222         if (!trace_file_->WriteFully(buf, sizeof(buf)) ||
1223             !trace_file_->WriteFully(header.c_str(), header.length())) {
1224           PLOG(WARNING) << "Failed streaming a tracing event.";
1225         }
1226       }
1227     } else {
1228       if (trace_file_.get() == nullptr) {
1229         std::vector<uint8_t> data;
1230         data.resize(header.length() + final_offset);
1231         memcpy(data.data(), header.c_str(), header.length());
1232         memcpy(data.data() + header.length(), buf_.get(), final_offset);
1233         Runtime::Current()->GetRuntimeCallbacks()->DdmPublishChunk(CHUNK_TYPE("MPSE"),
1234                                                                    ArrayRef<const uint8_t>(data));
1235       } else {
1236         if (!trace_file_->WriteFully(header.c_str(), header.length()) ||
1237             !trace_file_->WriteFully(buf_.get(), final_offset)) {
1238           std::string detail(StringPrintf("Trace data write failed: %s", strerror(errno)));
1239           PLOG(ERROR) << detail;
1240           ThrowRuntimeException("%s", detail.c_str());
1241         }
1242       }
1243     }
1244   } else {
1245     // This is only called from the child process post fork to abort the trace.
1246     // We shouldn't have any workers in the thread pool here.
1247     DCHECK_EQ(thread_pool_, nullptr);
1248   }
1249 
1250   if (trace_file_.get() != nullptr) {
1251     // Do not try to erase, so flush and close explicitly.
1252     if (flush_entries) {
1253       if (trace_file_->Flush() != 0) {
1254         PLOG(WARNING) << "Could not flush trace file.";
1255       }
1256     } else {
1257       trace_file_->MarkUnchecked();  // Do not trigger guard.
1258     }
1259     if (trace_file_->Close() != 0) {
1260       PLOG(ERROR) << "Could not close trace file.";
1261     }
1262   }
1263 }
1264 
DexPcMoved(Thread * thread,Handle<mirror::Object> this_object,ArtMethod * method,uint32_t new_dex_pc)1265 void Trace::DexPcMoved([[maybe_unused]] Thread* thread,
1266                        [[maybe_unused]] Handle<mirror::Object> this_object,
1267                        ArtMethod* method,
1268                        uint32_t new_dex_pc) {
1269   // We're not recorded to listen to this kind of event, so complain.
1270   LOG(ERROR) << "Unexpected dex PC event in tracing " << ArtMethod::PrettyMethod(method)
1271              << " " << new_dex_pc;
1272 }
1273 
FieldRead(Thread * thread,Handle<mirror::Object> this_object,ArtMethod * method,uint32_t dex_pc,ArtField * field)1274 void Trace::FieldRead([[maybe_unused]] Thread* thread,
1275                       [[maybe_unused]] Handle<mirror::Object> this_object,
1276                       ArtMethod* method,
1277                       uint32_t dex_pc,
1278                       [[maybe_unused]] ArtField* field) REQUIRES_SHARED(Locks::mutator_lock_) {
1279   // We're not recorded to listen to this kind of event, so complain.
1280   LOG(ERROR) << "Unexpected field read event in tracing " << ArtMethod::PrettyMethod(method)
1281              << " " << dex_pc;
1282 }
1283 
FieldWritten(Thread * thread,Handle<mirror::Object> this_object,ArtMethod * method,uint32_t dex_pc,ArtField * field,const JValue & field_value)1284 void Trace::FieldWritten([[maybe_unused]] Thread* thread,
1285                          [[maybe_unused]] Handle<mirror::Object> this_object,
1286                          ArtMethod* method,
1287                          uint32_t dex_pc,
1288                          [[maybe_unused]] ArtField* field,
1289                          [[maybe_unused]] const JValue& field_value)
1290     REQUIRES_SHARED(Locks::mutator_lock_) {
1291   // We're not recorded to listen to this kind of event, so complain.
1292   LOG(ERROR) << "Unexpected field write event in tracing " << ArtMethod::PrettyMethod(method)
1293              << " " << dex_pc;
1294 }
1295 
MethodEntered(Thread * thread,ArtMethod * method)1296 void Trace::MethodEntered(Thread* thread, ArtMethod* method) {
1297   uint32_t thread_clock_diff = 0;
1298   uint64_t timestamp_counter = 0;
1299   ReadClocks(thread, &thread_clock_diff, &timestamp_counter);
1300   LogMethodTraceEvent(thread, method, kTraceMethodEnter, thread_clock_diff, timestamp_counter);
1301 }
1302 
MethodExited(Thread * thread,ArtMethod * method,instrumentation::OptionalFrame frame,JValue & return_value)1303 void Trace::MethodExited(Thread* thread,
1304                          ArtMethod* method,
1305                          [[maybe_unused]] instrumentation::OptionalFrame frame,
1306                          [[maybe_unused]] JValue& return_value) {
1307   uint32_t thread_clock_diff = 0;
1308   uint64_t timestamp_counter = 0;
1309   ReadClocks(thread, &thread_clock_diff, &timestamp_counter);
1310   LogMethodTraceEvent(thread, method, kTraceMethodExit, thread_clock_diff, timestamp_counter);
1311 }
1312 
MethodUnwind(Thread * thread,ArtMethod * method,uint32_t dex_pc)1313 void Trace::MethodUnwind(Thread* thread, ArtMethod* method, [[maybe_unused]] uint32_t dex_pc) {
1314   uint32_t thread_clock_diff = 0;
1315   uint64_t timestamp_counter = 0;
1316   ReadClocks(thread, &thread_clock_diff, &timestamp_counter);
1317   LogMethodTraceEvent(thread, method, kTraceUnroll, thread_clock_diff, timestamp_counter);
1318 }
1319 
ExceptionThrown(Thread * thread,Handle<mirror::Throwable> exception_object)1320 void Trace::ExceptionThrown([[maybe_unused]] Thread* thread,
1321                             [[maybe_unused]] Handle<mirror::Throwable> exception_object)
1322     REQUIRES_SHARED(Locks::mutator_lock_) {
1323   LOG(ERROR) << "Unexpected exception thrown event in tracing";
1324 }
1325 
ExceptionHandled(Thread * thread,Handle<mirror::Throwable> exception_object)1326 void Trace::ExceptionHandled([[maybe_unused]] Thread* thread,
1327                              [[maybe_unused]] Handle<mirror::Throwable> exception_object)
1328     REQUIRES_SHARED(Locks::mutator_lock_) {
1329   LOG(ERROR) << "Unexpected exception thrown event in tracing";
1330 }
1331 
Branch(Thread *,ArtMethod * method,uint32_t,int32_t)1332 void Trace::Branch(Thread* /*thread*/, ArtMethod* method,
1333                    uint32_t /*dex_pc*/, int32_t /*dex_pc_offset*/)
1334       REQUIRES_SHARED(Locks::mutator_lock_) {
1335   LOG(ERROR) << "Unexpected branch event in tracing" << ArtMethod::PrettyMethod(method);
1336 }
1337 
WatchedFramePop(Thread * self,const ShadowFrame & frame)1338 void Trace::WatchedFramePop([[maybe_unused]] Thread* self,
1339                             [[maybe_unused]] const ShadowFrame& frame) {
1340   LOG(ERROR) << "Unexpected WatchedFramePop event in tracing";
1341 }
1342 
ReadClocks(Thread * thread,uint32_t * thread_clock_diff,uint64_t * timestamp_counter)1343 void Trace::ReadClocks(Thread* thread, uint32_t* thread_clock_diff, uint64_t* timestamp_counter) {
1344   if (UseThreadCpuClock(clock_source_)) {
1345     uint64_t clock_base = thread->GetTraceClockBase();
1346     if (UNLIKELY(clock_base == 0)) {
1347       // First event, record the base time in the map.
1348       uint64_t time = thread->GetCpuMicroTime();
1349       thread->SetTraceClockBase(time);
1350     } else {
1351       *thread_clock_diff = thread->GetCpuMicroTime() - clock_base;
1352     }
1353   }
1354   if (UseWallClock(clock_source_)) {
1355     *timestamp_counter = GetTimestamp();
1356   }
1357 }
1358 
GetMethodLine(const std::string & method_line,uint32_t method_index)1359 std::string TraceWriter::GetMethodLine(const std::string& method_line, uint32_t method_index) {
1360   return StringPrintf("%#x\t%s", (method_index << TraceActionBits), method_line.c_str());
1361 }
1362 
GetMethodInfoLine(ArtMethod * method)1363 std::string TraceWriter::GetMethodInfoLine(ArtMethod* method) {
1364   method = method->GetInterfaceMethodIfProxy(kRuntimePointerSize);
1365   return StringPrintf("%s\t%s\t%s\t%s\n",
1366                       PrettyDescriptor(method->GetDeclaringClassDescriptor()).c_str(),
1367                       method->GetName(),
1368                       method->GetSignature().ToString().c_str(),
1369                       method->GetDeclaringClassSourceFile());
1370 }
1371 
RecordThreadInfo(Thread * thread)1372 void TraceWriter::RecordThreadInfo(Thread* thread) {
1373   // This is the first event from this thread, so first record information about the thread.
1374   std::string thread_name;
1375   thread->GetThreadName(thread_name);
1376 
1377   // In tests, we destroy VM after already detaching the current thread. We re-attach the current
1378   // thread again as a "Shutdown thread" during the process of shutting down. So don't record
1379   // information about shutdown threads since it overwrites the actual thread_name.
1380   if (thread_name.compare("Shutdown thread") == 0) {
1381     return;
1382   }
1383 
1384   MutexLock mu(Thread::Current(), trace_writer_lock_);
1385   if (trace_output_mode_ != TraceOutputMode::kStreaming) {
1386     threads_list_.Overwrite(GetThreadEncoding(thread->GetTid()), thread_name);
1387     return;
1388   }
1389 
1390   static constexpr size_t kThreadNameHeaderSize = 7;
1391   uint8_t header[kThreadNameHeaderSize];
1392   if (trace_format_version_ == Trace::kFormatV1) {
1393     Append2LE(header, 0);
1394     header[2] = kOpNewThread;
1395     Append2LE(header + 3, GetThreadEncoding(thread->GetTid()));
1396   } else {
1397     header[0] = kThreadInfoHeaderV2;
1398     Append4LE(header + 1, thread->GetTid());
1399   }
1400   DCHECK(thread_name.length() < (1 << 16));
1401   Append2LE(header + 5, static_cast<uint16_t>(thread_name.length()));
1402 
1403   if (!trace_file_->WriteFully(header, kThreadNameHeaderSize) ||
1404       !trace_file_->WriteFully(reinterpret_cast<const uint8_t*>(thread_name.c_str()),
1405                                thread_name.length())) {
1406     PLOG(WARNING) << "Failed streaming a tracing event.";
1407   }
1408 }
1409 
PreProcessTraceForMethodInfos(uintptr_t * method_trace_entries,size_t current_offset,std::unordered_map<ArtMethod *,std::string> & method_infos)1410 void TraceWriter::PreProcessTraceForMethodInfos(
1411     uintptr_t* method_trace_entries,
1412     size_t current_offset,
1413     std::unordered_map<ArtMethod*, std::string>& method_infos) {
1414   // Compute the method infos before we process the entries. We don't want to assign an encoding
1415   // for the method here. The expectation is that once we assign a method id we write it to the
1416   // file before any other thread can see the method id. So we should assign method encoding while
1417   // holding the trace_writer_lock_ and not release it till we flush the method info to the file. We
1418   // don't want to flush entries to file while holding the mutator lock. We need the mutator lock to
1419   // get method info. So we just precompute method infos without assigning a method encoding here.
1420   // There may be a race and multiple threads computing the method info but only one of them would
1421   // actually put into the method_id_map_.
1422   MutexLock mu(Thread::Current(), trace_writer_lock_);
1423   size_t num_entries = GetNumEntries(clock_source_);
1424   DCHECK_EQ((kPerThreadBufSize - current_offset) % num_entries, 0u);
1425   for (size_t entry_index = kPerThreadBufSize; entry_index != current_offset;) {
1426     entry_index -= num_entries;
1427     uintptr_t method_and_action = method_trace_entries[entry_index];
1428     ArtMethod* method = reinterpret_cast<ArtMethod*>(method_and_action & kMaskTraceAction);
1429     if (!HasMethodEncoding(method) && method_infos.find(method) == method_infos.end()) {
1430       method_infos.emplace(method, std::move(GetMethodInfoLine(method)));
1431     }
1432   }
1433 }
1434 
RecordMethodInfoV1(const std::string & method_info_line,uint64_t method_id)1435 void TraceWriter::RecordMethodInfoV1(const std::string& method_info_line, uint64_t method_id) {
1436   // Write a special block with the name.
1437   std::string method_line;
1438   size_t header_size;
1439   static constexpr size_t kMethodNameHeaderSize = 5;
1440   DCHECK_LT(kMethodNameHeaderSize, kPerThreadBufSize);
1441   uint8_t method_header[kMethodNameHeaderSize];
1442   uint16_t method_line_length = static_cast<uint16_t>(method_line.length());
1443   DCHECK(method_line.length() < (1 << 16));
1444   // Write a special block with the name.
1445   Append2LE(method_header, 0);
1446   method_header[2] = kOpNewMethod;
1447   method_line = GetMethodLine(method_info_line, method_id);
1448   method_line_length = static_cast<uint16_t>(method_line.length());
1449   Append2LE(method_header + 3, method_line_length);
1450   header_size = kMethodNameHeaderSize;
1451 
1452   const uint8_t* ptr = reinterpret_cast<const uint8_t*>(method_line.c_str());
1453   if (!trace_file_->WriteFully(method_header, header_size) ||
1454       !trace_file_->WriteFully(ptr, method_line_length)) {
1455     PLOG(WARNING) << "Failed streaming a tracing event.";
1456   }
1457 }
1458 
FlushAllThreadBuffers()1459 void TraceWriter::FlushAllThreadBuffers() {
1460   ScopedThreadStateChange stsc(Thread::Current(), ThreadState::kSuspended);
1461   ScopedSuspendAll ssa(__FUNCTION__);
1462   {
1463     MutexLock mu(Thread::Current(), *Locks::thread_list_lock_);
1464     for (Thread* thread : Runtime::Current()->GetThreadList()->GetList()) {
1465       if (thread->GetMethodTraceBuffer() != nullptr) {
1466         FlushBuffer(thread, /* is_sync= */ true, /* free_buffer= */ false);
1467         // We cannot flush anynore data, so just break.
1468         if (overflow_) {
1469           break;
1470         }
1471       }
1472     }
1473   }
1474   Trace::RemoveListeners();
1475   return;
1476 }
1477 
PrepareBufferForNewEntries(Thread * thread)1478 uintptr_t* TraceWriter::PrepareBufferForNewEntries(Thread* thread) {
1479   if (trace_output_mode_ == TraceOutputMode::kStreaming) {
1480     // In streaming mode, just flush the per-thread buffer and reuse the
1481     // existing buffer for new entries.
1482     FlushBuffer(thread, /* is_sync= */ false, /* free_buffer= */ false);
1483     DCHECK_EQ(overflow_, false);
1484   } else {
1485     // For non-streaming mode, flush all the threads to check if we have space in the common
1486     // buffer to record any future events.
1487     FlushAllThreadBuffers();
1488   }
1489   if (overflow_) {
1490     return nullptr;
1491   }
1492   return thread->GetMethodTraceBuffer();
1493 }
1494 
InitializeTraceBuffers()1495 void TraceWriter::InitializeTraceBuffers() {
1496   for (size_t i = 0; i < owner_tids_.size(); i++) {
1497     owner_tids_[i].store(0);
1498   }
1499 
1500   trace_buffer_.reset(new uintptr_t[kPerThreadBufSize * owner_tids_.size()]);
1501   CHECK(trace_buffer_.get() != nullptr);
1502 }
1503 
AcquireTraceBuffer(size_t tid)1504 uintptr_t* TraceWriter::AcquireTraceBuffer(size_t tid) {
1505   Thread* self = Thread::Current();
1506 
1507   // Fast path, check if there is a free buffer in the pool
1508   for (size_t index = 0; index < owner_tids_.size(); index++) {
1509     size_t owner = 0;
1510     if (owner_tids_[index].compare_exchange_strong(owner, tid)) {
1511       return trace_buffer_.get() + index * kPerThreadBufSize;
1512     }
1513   }
1514 
1515   // Increment a counter so we know how many threads are potentially suspended in the tracing code.
1516   // We need this when stopping tracing. We need to wait for all these threads to finish executing
1517   // this code so we can safely delete the trace related data.
1518   num_waiters_for_buffer_.fetch_add(1);
1519 
1520   uintptr_t* buffer = nullptr;
1521   // If finish_tracing_ is set to true we shouldn't suspend ourselves. So check for finish_tracing_
1522   // before the thread suspension. As an example, consider the following:
1523   // T2 is looking for a free buffer in the loop above
1524   // T1 calls stop tracing -> Sets finish_tracing_ to true -> Checks that there are no waiters ->
1525   // Waiting to suspend all threads.
1526   // T2 doesn't find a buffer.
1527   // If T2 suspends before checking for finish_tracing_ there is a possibility T1 succeeds entering
1528   // SuspendAllScope while thread T2 is still in the TraceWriter code.
1529   // To avoid this, we increment the num_waiters_for_buffer and then check for finish_tracing
1530   // before suspending the thread. StopTracing sets finish_tracing_ to true first and then checks
1531   // for num_waiters_for_buffer. Both these are atomic variables and we use sequential consistency
1532   // (acquire for load and release for stores), so all threads see the updates for these variables
1533   // in the same order. That ensures we don't suspend in the tracing logic after Trace::StopTracing
1534   // has returned. This is required so that we can safely delete tracing data.
1535   if (self->IsThreadSuspensionAllowable() && !finish_tracing_.load()) {
1536     ScopedThreadSuspension sts(self, ThreadState::kSuspended);
1537     while (1) {
1538       MutexLock mu(self, buffer_pool_lock_);
1539       // Tracing is being stopped, so don't wait for a free buffer. Just return early.
1540       if (finish_tracing_.load()) {
1541         break;
1542       }
1543 
1544       // Check if there's a free buffer in the pool
1545       for (size_t index = 0; index < owner_tids_.size(); index++) {
1546         size_t owner = 0;
1547         if (owner_tids_[index].compare_exchange_strong(owner, tid)) {
1548           buffer = trace_buffer_.get() + index * kPerThreadBufSize;
1549           break;
1550         }
1551       }
1552 
1553       // Found a buffer
1554       if (buffer != nullptr) {
1555         break;
1556       }
1557 
1558       if (thread_pool_ == nullptr ||
1559           (thread_pool_->GetTaskCount(self) < num_waiters_for_buffer_.load())) {
1560         // We have fewer buffers than active threads, just allocate a new one.
1561         break;
1562       }
1563 
1564       buffer_available_.WaitHoldingLocks(self);
1565     }
1566   }
1567 
1568   // The thread is no longer in the suspend scope, so decrement the counter.
1569   num_waiters_for_buffer_.fetch_sub(1);
1570   if (num_waiters_for_buffer_.load() == 0 && finish_tracing_.load()) {
1571     MutexLock mu(self, buffer_pool_lock_);
1572     num_waiters_zero_cond_.Broadcast(self);
1573   }
1574 
1575   if (buffer == nullptr) {
1576     // Allocate a new buffer. We either don't want to wait or have too few buffers.
1577     buffer = new uintptr_t[kPerThreadBufSize];
1578     CHECK(buffer != nullptr);
1579   }
1580   return buffer;
1581 }
1582 
StopTracing()1583 void TraceWriter::StopTracing() {
1584   Thread* self = Thread::Current();
1585   MutexLock mu(self, buffer_pool_lock_);
1586   finish_tracing_.store(true);
1587   while (num_waiters_for_buffer_.load() != 0) {
1588     buffer_available_.Broadcast(self);
1589     num_waiters_zero_cond_.WaitHoldingLocks(self);
1590   }
1591 }
1592 
ReleaseBuffer(int index)1593 void TraceWriter::ReleaseBuffer(int index) {
1594   // Only the trace_writer_ thread can release the buffer.
1595   MutexLock mu(Thread::Current(), buffer_pool_lock_);
1596   if (index != -1) {
1597     owner_tids_[index].store(0);
1598   }
1599   buffer_available_.Signal(Thread::Current());
1600 }
1601 
ReleaseBufferForThread(Thread * self)1602 void TraceWriter::ReleaseBufferForThread(Thread* self) {
1603   uintptr_t* buffer = self->GetMethodTraceBuffer();
1604   int index = GetMethodTraceIndex(buffer);
1605   if (index == -1) {
1606     delete[] buffer;
1607   } else {
1608     ReleaseBuffer(index);
1609   }
1610 }
1611 
GetMethodTraceIndex(uintptr_t * current_buffer)1612 int TraceWriter::GetMethodTraceIndex(uintptr_t* current_buffer) {
1613   if (current_buffer < trace_buffer_.get() ||
1614       current_buffer > trace_buffer_.get() + (owner_tids_.size() - 1) * kPerThreadBufSize) {
1615     // This was the temporary buffer we allocated.
1616     return -1;
1617   }
1618   return (current_buffer - trace_buffer_.get()) / kPerThreadBufSize;
1619 }
1620 
FlushBuffer(Thread * thread,bool is_sync,bool release)1621 void TraceWriter::FlushBuffer(Thread* thread, bool is_sync, bool release) {
1622   uintptr_t* method_trace_entries = thread->GetMethodTraceBuffer();
1623   size_t* current_offset = thread->GetMethodTraceIndexPtr();
1624   size_t tid = thread->GetTid();
1625   DCHECK(method_trace_entries != nullptr);
1626 
1627   if (is_sync || thread_pool_ == nullptr) {
1628     std::unordered_map<ArtMethod*, std::string> method_infos;
1629     if (trace_format_version_ == Trace::kFormatV1) {
1630       PreProcessTraceForMethodInfos(method_trace_entries, *current_offset, method_infos);
1631     }
1632     FlushBuffer(method_trace_entries, *current_offset, tid, method_infos);
1633 
1634     // This is a synchronous flush, so no need to allocate a new buffer. This is used either
1635     // when the tracing has finished or in non-streaming mode.
1636     // Just reset the buffer pointer to the initial value, so we can reuse the same buffer.
1637     if (release) {
1638       thread->SetMethodTraceBuffer(nullptr);
1639       *current_offset = 0;
1640     } else {
1641       *current_offset = kPerThreadBufSize;
1642     }
1643   } else {
1644     int old_index = GetMethodTraceIndex(method_trace_entries);
1645     // The TraceWriterTask takes the ownership of the buffer and releases the buffer once the
1646     // entries are flushed.
1647     thread_pool_->AddTask(
1648         Thread::Current(),
1649         new TraceEntriesWriterTask(this, old_index, method_trace_entries, *current_offset, tid));
1650     if (release) {
1651       thread->SetMethodTraceBuffer(nullptr);
1652       *current_offset = 0;
1653     } else {
1654       thread->SetMethodTraceBuffer(AcquireTraceBuffer(tid));
1655       *current_offset = kPerThreadBufSize;
1656     }
1657   }
1658 
1659   return;
1660 }
1661 
ReadValuesFromRecord(uintptr_t * method_trace_entries,size_t record_index,MethodTraceRecord & record,bool has_thread_cpu_clock,bool has_wall_clock)1662 void TraceWriter::ReadValuesFromRecord(uintptr_t* method_trace_entries,
1663                                        size_t record_index,
1664                                        MethodTraceRecord& record,
1665                                        bool has_thread_cpu_clock,
1666                                        bool has_wall_clock) {
1667   uintptr_t method_and_action = method_trace_entries[record_index++];
1668   record.method = reinterpret_cast<ArtMethod*>(method_and_action & kMaskTraceAction);
1669   CHECK(record.method != nullptr);
1670   record.action = DecodeTraceAction(method_and_action);
1671 
1672   record.thread_cpu_time = 0;
1673   record.wall_clock_time = 0;
1674   if (has_thread_cpu_clock) {
1675     record.thread_cpu_time = method_trace_entries[record_index++];
1676   }
1677   if (has_wall_clock) {
1678     uint64_t timestamp = method_trace_entries[record_index++];
1679     if (art::kRuntimePointerSize == PointerSize::k32) {
1680       // On 32-bit architectures timestamp is stored as two 32-bit values.
1681       uint64_t high_timestamp = method_trace_entries[record_index++];
1682       timestamp = (high_timestamp << 32 | timestamp);
1683     }
1684     record.wall_clock_time = GetMicroTime(timestamp) - start_time_;
1685   }
1686 }
1687 
FlushEntriesFormatV1(uintptr_t * method_trace_entries,size_t tid,const std::unordered_map<ArtMethod *,std::string> & method_infos,size_t end_offset,size_t * current_index,uint8_t * buffer_ptr)1688 void TraceWriter::FlushEntriesFormatV1(
1689     uintptr_t* method_trace_entries,
1690     size_t tid,
1691     const std::unordered_map<ArtMethod*, std::string>& method_infos,
1692     size_t end_offset,
1693     size_t* current_index,
1694     uint8_t* buffer_ptr) {
1695   uint16_t thread_id = GetThreadEncoding(tid);
1696   bool has_thread_cpu_clock = UseThreadCpuClock(clock_source_);
1697   bool has_wall_clock = UseWallClock(clock_source_);
1698   size_t buffer_index = *current_index;
1699   size_t num_entries = GetNumEntries(clock_source_);
1700   const size_t record_size = GetRecordSize(clock_source_, trace_format_version_);
1701 
1702   for (size_t entry_index = kPerThreadBufSize; entry_index != end_offset;) {
1703     entry_index -= num_entries;
1704 
1705     MethodTraceRecord record;
1706     ReadValuesFromRecord(
1707         method_trace_entries, entry_index, record, has_thread_cpu_clock, has_wall_clock);
1708 
1709     auto [method_id, is_new_method] = GetMethodEncoding(record.method);
1710     if (is_new_method && trace_output_mode_ == TraceOutputMode::kStreaming) {
1711       RecordMethodInfoV1(method_infos.find(record.method)->second, method_id);
1712     }
1713 
1714     DCHECK_LT(buffer_index + record_size, buffer_size_);
1715     EncodeEventEntry(buffer_ptr + buffer_index,
1716                      thread_id,
1717                      method_id,
1718                      record.action,
1719                      record.thread_cpu_time,
1720                      record.wall_clock_time);
1721     buffer_index += record_size;
1722   }
1723   *current_index = buffer_index;
1724 }
1725 
FlushEntriesFormatV2(uintptr_t * method_trace_entries,size_t tid,size_t num_records,size_t * current_index,uint8_t * init_buffer_ptr)1726 void TraceWriter::FlushEntriesFormatV2(
1727     uintptr_t* method_trace_entries,
1728     size_t tid,
1729     size_t num_records,
1730     size_t* current_index,
1731     uint8_t* init_buffer_ptr) {
1732   bool has_thread_cpu_clock = UseThreadCpuClock(clock_source_);
1733   bool has_wall_clock = UseWallClock(clock_source_);
1734   size_t num_entries = GetNumEntries(clock_source_);
1735   uint32_t prev_wall_timestamp = 0;
1736   uint32_t prev_thread_timestamp = 0;
1737   uint64_t prev_method_action_encoding = 0;
1738   bool is_first_entry = true;
1739   uint8_t* current_buffer_ptr = init_buffer_ptr;
1740   uint32_t header_size = (clock_source_ == TraceClockSource::kDual) ? kEntryHeaderSizeDualClockV2 :
1741                                                                       kEntryHeaderSizeSingleClockV2;
1742 
1743   size_t entry_index = kPerThreadBufSize;
1744   for (size_t i = 0; i < num_records; i++) {
1745     entry_index -= num_entries;
1746 
1747     MethodTraceRecord record;
1748     ReadValuesFromRecord(
1749         method_trace_entries, entry_index, record, has_thread_cpu_clock, has_wall_clock);
1750 
1751     // TODO(mythria): Explore the possibility of using method pointer instead of having an encoding.
1752     // On 64-bit this means method ids would use 8 bytes but that is okay since we only encode the
1753     // full method id in the header and then encode the diff against the method id in the header.
1754     // The diff is usually expected to be small.
1755     uint64_t method_id = reinterpret_cast<uintptr_t>(record.method);
1756     uint64_t method_action_encoding = method_id | record.action;
1757 
1758     if (is_first_entry) {
1759       prev_wall_timestamp = record.wall_clock_time;
1760       prev_thread_timestamp = record.thread_cpu_time;
1761       prev_method_action_encoding = method_action_encoding;
1762       is_first_entry = false;
1763 
1764       EncodeEventBlockHeader(init_buffer_ptr,
1765                              tid,
1766                              method_action_encoding,
1767                              prev_thread_timestamp,
1768                              prev_wall_timestamp,
1769                              num_records);
1770       current_buffer_ptr += header_size;
1771     } else {
1772       int64_t method_diff = method_action_encoding - prev_method_action_encoding;
1773       current_buffer_ptr = EncodeSignedLeb128(current_buffer_ptr, method_diff);
1774       prev_method_action_encoding = method_action_encoding;
1775 
1776       if (has_wall_clock) {
1777         current_buffer_ptr =
1778             EncodeUnsignedLeb128(current_buffer_ptr, (record.wall_clock_time - prev_wall_timestamp));
1779         prev_wall_timestamp = record.wall_clock_time;
1780       }
1781 
1782       if (has_thread_cpu_clock) {
1783         current_buffer_ptr =
1784             EncodeUnsignedLeb128(current_buffer_ptr, (record.thread_cpu_time - prev_thread_timestamp));
1785         prev_thread_timestamp = record.thread_cpu_time;
1786       }
1787     }
1788   }
1789 
1790   // Update the total size of the block excluding header size.
1791   uint8_t* total_size_loc = init_buffer_ptr + header_size - 2;
1792   Append2LE(total_size_loc, current_buffer_ptr - (init_buffer_ptr + header_size));
1793   *current_index += current_buffer_ptr - init_buffer_ptr;
1794 }
1795 
FlushBuffer(uintptr_t * method_trace_entries,size_t current_offset,size_t tid,const std::unordered_map<ArtMethod *,std::string> & method_infos)1796 void TraceWriter::FlushBuffer(uintptr_t* method_trace_entries,
1797                               size_t current_offset,
1798                               size_t tid,
1799                               const std::unordered_map<ArtMethod*, std::string>& method_infos) {
1800   // Take a trace_writer_lock_ to serialize writes across threads. We also need to allocate a unique
1801   // method id for each method. We do that by maintaining a map from id to method for each newly
1802   // seen method. trace_writer_lock_ is required to serialize these.
1803   MutexLock mu(Thread::Current(), trace_writer_lock_);
1804   size_t current_index = 0;
1805   uint8_t* buffer_ptr = buf_.get();
1806   size_t buffer_size = buffer_size_;
1807 
1808   size_t num_entries = GetNumEntries(clock_source_);
1809   size_t num_records = (kPerThreadBufSize - current_offset) / num_entries;
1810   DCHECK_EQ((kPerThreadBufSize - current_offset) % num_entries, 0u);
1811   const size_t record_size = GetRecordSize(clock_source_, trace_format_version_);
1812   DCHECK_LT(record_size, kPerThreadBufSize);
1813 
1814   if (trace_output_mode_ != TraceOutputMode::kStreaming) {
1815     // In non-streaming mode we only flush to file at the end, so retain the earlier data. If the
1816     // buffer is full we don't process any more entries.
1817     current_index = cur_offset_;
1818 
1819     // Check if there is sufficient place in the buffer for non-streaming case. If not return early.
1820     if (cur_offset_ + record_size * num_records >= buffer_size) {
1821       overflow_ = true;
1822       return;
1823     }
1824   }
1825   num_records_ += num_records;
1826 
1827   DCHECK_GT(buffer_size_, record_size * num_entries);
1828   if (trace_format_version_ == Trace::kFormatV1) {
1829     FlushEntriesFormatV1(
1830         method_trace_entries, tid, method_infos, current_offset, &current_index, buffer_ptr);
1831   } else {
1832     FlushEntriesFormatV2(method_trace_entries, tid, num_records, &current_index, buffer_ptr);
1833   }
1834 
1835   if (trace_output_mode_ == TraceOutputMode::kStreaming) {
1836     // Flush the contents of buffer to file.
1837     if (!trace_file_->WriteFully(buffer_ptr, current_index)) {
1838       PLOG(WARNING) << "Failed streaming a tracing event.";
1839     }
1840   } else {
1841     // In non-streaming mode, we keep the data in the buffer and write to the
1842     // file when tracing has stopped. Just updated the offset of the buffer.
1843     cur_offset_ = current_index;
1844   }
1845   return;
1846 }
1847 
LogMethodTraceEvent(Thread * thread,ArtMethod * method,TraceAction action,uint32_t thread_clock_diff,uint64_t timestamp_counter)1848 void Trace::LogMethodTraceEvent(Thread* thread,
1849                                 ArtMethod* method,
1850                                 TraceAction action,
1851                                 uint32_t thread_clock_diff,
1852                                 uint64_t timestamp_counter) {
1853   // This method is called in both tracing modes (method and sampling). In sampling mode, this
1854   // method is only called by the sampling thread. In method tracing mode, it can be called
1855   // concurrently.
1856 
1857   uintptr_t* method_trace_buffer = thread->GetMethodTraceBuffer();
1858   size_t* current_index = thread->GetMethodTraceIndexPtr();
1859   // Initialize the buffer lazily. It's just simpler to keep the creation at one place.
1860   if (method_trace_buffer == nullptr) {
1861     method_trace_buffer = trace_writer_->AcquireTraceBuffer(thread->GetTid());
1862     DCHECK(method_trace_buffer != nullptr);
1863     thread->SetMethodTraceBuffer(method_trace_buffer);
1864     *current_index = kPerThreadBufSize;
1865     trace_writer_->RecordThreadInfo(thread);
1866   }
1867 
1868   if (trace_writer_->HasOverflow()) {
1869     // In non-streaming modes, we stop recoding events once the buffer is full. Just reset the
1870     // index, so we don't go to runtime for each method.
1871     *current_index = kPerThreadBufSize;
1872     return;
1873   }
1874 
1875   size_t required_entries = GetNumEntries(clock_source_);
1876   if (*current_index < required_entries) {
1877     // This returns nullptr in non-streaming mode if there's an overflow and we cannot record any
1878     // more entries. In streaming mode, it returns nullptr if it fails to allocate a new buffer.
1879     method_trace_buffer = trace_writer_->PrepareBufferForNewEntries(thread);
1880     if (method_trace_buffer == nullptr) {
1881       *current_index = kPerThreadBufSize;
1882       return;
1883     }
1884   }
1885 
1886   // Record entry in per-thread trace buffer.
1887   // Update the offset
1888   int new_entry_index = *current_index - required_entries;
1889   *current_index = new_entry_index;
1890 
1891   // Ensure we always use the non-obsolete version of the method so that entry/exit events have the
1892   // same pointer value.
1893   method = method->GetNonObsoleteMethod();
1894   method_trace_buffer[new_entry_index++] = reinterpret_cast<uintptr_t>(method) | action;
1895   if (UseThreadCpuClock(clock_source_)) {
1896     method_trace_buffer[new_entry_index++] = thread_clock_diff;
1897   }
1898   if (UseWallClock(clock_source_)) {
1899     if (art::kRuntimePointerSize == PointerSize::k32) {
1900       // On 32-bit architectures store timestamp counter as two 32-bit values.
1901       method_trace_buffer[new_entry_index++] = static_cast<uint32_t>(timestamp_counter);
1902       method_trace_buffer[new_entry_index++] = timestamp_counter >> 32;
1903     } else {
1904       method_trace_buffer[new_entry_index++] = timestamp_counter;
1905     }
1906   }
1907 }
1908 
EncodeEventEntry(uint8_t * ptr,uint16_t thread_id,uint32_t method_index,TraceAction action,uint32_t thread_clock_diff,uint32_t wall_clock_diff)1909 void TraceWriter::EncodeEventEntry(uint8_t* ptr,
1910                                    uint16_t thread_id,
1911                                    uint32_t method_index,
1912                                    TraceAction action,
1913                                    uint32_t thread_clock_diff,
1914                                    uint32_t wall_clock_diff) {
1915   static constexpr size_t kPacketSize = 14U;  // The maximum size of data in a packet.
1916   DCHECK(method_index < (1 << (32 - TraceActionBits)));
1917   uint32_t method_value = (method_index << TraceActionBits) | action;
1918   Append2LE(ptr, thread_id);
1919   Append4LE(ptr + 2, method_value);
1920   ptr += 6;
1921 
1922   if (UseThreadCpuClock(clock_source_)) {
1923     Append4LE(ptr, thread_clock_diff);
1924     ptr += 4;
1925   }
1926   if (UseWallClock(clock_source_)) {
1927     Append4LE(ptr, wall_clock_diff);
1928   }
1929   static_assert(kPacketSize == 2 + 4 + 4 + 4, "Packet size incorrect.");
1930 }
1931 
EncodeEventBlockHeader(uint8_t * ptr,uint32_t thread_id,uint64_t init_method_index,uint32_t init_thread_clock,uint32_t init_wall_clock,uint16_t num_records)1932 void TraceWriter::EncodeEventBlockHeader(uint8_t* ptr,
1933                                          uint32_t thread_id,
1934                                          uint64_t init_method_index,
1935                                          uint32_t init_thread_clock,
1936                                          uint32_t init_wall_clock,
1937                                          uint16_t num_records) {
1938   ptr[0] = kEntryHeaderV2;
1939   Append4LE(ptr + 1, thread_id);
1940   Append8LE(ptr + 5, init_method_index);
1941   ptr += 13;
1942 
1943   if (UseThreadCpuClock(clock_source_)) {
1944     Append4LE(ptr, init_thread_clock);
1945     ptr += 4;
1946   }
1947   if (UseWallClock(clock_source_)) {
1948     Append4LE(ptr, init_wall_clock);
1949     ptr += 4;
1950   }
1951   // This specifies the total number of records encoded in the block using lebs. We encode the first
1952   // entry in the header, so the block contains one less than num_records.
1953   Append2LE(ptr, num_records - 1);
1954 }
1955 
EnsureSpace(uint8_t * buffer,size_t * current_index,size_t buffer_size,size_t required_size)1956 void TraceWriter::EnsureSpace(uint8_t* buffer,
1957                               size_t* current_index,
1958                               size_t buffer_size,
1959                               size_t required_size) {
1960   if (*current_index + required_size < buffer_size) {
1961     return;
1962   }
1963 
1964   if (!trace_file_->WriteFully(buffer, *current_index)) {
1965     PLOG(WARNING) << "Failed streaming a tracing event.";
1966   }
1967   *current_index = 0;
1968 }
1969 
DumpMethodList(std::ostream & os)1970 void TraceWriter::DumpMethodList(std::ostream& os) {
1971   MutexLock mu(Thread::Current(), trace_writer_lock_);
1972   for (auto const& entry : art_method_id_map_) {
1973     os << GetMethodLine(GetMethodInfoLine(entry.first), entry.second);
1974   }
1975 }
1976 
DumpThreadList(std::ostream & os)1977 void TraceWriter::DumpThreadList(std::ostream& os) {
1978   MutexLock mu(Thread::Current(), trace_writer_lock_);
1979   for (const auto& it : threads_list_) {
1980     os << it.first << "\t" << it.second << "\n";
1981   }
1982 }
1983 
GetOutputMode()1984 TraceOutputMode Trace::GetOutputMode() {
1985   MutexLock mu(Thread::Current(), *Locks::trace_lock_);
1986   CHECK(the_trace_ != nullptr) << "Trace output mode requested, but no trace currently running";
1987   return the_trace_->trace_writer_->GetOutputMode();
1988 }
1989 
GetMode()1990 Trace::TraceMode Trace::GetMode() {
1991   MutexLock mu(Thread::Current(), *Locks::trace_lock_);
1992   CHECK(the_trace_ != nullptr) << "Trace mode requested, but no trace currently running";
1993   return the_trace_->trace_mode_;
1994 }
1995 
GetFlags()1996 int Trace::GetFlags() {
1997   MutexLock mu(Thread::Current(), *Locks::trace_lock_);
1998   CHECK(the_trace_ != nullptr) << "Trace flags requested, but no trace currently running";
1999   return the_trace_->flags_;
2000 }
2001 
GetIntervalInMillis()2002 int Trace::GetIntervalInMillis() {
2003   MutexLock mu(Thread::Current(), *Locks::trace_lock_);
2004   CHECK(the_trace_ != nullptr) << "Trace interval requested, but no trace currently running";
2005   return the_trace_->interval_us_;
2006 }
2007 
GetBufferSize()2008 size_t Trace::GetBufferSize() {
2009   MutexLock mu(Thread::Current(), *Locks::trace_lock_);
2010   CHECK(the_trace_ != nullptr) << "Trace buffer size requested, but no trace currently running";
2011   return the_trace_->trace_writer_->GetBufferSize();
2012 }
2013 
IsTracingEnabled()2014 bool Trace::IsTracingEnabled() {
2015   MutexLock mu(Thread::Current(), *Locks::trace_lock_);
2016   return the_trace_ != nullptr;
2017 }
2018 
2019 }  // namespace art
2020