[PATCH 19/24] trace: Support output of funcgraph records
Simon Glass
sjg at chromium.org
Sun Jan 15 22:15:56 CET 2023
Add support for writing ftrace records in the 'funcgraph' format, which
shows function entry and exit points as well as the time taken by each
function.
Signed-off-by: Simon Glass <sjg at chromium.org>
---
tools/proftool.c | 182 ++++++++++++++++++++++++++++++++++++++---------
1 file changed, 150 insertions(+), 32 deletions(-)
diff --git a/tools/proftool.c b/tools/proftool.c
index b5b8a9f7938..588ae48a0c8 100644
--- a/tools/proftool.c
+++ b/tools/proftool.c
@@ -47,6 +47,19 @@ enum {
MAX_LINE_LEN = 500, /* Max characters per line */
};
+/**
+ * enum out_format_t - supported output formats
+ *
+ * @OUT_FMT_DEFAULT: Use the default for the output file
+ * @OUT_FMT_FUNCTION: Write ftrace 'function' records
+ * @OUT_FMT_FUNCGRAPH: Write ftrace funcgraph_entry and funcgraph_exit records
+ */
+enum out_format_t {
+ OUT_FMT_DEFAULT,
+ OUT_FMT_FUNCTION,
+ OUT_FMT_FUNCGRAPH,
+};
+
/* Section types for v7 format (trace-cmd format) */
enum {
SECTION_OPTIONS,
@@ -211,10 +224,15 @@ static void usage(void)
"\n"
"Options:\n"
" -c <cfg>\tSpecify config file\n"
+ " -f <subtype>\tSpecify output subtype\n"
" -m <map>\tSpecify Systen.map file\n"
" -o <fname>\tSpecify output file\n"
" -t <fname>\tSpecify trace data file (from U-Boot 'trace calls')\n"
- " -v <0-4>\tSpecify verbosity\n");
+ " -v <0-4>\tSpecify verbosity\n"
+ "\n"
+ "Subtypes for dump-ftrace:\n"
+ " function - write function-call records (caller/callee)\n"
+ " funcgraph - write function entry/exit records (graph)\n");
exit(EXIT_FAILURE);
}
@@ -1165,6 +1183,43 @@ static int write_options(struct twriter *tw)
return 0;
}
+/**
+ * calc_min_depth() - Calculate the minimum call depth from the call list
+ *
+ * Starting with a depth of 0, this works through the call list, adding 1 for
+ * each function call and subtracting 1 for each function return. Most likely
+ * the value ends up being negative, since the trace does not start at the
+ * very top of the call stack, e.g. main(), but some function called by that.
+ *
+ * This value can be used to calculate the depth value for the first call,
+ * such that it never goes negative for subsequent returns.
+ *
+ * Returns: minimum call depth (e.g. -2)
+ */
+static int calc_min_depth(void)
+{
+ struct trace_call *call;
+ int depth, min_depth, i;
+
+ /* Calculate minimum depth */
+ depth = 0;
+ min_depth = 0;
+ for (i = 0, call = call_list; i < call_count; i++, call++) {
+ switch (TRACE_CALL_TYPE(call)) {
+ case FUNCF_ENTRY:
+ depth++;
+ break;
+ case FUNCF_EXIT:
+ depth--;
+ if (depth < min_depth)
+ min_depth = depth;
+ break;
+ }
+ }
+
+ return min_depth;
+}
+
/**
* write_pages() - Write the pages of trace data
*
@@ -1172,17 +1227,19 @@ static int write_options(struct twriter *tw)
* needed.
*
* @tw: Writer context
+ * @out_format: Output format to use
* @missing_countp: Returns number of missing functions (not found in function
* list)
* @skip_countp: Returns number of skipped functions (excluded from trace)
*
* Returns: 0 on success, -ve on error
*/
-static int write_pages(struct twriter *tw, int *missing_countp,
- int *skip_countp)
+static int write_pages(struct twriter *tw, enum out_format_t out_format,
+ int *missing_countp, int *skip_countp)
{
+ ulong func_stack[MAX_STACK_DEPTH];
int stack_ptr; /* next free position in stack */
- int upto, page_upto, i;
+ int upto, depth, page_upto, i;
int missing_count = 0, skip_count = 0;
struct trace_call *call;
ulong last_timestamp;
@@ -1200,8 +1257,13 @@ static int write_pages(struct twriter *tw, int *missing_countp,
/* maintain a stack of start times for calling functions */
stack_ptr = 0;
+ /*
+ * The first thing in the trace may not be the top-level function, so
+ * set the initial depth so that no function goes below depth 0
+ */
+ depth = -calc_min_depth();
for (i = 0, call = call_list; i < call_count; i++, call++) {
- struct func_info *caller_func;
+ bool entry = TRACE_CALL_TYPE(call) == FUNCF_ENTRY;
struct func_info *func;
ulong timestamp;
uint rec_words;
@@ -1227,7 +1289,10 @@ static int write_pages(struct twriter *tw, int *missing_countp,
continue;
}
- rec_words = 6;
+ if (out_format == OUT_FMT_FUNCTION)
+ rec_words = 6;
+ else /* 2 header words and then 3 or 8 others */
+ rec_words = 2 + (entry ? 3 : 8);
/* convert timestamp from us to ns */
timestamp = call->flags & FUNCF_TIMESTAMP_MASK;
@@ -1273,24 +1338,59 @@ static int write_pages(struct twriter *tw, int *missing_countp,
return -1;
}
- if (_DEBUG) {
- fprintf(stderr, "%d: delta=%d, stamp=%ld\n",
- upto, delta, timestamp);
- fprintf(stderr,
- " last_delta %x to %x: last_timestamp=%lx, timestamp=%lx, call->flags=%x, upto=%d\n",
- last_delta, delta, last_timestamp, timestamp, call->flags, upto);
- }
+ if (out_format == OUT_FMT_FUNCTION) {
+ struct func_info *caller_func;
- /* type_len is 6, meaning 4 * 6 = 24 bytes */
- tw->ptr += tputl(fout, rec_words | (uint)delta << 5);
- tw->ptr += tputh(fout, TRACE_FN);
- tw->ptr += tputh(fout, 0); /* flags */
- tw->ptr += tputl(fout, TRACE_PID); /* PID */
- /* function */
- tw->ptr += tputq(fout, text_offset + func->offset);
- caller_func = find_caller_by_offset(call->caller);
- /* caller */
- tw->ptr += tputq(fout, text_offset + caller_func->offset);
+ if (_DEBUG) {
+ fprintf(stderr, "%d: delta=%d, stamp=%ld\n",
+ upto, delta, timestamp);
+ fprintf(stderr,
+ " last_delta %x to %x: last_timestamp=%lx, "
+ "timestamp=%lx, call->flags=%x, upto=%d\n",
+ last_delta, delta, last_timestamp,
+ timestamp, call->flags, upto);
+ }
+
+ /* type_len is 6, meaning 4 * 6 = 24 bytes */
+ tw->ptr += tputl(fout, rec_words | (uint)delta << 5);
+ tw->ptr += tputh(fout, TRACE_FN);
+ tw->ptr += tputh(fout, 0); /* flags */
+ tw->ptr += tputl(fout, TRACE_PID); /* PID */
+ /* function */
+ tw->ptr += tputq(fout, text_offset + func->offset);
+ caller_func = find_caller_by_offset(call->caller);
+ /* caller */
+ tw->ptr += tputq(fout,
+ text_offset + caller_func->offset);
+ } else {
+ tw->ptr += tputl(fout, rec_words | delta << 5);
+ tw->ptr += tputh(fout, entry ? TRACE_GRAPH_ENT
+ : TRACE_GRAPH_RET);
+ tw->ptr += tputh(fout, 0); /* flags */
+ tw->ptr += tputl(fout, TRACE_PID); /* PID */
+ /* function */
+ tw->ptr += tputq(fout, text_offset + func->offset);
+ tw->ptr += tputl(fout, depth); /* depth */
+ if (entry) {
+ depth++;
+ if (stack_ptr < MAX_STACK_DEPTH)
+ func_stack[stack_ptr] = timestamp;
+ stack_ptr++;
+ } else {
+ ulong func_duration = 0;
+
+ depth--;
+ if (stack_ptr && stack_ptr <= MAX_STACK_DEPTH) {
+ ulong start = func_stack[--stack_ptr];
+
+ func_duration = timestamp - start;
+ }
+ tw->ptr += tputl(fout, 0); /* overrun */
+ tw->ptr += tputq(fout, 0); /* calltime */
+ /* rettime */
+ tw->ptr += tputq(fout, func_duration);
+ }
+ }
last_delta = delta;
last_timestamp = timestamp;
@@ -1314,14 +1414,15 @@ static int write_pages(struct twriter *tw, int *missing_countp,
* writes out the counter-type info, selecting "[local]"
*
* @tw: Writer context
+ * @out_format: Output format to use
* @missing_countp: Returns number of missing functions (not found in function
* list)
* @skip_countp: Returns number of skipped functions (excluded from trace)
*
* Returns: 0 on success, -ve on error
*/
-static int write_flyrecord(struct twriter *tw, int *missing_countp,
- int *skip_countp)
+static int write_flyrecord(struct twriter *tw, enum out_format_t out_format,
+ int *missing_countp, int *skip_countp)
{
int start, ret, len;
FILE *fout = tw->fout;
@@ -1347,7 +1448,7 @@ static int write_flyrecord(struct twriter *tw, int *missing_countp,
debug("trace text base %lx, map file %lx\n", text_base, text_offset);
- ret = write_pages(tw, missing_countp, skip_countp);
+ ret = write_pages(tw, out_format, missing_countp, skip_countp);
if (ret < 0) {
fprintf(stderr, "Cannot output pages\n");
return -1;
@@ -1370,9 +1471,10 @@ static int write_flyrecord(struct twriter *tw, int *missing_countp,
* https://github.com/rostedt/trace-cmd/blob/master/Documentation/trace-cmd/trace-cmd.dat.v7.5.txt
*
* @fout: Output file
+ * @out_format: Output format to use
* Returns: 0 on success, -ve on error
*/
-static int make_ftrace(FILE *fout)
+static int make_ftrace(FILE *fout, enum out_format_t out_format)
{
int missing_count, skip_count;
struct twriter tws, *tw = &tws;
@@ -1403,7 +1505,7 @@ static int make_ftrace(FILE *fout)
return -1;
}
- ret = write_flyrecord(tw, &missing_count, &skip_count);
+ ret = write_flyrecord(tw, out_format, &missing_count, &skip_count);
if (ret < 0) {
fprintf(stderr, "Cannot write flyrecord\n");
return -1;
@@ -1427,7 +1529,8 @@ static int make_ftrace(FILE *fout)
*/
static int prof_tool(int argc, char *const argv[],
const char *trace_fname, const char *map_fname,
- const char *trace_config_fname, const char *out_fname)
+ const char *trace_config_fname, const char *out_fname,
+ enum out_format_t out_format)
{
int err = 0;
@@ -1446,13 +1549,16 @@ static int prof_tool(int argc, char *const argv[],
if (!strcmp(cmd, "dump-ftrace")) {
FILE *fout;
+ if (out_format != OUT_FMT_FUNCTION &&
+ out_format != OUT_FMT_FUNCGRAPH)
+ out_format = OUT_FMT_FUNCTION;
fout = fopen(out_fname, "w");
if (!fout) {
fprintf(stderr, "Cannot write file '%s'\n",
out_fname);
return -1;
}
- err = make_ftrace(fout);
+ err = make_ftrace(fout, out_format);
fclose(fout);
} else {
warn("Unknown command '%s'\n", cmd);
@@ -1464,6 +1570,7 @@ static int prof_tool(int argc, char *const argv[],
int main(int argc, char *argv[])
{
+ enum out_format_t out_format = OUT_FMT_DEFAULT;
const char *map_fname = "System.map";
const char *trace_fname = NULL;
const char *config_fname = NULL;
@@ -1471,11 +1578,22 @@ int main(int argc, char *argv[])
int opt;
verbose = 2;
- while ((opt = getopt(argc, argv, "c:m:o:t:v:")) != -1) {
+ while ((opt = getopt(argc, argv, "c:f:m:o:t:v:")) != -1) {
switch (opt) {
case 'c':
config_fname = optarg;
break;
+ case 'f':
+ if (!strcmp("function", optarg)) {
+ out_format = OUT_FMT_FUNCTION;
+ } else if (!strcmp("funcgraph", optarg)) {
+ out_format = OUT_FMT_FUNCGRAPH;
+ } else {
+ fprintf(stderr,
+ "Invalid format: use function, funcgraph, calls, timing\n");
+ exit(1);
+ }
+ break;
case 'm':
map_fname = optarg;
break;
@@ -1504,5 +1622,5 @@ int main(int argc, char *argv[])
debug("Debug enabled\n");
return prof_tool(argc, argv, trace_fname, map_fname, config_fname,
- out_fname);
+ out_fname, out_format);
}
--
2.39.0.314.g84b9a713c41-goog
More information about the U-Boot
mailing list