1 /* 2 * Copyright (c) 2013 Google, Inc 3 * 4 * SPDX-License-Identifier: GPL-2.0+ 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 #include <sys/types.h> 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 324 if (err) { 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) { 435 int r = regex_report_error(&line->regex, err, 436 "compile", tok); 437 free(line); 438 return r; 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 } 601