1 // Copyright (c) 2013 The Chromium OS Authors. All rights reserved.
2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file.
4
5 #include "perf_parser.h"
6
7 #include <algorithm>
8 #include <cstdio>
9 #include <set>
10
11 #include "base/logging.h"
12
13 #include "address_mapper.h"
14 #include "quipper_string.h"
15 #include "perf_utils.h"
16
17 namespace quipper {
18
19 namespace {
20
21 struct EventAndTime {
22 ParsedEvent* event;
23 uint64_t time;
24 };
25
26 // Returns true if |e1| has an earlier timestamp than |e2|. The args are const
27 // pointers instead of references because of the way this function is used when
28 // calling std::stable_sort.
CompareParsedEventTimes(const std::unique_ptr<EventAndTime> & e1,const std::unique_ptr<EventAndTime> & e2)29 bool CompareParsedEventTimes(const std::unique_ptr<EventAndTime>& e1,
30 const std::unique_ptr<EventAndTime>& e2) {
31 return (e1->time < e2->time);
32 }
33
34 // Kernel MMAP entry pid appears as -1
35 const uint32_t kKernelPid = UINT32_MAX;
36
37 // Name and ID of the kernel swapper process.
38 const char kSwapperCommandName[] = "swapper";
39 const uint32_t kSwapperPid = 0;
40
IsNullBranchStackEntry(const struct branch_entry & entry)41 bool IsNullBranchStackEntry(const struct branch_entry& entry) {
42 return (!entry.from && !entry.to);
43 }
44
45 } // namespace
46
PerfParser()47 PerfParser::PerfParser()
48 : kernel_mapper_(new AddressMapper)
49 {}
50
~PerfParser()51 PerfParser::~PerfParser() {}
52
PerfParser(const PerfParser::Options & options)53 PerfParser::PerfParser(const PerfParser::Options& options) {
54 options_ = options;
55 }
56
set_options(const PerfParser::Options & options)57 void PerfParser::set_options(const PerfParser::Options& options) {
58 options_ = options;
59 }
60
ParseRawEvents()61 bool PerfParser::ParseRawEvents() {
62 process_mappers_.clear();
63 parsed_events_.resize(events_.size());
64 for (size_t i = 0; i < events_.size(); ++i) {
65 ParsedEvent& parsed_event = parsed_events_[i];
66 parsed_event.raw_event = events_[i].get();
67 }
68 MaybeSortParsedEvents();
69 if (!ProcessEvents()) {
70 return false;
71 }
72
73 if (!options_.discard_unused_events)
74 return true;
75
76 // Some MMAP/MMAP2 events' mapped regions will not have any samples. These
77 // MMAP/MMAP2 events should be dropped. |parsed_events_| should be
78 // reconstructed without these events.
79 size_t write_index = 0;
80 size_t read_index;
81 for (read_index = 0; read_index < parsed_events_.size(); ++read_index) {
82 const ParsedEvent& event = parsed_events_[read_index];
83 if ((event.raw_event->header.type == PERF_RECORD_MMAP ||
84 event.raw_event->header.type == PERF_RECORD_MMAP2) &&
85 event.num_samples_in_mmap_region == 0) {
86 continue;
87 }
88 if (read_index != write_index)
89 parsed_events_[write_index] = event;
90 ++write_index;
91 }
92 CHECK_LE(write_index, parsed_events_.size());
93 parsed_events_.resize(write_index);
94
95 // Now regenerate the sorted event list again. These are pointers to events
96 // so they must be regenerated after a resize() of the ParsedEvent vector.
97 MaybeSortParsedEvents();
98
99 return true;
100 }
101
MaybeSortParsedEvents()102 void PerfParser::MaybeSortParsedEvents() {
103 if (!(sample_type_ & PERF_SAMPLE_TIME)) {
104 parsed_events_sorted_by_time_.resize(parsed_events_.size());
105 for (size_t i = 0; i < parsed_events_.size(); ++i) {
106 parsed_events_sorted_by_time_[i] = &parsed_events_[i];
107 }
108 return;
109 }
110 std::vector<std::unique_ptr<EventAndTime>> events_and_times;
111 events_and_times.resize(parsed_events_.size());
112 for (size_t i = 0; i < parsed_events_.size(); ++i) {
113 std::unique_ptr<EventAndTime> event_and_time(new EventAndTime);
114
115 // Store the timestamp and event pointer in an array.
116 event_and_time->event = &parsed_events_[i];
117
118 struct perf_sample sample_info;
119 PerfSampleCustodian custodian(sample_info);
120 CHECK(ReadPerfSampleInfo(*parsed_events_[i].raw_event, &sample_info));
121 event_and_time->time = sample_info.time;
122
123 events_and_times[i] = std::move(event_and_time);
124 }
125 // Sort the events based on timestamp, and then populate the sorted event
126 // vector in sorted order.
127 std::stable_sort(events_and_times.begin(), events_and_times.end(),
128 CompareParsedEventTimes);
129
130 parsed_events_sorted_by_time_.resize(events_and_times.size());
131 for (unsigned int i = 0; i < events_and_times.size(); ++i) {
132 parsed_events_sorted_by_time_[i] = events_and_times[i]->event;
133 }
134 }
135
ProcessEvents()136 bool PerfParser::ProcessEvents() {
137 memset(&stats_, 0, sizeof(stats_));
138
139 stats_.did_remap = false; // Explicitly clear the remap flag.
140
141 // Pid 0 is called the swapper process. Even though perf does not record a
142 // COMM event for pid 0, we act like we did receive a COMM event for it. Perf
143 // does this itself, example:
144 // http://lxr.free-electrons.com/source/tools/perf/util/session.c#L1120
145 commands_.insert(kSwapperCommandName);
146 pidtid_to_comm_map_[std::make_pair(kSwapperPid, kSwapperPid)] =
147 &(*commands_.find(kSwapperCommandName));
148
149 // NB: Not necessarily actually sorted by time.
150 for (unsigned int i = 0; i < parsed_events_sorted_by_time_.size(); ++i) {
151 ParsedEvent& parsed_event = *parsed_events_sorted_by_time_[i];
152 event_t& event = *parsed_event.raw_event;
153 switch (event.header.type) {
154 case PERF_RECORD_SAMPLE:
155 // SAMPLE doesn't have any fields to log at a fixed,
156 // previously-endian-swapped location. This used to log ip.
157 VLOG(1) << "SAMPLE";
158 ++stats_.num_sample_events;
159
160 if (MapSampleEvent(&parsed_event)) {
161 ++stats_.num_sample_events_mapped;
162 }
163 break;
164 case PERF_RECORD_MMAP: {
165 VLOG(1) << "MMAP: " << event.mmap.filename;
166 ++stats_.num_mmap_events;
167 // Use the array index of the current mmap event as a unique identifier.
168 CHECK(MapMmapEvent(&event.mmap, i)) << "Unable to map MMAP event!";
169 // No samples in this MMAP region yet, hopefully.
170 parsed_event.num_samples_in_mmap_region = 0;
171 DSOInfo dso_info;
172 // TODO(sque): Add Build ID as well.
173 dso_info.name = event.mmap.filename;
174 dso_set_.insert(dso_info);
175 break;
176 }
177 case PERF_RECORD_MMAP2: {
178 VLOG(1) << "MMAP2: " << event.mmap2.filename;
179 ++stats_.num_mmap_events;
180 // Use the array index of the current mmap event as a unique identifier.
181 CHECK(MapMmapEvent(&event.mmap2, i)) << "Unable to map MMAP2 event!";
182 // No samples in this MMAP region yet, hopefully.
183 parsed_event.num_samples_in_mmap_region = 0;
184 DSOInfo dso_info;
185 // TODO(sque): Add Build ID as well.
186 dso_info.name = event.mmap2.filename;
187 dso_set_.insert(dso_info);
188 break;
189 }
190 case PERF_RECORD_FORK:
191 VLOG(1) << "FORK: " << event.fork.ppid << ":" << event.fork.ptid
192 << " -> " << event.fork.pid << ":" << event.fork.tid;
193 ++stats_.num_fork_events;
194 CHECK(MapForkEvent(event.fork)) << "Unable to map FORK event!";
195 break;
196 case PERF_RECORD_EXIT:
197 // EXIT events have the same structure as FORK events.
198 VLOG(1) << "EXIT: " << event.fork.ppid << ":" << event.fork.ptid;
199 ++stats_.num_exit_events;
200 break;
201 case PERF_RECORD_COMM:
202 VLOG(1) << "COMM: " << event.comm.pid << ":" << event.comm.tid << ": "
203 << event.comm.comm;
204 ++stats_.num_comm_events;
205 CHECK(MapCommEvent(event.comm));
206 commands_.insert(event.comm.comm);
207 pidtid_to_comm_map_[std::make_pair(event.comm.pid, event.comm.tid)] =
208 &(*commands_.find(event.comm.comm));
209 break;
210 case PERF_RECORD_LOST:
211 case PERF_RECORD_THROTTLE:
212 case PERF_RECORD_UNTHROTTLE:
213 case PERF_RECORD_READ:
214 case PERF_RECORD_MAX:
215 VLOG(1) << "Parsed event type: " << event.header.type
216 << ". Doing nothing.";
217 break;
218 default:
219 LOG(ERROR) << "Unknown event type: " << event.header.type;
220 return false;
221 }
222 }
223
224 // Print stats collected from parsing.
225 DLOG(INFO) << "Parser processed: "
226 << stats_.num_mmap_events << " MMAP/MMAP2 events, "
227 << stats_.num_comm_events << " COMM events, "
228 << stats_.num_fork_events << " FORK events, "
229 << stats_.num_exit_events << " EXIT events, "
230 << stats_.num_sample_events << " SAMPLE events, "
231 << stats_.num_sample_events_mapped << " of these were mapped";
232
233 float sample_mapping_percentage =
234 static_cast<float>(stats_.num_sample_events_mapped) /
235 stats_.num_sample_events * 100.;
236 float threshold = options_.sample_mapping_percentage_threshold;
237 if (sample_mapping_percentage < threshold) {
238 LOG(WARNING) << "Mapped " << static_cast<int>(sample_mapping_percentage)
239 << "% of samples, expected at least "
240 << static_cast<int>(threshold) << "%";
241 return false;
242 }
243 stats_.did_remap = options_.do_remap;
244 return true;
245 }
246
MapSampleEvent(ParsedEvent * parsed_event)247 bool PerfParser::MapSampleEvent(ParsedEvent* parsed_event) {
248 bool mapping_failed = false;
249
250 // Find the associated command.
251 if (!(sample_type_ & PERF_SAMPLE_IP && sample_type_ & PERF_SAMPLE_TID))
252 return false;
253 perf_sample sample_info;
254 PerfSampleCustodian custodian(sample_info);
255 if (!ReadPerfSampleInfo(*parsed_event->raw_event, &sample_info))
256 return false;
257 PidTid pidtid = std::make_pair(sample_info.pid, sample_info.tid);
258 const auto comm_iter = pidtid_to_comm_map_.find(pidtid);
259 if (comm_iter != pidtid_to_comm_map_.end()) {
260 parsed_event->set_command(comm_iter->second);
261 }
262
263 const uint64_t unmapped_event_ip = sample_info.ip;
264
265 // Map the event IP itself.
266 if (!MapIPAndPidAndGetNameAndOffset(sample_info.ip,
267 sample_info.pid,
268 &sample_info.ip,
269 &parsed_event->dso_and_offset)) {
270 mapping_failed = true;
271 }
272
273 if (sample_info.callchain &&
274 !MapCallchain(sample_info.ip,
275 sample_info.pid,
276 unmapped_event_ip,
277 sample_info.callchain,
278 parsed_event)) {
279 mapping_failed = true;
280 }
281
282 if (sample_info.branch_stack &&
283 !MapBranchStack(sample_info.pid,
284 sample_info.branch_stack,
285 parsed_event)) {
286 mapping_failed = true;
287 }
288
289 // Write the remapped data back to the raw event regardless of whether it was
290 // entirely successfully remapped. A single failed remap should not
291 // invalidate all the other remapped entries.
292 if (!WritePerfSampleInfo(sample_info, parsed_event->raw_event)) {
293 LOG(ERROR) << "Failed to write back remapped sample info.";
294 return false;
295 }
296
297 return !mapping_failed;
298 }
299
MapCallchain(const uint64_t ip,const uint32_t pid,const uint64_t original_event_addr,struct ip_callchain * callchain,ParsedEvent * parsed_event)300 bool PerfParser::MapCallchain(const uint64_t ip,
301 const uint32_t pid,
302 const uint64_t original_event_addr,
303 struct ip_callchain* callchain,
304 ParsedEvent* parsed_event) {
305 if (!callchain) {
306 LOG(ERROR) << "NULL call stack data.";
307 return false;
308 }
309
310 bool mapping_failed = false;
311
312 // If the callchain's length is 0, there is no work to do.
313 if (callchain->nr == 0)
314 return true;
315
316 // Keeps track of whether the current entry is kernel or user.
317 parsed_event->callchain.resize(callchain->nr);
318 int num_entries_mapped = 0;
319 for (unsigned int j = 0; j < callchain->nr; ++j) {
320 uint64_t entry = callchain->ips[j];
321 // When a callchain context entry is found, do not attempt to symbolize it.
322 if (entry >= PERF_CONTEXT_MAX) {
323 continue;
324 }
325 // The sample address has already been mapped so no need to map it.
326 if (entry == original_event_addr) {
327 callchain->ips[j] = ip;
328 continue;
329 }
330 if (!MapIPAndPidAndGetNameAndOffset(
331 entry,
332 pid,
333 &callchain->ips[j],
334 &parsed_event->callchain[num_entries_mapped++])) {
335 mapping_failed = true;
336 }
337 }
338 // Not all the entries were mapped. Trim |parsed_event->callchain| to
339 // remove unused entries at the end.
340 parsed_event->callchain.resize(num_entries_mapped);
341
342 return !mapping_failed;
343 }
344
MapBranchStack(const uint32_t pid,struct branch_stack * branch_stack,ParsedEvent * parsed_event)345 bool PerfParser::MapBranchStack(const uint32_t pid,
346 struct branch_stack* branch_stack,
347 ParsedEvent* parsed_event) {
348 if (!branch_stack) {
349 LOG(ERROR) << "NULL branch stack data.";
350 return false;
351 }
352
353 // First, trim the branch stack to remove trailing null entries.
354 size_t trimmed_size = 0;
355 for (size_t i = 0; i < branch_stack->nr; ++i) {
356 // Count the number of non-null entries before the first null entry.
357 if (IsNullBranchStackEntry(branch_stack->entries[i])) {
358 break;
359 }
360 ++trimmed_size;
361 }
362
363 // If a null entry was found, make sure all subsequent null entries are NULL
364 // as well.
365 for (size_t i = trimmed_size; i < branch_stack->nr; ++i) {
366 const struct branch_entry& entry = branch_stack->entries[i];
367 if (!IsNullBranchStackEntry(entry)) {
368 LOG(ERROR) << "Non-null branch stack entry found after null entry: "
369 << reinterpret_cast<void*>(entry.from) << " -> "
370 << reinterpret_cast<void*>(entry.to);
371 return false;
372 }
373 }
374
375 // Map branch stack addresses.
376 parsed_event->branch_stack.resize(trimmed_size);
377 for (unsigned int i = 0; i < trimmed_size; ++i) {
378 struct branch_entry& entry = branch_stack->entries[i];
379 ParsedEvent::BranchEntry& parsed_entry = parsed_event->branch_stack[i];
380 if (!MapIPAndPidAndGetNameAndOffset(entry.from,
381 pid,
382 &entry.from,
383 &parsed_entry.from)) {
384 return false;
385 }
386 if (!MapIPAndPidAndGetNameAndOffset(entry.to,
387 pid,
388 &entry.to,
389 &parsed_entry.to)) {
390 return false;
391 }
392 parsed_entry.predicted = entry.flags.predicted;
393 // Either predicted or mispredicted, not both. But don't use a CHECK here,
394 // just exit gracefully because it's a minor issue.
395 if (entry.flags.predicted == entry.flags.mispred) {
396 LOG(ERROR) << "Branch stack entry predicted and mispred flags "
397 << "both have value " << entry.flags.mispred;
398 return false;
399 }
400 }
401
402 return true;
403 }
404
MapIPAndPidAndGetNameAndOffset(uint64_t ip,uint32_t pid,uint64_t * new_ip,ParsedEvent::DSOAndOffset * dso_and_offset)405 bool PerfParser::MapIPAndPidAndGetNameAndOffset(
406 uint64_t ip,
407 uint32_t pid,
408 uint64_t* new_ip,
409 ParsedEvent::DSOAndOffset* dso_and_offset) {
410
411 // Attempt to find the synthetic address of the IP sample in this order:
412 // 1. Address space of its own process.
413 // 2. Address space of the kernel.
414
415 uint64_t mapped_addr = 0;
416
417 // Sometimes the first event we see is a SAMPLE event and we don't have the
418 // time to create an address mapper for a process. Example, for pid 0.
419 AddressMapper* mapper = GetOrCreateProcessMapper(pid).first;
420 bool mapped = mapper->GetMappedAddress(ip, &mapped_addr);
421 if (!mapped) {
422 mapper = kernel_mapper_.get();
423 mapped = mapper->GetMappedAddress(ip, &mapped_addr);
424 }
425
426 // TODO(asharif): What should we do when we cannot map a SAMPLE event?
427 if (mapped) {
428 if (dso_and_offset) {
429 uint64_t id = kuint64max;
430 CHECK(mapper->GetMappedIDAndOffset(ip, &id, &dso_and_offset->offset_));
431 // Make sure the ID points to a valid event.
432 CHECK_LE(id, parsed_events_sorted_by_time_.size());
433 ParsedEvent* parsed_event = parsed_events_sorted_by_time_[id];
434 const event_t* raw_event = parsed_event->raw_event;
435
436 DSOInfo dso_info;
437 if (raw_event->header.type == PERF_RECORD_MMAP) {
438 dso_info.name = raw_event->mmap.filename;
439 } else if (raw_event->header.type == PERF_RECORD_MMAP2) {
440 dso_info.name = raw_event->mmap2.filename;
441 } else {
442 LOG(FATAL) << "Expected MMAP or MMAP2 event";
443 }
444
445 // Find the mmap DSO filename in the set of known DSO names.
446 // TODO(sque): take build IDs into account.
447 std::set<DSOInfo>::const_iterator dso_iter = dso_set_.find(dso_info);
448 CHECK(dso_iter != dso_set_.end());
449 dso_and_offset->dso_info_ = &(*dso_iter);
450
451 ++parsed_event->num_samples_in_mmap_region;
452 }
453 if (options_.do_remap)
454 *new_ip = mapped_addr;
455 }
456 return mapped;
457 }
458
MapMmapEvent(uint64_t id,uint32_t pid,uint64_t * p_start,uint64_t * p_len,uint64_t * p_pgoff)459 bool PerfParser::MapMmapEvent(uint64_t id,
460 uint32_t pid,
461 uint64_t* p_start,
462 uint64_t* p_len,
463 uint64_t* p_pgoff)
464 {
465 // We need to hide only the real kernel addresses. However, to make things
466 // more secure, and make the mapping idempotent, we should remap all
467 // addresses, both kernel and non-kernel.
468 AddressMapper* mapper =
469 (pid == kKernelPid ? kernel_mapper_.get() :
470 GetOrCreateProcessMapper(pid).first);
471
472 uint64_t start = *p_start;
473 uint64_t len = *p_len;
474 uint64_t pgoff = *p_pgoff;
475
476 // |id| == 0 corresponds to the kernel mmap. We have several cases here:
477 //
478 // For ARM and x86, in sudo mode, pgoff == start, example:
479 // start=0x80008200
480 // pgoff=0x80008200
481 // len =0xfffffff7ff7dff
482 //
483 // For x86-64, in sudo mode, pgoff is between start and start + len. SAMPLE
484 // events lie between pgoff and pgoff + length of the real kernel binary,
485 // example:
486 // start=0x3bc00000
487 // pgoff=0xffffffffbcc00198
488 // len =0xffffffff843fffff
489 // SAMPLE events will be found after pgoff. For kernels with ASLR, pgoff will
490 // be something only visible to the root user, and will be randomized at
491 // startup. With |remap| set to true, we should hide pgoff in this case. So we
492 // normalize all SAMPLE events relative to pgoff.
493 //
494 // For non-sudo mode, the kernel will be mapped from 0 to the pointer limit,
495 // example:
496 // start=0x0
497 // pgoff=0x0
498 // len =0xffffffff
499 if (id == 0) {
500 // If pgoff is between start and len, we normalize the event by setting
501 // start to be pgoff just like how it is for ARM and x86. We also set len to
502 // be a much smaller number (closer to the real length of the kernel binary)
503 // because SAMPLEs are actually only seen between |event->pgoff| and
504 // |event->pgoff + kernel text size|.
505 if (pgoff > start && pgoff < start + len) {
506 len = len + start - pgoff;
507 start = pgoff;
508 }
509 // For kernels with ALSR pgoff is critical information that should not be
510 // revealed when |remap| is true.
511 pgoff = 0;
512 }
513
514 if (!mapper->MapWithID(start, len, id, pgoff, true)) {
515 mapper->DumpToLog();
516 return false;
517 }
518
519 if (options_.do_remap) {
520 uint64_t mapped_addr;
521 CHECK(mapper->GetMappedAddress(start, &mapped_addr));
522 *p_start = mapped_addr;
523 *p_len = len;
524 *p_pgoff = pgoff;
525 }
526 return true;
527 }
528
GetOrCreateProcessMapper(uint32_t pid,uint32_t * ppid)529 std::pair<AddressMapper*, bool> PerfParser::GetOrCreateProcessMapper(
530 uint32_t pid, uint32_t *ppid) {
531 const auto& search = process_mappers_.find(pid);
532 if (search != process_mappers_.end()) {
533 return std::make_pair(search->second.get(), false);
534 }
535
536 std::unique_ptr<AddressMapper> mapper;
537 const auto& parent_mapper = (ppid ? process_mappers_.find(*ppid) : process_mappers_.end());
538 if (parent_mapper != process_mappers_.end())
539 mapper.reset(new AddressMapper(*parent_mapper->second));
540 else
541 mapper.reset(new AddressMapper());
542
543 const auto inserted =
544 process_mappers_.insert(search, std::make_pair(pid, std::move(mapper)));
545 return std::make_pair(inserted->second.get(), true);
546 }
547
MapCommEvent(const struct comm_event & event)548 bool PerfParser::MapCommEvent(const struct comm_event& event) {
549 GetOrCreateProcessMapper(event.pid);
550 return true;
551 }
552
MapForkEvent(const struct fork_event & event)553 bool PerfParser::MapForkEvent(const struct fork_event& event) {
554 PidTid parent = std::make_pair(event.ppid, event.ptid);
555 PidTid child = std::make_pair(event.pid, event.tid);
556 if (parent != child &&
557 pidtid_to_comm_map_.find(parent) != pidtid_to_comm_map_.end()) {
558 pidtid_to_comm_map_[child] = pidtid_to_comm_map_[parent];
559 }
560
561 const uint32_t pid = event.pid;
562
563 // If the parent and child pids are the same, this is just a new thread
564 // within the same process, so don't do anything.
565 if (event.ppid == pid)
566 return true;
567
568 uint32_t ppid = event.ppid;
569 if (!GetOrCreateProcessMapper(pid, &ppid).second) {
570 DLOG(INFO) << "Found an existing process mapper with pid: " << pid;
571 }
572
573 return true;
574 }
575
576 } // namespace quipper
577