]>
Commit | Line | Data |
---|---|---|
6c887b2a SG |
1 | /* |
2 | * Copyright (c) 2013 Google, Inc | |
3 | * | |
1a459660 | 4 | * SPDX-License-Identifier: GPL-2.0+ |
6c887b2a SG |
5 | */ |
6 | ||
7 | /* Decode and dump U-Boot profiling information */ | |
8 | ||
9 | #include <assert.h> | |
10 | #include <ctype.h> | |
11 | #include <limits.h> | |
12 | #include <regex.h> | |
13 | #include <stdarg.h> | |
14 | #include <stdio.h> | |
15 | #include <stdlib.h> | |
16 | #include <string.h> | |
17 | #include <unistd.h> | |
18 | #include <sys/param.h> | |
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 | ||
208 | static int read_calls(FILE *fin, int count) | |
209 | { | |
210 | struct trace_call *call_data; | |
211 | int i; | |
212 | ||
213 | notice("call count: %d\n", count); | |
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) { | |
434 | free(line); | |
435 | return regex_report_error(&line->regex, err, "compile", | |
436 | tok); | |
437 | } | |
438 | ||
439 | /* link this new one to the end of the list */ | |
440 | line->name = strdup(tok); | |
441 | line->next = NULL; | |
442 | *tailp = line; | |
443 | tailp = &line->next; | |
444 | } | |
445 | ||
446 | if (!feof(fin)) { | |
447 | error("Cannot read from trace config file at position %ld\n", | |
448 | ftell(fin)); | |
449 | return -1; | |
450 | } | |
451 | return 0; | |
452 | } | |
453 | ||
454 | static int read_trace_config_file(const char *fname) | |
455 | { | |
456 | FILE *fin; | |
457 | int err; | |
458 | ||
459 | fin = fopen(fname, "r"); | |
460 | if (!fin) { | |
461 | error("Cannot open trace_config file '%s'\n", fname); | |
462 | return -1; | |
463 | } | |
464 | err = read_trace_config(fin); | |
465 | fclose(fin); | |
466 | return err; | |
467 | } | |
468 | ||
469 | static void out_func(ulong func_offset, int is_caller, const char *suffix) | |
470 | { | |
471 | struct func_info *func; | |
472 | ||
473 | func = (is_caller ? find_caller_by_offset : find_func_by_offset) | |
474 | (func_offset); | |
475 | ||
476 | if (func) | |
477 | printf("%s%s", func->name, suffix); | |
478 | else | |
479 | printf("%lx%s", func_offset, suffix); | |
480 | } | |
481 | ||
482 | /* | |
483 | * # tracer: function | |
484 | * # | |
485 | * # TASK-PID CPU# TIMESTAMP FUNCTION | |
486 | * # | | | | | | |
487 | * # bash-4251 [01] 10152.583854: path_put <-path_walk | |
488 | * # bash-4251 [01] 10152.583855: dput <-path_put | |
489 | * # bash-4251 [01] 10152.583855: _atomic_dec_and_lock <-dput | |
490 | */ | |
491 | static int make_ftrace(void) | |
492 | { | |
493 | struct trace_call *call; | |
494 | int missing_count = 0, skip_count = 0; | |
495 | int i; | |
496 | ||
497 | printf("# tracer: ftrace\n" | |
498 | "#\n" | |
499 | "# TASK-PID CPU# TIMESTAMP FUNCTION\n" | |
500 | "# | | | | |\n"); | |
501 | for (i = 0, call = call_list; i < call_count; i++, call++) { | |
502 | struct func_info *func = find_func_by_offset(call->func); | |
503 | ulong time = call->flags & FUNCF_TIMESTAMP_MASK; | |
504 | ||
505 | if (TRACE_CALL_TYPE(call) != FUNCF_ENTRY && | |
506 | TRACE_CALL_TYPE(call) != FUNCF_EXIT) | |
507 | continue; | |
508 | if (!func) { | |
509 | warn("Cannot find function at %lx\n", | |
510 | text_offset + call->func); | |
511 | missing_count++; | |
512 | continue; | |
513 | } | |
514 | ||
515 | if (!(func->flags & FUNCF_TRACE)) { | |
516 | debug("Funcion '%s' is excluded from trace\n", | |
517 | func->name); | |
518 | skip_count++; | |
519 | continue; | |
520 | } | |
521 | ||
522 | printf("%16s-%-5d [01] %lu.%06lu: ", "uboot", 1, | |
523 | time / 1000000, time % 1000000); | |
524 | ||
525 | out_func(call->func, 0, " <- "); | |
526 | out_func(call->caller, 1, "\n"); | |
527 | } | |
528 | info("ftrace: %d functions not found, %d excluded\n", missing_count, | |
529 | skip_count); | |
530 | ||
531 | return 0; | |
532 | } | |
533 | ||
534 | static int prof_tool(int argc, char * const argv[], | |
535 | const char *prof_fname, const char *map_fname, | |
536 | const char *trace_config_fname) | |
537 | { | |
538 | int err = 0; | |
539 | ||
540 | if (read_map_file(map_fname)) | |
541 | return -1; | |
542 | if (prof_fname && read_profile_file(prof_fname)) | |
543 | return -1; | |
544 | if (trace_config_fname && read_trace_config_file(trace_config_fname)) | |
545 | return -1; | |
546 | ||
547 | check_functions(); | |
548 | ||
549 | for (; argc; argc--, argv++) { | |
550 | const char *cmd = *argv; | |
551 | ||
552 | if (0 == strcmp(cmd, "dump-ftrace")) | |
553 | err = make_ftrace(); | |
554 | else | |
555 | warn("Unknown command '%s'\n", cmd); | |
556 | } | |
557 | ||
558 | return err; | |
559 | } | |
560 | ||
561 | int main(int argc, char *argv[]) | |
562 | { | |
563 | const char *map_fname = "System.map"; | |
564 | const char *prof_fname = NULL; | |
565 | const char *trace_config_fname = NULL; | |
566 | int opt; | |
567 | ||
568 | verbose = 2; | |
569 | while ((opt = getopt(argc, argv, "m:p:t:v:")) != -1) { | |
570 | switch (opt) { | |
571 | case 'm': | |
572 | map_fname = optarg; | |
573 | break; | |
574 | ||
575 | case 'p': | |
576 | prof_fname = optarg; | |
577 | break; | |
578 | ||
579 | case 't': | |
580 | trace_config_fname = optarg; | |
581 | break; | |
582 | ||
583 | case 'v': | |
584 | verbose = atoi(optarg); | |
585 | break; | |
586 | ||
587 | default: | |
588 | usage(); | |
589 | } | |
590 | } | |
591 | argc -= optind; argv += optind; | |
592 | if (argc < 1) | |
593 | usage(); | |
594 | ||
595 | debug("Debug enabled\n"); | |
596 | return prof_tool(argc, argv, prof_fname, map_fname, | |
597 | trace_config_fname); | |
598 | } |