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