1// SPDX-License-Identifier: GPL-2.0+ 2/* 3 * Copyright 2023 Google LLC 4 * Written by Simon Glass <sjg@chromium.org> 5 */ 6 7/* 8 * Decode and dump U-Boot trace information into formats that can be used 9 * by trace-cmd, kernelshark or flamegraph.pl 10 * 11 * See doc/develop/trace.rst for more information 12 */ 13 14#include <assert.h> 15#include <ctype.h> 16#include <limits.h> 17#include <regex.h> 18#include <stdarg.h> 19#include <stdio.h> 20#include <stdlib.h> 21#include <string.h> 22#include <unistd.h> 23#include <sys/param.h> 24#include <sys/types.h> 25 26#include <compiler.h> 27#include <trace.h> 28#include <abuf.h> 29 30#include <linux/list.h> 31 32/* Set to 1 to emit version 7 file (currently this doesn't work) */ 33#define VERSION7 0 34 35/* enable some debug features */ 36#define _DEBUG 0 37 38/* from linux/kernel.h */ 39#define __ALIGN_MASK(x, mask) (((x) + (mask)) & ~(mask)) 40#define ALIGN(x, a) __ALIGN_MASK((x), (typeof(x))(a) - 1) 41 42/** 43 * container_of - cast a member of a structure out to the containing structure 44 * @ptr: the pointer to the member. 45 * @type: the type of the container struct this is embedded in. 46 * @member: the name of the member within the struct. 47 * 48 * (this is needed by list.h) 49 */ 50#define container_of(ptr, type, member) ({ \ 51 const typeof( ((type *)0)->member ) *__mptr = (ptr); \ 52 (type *)( (char *)__mptr - offsetof(type,member) );}) 53 54enum { 55 FUNCF_TRACE = 1 << 0, /* Include this function in trace */ 56 TRACE_PAGE_SIZE = 4096, /* Assumed page size for trace */ 57 TRACE_PID = 1, /* PID to use for U-Boot */ 58 LEN_STACK_SIZE = 4, /* number of nested length fix-ups */ 59 TRACE_PAGE_MASK = TRACE_PAGE_SIZE - 1, 60 MAX_STACK_DEPTH = 50, /* Max nested function calls */ 61 MAX_LINE_LEN = 500, /* Max characters per line */ 62}; 63 64/** 65 * enum out_format_t - supported output formats 66 * 67 * @OUT_FMT_DEFAULT: Use the default for the output file 68 * @OUT_FMT_FUNCTION: Write ftrace 'function' records 69 * @OUT_FMT_FUNCGRAPH: Write ftrace funcgraph_entry and funcgraph_exit records 70 * @OUT_FMT_FLAMEGRAPH_CALLS: Write a file suitable for flamegraph.pl 71 * @OUT_FMT_FLAMEGRAPH_TIMING: Write a file suitable for flamegraph.pl with the 72 * counts set to the number of microseconds used by each function 73 */ 74enum out_format_t { 75 OUT_FMT_DEFAULT, 76 OUT_FMT_FUNCTION, 77 OUT_FMT_FUNCGRAPH, 78 OUT_FMT_FLAMEGRAPH_CALLS, 79 OUT_FMT_FLAMEGRAPH_TIMING, 80}; 81 82/* Section types for v7 format (trace-cmd format) */ 83enum { 84 SECTION_OPTIONS, 85}; 86 87/* Option types (trace-cmd format) */ 88enum { 89 OPTION_DONE, 90 OPTION_DATE, 91 OPTION_CPUSTAT, 92 OPTION_BUFFER, 93 OPTION_TRACECLOCK, 94 OPTION_UNAME, 95 OPTION_HOOK, 96 OPTION_OFFSET, 97 OPTION_CPUCOUNT, 98 OPTION_VERSION, 99 OPTION_PROCMAPS, 100 OPTION_TRACEID, 101 OPTION_TIME_SHIFT, 102 OPTION_GUEST, 103 OPTION_TSC2NSEC, 104}; 105 106/* types of trace records (trace-cmd format) */ 107enum trace_type { 108 __TRACE_FIRST_TYPE = 0, 109 110 TRACE_FN, 111 TRACE_CTX, 112 TRACE_WAKE, 113 TRACE_STACK, 114 TRACE_PRINT, 115 TRACE_BPRINT, 116 TRACE_MMIO_RW, 117 TRACE_MMIO_MAP, 118 TRACE_BRANCH, 119 TRACE_GRAPH_RET, 120 TRACE_GRAPH_ENT, 121}; 122 123/** 124 * struct flame_node - a node in the call-stack tree 125 * 126 * Each stack frame detected in the trace is given a node corresponding to a 127 * function call in the call stack. Functions can appear multiple times when 128 * they are called by a different set of parent functions. 129 * 130 * @parent: Parent node (the call stack for the function that called this one) 131 * @child_head: List of children of this node (functions called from here) 132 * @sibling: Next node in the list of children 133 * @func: Function this node refers to (NULL for root node) 134 * @count: Number of times this call-stack occurred 135 * @duration: Number of microseconds taken to run this function, excluding all 136 * of the functions it calls 137 */ 138struct flame_node { 139 struct flame_node *parent; 140 struct list_head child_head; 141 struct list_head sibling_node; 142 struct func_info *func; 143 int count; 144 ulong duration; 145}; 146 147/** 148 * struct flame_state - state information for building the flame graph 149 * 150 * @node: Current node being processed (corresponds to a function call) 151 * @stack: Stack of call-start time for this function as well as the 152 * accumulated total time of all child calls (so we can subtract them from the 153 * function's call time. This is an 'empty' stack, meaning that @stack_ptr 154 * points to the next available stack position 155 * @stack_ptr: points to first empty position in the stack 156 * @nodes: Number of nodes created (running count) 157 */ 158struct flame_state { 159 struct flame_node *node; 160 struct stack_info { 161 ulong timestamp; 162 ulong child_total; 163 } stack[MAX_STACK_DEPTH]; 164 int stack_ptr; 165 int nodes; 166}; 167 168/** 169 * struct func_info - information recorded for each function 170 * 171 * @offset: Function offset in the image, measured from the text_base 172 * @name: Function name 173 * @code_size: Total code size of the function 174 * @flags: Either 0 or FUNCF_TRACE 175 */ 176struct func_info { 177 unsigned long offset; 178 const char *name; 179 unsigned long code_size; 180 unsigned flags; 181}; 182 183/** 184 * enum trace_line_type - whether to include or exclude a function 185 * 186 * @TRACE_LINE_INCLUDE: Include the function 187 * @TRACE_LINE_EXCLUDE: Exclude the function 188 */ 189enum trace_line_type { 190 TRACE_LINE_INCLUDE, 191 TRACE_LINE_EXCLUDE, 192}; 193 194/** 195 * struct trace_configline_info - information about a config-file line 196 * 197 * @next: Next line 198 * @type: Line type 199 * @name: identifier name / wildcard 200 * @regex: Regex to use if name starts with '/' 201 */ 202struct trace_configline_info { 203 struct trace_configline_info *next; 204 enum trace_line_type type; 205 const char *name; 206 regex_t regex; 207}; 208 209/** 210 * struct tw_len - holds information about a length value that need fix-ups 211 * 212 * This is used to record a placeholder for a u32 or u64 length which is written 213 * to the output file but needs to be updated once the length is actually known 214 * 215 * This allows us to write tw->ptr - @len_base to position @ptr in the file 216 * 217 * @ptr: Position of the length value in the file 218 * @base: Base position for the calculation 219 * @size: Size of the length value, in bytes (4 or 8) 220 */ 221struct tw_len { 222 int ptr; 223 int base; 224 int size; 225}; 226 227/** 228 * struct twriter - Writer for trace records 229 * 230 * Maintains state used when writing the output file in trace-cmd format 231 * 232 * @ptr: Current file position 233 * @len_stack: Stack of length values that need fixing up 234 * @len: Number of items on @len_stack 235 * @str_buf: Buffer of strings (for v7 format) 236 * @str_ptr: Current write-position in the buffer for strings 237 * @fout: Output file 238 */ 239struct twriter { 240 int ptr; 241 struct tw_len len_stack[LEN_STACK_SIZE]; 242 int len_count; 243 struct abuf str_buf; 244 int str_ptr; 245 FILE *fout; 246}; 247 248/* The contents of the trace config file */ 249struct trace_configline_info *trace_config_head; 250 251/* list of all functions in System.map file, sorted by offset in the image */ 252struct func_info *func_list; 253 254int func_count; /* number of functions */ 255struct trace_call *call_list; /* list of all calls in the input trace file */ 256int call_count; /* number of calls */ 257int verbose; /* Verbosity level 0=none, 1=warn, 2=notice, 3=info, 4=debug */ 258ulong text_offset; /* text address of first function */ 259ulong text_base; /* CONFIG_TEXT_BASE from trace file */ 260 261/* debugging helpers */ 262static void outf(int level, const char *fmt, ...) 263 __attribute__ ((format (__printf__, 2, 3))); 264#define error(fmt, b...) outf(0, fmt, ##b) 265#define warn(fmt, b...) outf(1, fmt, ##b) 266#define notice(fmt, b...) outf(2, fmt, ##b) 267#define info(fmt, b...) outf(3, fmt, ##b) 268#define debug(fmt, b...) outf(4, fmt, ##b) 269 270static void outf(int level, const char *fmt, ...) 271{ 272 if (verbose >= level) { 273 va_list args; 274 275 va_start(args, fmt); 276 vfprintf(stderr, fmt, args); 277 va_end(args); 278 } 279} 280 281static void usage(void) 282{ 283 fprintf(stderr, 284 "Usage: proftool [-cmtv] <cmd> <profdata>\n" 285 "\n" 286 "Commands\n" 287 " dump-ftrace\t\tDump out records in ftrace format for use by trace-cmd\n" 288 " dump-flamegraph\tWrite a file for use with flamegraph.pl\n" 289 "\n" 290 "Options:\n" 291 " -c <cfg>\tSpecify config file\n" 292 " -f <subtype>\tSpecify output subtype\n" 293 " -m <map>\tSpecify System.map file\n" 294 " -o <fname>\tSpecify output file\n" 295 " -t <fname>\tSpecify trace data file (from U-Boot 'trace calls')\n" 296 " -v <0-4>\tSpecify verbosity\n" 297 "\n" 298 "Subtypes for dump-ftrace:\n" 299 " function - write function-call records (caller/callee)\n" 300 " funcgraph - write function entry/exit records (graph)\n" 301 "\n" 302 "Subtypes for dump-flamegraph\n" 303 " calls - create a flamegraph of stack frames\n" 304 " timing - create a flamegraph of microseconds for each stack frame\n"); 305 exit(EXIT_FAILURE); 306} 307 308/** 309 * h_cmp_offset - bsearch() function to compare two functions by their offset 310 * 311 * @v1: Pointer to first function (struct func_info) 312 * @v2: Pointer to second function (struct func_info) 313 * Returns: < 0 if v1 offset < v2 offset, 0 if equal, > 0 otherwise 314 */ 315static int h_cmp_offset(const void *v1, const void *v2) 316{ 317 const struct func_info *f1 = v1, *f2 = v2; 318 319 return (f1->offset / FUNC_SITE_SIZE) - (f2->offset / FUNC_SITE_SIZE); 320} 321 322/** 323 * read_system_map() - read the System.map file to create a list of functions 324 * 325 * This also reads the text_offset value, since we assume that the first text 326 * symbol is at that address 327 * 328 * @fin: File to read 329 * Returns: 0 if OK, non-zero on error 330 */ 331static int read_system_map(FILE *fin) 332{ 333 unsigned long offset, start = 0; 334 struct func_info *func; 335 char buff[MAX_LINE_LEN]; 336 char symtype; 337 char symname[MAX_LINE_LEN + 1]; 338 int linenum; 339 int alloced; 340 341 for (linenum = 1, alloced = func_count = 0;; linenum++) { 342 int fields = 0; 343 344 if (fgets(buff, sizeof(buff), fin)) 345 fields = sscanf(buff, "%lx %c %100s\n", &offset, 346 &symtype, symname); 347 if (fields == 2) { 348 continue; 349 } else if (feof(fin)) { 350 break; 351 } else if (fields < 2) { 352 error("Map file line %d: invalid format\n", linenum); 353 return 1; 354 } 355 356 /* Must be a text symbol */ 357 symtype = tolower(symtype); 358 if (symtype != 't' && symtype != 'w') 359 continue; 360 361 if (func_count == alloced) { 362 alloced += 256; 363 func_list = realloc(func_list, 364 sizeof(struct func_info) * alloced); 365 assert(func_list); 366 } 367 if (!func_count) 368 start = offset; 369 370 func = &func_list[func_count++]; 371 memset(func, '\0', sizeof(*func)); 372 func->offset = offset - start; 373 func->name = strdup(symname); 374 func->flags = FUNCF_TRACE; /* trace by default */ 375 376 /* Update previous function's code size */ 377 if (func_count > 1) 378 func[-1].code_size = func->offset - func[-1].offset; 379 } 380 notice("%d functions found in map file, start addr %lx\n", func_count, 381 start); 382 text_offset = start; 383 384 return 0; 385} 386 387static int read_data(FILE *fin, void *buff, int size) 388{ 389 int err; 390 391 err = fread(buff, 1, size, fin); 392 if (!err) 393 return 1; 394 if (err != size) { 395 error("Cannot read trace file at pos %lx\n", ftell(fin)); 396 return -1; 397 } 398 return 0; 399} 400 401/** 402 * find_func_by_offset() - Look up a function by its offset 403 * 404 * @offset: Offset to search for, from text_base 405 * Returns: function, if found, else NULL 406 * 407 * This does a fast search for a function given its offset from text_base 408 * 409 */ 410static struct func_info *find_func_by_offset(uint offset) 411{ 412 struct func_info key, *found; 413 414 key.offset = offset; 415 found = bsearch(&key, func_list, func_count, sizeof(struct func_info), 416 h_cmp_offset); 417 418 return found; 419} 420 421/** 422 * find_caller_by_offset() - finds the function which contains the given offset 423 * 424 * @offset: Offset to search for, from text_base 425 * Returns: function, if found, else NULL 426 * 427 * If the offset falls between two functions, then it is assumed to belong to 428 * the first function (with the lowest offset). This is a way of figuring out 429 * which function owns code at a particular offset 430 */ 431static struct func_info *find_caller_by_offset(uint offset) 432{ 433 int low; /* least function that could be a match */ 434 int high; /* greatest function that could be a match */ 435 struct func_info key; 436 437 low = 0; 438 high = func_count - 1; 439 key.offset = offset; 440 while (high > low + 1) { 441 int mid = (low + high) / 2; 442 int result; 443 444 result = h_cmp_offset(&key, &func_list[mid]); 445 if (result > 0) 446 low = mid; 447 else if (result < 0) 448 high = mid; 449 else 450 return &func_list[mid]; 451 } 452 453 return low >= 0 ? &func_list[low] : NULL; 454} 455 456/** 457 * read_calls() - Read the list of calls from the trace data 458 * 459 * The calls are stored consecutively in the trace output produced by U-Boot 460 * 461 * @fin: File to read from 462 * @count: Number of calls to read 463 * Returns: 0 if OK, -1 on error 464 */ 465static int read_calls(FILE *fin, size_t count) 466{ 467 struct trace_call *call_data; 468 int i; 469 470 notice("call count: %zu\n", count); 471 call_list = (struct trace_call *)calloc(count, sizeof(*call_data)); 472 if (!call_list) { 473 error("Cannot allocate call_list\n"); 474 return -1; 475 } 476 call_count = count; 477 478 call_data = call_list; 479 for (i = 0; i < count; i++, call_data++) { 480 if (read_data(fin, call_data, sizeof(*call_data))) 481 return -1; 482 } 483 return 0; 484} 485 486/** 487 * read_trace() - Read the U-Boot trace file 488 * 489 * Read in the calls from the trace file. The function list is ignored at 490 * present 491 * 492 * @fin: File to read 493 * Returns 0 if OK, non-zero on error 494 */ 495static int read_trace(FILE *fin) 496{ 497 struct trace_output_hdr hdr; 498 499 while (!feof(fin)) { 500 int err; 501 502 err = read_data(fin, &hdr, sizeof(hdr)); 503 if (err == 1) 504 break; /* EOF */ 505 else if (err) 506 return 1; 507 text_base = hdr.text_base; 508 509 switch (hdr.type) { 510 case TRACE_CHUNK_FUNCS: 511 /* Ignored at present */ 512 break; 513 514 case TRACE_CHUNK_CALLS: 515 if (read_calls(fin, hdr.rec_count)) 516 return 1; 517 break; 518 } 519 } 520 return 0; 521} 522 523/** 524 * read_map_file() - Read the System.map file 525 * 526 * This reads the file into the func_list array 527 * 528 * @fname: Filename to read 529 * Returns 0 if OK, non-zero on error 530 */ 531static int read_map_file(const char *fname) 532{ 533 FILE *fmap; 534 int err = 0; 535 536 fmap = fopen(fname, "r"); 537 if (!fmap) { 538 error("Cannot open map file '%s'\n", fname); 539 return 1; 540 } 541 if (fmap) { 542 err = read_system_map(fmap); 543 fclose(fmap); 544 } 545 return err; 546} 547 548/** 549 * read_trace_file() - Open and read the U-Boot trace file 550 * 551 * Read in the calls from the trace file. The function list is ignored at 552 * present 553 * 554 * @fin: File to read 555 * Returns 0 if OK, non-zero on error 556 */ 557static int read_trace_file(const char *fname) 558{ 559 FILE *fprof; 560 int err; 561 562 fprof = fopen(fname, "rb"); 563 if (!fprof) { 564 error("Cannot open trace data file '%s'\n", 565 fname); 566 return 1; 567 } else { 568 err = read_trace(fprof); 569 fclose(fprof); 570 if (err) 571 return err; 572 } 573 return 0; 574} 575 576static int regex_report_error(regex_t *regex, int err, const char *op, 577 const char *name) 578{ 579 char buf[200]; 580 581 regerror(err, regex, buf, sizeof(buf)); 582 error("Regex error '%s' in %s '%s'\n", buf, op, name); 583 return -1; 584} 585 586static void check_trace_config_line(struct trace_configline_info *item) 587{ 588 struct func_info *func, *end; 589 int err; 590 591 debug("Checking trace config line '%s'\n", item->name); 592 for (func = func_list, end = func + func_count; func < end; func++) { 593 err = regexec(&item->regex, func->name, 0, NULL, 0); 594 debug(" - regex '%s', string '%s': %d\n", item->name, 595 func->name, err); 596 if (err == REG_NOMATCH) 597 continue; 598 599 if (err) { 600 regex_report_error(&item->regex, err, "match", 601 item->name); 602 break; 603 } 604 605 /* It matches, so perform the action */ 606 switch (item->type) { 607 case TRACE_LINE_INCLUDE: 608 info(" include %s at %lx\n", func->name, 609 text_offset + func->offset); 610 func->flags |= FUNCF_TRACE; 611 break; 612 613 case TRACE_LINE_EXCLUDE: 614 info(" exclude %s at %lx\n", func->name, 615 text_offset + func->offset); 616 func->flags &= ~FUNCF_TRACE; 617 break; 618 } 619 } 620} 621 622/** check_trace_config() - Check trace-config file, reporting any problems */ 623static void check_trace_config(void) 624{ 625 struct trace_configline_info *line; 626 627 for (line = trace_config_head; line; line = line->next) 628 check_trace_config_line(line); 629} 630 631/** 632 * read_trace_config() - read the trace-config file 633 * 634 * This file consists of lines like: 635 * 636 * include-func <regex> 637 * exclude-func <regex> 638 * 639 * where <regex> is a regular expression matched against function names. It 640 * allows some functions to be dropped from the trace when producing ftrace 641 * records 642 * 643 * @fin: File to process 644 * Returns: 0 if OK, -1 on error 645 */ 646static int read_trace_config(FILE *fin) 647{ 648 char buff[200]; 649 int linenum = 0; 650 struct trace_configline_info **tailp = &trace_config_head; 651 652 while (fgets(buff, sizeof(buff), fin)) { 653 int len = strlen(buff); 654 struct trace_configline_info *line; 655 char *saveptr; 656 char *s, *tok; 657 int err; 658 659 linenum++; 660 if (len && buff[len - 1] == '\n') 661 buff[len - 1] = '\0'; 662 663 /* skip blank lines and comments */ 664 for (s = buff; *s == ' ' || *s == '\t'; s++) 665 ; 666 if (!*s || *s == '#') 667 continue; 668 669 line = (struct trace_configline_info *)calloc(1, sizeof(*line)); 670 if (!line) { 671 error("Cannot allocate config line\n"); 672 return -1; 673 } 674 675 tok = strtok_r(s, " \t", &saveptr); 676 if (!tok) { 677 error("Invalid trace config data on line %d\n", 678 linenum); 679 return -1; 680 } 681 if (0 == strcmp(tok, "include-func")) { 682 line->type = TRACE_LINE_INCLUDE; 683 } else if (0 == strcmp(tok, "exclude-func")) { 684 line->type = TRACE_LINE_EXCLUDE; 685 } else { 686 error("Unknown command in trace config data line %d\n", 687 linenum); 688 return -1; 689 } 690 691 tok = strtok_r(NULL, " \t", &saveptr); 692 if (!tok) { 693 error("Missing pattern in trace config data line %d\n", 694 linenum); 695 return -1; 696 } 697 698 err = regcomp(&line->regex, tok, REG_NOSUB); 699 if (err) { 700 int r = regex_report_error(&line->regex, err, 701 "compile", tok); 702 free(line); 703 return r; 704 } 705 706 /* link this new one to the end of the list */ 707 line->name = strdup(tok); 708 line->next = NULL; 709 *tailp = line; 710 tailp = &line->next; 711 } 712 713 if (!feof(fin)) { 714 error("Cannot read from trace config file at position %ld\n", 715 ftell(fin)); 716 return -1; 717 } 718 return 0; 719} 720 721static int read_trace_config_file(const char *fname) 722{ 723 FILE *fin; 724 int err; 725 726 fin = fopen(fname, "r"); 727 if (!fin) { 728 error("Cannot open trace_config file '%s'\n", fname); 729 return -1; 730 } 731 err = read_trace_config(fin); 732 fclose(fin); 733 return err; 734} 735 736/** 737 * tputh() - Write a 16-bit little-endian value to a file 738 * 739 * @fout: File to write to 740 * @val: Value to write 741 * Returns: number of bytes written (2) 742 */ 743static int tputh(FILE *fout, unsigned int val) 744{ 745 fputc(val, fout); 746 fputc(val >> 8, fout); 747 748 return 2; 749} 750 751/** 752 * tputl() - Write a 32-bit little-endian value to a file 753 * 754 * @fout: File to write to 755 * @val: Value to write 756 * Returns: number of bytes written (4) 757 */ 758static int tputl(FILE *fout, ulong val) 759{ 760 fputc(val, fout); 761 fputc(val >> 8, fout); 762 fputc(val >> 16, fout); 763 fputc(val >> 24, fout); 764 765 return 4; 766} 767 768/** 769 * tputh() - Write a 64-bit little-endian value to a file 770 * 771 * @fout: File to write to 772 * @val: Value to write 773 * Returns: number of bytes written (8) 774 */ 775static int tputq(FILE *fout, unsigned long long val) 776{ 777 tputl(fout, val); 778 tputl(fout, val >> 32U); 779 780 return 8; 781} 782 783/** 784 * tputh() - Write a string to a file 785 * 786 * The string is written without its terminator 787 * 788 * @fout: File to write to 789 * @val: Value to write 790 * Returns: number of bytes written 791 */ 792static int tputs(FILE *fout, const char *str) 793{ 794 fputs(str, fout); 795 796 return strlen(str); 797} 798 799/** 800 * add_str() - add a name string to the string table 801 * 802 * This is used by the v7 format 803 * 804 * @tw: Writer context 805 * @name: String to write 806 * Returns: Updated value of string pointer, or -1 if out of memory 807 */ 808static int add_str(struct twriter *tw, const char *name) 809{ 810 int str_ptr; 811 int len; 812 813 len = strlen(name) + 1; 814 str_ptr = tw->str_ptr; 815 tw->str_ptr += len; 816 817 if (tw->str_ptr > abuf_size(&tw->str_buf)) { 818 int new_size; 819 820 new_size = ALIGN(tw->str_ptr, 4096); 821 if (!abuf_realloc(&tw->str_buf, new_size)) 822 return -1; 823 } 824 825 return str_ptr; 826} 827 828/** 829 * push_len() - Push a new length request onto the stack 830 * 831 * @tw: Writer context 832 * @base: Base position of the length calculation 833 * @msg: Indicates the type of caller, for debugging 834 * @size: Size of the length value, either 4 bytes or 8 835 * Returns number of bytes written to the file (=@size on success), -ve on error 836 * 837 * This marks a place where a length must be written, covering data that is 838 * about to be written. It writes a placeholder value. 839 * 840 * Once the data is written, calling pop_len() will update the placeholder with 841 * the correct length based on how many bytes have been written 842 */ 843static int push_len(struct twriter *tw, int base, const char *msg, int size) 844{ 845 struct tw_len *lp; 846 847 if (tw->len_count >= LEN_STACK_SIZE) { 848 fprintf(stderr, "Length-stack overflow: %s\n", msg); 849 return -1; 850 } 851 if (size != 4 && size != 8) { 852 fprintf(stderr, "Length-stack invalid size %d: %s\n", size, 853 msg); 854 return -1; 855 } 856 857 lp = &tw->len_stack[tw->len_count++]; 858 lp->base = base; 859 lp->ptr = tw->ptr; 860 lp->size = size; 861 862 return size == 8 ? tputq(tw->fout, 0) : tputl(tw->fout, 0); 863} 864 865/** 866 * pop_len() - Update a length value once the length is known 867 * 868 * Pops a value of the length stack and updates the file at that position with 869 * the number of bytes written between now and then. Once done, the file is 870 * seeked to the current (tw->ptr) position again, so writing can continue as 871 * normal. 872 * 873 * @tw: Writer context 874 * @msg: Indicates the type of caller, for debugging 875 * Returns 0 if OK, -1 on error 876 */ 877static int pop_len(struct twriter *tw, const char *msg) 878{ 879 struct tw_len *lp; 880 int len, ret; 881 882 if (!tw->len_count) { 883 fprintf(stderr, "Length-stack underflow: %s\n", msg); 884 return -1; 885 } 886 887 lp = &tw->len_stack[--tw->len_count]; 888 if (fseek(tw->fout, lp->ptr, SEEK_SET)) 889 return -1; 890 len = tw->ptr - lp->base; 891 ret = lp->size == 8 ? tputq(tw->fout, len) : tputl(tw->fout, len); 892 if (ret < 0) 893 return -1; 894 if (fseek(tw->fout, tw->ptr, SEEK_SET)) 895 return -1; 896 897 return 0; 898} 899 900/** 901 * start_header() - Start a v7 section 902 * 903 * Writes a header in v7 format 904 * 905 * @tw: Writer context 906 * @id: ID of header to write (SECTION_...) 907 * @flags: Flags value to write 908 * @name: Name of section 909 * Returns: number of bytes written 910 */ 911static int start_header(struct twriter *tw, int id, uint flags, 912 const char *name) 913{ 914 int str_id; 915 int lptr; 916 int base; 917 int ret; 918 919 base = tw->ptr + 16; 920 lptr = 0; 921 lptr += tputh(tw->fout, id); 922 lptr += tputh(tw->fout, flags); 923 str_id = add_str(tw, name); 924 if (str_id < 0) 925 return -1; 926 lptr += tputl(tw->fout, str_id); 927 928 /* placeholder for size */ 929 ret = push_len(tw, base, "v7 header", 8); 930 if (ret < 0) 931 return -1; 932 lptr += ret; 933 934 return lptr; 935} 936 937/** 938 * start_page() - Start a new page of output data 939 * 940 * The output is arranged in 4KB pages with a base timestamp at the start of 941 * each. This starts a new page, making sure it is aligned to 4KB in the output 942 * file. 943 * 944 * @tw: Writer context 945 * @timestamp: Base timestamp for the page 946 */ 947static int start_page(struct twriter *tw, ulong timestamp) 948{ 949 int start; 950 int ret; 951 952 /* move to start of next page */ 953 start = ALIGN(tw->ptr, TRACE_PAGE_SIZE); 954 ret = fseek(tw->fout, start, SEEK_SET); 955 if (ret < 0) { 956 fprintf(stderr, "Cannot seek to page start\n"); 957 return -1; 958 } 959 tw->ptr = start; 960 961 /* page header */ 962 tw->ptr += tputq(tw->fout, timestamp); 963 ret = push_len(tw, start + 16, "page", 8); 964 if (ret < 0) 965 return ret; 966 tw->ptr += ret; 967 968 return 0; 969} 970 971/** 972 * finish_page() - finish a page 973 * 974 * Sets the lengths correctly and moves to the start of the next page 975 * 976 * @tw: Writer context 977 * Returns: 0 on success, -1 on error 978 */ 979static int finish_page(struct twriter *tw) 980{ 981 int ret, end; 982 983 ret = pop_len(tw, "page"); 984 if (ret < 0) 985 return ret; 986 end = ALIGN(tw->ptr, TRACE_PAGE_SIZE); 987 988 /* 989 * Write a byte so that the data actually makes to the file, in the case 990 * that we never write any more pages 991 */ 992 if (tw->ptr != end) { 993 if (fseek(tw->fout, end - 1, SEEK_SET)) { 994 fprintf(stderr, "cannot seek to start of next page\n"); 995 return -1; 996 } 997 fputc(0, tw->fout); 998 tw->ptr = end; 999 } 1000 1001 return 0; 1002} 1003 1004/** 1005 * output_headers() - Output v6 headers to the file 1006 * 1007 * Writes out the various formats so that trace-cmd and kernelshark can make 1008 * sense of the data 1009 * 1010 * This updates tw->ptr as it goes 1011 * 1012 * @tw: Writer context 1013 * Returns: 0 on success, -ve on error 1014 */ 1015static int output_headers(struct twriter *tw) 1016{ 1017 FILE *fout = tw->fout; 1018 char str[800]; 1019 int len, ret; 1020 1021 tw->ptr += fprintf(fout, "%c%c%ctracing6%c%c%c", 0x17, 0x08, 0x44, 1022 0 /* terminator */, 0 /* little endian */, 1023 4 /* 32-bit long values */); 1024 1025 /* host-machine page size 4KB */ 1026 tw->ptr += tputl(fout, 4 << 10); 1027 1028 tw->ptr += fprintf(fout, "header_page%c", 0); 1029 1030 snprintf(str, sizeof(str), 1031 "\tfield: u64 timestamp;\toffset:0;\tsize:8;\tsigned:0;\n" 1032 "\tfield: local_t commit;\toffset:8;\tsize:8;\tsigned:1;\n" 1033 "\tfield: int overwrite;\toffset:8;\tsize:1;\tsigned:1;\n" 1034 "\tfield: char data;\toffset:16;\tsize:4080;\tsigned:1;\n"); 1035 len = strlen(str); 1036 tw->ptr += tputq(fout, len); 1037 tw->ptr += tputs(fout, str); 1038 1039 if (VERSION7) { 1040 /* no compression */ 1041 tw->ptr += fprintf(fout, "none%cversion%c\n", 0, 0); 1042 1043 ret = start_header(tw, SECTION_OPTIONS, 0, "options"); 1044 if (ret < 0) { 1045 fprintf(stderr, "Cannot start option header\n"); 1046 return -1; 1047 } 1048 tw->ptr += ret; 1049 tw->ptr += tputh(fout, OPTION_DONE); 1050 tw->ptr += tputl(fout, 8); 1051 tw->ptr += tputl(fout, 0); 1052 ret = pop_len(tw, "t7 header"); 1053 if (ret < 0) { 1054 fprintf(stderr, "Cannot finish option header\n"); 1055 return -1; 1056 } 1057 } 1058 1059 tw->ptr += fprintf(fout, "header_event%c", 0); 1060 snprintf(str, sizeof(str), 1061 "# compressed entry header\n" 1062 "\ttype_len : 5 bits\n" 1063 "\ttime_delta : 27 bits\n" 1064 "\tarray : 32 bits\n" 1065 "\n" 1066 "\tpadding : type == 29\n" 1067 "\ttime_extend : type == 30\n" 1068 "\ttime_stamp : type == 31\n" 1069 "\tdata max type_len == 28\n"); 1070 len = strlen(str); 1071 tw->ptr += tputq(fout, len); 1072 tw->ptr += tputs(fout, str); 1073 1074 /* number of ftrace-event-format files */ 1075 tw->ptr += tputl(fout, 3); 1076 1077 snprintf(str, sizeof(str), 1078 "name: function\n" 1079 "ID: 1\n" 1080 "format:\n" 1081 "\tfield:unsigned short common_type;\toffset:0;\tsize:2;\tsigned:0;\n" 1082 "\tfield:unsigned char common_flags;\toffset:2;\tsize:1;\tsigned:0;\n" 1083 "\tfield:unsigned char common_preempt_count;\toffset:3;\tsize:1;signed:0;\n" 1084 "\tfield:int common_pid;\toffset:4;\tsize:4;\tsigned:1;\n" 1085 "\n" 1086 "\tfield:unsigned long ip;\toffset:8;\tsize:8;\tsigned:0;\n" 1087 "\tfield:unsigned long parent_ip;\toffset:16;\tsize:8;\tsigned:0;\n" 1088 "\n" 1089 "print fmt: \" %%ps <-- %%ps\", (void *)REC->ip, (void *)REC->parent_ip\n"); 1090 len = strlen(str); 1091 tw->ptr += tputq(fout, len); 1092 tw->ptr += tputs(fout, str); 1093 1094 snprintf(str, sizeof(str), 1095 "name: funcgraph_entry\n" 1096 "ID: 11\n" 1097 "format:\n" 1098 "\tfield:unsigned short common_type;\toffset:0;\tsize:2;\tsigned:0;\n" 1099 "\tfield:unsigned char common_flags;\toffset:2;\tsize:1;\tsigned:0;\n" 1100 "\tfield:unsigned char common_preempt_count;\toffset:3;\tsize:1;signed:0;\n" 1101 "\tfield:int common_pid;\toffset:4;\tsize:4;\tsigned:1;\n" 1102 "\n" 1103 "\tfield:unsigned long func;\toffset:8;\tsize:8;\tsigned:0;\n" 1104 "\tfield:int depth;\toffset:16;\tsize:4;\tsigned:1;\n" 1105 "\n" 1106 "print fmt: \"--> %%ps (%%d)\", (void *)REC->func, REC->depth\n"); 1107 len = strlen(str); 1108 tw->ptr += tputq(fout, len); 1109 tw->ptr += tputs(fout, str); 1110 1111 snprintf(str, sizeof(str), 1112 "name: funcgraph_exit\n" 1113 "ID: 10\n" 1114 "format:\n" 1115 "\tfield:unsigned short common_type;\toffset:0;\tsize:2;\tsigned:0;\n" 1116 "\tfield:unsigned char common_flags;\toffset:2;\tsize:1;\tsigned:0;\n" 1117 "\tfield:unsigned char common_preempt_count;\toffset:3;\tsize:1;signed:0;\n" 1118 "\tfield:int common_pid;\toffset:4;\tsize:4;\tsigned:1;\n" 1119 "\n" 1120 "\tfield:unsigned long func;\toffset:8;\tsize:8;\tsigned:0;\n" 1121 "\tfield:int depth;\toffset:16;\tsize:4;\tsigned:1;\n" 1122 "\tfield:unsigned int overrun;\toffset:20;\tsize:4;\tsigned:0;\n" 1123 "\tfield:unsigned long long calltime;\toffset:24;\tsize:8;\tsigned:0;\n" 1124 "\tfield:unsigned long long rettime;\toffset:32;\tsize:8;\tsigned:0;\n" 1125 "\n" 1126 "print fmt: \"<-- %%ps (%%d) (start: %%llx end: %%llx) over: %%d\", (void *)REC->func, REC->depth, REC->calltime, REC->rettime, REC->depth\n"); 1127 len = strlen(str); 1128 tw->ptr += tputq(fout, len); 1129 tw->ptr += tputs(fout, str); 1130 1131 return 0; 1132} 1133 1134/** 1135 * write_symbols() - Write the symbols out 1136 * 1137 * Writes the symbol information in the following format to mimic the Linux 1138 * /proc/kallsyms file: 1139 * 1140 * <address> T <name> 1141 * 1142 * This updates tw->ptr as it goes 1143 * 1144 * @tw: Writer context 1145 * Returns: 0 on success, -ve on error 1146 */ 1147static int write_symbols(struct twriter *tw) 1148{ 1149 char str[200]; 1150 int ret, i; 1151 1152 /* write symbols */ 1153 ret = push_len(tw, tw->ptr + 4, "syms", 4); 1154 if (ret < 0) 1155 return -1; 1156 tw->ptr += ret; 1157 for (i = 0; i < func_count; i++) { 1158 struct func_info *func = &func_list[i]; 1159 1160 snprintf(str, sizeof(str), "%016lx T %s\n", 1161 text_offset + func->offset, func->name); 1162 tw->ptr += tputs(tw->fout, str); 1163 } 1164 ret = pop_len(tw, "syms"); 1165 if (ret < 0) 1166 return -1; 1167 tw->ptr += ret; 1168 1169 return 0; 1170} 1171 1172/** 1173 * write_options() - Write the options out 1174 * 1175 * Writes various options which are needed or useful. We use OPTION_TSC2NSEC 1176 * to indicates that values in the output need to be multiplied by 1000 since 1177 * U-Boot's trace values are in microseconds. 1178 * 1179 * This updates tw->ptr as it goes 1180 * 1181 * @tw: Writer context 1182 * Returns: 0 on success, -ve on error 1183 */ 1184static int write_options(struct twriter *tw) 1185{ 1186 FILE *fout = tw->fout; 1187 char str[200]; 1188 int len; 1189 1190 /* trace_printk, 0 for now */ 1191 tw->ptr += tputl(fout, 0); 1192 1193 /* processes */ 1194 snprintf(str, sizeof(str), "%d u-boot\n", TRACE_PID); 1195 len = strlen(str); 1196 tw->ptr += tputq(fout, len); 1197 tw->ptr += tputs(fout, str); 1198 1199 /* number of CPUs */ 1200 tw->ptr += tputl(fout, 1); 1201 1202 tw->ptr += fprintf(fout, "options %c", 0); 1203 1204 /* traceclock */ 1205 tw->ptr += tputh(fout, OPTION_TRACECLOCK); 1206 tw->ptr += tputl(fout, 0); 1207 1208 /* uname */ 1209 tw->ptr += tputh(fout, OPTION_UNAME); 1210 snprintf(str, sizeof(str), "U-Boot"); 1211 len = strlen(str); 1212 tw->ptr += tputl(fout, len); 1213 tw->ptr += tputs(fout, str); 1214 1215 /* version */ 1216 tw->ptr += tputh(fout, OPTION_VERSION); 1217 snprintf(str, sizeof(str), "unknown"); 1218 len = strlen(str); 1219 tw->ptr += tputl(fout, len); 1220 tw->ptr += tputs(fout, str); 1221 1222 /* trace ID */ 1223 tw->ptr += tputh(fout, OPTION_TRACEID); 1224 tw->ptr += tputl(fout, 8); 1225 tw->ptr += tputq(fout, 0x123456780abcdef0); 1226 1227 /* time conversion */ 1228 tw->ptr += tputh(fout, OPTION_TSC2NSEC); 1229 tw->ptr += tputl(fout, 16); 1230 tw->ptr += tputl(fout, 1000); /* multiplier */ 1231 tw->ptr += tputl(fout, 0); /* shift */ 1232 tw->ptr += tputq(fout, 0); /* offset */ 1233 1234 /* cpustat - bogus data for now, but at least it mentions the CPU */ 1235 tw->ptr += tputh(fout, OPTION_CPUSTAT); 1236 snprintf(str, sizeof(str), 1237 "CPU: 0\n" 1238 "entries: 100\n" 1239 "overrun: 43565\n" 1240 "commit overrun: 0\n" 1241 "bytes: 3360\n" 1242 "oldest event ts: 963732.447752\n" 1243 "now ts: 963832.146824\n" 1244 "dropped events: 0\n" 1245 "read events: 42379\n"); 1246 len = strlen(str); 1247 tw->ptr += tputl(fout, len); 1248 tw->ptr += tputs(fout, str); 1249 1250 tw->ptr += tputh(fout, OPTION_DONE); 1251 1252 return 0; 1253} 1254 1255/** 1256 * calc_min_depth() - Calculate the minimum call depth from the call list 1257 * 1258 * Starting with a depth of 0, this works through the call list, adding 1 for 1259 * each function call and subtracting 1 for each function return. Most likely 1260 * the value ends up being negative, since the trace does not start at the 1261 * very top of the call stack, e.g. main(), but some function called by that. 1262 * 1263 * This value can be used to calculate the depth value for the first call, 1264 * such that it never goes negative for subsequent returns. 1265 * 1266 * Returns: minimum call depth (e.g. -2) 1267 */ 1268static int calc_min_depth(void) 1269{ 1270 struct trace_call *call; 1271 int depth, min_depth, i; 1272 1273 /* Calculate minimum depth */ 1274 depth = 0; 1275 min_depth = 0; 1276 for (i = 0, call = call_list; i < call_count; i++, call++) { 1277 switch (TRACE_CALL_TYPE(call)) { 1278 case FUNCF_ENTRY: 1279 depth++; 1280 break; 1281 case FUNCF_EXIT: 1282 depth--; 1283 if (depth < min_depth) 1284 min_depth = depth; 1285 break; 1286 } 1287 } 1288 1289 return min_depth; 1290} 1291 1292/** 1293 * write_pages() - Write the pages of trace data 1294 * 1295 * This works through all the calls, writing out as many pages of data as are 1296 * needed. 1297 * 1298 * @tw: Writer context 1299 * @out_format: Output format to use 1300 * @missing_countp: Returns number of missing functions (not found in function 1301 * list) 1302 * @skip_countp: Returns number of skipped functions (excluded from trace) 1303 * 1304 * Returns: 0 on success, -ve on error 1305 */ 1306static int write_pages(struct twriter *tw, enum out_format_t out_format, 1307 int *missing_countp, int *skip_countp) 1308{ 1309 ulong func_stack[MAX_STACK_DEPTH]; 1310 int stack_ptr; /* next free position in stack */ 1311 int upto, depth, page_upto, i; 1312 int missing_count = 0, skip_count = 0; 1313 struct trace_call *call; 1314 ulong last_timestamp; 1315 FILE *fout = tw->fout; 1316 int last_delta = 0; 1317 int err_count; 1318 bool in_page; 1319 1320 in_page = false; 1321 last_timestamp = 0; 1322 upto = 0; 1323 page_upto = 0; 1324 err_count = 0; 1325 1326 /* maintain a stack of start times for calling functions */ 1327 stack_ptr = 0; 1328 1329 /* 1330 * The first thing in the trace may not be the top-level function, so 1331 * set the initial depth so that no function goes below depth 0 1332 */ 1333 depth = -calc_min_depth(); 1334 for (i = 0, call = call_list; i < call_count; i++, call++) { 1335 bool entry = TRACE_CALL_TYPE(call) == FUNCF_ENTRY; 1336 struct func_info *func; 1337 ulong timestamp; 1338 uint rec_words; 1339 int delta; 1340 1341 func = find_func_by_offset(call->func); 1342 if (!func) { 1343 warn("Cannot find function at %lx\n", 1344 text_offset + call->func); 1345 missing_count++; 1346 if (missing_count > 20) { 1347 /* perhaps trace does not match System.map */ 1348 fprintf(stderr, "Too many missing functions\n"); 1349 return -1; 1350 } 1351 continue; 1352 } 1353 1354 if (!(func->flags & FUNCF_TRACE)) { 1355 debug("Function '%s' is excluded from trace\n", 1356 func->name); 1357 skip_count++; 1358 continue; 1359 } 1360 1361 if (out_format == OUT_FMT_FUNCTION) 1362 rec_words = 6; 1363 else /* 2 header words and then 3 or 8 others */ 1364 rec_words = 2 + (entry ? 3 : 8); 1365 1366 /* convert timestamp from us to ns */ 1367 timestamp = call->flags & FUNCF_TIMESTAMP_MASK; 1368 if (in_page) { 1369 if (page_upto + rec_words * 4 > TRACE_PAGE_SIZE) { 1370 if (finish_page(tw)) 1371 return -1; 1372 in_page = false; 1373 } 1374 } 1375 if (!in_page) { 1376 if (start_page(tw, timestamp)) 1377 return -1; 1378 in_page = true; 1379 last_timestamp = timestamp; 1380 last_delta = 0; 1381 page_upto = tw->ptr & TRACE_PAGE_MASK; 1382 if (_DEBUG) { 1383 fprintf(stderr, 1384 "new page, last_timestamp=%ld, upto=%d\n", 1385 last_timestamp, upto); 1386 } 1387 } 1388 1389 delta = timestamp - last_timestamp; 1390 if (delta < 0) { 1391 fprintf(stderr, "Time went backwards\n"); 1392 err_count++; 1393 } 1394 1395 if (err_count > 20) { 1396 fprintf(stderr, "Too many errors, giving up\n"); 1397 return -1; 1398 } 1399 1400 if (delta > 0x07fffff) { 1401 /* 1402 * hard to imagine how this could happen since it means 1403 * that no function calls were made for a long time 1404 */ 1405 fprintf(stderr, "cannot represent time delta %x\n", 1406 delta); 1407 return -1; 1408 } 1409 1410 if (out_format == OUT_FMT_FUNCTION) { 1411 struct func_info *caller_func; 1412 1413 if (_DEBUG) { 1414 fprintf(stderr, "%d: delta=%d, stamp=%ld\n", 1415 upto, delta, timestamp); 1416 fprintf(stderr, 1417 " last_delta %x to %x: last_timestamp=%lx, " 1418 "timestamp=%lx, call->flags=%x, upto=%d\n", 1419 last_delta, delta, last_timestamp, 1420 timestamp, call->flags, upto); 1421 } 1422 1423 /* type_len is 6, meaning 4 * 6 = 24 bytes */ 1424 tw->ptr += tputl(fout, rec_words | (uint)delta << 5); 1425 tw->ptr += tputh(fout, TRACE_FN); 1426 tw->ptr += tputh(fout, 0); /* flags */ 1427 tw->ptr += tputl(fout, TRACE_PID); /* PID */ 1428 /* function */ 1429 tw->ptr += tputq(fout, text_offset + func->offset); 1430 caller_func = find_caller_by_offset(call->caller); 1431 /* caller */ 1432 tw->ptr += tputq(fout, 1433 text_offset + caller_func->offset); 1434 } else { 1435 tw->ptr += tputl(fout, rec_words | delta << 5); 1436 tw->ptr += tputh(fout, entry ? TRACE_GRAPH_ENT 1437 : TRACE_GRAPH_RET); 1438 tw->ptr += tputh(fout, 0); /* flags */ 1439 tw->ptr += tputl(fout, TRACE_PID); /* PID */ 1440 /* function */ 1441 tw->ptr += tputq(fout, text_offset + func->offset); 1442 tw->ptr += tputl(fout, depth); /* depth */ 1443 if (entry) { 1444 depth++; 1445 if (stack_ptr < MAX_STACK_DEPTH) 1446 func_stack[stack_ptr] = timestamp; 1447 stack_ptr++; 1448 } else { 1449 ulong func_duration = 0; 1450 1451 depth--; 1452 if (stack_ptr && stack_ptr <= MAX_STACK_DEPTH) { 1453 ulong start = func_stack[--stack_ptr]; 1454 1455 func_duration = timestamp - start; 1456 } 1457 tw->ptr += tputl(fout, 0); /* overrun */ 1458 tw->ptr += tputq(fout, 0); /* calltime */ 1459 /* rettime */ 1460 tw->ptr += tputq(fout, func_duration); 1461 } 1462 } 1463 1464 last_delta = delta; 1465 last_timestamp = timestamp; 1466 page_upto += 4 + rec_words * 4; 1467 upto++; 1468 if (stack_ptr == MAX_STACK_DEPTH) 1469 break; 1470 } 1471 if (in_page && finish_page(tw)) 1472 return -1; 1473 *missing_countp = missing_count; 1474 *skip_countp = skip_count; 1475 1476 return 0; 1477} 1478 1479/** 1480 * write_flyrecord() - Write the flyrecord information 1481 * 1482 * Writes the header and pages of data for the "flyrecord" section. It also 1483 * writes out the counter-type info, selecting "[local]" 1484 * 1485 * @tw: Writer context 1486 * @out_format: Output format to use 1487 * @missing_countp: Returns number of missing functions (not found in function 1488 * list) 1489 * @skip_countp: Returns number of skipped functions (excluded from trace) 1490 * 1491 * Returns: 0 on success, -ve on error 1492 */ 1493static int write_flyrecord(struct twriter *tw, enum out_format_t out_format, 1494 int *missing_countp, int *skip_countp) 1495{ 1496 unsigned long long start, start_ofs, len; 1497 int ret; 1498 FILE *fout = tw->fout; 1499 char str[200]; 1500 1501 /* Record start pointer */ 1502 start_ofs = tw->ptr; 1503 debug("Start of flyrecord header at: 0x%llx\n", start_ofs); 1504 1505 tw->ptr += fprintf(fout, "flyrecord%c", 0); 1506 1507 /* flyrecord\0 - allocated 10 bytes */ 1508 start_ofs += 10; 1509 1510 /* 1511 * 8 bytes that are a 64-bit word containing the offset into the file 1512 * that holds the data for the CPU. 1513 * 1514 * 8 bytes that are a 64-bit word containing the size of the CPU 1515 * data at that offset. 1516 */ 1517 start_ofs += 16; 1518 1519 snprintf(str, sizeof(str), 1520 "[local] global counter uptime perf mono mono_raw boot x86-tsc\n"); 1521 len = strlen(str); 1522 1523 /* trace clock length - 8 bytes */ 1524 start_ofs += 8; 1525 /* trace clock data */ 1526 start_ofs += len; 1527 1528 debug("Calculated flyrecord header end at: 0x%llx, trace clock len: 0x%llx\n", 1529 start_ofs, len); 1530 1531 /* trace data */ 1532 start = ALIGN(start_ofs, TRACE_PAGE_SIZE); 1533 tw->ptr += tputq(fout, start); 1534 1535 /* use a placeholder for the size */ 1536 ret = push_len(tw, start, "flyrecord", 8); 1537 if (ret < 0) 1538 return -1; 1539 tw->ptr += ret; 1540 1541 tw->ptr += tputq(fout, len); 1542 tw->ptr += tputs(fout, str); 1543 1544 debug("End of flyrecord header at: 0x%x, offset: 0x%llx\n", 1545 tw->ptr, start); 1546 1547 debug("trace text base %lx, map file %lx\n", text_base, text_offset); 1548 1549 ret = write_pages(tw, out_format, missing_countp, skip_countp); 1550 if (ret < 0) { 1551 fprintf(stderr, "Cannot output pages\n"); 1552 return -1; 1553 } 1554 1555 ret = pop_len(tw, "flyrecord"); 1556 if (ret < 0) { 1557 fprintf(stderr, "Cannot finish flyrecord header\n"); 1558 return -1; 1559 } 1560 1561 return 0; 1562} 1563 1564/** 1565 * make_ftrace() - Write out an ftrace file 1566 * 1567 * See here for format: 1568 * 1569 * https://github.com/rostedt/trace-cmd/blob/master/Documentation/trace-cmd/trace-cmd.dat.v7.5.txt 1570 * 1571 * @fout: Output file 1572 * @out_format: Output format to use 1573 * Returns: 0 on success, -ve on error 1574 */ 1575static int make_ftrace(FILE *fout, enum out_format_t out_format) 1576{ 1577 int missing_count, skip_count; 1578 struct twriter tws, *tw = &tws; 1579 int ret; 1580 1581 memset(tw, '\0', sizeof(*tw)); 1582 abuf_init(&tw->str_buf); 1583 tw->fout = fout; 1584 1585 tw->ptr = 0; 1586 ret = output_headers(tw); 1587 if (ret < 0) { 1588 fprintf(stderr, "Cannot output headers\n"); 1589 return -1; 1590 } 1591 /* number of event systems files */ 1592 tw->ptr += tputl(fout, 0); 1593 1594 ret = write_symbols(tw); 1595 if (ret < 0) { 1596 fprintf(stderr, "Cannot write symbols\n"); 1597 return -1; 1598 } 1599 1600 ret = write_options(tw); 1601 if (ret < 0) { 1602 fprintf(stderr, "Cannot write options\n"); 1603 return -1; 1604 } 1605 1606 ret = write_flyrecord(tw, out_format, &missing_count, &skip_count); 1607 if (ret < 0) { 1608 fprintf(stderr, "Cannot write flyrecord\n"); 1609 return -1; 1610 } 1611 1612 info("ftrace: %d functions not found, %d excluded\n", missing_count, 1613 skip_count); 1614 1615 return 0; 1616} 1617 1618/** 1619 * create_node() - Create a new node in the flamegraph tree 1620 * 1621 * @msg: Message to use for debugging if something goes wrong 1622 * Returns: Pointer to newly created node, or NULL on error 1623 */ 1624static struct flame_node *create_node(const char *msg) 1625{ 1626 struct flame_node *node; 1627 1628 node = calloc(1, sizeof(*node)); 1629 if (!node) { 1630 fprintf(stderr, "Out of memory for %s\n", msg); 1631 return NULL; 1632 } 1633 INIT_LIST_HEAD(&node->child_head); 1634 1635 return node; 1636} 1637 1638/** 1639 * process_call(): Add a call to the flamegraph info 1640 * 1641 * For function calls, if this call stack has been seen before, this increments 1642 * the call count, creating a new node if needed. 1643 * 1644 * For function returns, it adds up the time spent in this call stack, 1645 * subtracting the time spent by child functions. 1646 * 1647 * @state: Current flamegraph state 1648 * @entry: true if this is a function entry, false if a function exit 1649 * @timestamp: Timestamp from the trace file (in microseconds) 1650 * @func: Function that was called/returned from 1651 * 1652 * Returns: 0 on success, -ve on error 1653 */ 1654static int process_call(struct flame_state *state, bool entry, ulong timestamp, 1655 struct func_info *func) 1656{ 1657 struct flame_node *node = state->node; 1658 int stack_ptr = state->stack_ptr; 1659 1660 if (entry) { 1661 struct flame_node *child, *chd; 1662 1663 /* see if we have this as a child node already */ 1664 child = NULL; 1665 list_for_each_entry(chd, &node->child_head, sibling_node) { 1666 if (chd->func == func) { 1667 child = chd; 1668 break; 1669 } 1670 } 1671 if (!child) { 1672 /* create a new node */ 1673 child = create_node("child"); 1674 if (!child) 1675 return -1; 1676 list_add_tail(&child->sibling_node, &node->child_head); 1677 child->func = func; 1678 child->parent = node; 1679 state->nodes++; 1680 } 1681 debug("entry %s: move from %s to %s\n", func->name, 1682 node->func ? node->func->name : "(root)", 1683 child->func->name); 1684 child->count++; 1685 if (stack_ptr < MAX_STACK_DEPTH) { 1686 state->stack[stack_ptr].timestamp = timestamp; 1687 state->stack[stack_ptr].child_total = 0; 1688 } 1689 debug("%d: %20s: entry at %ld\n", stack_ptr, func->name, 1690 timestamp); 1691 stack_ptr++; 1692 node = child; 1693 } else if (node->parent) { 1694 ulong total_duration = 0, child_duration = 0; 1695 struct stack_info *stk; 1696 1697 debug("exit %s: move from %s to %s\n", func->name, 1698 node->func->name, node->parent->func ? 1699 node->parent->func->name : "(root)"); 1700 if (stack_ptr && stack_ptr <= MAX_STACK_DEPTH) { 1701 stk = &state->stack[--stack_ptr]; 1702 1703 /* 1704 * get total duration of the function which just 1705 * exited 1706 */ 1707 total_duration = timestamp - stk->timestamp; 1708 child_duration = stk->child_total; 1709 1710 if (stack_ptr) 1711 state->stack[stack_ptr - 1].child_total += total_duration; 1712 1713 debug("%d: %20s: exit at %ld, total %ld, child %ld, child_total=%ld\n", 1714 stack_ptr, func->name, timestamp, 1715 total_duration, child_duration, 1716 stk->child_total); 1717 } 1718 node->duration += total_duration - child_duration; 1719 node = node->parent; 1720 } 1721 1722 state->stack_ptr = stack_ptr; 1723 state->node = node; 1724 1725 return 0; 1726} 1727 1728/** 1729 * make_flame_tree() - Create a tree of stack traces 1730 * 1731 * Set up a tree, with the root node having the top-level functions as children 1732 * and the leaf nodes being leaf functions. Each node has a count of how many 1733 * times this function appears in the trace 1734 * 1735 * @out_format: Output format to use 1736 * @treep: Returns the resulting flamegraph tree 1737 * Returns: 0 on success, -ve on error 1738 */ 1739static int make_flame_tree(enum out_format_t out_format, 1740 struct flame_node **treep) 1741{ 1742 struct flame_state state; 1743 struct flame_node *tree; 1744 struct trace_call *call; 1745 int i; 1746 1747 /* maintain a stack of start times, etc. for 'calling' functions */ 1748 state.stack_ptr = 0; 1749 1750 tree = create_node("tree"); 1751 if (!tree) 1752 return -1; 1753 state.node = tree; 1754 state.nodes = 0; 1755 1756 for (i = 0, call = call_list; i < call_count; i++, call++) { 1757 bool entry = TRACE_CALL_TYPE(call) == FUNCF_ENTRY; 1758 ulong timestamp = call->flags & FUNCF_TIMESTAMP_MASK; 1759 struct func_info *func; 1760 1761 func = find_func_by_offset(call->func); 1762 if (!func) { 1763 warn("Cannot find function at %lx\n", 1764 text_offset + call->func); 1765 continue; 1766 } 1767 1768 if (process_call(&state, entry, timestamp, func)) 1769 return -1; 1770 } 1771 fprintf(stderr, "%d nodes\n", state.nodes); 1772 *treep = tree; 1773 1774 return 0; 1775} 1776 1777/** 1778 * output_tree() - Output a flamegraph tree 1779 * 1780 * Writes the tree out to a file in a format suitable for flamegraph.pl 1781 * 1782 * This works by maintaining a string shared across all recursive calls. The 1783 * function name for this node is added to the existing string, to make up the 1784 * full call-stack description. For example, on entry, @str_buf->data might 1785 * contain: 1786 * 1787 * "initf_bootstage;bootstage_mark_name" 1788 * ^ @base 1789 * 1790 * with @base pointing to the \0 at the end of the string. This function adds 1791 * a ';' following by the name of the current function, e.g. "timer_get_boot_us" 1792 * as well as the output value, to get the full line: 1793 * 1794 * initf_bootstage;bootstage_mark_name;timer_get_boot_us 123 1795 * 1796 * @fout: Output file 1797 * @out_format: Output format to use 1798 * @node: Node to output (pass the whole tree at first) 1799 * @str_buf: String buffer to use to build the output line 1800 * @base: Current base position in the string 1801 * @treep: Returns the resulting flamegraph tree 1802 * Returns 0 if OK, -1 on error 1803 */ 1804static int output_tree(FILE *fout, enum out_format_t out_format, 1805 const struct flame_node *node, struct abuf *str_buf, 1806 int base) 1807{ 1808 const struct flame_node *child; 1809 int pos; 1810 char *str = abuf_data(str_buf); 1811 1812 if (node->count) { 1813 if (out_format == OUT_FMT_FLAMEGRAPH_CALLS) { 1814 fprintf(fout, "%s %d\n", str, node->count); 1815 } else { 1816 /* 1817 * Write out the number of microseconds used by this 1818 * call stack. Since the time taken by child calls is 1819 * subtracted from this total, it can reach 0, meaning 1820 * that this function took no time beyond what its 1821 * children used. For this case, write 1 rather than 0, 1822 * so that this call stack appears in the flamegraph. 1823 * This has the effect of inflating the timing slightly, 1824 * but only by at most 1 microsecond per function, 1825 * assuming that is the timestamp resolution 1826 */ 1827 fprintf(fout, "%s %ld\n", str, 1828 node->duration ? node->duration : 1); 1829 } 1830 } 1831 1832 pos = base; 1833 if (pos) 1834 str[pos++] = ';'; 1835 list_for_each_entry(child, &node->child_head, sibling_node) { 1836 int len, needed; 1837 1838 len = strlen(child->func->name); 1839 needed = pos + len + 1; 1840 if (needed > abuf_size(str_buf)) { 1841 /* 1842 * We need to re-allocate the string buffer; increase 1843 * its size by multiples of 500 characters. 1844 */ 1845 needed = 500 * ((needed / 500) + 1); 1846 if (!abuf_realloc(str_buf, needed)) 1847 return -1; 1848 str = abuf_data(str_buf); 1849 memset(str + pos, 0, abuf_size(str_buf) - pos); 1850 } 1851 strcpy(str + pos, child->func->name); 1852 if (output_tree(fout, out_format, child, str_buf, pos + len)) 1853 return -1; 1854 /* 1855 * Update our pointer as the string buffer might have been 1856 * re-allocated. 1857 */ 1858 str = abuf_data(str_buf); 1859 } 1860 1861 return 0; 1862} 1863 1864/** 1865 * make_flamegraph() - Write out a flame graph 1866 * 1867 * @fout: Output file 1868 * @out_format: Output format to use, e.g. function counts or timing 1869 * Returns 0 if OK, -1 on error 1870 */ 1871static int make_flamegraph(FILE *fout, enum out_format_t out_format) 1872{ 1873 struct flame_node *tree; 1874 struct abuf str_buf; 1875 char *str; 1876 int ret = 0; 1877 1878 if (make_flame_tree(out_format, &tree)) 1879 return -1; 1880 1881 abuf_init(&str_buf); 1882 if (!abuf_realloc(&str_buf, 500)) 1883 return -1; 1884 1885 str = abuf_data(&str_buf); 1886 memset(str, 0, abuf_size(&str_buf)); 1887 if (output_tree(fout, out_format, tree, &str_buf, 0)) 1888 ret = -1; 1889 1890 abuf_uninit(&str_buf); 1891 return ret; 1892} 1893 1894/** 1895 * prof_tool() - Performs requested action 1896 * 1897 * @argc: Number of arguments (used to obtain the command 1898 * @argv: List of arguments 1899 * @trace_fname: Filename of input file (trace data from U-Boot) 1900 * @map_fname: Filename of map file (System.map from U-Boot) 1901 * @trace_config_fname: Trace-configuration file, or NULL if none 1902 * @out_fname: Output filename 1903 */ 1904static int prof_tool(int argc, char *const argv[], 1905 const char *trace_fname, const char *map_fname, 1906 const char *trace_config_fname, const char *out_fname, 1907 enum out_format_t out_format) 1908{ 1909 int err = 0; 1910 1911 if (read_map_file(map_fname)) 1912 return -1; 1913 if (trace_fname && read_trace_file(trace_fname)) 1914 return -1; 1915 if (trace_config_fname && read_trace_config_file(trace_config_fname)) 1916 return -1; 1917 1918 check_trace_config(); 1919 1920 for (; argc; argc--, argv++) { 1921 const char *cmd = *argv; 1922 1923 if (!strcmp(cmd, "dump-ftrace")) { 1924 FILE *fout; 1925 1926 if (out_format != OUT_FMT_FUNCTION && 1927 out_format != OUT_FMT_FUNCGRAPH) 1928 out_format = OUT_FMT_FUNCTION; 1929 fout = fopen(out_fname, "w"); 1930 if (!fout) { 1931 fprintf(stderr, "Cannot write file '%s'\n", 1932 out_fname); 1933 return -1; 1934 } 1935 err = make_ftrace(fout, out_format); 1936 fclose(fout); 1937 } else if (!strcmp(cmd, "dump-flamegraph")) { 1938 FILE *fout; 1939 1940 if (out_format != OUT_FMT_FLAMEGRAPH_CALLS && 1941 out_format != OUT_FMT_FLAMEGRAPH_TIMING) 1942 out_format = OUT_FMT_FLAMEGRAPH_CALLS; 1943 fout = fopen(out_fname, "w"); 1944 if (!fout) { 1945 fprintf(stderr, "Cannot write file '%s'\n", 1946 out_fname); 1947 return -1; 1948 } 1949 err = make_flamegraph(fout, out_format); 1950 fclose(fout); 1951 } else { 1952 warn("Unknown command '%s'\n", cmd); 1953 } 1954 } 1955 1956 return err; 1957} 1958 1959int main(int argc, char *argv[]) 1960{ 1961 enum out_format_t out_format = OUT_FMT_DEFAULT; 1962 const char *map_fname = "System.map"; 1963 const char *trace_fname = NULL; 1964 const char *config_fname = NULL; 1965 const char *out_fname = NULL; 1966 int opt; 1967 1968 verbose = 2; 1969 while ((opt = getopt(argc, argv, "c:f:m:o:t:v:")) != -1) { 1970 switch (opt) { 1971 case 'c': 1972 config_fname = optarg; 1973 break; 1974 case 'f': 1975 if (!strcmp("function", optarg)) { 1976 out_format = OUT_FMT_FUNCTION; 1977 } else if (!strcmp("funcgraph", optarg)) { 1978 out_format = OUT_FMT_FUNCGRAPH; 1979 } else if (!strcmp("calls", optarg)) { 1980 out_format = OUT_FMT_FLAMEGRAPH_CALLS; 1981 } else if (!strcmp("timing", optarg)) { 1982 out_format = OUT_FMT_FLAMEGRAPH_TIMING; 1983 } else { 1984 fprintf(stderr, 1985 "Invalid format: use function, funcgraph, calls, timing\n"); 1986 exit(1); 1987 } 1988 break; 1989 case 'm': 1990 map_fname = optarg; 1991 break; 1992 case 'o': 1993 out_fname = optarg; 1994 break; 1995 case 't': 1996 trace_fname = optarg; 1997 break; 1998 case 'v': 1999 verbose = atoi(optarg); 2000 break; 2001 default: 2002 usage(); 2003 } 2004 } 2005 argc -= optind; argv += optind; 2006 if (argc < 1) 2007 usage(); 2008 2009 if (!out_fname || !map_fname || !trace_fname) { 2010 fprintf(stderr, 2011 "Must provide trace data, System.map file and output file\n"); 2012 usage(); 2013 } 2014 2015 debug("Debug enabled\n"); 2016 return prof_tool(argc, argv, trace_fname, map_fname, config_fname, 2017 out_fname, out_format); 2018} 2019