Thread (19 messages) flat view 19 messages, 6 authors, 2024-10-04

Re: [PATCH 6/7] tracing: add support for function argument to graph tracer

From: Steven Rostedt <rostedt@goodmis.org>
Date: 2024-10-04 22:39:13
Also in: bpf, lkml
Subsystem: the rest, tracing · Maintainers: Linus Torvalds, Steven Rostedt, Masami Hiramatsu 

On Wed,  4 Sep 2024 08:59:00 +0200
Sven Schnelle [off-list ref] wrote:

Wire up the code to print function arguments in the function graph
tracer. This functionality can be enabled/disabled during compile
time by setting CONFIG_FUNCTION_TRACE_ARGS and during runtime with
options/funcgraph-args.
I finally got around to looking at your patches. Do you plan on still
working on them? I really like this feature, and I'm willing to do the work
too if you have other things on your plate.

Example usage:

6)              | dummy_xmit [dummy](skb = 0x8887c100, dev = 0x872ca000) {
6)              |   consume_skb(skb = 0x8887c100) {
6)              |     skb_release_head_state(skb = 0x8887c100) {
6)  0.178 us    |       sock_wfree(skb = 0x8887c100)
6)  0.627 us    |     }

Signed-off-by: Sven Schnelle <svens@linux.ibm.com>
---
 include/linux/ftrace.h               |  1 +
 kernel/trace/fgraph.c                |  6 ++-
 kernel/trace/trace_functions_graph.c | 74 ++++++++++++++--------------
 3 files changed, 44 insertions(+), 37 deletions(-)
BTW, this is missing:

diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index 2f8017f8d34d..8a218b39d11d 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -879,6 +879,7 @@ static __always_inline bool ftrace_hash_empty(struct ftrace_hash *hash)
 #define TRACE_GRAPH_GRAPH_TIME          0x400
 #define TRACE_GRAPH_PRINT_RETVAL        0x800
 #define TRACE_GRAPH_PRINT_RETVAL_HEX    0x1000
+#define TRACE_GRAPH_ARGS		0x2000
 #define TRACE_GRAPH_PRINT_FILL_SHIFT	28
 #define TRACE_GRAPH_PRINT_FILL_MASK	(0x3 << TRACE_GRAPH_PRINT_FILL_SHIFT)
 
that you added in patch 7, but is needed for this patch, where it does not
build without it.
quoted hunk ↗ jump to hunk
diff --git a/include/linux/ftrace.h b/include/linux/ftrace.h
index 56d91041ecd2..5d0ff66f8a70 100644
--- a/include/linux/ftrace.h
+++ b/include/linux/ftrace.h
@@ -1010,6 +1010,7 @@ static inline void ftrace_init(void) { }
  * to remove extra padding at the end.
  */
 struct ftrace_graph_ent {
+	struct ftrace_regs regs;
 	unsigned long func; /* Current function */
 	int depth;
 } __packed;
This should have a different event type, to not waste the ring buffer when
not needed.

struct ftrace_graph_ent_args {
	struct ftrace_regs_args fargs;
	unsigned long func; /* Current function */
	int depth;
} __packed;

But also, we need to create a new structure, as nothing should depend on
the size of ftrace_regs (we plan on hiding that completely). I can add a
"struct ftrace_regs_args" that will hold just the args for each arch.
Especially for archs (like x86) where ftrace_regs can be pt_regs in size,
where most of the space is just wasted. Then we can do a:

	ftrace_regs_copy_args(fregs, &entry->addr);

And then:

	char buf[ftrace_regs_size()];
	struct ftrace_regs *fregs = &buf;

	ftrace_regs_from_args(fregs, &entry->addr);

to get the arguments.




quoted hunk ↗ jump to hunk
diff --git a/kernel/trace/fgraph.c b/kernel/trace/fgraph.c
index fa62ebfa0711..f4bb10c0aa52 100644
--- a/kernel/trace/fgraph.c
+++ b/kernel/trace/fgraph.c
@@ -614,7 +614,7 @@ ftrace_push_return_trace(unsigned long ret, unsigned long func,
 /* If the caller does not use ftrace, call this function. */
 int function_graph_enter(unsigned long ret, unsigned long func,
 			 unsigned long frame_pointer, unsigned long *retp,
-			struct ftrace_regs *fregs)
+			 struct ftrace_regs *fregs)
 {
 	struct ftrace_graph_ent trace;
 	unsigned long bitmap = 0;
@@ -623,6 +623,10 @@ int function_graph_enter(unsigned long ret, unsigned long func,
 
 	trace.func = func;
 	trace.depth = ++current->curr_ret_depth;
+	if (IS_ENABLED(CONFIG_FUNCTION_TRACE_ARGS) && fregs)
+		trace.regs = *fregs;
+	else
+		memset(&trace.regs, 0, sizeof(struct ftrace_regs));
 
 	offset = ftrace_push_return_trace(ret, func, frame_pointer, retp, 0);
 	if (offset < 0)
diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
index 13d0387ac6a6..be0cee52944a 100644
--- a/kernel/trace/trace_functions_graph.c
+++ b/kernel/trace/trace_functions_graph.c
@@ -12,6 +12,8 @@
 #include <linux/interrupt.h>
 #include <linux/slab.h>
 #include <linux/fs.h>
+#include <linux/btf.h>
+#include <linux/bpf.h>
 
 #include "trace.h"
 #include "trace_output.h"
@@ -63,6 +65,9 @@ static struct tracer_opt trace_opts[] = {
 	{ TRACER_OPT(funcgraph-retval, TRACE_GRAPH_PRINT_RETVAL) },
 	/* Display function return value in hexadecimal format ? */
 	{ TRACER_OPT(funcgraph-retval-hex, TRACE_GRAPH_PRINT_RETVAL_HEX) },
+#endif
+#ifdef CONFIG_FUNCTION_TRACE_ARGS
+	{ TRACER_OPT(funcgraph-args, TRACE_GRAPH_ARGS) },
 #endif
 	/* Include sleep time (scheduled out) between entry and return */
 	{ TRACER_OPT(sleep-time, TRACE_GRAPH_SLEEP_TIME) },
@@ -653,7 +658,7 @@ print_graph_duration(struct trace_array *tr, unsigned long long duration,
 #define __TRACE_GRAPH_PRINT_RETVAL TRACE_GRAPH_PRINT_RETVAL
 
 static void print_graph_retval(struct trace_seq *s, unsigned long retval,
-				bool leaf, void *func, bool hex_format)
+			       bool hex_format)
 {
 	unsigned long err_code = 0;
 
@@ -673,28 +678,17 @@ static void print_graph_retval(struct trace_seq *s, unsigned long retval,
 		err_code = 0;
 
 done:
-	if (leaf) {
-		if (hex_format || (err_code == 0))
-			trace_seq_printf(s, "%ps(); /* = 0x%lx */\n",
-					func, retval);
-		else
-			trace_seq_printf(s, "%ps(); /* = %ld */\n",
-					func, err_code);
-	} else {
-		if (hex_format || (err_code == 0))
-			trace_seq_printf(s, "} /* %ps = 0x%lx */\n",
-					func, retval);
-		else
-			trace_seq_printf(s, "} /* %ps = %ld */\n",
-					func, err_code);
-	}
+	if (hex_format || (err_code == 0))
+		trace_seq_printf(s, " /* = 0x%lx */", retval);
+	else
+		trace_seq_printf(s, " /* = %ld */", err_code);
 }
 
 #else
 
 #define __TRACE_GRAPH_PRINT_RETVAL 0
 
-#define print_graph_retval(_seq, _retval, _leaf, _func, _format) do {} while (0)
+#define print_graph_retval(_seq, _retval, _format) do {} while (0)
 
 #endif
 
@@ -741,16 +735,20 @@ print_graph_entry_leaf(struct trace_iterator *iter,
 	/* Function */
 	for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++)
 		trace_seq_putc(s, ' ');
+	trace_seq_printf(s, "%ps", (void *)graph_ret->func);
+	if (flags & TRACE_GRAPH_ARGS)
+		print_function_args(s, &call->regs, graph_ret->func);
Ideally, the flag is going to be set when args is recorded and not used for
printing. If the event is the ftrace_ent_args() this will print the
arguments, otherwise it does not.

To simplify these functions, we probably need to have a:

union fgraph_entry {
	struct ftrace_graph_ent		*normal;
	struct ftrace_graph_ent_args	*args;
};

And switch depending which is which (the header of both is the same as is
for all entries).

-- Steve


quoted hunk ↗ jump to hunk
+	else
+		trace_seq_puts(s, "();");
 
 	/*
 	 * Write out the function return value if the option function-retval is
 	 * enabled.
 	 */
 	if (flags & __TRACE_GRAPH_PRINT_RETVAL)
-		print_graph_retval(s, graph_ret->retval, true, (void *)call->func,
-				!!(flags & TRACE_GRAPH_PRINT_RETVAL_HEX));
-	else
-		trace_seq_printf(s, "%ps();\n", (void *)call->func);
+		print_graph_retval(s, graph_ret->retval,
+				   !!(flags & TRACE_GRAPH_PRINT_RETVAL_HEX));
+	trace_seq_printf(s, "\n");
 
 	print_graph_irq(iter, graph_ret->func, TRACE_GRAPH_RET,
 			cpu, iter->ent->pid, flags);
@@ -788,7 +786,12 @@ print_graph_entry_nested(struct trace_iterator *iter,
 	for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++)
 		trace_seq_putc(s, ' ');
 
-	trace_seq_printf(s, "%ps() {\n", (void *)call->func);
+	trace_seq_printf(s, "%ps", (void *)call->func);
+	if (flags & TRACE_GRAPH_ARGS)
+		print_function_args(s, &call->regs, call->func);
+	else
+		trace_seq_puts(s, "()");
+	trace_seq_printf(s, " {\n");
 
 	if (trace_seq_has_overflowed(s))
 		return TRACE_TYPE_PARTIAL_LINE;
@@ -1028,27 +1031,26 @@ print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s,
 	for (i = 0; i < trace->depth * TRACE_GRAPH_INDENT; i++)
 		trace_seq_putc(s, ' ');
 
+	/*
+	 * If the return function does not have a matching entry,
+	 * then the entry was lost. Instead of just printing
+	 * the '}' and letting the user guess what function this
+	 * belongs to, write out the function name. Always do
+	 * that if the funcgraph-tail option is enabled.
+	 */
+	if (func_match && !(flags & TRACE_GRAPH_PRINT_TAIL))
+		trace_seq_puts(s, "}");
+	else
+		trace_seq_printf(s, "} /* %ps */", (void *)trace->func);
 	/*
 	 * Always write out the function name and its return value if the
 	 * function-retval option is enabled.
 	 */
 	if (flags & __TRACE_GRAPH_PRINT_RETVAL) {
-		print_graph_retval(s, trace->retval, false, (void *)trace->func,
+		print_graph_retval(s, trace->retval,
 			!!(flags & TRACE_GRAPH_PRINT_RETVAL_HEX));
-	} else {
-		/*
-		 * If the return function does not have a matching entry,
-		 * then the entry was lost. Instead of just printing
-		 * the '}' and letting the user guess what function this
-		 * belongs to, write out the function name. Always do
-		 * that if the funcgraph-tail option is enabled.
-		 */
-		if (func_match && !(flags & TRACE_GRAPH_PRINT_TAIL))
-			trace_seq_puts(s, "}\n");
-		else
-			trace_seq_printf(s, "} /* %ps */\n", (void *)trace->func);
 	}
-
+	trace_seq_printf(s, "\n");
 	/* Overrun */
 	if (flags & TRACE_GRAPH_PRINT_OVERRUN)
 		trace_seq_printf(s, " (Overruns: %u)\n",
  




  

    Other recent patches touching these files
    
  



    
  

  
    

      

        Keyboard shortcuts
      

      

        
          
hback out one level

          
jnext message in thread

          
kprevious message in thread

          
ldrill in

          
Escclose help / fold thread tree

          
?toggle this help