[PATCH v2 0/4] ftrace: Add function arguments to function tracers

[PATCH v2 0/4] ftrace: Add function arguments to function tracers

[Steven Rostedt]

These patches add support for printing function arguments in ftrace.

Example usage:

function tracer:

 ~# cd /sys/kernel/tracing/
 ~# echo icmp_rcv >set_ftrace_filter
 ~# echo function >current_tracer
 ~# echo 1 >options/func-args
 ~# ping -c 10 127.0.0.1
[..]
 ~# cat trace
[..]
            ping-1277    [030] ..s1.    39.120939: icmp_rcv(skb=0xa0ecab00) <-ip_protocol_deliver_rcu
            ping-1277    [030] ..s1.    39.120946: icmp_rcv(skb=0xa0ecac00) <-ip_protocol_deliver_rcu
            ping-1277    [030] ..s1.    40.179724: icmp_rcv(skb=0xa0ecab00) <-ip_protocol_deliver_rcu
            ping-1277    [030] ..s1.    40.179730: icmp_rcv(skb=0xa0ecac00) <-ip_protocol_deliver_rcu
            ping-1277    [030] ..s1.    41.219700: icmp_rcv(skb=0xa0ecab00) <-ip_protocol_deliver_rcu
            ping-1277    [030] ..s1.    41.219706: icmp_rcv(skb=0xa0ecac00) <-ip_protocol_deliver_rcu
            ping-1277    [030] ..s1.    42.259717: icmp_rcv(skb=0xa0ecab00) <-ip_protocol_deliver_rcu
            ping-1277    [030] ..s1.    42.259725: icmp_rcv(skb=0xa0ecac00) <-ip_protocol_deliver_rcu
            ping-1277    [030] ..s1.    43.299735: icmp_rcv(skb=0xa0ecab00) <-ip_protocol_deliver_rcu
            ping-1277    [030] ..s1.    43.299742: icmp_rcv(skb=0xa0ecac00) <-ip_protocol_deliver_rcu

function graph:

 ~# cd /sys/kernel/tracing
 ~# echo icmp_rcv >set_graph_function
 ~# echo function_graph >current_tracer
 ~# echo 1 >options/funcgraph-args

 ~# ping -c 1 127.0.0.1

 ~# cat trace

 30)               |  icmp_rcv(skb=0xa0ecab00) {
 30)               |    __skb_checksum_complete(skb=0xa0ecab00) {
 30)               |      skb_checksum(skb=0xa0ecab00, offset=0, len=64, csum=0) {
 30)               |        __skb_checksum(skb=0xa0ecab00, offset=0, len=64, csum=0, ops=0x232e0327a88) {
 30)   0.418 us    |          csum_partial(buff=0xa0d20924, len=64, sum=0)
 30)   0.985 us    |        }
 30)   1.463 us    |      }
 30)   2.039 us    |    }
[..]

This was last posted by Sven Schnelle here:

  https://lore.kernel.org/all/20240904065908.1009086-1-svens@linux.ibm.com/

As Sven hasn't worked on it since, I decided to continue to push it
through. I'm keeping Sven as original author and added myself as
"Co-developed-by".

The main changes are:

- Made the kconfig option unconditional if all the dependencies are set.

- Not save ftrace_regs in the ring buffer, as that is an abstract
  descriptor defined by the architectures and should remain opaque from
  generic code. Instead, the args are read at the time they are recorded
  (with the ftrace_regs passed to the callback function), and saved into
  the ring buffer. Then the print function only takes an array of elements.

  This could allow archs to retrieve arguments that are on the stack where
  as, post processing ftrace_regs could cause undesirable results.

- Made the function and function graph entry events dynamically sized
  to allow the arguments to be appended to the event in the ring buffer.
  The print function only looks to see if the event saved in the ring
  buffer is big enough to hold all the arguments defined by the new
  FTRACE_REGS_MAX_ARGS macro and if so, it will assume there are arguments
  there and print them. This also means user space will not break on
  reading these events as arguments will simply be ignored.

- The printing of the arguments has some more data when things are not
  processed by BPF. Any unsupported argument will have the type printed
  out in the ring buffer. 

- Also removed the spaces around the '=' as that's more in line to how
  trace events show their fields.

- One new patch I added to convert function graph tracing over to using
  args as soon as the user sets the option even if function graph tracing
  is enabled. Function tracer did this already by default.

Steven Rostedt (1):
      ftrace: Have funcgraph-args take affect during tracing

Sven Schnelle (3):
      ftrace: Add print_function_args()
      ftrace: Add support for function argument to graph tracer
      ftrace: Add arguments to function tracer

----
 include/linux/ftrace_regs.h          |   5 +
 kernel/trace/Kconfig                 |  12 +++
 kernel/trace/trace.c                 |  12 ++-
 kernel/trace/trace.h                 |   4 +-
 kernel/trace/trace_entries.h         |  12 ++-
 kernel/trace/trace_functions.c       |  46 ++++++++-
 kernel/trace/trace_functions_graph.c | 174 ++++++++++++++++++++++++++++-------
 kernel/trace/trace_irqsoff.c         |   4 +-
 kernel/trace/trace_output.c          |  96 ++++++++++++++++++-
 kernel/trace/trace_output.h          |   9 ++
 kernel/trace/trace_sched_wakeup.c    |   4 +-
 11 files changed, 324 insertions(+), 54 deletions(-)

[PATCH v2 1/4] ftrace: Add print_function_args()

[Steven Rostedt]

From: Sven Schnelle <svens@linux.ibm.com>

Add a function to decode argument types with the help of BTF. Will
be used to display arguments in the function and function graph
tracer.

It can only handle simply arguments and up to FTRACE_REGS_MAX_ARGS number
of arguments. When it hits a max, it will print ", ...":

   page_to_skb(vi=0xffff8d53842dc980, rq=0xffff8d53843a0800, page=0xfffffc2e04337c00, offset=6160, len=64, truesize=1536, ...)

And if it hits an argument that is not recognized, it will print the raw
value and the type of argument it is:

   make_vfsuid(idmap=0xffffffff87f99db8, fs_userns=0xffffffff87e543c0, kuid=0x0 (STRUCT))
   __pti_set_user_pgtbl(pgdp=0xffff8d5384ab47f8, pgd=0x110e74067 (STRUCT))

Co-developed-by: Steven Rostedt (Google) <rostedt@goodmis.org>
Signed-off-by: Sven Schnelle <svens@linux.ibm.com>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
---
Changes since v1: https://lore.kernel.org/20240904065908.1009086-5-svens@linux.ibm.com

 - Added Config option FUNCTION_TRACE_ARGS to this patch
  (unconditional if dependencies are met)

 - Changed the print_function_args() function to take an array of
   unsigned long args and not the ftrace_regs pointer. The ftrace_regs
   should be opaque from generic code.

 - Have the function print the name of an BTF type that is not supported.

 - Added FTRACE_REGS_MAX_ARGS as the number of arguments saved in
   the event and printed out.

 - Print "...," if the number of arguments goes past FTRACE_REGS_MAX_ARGS.

 include/linux/ftrace_regs.h |  5 +++
 kernel/trace/Kconfig        |  6 +++
 kernel/trace/trace_output.c | 78 +++++++++++++++++++++++++++++++++++++
 kernel/trace/trace_output.h |  9 +++++
 4 files changed, 98 insertions(+)

diff --git a/include/linux/ftrace_regs.h b/include/linux/ftrace_regs.h
index bbc1873ca6b8..15627ceea9bc 100644
--- a/include/linux/ftrace_regs.h
+++ b/include/linux/ftrace_regs.h
@@ -35,4 +35,9 @@ struct ftrace_regs;
 
 #endif /* HAVE_ARCH_FTRACE_REGS */
 
+/* This can be overridden by the architectures */
+#ifndef FTRACE_REGS_MAX_ARGS
+# define FTRACE_REGS_MAX_ARGS	6
+#endif
+
 #endif /* _LINUX_FTRACE_REGS_H */
diff --git a/kernel/trace/Kconfig b/kernel/trace/Kconfig
index d570b8b9c0a9..60412c1012ef 100644
--- a/kernel/trace/Kconfig
+++ b/kernel/trace/Kconfig
@@ -263,6 +263,12 @@ config FUNCTION_GRAPH_RETADDR
 	  the function is called. This feature is off by default, and you can
 	  enable it via the trace option funcgraph-retaddr.
 
+config FUNCTION_TRACE_ARGS
+       bool
+	depends on HAVE_FUNCTION_ARG_ACCESS_API
+	depends on DEBUG_INFO_BTF
+	default y
+
 config DYNAMIC_FTRACE
 	bool "enable/disable function tracing dynamically"
 	depends on FUNCTION_TRACER
diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
index da748b7cbc4d..40d6c7a9e0c4 100644
--- a/kernel/trace/trace_output.c
+++ b/kernel/trace/trace_output.c
@@ -12,8 +12,11 @@
 #include <linux/sched/clock.h>
 #include <linux/sched/mm.h>
 #include <linux/idr.h>
+#include <linux/btf.h>
+#include <linux/bpf.h>
 
 #include "trace_output.h"
+#include "trace_btf.h"
 
 /* must be a power of 2 */
 #define EVENT_HASHSIZE	128
@@ -680,6 +683,81 @@ int trace_print_lat_context(struct trace_iterator *iter)
 	return !trace_seq_has_overflowed(s);
 }
 
+#ifdef CONFIG_FUNCTION_TRACE_ARGS
+void print_function_args(struct trace_seq *s, unsigned long *args,
+			 unsigned long func)
+{
+	const struct btf_param *param;
+	const struct btf_type *t;
+	const char *param_name;
+	char name[KSYM_NAME_LEN];
+	unsigned long arg;
+	struct btf *btf;
+	s32 tid, nr = 0;
+	int i;
+
+	trace_seq_printf(s, "(");
+
+	if (!args)
+		goto out;
+	if (lookup_symbol_name(func, name))
+		goto out;
+
+	btf = bpf_get_btf_vmlinux();
+	if (IS_ERR_OR_NULL(btf))
+		goto out;
+
+	t = btf_find_func_proto(name, &btf);
+	if (IS_ERR_OR_NULL(t))
+		goto out;
+
+	param = btf_get_func_param(t, &nr);
+	if (!param)
+		goto out_put;
+
+	for (i = 0; i < nr; i++) {
+		/* This only prints what the arch allows (6 args by default) */
+		if (i == FTRACE_REGS_MAX_ARGS) {
+			trace_seq_puts(s, "...");
+			break;
+		}
+
+		arg = args[i];
+
+		param_name = btf_name_by_offset(btf, param[i].name_off);
+		if (param_name)
+			trace_seq_printf(s, "%s=", param_name);
+		t = btf_type_skip_modifiers(btf, param[i].type, &tid);
+
+		switch (t ? BTF_INFO_KIND(t->info) : BTF_KIND_UNKN) {
+		case BTF_KIND_UNKN:
+			trace_seq_putc(s, '?');
+			/* Still print unknown type values */
+			fallthrough;
+		case BTF_KIND_PTR:
+			trace_seq_printf(s, "0x%lx", arg);
+			break;
+		case BTF_KIND_INT:
+			trace_seq_printf(s, "%ld", arg);
+			break;
+		case BTF_KIND_ENUM:
+			trace_seq_printf(s, "%ld", arg);
+			break;
+		default:
+			/* This does not handle complex arguments */
+			trace_seq_printf(s, "0x%lx (%s)", arg, btf_type_str(t));
+			break;
+		}
+		if (i < nr - 1)
+			trace_seq_printf(s, ", ");
+	}
+out_put:
+	btf_put(btf);
+out:
+	trace_seq_printf(s, ")");
+}
+#endif
+
 /**
  * ftrace_find_event - find a registered event
  * @type: the type of event to look for
diff --git a/kernel/trace/trace_output.h b/kernel/trace/trace_output.h
index dca40f1f1da4..2e305364f2a9 100644
--- a/kernel/trace/trace_output.h
+++ b/kernel/trace/trace_output.h
@@ -41,5 +41,14 @@ extern struct rw_semaphore trace_event_sem;
 #define SEQ_PUT_HEX_FIELD(s, x)				\
 	trace_seq_putmem_hex(s, &(x), sizeof(x))
 
+#ifdef CONFIG_FUNCTION_TRACE_ARGS
+void print_function_args(struct trace_seq *s, unsigned long *args,
+			 unsigned long func);
+#else
+static inline void print_function_args(struct trace_seq *s, unsigned long *args,
+				       unsigned long func) {
+	trace_seq_puts(s, "()");
+}
+#endif
 #endif
 
-- 
2.45.2

[PATCH v2 2/4] ftrace: Add support for function argument to graph tracer

[Steven Rostedt]

From: Sven Schnelle <svens@linux.ibm.com>

Wire up the code to print function arguments in the function graph
tracer. This functionality can be enabled/disabled during runtime with
options/funcgraph-args.

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    |     }

Co-developed-by: Steven Rostedt (Google) <rostedt@goodmis.org>
Signed-off-by: Sven Schnelle <svens@linux.ibm.com>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
---
Changes since v1: https://lore.kernel.org/20240904065908.1009086-7-svens@linux.ibm.com
 
 - Record just FTRACE_REGS_MAX_ARGS into the ring buffer and not the
   entire ftrace_regs structure, as that structure should be opaque
   from generic code.

 - Make the function graph entry event have a dynamic size, so that an
   array of arguments may be added in the ring buffer after it.

 kernel/trace/Kconfig                 |   6 ++
 kernel/trace/trace.h                 |   1 +
 kernel/trace/trace_entries.h         |   7 +-
 kernel/trace/trace_functions_graph.c | 147 +++++++++++++++++++++------
 4 files changed, 125 insertions(+), 36 deletions(-)

diff --git a/kernel/trace/Kconfig b/kernel/trace/Kconfig
index 60412c1012ef..033fba0633cf 100644
--- a/kernel/trace/Kconfig
+++ b/kernel/trace/Kconfig
@@ -268,6 +268,12 @@ config FUNCTION_TRACE_ARGS
 	depends on HAVE_FUNCTION_ARG_ACCESS_API
 	depends on DEBUG_INFO_BTF
 	default y
+	help
+	  If supported with function argument access API and BTF, then
+	  the function tracer and function graph tracer will support printing
+	  of function arguments. This feature is off by default, and can be
+	  enabled via the trace option func-args (for the function tracer) and
+	  funcgraph-args (for the function graph tracer)
 
 config DYNAMIC_FTRACE
 	bool "enable/disable function tracing dynamically"
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index ad9f008d7dd7..6f67bbc17bed 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -887,6 +887,7 @@ static __always_inline bool ftrace_hash_empty(struct ftrace_hash *hash)
 #define TRACE_GRAPH_PRINT_RETVAL        0x800
 #define TRACE_GRAPH_PRINT_RETVAL_HEX    0x1000
 #define TRACE_GRAPH_PRINT_RETADDR       0x2000
+#define TRACE_GRAPH_ARGS		0x4000
 #define TRACE_GRAPH_PRINT_FILL_SHIFT	28
 #define TRACE_GRAPH_PRINT_FILL_MASK	(0x3 << TRACE_GRAPH_PRINT_FILL_SHIFT)
 
diff --git a/kernel/trace/trace_entries.h b/kernel/trace/trace_entries.h
index 82fd174ebbe0..254491b545c3 100644
--- a/kernel/trace/trace_entries.h
+++ b/kernel/trace/trace_entries.h
@@ -72,17 +72,18 @@ FTRACE_ENTRY_REG(function, ftrace_entry,
 );
 
 /* Function call entry */
-FTRACE_ENTRY_PACKED(funcgraph_entry, ftrace_graph_ent_entry,
+FTRACE_ENTRY(funcgraph_entry, ftrace_graph_ent_entry,
 
 	TRACE_GRAPH_ENT,
 
 	F_STRUCT(
 		__field_struct(	struct ftrace_graph_ent,	graph_ent	)
 		__field_packed(	unsigned long,	graph_ent,	func		)
-		__field_packed(	int,		graph_ent,	depth		)
+		__field_packed(	unsigned long,	graph_ent,	depth		)
+		__dynamic_array(unsigned long,	args				)
 	),
 
-	F_printk("--> %ps (%d)", (void *)__entry->func, __entry->depth)
+	F_printk("--> %ps (%lu)", (void *)__entry->func, __entry->depth)
 );
 
 #ifdef CONFIG_FUNCTION_GRAPH_RETADDR
diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
index d0e4f412c298..c8eda9bebdf4 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"
@@ -70,6 +72,10 @@ static struct tracer_opt trace_opts[] = {
 #ifdef CONFIG_FUNCTION_GRAPH_RETADDR
 	/* Display function return address ? */
 	{ TRACER_OPT(funcgraph-retaddr, TRACE_GRAPH_PRINT_RETADDR) },
+#endif
+#ifdef CONFIG_FUNCTION_TRACE_ARGS
+	/* Display function arguments ? */
+	{ 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) },
@@ -110,25 +116,41 @@ static void
 print_graph_duration(struct trace_array *tr, unsigned long long duration,
 		     struct trace_seq *s, u32 flags);
 
-int __trace_graph_entry(struct trace_array *tr,
-				struct ftrace_graph_ent *trace,
-				unsigned int trace_ctx)
+static int __graph_entry(struct trace_array *tr, struct ftrace_graph_ent *trace,
+			 unsigned int trace_ctx, struct ftrace_regs *fregs)
 {
 	struct ring_buffer_event *event;
 	struct trace_buffer *buffer = tr->array_buffer.buffer;
 	struct ftrace_graph_ent_entry *entry;
+	int size;
 
-	event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_ENT,
-					  sizeof(*entry), trace_ctx);
+	/* If fregs is defined, add FTRACE_REGS_MAX_ARGS long size words */
+	size = sizeof(*entry) + (FTRACE_REGS_MAX_ARGS * !!fregs * sizeof(long));
+
+	event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_ENT, size, trace_ctx);
 	if (!event)
 		return 0;
-	entry	= ring_buffer_event_data(event);
-	entry->graph_ent			= *trace;
+
+	entry = ring_buffer_event_data(event);
+	entry->graph_ent = *trace;
+
+	if (fregs) {
+		for (int i = 0; i < FTRACE_REGS_MAX_ARGS; i++)
+			entry->args[i] = ftrace_regs_get_argument(fregs, i);
+	}
+
 	trace_buffer_unlock_commit_nostack(buffer, event);
 
 	return 1;
 }
 
+int __trace_graph_entry(struct trace_array *tr,
+				struct ftrace_graph_ent *trace,
+				unsigned int trace_ctx)
+{
+	return __graph_entry(tr, trace, trace_ctx, NULL);
+}
+
 #ifdef CONFIG_FUNCTION_GRAPH_RETADDR
 int __trace_graph_retaddr_entry(struct trace_array *tr,
 				struct ftrace_graph_ent *trace,
@@ -174,9 +196,9 @@ struct fgraph_times {
 	unsigned long long		sleeptime; /* may be optional! */
 };
 
-int trace_graph_entry(struct ftrace_graph_ent *trace,
-		      struct fgraph_ops *gops,
-		      struct ftrace_regs *fregs)
+static int graph_entry(struct ftrace_graph_ent *trace,
+		       struct fgraph_ops *gops,
+		       struct ftrace_regs *fregs)
 {
 	unsigned long *task_var = fgraph_get_task_var(gops);
 	struct trace_array *tr = gops->private;
@@ -248,7 +270,7 @@ int trace_graph_entry(struct ftrace_graph_ent *trace,
 
 			ret = __trace_graph_retaddr_entry(tr, trace, trace_ctx, retaddr);
 		} else
-			ret = __trace_graph_entry(tr, trace, trace_ctx);
+			ret = __graph_entry(tr, trace, trace_ctx, fregs);
 	} else {
 		ret = 0;
 	}
@@ -259,6 +281,20 @@ int trace_graph_entry(struct ftrace_graph_ent *trace,
 	return ret;
 }
 
+int trace_graph_entry(struct ftrace_graph_ent *trace,
+		      struct fgraph_ops *gops,
+		      struct ftrace_regs *fregs)
+{
+	return graph_entry(trace, gops, NULL);
+}
+
+static int trace_graph_entry_args(struct ftrace_graph_ent *trace,
+				  struct fgraph_ops *gops,
+				  struct ftrace_regs *fregs)
+{
+	return graph_entry(trace, gops, fregs);
+}
+
 static void
 __trace_graph_function(struct trace_array *tr,
 		unsigned long ip, unsigned int trace_ctx)
@@ -423,7 +459,10 @@ static int graph_trace_init(struct trace_array *tr)
 {
 	int ret;
 
-	tr->gops->entryfunc = trace_graph_entry;
+	if (tracer_flags_is_set(TRACE_GRAPH_ARGS))
+		tr->gops->entryfunc = trace_graph_entry_args;
+	else
+		tr->gops->entryfunc = trace_graph_entry;
 
 	if (tracing_thresh)
 		tr->gops->retfunc = trace_graph_thresh_return;
@@ -780,7 +819,7 @@ static void print_graph_retaddr(struct trace_seq *s, struct fgraph_retaddr_ent_e
 
 static void print_graph_retval(struct trace_seq *s, struct ftrace_graph_ent_entry *entry,
 				struct ftrace_graph_ret *graph_ret, void *func,
-				u32 opt_flags, u32 trace_flags)
+				u32 opt_flags, u32 trace_flags, int args_size)
 {
 	unsigned long err_code = 0;
 	unsigned long retval = 0;
@@ -814,7 +853,14 @@ static void print_graph_retval(struct trace_seq *s, struct ftrace_graph_ent_entr
 		if (entry->ent.type != TRACE_GRAPH_RETADDR_ENT)
 			print_retaddr = false;
 
-		trace_seq_printf(s, "%ps();", func);
+		trace_seq_printf(s, "%ps", func);
+
+		if (args_size >= FTRACE_REGS_MAX_ARGS * sizeof(long)) {
+			print_function_args(s, entry->args, (unsigned long)func);
+			trace_seq_putc(s, ';');
+		} else
+			trace_seq_puts(s, "();");
+
 		if (print_retval || print_retaddr)
 			trace_seq_puts(s, " /*");
 		else
@@ -836,12 +882,13 @@ static void print_graph_retval(struct trace_seq *s, struct ftrace_graph_ent_entr
 	}
 
 	if (!entry || print_retval || print_retaddr)
-		trace_seq_puts(s, " */\n");
+		trace_seq_puts(s, " */");
 }
 
 #else
 
-#define print_graph_retval(_seq, _ent, _ret, _func, _opt_flags, _trace_flags) do {} while (0)
+#define print_graph_retval(_seq, _ent, _ret, _func, _opt_flags, _trace_flags, args_size) \
+	do {} while (0)
 
 #endif
 
@@ -857,10 +904,14 @@ print_graph_entry_leaf(struct trace_iterator *iter,
 	struct ftrace_graph_ret *graph_ret;
 	struct ftrace_graph_ent *call;
 	unsigned long long duration;
+	unsigned long ret_func;
 	unsigned long func;
+	int args_size;
 	int cpu = iter->cpu;
 	int i;
 
+	args_size = iter->ent_size - offsetof(struct ftrace_graph_ent_entry, args);
+
 	graph_ret = &ret_entry->ret;
 	call = &entry->graph_ent;
 	duration = graph_ret->rettime - graph_ret->calltime;
@@ -892,16 +943,25 @@ print_graph_entry_leaf(struct trace_iterator *iter,
 	for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++)
 		trace_seq_putc(s, ' ');
 
+	ret_func = graph_ret->func + iter->tr->text_delta;
+
 	/*
 	 * Write out the function return value or return address
 	 */
 	if (flags & (__TRACE_GRAPH_PRINT_RETVAL | __TRACE_GRAPH_PRINT_RETADDR)) {
 		print_graph_retval(s, entry, graph_ret,
 				   (void *)graph_ret->func + iter->tr->text_delta,
-				   flags, tr->trace_flags);
+				   flags, tr->trace_flags, args_size);
 	} else {
-		trace_seq_printf(s, "%ps();\n", (void *)func);
+		trace_seq_printf(s, "%ps", (void *)ret_func);
+
+		if (args_size >= FTRACE_REGS_MAX_ARGS * sizeof(long)) {
+			print_function_args(s, entry->args, ret_func);
+			trace_seq_putc(s, ';');
+		} else
+			trace_seq_puts(s, "();");
 	}
+	trace_seq_printf(s, "\n");
 
 	print_graph_irq(iter, graph_ret->func, TRACE_GRAPH_RET,
 			cpu, iter->ent->pid, flags);
@@ -918,6 +978,7 @@ print_graph_entry_nested(struct trace_iterator *iter,
 	struct fgraph_data *data = iter->private;
 	struct trace_array *tr = iter->tr;
 	unsigned long func;
+	int args_size;
 	int i;
 
 	if (data) {
@@ -942,7 +1003,17 @@ print_graph_entry_nested(struct trace_iterator *iter,
 
 	func = call->func + iter->tr->text_delta;
 
-	trace_seq_printf(s, "%ps() {", (void *)func);
+	trace_seq_printf(s, "%ps", (void *)func);
+
+	args_size = iter->ent_size - offsetof(struct ftrace_graph_ent_entry, args);
+
+	if (args_size >= FTRACE_REGS_MAX_ARGS * sizeof(long))
+		print_function_args(s, entry->args, func);
+	else
+		trace_seq_puts(s, "()");
+
+	trace_seq_puts(s, " {");
+
 	if (flags & __TRACE_GRAPH_PRINT_RETADDR  &&
 		entry->ent.type == TRACE_GRAPH_RETADDR_ENT)
 		print_graph_retaddr(s, (struct fgraph_retaddr_ent_entry *)entry,
@@ -1112,21 +1183,38 @@ print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s,
 			struct trace_iterator *iter, u32 flags)
 {
 	struct fgraph_data *data = iter->private;
-	struct ftrace_graph_ent *call = &field->graph_ent;
+	struct ftrace_graph_ent *call;
 	struct ftrace_graph_ret_entry *leaf_ret;
 	static enum print_line_t ret;
 	int cpu = iter->cpu;
+	/*
+	 * print_graph_entry() may consume the current event,
+	 * thus @field may become invalid, so we need to save it.
+	 * sizeof(struct ftrace_graph_ent_entry) is very small,
+	 * it can be safely saved at the stack.
+	 */
+	struct ftrace_graph_ent_entry *entry;
+	u8 save_buf[sizeof(*entry) + FTRACE_REGS_MAX_ARGS * sizeof(long)];
+
+	/* The ent_size is expected to be as big as the entry */
+	if (iter->ent_size > sizeof(save_buf))
+		iter->ent_size = sizeof(save_buf);
+
+	entry = (void *)save_buf;
+	memcpy(entry, field, iter->ent_size);
+
+	call = &entry->graph_ent;
 
 	if (check_irq_entry(iter, flags, call->func, call->depth))
 		return TRACE_TYPE_HANDLED;
 
 	print_graph_prologue(iter, s, TRACE_GRAPH_ENT, call->func, flags);
 
-	leaf_ret = get_return_for_leaf(iter, field);
+	leaf_ret = get_return_for_leaf(iter, entry);
 	if (leaf_ret)
-		ret = print_graph_entry_leaf(iter, field, leaf_ret, s, flags);
+		ret = print_graph_entry_leaf(iter, entry, leaf_ret, s, flags);
 	else
-		ret = print_graph_entry_nested(iter, field, s, cpu, flags);
+		ret = print_graph_entry_nested(iter, entry, s, cpu, flags);
 
 	if (data) {
 		/*
@@ -1197,7 +1285,8 @@ print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s,
 	 * funcgraph-retval option is enabled.
 	 */
 	if (flags & __TRACE_GRAPH_PRINT_RETVAL) {
-		print_graph_retval(s, NULL, trace, (void *)func, flags, tr->trace_flags);
+		print_graph_retval(s, NULL, trace, (void *)func, flags,
+				   tr->trace_flags, 0);
 	} else {
 		/*
 		 * If the return function does not have a matching entry,
@@ -1325,16 +1414,8 @@ print_graph_function_flags(struct trace_iterator *iter, u32 flags)
 
 	switch (entry->type) {
 	case TRACE_GRAPH_ENT: {
-		/*
-		 * print_graph_entry() may consume the current event,
-		 * thus @field may become invalid, so we need to save it.
-		 * sizeof(struct ftrace_graph_ent_entry) is very small,
-		 * it can be safely saved at the stack.
-		 */
-		struct ftrace_graph_ent_entry saved;
 		trace_assign_type(field, entry);
-		saved = *field;
-		return print_graph_entry(&saved, s, iter, flags);
+		return print_graph_entry(field, s, iter, flags);
 	}
 #ifdef CONFIG_FUNCTION_GRAPH_RETADDR
 	case TRACE_GRAPH_RETADDR_ENT: {
-- 
2.45.2

[PATCH v2 3/4] ftrace: Have funcgraph-args take affect during tracing

[Steven Rostedt]

From: Steven Rostedt <rostedt@goodmis.org>

Currently, when function_graph is started, it looks at the option
funcgraph-args, and if it is set, it will enable tracing of the arguments.

But if tracing is already running, and the user enables funcgraph-args, it
will have no effect. Instead, it should enable argument tracing when it is
enabled, even if it means disabling the function graph tracing for a short
time in order to do the transition.

Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
---
 kernel/trace/trace_functions_graph.c | 27 ++++++++++++++++++++++++++-
 1 file changed, 26 insertions(+), 1 deletion(-)

diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
index c8eda9bebdf4..d1ee001f5a8e 100644
--- a/kernel/trace/trace_functions_graph.c
+++ b/kernel/trace/trace_functions_graph.c
@@ -469,7 +469,7 @@ static int graph_trace_init(struct trace_array *tr)
 	else
 		tr->gops->retfunc = trace_graph_return;
 
-	/* Make gops functions are visible before we start tracing */
+	/* Make gops functions visible before we start tracing */
 	smp_mb();
 
 	ret = register_ftrace_graph(tr->gops);
@@ -480,6 +480,28 @@ static int graph_trace_init(struct trace_array *tr)
 	return 0;
 }
 
+static int ftrace_graph_trace_args(struct trace_array *tr, int set)
+{
+	trace_func_graph_ent_t entry;
+
+	if (set)
+		entry = trace_graph_entry_args;
+	else
+		entry = trace_graph_entry;
+
+	/* See if there's any changes */
+	if (tr->gops->entryfunc == entry)
+		return 0;
+
+	unregister_ftrace_graph(tr->gops);
+
+	tr->gops->entryfunc = entry;
+
+	/* Make gops functions visible before we start tracing */
+	smp_mb();
+	return register_ftrace_graph(tr->gops);
+}
+
 static void graph_trace_reset(struct trace_array *tr)
 {
 	tracing_stop_cmdline_record();
@@ -1609,6 +1631,9 @@ func_graph_set_flag(struct trace_array *tr, u32 old_flags, u32 bit, int set)
 	if (bit == TRACE_GRAPH_GRAPH_TIME)
 		ftrace_graph_graph_time_control(set);
 
+	if (bit == TRACE_GRAPH_ARGS)
+		return ftrace_graph_trace_args(tr, set);
+
 	return 0;
 }
 
-- 
2.45.2

[PATCH v2 4/4] ftrace: Add arguments to function tracer

[Steven Rostedt]

From: Sven Schnelle <svens@linux.ibm.com>

Wire up the code to print function arguments in the function tracer.
This functionality can be enabled/disabled during runtime with
options/func-args.

        ping-689     [004] b....    77.170220: dummy_xmit(skb = 0x82904800, dev = 0x882d0000) <-dev_hard_start_xmit

Co-developed-by: Steven Rostedt (Google) <rostedt@goodmis.org>
Signed-off-by: Sven Schnelle <svens@linux.ibm.com>
Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
---
Changes since v1: https://lore.kernel.org/20240904065908.1009086-8-svens@linux.ibm.com

 - Save only the arguments into the ring buffer and not the ftrace_regs
   as the ftrace_regs should be opaque from generic code.

 - Have the function tracer event be dynamic so that it can hold an array
   of arguments after the entry.

 kernel/trace/trace.c              | 12 ++++++--
 kernel/trace/trace.h              |  3 +-
 kernel/trace/trace_entries.h      |  5 ++--
 kernel/trace/trace_functions.c    | 46 +++++++++++++++++++++++++++----
 kernel/trace/trace_irqsoff.c      |  4 +--
 kernel/trace/trace_output.c       | 18 ++++++++++--
 kernel/trace/trace_sched_wakeup.c |  4 +--
 7 files changed, 75 insertions(+), 17 deletions(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index be62f0ea1814..3c0ffdcdcb7e 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -2897,13 +2897,16 @@ trace_buffer_unlock_commit_nostack(struct trace_buffer *buffer,
 
 void
 trace_function(struct trace_array *tr, unsigned long ip, unsigned long
-	       parent_ip, unsigned int trace_ctx)
+	       parent_ip, unsigned int trace_ctx, struct ftrace_regs *fregs)
 {
 	struct trace_buffer *buffer = tr->array_buffer.buffer;
 	struct ring_buffer_event *event;
 	struct ftrace_entry *entry;
+	int size = sizeof(*entry);
 
-	event = __trace_buffer_lock_reserve(buffer, TRACE_FN, sizeof(*entry),
+	size += FTRACE_REGS_MAX_ARGS * !!fregs * sizeof(long);
+
+	event = __trace_buffer_lock_reserve(buffer, TRACE_FN, size,
 					    trace_ctx);
 	if (!event)
 		return;
@@ -2911,6 +2914,11 @@ trace_function(struct trace_array *tr, unsigned long ip, unsigned long
 	entry->ip			= ip;
 	entry->parent_ip		= parent_ip;
 
+	if (fregs) {
+		for (int i = 0; i < FTRACE_REGS_MAX_ARGS; i++)
+			entry->args[i] = ftrace_regs_get_argument(fregs, i);
+	}
+
 	if (static_branch_unlikely(&trace_function_exports_enabled))
 		ftrace_exports(event, TRACE_EXPORT_FUNCTION);
 	__buffer_unlock_commit(buffer, event);
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index 6f67bbc17bed..3d4a5ec9ee55 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -685,7 +685,8 @@ unsigned long trace_total_entries(struct trace_array *tr);
 void trace_function(struct trace_array *tr,
 		    unsigned long ip,
 		    unsigned long parent_ip,
-		    unsigned int trace_ctx);
+		    unsigned int trace_ctx,
+		    struct ftrace_regs *regs);
 void trace_graph_function(struct trace_array *tr,
 		    unsigned long ip,
 		    unsigned long parent_ip,
diff --git a/kernel/trace/trace_entries.h b/kernel/trace/trace_entries.h
index 254491b545c3..11288dc4f59b 100644
--- a/kernel/trace/trace_entries.h
+++ b/kernel/trace/trace_entries.h
@@ -61,8 +61,9 @@ FTRACE_ENTRY_REG(function, ftrace_entry,
 	TRACE_FN,
 
 	F_STRUCT(
-		__field_fn(	unsigned long,	ip		)
-		__field_fn(	unsigned long,	parent_ip	)
+		__field_fn(	unsigned long,		ip		)
+		__field_fn(	unsigned long,		parent_ip	)
+		__dynamic_array( unsigned long,		args		)
 	),
 
 	F_printk(" %ps <-- %ps",
diff --git a/kernel/trace/trace_functions.c b/kernel/trace/trace_functions.c
index d358c9935164..1f4f02df6f8c 100644
--- a/kernel/trace/trace_functions.c
+++ b/kernel/trace/trace_functions.c
@@ -25,6 +25,9 @@ static void
 function_trace_call(unsigned long ip, unsigned long parent_ip,
 		    struct ftrace_ops *op, struct ftrace_regs *fregs);
 static void
+function_args_trace_call(unsigned long ip, unsigned long parent_ip,
+			 struct ftrace_ops *op, struct ftrace_regs *fregs);
+static void
 function_stack_trace_call(unsigned long ip, unsigned long parent_ip,
 			  struct ftrace_ops *op, struct ftrace_regs *fregs);
 static void
@@ -42,9 +45,10 @@ enum {
 	TRACE_FUNC_NO_OPTS		= 0x0, /* No flags set. */
 	TRACE_FUNC_OPT_STACK		= 0x1,
 	TRACE_FUNC_OPT_NO_REPEATS	= 0x2,
+	TRACE_FUNC_OPT_ARGS		= 0x4,
 
 	/* Update this to next highest bit. */
-	TRACE_FUNC_OPT_HIGHEST_BIT	= 0x4
+	TRACE_FUNC_OPT_HIGHEST_BIT	= 0x8
 };
 
 #define TRACE_FUNC_OPT_MASK	(TRACE_FUNC_OPT_HIGHEST_BIT - 1)
@@ -114,6 +118,8 @@ static ftrace_func_t select_trace_function(u32 flags_val)
 	switch (flags_val & TRACE_FUNC_OPT_MASK) {
 	case TRACE_FUNC_NO_OPTS:
 		return function_trace_call;
+	case TRACE_FUNC_OPT_ARGS:
+		return function_args_trace_call;
 	case TRACE_FUNC_OPT_STACK:
 		return function_stack_trace_call;
 	case TRACE_FUNC_OPT_NO_REPEATS:
@@ -220,7 +226,34 @@ function_trace_call(unsigned long ip, unsigned long parent_ip,
 
 	data = this_cpu_ptr(tr->array_buffer.data);
 	if (!atomic_read(&data->disabled))
-		trace_function(tr, ip, parent_ip, trace_ctx);
+		trace_function(tr, ip, parent_ip, trace_ctx, NULL);
+
+	ftrace_test_recursion_unlock(bit);
+}
+
+static void
+function_args_trace_call(unsigned long ip, unsigned long parent_ip,
+			 struct ftrace_ops *op, struct ftrace_regs *fregs)
+{
+	struct trace_array *tr = op->private;
+	struct trace_array_cpu *data;
+	unsigned int trace_ctx;
+	int bit;
+	int cpu;
+
+	if (unlikely(!tr->function_enabled))
+		return;
+
+	bit = ftrace_test_recursion_trylock(ip, parent_ip);
+	if (bit < 0)
+		return;
+
+	trace_ctx = tracing_gen_ctx();
+
+	cpu = smp_processor_id();
+	data = per_cpu_ptr(tr->array_buffer.data, cpu);
+	if (!atomic_read(&data->disabled))
+		trace_function(tr, ip, parent_ip, trace_ctx, fregs);
 
 	ftrace_test_recursion_unlock(bit);
 }
@@ -270,7 +303,7 @@ function_stack_trace_call(unsigned long ip, unsigned long parent_ip,
 
 	if (likely(disabled == 1)) {
 		trace_ctx = tracing_gen_ctx_flags(flags);
-		trace_function(tr, ip, parent_ip, trace_ctx);
+		trace_function(tr, ip, parent_ip, trace_ctx, NULL);
 #ifdef CONFIG_UNWINDER_FRAME_POINTER
 		if (ftrace_pids_enabled(op))
 			skip++;
@@ -351,7 +384,7 @@ function_no_repeats_trace_call(unsigned long ip, unsigned long parent_ip,
 	trace_ctx = tracing_gen_ctx_flags(flags);
 	process_repeats(tr, ip, parent_ip, last_info, trace_ctx);
 
-	trace_function(tr, ip, parent_ip, trace_ctx);
+	trace_function(tr, ip, parent_ip, trace_ctx, NULL);
 
 out:
 	ftrace_test_recursion_unlock(bit);
@@ -391,7 +424,7 @@ function_stack_no_repeats_trace_call(unsigned long ip, unsigned long parent_ip,
 		trace_ctx = tracing_gen_ctx_flags(flags);
 		process_repeats(tr, ip, parent_ip, last_info, trace_ctx);
 
-		trace_function(tr, ip, parent_ip, trace_ctx);
+		trace_function(tr, ip, parent_ip, trace_ctx, NULL);
 		__trace_stack(tr, trace_ctx, STACK_SKIP);
 	}
 
@@ -405,6 +438,9 @@ static struct tracer_opt func_opts[] = {
 	{ TRACER_OPT(func_stack_trace, TRACE_FUNC_OPT_STACK) },
 #endif
 	{ TRACER_OPT(func-no-repeats, TRACE_FUNC_OPT_NO_REPEATS) },
+#ifdef CONFIG_FUNCTION_TRACE_ARGS
+	{ TRACER_OPT(func-args, TRACE_FUNC_OPT_ARGS) },
+#endif
 	{ } /* Always set a last empty entry */
 };
 
diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
index 504de7a05498..68ce152dbb8c 100644
--- a/kernel/trace/trace_irqsoff.c
+++ b/kernel/trace/trace_irqsoff.c
@@ -150,7 +150,7 @@ irqsoff_tracer_call(unsigned long ip, unsigned long parent_ip,
 
 	trace_ctx = tracing_gen_ctx_flags(flags);
 
-	trace_function(tr, ip, parent_ip, trace_ctx);
+	trace_function(tr, ip, parent_ip, trace_ctx, fregs);
 
 	atomic_dec(&data->disabled);
 }
@@ -280,7 +280,7 @@ __trace_function(struct trace_array *tr,
 	if (is_graph(tr))
 		trace_graph_function(tr, ip, parent_ip, trace_ctx);
 	else
-		trace_function(tr, ip, parent_ip, trace_ctx);
+		trace_function(tr, ip, parent_ip, trace_ctx, NULL);
 }
 
 #else
diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
index 40d6c7a9e0c4..aed6758416a0 100644
--- a/kernel/trace/trace_output.c
+++ b/kernel/trace/trace_output.c
@@ -1079,12 +1079,15 @@ enum print_line_t trace_nop_print(struct trace_iterator *iter, int flags,
 }
 
 static void print_fn_trace(struct trace_seq *s, unsigned long ip,
-			   unsigned long parent_ip, long delta, int flags)
+			   unsigned long parent_ip, long delta,
+			   unsigned long *args, int flags)
 {
 	ip += delta;
 	parent_ip += delta;
 
 	seq_print_ip_sym(s, ip, flags);
+	if (args)
+		print_function_args(s, args, ip);
 
 	if ((flags & TRACE_ITER_PRINT_PARENT) && parent_ip) {
 		trace_seq_puts(s, " <-");
@@ -1098,10 +1101,19 @@ static enum print_line_t trace_fn_trace(struct trace_iterator *iter, int flags,
 {
 	struct ftrace_entry *field;
 	struct trace_seq *s = &iter->seq;
+	unsigned long *args;
+	int args_size;
 
 	trace_assign_type(field, iter->ent);
 
-	print_fn_trace(s, field->ip, field->parent_ip, iter->tr->text_delta, flags);
+	args_size = iter->ent_size - offsetof(struct ftrace_entry, args);
+	if (args_size >= FTRACE_REGS_MAX_ARGS * sizeof(long))
+		args = field->args;
+	else
+		args = NULL;
+
+	print_fn_trace(s, field->ip, field->parent_ip, iter->tr->text_delta,
+		       args, flags);
 	trace_seq_putc(s, '\n');
 
 	return trace_handle_return(s);
@@ -1774,7 +1786,7 @@ trace_func_repeats_print(struct trace_iterator *iter, int flags,
 
 	trace_assign_type(field, iter->ent);
 
-	print_fn_trace(s, field->ip, field->parent_ip, iter->tr->text_delta, flags);
+	print_fn_trace(s, field->ip, field->parent_ip, iter->tr->text_delta, NULL, flags);
 	trace_seq_printf(s, " (repeats: %u, last_ts:", field->count);
 	trace_print_time(s, iter,
 			 iter->ts - FUNC_REPEATS_GET_DELTA_TS(field));
diff --git a/kernel/trace/trace_sched_wakeup.c b/kernel/trace/trace_sched_wakeup.c
index 8165382a174a..19b0205b91dd 100644
--- a/kernel/trace/trace_sched_wakeup.c
+++ b/kernel/trace/trace_sched_wakeup.c
@@ -226,7 +226,7 @@ wakeup_tracer_call(unsigned long ip, unsigned long parent_ip,
 		return;
 
 	local_irq_save(flags);
-	trace_function(tr, ip, parent_ip, trace_ctx);
+	trace_function(tr, ip, parent_ip, trace_ctx, fregs);
 	local_irq_restore(flags);
 
 	atomic_dec(&data->disabled);
@@ -311,7 +311,7 @@ __trace_function(struct trace_array *tr,
 	if (is_graph(tr))
 		trace_graph_function(tr, ip, parent_ip, trace_ctx);
 	else
-		trace_function(tr, ip, parent_ip, trace_ctx);
+		trace_function(tr, ip, parent_ip, trace_ctx, NULL);
 }
 
 static int wakeup_flag_changed(struct trace_array *tr, u32 mask, int set)
-- 
2.45.2

Re: [PATCH v2 1/4] ftrace: Add print_function_args()

[Steven Rostedt]

On Mon, 23 Dec 2024 15:13:48 -0500
Steven Rostedt <rostedt@goodmis.org> wrote:

> +#ifdef CONFIG_FUNCTION_TRACE_ARGS
> +void print_function_args(struct trace_seq *s, unsigned long *args,
> +			 unsigned long func)
> +{
> +	const struct btf_param *param;
> +	const struct btf_type *t;
> +	const char *param_name;
> +	char name[KSYM_NAME_LEN];
> +	unsigned long arg;
> +	struct btf *btf;
> +	s32 tid, nr = 0;
> +	int i;
> +
> +	trace_seq_printf(s, "(");
> +
> +	if (!args)
> +		goto out;
> +	if (lookup_symbol_name(func, name))
> +		goto out;
> +
> +	btf = bpf_get_btf_vmlinux();
> +	if (IS_ERR_OR_NULL(btf))
> +		goto out;
> +
> +	t = btf_find_func_proto(name, &btf);
> +	if (IS_ERR_OR_NULL(t))
> +		goto out;
> +
> +	param = btf_get_func_param(t, &nr);
> +	if (!param)
> +		goto out_put;
> +
> +	for (i = 0; i < nr; i++) {
> +		/* This only prints what the arch allows (6 args by default) */
> +		if (i == FTRACE_REGS_MAX_ARGS) {
> +			trace_seq_puts(s, "...");
> +			break;
> +		}
> +
> +		arg = args[i];
> +
> +		param_name = btf_name_by_offset(btf, param[i].name_off);
> +		if (param_name)
> +			trace_seq_printf(s, "%s=", param_name);
> +		t = btf_type_skip_modifiers(btf, param[i].type, &tid);
> +
> +		switch (t ? BTF_INFO_KIND(t->info) : BTF_KIND_UNKN) {
> +		case BTF_KIND_UNKN:
> +			trace_seq_putc(s, '?');
> +			/* Still print unknown type values */
> +			fallthrough;
> +		case BTF_KIND_PTR:
> +			trace_seq_printf(s, "0x%lx", arg);
> +			break;
> +		case BTF_KIND_INT:
> +			trace_seq_printf(s, "%ld", arg);
> +			break;
> +		case BTF_KIND_ENUM:
> +			trace_seq_printf(s, "%ld", arg);
> +			break;
> +		default:
> +			/* This does not handle complex arguments */
> +			trace_seq_printf(s, "0x%lx (%s)", arg, btf_type_str(t));

This will need to take into account the size of the type. STRUCTs show up,
and most of the time they are simply the size of the architecture's word.
But I hit this:

    timespec64_add_safe(lhs=0x6c2 (STRUCT), rhs=0x39c4153f (STRUCT))

Where it definitely isn't correct, as we have:

struct timespec64 {
	time64_t	tv_sec;			/* seconds */
	long		tv_nsec;		/* nanoseconds */
};

struct timespec64 timespec64_add_safe(const struct timespec64 lhs,
				const struct timespec64 rhs)


> +			break;
> +		}
> +		if (i < nr - 1)
> +			trace_seq_printf(s, ", ");
> +	}
> +out_put:
> +	btf_put(btf);
> +out:
> +	trace_seq_printf(s, ")");
> +}
> +#endif
> +

I updated to this (separating the args array from the BTF parameters):

@@ -684,6 +683,91 @@ int trace_print_lat_context(struct trace_iterator *iter)
 	return !trace_seq_has_overflowed(s);
 }
 
+#ifdef CONFIG_FUNCTION_TRACE_ARGS
+void print_function_args(struct trace_seq *s, unsigned long *args,
+			 unsigned long func)
+{
+	const struct btf_param *param;
+	const struct btf_type *t;
+	const char *param_name;
+	char name[KSYM_NAME_LEN];
+	unsigned long arg;
+	struct btf *btf;
+	s32 tid, nr = 0;
+	int a, p, x;
+
+	trace_seq_printf(s, "(");
+
+	if (!args)
+		goto out;
+	if (lookup_symbol_name(func, name))
+		goto out;
+
+	btf = bpf_get_btf_vmlinux();
+	if (IS_ERR_OR_NULL(btf))
+		goto out;
+
+	t = btf_find_func_proto(name, &btf);
+	if (IS_ERR_OR_NULL(t))
+		goto out;
+
+	param = btf_get_func_param(t, &nr);
+	if (!param)
+		goto out_put;
+
+	for (a = 0, p = 0; p < nr; a++, p++) {
+		if (p)
+			trace_seq_puts(s, ", ");
+
+		/* This only prints what the arch allows (6 args by default) */
+		if (a == FTRACE_REGS_MAX_ARGS) {
+			trace_seq_puts(s, "...");
+			break;
+		}
+
+		arg = args[a];
+
+		param_name = btf_name_by_offset(btf, param[p].name_off);
+		if (param_name)
+			trace_seq_printf(s, "%s=", param_name);
+		t = btf_type_skip_modifiers(btf, param[p].type, &tid);
+
+		switch (t ? BTF_INFO_KIND(t->info) : BTF_KIND_UNKN) {
+		case BTF_KIND_UNKN:
+			trace_seq_putc(s, '?');
+			/* Still print unknown type values */
+			fallthrough;
+		case BTF_KIND_PTR:
+			trace_seq_printf(s, "0x%lx", arg);
+			break;
+		case BTF_KIND_INT:
+			trace_seq_printf(s, "%ld", arg);
+			break;
+		case BTF_KIND_ENUM:
+			trace_seq_printf(s, "%ld", arg);
+			break;
+		default:
+			/* This does not handle complex arguments */
+			trace_seq_printf(s, "(%s)[0x%lx", btf_type_str(t), arg);
+			for (x = sizeof(long); x < t->size; x += sizeof(long)) {
+				trace_seq_putc(s, ':');
+				if (++a == FTRACE_REGS_MAX_ARGS) {
+					trace_seq_puts(s, "...]");
+					goto out_put;
+				}
+				trace_seq_printf(s, "0x%lx", args[a]);
+			}
+			trace_seq_putc(s, ']');
+			break;
+		}
+	}
+out_put:
+	btf_put(btf);
+out:
+	trace_seq_printf(s, ")");
+}
+#endif
+
 /**
  * ftrace_find_event - find a registered event
  * @type: the type of event to look for


And now I get this as output:

            less-912     [006] ...1.   240.085082: timespec64_add_safe(lhs=(STRUCT)[0xef:0x10c8f152], rhs=(STRUCT)[0x4:0x0]) <-__se_sys_poll
            less-914     [006] ...1.   241.241416: timespec64_add_safe(lhs=(STRUCT)[0xf0:0x1a1af859], rhs=(STRUCT)[0x4:0x0]) <-__se_sys_poll
            less-916     [006] ...1.   242.653586: timespec64_add_safe(lhs=(STRUCT)[0xf1:0x32ac56c9], rhs=(STRUCT)[0x4:0x0]) <-__se_sys_poll
  wpa_supplicant-488     [004] ...1.   246.771910: timespec64_add_safe(lhs=(STRUCT)[0xf5:0x39ba39d3], rhs=(STRUCT)[0x9:0x3b9ac618]) <-__se_sys_pselect6
  wpa_supplicant-488     [004] ...1.   256.783841: timespec64_add_safe(lhs=(STRUCT)[0xff:0x3a714d62], rhs=(STRUCT)[0xa:0x0]) <-__se_sys_pselect6
  NetworkManager-485     [006] ...1.   257.008653: timespec64_add_safe(lhs=(STRUCT)[0x100:0xc3ce7d5], rhs=(STRUCT)[0x0:0x16358818]) <-__se_sys_ppoll
  NetworkManager-485     [006] ...1.   257.008676: timespec64_add_safe(lhs=(STRUCT)[0x100:0xc3d477e], rhs=(STRUCT)[0x0:0x16352288]) <-__se_sys_ppoll
  NetworkManager-485     [006] ...1.   257.383973: timespec64_add_safe(lhs=(STRUCT)[0x100:0x229be0b6], rhs=(STRUCT)[0x11:0x11c46e70]) <-__se_sys_ppoll


Which looks much more reasonable.

-- Steve

Re: [PATCH v2 1/4] ftrace: Add print_function_args()

[Masami Hiramatsu]

On Mon, 23 Dec 2024 15:13:48 -0500
Steven Rostedt <rostedt@goodmis.org> wrote:

> From: Sven Schnelle <svens@linux.ibm.com>
> 
> Add a function to decode argument types with the help of BTF. Will
> be used to display arguments in the function and function graph
> tracer.
> 
> It can only handle simply arguments and up to FTRACE_REGS_MAX_ARGS number
> of arguments. When it hits a max, it will print ", ...":
> 
>    page_to_skb(vi=0xffff8d53842dc980, rq=0xffff8d53843a0800, page=0xfffffc2e04337c00, offset=6160, len=64, truesize=1536, ...)
> 
> And if it hits an argument that is not recognized, it will print the raw
> value and the type of argument it is:
> 
>    make_vfsuid(idmap=0xffffffff87f99db8, fs_userns=0xffffffff87e543c0, kuid=0x0 (STRUCT))
>    __pti_set_user_pgtbl(pgdp=0xffff8d5384ab47f8, pgd=0x110e74067 (STRUCT))
> 
> Co-developed-by: Steven Rostedt (Google) <rostedt@goodmis.org>
> Signed-off-by: Sven Schnelle <svens@linux.ibm.com>
> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
> ---
> Changes since v1: https://lore.kernel.org/20240904065908.1009086-5-svens@linux.ibm.com
> 
>  - Added Config option FUNCTION_TRACE_ARGS to this patch
>   (unconditional if dependencies are met)
> 
>  - Changed the print_function_args() function to take an array of
>    unsigned long args and not the ftrace_regs pointer. The ftrace_regs
>    should be opaque from generic code.
> 
>  - Have the function print the name of an BTF type that is not supported.
> 
>  - Added FTRACE_REGS_MAX_ARGS as the number of arguments saved in
>    the event and printed out.
> 
>  - Print "...," if the number of arguments goes past FTRACE_REGS_MAX_ARGS.
> 
>  include/linux/ftrace_regs.h |  5 +++
>  kernel/trace/Kconfig        |  6 +++
>  kernel/trace/trace_output.c | 78 +++++++++++++++++++++++++++++++++++++
>  kernel/trace/trace_output.h |  9 +++++
>  4 files changed, 98 insertions(+)
> 
> diff --git a/include/linux/ftrace_regs.h b/include/linux/ftrace_regs.h
> index bbc1873ca6b8..15627ceea9bc 100644
> --- a/include/linux/ftrace_regs.h
> +++ b/include/linux/ftrace_regs.h
> @@ -35,4 +35,9 @@ struct ftrace_regs;
>  
>  #endif /* HAVE_ARCH_FTRACE_REGS */
>  
> +/* This can be overridden by the architectures */
> +#ifndef FTRACE_REGS_MAX_ARGS
> +# define FTRACE_REGS_MAX_ARGS	6
> +#endif
> +
>  #endif /* _LINUX_FTRACE_REGS_H */
> diff --git a/kernel/trace/Kconfig b/kernel/trace/Kconfig
> index d570b8b9c0a9..60412c1012ef 100644
> --- a/kernel/trace/Kconfig
> +++ b/kernel/trace/Kconfig
> @@ -263,6 +263,12 @@ config FUNCTION_GRAPH_RETADDR
>  	  the function is called. This feature is off by default, and you can
>  	  enable it via the trace option funcgraph-retaddr.
>  
> +config FUNCTION_TRACE_ARGS
> +       bool
> +	depends on HAVE_FUNCTION_ARG_ACCESS_API
> +	depends on DEBUG_INFO_BTF

For using the BTF APIs, we also needs BPF_SYSCALL (DEBUG_INFO_BTF just
compiles the BTF info into the kernel binary.)

Others looks good to me.

Revewied-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>

Thanks!

> +	default y
> +
>  config DYNAMIC_FTRACE
>  	bool "enable/disable function tracing dynamically"
>  	depends on FUNCTION_TRACER
> diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
> index da748b7cbc4d..40d6c7a9e0c4 100644
> --- a/kernel/trace/trace_output.c
> +++ b/kernel/trace/trace_output.c
> @@ -12,8 +12,11 @@
>  #include <linux/sched/clock.h>
>  #include <linux/sched/mm.h>
>  #include <linux/idr.h>
> +#include <linux/btf.h>
> +#include <linux/bpf.h>
>  
>  #include "trace_output.h"
> +#include "trace_btf.h"
>  
>  /* must be a power of 2 */
>  #define EVENT_HASHSIZE	128
> @@ -680,6 +683,81 @@ int trace_print_lat_context(struct trace_iterator *iter)
>  	return !trace_seq_has_overflowed(s);
>  }
>  
> +#ifdef CONFIG_FUNCTION_TRACE_ARGS
> +void print_function_args(struct trace_seq *s, unsigned long *args,
> +			 unsigned long func)
> +{
> +	const struct btf_param *param;
> +	const struct btf_type *t;
> +	const char *param_name;
> +	char name[KSYM_NAME_LEN];
> +	unsigned long arg;
> +	struct btf *btf;
> +	s32 tid, nr = 0;
> +	int i;
> +
> +	trace_seq_printf(s, "(");
> +
> +	if (!args)
> +		goto out;
> +	if (lookup_symbol_name(func, name))
> +		goto out;
> +
> +	btf = bpf_get_btf_vmlinux();
> +	if (IS_ERR_OR_NULL(btf))
> +		goto out;
> +
> +	t = btf_find_func_proto(name, &btf);
> +	if (IS_ERR_OR_NULL(t))
> +		goto out;
> +
> +	param = btf_get_func_param(t, &nr);
> +	if (!param)
> +		goto out_put;
> +
> +	for (i = 0; i < nr; i++) {
> +		/* This only prints what the arch allows (6 args by default) */
> +		if (i == FTRACE_REGS_MAX_ARGS) {
> +			trace_seq_puts(s, "...");
> +			break;
> +		}
> +
> +		arg = args[i];
> +
> +		param_name = btf_name_by_offset(btf, param[i].name_off);
> +		if (param_name)
> +			trace_seq_printf(s, "%s=", param_name);
> +		t = btf_type_skip_modifiers(btf, param[i].type, &tid);
> +
> +		switch (t ? BTF_INFO_KIND(t->info) : BTF_KIND_UNKN) {
> +		case BTF_KIND_UNKN:
> +			trace_seq_putc(s, '?');
> +			/* Still print unknown type values */
> +			fallthrough;
> +		case BTF_KIND_PTR:
> +			trace_seq_printf(s, "0x%lx", arg);
> +			break;
> +		case BTF_KIND_INT:
> +			trace_seq_printf(s, "%ld", arg);
> +			break;
> +		case BTF_KIND_ENUM:
> +			trace_seq_printf(s, "%ld", arg);
> +			break;
> +		default:
> +			/* This does not handle complex arguments */
> +			trace_seq_printf(s, "0x%lx (%s)", arg, btf_type_str(t));
> +			break;
> +		}
> +		if (i < nr - 1)
> +			trace_seq_printf(s, ", ");
> +	}
> +out_put:
> +	btf_put(btf);
> +out:
> +	trace_seq_printf(s, ")");
> +}
> +#endif
> +
>  /**
>   * ftrace_find_event - find a registered event
>   * @type: the type of event to look for
> diff --git a/kernel/trace/trace_output.h b/kernel/trace/trace_output.h
> index dca40f1f1da4..2e305364f2a9 100644
> --- a/kernel/trace/trace_output.h
> +++ b/kernel/trace/trace_output.h
> @@ -41,5 +41,14 @@ extern struct rw_semaphore trace_event_sem;
>  #define SEQ_PUT_HEX_FIELD(s, x)				\
>  	trace_seq_putmem_hex(s, &(x), sizeof(x))
>  
> +#ifdef CONFIG_FUNCTION_TRACE_ARGS
> +void print_function_args(struct trace_seq *s, unsigned long *args,
> +			 unsigned long func);
> +#else
> +static inline void print_function_args(struct trace_seq *s, unsigned long *args,
> +				       unsigned long func) {
> +	trace_seq_puts(s, "()");
> +}
> +#endif
>  #endif
>  
> -- 
> 2.45.2
> 
> 


-- 
Masami Hiramatsu (Google) <mhiramat@kernel.org>

Re: [PATCH v2 4/4] ftrace: Add arguments to function tracer

[Masami Hiramatsu]

On Mon, 23 Dec 2024 15:13:51 -0500
Steven Rostedt <rostedt@goodmis.org> wrote:

> From: Sven Schnelle <svens@linux.ibm.com>
> 
> Wire up the code to print function arguments in the function tracer.
> This functionality can be enabled/disabled during runtime with
> options/func-args.
> 
>         ping-689     [004] b....    77.170220: dummy_xmit(skb = 0x82904800, dev = 0x882d0000) <-dev_hard_start_xmit
> 

Looks good to me.

Reviewed-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>

> Co-developed-by: Steven Rostedt (Google) <rostedt@goodmis.org>
> Signed-off-by: Sven Schnelle <svens@linux.ibm.com>
> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
> ---
> Changes since v1: https://lore.kernel.org/20240904065908.1009086-8-svens@linux.ibm.com
> 
>  - Save only the arguments into the ring buffer and not the ftrace_regs
>    as the ftrace_regs should be opaque from generic code.
> 
>  - Have the function tracer event be dynamic so that it can hold an array
>    of arguments after the entry.
> 
>  kernel/trace/trace.c              | 12 ++++++--
>  kernel/trace/trace.h              |  3 +-
>  kernel/trace/trace_entries.h      |  5 ++--
>  kernel/trace/trace_functions.c    | 46 +++++++++++++++++++++++++++----
>  kernel/trace/trace_irqsoff.c      |  4 +--
>  kernel/trace/trace_output.c       | 18 ++++++++++--
>  kernel/trace/trace_sched_wakeup.c |  4 +--
>  7 files changed, 75 insertions(+), 17 deletions(-)
> 
> diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
> index be62f0ea1814..3c0ffdcdcb7e 100644
> --- a/kernel/trace/trace.c
> +++ b/kernel/trace/trace.c
> @@ -2897,13 +2897,16 @@ trace_buffer_unlock_commit_nostack(struct trace_buffer *buffer,
>  
>  void
>  trace_function(struct trace_array *tr, unsigned long ip, unsigned long
> -	       parent_ip, unsigned int trace_ctx)
> +	       parent_ip, unsigned int trace_ctx, struct ftrace_regs *fregs)
>  {
>  	struct trace_buffer *buffer = tr->array_buffer.buffer;
>  	struct ring_buffer_event *event;
>  	struct ftrace_entry *entry;
> +	int size = sizeof(*entry);
>  
> -	event = __trace_buffer_lock_reserve(buffer, TRACE_FN, sizeof(*entry),
> +	size += FTRACE_REGS_MAX_ARGS * !!fregs * sizeof(long);
> +
> +	event = __trace_buffer_lock_reserve(buffer, TRACE_FN, size,
>  					    trace_ctx);
>  	if (!event)
>  		return;
> @@ -2911,6 +2914,11 @@ trace_function(struct trace_array *tr, unsigned long ip, unsigned long
>  	entry->ip			= ip;
>  	entry->parent_ip		= parent_ip;
>  
> +	if (fregs) {
> +		for (int i = 0; i < FTRACE_REGS_MAX_ARGS; i++)
> +			entry->args[i] = ftrace_regs_get_argument(fregs, i);
> +	}
> +
>  	if (static_branch_unlikely(&trace_function_exports_enabled))
>  		ftrace_exports(event, TRACE_EXPORT_FUNCTION);
>  	__buffer_unlock_commit(buffer, event);
> diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
> index 6f67bbc17bed..3d4a5ec9ee55 100644
> --- a/kernel/trace/trace.h
> +++ b/kernel/trace/trace.h
> @@ -685,7 +685,8 @@ unsigned long trace_total_entries(struct trace_array *tr);
>  void trace_function(struct trace_array *tr,
>  		    unsigned long ip,
>  		    unsigned long parent_ip,
> -		    unsigned int trace_ctx);
> +		    unsigned int trace_ctx,
> +		    struct ftrace_regs *regs);
>  void trace_graph_function(struct trace_array *tr,
>  		    unsigned long ip,
>  		    unsigned long parent_ip,
> diff --git a/kernel/trace/trace_entries.h b/kernel/trace/trace_entries.h
> index 254491b545c3..11288dc4f59b 100644
> --- a/kernel/trace/trace_entries.h
> +++ b/kernel/trace/trace_entries.h
> @@ -61,8 +61,9 @@ FTRACE_ENTRY_REG(function, ftrace_entry,
>  	TRACE_FN,
>  
>  	F_STRUCT(
> -		__field_fn(	unsigned long,	ip		)
> -		__field_fn(	unsigned long,	parent_ip	)
> +		__field_fn(	unsigned long,		ip		)
> +		__field_fn(	unsigned long,		parent_ip	)
> +		__dynamic_array( unsigned long,		args		)
>  	),
>  
>  	F_printk(" %ps <-- %ps",
> diff --git a/kernel/trace/trace_functions.c b/kernel/trace/trace_functions.c
> index d358c9935164..1f4f02df6f8c 100644
> --- a/kernel/trace/trace_functions.c
> +++ b/kernel/trace/trace_functions.c
> @@ -25,6 +25,9 @@ static void
>  function_trace_call(unsigned long ip, unsigned long parent_ip,
>  		    struct ftrace_ops *op, struct ftrace_regs *fregs);
>  static void
> +function_args_trace_call(unsigned long ip, unsigned long parent_ip,
> +			 struct ftrace_ops *op, struct ftrace_regs *fregs);
> +static void
>  function_stack_trace_call(unsigned long ip, unsigned long parent_ip,
>  			  struct ftrace_ops *op, struct ftrace_regs *fregs);
>  static void
> @@ -42,9 +45,10 @@ enum {
>  	TRACE_FUNC_NO_OPTS		= 0x0, /* No flags set. */
>  	TRACE_FUNC_OPT_STACK		= 0x1,
>  	TRACE_FUNC_OPT_NO_REPEATS	= 0x2,
> +	TRACE_FUNC_OPT_ARGS		= 0x4,
>  
>  	/* Update this to next highest bit. */
> -	TRACE_FUNC_OPT_HIGHEST_BIT	= 0x4
> +	TRACE_FUNC_OPT_HIGHEST_BIT	= 0x8
>  };
>  
>  #define TRACE_FUNC_OPT_MASK	(TRACE_FUNC_OPT_HIGHEST_BIT - 1)
> @@ -114,6 +118,8 @@ static ftrace_func_t select_trace_function(u32 flags_val)
>  	switch (flags_val & TRACE_FUNC_OPT_MASK) {
>  	case TRACE_FUNC_NO_OPTS:
>  		return function_trace_call;
> +	case TRACE_FUNC_OPT_ARGS:
> +		return function_args_trace_call;
>  	case TRACE_FUNC_OPT_STACK:
>  		return function_stack_trace_call;
>  	case TRACE_FUNC_OPT_NO_REPEATS:
> @@ -220,7 +226,34 @@ function_trace_call(unsigned long ip, unsigned long parent_ip,
>  
>  	data = this_cpu_ptr(tr->array_buffer.data);
>  	if (!atomic_read(&data->disabled))
> -		trace_function(tr, ip, parent_ip, trace_ctx);
> +		trace_function(tr, ip, parent_ip, trace_ctx, NULL);
> +
> +	ftrace_test_recursion_unlock(bit);
> +}
> +
> +static void
> +function_args_trace_call(unsigned long ip, unsigned long parent_ip,
> +			 struct ftrace_ops *op, struct ftrace_regs *fregs)
> +{
> +	struct trace_array *tr = op->private;
> +	struct trace_array_cpu *data;
> +	unsigned int trace_ctx;
> +	int bit;
> +	int cpu;
> +
> +	if (unlikely(!tr->function_enabled))
> +		return;
> +
> +	bit = ftrace_test_recursion_trylock(ip, parent_ip);
> +	if (bit < 0)
> +		return;
> +
> +	trace_ctx = tracing_gen_ctx();
> +
> +	cpu = smp_processor_id();
> +	data = per_cpu_ptr(tr->array_buffer.data, cpu);
> +	if (!atomic_read(&data->disabled))
> +		trace_function(tr, ip, parent_ip, trace_ctx, fregs);
>  
>  	ftrace_test_recursion_unlock(bit);
>  }
> @@ -270,7 +303,7 @@ function_stack_trace_call(unsigned long ip, unsigned long parent_ip,
>  
>  	if (likely(disabled == 1)) {
>  		trace_ctx = tracing_gen_ctx_flags(flags);
> -		trace_function(tr, ip, parent_ip, trace_ctx);
> +		trace_function(tr, ip, parent_ip, trace_ctx, NULL);
>  #ifdef CONFIG_UNWINDER_FRAME_POINTER
>  		if (ftrace_pids_enabled(op))
>  			skip++;
> @@ -351,7 +384,7 @@ function_no_repeats_trace_call(unsigned long ip, unsigned long parent_ip,
>  	trace_ctx = tracing_gen_ctx_flags(flags);
>  	process_repeats(tr, ip, parent_ip, last_info, trace_ctx);
>  
> -	trace_function(tr, ip, parent_ip, trace_ctx);
> +	trace_function(tr, ip, parent_ip, trace_ctx, NULL);
>  
>  out:
>  	ftrace_test_recursion_unlock(bit);
> @@ -391,7 +424,7 @@ function_stack_no_repeats_trace_call(unsigned long ip, unsigned long parent_ip,
>  		trace_ctx = tracing_gen_ctx_flags(flags);
>  		process_repeats(tr, ip, parent_ip, last_info, trace_ctx);
>  
> -		trace_function(tr, ip, parent_ip, trace_ctx);
> +		trace_function(tr, ip, parent_ip, trace_ctx, NULL);
>  		__trace_stack(tr, trace_ctx, STACK_SKIP);
>  	}
>  
> @@ -405,6 +438,9 @@ static struct tracer_opt func_opts[] = {
>  	{ TRACER_OPT(func_stack_trace, TRACE_FUNC_OPT_STACK) },
>  #endif
>  	{ TRACER_OPT(func-no-repeats, TRACE_FUNC_OPT_NO_REPEATS) },
> +#ifdef CONFIG_FUNCTION_TRACE_ARGS
> +	{ TRACER_OPT(func-args, TRACE_FUNC_OPT_ARGS) },
> +#endif
>  	{ } /* Always set a last empty entry */
>  };
>  
> diff --git a/kernel/trace/trace_irqsoff.c b/kernel/trace/trace_irqsoff.c
> index 504de7a05498..68ce152dbb8c 100644
> --- a/kernel/trace/trace_irqsoff.c
> +++ b/kernel/trace/trace_irqsoff.c
> @@ -150,7 +150,7 @@ irqsoff_tracer_call(unsigned long ip, unsigned long parent_ip,
>  
>  	trace_ctx = tracing_gen_ctx_flags(flags);
>  
> -	trace_function(tr, ip, parent_ip, trace_ctx);
> +	trace_function(tr, ip, parent_ip, trace_ctx, fregs);
>  
>  	atomic_dec(&data->disabled);
>  }
> @@ -280,7 +280,7 @@ __trace_function(struct trace_array *tr,
>  	if (is_graph(tr))
>  		trace_graph_function(tr, ip, parent_ip, trace_ctx);
>  	else
> -		trace_function(tr, ip, parent_ip, trace_ctx);
> +		trace_function(tr, ip, parent_ip, trace_ctx, NULL);
>  }
>  
>  #else
> diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
> index 40d6c7a9e0c4..aed6758416a0 100644
> --- a/kernel/trace/trace_output.c
> +++ b/kernel/trace/trace_output.c
> @@ -1079,12 +1079,15 @@ enum print_line_t trace_nop_print(struct trace_iterator *iter, int flags,
>  }
>  
>  static void print_fn_trace(struct trace_seq *s, unsigned long ip,
> -			   unsigned long parent_ip, long delta, int flags)
> +			   unsigned long parent_ip, long delta,
> +			   unsigned long *args, int flags)
>  {
>  	ip += delta;
>  	parent_ip += delta;
>  
>  	seq_print_ip_sym(s, ip, flags);
> +	if (args)
> +		print_function_args(s, args, ip);
>  
>  	if ((flags & TRACE_ITER_PRINT_PARENT) && parent_ip) {
>  		trace_seq_puts(s, " <-");
> @@ -1098,10 +1101,19 @@ static enum print_line_t trace_fn_trace(struct trace_iterator *iter, int flags,
>  {
>  	struct ftrace_entry *field;
>  	struct trace_seq *s = &iter->seq;
> +	unsigned long *args;
> +	int args_size;
>  
>  	trace_assign_type(field, iter->ent);
>  
> -	print_fn_trace(s, field->ip, field->parent_ip, iter->tr->text_delta, flags);
> +	args_size = iter->ent_size - offsetof(struct ftrace_entry, args);
> +	if (args_size >= FTRACE_REGS_MAX_ARGS * sizeof(long))
> +		args = field->args;
> +	else
> +		args = NULL;
> +
> +	print_fn_trace(s, field->ip, field->parent_ip, iter->tr->text_delta,
> +		       args, flags);
>  	trace_seq_putc(s, '\n');
>  
>  	return trace_handle_return(s);
> @@ -1774,7 +1786,7 @@ trace_func_repeats_print(struct trace_iterator *iter, int flags,
>  
>  	trace_assign_type(field, iter->ent);
>  
> -	print_fn_trace(s, field->ip, field->parent_ip, iter->tr->text_delta, flags);
> +	print_fn_trace(s, field->ip, field->parent_ip, iter->tr->text_delta, NULL, flags);
>  	trace_seq_printf(s, " (repeats: %u, last_ts:", field->count);
>  	trace_print_time(s, iter,
>  			 iter->ts - FUNC_REPEATS_GET_DELTA_TS(field));
> diff --git a/kernel/trace/trace_sched_wakeup.c b/kernel/trace/trace_sched_wakeup.c
> index 8165382a174a..19b0205b91dd 100644
> --- a/kernel/trace/trace_sched_wakeup.c
> +++ b/kernel/trace/trace_sched_wakeup.c
> @@ -226,7 +226,7 @@ wakeup_tracer_call(unsigned long ip, unsigned long parent_ip,
>  		return;
>  
>  	local_irq_save(flags);
> -	trace_function(tr, ip, parent_ip, trace_ctx);
> +	trace_function(tr, ip, parent_ip, trace_ctx, fregs);
>  	local_irq_restore(flags);
>  
>  	atomic_dec(&data->disabled);
> @@ -311,7 +311,7 @@ __trace_function(struct trace_array *tr,
>  	if (is_graph(tr))
>  		trace_graph_function(tr, ip, parent_ip, trace_ctx);
>  	else
> -		trace_function(tr, ip, parent_ip, trace_ctx);
> +		trace_function(tr, ip, parent_ip, trace_ctx, NULL);
>  }
>  
>  static int wakeup_flag_changed(struct trace_array *tr, u32 mask, int set)
> -- 
> 2.45.2
> 
> 


-- 
Masami Hiramatsu (Google) <mhiramat@kernel.org>

Re: [PATCH v2 3/4] ftrace: Have funcgraph-args take affect during tracing

[Masami Hiramatsu]

On Mon, 23 Dec 2024 15:13:50 -0500
Steven Rostedt <rostedt@goodmis.org> wrote:

> From: Steven Rostedt <rostedt@goodmis.org>
> 
> Currently, when function_graph is started, it looks at the option
> funcgraph-args, and if it is set, it will enable tracing of the arguments.
> 
> But if tracing is already running, and the user enables funcgraph-args, it
> will have no effect. Instead, it should enable argument tracing when it is
> enabled, even if it means disabling the function graph tracing for a short
> time in order to do the transition.
> 

Looks good to me.

Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>


> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
> ---
>  kernel/trace/trace_functions_graph.c | 27 ++++++++++++++++++++++++++-
>  1 file changed, 26 insertions(+), 1 deletion(-)
> 
> diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
> index c8eda9bebdf4..d1ee001f5a8e 100644
> --- a/kernel/trace/trace_functions_graph.c
> +++ b/kernel/trace/trace_functions_graph.c
> @@ -469,7 +469,7 @@ static int graph_trace_init(struct trace_array *tr)
>  	else
>  		tr->gops->retfunc = trace_graph_return;
>  
> -	/* Make gops functions are visible before we start tracing */
> +	/* Make gops functions visible before we start tracing */
>  	smp_mb();
>  
>  	ret = register_ftrace_graph(tr->gops);
> @@ -480,6 +480,28 @@ static int graph_trace_init(struct trace_array *tr)
>  	return 0;
>  }
>  
> +static int ftrace_graph_trace_args(struct trace_array *tr, int set)
> +{
> +	trace_func_graph_ent_t entry;
> +
> +	if (set)
> +		entry = trace_graph_entry_args;
> +	else
> +		entry = trace_graph_entry;
> +
> +	/* See if there's any changes */
> +	if (tr->gops->entryfunc == entry)
> +		return 0;
> +
> +	unregister_ftrace_graph(tr->gops);
> +
> +	tr->gops->entryfunc = entry;
> +
> +	/* Make gops functions visible before we start tracing */
> +	smp_mb();
> +	return register_ftrace_graph(tr->gops);
> +}
> +
>  static void graph_trace_reset(struct trace_array *tr)
>  {
>  	tracing_stop_cmdline_record();
> @@ -1609,6 +1631,9 @@ func_graph_set_flag(struct trace_array *tr, u32 old_flags, u32 bit, int set)
>  	if (bit == TRACE_GRAPH_GRAPH_TIME)
>  		ftrace_graph_graph_time_control(set);
>  
> +	if (bit == TRACE_GRAPH_ARGS)
> +		return ftrace_graph_trace_args(tr, set);
> +
>  	return 0;
>  }
>  
> -- 
> 2.45.2
> 
> 


-- 
Masami Hiramatsu (Google) <mhiramat@kernel.org>

Re: [PATCH v2 2/4] ftrace: Add support for function argument to graph tracer

[Masami Hiramatsu]

On Mon, 23 Dec 2024 15:13:49 -0500
Steven Rostedt <rostedt@goodmis.org> wrote:

> From: Sven Schnelle <svens@linux.ibm.com>
> 
> Wire up the code to print function arguments in the function graph
> tracer. This functionality can be enabled/disabled during runtime with
> options/funcgraph-args.
> 
> 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    |     }
> 



> Co-developed-by: Steven Rostedt (Google) <rostedt@goodmis.org>
> Signed-off-by: Sven Schnelle <svens@linux.ibm.com>
> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
> ---
> Changes since v1: https://lore.kernel.org/20240904065908.1009086-7-svens@linux.ibm.com
>  
>  - Record just FTRACE_REGS_MAX_ARGS into the ring buffer and not the
>    entire ftrace_regs structure, as that structure should be opaque
>    from generic code.
> 
>  - Make the function graph entry event have a dynamic size, so that an
>    array of arguments may be added in the ring buffer after it.
> 
>  kernel/trace/Kconfig                 |   6 ++
>  kernel/trace/trace.h                 |   1 +
>  kernel/trace/trace_entries.h         |   7 +-
>  kernel/trace/trace_functions_graph.c | 147 +++++++++++++++++++++------
>  4 files changed, 125 insertions(+), 36 deletions(-)
> 
> diff --git a/kernel/trace/Kconfig b/kernel/trace/Kconfig
> index 60412c1012ef..033fba0633cf 100644
> --- a/kernel/trace/Kconfig
> +++ b/kernel/trace/Kconfig
> @@ -268,6 +268,12 @@ config FUNCTION_TRACE_ARGS
>  	depends on HAVE_FUNCTION_ARG_ACCESS_API
>  	depends on DEBUG_INFO_BTF
>  	default y
> +	help
> +	  If supported with function argument access API and BTF, then
> +	  the function tracer and function graph tracer will support printing
> +	  of function arguments. This feature is off by default, and can be
> +	  enabled via the trace option func-args (for the function tracer) and
> +	  funcgraph-args (for the function graph tracer)
>  
>  config DYNAMIC_FTRACE
>  	bool "enable/disable function tracing dynamically"
> diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
> index ad9f008d7dd7..6f67bbc17bed 100644
> --- a/kernel/trace/trace.h
> +++ b/kernel/trace/trace.h
> @@ -887,6 +887,7 @@ static __always_inline bool ftrace_hash_empty(struct ftrace_hash *hash)
>  #define TRACE_GRAPH_PRINT_RETVAL        0x800
>  #define TRACE_GRAPH_PRINT_RETVAL_HEX    0x1000
>  #define TRACE_GRAPH_PRINT_RETADDR       0x2000
> +#define TRACE_GRAPH_ARGS		0x4000
>  #define TRACE_GRAPH_PRINT_FILL_SHIFT	28
>  #define TRACE_GRAPH_PRINT_FILL_MASK	(0x3 << TRACE_GRAPH_PRINT_FILL_SHIFT)
>  
> diff --git a/kernel/trace/trace_entries.h b/kernel/trace/trace_entries.h
> index 82fd174ebbe0..254491b545c3 100644
> --- a/kernel/trace/trace_entries.h
> +++ b/kernel/trace/trace_entries.h
> @@ -72,17 +72,18 @@ FTRACE_ENTRY_REG(function, ftrace_entry,
>  );
>  
>  /* Function call entry */
> -FTRACE_ENTRY_PACKED(funcgraph_entry, ftrace_graph_ent_entry,
> +FTRACE_ENTRY(funcgraph_entry, ftrace_graph_ent_entry,
>  
>  	TRACE_GRAPH_ENT,
>  
>  	F_STRUCT(
>  		__field_struct(	struct ftrace_graph_ent,	graph_ent	)
>  		__field_packed(	unsigned long,	graph_ent,	func		)
> -		__field_packed(	int,		graph_ent,	depth		)
> +		__field_packed(	unsigned long,	graph_ent,	depth		)
> +		__dynamic_array(unsigned long,	args				)
>  	),
>  
> -	F_printk("--> %ps (%d)", (void *)__entry->func, __entry->depth)
> +	F_printk("--> %ps (%lu)", (void *)__entry->func, __entry->depth)
>  );
>  
>  #ifdef CONFIG_FUNCTION_GRAPH_RETADDR
> diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
> index d0e4f412c298..c8eda9bebdf4 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>

Do we need these headers? I think it is wrapped by print_function_args().

>  
>  #include "trace.h"
>  #include "trace_output.h"
> @@ -70,6 +72,10 @@ static struct tracer_opt trace_opts[] = {
>  #ifdef CONFIG_FUNCTION_GRAPH_RETADDR
>  	/* Display function return address ? */
>  	{ TRACER_OPT(funcgraph-retaddr, TRACE_GRAPH_PRINT_RETADDR) },
> +#endif
> +#ifdef CONFIG_FUNCTION_TRACE_ARGS
> +	/* Display function arguments ? */
> +	{ 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) },
> @@ -110,25 +116,41 @@ static void
>  print_graph_duration(struct trace_array *tr, unsigned long long duration,
>  		     struct trace_seq *s, u32 flags);
>  
> -int __trace_graph_entry(struct trace_array *tr,
> -				struct ftrace_graph_ent *trace,
> -				unsigned int trace_ctx)
> +static int __graph_entry(struct trace_array *tr, struct ftrace_graph_ent *trace,
> +			 unsigned int trace_ctx, struct ftrace_regs *fregs)
>  {
>  	struct ring_buffer_event *event;
>  	struct trace_buffer *buffer = tr->array_buffer.buffer;
>  	struct ftrace_graph_ent_entry *entry;
> +	int size;
>  
> -	event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_ENT,
> -					  sizeof(*entry), trace_ctx);
> +	/* If fregs is defined, add FTRACE_REGS_MAX_ARGS long size words */
> +	size = sizeof(*entry) + (FTRACE_REGS_MAX_ARGS * !!fregs * sizeof(long));
> +
> +	event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_ENT, size, trace_ctx);
>  	if (!event)
>  		return 0;
> -	entry	= ring_buffer_event_data(event);
> -	entry->graph_ent			= *trace;
> +
> +	entry = ring_buffer_event_data(event);
> +	entry->graph_ent = *trace;
> +
> +	if (fregs) {
> +		for (int i = 0; i < FTRACE_REGS_MAX_ARGS; i++)
> +			entry->args[i] = ftrace_regs_get_argument(fregs, i);
> +	}
> +
>  	trace_buffer_unlock_commit_nostack(buffer, event);
>  
>  	return 1;
>  }
>  
> +int __trace_graph_entry(struct trace_array *tr,
> +				struct ftrace_graph_ent *trace,
> +				unsigned int trace_ctx)
> +{
> +	return __graph_entry(tr, trace, trace_ctx, NULL);
> +}
> +
>  #ifdef CONFIG_FUNCTION_GRAPH_RETADDR
>  int __trace_graph_retaddr_entry(struct trace_array *tr,
>  				struct ftrace_graph_ent *trace,
> @@ -174,9 +196,9 @@ struct fgraph_times {
>  	unsigned long long		sleeptime; /* may be optional! */
>  };
>  
> -int trace_graph_entry(struct ftrace_graph_ent *trace,
> -		      struct fgraph_ops *gops,
> -		      struct ftrace_regs *fregs)
> +static int graph_entry(struct ftrace_graph_ent *trace,
> +		       struct fgraph_ops *gops,
> +		       struct ftrace_regs *fregs)
>  {
>  	unsigned long *task_var = fgraph_get_task_var(gops);
>  	struct trace_array *tr = gops->private;
> @@ -248,7 +270,7 @@ int trace_graph_entry(struct ftrace_graph_ent *trace,
>  
>  			ret = __trace_graph_retaddr_entry(tr, trace, trace_ctx, retaddr);
>  		} else
> -			ret = __trace_graph_entry(tr, trace, trace_ctx);
> +			ret = __graph_entry(tr, trace, trace_ctx, fregs);
>  	} else {
>  		ret = 0;
>  	}
> @@ -259,6 +281,20 @@ int trace_graph_entry(struct ftrace_graph_ent *trace,
>  	return ret;
>  }
>  
> +int trace_graph_entry(struct ftrace_graph_ent *trace,
> +		      struct fgraph_ops *gops,
> +		      struct ftrace_regs *fregs)
> +{
> +	return graph_entry(trace, gops, NULL);
> +}
> +
> +static int trace_graph_entry_args(struct ftrace_graph_ent *trace,
> +				  struct fgraph_ops *gops,
> +				  struct ftrace_regs *fregs)
> +{
> +	return graph_entry(trace, gops, fregs);
> +}
> +
>  static void
>  __trace_graph_function(struct trace_array *tr,
>  		unsigned long ip, unsigned int trace_ctx)
> @@ -423,7 +459,10 @@ static int graph_trace_init(struct trace_array *tr)
>  {
>  	int ret;
>  
> -	tr->gops->entryfunc = trace_graph_entry;
> +	if (tracer_flags_is_set(TRACE_GRAPH_ARGS))
> +		tr->gops->entryfunc = trace_graph_entry_args;
> +	else
> +		tr->gops->entryfunc = trace_graph_entry;
>  
>  	if (tracing_thresh)
>  		tr->gops->retfunc = trace_graph_thresh_return;
> @@ -780,7 +819,7 @@ static void print_graph_retaddr(struct trace_seq *s, struct fgraph_retaddr_ent_e
>  
>  static void print_graph_retval(struct trace_seq *s, struct ftrace_graph_ent_entry *entry,
>  				struct ftrace_graph_ret *graph_ret, void *func,
> -				u32 opt_flags, u32 trace_flags)
> +				u32 opt_flags, u32 trace_flags, int args_size)
>  {
>  	unsigned long err_code = 0;
>  	unsigned long retval = 0;
> @@ -814,7 +853,14 @@ static void print_graph_retval(struct trace_seq *s, struct ftrace_graph_ent_entr
>  		if (entry->ent.type != TRACE_GRAPH_RETADDR_ENT)
>  			print_retaddr = false;
>  
> -		trace_seq_printf(s, "%ps();", func);
> +		trace_seq_printf(s, "%ps", func);
> +
> +		if (args_size >= FTRACE_REGS_MAX_ARGS * sizeof(long)) {
> +			print_function_args(s, entry->args, (unsigned long)func);
> +			trace_seq_putc(s, ';');
> +		} else
> +			trace_seq_puts(s, "();");
> +
>  		if (print_retval || print_retaddr)
>  			trace_seq_puts(s, " /*");
>  		else
> @@ -836,12 +882,13 @@ static void print_graph_retval(struct trace_seq *s, struct ftrace_graph_ent_entr
>  	}
>  
>  	if (!entry || print_retval || print_retaddr)
> -		trace_seq_puts(s, " */\n");
> +		trace_seq_puts(s, " */");

Do we need this change?

Thank you,



-- 
Masami Hiramatsu (Google) <mhiramat@kernel.org>

Re: [PATCH v2 0/4] ftrace: Add function arguments to function tracers

[Jiri Olsa]

On Mon, Dec 23, 2024 at 03:13:47PM -0500, Steven Rostedt wrote:
> 
> These patches add support for printing function arguments in ftrace.
> 
> Example usage:
> 
> function tracer:
> 
>  ~# cd /sys/kernel/tracing/
>  ~# echo icmp_rcv >set_ftrace_filter
>  ~# echo function >current_tracer
>  ~# echo 1 >options/func-args
>  ~# ping -c 10 127.0.0.1
> [..]
>  ~# cat trace
> [..]
>             ping-1277    [030] ..s1.    39.120939: icmp_rcv(skb=0xa0ecab00) <-ip_protocol_deliver_rcu
>             ping-1277    [030] ..s1.    39.120946: icmp_rcv(skb=0xa0ecac00) <-ip_protocol_deliver_rcu
>             ping-1277    [030] ..s1.    40.179724: icmp_rcv(skb=0xa0ecab00) <-ip_protocol_deliver_rcu
>             ping-1277    [030] ..s1.    40.179730: icmp_rcv(skb=0xa0ecac00) <-ip_protocol_deliver_rcu
>             ping-1277    [030] ..s1.    41.219700: icmp_rcv(skb=0xa0ecab00) <-ip_protocol_deliver_rcu
>             ping-1277    [030] ..s1.    41.219706: icmp_rcv(skb=0xa0ecac00) <-ip_protocol_deliver_rcu
>             ping-1277    [030] ..s1.    42.259717: icmp_rcv(skb=0xa0ecab00) <-ip_protocol_deliver_rcu
>             ping-1277    [030] ..s1.    42.259725: icmp_rcv(skb=0xa0ecac00) <-ip_protocol_deliver_rcu
>             ping-1277    [030] ..s1.    43.299735: icmp_rcv(skb=0xa0ecab00) <-ip_protocol_deliver_rcu
>             ping-1277    [030] ..s1.    43.299742: icmp_rcv(skb=0xa0ecac00) <-ip_protocol_deliver_rcu
> 
> function graph:
> 
>  ~# cd /sys/kernel/tracing
>  ~# echo icmp_rcv >set_graph_function
>  ~# echo function_graph >current_tracer
>  ~# echo 1 >options/funcgraph-args
> 
>  ~# ping -c 1 127.0.0.1
> 
>  ~# cat trace
> 
>  30)               |  icmp_rcv(skb=0xa0ecab00) {
>  30)               |    __skb_checksum_complete(skb=0xa0ecab00) {
>  30)               |      skb_checksum(skb=0xa0ecab00, offset=0, len=64, csum=0) {
>  30)               |        __skb_checksum(skb=0xa0ecab00, offset=0, len=64, csum=0, ops=0x232e0327a88) {
>  30)   0.418 us    |          csum_partial(buff=0xa0d20924, len=64, sum=0)
>  30)   0.985 us    |        }
>  30)   1.463 us    |      }
>  30)   2.039 us    |    }
> [..]
> 
> This was last posted by Sven Schnelle here:
> 
>   https://lore.kernel.org/all/20240904065908.1009086-1-svens@linux.ibm.com/
> 
> As Sven hasn't worked on it since, I decided to continue to push it
> through. I'm keeping Sven as original author and added myself as
> "Co-developed-by".
> 
> The main changes are:
> 
> - Made the kconfig option unconditional if all the dependencies are set.
> 
> - Not save ftrace_regs in the ring buffer, as that is an abstract
>   descriptor defined by the architectures and should remain opaque from
>   generic code. Instead, the args are read at the time they are recorded
>   (with the ftrace_regs passed to the callback function), and saved into
>   the ring buffer. Then the print function only takes an array of elements.
> 
>   This could allow archs to retrieve arguments that are on the stack where
>   as, post processing ftrace_regs could cause undesirable results.
> 
> - Made the function and function graph entry events dynamically sized
>   to allow the arguments to be appended to the event in the ring buffer.
>   The print function only looks to see if the event saved in the ring
>   buffer is big enough to hold all the arguments defined by the new
>   FTRACE_REGS_MAX_ARGS macro and if so, it will assume there are arguments
>   there and print them. This also means user space will not break on
>   reading these events as arguments will simply be ignored.
> 
> - The printing of the arguments has some more data when things are not
>   processed by BPF. Any unsupported argument will have the type printed
>   out in the ring buffer. 
> 
> - Also removed the spaces around the '=' as that's more in line to how
>   trace events show their fields.
> 
> - One new patch I added to convert function graph tracing over to using
>   args as soon as the user sets the option even if function graph tracing
>   is enabled. Function tracer did this already by default.
> 
> Steven Rostedt (1):
>       ftrace: Have funcgraph-args take affect during tracing
> 
> Sven Schnelle (3):
>       ftrace: Add print_function_args()
>       ftrace: Add support for function argument to graph tracer
>       ftrace: Add arguments to function tracer

hi,
what branch is this based on? can't find any that would apply patch#2
without conflict.

thanks,
jirka

> 
> ----
>  include/linux/ftrace_regs.h          |   5 +
>  kernel/trace/Kconfig                 |  12 +++
>  kernel/trace/trace.c                 |  12 ++-
>  kernel/trace/trace.h                 |   4 +-
>  kernel/trace/trace_entries.h         |  12 ++-
>  kernel/trace/trace_functions.c       |  46 ++++++++-
>  kernel/trace/trace_functions_graph.c | 174 ++++++++++++++++++++++++++++-------
>  kernel/trace/trace_irqsoff.c         |   4 +-
>  kernel/trace/trace_output.c          |  96 ++++++++++++++++++-
>  kernel/trace/trace_output.h          |   9 ++
>  kernel/trace/trace_sched_wakeup.c    |   4 +-
>  11 files changed, 324 insertions(+), 54 deletions(-)
> 

Re: [PATCH v2 0/4] ftrace: Add function arguments to function tracers

[Steven Rostedt]

On Wed, 25 Dec 2024 22:40:53 +0100
Jiri Olsa <olsajiri@gmail.com> wrote:

> hi,
> what branch is this based on? can't find any that would apply patch#2
> without conflict.

Sorry, I should have mentioned in the cover letter, that this is based
on v6.13-rc4 with Masami's fprobe patchset applied:

  https://lore.kernel.org/linux-trace-kernel/173379652547.973433.2311391879173461183.stgit@devnote2/

-- Steve

Re: [PATCH v2 1/4] ftrace: Add print_function_args()

[Steven Rostedt]

On Wed, 25 Dec 2024 22:15:55 +0900
Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote:

> >  
> > +config FUNCTION_TRACE_ARGS
> > +       bool
> > +	depends on HAVE_FUNCTION_ARG_ACCESS_API
> > +	depends on DEBUG_INFO_BTF  
> 
> For using the BTF APIs, we also needs BPF_SYSCALL (DEBUG_INFO_BTF just
> compiles the BTF info into the kernel binary.)
> 
> Others looks good to me.

Hmm, I removed it due to this feedback:

  https://lore.kernel.org/linux-trace-kernel/20240909225614.4f6d022e58f1276113c8492b@kernel.org/


> 
> Revewied-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>

Thanks!

-- Steve

Re: [PATCH v2 2/4] ftrace: Add support for function argument to graph tracer

[Steven Rostedt]

On Thu, 26 Dec 2024 00:41:52 +0900
Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote:
> > diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
> > index d0e4f412c298..c8eda9bebdf4 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>  
> 
> Do we need these headers? I think it is wrapped by print_function_args().

Oh, probably not. This is just leftovers from the original patch.

> > @@ -814,7 +853,14 @@ static void print_graph_retval(struct trace_seq *s, struct ftrace_graph_ent_entr
> >  		if (entry->ent.type != TRACE_GRAPH_RETADDR_ENT)
> >  			print_retaddr = false;
> >  
> > -		trace_seq_printf(s, "%ps();", func);
> > +		trace_seq_printf(s, "%ps", func);
> > +
> > +		if (args_size >= FTRACE_REGS_MAX_ARGS * sizeof(long)) {
> > +			print_function_args(s, entry->args, (unsigned long)func);
> > +			trace_seq_putc(s, ';');
> > +		} else
> > +			trace_seq_puts(s, "();");
> > +
> >  		if (print_retval || print_retaddr)
> >  			trace_seq_puts(s, " /*");
> >  		else
> > @@ -836,12 +882,13 @@ static void print_graph_retval(struct trace_seq *s, struct ftrace_graph_ent_entr
> >  	}
> >  
> >  	if (!entry || print_retval || print_retaddr)
> > -		trace_seq_puts(s, " */\n");
> > +		trace_seq_puts(s, " */");  
> 
> Do we need this change?

Hmm, maybe not. It may have been caused by added (and removed) debugging.

Thanks for the review.

-- Steve

Re: [PATCH v2 1/4] ftrace: Add print_function_args()

[Masami Hiramatsu]

On Wed, 8 Jan 2025 10:30:08 +0800
Donglin Peng <dolinux.peng@gmail.com> wrote:

> Steven Rostedt <rostedt@goodmis.org>于2024年12月24日 周二04:14写道：
> 
> > From: Sven Schnelle <svens@linux.ibm.com>
> >
> > Add a function to decode argument types with the help of BTF. Will
> > be used to display arguments in the function and function graph
> > tracer.
> >
> > It can only handle simply arguments and up to FTRACE_REGS_MAX_ARGS number
> > of arguments. When it hits a max, it will print ", ...":
> >
> >    page_to_skb(vi=0xffff8d53842dc980, rq=0xffff8d53843a0800,
> > page=0xfffffc2e04337c00, offset=6160, len=64, truesize=1536, ...)
> >
> > And if it hits an argument that is not recognized, it will print the raw
> > value and the type of argument it is:
> >
> >    make_vfsuid(idmap=0xffffffff87f99db8, fs_userns=0xffffffff87e543c0,
> > kuid=0x0 (STRUCT))
> >    __pti_set_user_pgtbl(pgdp=0xffff8d5384ab47f8, pgd=0x110e74067 (STRUCT))
> >
> > Co-developed-by: Steven Rostedt (Google) <rostedt@goodmis.org>
> > Signed-off-by: Sven Schnelle <svens@linux.ibm.com>
> > Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
> > ---
> > Changes since v1:
> > https://lore.kernel.org/20240904065908.1009086-5-svens@linux.ibm.com
> >
> >  - Added Config option FUNCTION_TRACE_ARGS to this patch
> >   (unconditional if dependencies are met)
> >
> >  - Changed the print_function_args() function to take an array of
> >    unsigned long args and not the ftrace_regs pointer. The ftrace_regs
> >    should be opaque from generic code.
> >
> >  - Have the function print the name of an BTF type that is not supported.
> >
> >  - Added FTRACE_REGS_MAX_ARGS as the number of arguments saved in
> >    the event and printed out.
> >
> >  - Print "...," if the number of arguments goes past FTRACE_REGS_MAX_ARGS.
> >
> >  include/linux/ftrace_regs.h |  5 +++
> >  kernel/trace/Kconfig        |  6 +++
> >  kernel/trace/trace_output.c | 78 +++++++++++++++++++++++++++++++++++++
> >  kernel/trace/trace_output.h |  9 +++++
> >  4 files changed, 98 insertions(+)
> >
> > diff --git a/include/linux/ftrace_regs.h b/include/linux/ftrace_regs.h
> > index bbc1873ca6b8..15627ceea9bc 100644
> > --- a/include/linux/ftrace_regs.h
> > +++ b/include/linux/ftrace_regs.h
> > @@ -35,4 +35,9 @@ struct ftrace_regs;
> >
> >  #endif /* HAVE_ARCH_FTRACE_REGS */
> >
> > +/* This can be overridden by the architectures */
> > +#ifndef FTRACE_REGS_MAX_ARGS
> > +# define FTRACE_REGS_MAX_ARGS  6
> > +#endif
> > +
> >  #endif /* _LINUX_FTRACE_REGS_H */
> > diff --git a/kernel/trace/Kconfig b/kernel/trace/Kconfig
> > index d570b8b9c0a9..60412c1012ef 100644
> > --- a/kernel/trace/Kconfig
> > +++ b/kernel/trace/Kconfig
> > @@ -263,6 +263,12 @@ config FUNCTION_GRAPH_RETADDR
> >           the function is called. This feature is off by default, and you
> > can
> >           enable it via the trace option funcgraph-retaddr.
> >
> > +config FUNCTION_TRACE_ARGS
> > +       bool
> > +       depends on HAVE_FUNCTION_ARG_ACCESS_API
> > +       depends on DEBUG_INFO_BTF
> > +       default y
> > +
> >  config DYNAMIC_FTRACE
> >         bool "enable/disable function tracing dynamically"
> >         depends on FUNCTION_TRACER
> > diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
> > index da748b7cbc4d..40d6c7a9e0c4 100644
> > --- a/kernel/trace/trace_output.c
> > +++ b/kernel/trace/trace_output.c
> > @@ -12,8 +12,11 @@
> >  #include <linux/sched/clock.h>
> >  #include <linux/sched/mm.h>
> >  #include <linux/idr.h>
> > +#include <linux/btf.h>
> > +#include <linux/bpf.h>
> >
> >  #include "trace_output.h"
> > +#include "trace_btf.h"
> >
> >  /* must be a power of 2 */
> >  #define EVENT_HASHSIZE 128
> > @@ -680,6 +683,81 @@ int trace_print_lat_context(struct trace_iterator
> > *iter)
> >         return !trace_seq_has_overflowed(s);
> >  }
> >
> > +#ifdef CONFIG_FUNCTION_TRACE_ARGS
> > +void print_function_args(struct trace_seq *s, unsigned long *args,
> > +                        unsigned long func)
> > +{
> > +       const struct btf_param *param;
> > +       const struct btf_type *t;
> > +       const char *param_name;
> > +       char name[KSYM_NAME_LEN];
> > +       unsigned long arg;
> > +       struct btf *btf;
> > +       s32 tid, nr = 0;
> > +       int i;
> > +
> > +       trace_seq_printf(s, "(");
> > +
> > +       if (!args)
> > +               goto out;
> > +       if (lookup_symbol_name(func, name))
> > +               goto out;
> > +
> > +       btf = bpf_get_btf_vmlinux();
> > +       if (IS_ERR_OR_NULL(btf))
> > +               goto out;
> 
> 
> There is no need to the retrieve the BTF of vmlinux, as btf_find_func_proto
> will return the correct BTF via its second parameter.

Good catch! The second parameter of btf_find_func_proto() is output.

Thank you,

> 
> — donglin
> 
> 
> > +
> > +       t = btf_find_func_proto(name, &btf);
> > +       if (IS_ERR_OR_NULL(t))
> > +               goto out;
> > +
> > +       param = btf_get_func_param(t, &nr);
> > +       if (!param)
> > +               goto out_put;
> > +
> > +       for (i = 0; i < nr; i++) {
> > +               /* This only prints what the arch allows (6 args by
> > default) */
> > +               if (i == FTRACE_REGS_MAX_ARGS) {
> > +                       trace_seq_puts(s, "...");
> > +                       break;
> > +               }
> > +
> > +               arg = args[i];
> > +
> > +               param_name = btf_name_by_offset(btf, param[i].name_off);
> > +               if (param_name)
> > +                       trace_seq_printf(s, "%s=", param_name);
> > +               t = btf_type_skip_modifiers(btf, param[i].type, &tid);
> > +
> > +               switch (t ? BTF_INFO_KIND(t->info) : BTF_KIND_UNKN) {
> > +               case BTF_KIND_UNKN:
> > +                       trace_seq_putc(s, '?');
> > +                       /* Still print unknown type values */
> > +                       fallthrough;
> > +               case BTF_KIND_PTR:
> > +                       trace_seq_printf(s, "0x%lx", arg);
> > +                       break;
> > +               case BTF_KIND_INT:
> > +                       trace_seq_printf(s, "%ld", arg);
> > +                       break;
> > +               case BTF_KIND_ENUM:
> > +                       trace_seq_printf(s, "%ld", arg);
> > +                       break;
> > +               default:
> > +                       /* This does not handle complex arguments */
> > +                       trace_seq_printf(s, "0x%lx (%s)", arg,
> > btf_type_str(t));
> > +                       break;
> > +               }
> > +               if (i < nr - 1)
> > +                       trace_seq_printf(s, ", ");
> > +       }
> > +out_put:
> > +       btf_put(btf);
> > +out:
> > +       trace_seq_printf(s, ")");
> > +}
> > +#endif
> > +
> >  /**
> >   * ftrace_find_event - find a registered event
> >   * @type: the type of event to look for
> > diff --git a/kernel/trace/trace_output.h b/kernel/trace/trace_output.h
> > index dca40f1f1da4..2e305364f2a9 100644
> > --- a/kernel/trace/trace_output.h
> > +++ b/kernel/trace/trace_output.h
> > @@ -41,5 +41,14 @@ extern struct rw_semaphore trace_event_sem;
> >  #define SEQ_PUT_HEX_FIELD(s, x)                                \
> >         trace_seq_putmem_hex(s, &(x), sizeof(x))
> >
> > +#ifdef CONFIG_FUNCTION_TRACE_ARGS
> > +void print_function_args(struct trace_seq *s, unsigned long *args,
> > +                        unsigned long func);
> > +#else
> > +static inline void print_function_args(struct trace_seq *s, unsigned long
> > *args,
> > +                                      unsigned long func) {
> > +       trace_seq_puts(s, "()");
> > +}
> > +#endif
> >  #endif
> >
> > --
> > 2.45.2
> >
> >
> >


-- 
Masami Hiramatsu (Google) <mhiramat@kernel.org>

Re: [PATCH v2 1/4] ftrace: Add print_function_args()

[Alan Maguire]

On 08/01/2025 04:52, Masami Hiramatsu (Google) wrote:
> On Wed, 8 Jan 2025 10:30:08 +0800
> Donglin Peng <dolinux.peng@gmail.com> wrote:
> 
>> Steven Rostedt <rostedt@goodmis.org>于2024年12月24日 周二04:14写道：
>>
>>> From: Sven Schnelle <svens@linux.ibm.com>
>>>
>>> Add a function to decode argument types with the help of BTF. Will
>>> be used to display arguments in the function and function graph
>>> tracer.
>>>
>>> It can only handle simply arguments and up to FTRACE_REGS_MAX_ARGS number
>>> of arguments. When it hits a max, it will print ", ...":
>>>
>>>    page_to_skb(vi=0xffff8d53842dc980, rq=0xffff8d53843a0800,
>>> page=0xfffffc2e04337c00, offset=6160, len=64, truesize=1536, ...)
>>>
>>> And if it hits an argument that is not recognized, it will print the raw
>>> value and the type of argument it is:
>>>
>>>    make_vfsuid(idmap=0xffffffff87f99db8, fs_userns=0xffffffff87e543c0,
>>> kuid=0x0 (STRUCT))
>>>    __pti_set_user_pgtbl(pgdp=0xffff8d5384ab47f8, pgd=0x110e74067 (STRUCT))
>>>
>>> Co-developed-by: Steven Rostedt (Google) <rostedt@goodmis.org>
>>> Signed-off-by: Sven Schnelle <svens@linux.ibm.com>
>>> Signed-off-by: Steven Rostedt (Google) <rostedt@goodmis.org>
>>> ---
>>> Changes since v1:
>>> https://lore.kernel.org/20240904065908.1009086-5-svens@linux.ibm.com
>>>
>>>  - Added Config option FUNCTION_TRACE_ARGS to this patch
>>>   (unconditional if dependencies are met)
>>>
>>>  - Changed the print_function_args() function to take an array of
>>>    unsigned long args and not the ftrace_regs pointer. The ftrace_regs
>>>    should be opaque from generic code.
>>>
>>>  - Have the function print the name of an BTF type that is not supported.
>>>
>>>  - Added FTRACE_REGS_MAX_ARGS as the number of arguments saved in
>>>    the event and printed out.
>>>
>>>  - Print "...," if the number of arguments goes past FTRACE_REGS_MAX_ARGS.
>>>
>>>  include/linux/ftrace_regs.h |  5 +++
>>>  kernel/trace/Kconfig        |  6 +++
>>>  kernel/trace/trace_output.c | 78 +++++++++++++++++++++++++++++++++++++
>>>  kernel/trace/trace_output.h |  9 +++++
>>>  4 files changed, 98 insertions(+)
>>>
>>> diff --git a/include/linux/ftrace_regs.h b/include/linux/ftrace_regs.h
>>> index bbc1873ca6b8..15627ceea9bc 100644
>>> --- a/include/linux/ftrace_regs.h
>>> +++ b/include/linux/ftrace_regs.h
>>> @@ -35,4 +35,9 @@ struct ftrace_regs;
>>>
>>>  #endif /* HAVE_ARCH_FTRACE_REGS */
>>>
>>> +/* This can be overridden by the architectures */
>>> +#ifndef FTRACE_REGS_MAX_ARGS
>>> +# define FTRACE_REGS_MAX_ARGS  6
>>> +#endif
>>> +
>>>  #endif /* _LINUX_FTRACE_REGS_H */
>>> diff --git a/kernel/trace/Kconfig b/kernel/trace/Kconfig
>>> index d570b8b9c0a9..60412c1012ef 100644
>>> --- a/kernel/trace/Kconfig
>>> +++ b/kernel/trace/Kconfig
>>> @@ -263,6 +263,12 @@ config FUNCTION_GRAPH_RETADDR
>>>           the function is called. This feature is off by default, and you
>>> can
>>>           enable it via the trace option funcgraph-retaddr.
>>>
>>> +config FUNCTION_TRACE_ARGS
>>> +       bool
>>> +       depends on HAVE_FUNCTION_ARG_ACCESS_API
>>> +       depends on DEBUG_INFO_BTF
>>> +       default y
>>> +
>>>  config DYNAMIC_FTRACE
>>>         bool "enable/disable function tracing dynamically"
>>>         depends on FUNCTION_TRACER
>>> diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
>>> index da748b7cbc4d..40d6c7a9e0c4 100644
>>> --- a/kernel/trace/trace_output.c
>>> +++ b/kernel/trace/trace_output.c
>>> @@ -12,8 +12,11 @@
>>>  #include <linux/sched/clock.h>
>>>  #include <linux/sched/mm.h>
>>>  #include <linux/idr.h>
>>> +#include <linux/btf.h>
>>> +#include <linux/bpf.h>
>>>
>>>  #include "trace_output.h"
>>> +#include "trace_btf.h"
>>>
>>>  /* must be a power of 2 */
>>>  #define EVENT_HASHSIZE 128
>>> @@ -680,6 +683,81 @@ int trace_print_lat_context(struct trace_iterator
>>> *iter)
>>>         return !trace_seq_has_overflowed(s);
>>>  }
>>>
>>> +#ifdef CONFIG_FUNCTION_TRACE_ARGS
>>> +void print_function_args(struct trace_seq *s, unsigned long *args,
>>> +                        unsigned long func)
>>> +{
>>> +       const struct btf_param *param;
>>> +       const struct btf_type *t;
>>> +       const char *param_name;
>>> +       char name[KSYM_NAME_LEN];
>>> +       unsigned long arg;
>>> +       struct btf *btf;
>>> +       s32 tid, nr = 0;
>>> +       int i;
>>> +
>>> +       trace_seq_printf(s, "(");
>>> +
>>> +       if (!args)
>>> +               goto out;
>>> +       if (lookup_symbol_name(func, name))
>>> +               goto out;
>>> +
>>> +       btf = bpf_get_btf_vmlinux();
>>> +       if (IS_ERR_OR_NULL(btf))
>>> +               goto out;
>>
>>
>> There is no need to the retrieve the BTF of vmlinux, as btf_find_func_proto
>> will return the correct BTF via its second parameter.
> 
> Good catch! The second parameter of btf_find_func_proto() is output.
>

One thought here - with btf_find_func_proto(), we will try kernel BTF
and then proceed to module BTF, iterating over all modules to find the
function prototype. So where we are tracing module functions this could
get expensive if such a function is frequently encountered, and it also
opens up the risk that we end up using the wrong function prototype from
the wrong module that just happens to match on function name.

So I wonder if we could use the function address to do a more guided
lookup. Perhaps we could use kallsyms_lookup(), retrieving the
(potential) module name. Then maybe modify the signature of
btf_find_func_proto() to take an optional module name parameter to avoid
iteration? None of this is strictly needed, but it may speed things up a
bit and give us more accurate parameter info for those few cases with
name clashes, so could be done as a follow-up if needed. Thanks!

Alan

> Thank you,
> 
>>
>> — donglin
>>
>>
>>> +
>>> +       t = btf_find_func_proto(name, &btf);
>>> +       if (IS_ERR_OR_NULL(t))
>>> +               goto out;
>>> +
>>> +       param = btf_get_func_param(t, &nr);
>>> +       if (!param)
>>> +               goto out_put;
>>> +
>>> +       for (i = 0; i < nr; i++) {
>>> +               /* This only prints what the arch allows (6 args by
>>> default) */
>>> +               if (i == FTRACE_REGS_MAX_ARGS) {
>>> +                       trace_seq_puts(s, "...");
>>> +                       break;
>>> +               }
>>> +
>>> +               arg = args[i];
>>> +
>>> +               param_name = btf_name_by_offset(btf, param[i].name_off);
>>> +               if (param_name)
>>> +                       trace_seq_printf(s, "%s=", param_name);
>>> +               t = btf_type_skip_modifiers(btf, param[i].type, &tid);
>>> +
>>> +               switch (t ? BTF_INFO_KIND(t->info) : BTF_KIND_UNKN) {
>>> +               case BTF_KIND_UNKN:
>>> +                       trace_seq_putc(s, '?');
>>> +                       /* Still print unknown type values */
>>> +                       fallthrough;
>>> +               case BTF_KIND_PTR:
>>> +                       trace_seq_printf(s, "0x%lx", arg);
>>> +                       break;
>>> +               case BTF_KIND_INT:
>>> +                       trace_seq_printf(s, "%ld", arg);
>>> +                       break;
>>> +               case BTF_KIND_ENUM:
>>> +                       trace_seq_printf(s, "%ld", arg);
>>> +                       break;
>>> +               default:
>>> +                       /* This does not handle complex arguments */
>>> +                       trace_seq_printf(s, "0x%lx (%s)", arg,
>>> btf_type_str(t));
>>> +                       break;
>>> +               }
>>> +               if (i < nr - 1)
>>> +                       trace_seq_printf(s, ", ");
>>> +       }
>>> +out_put:
>>> +       btf_put(btf);
>>> +out:
>>> +       trace_seq_printf(s, ")");
>>> +}
>>> +#endif
>>> +
>>>  /**
>>>   * ftrace_find_event - find a registered event
>>>   * @type: the type of event to look for
>>> diff --git a/kernel/trace/trace_output.h b/kernel/trace/trace_output.h
>>> index dca40f1f1da4..2e305364f2a9 100644
>>> --- a/kernel/trace/trace_output.h
>>> +++ b/kernel/trace/trace_output.h
>>> @@ -41,5 +41,14 @@ extern struct rw_semaphore trace_event_sem;
>>>  #define SEQ_PUT_HEX_FIELD(s, x)                                \
>>>         trace_seq_putmem_hex(s, &(x), sizeof(x))
>>>
>>> +#ifdef CONFIG_FUNCTION_TRACE_ARGS
>>> +void print_function_args(struct trace_seq *s, unsigned long *args,
>>> +                        unsigned long func);
>>> +#else
>>> +static inline void print_function_args(struct trace_seq *s, unsigned long
>>> *args,
>>> +                                      unsigned long func) {
>>> +       trace_seq_puts(s, "()");
>>> +}
>>> +#endif
>>>  #endif
>>>
>>> --
>>> 2.45.2
>>>
>>>
>>>
> 
> 

Re: [PATCH v2 1/4] ftrace: Add print_function_args()

[Steven Rostedt]

On Wed, 8 Jan 2025 11:19:11 +0000
Alan Maguire <alan.maguire@oracle.com> wrote:

> >>> +       trace_seq_printf(s, "(");
> >>> +
> >>> +       if (!args)
> >>> +               goto out;
> >>> +       if (lookup_symbol_name(func, name))
> >>> +               goto out;
> >>> +
> >>> +       btf = bpf_get_btf_vmlinux();
> >>> +       if (IS_ERR_OR_NULL(btf))
> >>> +               goto out;  
> >>
> >>
> >> There is no need to the retrieve the BTF of vmlinux, as btf_find_func_proto
> >> will return the correct BTF via its second parameter.  
> > 
> > Good catch! The second parameter of btf_find_func_proto() is output.
> >  
> 
> One thought here - with btf_find_func_proto(), we will try kernel BTF
> and then proceed to module BTF, iterating over all modules to find the
> function prototype. So where we are tracing module functions this could
> get expensive if such a function is frequently encountered, and it also
> opens up the risk that we end up using the wrong function prototype from
> the wrong module that just happens to match on function name.
> 
> So I wonder if we could use the function address to do a more guided
> lookup. Perhaps we could use kallsyms_lookup(), retrieving the
> (potential) module name. Then maybe modify the signature of
> btf_find_func_proto() to take an optional module name parameter to avoid
> iteration? None of this is strictly needed, but it may speed things up a
> bit and give us more accurate parameter info for those few cases with
> name clashes, so could be done as a follow-up if needed. Thanks!

Well, every place this is called, we first get the function name from
kallsyms. Perhaps I can modify the code to get the module name as well, and
if it exists, we can pass that too?

-- Steve

Re: [PATCH v2 1/4] ftrace: Add print_function_args()

[Alan Maguire]

On 08/01/2025 15:24, Steven Rostedt wrote:
> On Wed, 8 Jan 2025 11:19:11 +0000
> Alan Maguire <alan.maguire@oracle.com> wrote:
> 
>>>>> +       trace_seq_printf(s, "(");
>>>>> +
>>>>> +       if (!args)
>>>>> +               goto out;
>>>>> +       if (lookup_symbol_name(func, name))
>>>>> +               goto out;
>>>>> +
>>>>> +       btf = bpf_get_btf_vmlinux();
>>>>> +       if (IS_ERR_OR_NULL(btf))
>>>>> +               goto out;  
>>>>
>>>>
>>>> There is no need to the retrieve the BTF of vmlinux, as btf_find_func_proto
>>>> will return the correct BTF via its second parameter.  
>>>
>>> Good catch! The second parameter of btf_find_func_proto() is output.
>>>  
>>
>> One thought here - with btf_find_func_proto(), we will try kernel BTF
>> and then proceed to module BTF, iterating over all modules to find the
>> function prototype. So where we are tracing module functions this could
>> get expensive if such a function is frequently encountered, and it also
>> opens up the risk that we end up using the wrong function prototype from
>> the wrong module that just happens to match on function name.
>>
>> So I wonder if we could use the function address to do a more guided
>> lookup. Perhaps we could use kallsyms_lookup(), retrieving the
>> (potential) module name. Then maybe modify the signature of
>> btf_find_func_proto() to take an optional module name parameter to avoid
>> iteration? None of this is strictly needed, but it may speed things up a
>> bit and give us more accurate parameter info for those few cases with
>> name clashes, so could be done as a follow-up if needed. Thanks!
> 
> Well, every place this is called, we first get the function name from
> kallsyms. Perhaps I can modify the code to get the module name as well, and
> if it exists, we can pass that too?
>

yep, that would be great! One thing we should probably think about for
the future is ways to stash module/BTF ids such that we don't need
lookup each time, but I can't see any obvious way to do that currently.


> -- Steve