blob: a48ed286a5f240de526f4be50bd03463465fdb72 [file] [log] [blame]
Simon Glass6c887b22013-06-11 11:14:43 -07001/*
2 * Copyright (c) 2013 Google, Inc
3 *
4 * This program is free software; you can redistribute it and/or
5 * modify it under the terms of the GNU General Public License as
6 * published by the Free Software Foundation; either version 2 of
7 * the License, or (at your option) any later version.
8 *
9 * This program is distributed in the hope that it will be useful,
10 * but WITHOUT ANY WARRANTY; without even the implied warranty of
11 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the
12 * GNU General Public License for more details.
13 *
14 * You should have received a copy of the GNU General Public License
15 * along with this program; if not, write to the Free Software
16 * Foundation, Inc., 59 Temple Place, Suite 330, Boston,
17 * MA 02111-1307 USA
18 */
19
20/* Decode and dump U-Boot profiling information */
21
22#include <assert.h>
23#include <ctype.h>
24#include <limits.h>
25#include <regex.h>
26#include <stdarg.h>
27#include <stdio.h>
28#include <stdlib.h>
29#include <string.h>
30#include <unistd.h>
31#include <sys/param.h>
32
33#include <compiler.h>
34#include <trace.h>
35
36#define MAX_LINE_LEN 500
37
38enum {
39 FUNCF_TRACE = 1 << 0, /* Include this function in trace */
40};
41
42struct func_info {
43 unsigned long offset;
44 const char *name;
45 unsigned long code_size;
46 unsigned long call_count;
47 unsigned flags;
48 /* the section this function is in */
49 struct objsection_info *objsection;
50};
51
52enum trace_line_type {
53 TRACE_LINE_INCLUDE,
54 TRACE_LINE_EXCLUDE,
55};
56
57struct trace_configline_info {
58 struct trace_configline_info *next;
59 enum trace_line_type type;
60 const char *name; /* identifier name / wildcard */
61 regex_t regex; /* Regex to use if name starts with / */
62};
63
64/* The contents of the trace config file */
65struct trace_configline_info *trace_config_head;
66
67struct func_info *func_list;
68int func_count;
69struct trace_call *call_list;
70int call_count;
71int verbose; /* Verbosity level 0=none, 1=warn, 2=notice, 3=info, 4=debug */
72unsigned long text_offset; /* text address of first function */
73
74static void outf(int level, const char *fmt, ...)
75 __attribute__ ((format (__printf__, 2, 3)));
76#define error(fmt, b...) outf(0, fmt, ##b)
77#define warn(fmt, b...) outf(1, fmt, ##b)
78#define notice(fmt, b...) outf(2, fmt, ##b)
79#define info(fmt, b...) outf(3, fmt, ##b)
80#define debug(fmt, b...) outf(4, fmt, ##b)
81
82
83static void outf(int level, const char *fmt, ...)
84{
85 if (verbose >= level) {
86 va_list args;
87
88 va_start(args, fmt);
89 vfprintf(stderr, fmt, args);
90 va_end(args);
91 }
92}
93
94static void usage(void)
95{
96 fprintf(stderr,
97 "Usage: proftool -cds -v3 <cmd> <profdata>\n"
98 "\n"
99 "Commands\n"
100 " dump-ftrace\t\tDump out textual data in ftrace format\n"
101 "\n"
102 "Options:\n"
103 " -m <map>\tSpecify Systen.map file\n"
104 " -t <trace>\tSpecific trace data file (from U-Boot)\n"
105 " -v <0-4>\tSpecify verbosity\n");
106 exit(EXIT_FAILURE);
107}
108
109static int h_cmp_offset(const void *v1, const void *v2)
110{
111 const struct func_info *f1 = v1, *f2 = v2;
112
113 return (f1->offset / FUNC_SITE_SIZE) - (f2->offset / FUNC_SITE_SIZE);
114}
115
116static int read_system_map(FILE *fin)
117{
118 unsigned long offset, start = 0;
119 struct func_info *func;
120 char buff[MAX_LINE_LEN];
121 char symtype;
122 char symname[MAX_LINE_LEN + 1];
123 int linenum;
124 int alloced;
125
126 for (linenum = 1, alloced = func_count = 0;; linenum++) {
127 int fields = 0;
128
129 if (fgets(buff, sizeof(buff), fin))
130 fields = sscanf(buff, "%lx %c %100s\n", &offset,
131 &symtype, symname);
132 if (fields == 2) {
133 continue;
134 } else if (feof(fin)) {
135 break;
136 } else if (fields < 2) {
137 error("Map file line %d: invalid format\n", linenum);
138 return 1;
139 }
140
141 /* Must be a text symbol */
142 symtype = tolower(symtype);
143 if (symtype != 't' && symtype != 'w')
144 continue;
145
146 if (func_count == alloced) {
147 alloced += 256;
148 func_list = realloc(func_list,
149 sizeof(struct func_info) * alloced);
150 assert(func_list);
151 }
152 if (!func_count)
153 start = offset;
154
155 func = &func_list[func_count++];
156 memset(func, '\0', sizeof(*func));
157 func->offset = offset - start;
158 func->name = strdup(symname);
159 func->flags = FUNCF_TRACE; /* trace by default */
160
161 /* Update previous function's code size */
162 if (func_count > 1)
163 func[-1].code_size = func->offset - func[-1].offset;
164 }
165 notice("%d functions found in map file\n", func_count);
166 text_offset = start;
167 return 0;
168}
169
170static int read_data(FILE *fin, void *buff, int size)
171{
172 int err;
173
174 err = fread(buff, 1, size, fin);
175 if (!err)
176 return 1;
177 if (err != size) {
178 error("Cannot read profile file at pos %ld\n", ftell(fin));
179 return -1;
180 }
181 return 0;
182}
183
184static struct func_info *find_func_by_offset(uint32_t offset)
185{
186 struct func_info key, *found;
187
188 key.offset = offset;
189 found = bsearch(&key, func_list, func_count, sizeof(struct func_info),
190 h_cmp_offset);
191
192 return found;
193}
194
195/* This finds the function which contains the given offset */
196static struct func_info *find_caller_by_offset(uint32_t offset)
197{
198 int low; /* least function that could be a match */
199 int high; /* greated function that could be a match */
200 struct func_info key;
201
202 low = 0;
203 high = func_count - 1;
204 key.offset = offset;
205 while (high > low + 1) {
206 int mid = (low + high) / 2;
207 int result;
208
209 result = h_cmp_offset(&key, &func_list[mid]);
210 if (result > 0)
211 low = mid;
212 else if (result < 0)
213 high = mid;
214 else
215 return &func_list[mid];
216 }
217
218 return low >= 0 ? &func_list[low] : NULL;
219}
220
221static int read_calls(FILE *fin, int count)
222{
223 struct trace_call *call_data;
224 int i;
225
226 notice("call count: %d\n", count);
227 call_list = (struct trace_call *)calloc(count, sizeof(*call_data));
228 if (!call_list) {
229 error("Cannot allocate call_list\n");
230 return -1;
231 }
232 call_count = count;
233
234 call_data = call_list;
235 for (i = 0; i < count; i++, call_data++) {
236 if (read_data(fin, call_data, sizeof(*call_data)))
237 return 1;
238 }
239 return 0;
240}
241
242static int read_profile(FILE *fin, int *not_found)
243{
244 struct trace_output_hdr hdr;
245
246 *not_found = 0;
247 while (!feof(fin)) {
248 int err;
249
250 err = read_data(fin, &hdr, sizeof(hdr));
251 if (err == 1)
252 break; /* EOF */
253 else if (err)
254 return 1;
255
256 switch (hdr.type) {
257 case TRACE_CHUNK_FUNCS:
258 /* Ignored at present */
259 break;
260
261 case TRACE_CHUNK_CALLS:
262 if (read_calls(fin, hdr.rec_count))
263 return 1;
264 break;
265 }
266 }
267 return 0;
268}
269
270static int read_map_file(const char *fname)
271{
272 FILE *fmap;
273 int err = 0;
274
275 fmap = fopen(fname, "r");
276 if (!fmap) {
277 error("Cannot open map file '%s'\n", fname);
278 return 1;
279 }
280 if (fmap) {
281 err = read_system_map(fmap);
282 fclose(fmap);
283 }
284 return err;
285}
286
287static int read_profile_file(const char *fname)
288{
289 int not_found = INT_MAX;
290 FILE *fprof;
291 int err;
292
293 fprof = fopen(fname, "rb");
294 if (!fprof) {
295 error("Cannot open profile data file '%s'\n",
296 fname);
297 return 1;
298 } else {
299 err = read_profile(fprof, &not_found);
300 fclose(fprof);
301 if (err)
302 return err;
303
304 if (not_found) {
305 warn("%d profile functions could not be found in the map file - are you sure that your profile data and map file correspond?\n",
306 not_found);
307 return 1;
308 }
309 }
310 return 0;
311}
312
313static int regex_report_error(regex_t *regex, int err, const char *op,
314 const char *name)
315{
316 char buf[200];
317
318 regerror(err, regex, buf, sizeof(buf));
319 error("Regex error '%s' in %s '%s'\n", buf, op, name);
320 return -1;
321}
322
323static void check_trace_config_line(struct trace_configline_info *item)
324{
325 struct func_info *func, *end;
326 int err;
327
328 debug("Checking trace config line '%s'\n", item->name);
329 for (func = func_list, end = func + func_count; func < end; func++) {
330 err = regexec(&item->regex, func->name, 0, NULL, 0);
331 debug(" - regex '%s', string '%s': %d\n", item->name,
332 func->name, err);
333 if (err == REG_NOMATCH)
334 continue;
335
336 if (err != REG_NOERROR) {
337 regex_report_error(&item->regex, err, "match",
338 item->name);
339 break;
340 }
341
342 /* It matches, so perform the action */
343 switch (item->type) {
344 case TRACE_LINE_INCLUDE:
345 info(" include %s at %lx\n", func->name,
346 text_offset + func->offset);
347 func->flags |= FUNCF_TRACE;
348 break;
349
350 case TRACE_LINE_EXCLUDE:
351 info(" exclude %s at %lx\n", func->name,
352 text_offset + func->offset);
353 func->flags &= ~FUNCF_TRACE;
354 break;
355 }
356 }
357}
358
359static void check_trace_config(void)
360{
361 struct trace_configline_info *line;
362
363 for (line = trace_config_head; line; line = line->next)
364 check_trace_config_line(line);
365}
366
367/**
368 * Check the functions to see if they each have an objsection. If not, then
369 * the linker must have eliminated them.
370 */
371static void check_functions(void)
372{
373 struct func_info *func, *end;
374 unsigned long removed_code_size = 0;
375 int not_found = 0;
376
377 /* Look for missing functions */
378 for (func = func_list, end = func + func_count; func < end; func++) {
379 if (!func->objsection) {
380 removed_code_size += func->code_size;
381 not_found++;
382 }
383 }
384
385 /* Figure out what functions we want to trace */
386 check_trace_config();
387
388 warn("%d functions removed by linker, %ld code size\n",
389 not_found, removed_code_size);
390}
391
392static int read_trace_config(FILE *fin)
393{
394 char buff[200];
395 int linenum = 0;
396 struct trace_configline_info **tailp = &trace_config_head;
397
398 while (fgets(buff, sizeof(buff), fin)) {
399 int len = strlen(buff);
400 struct trace_configline_info *line;
401 char *saveptr;
402 char *s, *tok;
403 int err;
404
405 linenum++;
406 if (len && buff[len - 1] == '\n')
407 buff[len - 1] = '\0';
408
409 /* skip blank lines and comments */
410 for (s = buff; *s == ' ' || *s == '\t'; s++)
411 ;
412 if (!*s || *s == '#')
413 continue;
414
415 line = (struct trace_configline_info *)calloc(1,
416 sizeof(*line));
417 if (!line) {
418 error("Cannot allocate config line\n");
419 return -1;
420 }
421
422 tok = strtok_r(s, " \t", &saveptr);
423 if (!tok) {
424 error("Invalid trace config data on line %d\n",
425 linenum);
426 return -1;
427 }
428 if (0 == strcmp(tok, "include-func")) {
429 line->type = TRACE_LINE_INCLUDE;
430 } else if (0 == strcmp(tok, "exclude-func")) {
431 line->type = TRACE_LINE_EXCLUDE;
432 } else {
433 error("Unknown command in trace config data line %d\n",
434 linenum);
435 return -1;
436 }
437
438 tok = strtok_r(NULL, " \t", &saveptr);
439 if (!tok) {
440 error("Missing pattern in trace config data line %d\n",
441 linenum);
442 return -1;
443 }
444
445 err = regcomp(&line->regex, tok, REG_NOSUB);
446 if (err) {
447 free(line);
448 return regex_report_error(&line->regex, err, "compile",
449 tok);
450 }
451
452 /* link this new one to the end of the list */
453 line->name = strdup(tok);
454 line->next = NULL;
455 *tailp = line;
456 tailp = &line->next;
457 }
458
459 if (!feof(fin)) {
460 error("Cannot read from trace config file at position %ld\n",
461 ftell(fin));
462 return -1;
463 }
464 return 0;
465}
466
467static int read_trace_config_file(const char *fname)
468{
469 FILE *fin;
470 int err;
471
472 fin = fopen(fname, "r");
473 if (!fin) {
474 error("Cannot open trace_config file '%s'\n", fname);
475 return -1;
476 }
477 err = read_trace_config(fin);
478 fclose(fin);
479 return err;
480}
481
482static void out_func(ulong func_offset, int is_caller, const char *suffix)
483{
484 struct func_info *func;
485
486 func = (is_caller ? find_caller_by_offset : find_func_by_offset)
487 (func_offset);
488
489 if (func)
490 printf("%s%s", func->name, suffix);
491 else
492 printf("%lx%s", func_offset, suffix);
493}
494
495/*
496 * # tracer: function
497 * #
498 * # TASK-PID CPU# TIMESTAMP FUNCTION
499 * # | | | | |
500 * # bash-4251 [01] 10152.583854: path_put <-path_walk
501 * # bash-4251 [01] 10152.583855: dput <-path_put
502 * # bash-4251 [01] 10152.583855: _atomic_dec_and_lock <-dput
503 */
504static int make_ftrace(void)
505{
506 struct trace_call *call;
507 int missing_count = 0, skip_count = 0;
508 int i;
509
510 printf("# tracer: ftrace\n"
511 "#\n"
512 "# TASK-PID CPU# TIMESTAMP FUNCTION\n"
513 "# | | | | |\n");
514 for (i = 0, call = call_list; i < call_count; i++, call++) {
515 struct func_info *func = find_func_by_offset(call->func);
516 ulong time = call->flags & FUNCF_TIMESTAMP_MASK;
517
518 if (TRACE_CALL_TYPE(call) != FUNCF_ENTRY &&
519 TRACE_CALL_TYPE(call) != FUNCF_EXIT)
520 continue;
521 if (!func) {
522 warn("Cannot find function at %lx\n",
523 text_offset + call->func);
524 missing_count++;
525 continue;
526 }
527
528 if (!(func->flags & FUNCF_TRACE)) {
529 debug("Funcion '%s' is excluded from trace\n",
530 func->name);
531 skip_count++;
532 continue;
533 }
534
535 printf("%16s-%-5d [01] %lu.%06lu: ", "uboot", 1,
536 time / 1000000, time % 1000000);
537
538 out_func(call->func, 0, " <- ");
539 out_func(call->caller, 1, "\n");
540 }
541 info("ftrace: %d functions not found, %d excluded\n", missing_count,
542 skip_count);
543
544 return 0;
545}
546
547static int prof_tool(int argc, char * const argv[],
548 const char *prof_fname, const char *map_fname,
549 const char *trace_config_fname)
550{
551 int err = 0;
552
553 if (read_map_file(map_fname))
554 return -1;
555 if (prof_fname && read_profile_file(prof_fname))
556 return -1;
557 if (trace_config_fname && read_trace_config_file(trace_config_fname))
558 return -1;
559
560 check_functions();
561
562 for (; argc; argc--, argv++) {
563 const char *cmd = *argv;
564
565 if (0 == strcmp(cmd, "dump-ftrace"))
566 err = make_ftrace();
567 else
568 warn("Unknown command '%s'\n", cmd);
569 }
570
571 return err;
572}
573
574int main(int argc, char *argv[])
575{
576 const char *map_fname = "System.map";
577 const char *prof_fname = NULL;
578 const char *trace_config_fname = NULL;
579 int opt;
580
581 verbose = 2;
582 while ((opt = getopt(argc, argv, "m:p:t:v:")) != -1) {
583 switch (opt) {
584 case 'm':
585 map_fname = optarg;
586 break;
587
588 case 'p':
589 prof_fname = optarg;
590 break;
591
592 case 't':
593 trace_config_fname = optarg;
594 break;
595
596 case 'v':
597 verbose = atoi(optarg);
598 break;
599
600 default:
601 usage();
602 }
603 }
604 argc -= optind; argv += optind;
605 if (argc < 1)
606 usage();
607
608 debug("Debug enabled\n");
609 return prof_tool(argc, argv, prof_fname, map_fname,
610 trace_config_fname);
611}