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
17namespace quipper {
18
19namespace {
20
21struct 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.
29bool 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
35const uint32_t kKernelPid = UINT32_MAX;
36
37// Name and ID of the kernel swapper process.
38const char kSwapperCommandName[] = "swapper";
39const uint32_t kSwapperPid = 0;
40
41bool IsNullBranchStackEntry(const struct branch_entry& entry) {
42  return (!entry.from && !entry.to);
43}
44
45}  // namespace
46
47PerfParser::PerfParser()
48    : kernel_mapper_(new AddressMapper)
49{}
50
51PerfParser::~PerfParser() {}
52
53PerfParser::PerfParser(const PerfParser::Options& options) {
54  options_ = options;
55}
56
57void PerfParser::set_options(const PerfParser::Options& options) {
58  options_ = options;
59}
60
61bool 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
102void 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
136bool 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
247bool 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
300bool 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
345bool 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
405bool 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
459bool 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
529std::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
548bool PerfParser::MapCommEvent(const struct comm_event& event) {
549  GetOrCreateProcessMapper(event.pid);
550  return true;
551}
552
553bool 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