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