This tool provides the facility to decode U-Boot trace data and write out a text file in Linux ftrace format for use with pytimechart.
Signed-off-by: Simon Glass sjg@chromium.org --- Changes in v2: None
Makefile | 3 +- tools/.gitignore | 1 + tools/Makefile | 6 + tools/proftool.c | 611 +++++++++++++++++++++++++++++++++++++++++++++++++++++++ 4 files changed, 620 insertions(+), 1 deletion(-) create mode 100644 tools/proftool.c
diff --git a/Makefile b/Makefile index ef154aa..29af07a 100644 --- a/Makefile +++ b/Makefile @@ -824,7 +824,8 @@ clean: $(obj)tools/mk{smdk5250,}spl \ $(obj)tools/mxsboot \ $(obj)tools/ncb $(obj)tools/ubsha1 \ - $(obj)tools/kernel-doc/docproc + $(obj)tools/kernel-doc/docproc \ + $(obj)tools/proftool @rm -f $(obj)board/cray/L1/{bootscript.c,bootscript.image} \ $(obj)board/matrix_vision/*/bootscript.img \ $(obj)board/voiceblue/eeprom \ diff --git a/tools/.gitignore b/tools/.gitignore index 9bce719..a7fee26 100644 --- a/tools/.gitignore +++ b/tools/.gitignore @@ -9,6 +9,7 @@ /mxsboot /ncb /ncp +/proftool /ubsha1 /xway-swap-bytes /*.exe diff --git a/tools/Makefile b/tools/Makefile index 26eb500..569dc77 100644 --- a/tools/Makefile +++ b/tools/Makefile @@ -74,6 +74,7 @@ BIN_FILES-$(CONFIG_MX28) += mxsboot$(SFX) BIN_FILES-$(CONFIG_NETCONSOLE) += ncb$(SFX) BIN_FILES-$(CONFIG_SHA1_CHECK_UB_IMG) += ubsha1$(SFX) BIN_FILES-$(CONFIG_KIRKWOOD) += kwboot$(SFX) +BIN_FILES-y += proftool(SFX)
# Source files which exist outside the tools directory EXT_OBJ_FILES-$(CONFIG_BUILD_ENVCRC) += common/env_embedded.o @@ -87,6 +88,7 @@ EXT_OBJ_FILES-y += lib/sha1.o OBJ_FILES-$(CONFIG_LCD_LOGO) += bmp_logo.o OBJ_FILES-$(CONFIG_VIDEO_LOGO) += bmp_logo.o NOPED_OBJ_FILES-y += default_image.o +NOPED_OBJ_FILES-y += proftool.o OBJ_FILES-$(CONFIG_BUILD_ENVCRC) += envcrc.o NOPED_OBJ_FILES-y += fit_image.o OBJ_FILES-$(CONFIG_CMD_NET) += gen_eth_addr.o @@ -187,6 +189,10 @@ $(obj)bmp_logo$(SFX): $(obj)bmp_logo.o $(HOSTCC) $(HOSTCFLAGS) $(HOSTLDFLAGS) -o $@ $^ $(HOSTSTRIP) $@
+$(obj)proftool(SFX): $(obj)proftool.o + $(HOSTCC) $(HOSTCFLAGS) $(HOSTLDFLAGS) -o $@ $^ + $(HOSTSTRIP) $@ + $(obj)envcrc$(SFX): $(obj)crc32.o $(obj)env_embedded.o $(obj)envcrc.o $(obj)sha1.o $(HOSTCC) $(HOSTCFLAGS) $(HOSTLDFLAGS) -o $@ $^
diff --git a/tools/proftool.c b/tools/proftool.c new file mode 100644 index 0000000..a48ed28 --- /dev/null +++ b/tools/proftool.c @@ -0,0 +1,611 @@ +/* + * Copyright (c) 2013 Google, Inc + * + * This program is free software; you can redistribute it and/or + * modify it under the terms of the GNU General Public License as + * published by the Free Software Foundation; either version 2 of + * the License, or (at your option) any later version. + * + * This program is distributed in the hope that it will be useful, + * but WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the + * GNU General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * along with this program; if not, write to the Free Software + * Foundation, Inc., 59 Temple Place, Suite 330, Boston, + * MA 02111-1307 USA + */ + +/* Decode and dump U-Boot profiling information */ + +#include <assert.h> +#include <ctype.h> +#include <limits.h> +#include <regex.h> +#include <stdarg.h> +#include <stdio.h> +#include <stdlib.h> +#include <string.h> +#include <unistd.h> +#include <sys/param.h> + +#include <compiler.h> +#include <trace.h> + +#define MAX_LINE_LEN 500 + +enum { + FUNCF_TRACE = 1 << 0, /* Include this function in trace */ +}; + +struct func_info { + unsigned long offset; + const char *name; + unsigned long code_size; + unsigned long call_count; + unsigned flags; + /* the section this function is in */ + struct objsection_info *objsection; +}; + +enum trace_line_type { + TRACE_LINE_INCLUDE, + TRACE_LINE_EXCLUDE, +}; + +struct trace_configline_info { + struct trace_configline_info *next; + enum trace_line_type type; + const char *name; /* identifier name / wildcard */ + regex_t regex; /* Regex to use if name starts with / */ +}; + +/* The contents of the trace config file */ +struct trace_configline_info *trace_config_head; + +struct func_info *func_list; +int func_count; +struct trace_call *call_list; +int call_count; +int verbose; /* Verbosity level 0=none, 1=warn, 2=notice, 3=info, 4=debug */ +unsigned long text_offset; /* text address of first function */ + +static void outf(int level, const char *fmt, ...) + __attribute__ ((format (__printf__, 2, 3))); +#define error(fmt, b...) outf(0, fmt, ##b) +#define warn(fmt, b...) outf(1, fmt, ##b) +#define notice(fmt, b...) outf(2, fmt, ##b) +#define info(fmt, b...) outf(3, fmt, ##b) +#define debug(fmt, b...) outf(4, fmt, ##b) + + +static void outf(int level, const char *fmt, ...) +{ + if (verbose >= level) { + va_list args; + + va_start(args, fmt); + vfprintf(stderr, fmt, args); + va_end(args); + } +} + +static void usage(void) +{ + fprintf(stderr, + "Usage: proftool -cds -v3 <cmd> <profdata>\n" + "\n" + "Commands\n" + " dump-ftrace\t\tDump out textual data in ftrace format\n" + "\n" + "Options:\n" + " -m <map>\tSpecify Systen.map file\n" + " -t <trace>\tSpecific trace data file (from U-Boot)\n" + " -v <0-4>\tSpecify verbosity\n"); + exit(EXIT_FAILURE); +} + +static int h_cmp_offset(const void *v1, const void *v2) +{ + const struct func_info *f1 = v1, *f2 = v2; + + return (f1->offset / FUNC_SITE_SIZE) - (f2->offset / FUNC_SITE_SIZE); +} + +static int read_system_map(FILE *fin) +{ + unsigned long offset, start = 0; + struct func_info *func; + char buff[MAX_LINE_LEN]; + char symtype; + char symname[MAX_LINE_LEN + 1]; + int linenum; + int alloced; + + for (linenum = 1, alloced = func_count = 0;; linenum++) { + int fields = 0; + + if (fgets(buff, sizeof(buff), fin)) + fields = sscanf(buff, "%lx %c %100s\n", &offset, + &symtype, symname); + if (fields == 2) { + continue; + } else if (feof(fin)) { + break; + } else if (fields < 2) { + error("Map file line %d: invalid format\n", linenum); + return 1; + } + + /* Must be a text symbol */ + symtype = tolower(symtype); + if (symtype != 't' && symtype != 'w') + continue; + + if (func_count == alloced) { + alloced += 256; + func_list = realloc(func_list, + sizeof(struct func_info) * alloced); + assert(func_list); + } + if (!func_count) + start = offset; + + func = &func_list[func_count++]; + memset(func, '\0', sizeof(*func)); + func->offset = offset - start; + func->name = strdup(symname); + func->flags = FUNCF_TRACE; /* trace by default */ + + /* Update previous function's code size */ + if (func_count > 1) + func[-1].code_size = func->offset - func[-1].offset; + } + notice("%d functions found in map file\n", func_count); + text_offset = start; + return 0; +} + +static int read_data(FILE *fin, void *buff, int size) +{ + int err; + + err = fread(buff, 1, size, fin); + if (!err) + return 1; + if (err != size) { + error("Cannot read profile file at pos %ld\n", ftell(fin)); + return -1; + } + return 0; +} + +static struct func_info *find_func_by_offset(uint32_t offset) +{ + struct func_info key, *found; + + key.offset = offset; + found = bsearch(&key, func_list, func_count, sizeof(struct func_info), + h_cmp_offset); + + return found; +} + +/* This finds the function which contains the given offset */ +static struct func_info *find_caller_by_offset(uint32_t offset) +{ + int low; /* least function that could be a match */ + int high; /* greated function that could be a match */ + struct func_info key; + + low = 0; + high = func_count - 1; + key.offset = offset; + while (high > low + 1) { + int mid = (low + high) / 2; + int result; + + result = h_cmp_offset(&key, &func_list[mid]); + if (result > 0) + low = mid; + else if (result < 0) + high = mid; + else + return &func_list[mid]; + } + + return low >= 0 ? &func_list[low] : NULL; +} + +static int read_calls(FILE *fin, int count) +{ + struct trace_call *call_data; + int i; + + notice("call count: %d\n", count); + call_list = (struct trace_call *)calloc(count, sizeof(*call_data)); + if (!call_list) { + error("Cannot allocate call_list\n"); + return -1; + } + call_count = count; + + call_data = call_list; + for (i = 0; i < count; i++, call_data++) { + if (read_data(fin, call_data, sizeof(*call_data))) + return 1; + } + return 0; +} + +static int read_profile(FILE *fin, int *not_found) +{ + struct trace_output_hdr hdr; + + *not_found = 0; + while (!feof(fin)) { + int err; + + err = read_data(fin, &hdr, sizeof(hdr)); + if (err == 1) + break; /* EOF */ + else if (err) + return 1; + + switch (hdr.type) { + case TRACE_CHUNK_FUNCS: + /* Ignored at present */ + break; + + case TRACE_CHUNK_CALLS: + if (read_calls(fin, hdr.rec_count)) + return 1; + break; + } + } + return 0; +} + +static int read_map_file(const char *fname) +{ + FILE *fmap; + int err = 0; + + fmap = fopen(fname, "r"); + if (!fmap) { + error("Cannot open map file '%s'\n", fname); + return 1; + } + if (fmap) { + err = read_system_map(fmap); + fclose(fmap); + } + return err; +} + +static int read_profile_file(const char *fname) +{ + int not_found = INT_MAX; + FILE *fprof; + int err; + + fprof = fopen(fname, "rb"); + if (!fprof) { + error("Cannot open profile data file '%s'\n", + fname); + return 1; + } else { + err = read_profile(fprof, ¬_found); + fclose(fprof); + if (err) + return err; + + if (not_found) { + warn("%d profile functions could not be found in the map file - are you sure that your profile data and map file correspond?\n", + not_found); + return 1; + } + } + return 0; +} + +static int regex_report_error(regex_t *regex, int err, const char *op, + const char *name) +{ + char buf[200]; + + regerror(err, regex, buf, sizeof(buf)); + error("Regex error '%s' in %s '%s'\n", buf, op, name); + return -1; +} + +static void check_trace_config_line(struct trace_configline_info *item) +{ + struct func_info *func, *end; + int err; + + debug("Checking trace config line '%s'\n", item->name); + for (func = func_list, end = func + func_count; func < end; func++) { + err = regexec(&item->regex, func->name, 0, NULL, 0); + debug(" - regex '%s', string '%s': %d\n", item->name, + func->name, err); + if (err == REG_NOMATCH) + continue; + + if (err != REG_NOERROR) { + regex_report_error(&item->regex, err, "match", + item->name); + break; + } + + /* It matches, so perform the action */ + switch (item->type) { + case TRACE_LINE_INCLUDE: + info(" include %s at %lx\n", func->name, + text_offset + func->offset); + func->flags |= FUNCF_TRACE; + break; + + case TRACE_LINE_EXCLUDE: + info(" exclude %s at %lx\n", func->name, + text_offset + func->offset); + func->flags &= ~FUNCF_TRACE; + break; + } + } +} + +static void check_trace_config(void) +{ + struct trace_configline_info *line; + + for (line = trace_config_head; line; line = line->next) + check_trace_config_line(line); +} + +/** + * Check the functions to see if they each have an objsection. If not, then + * the linker must have eliminated them. + */ +static void check_functions(void) +{ + struct func_info *func, *end; + unsigned long removed_code_size = 0; + int not_found = 0; + + /* Look for missing functions */ + for (func = func_list, end = func + func_count; func < end; func++) { + if (!func->objsection) { + removed_code_size += func->code_size; + not_found++; + } + } + + /* Figure out what functions we want to trace */ + check_trace_config(); + + warn("%d functions removed by linker, %ld code size\n", + not_found, removed_code_size); +} + +static int read_trace_config(FILE *fin) +{ + char buff[200]; + int linenum = 0; + struct trace_configline_info **tailp = &trace_config_head; + + while (fgets(buff, sizeof(buff), fin)) { + int len = strlen(buff); + struct trace_configline_info *line; + char *saveptr; + char *s, *tok; + int err; + + linenum++; + if (len && buff[len - 1] == '\n') + buff[len - 1] = '\0'; + + /* skip blank lines and comments */ + for (s = buff; *s == ' ' || *s == '\t'; s++) + ; + if (!*s || *s == '#') + continue; + + line = (struct trace_configline_info *)calloc(1, + sizeof(*line)); + if (!line) { + error("Cannot allocate config line\n"); + return -1; + } + + tok = strtok_r(s, " \t", &saveptr); + if (!tok) { + error("Invalid trace config data on line %d\n", + linenum); + return -1; + } + if (0 == strcmp(tok, "include-func")) { + line->type = TRACE_LINE_INCLUDE; + } else if (0 == strcmp(tok, "exclude-func")) { + line->type = TRACE_LINE_EXCLUDE; + } else { + error("Unknown command in trace config data line %d\n", + linenum); + return -1; + } + + tok = strtok_r(NULL, " \t", &saveptr); + if (!tok) { + error("Missing pattern in trace config data line %d\n", + linenum); + return -1; + } + + err = regcomp(&line->regex, tok, REG_NOSUB); + if (err) { + free(line); + return regex_report_error(&line->regex, err, "compile", + tok); + } + + /* link this new one to the end of the list */ + line->name = strdup(tok); + line->next = NULL; + *tailp = line; + tailp = &line->next; + } + + if (!feof(fin)) { + error("Cannot read from trace config file at position %ld\n", + ftell(fin)); + return -1; + } + return 0; +} + +static int read_trace_config_file(const char *fname) +{ + FILE *fin; + int err; + + fin = fopen(fname, "r"); + if (!fin) { + error("Cannot open trace_config file '%s'\n", fname); + return -1; + } + err = read_trace_config(fin); + fclose(fin); + return err; +} + +static void out_func(ulong func_offset, int is_caller, const char *suffix) +{ + struct func_info *func; + + func = (is_caller ? find_caller_by_offset : find_func_by_offset) + (func_offset); + + if (func) + printf("%s%s", func->name, suffix); + else + printf("%lx%s", func_offset, suffix); +} + +/* + * # tracer: function + * # + * # TASK-PID CPU# TIMESTAMP FUNCTION + * # | | | | | + * # bash-4251 [01] 10152.583854: path_put <-path_walk + * # bash-4251 [01] 10152.583855: dput <-path_put + * # bash-4251 [01] 10152.583855: _atomic_dec_and_lock <-dput + */ +static int make_ftrace(void) +{ + struct trace_call *call; + int missing_count = 0, skip_count = 0; + int i; + + printf("# tracer: ftrace\n" + "#\n" + "# TASK-PID CPU# TIMESTAMP FUNCTION\n" + "# | | | | |\n"); + for (i = 0, call = call_list; i < call_count; i++, call++) { + struct func_info *func = find_func_by_offset(call->func); + ulong time = call->flags & FUNCF_TIMESTAMP_MASK; + + if (TRACE_CALL_TYPE(call) != FUNCF_ENTRY && + TRACE_CALL_TYPE(call) != FUNCF_EXIT) + continue; + if (!func) { + warn("Cannot find function at %lx\n", + text_offset + call->func); + missing_count++; + continue; + } + + if (!(func->flags & FUNCF_TRACE)) { + debug("Funcion '%s' is excluded from trace\n", + func->name); + skip_count++; + continue; + } + + printf("%16s-%-5d [01] %lu.%06lu: ", "uboot", 1, + time / 1000000, time % 1000000); + + out_func(call->func, 0, " <- "); + out_func(call->caller, 1, "\n"); + } + info("ftrace: %d functions not found, %d excluded\n", missing_count, + skip_count); + + return 0; +} + +static int prof_tool(int argc, char * const argv[], + const char *prof_fname, const char *map_fname, + const char *trace_config_fname) +{ + int err = 0; + + if (read_map_file(map_fname)) + return -1; + if (prof_fname && read_profile_file(prof_fname)) + return -1; + if (trace_config_fname && read_trace_config_file(trace_config_fname)) + return -1; + + check_functions(); + + for (; argc; argc--, argv++) { + const char *cmd = *argv; + + if (0 == strcmp(cmd, "dump-ftrace")) + err = make_ftrace(); + else + warn("Unknown command '%s'\n", cmd); + } + + return err; +} + +int main(int argc, char *argv[]) +{ + const char *map_fname = "System.map"; + const char *prof_fname = NULL; + const char *trace_config_fname = NULL; + int opt; + + verbose = 2; + while ((opt = getopt(argc, argv, "m:p:t:v:")) != -1) { + switch (opt) { + case 'm': + map_fname = optarg; + break; + + case 'p': + prof_fname = optarg; + break; + + case 't': + trace_config_fname = optarg; + break; + + case 'v': + verbose = atoi(optarg); + break; + + default: + usage(); + } + } + argc -= optind; argv += optind; + if (argc < 1) + usage(); + + debug("Debug enabled\n"); + return prof_tool(argc, argv, prof_fname, map_fname, + trace_config_fname); +}