xref: /aosp_15_r20/art/runtime/trace_profile.cc (revision 795d594fd825385562da6b089ea9b2033f3abf5a)
1 /*
2  * Copyright (C) 2024 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_profile.h"
18 
19 #include "android-base/stringprintf.h"
20 #include "art_method-inl.h"
21 #include "base/leb128.h"
22 #include "base/mutex.h"
23 #include "base/unix_file/fd_file.h"
24 #include "com_android_art_flags.h"
25 #include "dex/descriptors_names.h"
26 #include "runtime.h"
27 #include "thread-current-inl.h"
28 #include "thread.h"
29 #include "thread_list.h"
30 #include "trace.h"
31 
32 namespace art_flags = com::android::art::flags;
33 
34 namespace art HIDDEN {
35 
36 using android::base::StringPrintf;
37 
38 // This specifies the maximum number of bits we need for encoding one entry. Each entry just
39 // consists of a SLEB encoded value of method and action encodig which is a maximum of
40 // sizeof(uintptr_t).
41 static constexpr size_t kMaxBytesPerTraceEntry = sizeof(uintptr_t);
42 
43 // We don't handle buffer overflows when processing the raw trace entries. We have a maximum of
44 // kAlwaysOnTraceBufSize raw entries and we need a maximum of kMaxBytesPerTraceEntry to encode
45 // each entry. To avoid overflow, we ensure that there are at least kMinBufSizeForEncodedData
46 // bytes free space in the buffer.
47 static constexpr size_t kMinBufSizeForEncodedData = kAlwaysOnTraceBufSize * kMaxBytesPerTraceEntry;
48 
49 static constexpr size_t kProfileMagicValue = 0x4C4F4D54;
50 
51 // TODO(mythria): 10 is a randomly chosen value. Tune it if required.
52 static constexpr size_t kBufSizeForEncodedData = kMinBufSizeForEncodedData * 10;
53 
54 static constexpr size_t kAlwaysOnTraceHeaderSize = 8;
55 
56 bool TraceProfiler::profile_in_progress_ = false;
57 
AllocateBuffer(Thread * thread)58 void TraceProfiler::AllocateBuffer(Thread* thread) {
59   if (!art_flags::always_enable_profile_code()) {
60     return;
61   }
62 
63   Thread* self = Thread::Current();
64   MutexLock mu(self, *Locks::trace_lock_);
65   if (!profile_in_progress_) {
66     return;
67   }
68 
69   auto buffer = new uintptr_t[kAlwaysOnTraceBufSize];
70   memset(buffer, 0, kAlwaysOnTraceBufSize * sizeof(uintptr_t));
71   thread->SetMethodTraceBuffer(buffer, kAlwaysOnTraceBufSize);
72 }
73 
Start()74 void TraceProfiler::Start() {
75   if (!art_flags::always_enable_profile_code()) {
76     LOG(ERROR) << "Feature not supported. Please build with ART_ALWAYS_ENABLE_PROFILE_CODE.";
77     return;
78   }
79 
80   Thread* self = Thread::Current();
81   MutexLock mu(self, *Locks::trace_lock_);
82   if (profile_in_progress_) {
83     LOG(ERROR) << "Profile already in progress. Ignoring this request";
84     return;
85   }
86 
87   if (Trace::IsTracingEnabledLocked()) {
88     LOG(ERROR) << "Cannot start a profile when method tracing is in progress";
89     return;
90   }
91 
92   profile_in_progress_ = true;
93 
94   ScopedSuspendAll ssa(__FUNCTION__);
95   MutexLock tl(self, *Locks::thread_list_lock_);
96   for (Thread* thread : Runtime::Current()->GetThreadList()->GetList()) {
97     auto buffer = new uintptr_t[kAlwaysOnTraceBufSize];
98     memset(buffer, 0, kAlwaysOnTraceBufSize * sizeof(uintptr_t));
99     thread->SetMethodTraceBuffer(buffer, kAlwaysOnTraceBufSize);
100   }
101 }
102 
Stop()103 void TraceProfiler::Stop() {
104   if (!art_flags::always_enable_profile_code()) {
105     LOG(ERROR) << "Feature not supported. Please build with ART_ALWAYS_ENABLE_PROFILE_CODE.";
106     return;
107   }
108 
109   Thread* self = Thread::Current();
110   MutexLock mu(self, *Locks::trace_lock_);
111   if (!profile_in_progress_) {
112     LOG(ERROR) << "No Profile in progress but a stop was requested";
113     return;
114   }
115 
116   ScopedSuspendAll ssa(__FUNCTION__);
117   MutexLock tl(self, *Locks::thread_list_lock_);
118   for (Thread* thread : Runtime::Current()->GetThreadList()->GetList()) {
119     auto buffer = thread->GetMethodTraceBuffer();
120     if (buffer != nullptr) {
121       delete[] buffer;
122       thread->SetMethodTraceBuffer(/* buffer= */ nullptr, /* offset= */ 0);
123     }
124   }
125 
126   profile_in_progress_ = false;
127 }
128 
DumpBuffer(uint32_t thread_id,uintptr_t * method_trace_entries,uint8_t * buffer,std::unordered_set<ArtMethod * > & methods)129 uint8_t* TraceProfiler::DumpBuffer(uint32_t thread_id,
130                                    uintptr_t* method_trace_entries,
131                                    uint8_t* buffer,
132                                    std::unordered_set<ArtMethod*>& methods) {
133   // Encode header at the end once we compute the number of records.
134   uint8_t* curr_buffer_ptr = buffer + kAlwaysOnTraceHeaderSize;
135 
136   int num_records = 0;
137   uintptr_t prev_method_action_encoding = 0;
138   int prev_action = -1;
139   for (size_t i = kAlwaysOnTraceBufSize - 1; i > 0; i-=1) {
140     uintptr_t method_action_encoding = method_trace_entries[i];
141     // 0 value indicates the rest of the entries are empty.
142     if (method_action_encoding == 0) {
143       break;
144     }
145 
146     int action = method_action_encoding & ~kMaskTraceAction;
147     int64_t diff;
148     if (action == TraceAction::kTraceMethodEnter) {
149       diff = method_action_encoding - prev_method_action_encoding;
150 
151       ArtMethod* method = reinterpret_cast<ArtMethod*>(method_action_encoding & kMaskTraceAction);
152       methods.insert(method);
153     } else {
154       // On a method exit, we don't record the information about method. We just need a 1 in the
155       // lsb and the method information can be derived from the last method that entered. To keep
156       // the encoded value small just add the smallest value to make the lsb one.
157       if (prev_action == TraceAction::kTraceMethodExit) {
158         diff = 0;
159       } else {
160         diff = 1;
161       }
162     }
163     curr_buffer_ptr = EncodeSignedLeb128(curr_buffer_ptr, diff);
164     num_records++;
165     prev_method_action_encoding = method_action_encoding;
166     prev_action = action;
167   }
168 
169   // Fill in header information:
170   // 1 byte of header identifier
171   // 4 bytes of thread_id
172   // 3 bytes of number of records
173   buffer[0] = kEntryHeaderV2;
174   Append4LE(buffer + 1, thread_id);
175   Append3LE(buffer + 5, num_records);
176   return curr_buffer_ptr;
177 }
178 
Dump(int fd)179 void TraceProfiler::Dump(int fd) {
180   if (!art_flags::always_enable_profile_code()) {
181     LOG(ERROR) << "Feature not supported. Please build with ART_ALWAYS_ENABLE_PROFILE_CODE.";
182     return;
183   }
184 
185   std::unique_ptr<File> trace_file(new File(fd, /*check_usage=*/true));
186   Dump(std::move(trace_file));
187 }
188 
GetMethodInfoLine(ArtMethod * method)189 std::string TraceProfiler::GetMethodInfoLine(ArtMethod* method) {
190   return StringPrintf("%s\t%s\t%s\t%s\n",
191                       PrettyDescriptor(method->GetDeclaringClassDescriptor()).c_str(),
192                       method->GetName(),
193                       method->GetSignature().ToString().c_str(),
194                       method->GetDeclaringClassSourceFile());
195 }
196 
Dump(const char * filename)197 void TraceProfiler::Dump(const char* filename) {
198   if (!art_flags::always_enable_profile_code()) {
199     LOG(ERROR) << "Feature not supported. Please build with ART_ALWAYS_ENABLE_PROFILE_CODE.";
200     return;
201   }
202 
203   std::unique_ptr<File> trace_file(OS::CreateEmptyFileWriteOnly(filename));
204   if (trace_file == nullptr) {
205     PLOG(ERROR) << "Unable to open trace file " << filename;
206     return;
207   }
208 
209   Dump(std::move(trace_file));
210 }
211 
Dump(std::unique_ptr<File> && trace_file)212 void TraceProfiler::Dump(std::unique_ptr<File>&& trace_file) {
213   Thread* self = Thread::Current();
214   std::unordered_set<ArtMethod*> traced_methods;
215   std::unordered_map<size_t, std::string> traced_threads;
216   MutexLock mu(self, *Locks::trace_lock_);
217   if (!profile_in_progress_) {
218     LOG(ERROR) << "No Profile in progress. Nothing to dump.";
219     return;
220   }
221 
222   uint8_t* buffer_ptr = new uint8_t[kBufSizeForEncodedData];
223   uint8_t* curr_buffer_ptr = buffer_ptr;
224 
225   // Add a header for the trace: 4-bits of magic value and 2-bits for the version.
226   Append4LE(curr_buffer_ptr, kProfileMagicValue);
227   Append2LE(curr_buffer_ptr + 4, /*trace_version=*/ 1);
228   curr_buffer_ptr += 6;
229 
230   ScopedSuspendAll ssa(__FUNCTION__);
231   MutexLock tl(self, *Locks::thread_list_lock_);
232   for (Thread* thread : Runtime::Current()->GetThreadList()->GetList()) {
233     auto method_trace_entries = thread->GetMethodTraceBuffer();
234     if (method_trace_entries == nullptr) {
235       continue;
236     }
237 
238     std::string thread_name;
239     thread->GetThreadName(thread_name);
240     traced_threads.emplace(thread->GetThreadId(), thread_name);
241 
242     size_t offset = curr_buffer_ptr - buffer_ptr;
243     if (offset >= kMinBufSizeForEncodedData) {
244       if (!trace_file->WriteFully(buffer_ptr, offset)) {
245         PLOG(WARNING) << "Failed streaming a tracing event.";
246       }
247       curr_buffer_ptr = buffer_ptr;
248     }
249     curr_buffer_ptr =
250         DumpBuffer(thread->GetTid(), method_trace_entries, curr_buffer_ptr, traced_methods);
251     // Reset the buffer and continue profiling. We need to set the buffer to
252     // zeroes, since we use a circular buffer and detect empty entries by
253     // checking for zeroes.
254     memset(method_trace_entries, 0, kAlwaysOnTraceBufSize * sizeof(uintptr_t));
255     // Reset the current pointer.
256     thread->SetMethodTraceBufferCurrentEntry(kAlwaysOnTraceBufSize);
257   }
258 
259   // Write any remaining data to file and close the file.
260   if (curr_buffer_ptr != buffer_ptr) {
261     if (!trace_file->WriteFully(buffer_ptr, curr_buffer_ptr - buffer_ptr)) {
262       PLOG(WARNING) << "Failed streaming a tracing event.";
263     }
264   }
265 
266   std::ostringstream os;
267   // Dump data about thread information.
268   os << "\n*threads\n";
269   for (const auto& it : traced_threads) {
270     os << it.first << "\t" << it.second << "\n";
271   }
272 
273   // Dump data about method information.
274   os << "*methods\n";
275   for (ArtMethod* method : traced_methods) {
276     uint64_t method_id = reinterpret_cast<uint64_t>(method);
277     os << method_id << "\t" << GetMethodInfoLine(method);
278   }
279 
280   os << "*end";
281 
282   std::string info = os.str();
283   if (!trace_file->WriteFully(info.c_str(), info.length())) {
284     PLOG(WARNING) << "Failed writing information to file";
285   }
286 
287   if (!trace_file->Close()) {
288     PLOG(WARNING) << "Failed to close file.";
289   }
290 }
291 
ReleaseThreadBuffer(Thread * self)292 void TraceProfiler::ReleaseThreadBuffer(Thread* self) {
293   if (!IsTraceProfileInProgress()) {
294     return;
295   }
296   // TODO(mythria): Maybe it's good to cache these and dump them when requested. For now just
297   // relese the buffer when a thread is exiting.
298   auto buffer = self->GetMethodTraceBuffer();
299   delete[] buffer;
300   self->SetMethodTraceBuffer(nullptr, 0);
301 }
302 
IsTraceProfileInProgress()303 bool TraceProfiler::IsTraceProfileInProgress() {
304   return profile_in_progress_;
305 }
306 
307 }  // namespace art
308