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