emulator/qtools/profile_trace.cpp

   1 #include <stdio.h>
   2 #include <unistd.h>
   3 #include <stdlib.h>
   4 #include <string.h>
   5 #include <inttypes.h>
   6 #include "trace_reader.h"
   7 #include "parse_options.h"
   8
   9 const int kMillion = 1000000;
  10 const int kMHz = 200 * kMillion;
  11
  12 struct symbol {
  13     int         count;      // number of times a function is executed
  14     uint64_t    elapsed;    // elapsed time for this function
  15 };
  16
  17 typedef TraceReader<symbol> TraceReaderType;
  18
  19 #include "parse_options-inl.h"
  20
  21 static const uint32_t kOffsetThreshold = 0x100000;
  22
  23 // This comparison function is called from qsort() to sort
  24 // symbols into decreasing elapsed time.
  25 int cmp_sym_elapsed(const void *a, const void *b) {
  26     const symbol_type *syma, *symb;
  27     uint64_t elapsed1, elapsed2;
  28
  29     syma = static_cast<symbol_type const *>(a);
  30     symb = static_cast<symbol_type const *>(b);
  31     elapsed1 = syma->elapsed;
  32     elapsed2 = symb->elapsed;
  33     if (elapsed1 < elapsed2)
  34         return 1;
  35     if (elapsed1 == elapsed2)
  36         return strcmp(syma->name, symb->name);
  37     return -1;
  38 }
  39
  40 void Usage(const char *program)
  41 {
  42     fprintf(stderr, "Usage: %s [options] trace_file elf_file\n", program);
  43     OptionsUsage();
  44 }
  45
  46 int main(int argc, char **argv)
  47 {
  48     ParseOptions(argc, argv);
  49     if (argc - optind != 2) {
  50         Usage(argv[0]);
  51         exit(1);
  52     }
  53
  54     char *trace_filename = argv[optind++];
  55     char *elf_file = argv[optind++];
  56     TraceReader<symbol> *trace = new TraceReader<symbol>;
  57     trace->Open(trace_filename);
  58     trace->SetDemangle(demangle);
  59     trace->ReadKernelSymbols(elf_file);
  60     trace->SetRoot(root);
  61
  62     symbol_type dummy;
  63     dummy.count = 0;
  64     dummy.elapsed = 0;
  65     symbol_type *prev_sym = &dummy;
  66     uint64_t prev_bb_time = 0;
  67     while (1) {
  68         symbol_type *sym;
  69         BBEvent event;
  70         BBEvent first_ignored_event;
  71
  72         bool eof = GetNextValidEvent(trace, &event, &first_ignored_event, &sym);
  73
  74         // Assign the elapsed time to the previous function symbol
  75         uint64_t elapsed = 0;
  76         if (first_ignored_event.time != 0)
  77             elapsed = first_ignored_event.time - prev_bb_time;
  78         else if (!eof)
  79             elapsed = event.time - prev_bb_time;
  80         prev_sym->elapsed += elapsed;
  81
  82         if (eof)
  83             break;
  84
  85         prev_bb_time = event.time;
  86         sym->count += 1;
  87         prev_sym = sym;
  88 #if 0
  89         printf("t%lld bb_num: %d, bb_addr: 0x%x func: %s, addr: 0x%x, count: %d\n",
  90                bb_time, bb_num, bb_addr, sym->name, sym->addr, sym->count);
  91 #endif
  92     }
  93
  94     int nsyms;
  95     symbol_type *syms = trace->GetSymbols(&nsyms);
  96
  97     // Sort the symbols into decreasing order of elapsed time
  98     qsort(syms, nsyms, sizeof(symbol_type), cmp_sym_elapsed);
  99
 100     // Add up all the cycles
 101     uint64_t total = 0;
 102     symbol_type *sym = syms;
 103     for (int ii = 0; ii < nsyms; ++ii, ++sym) {
 104         total += sym->elapsed;
 105     }
 106
 107     double secs = 1.0 * total / kMHz;
 108     printf("Total seconds: %.2f, total cycles: %lld, MHz: %d\n\n",
 109            secs, total, kMHz / kMillion);
 110
 111     uint64_t sum = 0;
 112     printf("Elapsed secs Elapsed cyc      %%      %%    Function\n");
 113     sym = syms;
 114     for (int ii = 0; ii < nsyms; ++ii, ++sym) {
 115         if (sym->elapsed == 0)
 116             break;
 117         sum += sym->elapsed;
 118         double per = 100.0 * sym->elapsed / total;
 119         double sum_per = 100.0 * sum / total;
 120         double secs = 1.0 * sym->elapsed / kMHz;
 121         const char *ksym = " ";
 122         if (sym->region->flags & region_type::kIsKernelRegion)
 123             ksym = "k";
 124         printf("%12.2f %11lld %6.2f %6.2f  %s %s\n",
 125                secs, sym->elapsed, per, sum_per, ksym, sym->name);
 126     }
 127     delete[] syms;
 128     delete trace;
 129
 130     return 0;
 131 }