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