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