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 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 323 if (err) { 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 } 599