1 /*
2 * Copyright 2016 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 "jit_logger.h"
18
19 #include "arch/instruction_set.h"
20 #include "art_method-inl.h"
21 #include "base/time_utils.h"
22 #include "base/unix_file/fd_file.h"
23 #include "driver/compiler_driver.h"
24 #include "jit/jit.h"
25 #include "jit/jit_code_cache.h"
26 #include "oat_file-inl.h"
27
28 namespace art {
29 namespace jit {
30
31 #ifdef ART_TARGET_ANDROID
32 static const char* kLogPrefix = "/data/misc/trace";
33 #else
34 static const char* kLogPrefix = "/tmp";
35 #endif
36
37 // File format of perf-PID.map:
38 // +---------------------+
39 // |ADDR SIZE symbolname1|
40 // |ADDR SIZE symbolname2|
41 // |... |
42 // +---------------------+
OpenPerfMapLog()43 void JitLogger::OpenPerfMapLog() {
44 std::string pid_str = std::to_string(getpid());
45 std::string perf_filename = std::string(kLogPrefix) + "/perf-" + pid_str + ".map";
46 perf_file_.reset(OS::CreateEmptyFileWriteOnly(perf_filename.c_str()));
47 if (perf_file_ == nullptr) {
48 LOG(ERROR) << "Could not create perf file at " << perf_filename <<
49 " Are you on a user build? Perf only works on userdebug/eng builds";
50 }
51 }
52
WritePerfMapLog(JitCodeCache * code_cache,ArtMethod * method,bool osr)53 void JitLogger::WritePerfMapLog(JitCodeCache* code_cache, ArtMethod* method, bool osr) {
54 if (perf_file_ != nullptr) {
55 const void* ptr = osr ? code_cache->LookupOsrMethodHeader(method)->GetCode()
56 : method->GetEntryPointFromQuickCompiledCode();
57 size_t code_size = code_cache->GetMemorySizeOfCodePointer(ptr);
58 std::string method_name = method->PrettyMethod();
59
60 std::ostringstream stream;
61 stream << std::hex
62 << reinterpret_cast<uintptr_t>(ptr)
63 << " "
64 << code_size
65 << " "
66 << method_name
67 << std::endl;
68 std::string str = stream.str();
69 bool res = perf_file_->WriteFully(str.c_str(), str.size());
70 if (!res) {
71 LOG(WARNING) << "Failed to write jitted method info in log: write failure.";
72 }
73 } else {
74 LOG(WARNING) << "Failed to write jitted method info in log: log file doesn't exist.";
75 }
76 }
77
ClosePerfMapLog()78 void JitLogger::ClosePerfMapLog() {
79 if (perf_file_ != nullptr) {
80 UNUSED(perf_file_->Flush());
81 UNUSED(perf_file_->Close());
82 }
83 }
84
85 // File format of jit-PID.jump:
86 //
87 // +--------------------------------+
88 // | PerfJitHeader |
89 // +--------------------------------+
90 // | PerfJitCodeLoad { | .
91 // | struct PerfJitBase; | .
92 // | uint32_t process_id_; | .
93 // | uint32_t thread_id_; | .
94 // | uint64_t vma_; | .
95 // | uint64_t code_address_; | .
96 // | uint64_t code_size_; | .
97 // | uint64_t code_id_; | .
98 // | } | .
99 // +- -+ .
100 // | method_name'\0' | +--> one jitted method
101 // +- -+ .
102 // | jitted code binary | .
103 // | ... | .
104 // +--------------------------------+ .
105 // | PerfJitCodeDebugInfo { | .
106 // | struct PerfJitBase; | .
107 // | uint64_t address_; | .
108 // | uint64_t entry_count_; | .
109 // | struct PerfJitDebugEntry; | .
110 // | } | .
111 // +--------------------------------+
112 // | PerfJitCodeLoad |
113 // ...
114 //
115 struct PerfJitHeader {
116 uint32_t magic_; // Characters "JiTD"
117 uint32_t version_; // Header version
118 uint32_t size_; // Total size of header
119 uint32_t elf_mach_target_; // Elf mach target
120 uint32_t reserved_; // Reserved, currently not used
121 uint32_t process_id_; // Process ID of the JIT compiler
122 uint64_t time_stamp_; // Timestamp when the header is generated
123 uint64_t flags_; // Currently the flags are only used for choosing clock for timestamp,
124 // we set it to 0 to tell perf that we use CLOCK_MONOTONIC clock.
125 static const uint32_t kMagic = 0x4A695444; // "JiTD"
126 static const uint32_t kVersion = 1;
127 };
128
129 // Each record starts with such basic information: event type, total size, and timestamp.
130 struct PerfJitBase {
131 enum PerfJitEvent {
132 // A jitted code load event.
133 // In ART JIT, it is used to log a new method is jit compiled and committed to jit-code-cache.
134 // Note that such kLoad event supports code cache GC in ART JIT.
135 // For every kLoad event recorded in jit-PID.dump and every perf sample recorded in perf.data,
136 // each event/sample has time stamp. In case code cache GC happens in ART JIT, and a new
137 // jitted method is committed to the same address of a previously deleted method,
138 // the time stamp information can help profiler to tell whether this sample belongs to the
139 // era of the first jitted method, or does it belong to the period of the second jitted method.
140 // JitCodeCache doesn't have to record any event on 'code delete'.
141 kLoad = 0,
142
143 // A jitted code move event, i,e. a jitted code moved from one address to another address.
144 // It helps profiler to map samples to the right symbol even when the code is moved.
145 // In ART JIT, this event can help log such behavior:
146 // A jitted method is recorded in previous kLoad event, but due to some reason,
147 // it is moved to another address in jit-code-cache.
148 kMove = 1,
149
150 // Logs debug line/column information.
151 kDebugInfo = 2,
152
153 // Logs JIT VM end of life event.
154 kClose = 3
155 };
156 uint32_t event_; // Must be one of the events defined in PerfJitEvent.
157 uint32_t size_; // Total size of this event record.
158 // For example, for kLoad event, size of the event record is:
159 // sizeof(PerfJitCodeLoad) + method_name.size() + compiled code size.
160 uint64_t time_stamp_; // Timestamp for the event.
161 };
162
163 // Logs a jitted code load event (kLoad).
164 // In ART JIT, it is used to log a new method is jit compiled and commited to jit-code-cache.
165 struct PerfJitCodeLoad : PerfJitBase {
166 uint32_t process_id_; // Process ID who performs the jit code load.
167 // In ART JIT, it is the pid of the JIT compiler.
168 uint32_t thread_id_; // Thread ID who performs the jit code load.
169 // In ART JIT, it is the tid of the JIT compiler.
170 uint64_t vma_; // Address of the code section. In ART JIT, because code_address_
171 // uses absolute address, this field is 0.
172 uint64_t code_address_; // Address where is jitted code is loaded.
173 uint64_t code_size_; // Size of the jitted code.
174 uint64_t code_id_; // Unique ID for each jitted code.
175 };
176
177 // This structure is for source line/column mapping.
178 // Currently this feature is not implemented in ART JIT yet.
179 struct PerfJitDebugEntry {
180 uint64_t address_; // Code address which maps to the line/column in source.
181 uint32_t line_number_; // Source line number starting at 1.
182 uint32_t column_; // Column discriminator, default 0.
183 const char name_[0]; // Followed by null-terminated name or \0xff\0 if same as previous.
184 };
185
186 // Logs debug line information (kDebugInfo).
187 // This structure is for source line/column mapping.
188 // Currently this feature is not implemented in ART JIT yet.
189 struct PerfJitCodeDebugInfo : PerfJitBase {
190 uint64_t address_; // Starting code address which the debug info describes.
191 uint64_t entry_count_; // How many instances of PerfJitDebugEntry.
192 PerfJitDebugEntry entries_[0]; // Followed by entry_count_ instances of PerfJitDebugEntry.
193 };
194
GetElfMach()195 static uint32_t GetElfMach() {
196 #if defined(__arm__)
197 static const uint32_t kElfMachARM = 0x28;
198 return kElfMachARM;
199 #elif defined(__aarch64__)
200 static const uint32_t kElfMachARM64 = 0xB7;
201 return kElfMachARM64;
202 #elif defined(__i386__)
203 static const uint32_t kElfMachIA32 = 0x3;
204 return kElfMachIA32;
205 #elif defined(__x86_64__)
206 static const uint32_t kElfMachX64 = 0x3E;
207 return kElfMachX64;
208 #else
209 UNIMPLEMENTED(WARNING) << "Unsupported architecture in JitLogger";
210 return 0;
211 #endif
212 }
213
OpenMarkerFile()214 void JitLogger::OpenMarkerFile() {
215 int fd = jit_dump_file_->Fd();
216 // The 'perf inject' tool requires that the jit-PID.dump file
217 // must have a mmap(PROT_READ|PROT_EXEC) record in perf.data.
218 marker_address_ = mmap(nullptr, kPageSize, PROT_READ | PROT_EXEC, MAP_PRIVATE, fd, 0);
219 if (marker_address_ == MAP_FAILED) {
220 LOG(WARNING) << "Failed to create record in perf.data. JITed code profiling will not work.";
221 return;
222 }
223 }
224
CloseMarkerFile()225 void JitLogger::CloseMarkerFile() {
226 if (marker_address_ != nullptr) {
227 munmap(marker_address_, kPageSize);
228 }
229 }
230
WriteJitDumpDebugInfo()231 void JitLogger::WriteJitDumpDebugInfo() {
232 // In the future, we can add java source file line/column mapping here.
233 }
234
WriteJitDumpHeader()235 void JitLogger::WriteJitDumpHeader() {
236 PerfJitHeader header;
237
238 std::memset(&header, 0, sizeof(header));
239 header.magic_ = PerfJitHeader::kMagic;
240 header.version_ = PerfJitHeader::kVersion;
241 header.size_ = sizeof(header);
242 header.elf_mach_target_ = GetElfMach();
243 header.process_id_ = static_cast<uint32_t>(getpid());
244 header.time_stamp_ = art::NanoTime(); // CLOCK_MONOTONIC clock is required.
245 header.flags_ = 0;
246
247 bool res = jit_dump_file_->WriteFully(reinterpret_cast<const char*>(&header), sizeof(header));
248 if (!res) {
249 LOG(WARNING) << "Failed to write profiling log. The 'perf inject' tool will not work.";
250 }
251 }
252
OpenJitDumpLog()253 void JitLogger::OpenJitDumpLog() {
254 std::string pid_str = std::to_string(getpid());
255 std::string jitdump_filename = std::string(kLogPrefix) + "/jit-" + pid_str + ".dump";
256
257 jit_dump_file_.reset(OS::CreateEmptyFile(jitdump_filename.c_str()));
258 if (jit_dump_file_ == nullptr) {
259 LOG(ERROR) << "Could not create jit dump file at " << jitdump_filename <<
260 " Are you on a user build? Perf only works on userdebug/eng builds";
261 return;
262 }
263
264 OpenMarkerFile();
265
266 // Continue to write jit-PID.dump file even above OpenMarkerFile() fails.
267 // Even if that means 'perf inject' tool cannot work, developers can still use other tools
268 // to map the samples in perf.data to the information (symbol,address,code) recorded
269 // in the jit-PID.dump file, and still proceed the jitted code analysis.
270 WriteJitDumpHeader();
271 }
272
WriteJitDumpLog(JitCodeCache * code_cache,ArtMethod * method,bool osr)273 void JitLogger::WriteJitDumpLog(JitCodeCache* code_cache, ArtMethod* method, bool osr) {
274 if (jit_dump_file_ != nullptr) {
275 const void* code = osr ? code_cache->LookupOsrMethodHeader(method)->GetCode()
276 : method->GetEntryPointFromQuickCompiledCode();
277 size_t code_size = code_cache->GetMemorySizeOfCodePointer(code);
278 std::string method_name = method->PrettyMethod();
279
280 PerfJitCodeLoad jit_code;
281 std::memset(&jit_code, 0, sizeof(jit_code));
282 jit_code.event_ = PerfJitCodeLoad::kLoad;
283 jit_code.size_ = sizeof(jit_code) + method_name.size() + 1 + code_size;
284 jit_code.time_stamp_ = art::NanoTime(); // CLOCK_MONOTONIC clock is required.
285 jit_code.process_id_ = static_cast<uint32_t>(getpid());
286 jit_code.thread_id_ = static_cast<uint32_t>(art::GetTid());
287 jit_code.vma_ = 0x0;
288 jit_code.code_address_ = reinterpret_cast<uint64_t>(code);
289 jit_code.code_size_ = code_size;
290 jit_code.code_id_ = code_index_++;
291
292 // Write one complete jitted method info, including:
293 // - PerfJitCodeLoad structure
294 // - Method name
295 // - Complete generated code of this method
296 //
297 // Use UNUSED() here to avoid compiler warnings.
298 UNUSED(jit_dump_file_->WriteFully(reinterpret_cast<const char*>(&jit_code), sizeof(jit_code)));
299 UNUSED(jit_dump_file_->WriteFully(method_name.c_str(), method_name.size() + 1));
300 UNUSED(jit_dump_file_->WriteFully(code, code_size));
301
302 WriteJitDumpDebugInfo();
303 }
304 }
305
CloseJitDumpLog()306 void JitLogger::CloseJitDumpLog() {
307 if (jit_dump_file_ != nullptr) {
308 CloseMarkerFile();
309 UNUSED(jit_dump_file_->Flush());
310 UNUSED(jit_dump_file_->Close());
311 }
312 }
313
314 } // namespace jit
315 } // namespace art
316