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