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