linux-riscv.lists.infradead.org archive mirror
 help / color / mirror / Atom feed
* [PATCH v10 0/8] function_graph: Support recording and printing the return value of function
@ 2023-03-31 12:47 Donglin Peng
  2023-03-31 12:47 ` [PATCH v10 1/8] " Donglin Peng
                   ` (7 more replies)
  0 siblings, 8 replies; 19+ messages in thread
From: Donglin Peng @ 2023-03-31 12:47 UTC (permalink / raw)
  To: mhiramat, rostedt, linux, mark.rutland, will, catalin.marinas,
	rmk+kernel, palmer, paul.walmsley, aou, tglx, dave.hansen, x86,
	bp, hpa, chenhuacai, zhangqing, kernel, mingo, peterz, xiehuan09,
	dinghui, huangcun, dolinux.peng
  Cc: linux-trace-kernel, loongarch, linux-riscv, linux-arm-kernel,
	linux-kernel, Donglin Peng

When using the function_graph tracer to analyze system call failures,
it can be time-consuming to analyze the trace logs and locate the kernel
function that first returns an error. This change aims to simplify the
process by recording the function return value to the 'retval' member of
'ftrace_graph_ent' and printing it when outputing the trace log.

Note that even if a function's return type is void, a return value will
still be printed, so it should be ignored. If you care about this, the
BTF file can be used to obtain the details of function return type. We
can implement a tool to process the trace log and display the return
value based on its actual type.

Here is an example:

...

 1)               |  cgroup_attach_task() {
 1)               |    cgroup_migrate_add_src() {
 1)   1.403 us    |      cset_cgroup_from_root(); /* = 0xffff93fc86f58010 */
 1)   2.154 us    |    } /* cgroup_migrate_add_src = 0xffffb286c1297d00 */
 1) ! 386.538 us  |    cgroup_migrate_prepare_dst(); /* = 0x0 */
 1)               |    cgroup_migrate() {
 1)   0.651 us    |      cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
 1)               |      cgroup_migrate_execute() {
 1)               |        cpu_cgroup_can_attach() {
 1)               |          cgroup_taskset_first() {
 1)   0.732 us    |            cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
 1)   1.232 us    |          } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
 1)   0.380 us    |          sched_rt_can_attach(); /* = 0x0 */
 1)   2.335 us    |        } /* cpu_cgroup_can_attach = -22 */
 1)   4.369 us    |      } /* cgroup_migrate_execute = -22 */
 1)   7.143 us    |    } /* cgroup_migrate = -22 */
 1)               |    cgroup_migrate_finish() {
 1)   0.411 us    |      put_css_set_locked(); /* = 0x8 */
 1) + 62.397 us   |      put_css_set_locked(); /* = 0x80000001 */
 1) + 64.742 us   |    } /* cgroup_migrate_finish = 0x80000000 */
 1) ! 465.605 us  |  } /* cgroup_attach_task = -22 */

...

After processing the above trace logs using BTF information:

...

 1)               |  cgroup_attach_task() {
 1)               |    cgroup_migrate_add_src() {
 1)   1.403 us    |      cset_cgroup_from_root(); /* = 0xffff93fc86f58010 */
 1)   2.154 us    |    } /* cgroup_migrate_add_src */
 1) ! 386.538 us  |    cgroup_migrate_prepare_dst(); /* = 0 */
 1)               |    cgroup_migrate() {
 1)   0.651 us    |      cgroup_migrate_add_task();
 1)               |      cgroup_migrate_execute() {
 1)               |        cpu_cgroup_can_attach() {
 1)               |          cgroup_taskset_first() {
 1)   0.732 us    |            cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
 1)   1.232 us    |          } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
 1)   0.380 us    |          sched_rt_can_attach(); /* = 0 */
 1)   2.335 us    |        } /* cpu_cgroup_can_attach = -22 */
 1)   4.369 us    |      } /* cgroup_migrate_execute = -22 */
 1)   7.143 us    |    } /* cgroup_migrate = -22 */
 1)               |    cgroup_migrate_finish() {
 1)   0.411 us    |      put_css_set_locked();
 1) + 62.397 us   |      put_css_set_locked();
 1) + 64.742 us   |    } /* cgroup_migrate_finish */
 1) ! 465.605 us  |  } /* cgroup_attach_task = -22 */

...

---
v10:
 - Fix code style issues for LoongArch
 - Fix selftest issues
 - Use CONFIG_FUNCTION_GRAPH_TRACER to control fgraph_ret_regs definition

v9:
 - Fix align issues in ARM asm code
 - Fix align issues in LoongArch asm code
 - Update commit messages
 - Update comments for ftrace_return_to_handler

v8:
 - Fix issues in ARM64 asm code
 - Fix issues in selftest
 - Add some comments on CONFIG_HAVE_FUNCTION_GRAPH_RETVAL
 - Make CONFIG_FUNCTION_GRAPH_RETVAL switable
 - Modify the control range of CONFIG_HAVE_FUNCTION_GRAPH_RETVAL

v7:
 - Rename trace option 'graph_retval_hex' to 'funcgraph-retval-hex'
 - Introduce a new structure fgraph_ret_regs for each architecture to
   hold return registers
 - Separate each architecture modification info individual patches
 - Add a test case for funcgraph-retval
 - Update documentation description
 - Support LoongArch

v6:
 - Remove the conversion code for short and char types, because these
   two types are rarely used to store an error code.
 - Modify the limitations for funcgraph-retval
 - Optimize the English expression

v5:
 - Pass both the return values to ftrace_return_to_handler
 - Modify the parameter sequence of ftrace_return_to_handler to
   decrease the modification of assembly code, thanks to Russell King
 - Wrap __ftrace_return_to_handler with ftrace_return_to_handler
   for compatible
 - Describe the limitations of funcgraph-retval

v4:
 - Modify commit message
 - Introduce new option graph_retval_hex to control display format
 - Introduce macro CONFIG_FUNCTION_GRAPH_RETVAL and
   CONFIG_HAVE_FUNCTION_GRAPH_RETVAL
 - Add related arch maintainers to review

v3:
 - Modify the commit message: add trace logs processed with the btf tool

v2:
 - Modify the commit message: use BTF to get the return type of function

Donglin Peng (8):
  function_graph: Support recording and printing the return value of
    function
  tracing: Add documentation for funcgraph-retval and
    funcgraph-retval-hex
  ARM: ftrace: Enable HAVE_FUNCTION_GRAPH_RETVAL
  arm64: ftrace: Enable HAVE_FUNCTION_GRAPH_RETVAL
  riscv: ftrace: Enable HAVE_FUNCTION_GRAPH_RETVAL
  x86/ftrace: Enable HAVE_FUNCTION_GRAPH_RETVAL
  LoongArch: ftrace: Enable HAVE_FUNCTION_GRAPH_RETVAL
  selftests/ftrace: Add funcgraph-retval test case

 Documentation/trace/ftrace.rst                | 74 +++++++++++++++
 arch/arm/Kconfig                              |  1 +
 arch/arm/include/asm/ftrace.h                 | 22 +++++
 arch/arm/kernel/asm-offsets.c                 |  8 +-
 arch/arm/kernel/entry-ftrace.S                | 10 +-
 arch/arm64/Kconfig                            |  1 +
 arch/arm64/include/asm/ftrace.h               | 22 +++++
 arch/arm64/kernel/asm-offsets.c               | 13 +++
 arch/arm64/kernel/entry-ftrace.S              | 27 +++---
 arch/loongarch/Kconfig                        |  1 +
 arch/loongarch/include/asm/ftrace.h           | 22 +++++
 arch/loongarch/kernel/asm-offsets.c           | 15 ++-
 arch/loongarch/kernel/mcount.S                | 14 +--
 arch/loongarch/kernel/mcount_dyn.S            | 15 +--
 arch/riscv/Kconfig                            |  1 +
 arch/riscv/include/asm/ftrace.h               | 21 +++++
 arch/riscv/kernel/mcount.S                    |  7 +-
 arch/x86/Kconfig                              |  1 +
 arch/x86/include/asm/ftrace.h                 | 20 ++++
 arch/x86/kernel/ftrace_32.S                   |  8 +-
 arch/x86/kernel/ftrace_64.S                   |  7 +-
 include/linux/ftrace.h                        |  3 +
 kernel/trace/Kconfig                          | 15 +++
 kernel/trace/fgraph.c                         | 23 ++++-
 kernel/trace/trace.h                          |  2 +
 kernel/trace/trace_entries.h                  | 26 ++++++
 kernel/trace/trace_functions_graph.c          | 93 +++++++++++++++++--
 .../ftrace/test.d/ftrace/fgraph-retval.tc     | 43 +++++++++
 28 files changed, 460 insertions(+), 55 deletions(-)
 create mode 100644 tools/testing/selftests/ftrace/test.d/ftrace/fgraph-retval.tc

-- 
2.25.1


_______________________________________________
linux-riscv mailing list
linux-riscv@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-riscv

^ permalink raw reply	[flat|nested] 19+ messages in thread

* [PATCH v10 1/8] function_graph: Support recording and printing the return value of function
  2023-03-31 12:47 [PATCH v10 0/8] function_graph: Support recording and printing the return value of function Donglin Peng
@ 2023-03-31 12:47 ` Donglin Peng
  2023-03-31 12:47 ` [PATCH v10 2/8] tracing: Add documentation for funcgraph-retval and funcgraph-retval-hex Donglin Peng
                   ` (6 subsequent siblings)
  7 siblings, 0 replies; 19+ messages in thread
From: Donglin Peng @ 2023-03-31 12:47 UTC (permalink / raw)
  To: mhiramat, rostedt, linux, mark.rutland, will, catalin.marinas,
	rmk+kernel, palmer, paul.walmsley, aou, tglx, dave.hansen, x86,
	bp, hpa, chenhuacai, zhangqing, kernel, mingo, peterz, xiehuan09,
	dinghui, huangcun, dolinux.peng
  Cc: linux-trace-kernel, loongarch, linux-riscv, linux-arm-kernel,
	linux-kernel, Donglin Peng, Florian Kauer

Analyzing system call failures with the function_graph tracer can be a
time-consuming process, particularly when locating the kernel function
that first returns an error in the trace logs. This change aims to
simplify the process by recording the function return value to the
'retval' member of 'ftrace_graph_ent' and printing it when outputting
the trace log.

We have introduced new trace options: funcgraph-retval and
funcgraph-retval-hex. The former controls whether to display the return
value, while the latter controls the display format.

Please note that even if a function's return type is void, a return
value will still be printed. You can simply ignore it.

This patch only establishes the fundamental infrastructure. Subsequent
patches will make this feature available on some commonly used processor
architectures.

Here is an example:

I attempted to attach the demo process to a cpu cgroup, but it failed:

echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
-bash: echo: write error: Invalid argument

The strace logs indicate that the write system call returned -EINVAL(-22):
...
write(1, "273\n", 4)                    = -1 EINVAL (Invalid argument)
...

To capture trace logs during a write system call, use the following
commands:

cd /sys/kernel/debug/tracing/
echo 0 > tracing_on
echo > trace
echo *sys_write > set_graph_function
echo *spin* > set_graph_notrace
echo *rcu* >> set_graph_notrace
echo *alloc* >> set_graph_notrace
echo preempt* >> set_graph_notrace
echo kfree* >> set_graph_notrace
echo $$ > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval
echo 0 > options/funcgraph-retval-hex
echo 1 > tracing_on
echo `pidof demo` > /sys/fs/cgroup/cpu/test/tasks
echo 0 > tracing_on
cat trace > ~/trace.log

To locate the root cause, search for error code -22 directly in the file
trace.log and identify the first function that returned -22. Once you
have identified this function, examine its code to determine the root
cause.

For example, in the trace log below, cpu_cgroup_can_attach
returned -22 first, so we can focus our analysis on this function to
identify the root cause.

...

 1)          | cgroup_migrate() {
 1) 0.651 us |   cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
 1)          |   cgroup_migrate_execute() {
 1)          |     cpu_cgroup_can_attach() {
 1)          |       cgroup_taskset_first() {
 1) 0.732 us |         cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
 1) 1.232 us |       } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
 1) 0.380 us |       sched_rt_can_attach(); /* = 0x0 */
 1) 2.335 us |     } /* cpu_cgroup_can_attach = -22 */
 1) 4.369 us |   } /* cgroup_migrate_execute = -22 */
 1) 7.143 us | } /* cgroup_migrate = -22 */

...

Tested-by: Florian Kauer <florian.kauer@linutronix.de>
Acked-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
---
v9:
 - Update comments for ftrace_return_to_handler

v8:
 - Add some comments on CONFIG_HAVE_FUNCTION_GRAPH_RETVAL
 - Make CONFIG_FUNCTION_GRAPH_RETVAL switable

v7:
 - Rename trace option 'graph_retval_hex' to 'funcgraph-retval-hex'
 - Separate each architecture modification info individual patches
 - Introduce a new structure fgraph_ret_regs for each architecture to
   hold return registers

v6:
 - Remove the conversion code for short and char types, because these
   two types are rarely used to store an error code.

v5:
 - Pass both the return values to ftrace_return_to_handler
 - Modify the parameter sequence of ftrace_return_to_handler to
   decrease the modification of assembly code, thanks to Russell King
 - Wrap __ftrace_return_to_handler with ftrace_return_to_handler
   for compatible

v4:
 - Modify commit message
 - Introduce new option graph_retval_hex to control display format
 - Introduce macro CONFIG_FUNCTION_GRAPH_RETVAL and
   CONFIG_HAVE_FUNCTION_GRAPH_RETVAL
 - Add related arch maintainers to review

v3:
 - Modify the commit message: add trace logs processed with the btf tool

v2:
 - Modify the commit message: use BTF to get the return type of function
---
 include/linux/ftrace.h               |  3 +
 kernel/trace/Kconfig                 | 15 +++++
 kernel/trace/fgraph.c                | 23 ++++++-
 kernel/trace/trace.h                 |  2 +
 kernel/trace/trace_entries.h         | 26 ++++++++
 kernel/trace/trace_functions_graph.c | 93 +++++++++++++++++++++++++---
 6 files changed, 151 insertions(+), 11 deletions(-)

diff --git a/include/linux/ftrace.h b/include/linux/ftrace.h
index 366c730beaa3..be662a11cd13 100644
--- a/include/linux/ftrace.h
+++ b/include/linux/ftrace.h
@@ -1032,6 +1032,9 @@ struct ftrace_graph_ent {
  */
 struct ftrace_graph_ret {
 	unsigned long func; /* Current function */
+#ifdef CONFIG_FUNCTION_GRAPH_RETVAL
+	unsigned long retval;
+#endif
 	int depth;
 	/* Number of functions that overran the depth limit for current task */
 	unsigned int overrun;
diff --git a/kernel/trace/Kconfig b/kernel/trace/Kconfig
index a856d4a34c67..87de5964c81d 100644
--- a/kernel/trace/Kconfig
+++ b/kernel/trace/Kconfig
@@ -31,6 +31,9 @@ config HAVE_FUNCTION_GRAPH_TRACER
 	help
 	  See Documentation/trace/ftrace-design.rst
 
+config HAVE_FUNCTION_GRAPH_RETVAL
+	bool
+
 config HAVE_DYNAMIC_FTRACE
 	bool
 	help
@@ -227,6 +230,18 @@ config FUNCTION_GRAPH_TRACER
 	  the return value. This is done by setting the current return
 	  address on the current task structure into a stack of calls.
 
+config FUNCTION_GRAPH_RETVAL
+	bool "Function Graph Return Value"
+	depends on HAVE_FUNCTION_GRAPH_RETVAL
+	depends on FUNCTION_GRAPH_TRACER
+	default n
+	help
+	  Support recording and printing the function return value when
+	  using function graph tracer. It can be helpful to locate functions
+	  that return errors. This feature is off by default, and you can
+	  enable it via the trace option funcgraph-retval.
+	  See Documentation/trace/ftrace.rst
+
 config DYNAMIC_FTRACE
 	bool "enable/disable function tracing dynamically"
 	depends on FUNCTION_TRACER
diff --git a/kernel/trace/fgraph.c b/kernel/trace/fgraph.c
index 218cd95bf8e4..170ec9429efb 100644
--- a/kernel/trace/fgraph.c
+++ b/kernel/trace/fgraph.c
@@ -240,12 +240,16 @@ static struct notifier_block ftrace_suspend_notifier = {
  * Send the trace to the ring-buffer.
  * @return the original return address.
  */
-unsigned long ftrace_return_to_handler(unsigned long frame_pointer)
+static unsigned long __ftrace_return_to_handler(struct fgraph_ret_regs *ret_regs,
+						unsigned long frame_pointer)
 {
 	struct ftrace_graph_ret trace;
 	unsigned long ret;
 
 	ftrace_pop_return_trace(&trace, &ret, frame_pointer);
+#ifdef CONFIG_FUNCTION_GRAPH_RETVAL
+	trace.retval = fgraph_ret_regs_return_value(ret_regs);
+#endif
 	trace.rettime = trace_clock_local();
 	ftrace_graph_return(&trace);
 	/*
@@ -266,6 +270,23 @@ unsigned long ftrace_return_to_handler(unsigned long frame_pointer)
 	return ret;
 }
 
+/*
+ * After all architecures have selected HAVE_FUNCTION_GRAPH_RETVAL, we can
+ * leave only ftrace_return_to_handler(ret_regs).
+ */
+#ifdef CONFIG_HAVE_FUNCTION_GRAPH_RETVAL
+unsigned long ftrace_return_to_handler(struct fgraph_ret_regs *ret_regs)
+{
+	return __ftrace_return_to_handler(ret_regs,
+				fgraph_ret_regs_frame_pointer(ret_regs));
+}
+#else
+unsigned long ftrace_return_to_handler(unsigned long frame_pointer)
+{
+	return __ftrace_return_to_handler(NULL, frame_pointer);
+}
+#endif
+
 /**
  * ftrace_graph_get_ret_stack - return the entry of the shadow stack
  * @task: The task to read the shadow stack from
diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index 616e1aa1c4da..0a3c4582df10 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -831,6 +831,8 @@ static __always_inline bool ftrace_hash_empty(struct ftrace_hash *hash)
 #define TRACE_GRAPH_PRINT_TAIL          0x100
 #define TRACE_GRAPH_SLEEP_TIME          0x200
 #define TRACE_GRAPH_GRAPH_TIME          0x400
+#define TRACE_GRAPH_PRINT_RETVAL        0x800
+#define TRACE_GRAPH_PRINT_RETVAL_HEX    0x1000
 #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 cd41e863b51c..340b2fa98218 100644
--- a/kernel/trace/trace_entries.h
+++ b/kernel/trace/trace_entries.h
@@ -86,6 +86,30 @@ FTRACE_ENTRY_PACKED(funcgraph_entry, ftrace_graph_ent_entry,
 );
 
 /* Function return entry */
+#ifdef CONFIG_FUNCTION_GRAPH_RETVAL
+
+FTRACE_ENTRY_PACKED(funcgraph_exit, ftrace_graph_ret_entry,
+
+	TRACE_GRAPH_RET,
+
+	F_STRUCT(
+		__field_struct(	struct ftrace_graph_ret,	ret	)
+		__field_packed(	unsigned long,	ret,		func	)
+		__field_packed(	unsigned long,	ret,		retval	)
+		__field_packed(	int,		ret,		depth	)
+		__field_packed(	unsigned int,	ret,		overrun	)
+		__field_packed(	unsigned long long, ret,	calltime)
+		__field_packed(	unsigned long long, ret,	rettime	)
+	),
+
+	F_printk("<-- %ps (%d) (start: %llx  end: %llx) over: %d retval: %lx",
+		 (void *)__entry->func, __entry->depth,
+		 __entry->calltime, __entry->rettime,
+		 __entry->depth, __entry->retval)
+);
+
+#else
+
 FTRACE_ENTRY_PACKED(funcgraph_exit, ftrace_graph_ret_entry,
 
 	TRACE_GRAPH_RET,
@@ -105,6 +129,8 @@ FTRACE_ENTRY_PACKED(funcgraph_exit, ftrace_graph_ret_entry,
 		 __entry->depth)
 );
 
+#endif
+
 /*
  * Context switch trace entry - which task (and prio) we switched from/to:
  *
diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
index 203204cadf92..c35fbaab2a47 100644
--- a/kernel/trace/trace_functions_graph.c
+++ b/kernel/trace/trace_functions_graph.c
@@ -58,6 +58,12 @@ static struct tracer_opt trace_opts[] = {
 	{ TRACER_OPT(funcgraph-irqs, TRACE_GRAPH_PRINT_IRQS) },
 	/* Display function name after trailing } */
 	{ TRACER_OPT(funcgraph-tail, TRACE_GRAPH_PRINT_TAIL) },
+#ifdef CONFIG_FUNCTION_GRAPH_RETVAL
+	/* Display function return value ? */
+	{ TRACER_OPT(funcgraph-retval, TRACE_GRAPH_PRINT_RETVAL) },
+	/* Display function return value in hexadecimal format ? */
+	{ TRACER_OPT(funcgraph-retval-hex, TRACE_GRAPH_PRINT_RETVAL_HEX) },
+#endif
 	/* Include sleep time (scheduled out) between entry and return */
 	{ TRACER_OPT(sleep-time, TRACE_GRAPH_SLEEP_TIME) },
 
@@ -619,6 +625,56 @@ print_graph_duration(struct trace_array *tr, unsigned long long duration,
 	trace_seq_puts(s, "|  ");
 }
 
+#ifdef CONFIG_FUNCTION_GRAPH_RETVAL
+
+#define __TRACE_GRAPH_PRINT_RETVAL TRACE_GRAPH_PRINT_RETVAL
+
+static void print_graph_retval(struct trace_seq *s, unsigned long retval,
+				bool leaf, void *func, bool hex_format)
+{
+	unsigned long err_code = 0;
+
+	if (retval == 0 || hex_format)
+		goto done;
+
+	/* Check if the return value matches the negative format */
+	if (IS_ENABLED(CONFIG_64BIT) && (retval & BIT(31)) &&
+		(((u64)retval) >> 32) == 0) {
+		/* sign extension */
+		err_code = (unsigned long)(s32)retval;
+	} else {
+		err_code = retval;
+	}
+
+	if (!IS_ERR_VALUE(err_code))
+		err_code = 0;
+
+done:
+	if (leaf) {
+		if (hex_format || (err_code == 0))
+			trace_seq_printf(s, "%ps(); /* = 0x%lx */\n",
+					func, retval);
+		else
+			trace_seq_printf(s, "%ps(); /* = %ld */\n",
+					func, err_code);
+	} else {
+		if (hex_format || (err_code == 0))
+			trace_seq_printf(s, "} /* %ps = 0x%lx */\n",
+					func, retval);
+		else
+			trace_seq_printf(s, "} /* %ps = %ld */\n",
+					func, err_code);
+	}
+}
+
+#else
+
+#define __TRACE_GRAPH_PRINT_RETVAL 0
+
+#define print_graph_retval(_seq, _retval, _leaf, _func, _format) do {} while (0)
+
+#endif
+
 /* Case of a leaf function on its call entry */
 static enum print_line_t
 print_graph_entry_leaf(struct trace_iterator *iter,
@@ -663,7 +719,15 @@ print_graph_entry_leaf(struct trace_iterator *iter,
 	for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++)
 		trace_seq_putc(s, ' ');
 
-	trace_seq_printf(s, "%ps();\n", (void *)call->func);
+	/*
+	 * Write out the function return value if the option function-retval is
+	 * enabled.
+	 */
+	if (flags & __TRACE_GRAPH_PRINT_RETVAL)
+		print_graph_retval(s, graph_ret->retval, true, (void *)call->func,
+				!!(flags & TRACE_GRAPH_PRINT_RETVAL_HEX));
+	else
+		trace_seq_printf(s, "%ps();\n", (void *)call->func);
 
 	print_graph_irq(iter, graph_ret->func, TRACE_GRAPH_RET,
 			cpu, iter->ent->pid, flags);
@@ -942,16 +1006,25 @@ print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s,
 		trace_seq_putc(s, ' ');
 
 	/*
-	 * If the return function does not have a matching entry,
-	 * then the entry was lost. Instead of just printing
-	 * the '}' and letting the user guess what function this
-	 * belongs to, write out the function name. Always do
-	 * that if the funcgraph-tail option is enabled.
+	 * Always write out the function name and its return value if the
+	 * function-retval option is enabled.
 	 */
-	if (func_match && !(flags & TRACE_GRAPH_PRINT_TAIL))
-		trace_seq_puts(s, "}\n");
-	else
-		trace_seq_printf(s, "} /* %ps */\n", (void *)trace->func);
+	if (flags & __TRACE_GRAPH_PRINT_RETVAL) {
+		print_graph_retval(s, trace->retval, false, (void *)trace->func,
+			!!(flags & TRACE_GRAPH_PRINT_RETVAL_HEX));
+	} else {
+		/*
+		 * If the return function does not have a matching entry,
+		 * then the entry was lost. Instead of just printing
+		 * the '}' and letting the user guess what function this
+		 * belongs to, write out the function name. Always do
+		 * that if the funcgraph-tail option is enabled.
+		 */
+		if (func_match && !(flags & TRACE_GRAPH_PRINT_TAIL))
+			trace_seq_puts(s, "}\n");
+		else
+			trace_seq_printf(s, "} /* %ps */\n", (void *)trace->func);
+	}
 
 	/* Overrun */
 	if (flags & TRACE_GRAPH_PRINT_OVERRUN)
-- 
2.25.1


_______________________________________________
linux-riscv mailing list
linux-riscv@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-riscv

^ permalink raw reply related	[flat|nested] 19+ messages in thread

* [PATCH v10 2/8] tracing: Add documentation for funcgraph-retval and funcgraph-retval-hex
  2023-03-31 12:47 [PATCH v10 0/8] function_graph: Support recording and printing the return value of function Donglin Peng
  2023-03-31 12:47 ` [PATCH v10 1/8] " Donglin Peng
@ 2023-03-31 12:47 ` Donglin Peng
  2023-04-01 22:17   ` Masami Hiramatsu
  2023-04-03  8:30   ` Mark Rutland
  2023-03-31 12:47 ` [PATCH v10 3/8] ARM: ftrace: Enable HAVE_FUNCTION_GRAPH_RETVAL Donglin Peng
                   ` (5 subsequent siblings)
  7 siblings, 2 replies; 19+ messages in thread
From: Donglin Peng @ 2023-03-31 12:47 UTC (permalink / raw)
  To: mhiramat, rostedt, linux, mark.rutland, will, catalin.marinas,
	rmk+kernel, palmer, paul.walmsley, aou, tglx, dave.hansen, x86,
	bp, hpa, chenhuacai, zhangqing, kernel, mingo, peterz, xiehuan09,
	dinghui, huangcun, dolinux.peng
  Cc: linux-trace-kernel, loongarch, linux-riscv, linux-arm-kernel,
	linux-kernel, Donglin Peng

Add documentation for the two newly introduced options for the
function_graph tracer. The funcgraph-retval option is used to
control whether or not to display the return value, while the
funcgraph-retval-hex option is used to control the display
format of the return value.

Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
---
v9:
 - Update limitation description

v7:
 - Rename trace option 'graph_retval_hex' to 'funcgraph-retval-hex'
 - Update documentation description

v6:
 - Modify the limitations for funcgraph-retval
 - Optimize the English expression

v5:
 - Describe the limitations of funcgraph-retval
---
 Documentation/trace/ftrace.rst | 74 ++++++++++++++++++++++++++++++++++
 1 file changed, 74 insertions(+)

diff --git a/Documentation/trace/ftrace.rst b/Documentation/trace/ftrace.rst
index b927fb2b94dc..f572ae419219 100644
--- a/Documentation/trace/ftrace.rst
+++ b/Documentation/trace/ftrace.rst
@@ -1328,6 +1328,19 @@ Options for function_graph tracer:
 	only a closing curly bracket "}" is displayed for
 	the return of a function.
 
+  funcgraph-retval
+	When set, the return value of each traced function
+	will be printed after an equal sign "=". By default
+	this is off.
+
+  funcgraph-retval-hex
+	When set, the return value will always be printed
+	in hexadecimal format. If the option is not set and
+	the return value is an error code, it will be printed
+	in signed decimal format; otherwise it will also be
+	printed in hexadecimal format. By default, this option
+	is off.
+
   sleep-time
 	When running function graph tracer, to include
 	the time a task schedules out in its function.
@@ -2673,6 +2686,67 @@ It is default disabled.
     0)   1.757 us    |        } /* kmem_cache_free() */
     0)   2.861 us    |      } /* putname() */
 
+The return value of each traced function can be displayed after
+an equal sign "=". When encountering system call failures, it
+can be verfy helpful to quickly locate the function that first
+returns an error code.
+
+	- hide: echo nofuncgraph-retval > trace_options
+	- show: echo funcgraph-retval > trace_options
+
+  Example with funcgraph-retval::
+
+    1)               |    cgroup_migrate() {
+    1)   0.651 us    |      cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
+    1)               |      cgroup_migrate_execute() {
+    1)               |        cpu_cgroup_can_attach() {
+    1)               |          cgroup_taskset_first() {
+    1)   0.732 us    |            cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
+    1)   1.232 us    |          } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
+    1)   0.380 us    |          sched_rt_can_attach(); /* = 0x0 */
+    1)   2.335 us    |        } /* cpu_cgroup_can_attach = -22 */
+    1)   4.369 us    |      } /* cgroup_migrate_execute = -22 */
+    1)   7.143 us    |    } /* cgroup_migrate = -22 */
+
+The above example shows that the function cpu_cgroup_can_attach
+returned the error code -22 firstly, then we can read the code
+of this function to get the root cause.
+
+When the option funcgraph-retval-hex is not set, the return value can
+be displayed in a smart way. Specifically, if it is an error code,
+it will be printed in signed decimal format, otherwise it will
+printed in hexadecimal format.
+
+	- smart: echo nofuncgraph-retval-hex > trace_options
+	- hexadecimal always: echo funcgraph-retval-hex > trace_options
+
+  Example with funcgraph-retval-hex::
+
+    1)               |      cgroup_migrate() {
+    1)   0.651 us    |        cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
+    1)               |        cgroup_migrate_execute() {
+    1)               |          cpu_cgroup_can_attach() {
+    1)               |            cgroup_taskset_first() {
+    1)   0.732 us    |              cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
+    1)   1.232 us    |            } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
+    1)   0.380 us    |            sched_rt_can_attach(); /* = 0x0 */
+    1)   2.335 us    |          } /* cpu_cgroup_can_attach = 0xffffffea */
+    1)   4.369 us    |        } /* cgroup_migrate_execute = 0xffffffea */
+    1)   7.143 us    |      } /* cgroup_migrate = 0xffffffea */
+
+At present, there are some limitations when using the funcgraph-retval
+option, and these limitations will be eliminated in the future:
+
+- Even if the function return type is void, a return value will still
+  be printed, and you can just ignore it.
+
+- Even if return values are stored in multiple registers, only the
+  value contained in the first register will be recorded and printed.
+  To illustrate, in the x86 architecture, eax and edx are used to store
+  a 64-bit return value, with the lower 32 bits saved in eax and the
+  upper 32 bits saved in edx. However, only the value stored in eax
+  will be recorded and printed.
+
 You can put some comments on specific functions by using
 trace_printk() For example, if you want to put a comment inside
 the __might_sleep() function, you just have to include
-- 
2.25.1


_______________________________________________
linux-riscv mailing list
linux-riscv@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-riscv

^ permalink raw reply related	[flat|nested] 19+ messages in thread

* [PATCH v10 3/8] ARM: ftrace: Enable HAVE_FUNCTION_GRAPH_RETVAL
  2023-03-31 12:47 [PATCH v10 0/8] function_graph: Support recording and printing the return value of function Donglin Peng
  2023-03-31 12:47 ` [PATCH v10 1/8] " Donglin Peng
  2023-03-31 12:47 ` [PATCH v10 2/8] tracing: Add documentation for funcgraph-retval and funcgraph-retval-hex Donglin Peng
@ 2023-03-31 12:47 ` Donglin Peng
  2023-03-31 12:47 ` [PATCH v10 4/8] arm64: " Donglin Peng
                   ` (4 subsequent siblings)
  7 siblings, 0 replies; 19+ messages in thread
From: Donglin Peng @ 2023-03-31 12:47 UTC (permalink / raw)
  To: mhiramat, rostedt, linux, mark.rutland, will, catalin.marinas,
	rmk+kernel, palmer, paul.walmsley, aou, tglx, dave.hansen, x86,
	bp, hpa, chenhuacai, zhangqing, kernel, mingo, peterz, xiehuan09,
	dinghui, huangcun, dolinux.peng
  Cc: linux-trace-kernel, loongarch, linux-riscv, linux-arm-kernel,
	linux-kernel, Donglin Peng

The previous patch ("function_graph: Support recording and printing
the return value of function") has laid the groundwork for the for
the funcgraph-retval, and this modification makes it available on
the ARM platform.

We introduce a new structure called fgraph_ret_regs for the ARM platform
to hold return registers and the frame pointer. We then fill its content
in the return_to_handler and pass its address to the function
ftrace_return_to_handler to record the return value.

Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
---
v10:
 - Use CONFIG_FUNCTION_GRAPH_TRACER to control fgraph_ret_regs definition

v9:
 - Fix stack pointer align issues
 - Update the commit message

v8:
 - Modify the control range of CONFIG_HAVE_FUNCTION_GRAPH_RETVAL
---
 arch/arm/Kconfig               |  1 +
 arch/arm/include/asm/ftrace.h  | 22 ++++++++++++++++++++++
 arch/arm/kernel/asm-offsets.c  |  8 +++++++-
 arch/arm/kernel/entry-ftrace.S | 10 ++++++----
 4 files changed, 36 insertions(+), 5 deletions(-)

diff --git a/arch/arm/Kconfig b/arch/arm/Kconfig
index e24a9820e12f..73061379855a 100644
--- a/arch/arm/Kconfig
+++ b/arch/arm/Kconfig
@@ -98,6 +98,7 @@ config ARM
 	select HAVE_FAST_GUP if ARM_LPAE
 	select HAVE_FTRACE_MCOUNT_RECORD if !XIP_KERNEL
 	select HAVE_FUNCTION_ERROR_INJECTION
+	select HAVE_FUNCTION_GRAPH_RETVAL if HAVE_FUNCTION_GRAPH_TRACER
 	select HAVE_FUNCTION_GRAPH_TRACER
 	select HAVE_FUNCTION_TRACER if !XIP_KERNEL
 	select HAVE_GCC_PLUGINS
diff --git a/arch/arm/include/asm/ftrace.h b/arch/arm/include/asm/ftrace.h
index 7e9251ca29fe..3c457902b355 100644
--- a/arch/arm/include/asm/ftrace.h
+++ b/arch/arm/include/asm/ftrace.h
@@ -77,4 +77,26 @@ static inline bool arch_syscall_match_sym_name(const char *sym,
 
 #endif /* ifndef __ASSEMBLY__ */
 
+#ifndef __ASSEMBLY__
+#ifdef CONFIG_FUNCTION_GRAPH_TRACER
+struct fgraph_ret_regs {
+	/* r0 - r3 */
+	unsigned long regs[4];
+
+	unsigned long fp;
+	unsigned long __unused;
+};
+
+static inline unsigned long fgraph_ret_regs_return_value(struct fgraph_ret_regs *ret_regs)
+{
+	return ret_regs->regs[0];
+}
+
+static inline unsigned long fgraph_ret_regs_frame_pointer(struct fgraph_ret_regs *ret_regs)
+{
+	return ret_regs->fp;
+}
+#endif /* ifdef CONFIG_FUNCTION_GRAPH_TRACER */
+#endif
+
 #endif /* _ASM_ARM_FTRACE */
diff --git a/arch/arm/kernel/asm-offsets.c b/arch/arm/kernel/asm-offsets.c
index 38121c59cbc2..18bb85115b21 100644
--- a/arch/arm/kernel/asm-offsets.c
+++ b/arch/arm/kernel/asm-offsets.c
@@ -23,6 +23,7 @@
 #include <asm/suspend.h>
 #include <asm/vdso_datapage.h>
 #include <asm/hardware/cache-l2x0.h>
+#include <asm/ftrace.h>
 #include <linux/kbuild.h>
 #include <linux/arm-smccc.h>
 #include "signal.h"
@@ -170,5 +171,10 @@ int main(void)
   DEFINE(KEXEC_INDIR_PAGE,	offsetof(struct kexec_relocate_data, kexec_indirection_page));
   DEFINE(KEXEC_MACH_TYPE,	offsetof(struct kexec_relocate_data, kexec_mach_type));
   DEFINE(KEXEC_R2,		offsetof(struct kexec_relocate_data, kexec_r2));
-  return 0; 
+#ifdef CONFIG_FUNCTION_GRAPH_TRACER
+  BLANK();
+  DEFINE(FGRET_REGS_SIZE,	sizeof(struct fgraph_ret_regs));
+  BLANK();
+#endif
+  return 0;
 }
diff --git a/arch/arm/kernel/entry-ftrace.S b/arch/arm/kernel/entry-ftrace.S
index 3e7bcaca5e07..d41a1676608c 100644
--- a/arch/arm/kernel/entry-ftrace.S
+++ b/arch/arm/kernel/entry-ftrace.S
@@ -257,11 +257,13 @@ ENDPROC(ftrace_graph_regs_caller)
 
 #ifdef CONFIG_FUNCTION_GRAPH_TRACER
 ENTRY(return_to_handler)
-	stmdb	sp!, {r0-r3}
-	add	r0, sp, #16		@ sp at exit of instrumented routine
+	mov	ip, sp				@ sp at exit of instrumented routine
+	stmdb	sp!, {r0-r3, ip, lr}		@ fill fgraph_ret_regs
+	mov	r0, sp
 	bl	ftrace_return_to_handler
-	mov	lr, r0			@ r0 has real ret addr
-	ldmia	sp!, {r0-r3}
+	mov	lr, r0				@ r0 has real ret addr
+	ldmia	sp, {r0-r3}
+	add	sp, sp, #FGRET_REGS_SIZE	@ restore stack pointer
 	ret	lr
 ENDPROC(return_to_handler)
 #endif
-- 
2.25.1


_______________________________________________
linux-riscv mailing list
linux-riscv@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-riscv

^ permalink raw reply related	[flat|nested] 19+ messages in thread

* [PATCH v10 4/8] arm64: ftrace: Enable HAVE_FUNCTION_GRAPH_RETVAL
  2023-03-31 12:47 [PATCH v10 0/8] function_graph: Support recording and printing the return value of function Donglin Peng
                   ` (2 preceding siblings ...)
  2023-03-31 12:47 ` [PATCH v10 3/8] ARM: ftrace: Enable HAVE_FUNCTION_GRAPH_RETVAL Donglin Peng
@ 2023-03-31 12:47 ` Donglin Peng
  2023-04-03  8:13   ` Mark Rutland
  2023-03-31 12:47 ` [PATCH v10 5/8] riscv: " Donglin Peng
                   ` (3 subsequent siblings)
  7 siblings, 1 reply; 19+ messages in thread
From: Donglin Peng @ 2023-03-31 12:47 UTC (permalink / raw)
  To: mhiramat, rostedt, linux, mark.rutland, will, catalin.marinas,
	rmk+kernel, palmer, paul.walmsley, aou, tglx, dave.hansen, x86,
	bp, hpa, chenhuacai, zhangqing, kernel, mingo, peterz, xiehuan09,
	dinghui, huangcun, dolinux.peng
  Cc: linux-trace-kernel, loongarch, linux-riscv, linux-arm-kernel,
	linux-kernel, Donglin Peng

The previous patch ("function_graph: Support recording and printing
the return value of function") has laid the groundwork for the for
the funcgraph-retval, and this modification makes it available on
the ARM64 platform.

We introduce a new structure called fgraph_ret_regs for the ARM64
platform to hold return registers and the frame pointer. We then
fill its content in the return_to_handler and pass its address to
the function ftrace_return_to_handler to record the return value.

Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
---
v10:
 - Use CONFIG_FUNCTION_GRAPH_TRACER to control fgraph_ret_regs definition

v9:
 - Update the commit message

v8:
 - Fix issues in ARM64 asm code
 - Modify the control range of CONFIG_HAVE_FUNCTION_GRAPH_RETVAL
---
 arch/arm64/Kconfig               |  1 +
 arch/arm64/include/asm/ftrace.h  | 22 ++++++++++++++++++++++
 arch/arm64/kernel/asm-offsets.c  | 13 +++++++++++++
 arch/arm64/kernel/entry-ftrace.S | 27 ++++++++++++++-------------
 4 files changed, 50 insertions(+), 13 deletions(-)

diff --git a/arch/arm64/Kconfig b/arch/arm64/Kconfig
index 1023e896d46b..48856d230800 100644
--- a/arch/arm64/Kconfig
+++ b/arch/arm64/Kconfig
@@ -195,6 +195,7 @@ config ARM64
 	select HAVE_FTRACE_MCOUNT_RECORD
 	select HAVE_FUNCTION_TRACER
 	select HAVE_FUNCTION_ERROR_INJECTION
+	select HAVE_FUNCTION_GRAPH_RETVAL if HAVE_FUNCTION_GRAPH_TRACER
 	select HAVE_FUNCTION_GRAPH_TRACER
 	select HAVE_GCC_PLUGINS
 	select HAVE_HW_BREAKPOINT if PERF_EVENTS
diff --git a/arch/arm64/include/asm/ftrace.h b/arch/arm64/include/asm/ftrace.h
index 1c2672bbbf37..657adcbd80a4 100644
--- a/arch/arm64/include/asm/ftrace.h
+++ b/arch/arm64/include/asm/ftrace.h
@@ -170,4 +170,26 @@ static inline bool arch_syscall_match_sym_name(const char *sym,
 }
 #endif /* ifndef __ASSEMBLY__ */
 
+#ifndef __ASSEMBLY__
+#ifdef CONFIG_FUNCTION_GRAPH_TRACER
+struct fgraph_ret_regs {
+	/* x0 - x7 */
+	unsigned long regs[8];
+
+	unsigned long fp;
+	unsigned long __unused;
+};
+
+static inline unsigned long fgraph_ret_regs_return_value(struct fgraph_ret_regs *ret_regs)
+{
+	return ret_regs->regs[0];
+}
+
+static inline unsigned long fgraph_ret_regs_frame_pointer(struct fgraph_ret_regs *ret_regs)
+{
+	return ret_regs->fp;
+}
+#endif /* ifdef CONFIG_FUNCTION_GRAPH_TRACER  */
+#endif
+
 #endif /* __ASM_FTRACE_H */
diff --git a/arch/arm64/kernel/asm-offsets.c b/arch/arm64/kernel/asm-offsets.c
index ae345b06e9f7..75082e0409bf 100644
--- a/arch/arm64/kernel/asm-offsets.c
+++ b/arch/arm64/kernel/asm-offsets.c
@@ -197,6 +197,19 @@ int main(void)
 #endif
 #ifdef CONFIG_FUNCTION_TRACER
   DEFINE(FTRACE_OPS_FUNC,		offsetof(struct ftrace_ops, func));
+#endif
+  BLANK();
+#ifdef CONFIG_FUNCTION_GRAPH_TRACER
+  DEFINE(FGRET_REGS_X0,			offsetof(struct fgraph_ret_regs, regs[0]));
+  DEFINE(FGRET_REGS_X1,			offsetof(struct fgraph_ret_regs, regs[1]));
+  DEFINE(FGRET_REGS_X2,			offsetof(struct fgraph_ret_regs, regs[2]));
+  DEFINE(FGRET_REGS_X3,			offsetof(struct fgraph_ret_regs, regs[3]));
+  DEFINE(FGRET_REGS_X4,			offsetof(struct fgraph_ret_regs, regs[4]));
+  DEFINE(FGRET_REGS_X5,			offsetof(struct fgraph_ret_regs, regs[5]));
+  DEFINE(FGRET_REGS_X6,			offsetof(struct fgraph_ret_regs, regs[6]));
+  DEFINE(FGRET_REGS_X7,			offsetof(struct fgraph_ret_regs, regs[7]));
+  DEFINE(FGRET_REGS_FP,			offsetof(struct fgraph_ret_regs, fp));
+  DEFINE(FGRET_REGS_SIZE,		sizeof(struct fgraph_ret_regs));
 #endif
   return 0;
 }
diff --git a/arch/arm64/kernel/entry-ftrace.S b/arch/arm64/kernel/entry-ftrace.S
index 350ed81324ac..da1443bcf776 100644
--- a/arch/arm64/kernel/entry-ftrace.S
+++ b/arch/arm64/kernel/entry-ftrace.S
@@ -270,22 +270,23 @@ SYM_FUNC_END(ftrace_stub_graph)
  */
 SYM_CODE_START(return_to_handler)
 	/* save return value regs */
-	sub sp, sp, #64
-	stp x0, x1, [sp]
-	stp x2, x3, [sp, #16]
-	stp x4, x5, [sp, #32]
-	stp x6, x7, [sp, #48]
+	sub sp, sp, #FGRET_REGS_SIZE
+	stp x0, x1, [sp, #FGRET_REGS_X0]
+	stp x2, x3, [sp, #FGRET_REGS_X2]
+	stp x4, x5, [sp, #FGRET_REGS_X4]
+	stp x6, x7, [sp, #FGRET_REGS_X6]
+	str x29,    [sp, #FGRET_REGS_FP]	// parent's fp
 
-	mov	x0, x29			//     parent's fp
-	bl	ftrace_return_to_handler// addr = ftrace_return_to_hander(fp);
-	mov	x30, x0			// restore the original return address
+	mov	x0, sp
+	bl	ftrace_return_to_handler	// addr = ftrace_return_to_hander(regs);
+	mov	x30, x0				// restore the original return address
 
 	/* restore return value regs */
-	ldp x0, x1, [sp]
-	ldp x2, x3, [sp, #16]
-	ldp x4, x5, [sp, #32]
-	ldp x6, x7, [sp, #48]
-	add sp, sp, #64
+	ldp x0, x1, [sp, #FGRET_REGS_X0]
+	ldp x2, x3, [sp, #FGRET_REGS_X2]
+	ldp x4, x5, [sp, #FGRET_REGS_X4]
+	ldp x6, x7, [sp, #FGRET_REGS_X6]
+	add sp, sp, #FGRET_REGS_SIZE
 
 	ret
 SYM_CODE_END(return_to_handler)
-- 
2.25.1


_______________________________________________
linux-riscv mailing list
linux-riscv@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-riscv

^ permalink raw reply related	[flat|nested] 19+ messages in thread

* [PATCH v10 5/8] riscv: ftrace: Enable HAVE_FUNCTION_GRAPH_RETVAL
  2023-03-31 12:47 [PATCH v10 0/8] function_graph: Support recording and printing the return value of function Donglin Peng
                   ` (3 preceding siblings ...)
  2023-03-31 12:47 ` [PATCH v10 4/8] arm64: " Donglin Peng
@ 2023-03-31 12:47 ` Donglin Peng
  2023-03-31 12:47 ` [PATCH v10 6/8] x86/ftrace: " Donglin Peng
                   ` (2 subsequent siblings)
  7 siblings, 0 replies; 19+ messages in thread
From: Donglin Peng @ 2023-03-31 12:47 UTC (permalink / raw)
  To: mhiramat, rostedt, linux, mark.rutland, will, catalin.marinas,
	rmk+kernel, palmer, paul.walmsley, aou, tglx, dave.hansen, x86,
	bp, hpa, chenhuacai, zhangqing, kernel, mingo, peterz, xiehuan09,
	dinghui, huangcun, dolinux.peng
  Cc: linux-trace-kernel, loongarch, linux-riscv, linux-arm-kernel,
	linux-kernel, Donglin Peng

The previous patch ("function_graph: Support recording and printing
the return value of function") has laid the groundwork for the for
the funcgraph-retval, and this modification makes it available on
the RISC-V platform.

We introduce a new structure called fgraph_ret_regs for the RISC-V
platform to hold return registers and the frame pointer. We then
fill its content in the return_to_handler and pass its address to
the function ftrace_return_to_handler to record the return value.

Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
---
v10:
 - Use CONFIG_FUNCTION_GRAPH_TRACER to control fgraph_ret_regs definition

v9:
 - Update the commit message

v8:
 - Modify the control range of CONFIG_HAVE_FUNCTION_GRAPH_RETVAL
---
 arch/riscv/Kconfig              |  1 +
 arch/riscv/include/asm/ftrace.h | 21 +++++++++++++++++++++
 arch/riscv/kernel/mcount.S      |  7 +------
 3 files changed, 23 insertions(+), 6 deletions(-)

diff --git a/arch/riscv/Kconfig b/arch/riscv/Kconfig
index 5b182d1c196c..0573eae28823 100644
--- a/arch/riscv/Kconfig
+++ b/arch/riscv/Kconfig
@@ -138,6 +138,7 @@ config RISCV
 	select HAVE_DYNAMIC_FTRACE if !XIP_KERNEL && MMU && $(cc-option,-fpatchable-function-entry=8)
 	select HAVE_DYNAMIC_FTRACE_WITH_REGS if HAVE_DYNAMIC_FTRACE
 	select HAVE_FTRACE_MCOUNT_RECORD if !XIP_KERNEL
+	select HAVE_FUNCTION_GRAPH_RETVAL if HAVE_FUNCTION_GRAPH_TRACER
 	select HAVE_FUNCTION_GRAPH_TRACER
 	select HAVE_FUNCTION_TRACER if !XIP_KERNEL && !PREEMPTION
 
diff --git a/arch/riscv/include/asm/ftrace.h b/arch/riscv/include/asm/ftrace.h
index d47d87c2d7e3..740a979171e5 100644
--- a/arch/riscv/include/asm/ftrace.h
+++ b/arch/riscv/include/asm/ftrace.h
@@ -111,4 +111,25 @@ int ftrace_init_nop(struct module *mod, struct dyn_ftrace *rec);
 
 #endif /* CONFIG_DYNAMIC_FTRACE */
 
+#ifndef __ASSEMBLY__
+#ifdef CONFIG_FUNCTION_GRAPH_TRACER
+struct fgraph_ret_regs {
+	unsigned long a1;
+	unsigned long a0;
+	unsigned long s0;
+	unsigned long ra;
+};
+
+static inline unsigned long fgraph_ret_regs_return_value(struct fgraph_ret_regs *ret_regs)
+{
+	return ret_regs->a0;
+}
+
+static inline unsigned long fgraph_ret_regs_frame_pointer(struct fgraph_ret_regs *ret_regs)
+{
+	return ret_regs->s0;
+}
+#endif /* ifdef CONFIG_FUNCTION_GRAPH_TRACER */
+#endif
+
 #endif /* _ASM_RISCV_FTRACE_H */
diff --git a/arch/riscv/kernel/mcount.S b/arch/riscv/kernel/mcount.S
index 30102aadc4d7..8a6e5a9e842a 100644
--- a/arch/riscv/kernel/mcount.S
+++ b/arch/riscv/kernel/mcount.S
@@ -65,13 +65,8 @@ ENTRY(return_to_handler)
  * So alternatively we check the *old* frame pointer position, that is, the
  * value stored in -16(s0) on entry, and the s0 on return.
  */
-#ifdef HAVE_FUNCTION_GRAPH_FP_TEST
-	mv	t6, s0
-#endif
 	SAVE_RET_ABI_STATE
-#ifdef HAVE_FUNCTION_GRAPH_FP_TEST
-	mv	a0, t6
-#endif
+	mv	a0, sp
 	call	ftrace_return_to_handler
 	mv	a2, a0
 	RESTORE_RET_ABI_STATE
-- 
2.25.1


_______________________________________________
linux-riscv mailing list
linux-riscv@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-riscv

^ permalink raw reply related	[flat|nested] 19+ messages in thread

* [PATCH v10 6/8] x86/ftrace: Enable HAVE_FUNCTION_GRAPH_RETVAL
  2023-03-31 12:47 [PATCH v10 0/8] function_graph: Support recording and printing the return value of function Donglin Peng
                   ` (4 preceding siblings ...)
  2023-03-31 12:47 ` [PATCH v10 5/8] riscv: " Donglin Peng
@ 2023-03-31 12:47 ` Donglin Peng
  2023-03-31 12:47 ` [PATCH v10 7/8] LoongArch: ftrace: " Donglin Peng
  2023-03-31 12:47 ` [PATCH v10 8/8] selftests/ftrace: Add funcgraph-retval test case Donglin Peng
  7 siblings, 0 replies; 19+ messages in thread
From: Donglin Peng @ 2023-03-31 12:47 UTC (permalink / raw)
  To: mhiramat, rostedt, linux, mark.rutland, will, catalin.marinas,
	rmk+kernel, palmer, paul.walmsley, aou, tglx, dave.hansen, x86,
	bp, hpa, chenhuacai, zhangqing, kernel, mingo, peterz, xiehuan09,
	dinghui, huangcun, dolinux.peng
  Cc: linux-trace-kernel, loongarch, linux-riscv, linux-arm-kernel,
	linux-kernel, Donglin Peng

The previous patch ("function_graph: Support recording and printing
the return value of function") has laid the groundwork for the for
the funcgraph-retval, and this modification makes it available on
the x86 platform.

We introduce a new structure called fgraph_ret_regs for the x86
platform to hold return registers and the frame pointer. We then
fill its content in the return_to_handler and pass its address
to the function ftrace_return_to_handler to record the return
value.

Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
---
v10:
 - Use CONFIG_FUNCTION_GRAPH_TRACER to control fgraph_ret_regs definition

v9:
 - Update the commit message

v8:
 - Modify the control range of CONFIG_HAVE_FUNCTION_GRAPH_RETVAL
---
 arch/x86/Kconfig              |  1 +
 arch/x86/include/asm/ftrace.h | 20 ++++++++++++++++++++
 arch/x86/kernel/ftrace_32.S   |  8 +++++---
 arch/x86/kernel/ftrace_64.S   |  7 ++++---
 4 files changed, 30 insertions(+), 6 deletions(-)

diff --git a/arch/x86/Kconfig b/arch/x86/Kconfig
index a825bf031f49..956cc988bdf9 100644
--- a/arch/x86/Kconfig
+++ b/arch/x86/Kconfig
@@ -214,6 +214,7 @@ config X86
 	select HAVE_FAST_GUP
 	select HAVE_FENTRY			if X86_64 || DYNAMIC_FTRACE
 	select HAVE_FTRACE_MCOUNT_RECORD
+	select HAVE_FUNCTION_GRAPH_RETVAL	if HAVE_FUNCTION_GRAPH_TRACER
 	select HAVE_FUNCTION_GRAPH_TRACER	if X86_32 || (X86_64 && DYNAMIC_FTRACE)
 	select HAVE_FUNCTION_TRACER
 	select HAVE_GCC_PLUGINS
diff --git a/arch/x86/include/asm/ftrace.h b/arch/x86/include/asm/ftrace.h
index 5061ac98ffa1..38d1df9aed37 100644
--- a/arch/x86/include/asm/ftrace.h
+++ b/arch/x86/include/asm/ftrace.h
@@ -147,4 +147,24 @@ static inline bool arch_trace_is_compat_syscall(struct pt_regs *regs)
 #endif /* !COMPILE_OFFSETS */
 #endif /* !__ASSEMBLY__ */
 
+#ifndef __ASSEMBLY__
+#ifdef CONFIG_FUNCTION_GRAPH_TRACER
+struct fgraph_ret_regs {
+	unsigned long ax;
+	unsigned long dx;
+	unsigned long bp;
+};
+
+static inline unsigned long fgraph_ret_regs_return_value(struct fgraph_ret_regs *ret_regs)
+{
+	return ret_regs->ax;
+}
+
+static inline unsigned long fgraph_ret_regs_frame_pointer(struct fgraph_ret_regs *ret_regs)
+{
+	return ret_regs->bp;
+}
+#endif /* ifdef CONFIG_FUNCTION_GRAPH_TRACER */
+#endif
+
 #endif /* _ASM_X86_FTRACE_H */
diff --git a/arch/x86/kernel/ftrace_32.S b/arch/x86/kernel/ftrace_32.S
index a0ed0e4a2c0c..5a9cc723f81f 100644
--- a/arch/x86/kernel/ftrace_32.S
+++ b/arch/x86/kernel/ftrace_32.S
@@ -182,12 +182,14 @@ SYM_CODE_END(ftrace_graph_caller)
 
 .globl return_to_handler
 return_to_handler:
-	pushl	%eax
+	pushl	$0
 	pushl	%edx
-	movl	$0, %eax
+	pushl	%eax
+	movl	%esp, %eax
 	call	ftrace_return_to_handler
 	movl	%eax, %ecx
-	popl	%edx
 	popl	%eax
+	popl	%edx
+	addl	$4, %esp		# skip ebp
 	JMP_NOSPEC ecx
 #endif
diff --git a/arch/x86/kernel/ftrace_64.S b/arch/x86/kernel/ftrace_64.S
index fb4f1e01b64a..ef78c0bbae62 100644
--- a/arch/x86/kernel/ftrace_64.S
+++ b/arch/x86/kernel/ftrace_64.S
@@ -344,12 +344,13 @@ STACK_FRAME_NON_STANDARD_FP(__fentry__)
 SYM_CODE_START(return_to_handler)
 	UNWIND_HINT_EMPTY
 	ANNOTATE_NOENDBR
-	subq  $16, %rsp
+	subq  $24, %rsp
 
 	/* Save the return values */
 	movq %rax, (%rsp)
 	movq %rdx, 8(%rsp)
-	movq %rbp, %rdi
+	movq %rbp, 16(%rsp)
+	movq %rsp, %rdi
 
 	call ftrace_return_to_handler
 
@@ -357,7 +358,7 @@ SYM_CODE_START(return_to_handler)
 	movq 8(%rsp), %rdx
 	movq (%rsp), %rax
 
-	addq $16, %rsp
+	addq $24, %rsp
 	/*
 	 * Jump back to the old return address. This cannot be JMP_NOSPEC rdi
 	 * since IBT would demand that contain ENDBR, which simply isn't so for
-- 
2.25.1


_______________________________________________
linux-riscv mailing list
linux-riscv@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-riscv

^ permalink raw reply related	[flat|nested] 19+ messages in thread

* [PATCH v10 7/8] LoongArch: ftrace: Enable HAVE_FUNCTION_GRAPH_RETVAL
  2023-03-31 12:47 [PATCH v10 0/8] function_graph: Support recording and printing the return value of function Donglin Peng
                   ` (5 preceding siblings ...)
  2023-03-31 12:47 ` [PATCH v10 6/8] x86/ftrace: " Donglin Peng
@ 2023-03-31 12:47 ` Donglin Peng
  2023-04-03  0:54   ` Huacai Chen
  2023-03-31 12:47 ` [PATCH v10 8/8] selftests/ftrace: Add funcgraph-retval test case Donglin Peng
  7 siblings, 1 reply; 19+ messages in thread
From: Donglin Peng @ 2023-03-31 12:47 UTC (permalink / raw)
  To: mhiramat, rostedt, linux, mark.rutland, will, catalin.marinas,
	rmk+kernel, palmer, paul.walmsley, aou, tglx, dave.hansen, x86,
	bp, hpa, chenhuacai, zhangqing, kernel, mingo, peterz, xiehuan09,
	dinghui, huangcun, dolinux.peng
  Cc: linux-trace-kernel, loongarch, linux-riscv, linux-arm-kernel,
	linux-kernel, Donglin Peng

The previous patch ("function_graph: Support recording and printing
the return value of function") has laid the groundwork for the for
the funcgraph-retval, and this modification makes it available on
the LoongArch platform.

We introduce a new structure called fgraph_ret_regs for the LoongArch
platform to hold return registers and the frame pointer. We then fill
its content in the return_to_handler and pass its address to the
function ftrace_return_to_handler to record the return value.

Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
---
v10:
 - Fix code style issues for LoongArch
 - Use CONFIG_FUNCTION_GRAPH_TRACER to control fgraph_ret_regs definition

v9:
 - Fix stack pointer align issues
 - Update the commit message

v8:
 - Modify the control range of CONFIG_HAVE_FUNCTION_GRAPH_RETVAL
---
 arch/loongarch/Kconfig              |  1 +
 arch/loongarch/include/asm/ftrace.h | 22 ++++++++++++++++++++++
 arch/loongarch/kernel/asm-offsets.c | 15 ++++++++++++++-
 arch/loongarch/kernel/mcount.S      | 14 ++++++++------
 arch/loongarch/kernel/mcount_dyn.S  | 15 ++++++++-------
 5 files changed, 53 insertions(+), 14 deletions(-)

diff --git a/arch/loongarch/Kconfig b/arch/loongarch/Kconfig
index 7fd51257e0ed..4bf60132869b 100644
--- a/arch/loongarch/Kconfig
+++ b/arch/loongarch/Kconfig
@@ -99,6 +99,7 @@ config LOONGARCH
 	select HAVE_FAST_GUP
 	select HAVE_FTRACE_MCOUNT_RECORD
 	select HAVE_FUNCTION_ARG_ACCESS_API
+	select HAVE_FUNCTION_GRAPH_RETVAL if HAVE_FUNCTION_GRAPH_TRACER
 	select HAVE_FUNCTION_GRAPH_TRACER
 	select HAVE_FUNCTION_TRACER
 	select HAVE_GENERIC_VDSO
diff --git a/arch/loongarch/include/asm/ftrace.h b/arch/loongarch/include/asm/ftrace.h
index 3418d32d4fc7..22797b7504b5 100644
--- a/arch/loongarch/include/asm/ftrace.h
+++ b/arch/loongarch/include/asm/ftrace.h
@@ -63,4 +63,26 @@ void ftrace_graph_func(unsigned long ip, unsigned long parent_ip,
 
 #endif /* CONFIG_FUNCTION_TRACER */
 
+#ifndef __ASSEMBLY__
+#ifdef CONFIG_FUNCTION_GRAPH_TRACER
+struct fgraph_ret_regs {
+	/* a0 - a1 */
+	unsigned long regs[2];
+
+	unsigned long fp;
+	unsigned long __unused;
+};
+
+static inline unsigned long fgraph_ret_regs_return_value(struct fgraph_ret_regs *ret_regs)
+{
+	return ret_regs->regs[0];
+}
+
+static inline unsigned long fgraph_ret_regs_frame_pointer(struct fgraph_ret_regs *ret_regs)
+{
+	return ret_regs->fp;
+}
+#endif /* ifdef CONFIG_FUNCTION_GRAPH_TRACER */
+#endif
+
 #endif /* _ASM_LOONGARCH_FTRACE_H */
diff --git a/arch/loongarch/kernel/asm-offsets.c b/arch/loongarch/kernel/asm-offsets.c
index 4bdb203fc66e..505e4bf59603 100644
--- a/arch/loongarch/kernel/asm-offsets.c
+++ b/arch/loongarch/kernel/asm-offsets.c
@@ -12,6 +12,7 @@
 #include <asm/cpu-info.h>
 #include <asm/ptrace.h>
 #include <asm/processor.h>
+#include <asm/ftrace.h>
 
 void output_ptreg_defines(void)
 {
@@ -264,7 +265,7 @@ void output_smpboot_defines(void)
 #ifdef CONFIG_HIBERNATION
 void output_pbe_defines(void)
 {
-	COMMENT(" Linux struct pbe offsets. ");
+	COMMENT("Linux struct pbe offsets.");
 	OFFSET(PBE_ADDRESS, pbe, address);
 	OFFSET(PBE_ORIG_ADDRESS, pbe, orig_address);
 	OFFSET(PBE_NEXT, pbe, next);
@@ -272,3 +273,15 @@ void output_pbe_defines(void)
 	BLANK();
 }
 #endif
+
+#ifdef CONFIG_FUNCTION_GRAPH_TRACER
+void output_fgraph_ret_regs_defines(void)
+{
+	COMMENT("LoongArch fgraph_ret_regs offsets.");
+	OFFSET(FGRET_REGS_A0, fgraph_ret_regs, regs[0]);
+	OFFSET(FGRET_REGS_A1, fgraph_ret_regs, regs[1]);
+	OFFSET(FGRET_REGS_FP, fgraph_ret_regs, fp);
+	DEFINE(FGRET_REGS_SIZE, sizeof(struct fgraph_ret_regs));
+	BLANK();
+}
+#endif
diff --git a/arch/loongarch/kernel/mcount.S b/arch/loongarch/kernel/mcount.S
index 8cdc1563cd33..cb8e5803de4b 100644
--- a/arch/loongarch/kernel/mcount.S
+++ b/arch/loongarch/kernel/mcount.S
@@ -79,18 +79,20 @@ SYM_FUNC_START(ftrace_graph_caller)
 SYM_FUNC_END(ftrace_graph_caller)
 
 SYM_FUNC_START(return_to_handler)
-	PTR_ADDI	sp, sp, -2 * SZREG
-	PTR_S		a0, sp, 0
-	PTR_S		a1, sp, SZREG
+	PTR_ADDI	sp, sp, -FGRET_REGS_SIZE
+	PTR_S		a0, sp, FGRET_REGS_A0
+	PTR_S		a1, sp, FGRET_REGS_A1
+	PTR_S		zero, sp, FGRET_REGS_FP
 
+	move		a0, sp
 	bl		ftrace_return_to_handler
 
 	/* Restore the real parent address: a0 -> ra */
 	move		ra, a0
 
-	PTR_L		a0, sp, 0
-	PTR_L		a1, sp, SZREG
-	PTR_ADDI	sp, sp, 2 * SZREG
+	PTR_L		a0, sp, FGRET_REGS_A0
+	PTR_L		a1, sp, FGRET_REGS_A1
+	PTR_ADDI	sp, sp, FGRET_REGS_SIZE
 	jr		ra
 SYM_FUNC_END(return_to_handler)
 #endif /* CONFIG_FUNCTION_GRAPH_TRACER */
diff --git a/arch/loongarch/kernel/mcount_dyn.S b/arch/loongarch/kernel/mcount_dyn.S
index bbabf06244c2..ec24ae1de741 100644
--- a/arch/loongarch/kernel/mcount_dyn.S
+++ b/arch/loongarch/kernel/mcount_dyn.S
@@ -131,18 +131,19 @@ SYM_CODE_END(ftrace_graph_caller)
 
 SYM_CODE_START(return_to_handler)
 	/* Save return value regs */
-	PTR_ADDI 	sp, sp, -2 * SZREG
-	PTR_S		a0, sp, 0
-	PTR_S		a1, sp, SZREG
+	PTR_ADDI	sp, sp, -FGRET_REGS_SIZE
+	PTR_S		a0, sp, FGRET_REGS_A0
+	PTR_S		a1, sp, FGRET_REGS_A1
+	PTR_S		zero, sp, FGRET_REGS_FP
 
-	move		a0, zero
+	move		a0, sp
 	bl		ftrace_return_to_handler
 	move		ra, a0
 
 	/* Restore return value regs */
-	PTR_L		a0, sp, 0
-	PTR_L		a1, sp, SZREG
-	PTR_ADDI 	sp, sp, 2 * SZREG
+	PTR_L		a0, sp, FGRET_REGS_A0
+	PTR_L		a1, sp, FGRET_REGS_A1
+	PTR_ADDI	sp, sp, FGRET_REGS_SIZE
 
 	jr		ra
 SYM_CODE_END(return_to_handler)
-- 
2.25.1


_______________________________________________
linux-riscv mailing list
linux-riscv@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-riscv

^ permalink raw reply related	[flat|nested] 19+ messages in thread

* [PATCH v10 8/8] selftests/ftrace: Add funcgraph-retval test case
  2023-03-31 12:47 [PATCH v10 0/8] function_graph: Support recording and printing the return value of function Donglin Peng
                   ` (6 preceding siblings ...)
  2023-03-31 12:47 ` [PATCH v10 7/8] LoongArch: ftrace: " Donglin Peng
@ 2023-03-31 12:47 ` Donglin Peng
  2023-04-01 22:04   ` Masami Hiramatsu
  7 siblings, 1 reply; 19+ messages in thread
From: Donglin Peng @ 2023-03-31 12:47 UTC (permalink / raw)
  To: mhiramat, rostedt, linux, mark.rutland, will, catalin.marinas,
	rmk+kernel, palmer, paul.walmsley, aou, tglx, dave.hansen, x86,
	bp, hpa, chenhuacai, zhangqing, kernel, mingo, peterz, xiehuan09,
	dinghui, huangcun, dolinux.peng
  Cc: linux-trace-kernel, loongarch, linux-riscv, linux-arm-kernel,
	linux-kernel, Donglin Peng

Add a test case for the funcgraph-retval and funcgraph-retval-hex
trace options.

Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
---
v10:
 - Fix issues in selftest

v8:
 - Fix issues in selftest
---
 .../ftrace/test.d/ftrace/fgraph-retval.tc     | 43 +++++++++++++++++++
 1 file changed, 43 insertions(+)
 create mode 100644 tools/testing/selftests/ftrace/test.d/ftrace/fgraph-retval.tc

diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-retval.tc b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-retval.tc
new file mode 100644
index 000000000000..5819aa2dd6ad
--- /dev/null
+++ b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-retval.tc
@@ -0,0 +1,43 @@
+#!/bin/sh
+# SPDX-License-Identifier: GPL-2.0
+# description: ftrace - function graph print function return value
+# requires: options/funcgraph-retval options/funcgraph-retval-hex function_graph:tracer
+
+# Make sure that funcgraph-retval works
+
+fail() { # msg
+    echo $1
+    exit_fail
+}
+
+disable_tracing
+clear_trace
+
+read PID _ < /proc/self/stat
+[ -f set_ftrace_pid ] && echo ${PID} > set_ftrace_pid
+[ -f set_ftrace_filter ] && echo proc_reg_write > set_ftrace_filter
+[ -f set_graph_function ] && echo proc_reg_write > set_graph_function
+echo function_graph > current_tracer
+echo funcgraph-retval > trace_options
+
+set +e
+enable_tracing
+echo > /proc/interrupts
+disable_tracing
+set -e
+
+: "Test printing the error code in signed decimal format"
+echo nofuncgraph-retval-hex > trace_options
+count=`cat trace | grep 'proc_reg_write' | grep '= -5' | wc -l`
+if [ $count -eq 0 ]; then
+    fail "Return value can not be printed in signed decimal format"
+fi
+
+: "Test printing the error code in hexadecimal format"
+echo funcgraph-retval-hex > trace_options
+count=`cat trace | grep 'proc_reg_write' | grep 'fffffffb' | wc -l`
+if [ $count -eq 0 ]; then
+    fail "Return value can not be printed in hexadecimal format"
+fi
+
+exit 0
-- 
2.25.1


_______________________________________________
linux-riscv mailing list
linux-riscv@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-riscv

^ permalink raw reply related	[flat|nested] 19+ messages in thread

* Re: [PATCH v10 8/8] selftests/ftrace: Add funcgraph-retval test case
  2023-03-31 12:47 ` [PATCH v10 8/8] selftests/ftrace: Add funcgraph-retval test case Donglin Peng
@ 2023-04-01 22:04   ` Masami Hiramatsu
  2023-04-03  2:33     ` Donglin Peng
  0 siblings, 1 reply; 19+ messages in thread
From: Masami Hiramatsu @ 2023-04-01 22:04 UTC (permalink / raw)
  To: Donglin Peng
  Cc: rostedt, linux, mark.rutland, will, catalin.marinas, rmk+kernel,
	palmer, paul.walmsley, aou, tglx, dave.hansen, x86, bp, hpa,
	chenhuacai, zhangqing, kernel, mingo, peterz, xiehuan09, dinghui,
	huangcun, dolinux.peng, linux-trace-kernel, loongarch,
	linux-riscv, linux-arm-kernel, linux-kernel

On Fri, 31 Mar 2023 05:47:44 -0700
Donglin Peng <pengdonglin@sangfor.com.cn> wrote:

> Add a test case for the funcgraph-retval and funcgraph-retval-hex
> trace options.
> 
> Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
> ---
> v10:
>  - Fix issues in selftest
> 
> v8:
>  - Fix issues in selftest
> ---
>  .../ftrace/test.d/ftrace/fgraph-retval.tc     | 43 +++++++++++++++++++
>  1 file changed, 43 insertions(+)
>  create mode 100644 tools/testing/selftests/ftrace/test.d/ftrace/fgraph-retval.tc
> 
> diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-retval.tc b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-retval.tc
> new file mode 100644
> index 000000000000..5819aa2dd6ad
> --- /dev/null
> +++ b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-retval.tc
> @@ -0,0 +1,43 @@
> +#!/bin/sh
> +# SPDX-License-Identifier: GPL-2.0
> +# description: ftrace - function graph print function return value
> +# requires: options/funcgraph-retval options/funcgraph-retval-hex function_graph:tracer
> +
> +# Make sure that funcgraph-retval works
> +
> +fail() { # msg
> +    echo $1
> +    exit_fail
> +}
> +
> +disable_tracing
> +clear_trace
> +
> +read PID _ < /proc/self/stat

You can use "$$" for self pid.

> +[ -f set_ftrace_pid ] && echo ${PID} > set_ftrace_pid
> +[ -f set_ftrace_filter ] && echo proc_reg_write > set_ftrace_filter
> +[ -f set_graph_function ] && echo proc_reg_write > set_graph_function

You should set the required files for this test, so that the test result
is always same. BTW, you need to set either 'set_ftrace_filter' or
'set_graph_function'.

> +echo function_graph > current_tracer
> +echo funcgraph-retval > trace_options
> +
> +set +e
> +enable_tracing
> +echo > /proc/interrupts
> +disable_tracing
> +set -e
> +
> +: "Test printing the error code in signed decimal format"
> +echo nofuncgraph-retval-hex > trace_options

echo 0 > options/funcgraph-retval-hex

If you require 'options/funcgraph-retval-hex' file, you can use the
file to set it or clear it.

> +count=`cat trace | grep 'proc_reg_write' | grep '= -5' | wc -l`
> +if [ $count -eq 0 ]; then
> +    fail "Return value can not be printed in signed decimal format"
> +fi
> +
> +: "Test printing the error code in hexadecimal format"
> +echo funcgraph-retval-hex > trace_options

Ditto.

Thanks,

> +count=`cat trace | grep 'proc_reg_write' | grep 'fffffffb' | wc -l`
> +if [ $count -eq 0 ]; then
> +    fail "Return value can not be printed in hexadecimal format"
> +fi
> +
> +exit 0
> -- 
> 2.25.1
> 


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

_______________________________________________
linux-riscv mailing list
linux-riscv@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-riscv

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH v10 2/8] tracing: Add documentation for funcgraph-retval and funcgraph-retval-hex
  2023-03-31 12:47 ` [PATCH v10 2/8] tracing: Add documentation for funcgraph-retval and funcgraph-retval-hex Donglin Peng
@ 2023-04-01 22:17   ` Masami Hiramatsu
  2023-04-03  8:30   ` Mark Rutland
  1 sibling, 0 replies; 19+ messages in thread
From: Masami Hiramatsu @ 2023-04-01 22:17 UTC (permalink / raw)
  To: Donglin Peng
  Cc: rostedt, linux, mark.rutland, will, catalin.marinas, rmk+kernel,
	palmer, paul.walmsley, aou, tglx, dave.hansen, x86, bp, hpa,
	chenhuacai, zhangqing, kernel, mingo, peterz, xiehuan09, dinghui,
	huangcun, dolinux.peng, linux-trace-kernel, loongarch,
	linux-riscv, linux-arm-kernel, linux-kernel

On Fri, 31 Mar 2023 05:47:38 -0700
Donglin Peng <pengdonglin@sangfor.com.cn> wrote:

> Add documentation for the two newly introduced options for the
> function_graph tracer. The funcgraph-retval option is used to
> control whether or not to display the return value, while the
> funcgraph-retval-hex option is used to control the display
> format of the return value.
> 
> Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>

Looks good to me.

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

Thank you!

> ---
> v9:
>  - Update limitation description
> 
> v7:
>  - Rename trace option 'graph_retval_hex' to 'funcgraph-retval-hex'
>  - Update documentation description
> 
> v6:
>  - Modify the limitations for funcgraph-retval
>  - Optimize the English expression
> 
> v5:
>  - Describe the limitations of funcgraph-retval
> ---
>  Documentation/trace/ftrace.rst | 74 ++++++++++++++++++++++++++++++++++
>  1 file changed, 74 insertions(+)
> 
> diff --git a/Documentation/trace/ftrace.rst b/Documentation/trace/ftrace.rst
> index b927fb2b94dc..f572ae419219 100644
> --- a/Documentation/trace/ftrace.rst
> +++ b/Documentation/trace/ftrace.rst
> @@ -1328,6 +1328,19 @@ Options for function_graph tracer:
>  	only a closing curly bracket "}" is displayed for
>  	the return of a function.
>  
> +  funcgraph-retval
> +	When set, the return value of each traced function
> +	will be printed after an equal sign "=". By default
> +	this is off.
> +
> +  funcgraph-retval-hex
> +	When set, the return value will always be printed
> +	in hexadecimal format. If the option is not set and
> +	the return value is an error code, it will be printed
> +	in signed decimal format; otherwise it will also be
> +	printed in hexadecimal format. By default, this option
> +	is off.
> +
>    sleep-time
>  	When running function graph tracer, to include
>  	the time a task schedules out in its function.
> @@ -2673,6 +2686,67 @@ It is default disabled.
>      0)   1.757 us    |        } /* kmem_cache_free() */
>      0)   2.861 us    |      } /* putname() */
>  
> +The return value of each traced function can be displayed after
> +an equal sign "=". When encountering system call failures, it
> +can be verfy helpful to quickly locate the function that first
> +returns an error code.
> +
> +	- hide: echo nofuncgraph-retval > trace_options
> +	- show: echo funcgraph-retval > trace_options
> +
> +  Example with funcgraph-retval::
> +
> +    1)               |    cgroup_migrate() {
> +    1)   0.651 us    |      cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
> +    1)               |      cgroup_migrate_execute() {
> +    1)               |        cpu_cgroup_can_attach() {
> +    1)               |          cgroup_taskset_first() {
> +    1)   0.732 us    |            cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
> +    1)   1.232 us    |          } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
> +    1)   0.380 us    |          sched_rt_can_attach(); /* = 0x0 */
> +    1)   2.335 us    |        } /* cpu_cgroup_can_attach = -22 */
> +    1)   4.369 us    |      } /* cgroup_migrate_execute = -22 */
> +    1)   7.143 us    |    } /* cgroup_migrate = -22 */
> +
> +The above example shows that the function cpu_cgroup_can_attach
> +returned the error code -22 firstly, then we can read the code
> +of this function to get the root cause.
> +
> +When the option funcgraph-retval-hex is not set, the return value can
> +be displayed in a smart way. Specifically, if it is an error code,
> +it will be printed in signed decimal format, otherwise it will
> +printed in hexadecimal format.
> +
> +	- smart: echo nofuncgraph-retval-hex > trace_options
> +	- hexadecimal always: echo funcgraph-retval-hex > trace_options
> +
> +  Example with funcgraph-retval-hex::
> +
> +    1)               |      cgroup_migrate() {
> +    1)   0.651 us    |        cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
> +    1)               |        cgroup_migrate_execute() {
> +    1)               |          cpu_cgroup_can_attach() {
> +    1)               |            cgroup_taskset_first() {
> +    1)   0.732 us    |              cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
> +    1)   1.232 us    |            } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
> +    1)   0.380 us    |            sched_rt_can_attach(); /* = 0x0 */
> +    1)   2.335 us    |          } /* cpu_cgroup_can_attach = 0xffffffea */
> +    1)   4.369 us    |        } /* cgroup_migrate_execute = 0xffffffea */
> +    1)   7.143 us    |      } /* cgroup_migrate = 0xffffffea */
> +
> +At present, there are some limitations when using the funcgraph-retval
> +option, and these limitations will be eliminated in the future:
> +
> +- Even if the function return type is void, a return value will still
> +  be printed, and you can just ignore it.
> +
> +- Even if return values are stored in multiple registers, only the
> +  value contained in the first register will be recorded and printed.
> +  To illustrate, in the x86 architecture, eax and edx are used to store
> +  a 64-bit return value, with the lower 32 bits saved in eax and the
> +  upper 32 bits saved in edx. However, only the value stored in eax
> +  will be recorded and printed.
> +
>  You can put some comments on specific functions by using
>  trace_printk() For example, if you want to put a comment inside
>  the __might_sleep() function, you just have to include
> -- 
> 2.25.1
> 


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

_______________________________________________
linux-riscv mailing list
linux-riscv@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-riscv

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH v10 7/8] LoongArch: ftrace: Enable HAVE_FUNCTION_GRAPH_RETVAL
  2023-03-31 12:47 ` [PATCH v10 7/8] LoongArch: ftrace: " Donglin Peng
@ 2023-04-03  0:54   ` Huacai Chen
  0 siblings, 0 replies; 19+ messages in thread
From: Huacai Chen @ 2023-04-03  0:54 UTC (permalink / raw)
  To: Donglin Peng
  Cc: mhiramat, rostedt, linux, mark.rutland, will, catalin.marinas,
	rmk+kernel, palmer, paul.walmsley, aou, tglx, dave.hansen, x86,
	bp, hpa, zhangqing, kernel, mingo, peterz, xiehuan09, dinghui,
	huangcun, dolinux.peng, linux-trace-kernel, loongarch,
	linux-riscv, linux-arm-kernel, linux-kernel

Reviewed-by: Huacai Chen <chenhuacai@loongson.cn>

On Fri, Mar 31, 2023 at 8:48 PM Donglin Peng <pengdonglin@sangfor.com.cn> wrote:
>
> The previous patch ("function_graph: Support recording and printing
> the return value of function") has laid the groundwork for the for
> the funcgraph-retval, and this modification makes it available on
> the LoongArch platform.
>
> We introduce a new structure called fgraph_ret_regs for the LoongArch
> platform to hold return registers and the frame pointer. We then fill
> its content in the return_to_handler and pass its address to the
> function ftrace_return_to_handler to record the return value.
>
> Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
> ---
> v10:
>  - Fix code style issues for LoongArch
>  - Use CONFIG_FUNCTION_GRAPH_TRACER to control fgraph_ret_regs definition
>
> v9:
>  - Fix stack pointer align issues
>  - Update the commit message
>
> v8:
>  - Modify the control range of CONFIG_HAVE_FUNCTION_GRAPH_RETVAL
> ---
>  arch/loongarch/Kconfig              |  1 +
>  arch/loongarch/include/asm/ftrace.h | 22 ++++++++++++++++++++++
>  arch/loongarch/kernel/asm-offsets.c | 15 ++++++++++++++-
>  arch/loongarch/kernel/mcount.S      | 14 ++++++++------
>  arch/loongarch/kernel/mcount_dyn.S  | 15 ++++++++-------
>  5 files changed, 53 insertions(+), 14 deletions(-)
>
> diff --git a/arch/loongarch/Kconfig b/arch/loongarch/Kconfig
> index 7fd51257e0ed..4bf60132869b 100644
> --- a/arch/loongarch/Kconfig
> +++ b/arch/loongarch/Kconfig
> @@ -99,6 +99,7 @@ config LOONGARCH
>         select HAVE_FAST_GUP
>         select HAVE_FTRACE_MCOUNT_RECORD
>         select HAVE_FUNCTION_ARG_ACCESS_API
> +       select HAVE_FUNCTION_GRAPH_RETVAL if HAVE_FUNCTION_GRAPH_TRACER
>         select HAVE_FUNCTION_GRAPH_TRACER
>         select HAVE_FUNCTION_TRACER
>         select HAVE_GENERIC_VDSO
> diff --git a/arch/loongarch/include/asm/ftrace.h b/arch/loongarch/include/asm/ftrace.h
> index 3418d32d4fc7..22797b7504b5 100644
> --- a/arch/loongarch/include/asm/ftrace.h
> +++ b/arch/loongarch/include/asm/ftrace.h
> @@ -63,4 +63,26 @@ void ftrace_graph_func(unsigned long ip, unsigned long parent_ip,
>
>  #endif /* CONFIG_FUNCTION_TRACER */
>
> +#ifndef __ASSEMBLY__
> +#ifdef CONFIG_FUNCTION_GRAPH_TRACER
> +struct fgraph_ret_regs {
> +       /* a0 - a1 */
> +       unsigned long regs[2];
> +
> +       unsigned long fp;
> +       unsigned long __unused;
> +};
> +
> +static inline unsigned long fgraph_ret_regs_return_value(struct fgraph_ret_regs *ret_regs)
> +{
> +       return ret_regs->regs[0];
> +}
> +
> +static inline unsigned long fgraph_ret_regs_frame_pointer(struct fgraph_ret_regs *ret_regs)
> +{
> +       return ret_regs->fp;
> +}
> +#endif /* ifdef CONFIG_FUNCTION_GRAPH_TRACER */
> +#endif
> +
>  #endif /* _ASM_LOONGARCH_FTRACE_H */
> diff --git a/arch/loongarch/kernel/asm-offsets.c b/arch/loongarch/kernel/asm-offsets.c
> index 4bdb203fc66e..505e4bf59603 100644
> --- a/arch/loongarch/kernel/asm-offsets.c
> +++ b/arch/loongarch/kernel/asm-offsets.c
> @@ -12,6 +12,7 @@
>  #include <asm/cpu-info.h>
>  #include <asm/ptrace.h>
>  #include <asm/processor.h>
> +#include <asm/ftrace.h>
>
>  void output_ptreg_defines(void)
>  {
> @@ -264,7 +265,7 @@ void output_smpboot_defines(void)
>  #ifdef CONFIG_HIBERNATION
>  void output_pbe_defines(void)
>  {
> -       COMMENT(" Linux struct pbe offsets. ");
> +       COMMENT("Linux struct pbe offsets.");
>         OFFSET(PBE_ADDRESS, pbe, address);
>         OFFSET(PBE_ORIG_ADDRESS, pbe, orig_address);
>         OFFSET(PBE_NEXT, pbe, next);
> @@ -272,3 +273,15 @@ void output_pbe_defines(void)
>         BLANK();
>  }
>  #endif
> +
> +#ifdef CONFIG_FUNCTION_GRAPH_TRACER
> +void output_fgraph_ret_regs_defines(void)
> +{
> +       COMMENT("LoongArch fgraph_ret_regs offsets.");
> +       OFFSET(FGRET_REGS_A0, fgraph_ret_regs, regs[0]);
> +       OFFSET(FGRET_REGS_A1, fgraph_ret_regs, regs[1]);
> +       OFFSET(FGRET_REGS_FP, fgraph_ret_regs, fp);
> +       DEFINE(FGRET_REGS_SIZE, sizeof(struct fgraph_ret_regs));
> +       BLANK();
> +}
> +#endif
> diff --git a/arch/loongarch/kernel/mcount.S b/arch/loongarch/kernel/mcount.S
> index 8cdc1563cd33..cb8e5803de4b 100644
> --- a/arch/loongarch/kernel/mcount.S
> +++ b/arch/loongarch/kernel/mcount.S
> @@ -79,18 +79,20 @@ SYM_FUNC_START(ftrace_graph_caller)
>  SYM_FUNC_END(ftrace_graph_caller)
>
>  SYM_FUNC_START(return_to_handler)
> -       PTR_ADDI        sp, sp, -2 * SZREG
> -       PTR_S           a0, sp, 0
> -       PTR_S           a1, sp, SZREG
> +       PTR_ADDI        sp, sp, -FGRET_REGS_SIZE
> +       PTR_S           a0, sp, FGRET_REGS_A0
> +       PTR_S           a1, sp, FGRET_REGS_A1
> +       PTR_S           zero, sp, FGRET_REGS_FP
>
> +       move            a0, sp
>         bl              ftrace_return_to_handler
>
>         /* Restore the real parent address: a0 -> ra */
>         move            ra, a0
>
> -       PTR_L           a0, sp, 0
> -       PTR_L           a1, sp, SZREG
> -       PTR_ADDI        sp, sp, 2 * SZREG
> +       PTR_L           a0, sp, FGRET_REGS_A0
> +       PTR_L           a1, sp, FGRET_REGS_A1
> +       PTR_ADDI        sp, sp, FGRET_REGS_SIZE
>         jr              ra
>  SYM_FUNC_END(return_to_handler)
>  #endif /* CONFIG_FUNCTION_GRAPH_TRACER */
> diff --git a/arch/loongarch/kernel/mcount_dyn.S b/arch/loongarch/kernel/mcount_dyn.S
> index bbabf06244c2..ec24ae1de741 100644
> --- a/arch/loongarch/kernel/mcount_dyn.S
> +++ b/arch/loongarch/kernel/mcount_dyn.S
> @@ -131,18 +131,19 @@ SYM_CODE_END(ftrace_graph_caller)
>
>  SYM_CODE_START(return_to_handler)
>         /* Save return value regs */
> -       PTR_ADDI        sp, sp, -2 * SZREG
> -       PTR_S           a0, sp, 0
> -       PTR_S           a1, sp, SZREG
> +       PTR_ADDI        sp, sp, -FGRET_REGS_SIZE
> +       PTR_S           a0, sp, FGRET_REGS_A0
> +       PTR_S           a1, sp, FGRET_REGS_A1
> +       PTR_S           zero, sp, FGRET_REGS_FP
>
> -       move            a0, zero
> +       move            a0, sp
>         bl              ftrace_return_to_handler
>         move            ra, a0
>
>         /* Restore return value regs */
> -       PTR_L           a0, sp, 0
> -       PTR_L           a1, sp, SZREG
> -       PTR_ADDI        sp, sp, 2 * SZREG
> +       PTR_L           a0, sp, FGRET_REGS_A0
> +       PTR_L           a1, sp, FGRET_REGS_A1
> +       PTR_ADDI        sp, sp, FGRET_REGS_SIZE
>
>         jr              ra
>  SYM_CODE_END(return_to_handler)
> --
> 2.25.1
>

_______________________________________________
linux-riscv mailing list
linux-riscv@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-riscv

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH v10 8/8] selftests/ftrace: Add funcgraph-retval test case
  2023-04-01 22:04   ` Masami Hiramatsu
@ 2023-04-03  2:33     ` Donglin Peng
  2023-04-03  5:01       ` Donglin Peng
  0 siblings, 1 reply; 19+ messages in thread
From: Donglin Peng @ 2023-04-03  2:33 UTC (permalink / raw)
  To: Masami Hiramatsu (Google)
  Cc: rostedt, linux, mark.rutland, will, catalin.marinas, rmk+kernel,
	palmer, paul.walmsley, aou, tglx, dave.hansen, x86, bp, hpa,
	chenhuacai, zhangqing, kernel, mingo, peterz, xiehuan09, dinghui,
	huangcun, dolinux.peng, linux-trace-kernel, loongarch,
	linux-riscv, linux-arm-kernel, linux-kernel

On 2023/4/2 6:04, Masami Hiramatsu (Google) wrote:
> On Fri, 31 Mar 2023 05:47:44 -0700
> Donglin Peng <pengdonglin@sangfor.com.cn> wrote:
> 
>> Add a test case for the funcgraph-retval and funcgraph-retval-hex
>> trace options.
>>
>> Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
>> ---
>> v10:
>>   - Fix issues in selftest
>>
>> v8:
>>   - Fix issues in selftest
>> ---
>>   .../ftrace/test.d/ftrace/fgraph-retval.tc     | 43 +++++++++++++++++++
>>   1 file changed, 43 insertions(+)
>>   create mode 100644 tools/testing/selftests/ftrace/test.d/ftrace/fgraph-retval.tc
>>
>> diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-retval.tc b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-retval.tc
>> new file mode 100644
>> index 000000000000..5819aa2dd6ad
>> --- /dev/null
>> +++ b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-retval.tc
>> @@ -0,0 +1,43 @@
>> +#!/bin/sh
>> +# SPDX-License-Identifier: GPL-2.0
>> +# description: ftrace - function graph print function return value
>> +# requires: options/funcgraph-retval options/funcgraph-retval-hex function_graph:tracer
>> +
>> +# Make sure that funcgraph-retval works
>> +
>> +fail() { # msg
>> +    echo $1
>> +    exit_fail
>> +}
>> +
>> +disable_tracing
>> +clear_trace
>> +
>> +read PID _ < /proc/self/stat
> 
> You can use "$$" for self pid.

Yeah, I will fix it.

> 
>> +[ -f set_ftrace_pid ] && echo ${PID} > set_ftrace_pid
>> +[ -f set_ftrace_filter ] && echo proc_reg_write > set_ftrace_filter
>> +[ -f set_graph_function ] && echo proc_reg_write > set_graph_function
> 
> You should set the required files for this test, so that the test result
> is always same. BTW, you need to set either 'set_ftrace_filter' or
> 'set_graph_function'.

Yes, but I discovered that set_ftrace_filter and set_graph_function rely 
on the CONFIG_DYNAMIC_FTRACE configuration, which means that these two 
files are not present when CONFIG_DYNAMIC_FTRACE is disabled, even if 
CONFIG_FUNCTION_GRAPH_RETVAL is enabled. Therefore, I think that these 
two trace files are not necessary for this test.

I will modify the above like this:

[ -f set_ftrace_pid ] && echo $$ > set_ftrace_pid
[ -f set_ftrace_filter ] && echo proc_reg_write > set_ftrace_filter

> 
>> +echo function_graph > current_tracer
>> +echo funcgraph-retval > trace_options
>> +
>> +set +e
>> +enable_tracing
>> +echo > /proc/interrupts
>> +disable_tracing
>> +set -e
>> +
>> +: "Test printing the error code in signed decimal format"
>> +echo nofuncgraph-retval-hex > trace_options
> 
> echo 0 > options/funcgraph-retval-hex
> 
> If you require 'options/funcgraph-retval-hex' file, you can use the
> file to set it or clear it.

Yeah.

> 
>> +count=`cat trace | grep 'proc_reg_write' | grep '= -5' | wc -l`
>> +if [ $count -eq 0 ]; then
>> +    fail "Return value can not be printed in signed decimal format"
>> +fi
>> +
>> +: "Test printing the error code in hexadecimal format"
>> +echo funcgraph-retval-hex > trace_options
> 
> Ditto.

Thanks.

> 
> Thanks,
> 
>> +count=`cat trace | grep 'proc_reg_write' | grep 'fffffffb' | wc -l`
>> +if [ $count -eq 0 ]; then
>> +    fail "Return value can not be printed in hexadecimal format"
>> +fi
>> +
>> +exit 0
>> -- 
>> 2.25.1
>>
> 
> 


_______________________________________________
linux-riscv mailing list
linux-riscv@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-riscv

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH v10 8/8] selftests/ftrace: Add funcgraph-retval test case
  2023-04-03  2:33     ` Donglin Peng
@ 2023-04-03  5:01       ` Donglin Peng
  2023-04-06 10:35         ` Donglin Peng
  0 siblings, 1 reply; 19+ messages in thread
From: Donglin Peng @ 2023-04-03  5:01 UTC (permalink / raw)
  To: Masami Hiramatsu (Google)
  Cc: rostedt, linux, mark.rutland, will, catalin.marinas, rmk+kernel,
	palmer, paul.walmsley, aou, tglx, dave.hansen, x86, bp, hpa,
	chenhuacai, zhangqing, kernel, mingo, peterz, xiehuan09, dinghui,
	huangcun, dolinux.peng, linux-trace-kernel, loongarch,
	linux-riscv, linux-arm-kernel, linux-kernel

On 2023/4/3 10:33, Donglin Peng wrote:
> On 2023/4/2 6:04, Masami Hiramatsu (Google) wrote:
>> On Fri, 31 Mar 2023 05:47:44 -0700
>> Donglin Peng <pengdonglin@sangfor.com.cn> wrote:
>>
>>> Add a test case for the funcgraph-retval and funcgraph-retval-hex
>>> trace options.
>>>
>>> Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
>>> ---
>>> v10:
>>>   - Fix issues in selftest
>>>
>>> v8:
>>>   - Fix issues in selftest
>>> ---
>>>   .../ftrace/test.d/ftrace/fgraph-retval.tc     | 43 +++++++++++++++++++
>>>   1 file changed, 43 insertions(+)
>>>   create mode 100644 
>>> tools/testing/selftests/ftrace/test.d/ftrace/fgraph-retval.tc
>>>
>>> diff --git 
>>> a/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-retval.tc 
>>> b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-retval.tc
>>> new file mode 100644
>>> index 000000000000..5819aa2dd6ad
>>> --- /dev/null
>>> +++ b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-retval.tc
>>> @@ -0,0 +1,43 @@
>>> +#!/bin/sh
>>> +# SPDX-License-Identifier: GPL-2.0
>>> +# description: ftrace - function graph print function return value
>>> +# requires: options/funcgraph-retval options/funcgraph-retval-hex 
>>> function_graph:tracer
>>> +
>>> +# Make sure that funcgraph-retval works
>>> +
>>> +fail() { # msg
>>> +    echo $1
>>> +    exit_fail
>>> +}
>>> +
>>> +disable_tracing
>>> +clear_trace
>>> +
>>> +read PID _ < /proc/self/stat
>>
>> You can use "$$" for self pid.
> 
> Yeah, I will fix it.

I found that ftracetest used () to launch a new child process for
executing a .tc script file, however the $$ value remains unchanged,
so we can not use $$ here, because it is PPID. Therefore I think we
have to get PID from /proc/self/stat.

Here is the code from ftracetest that launches a child shell for 
executing the .tc file.

__run_test() { # testfile
   # setup PID and PPID, $$ is *not* updated.
   (cd $TRACING_DIR; read PID _ < /proc/self/stat; set -e; set -x;
    checkreq $1; initialize_ftrace; . $1)
   [ $? -ne 0 ] && kill -s $SIG_FAIL $SIG_PID
}

> 
>>
>>> +[ -f set_ftrace_pid ] && echo ${PID} > set_ftrace_pid
>>> +[ -f set_ftrace_filter ] && echo proc_reg_write > set_ftrace_filter
>>> +[ -f set_graph_function ] && echo proc_reg_write > set_graph_function
>>
>> You should set the required files for this test, so that the test result
>> is always same. BTW, you need to set either 'set_ftrace_filter' or
>> 'set_graph_function'.
> 
> Yes, but I discovered that set_ftrace_filter and set_graph_function rely 
> on the CONFIG_DYNAMIC_FTRACE configuration, which means that these two 
> files are not present when CONFIG_DYNAMIC_FTRACE is disabled, even if 
> CONFIG_FUNCTION_GRAPH_RETVAL is enabled. Therefore, I think that these 
> two trace files are not necessary for this test.
> 
> I will modify the above like this:
> 
> [ -f set_ftrace_pid ] && echo $$ > set_ftrace_pid
> [ -f set_ftrace_filter ] && echo proc_reg_write > set_ftrace_filter
> 
>>
>>> +echo function_graph > current_tracer
>>> +echo funcgraph-retval > trace_options
>>> +
>>> +set +e
>>> +enable_tracing
>>> +echo > /proc/interrupts
>>> +disable_tracing
>>> +set -e
>>> +
>>> +: "Test printing the error code in signed decimal format"
>>> +echo nofuncgraph-retval-hex > trace_options
>>
>> echo 0 > options/funcgraph-retval-hex
>>
>> If you require 'options/funcgraph-retval-hex' file, you can use the
>> file to set it or clear it.
> 
> Yeah.
> 
>>
>>> +count=`cat trace | grep 'proc_reg_write' | grep '= -5' | wc -l`
>>> +if [ $count -eq 0 ]; then
>>> +    fail "Return value can not be printed in signed decimal format"
>>> +fi
>>> +
>>> +: "Test printing the error code in hexadecimal format"
>>> +echo funcgraph-retval-hex > trace_options
>>
>> Ditto.
> 
> Thanks.
> 
>>
>> Thanks,
>>
>>> +count=`cat trace | grep 'proc_reg_write' | grep 'fffffffb' | wc -l`
>>> +if [ $count -eq 0 ]; then
>>> +    fail "Return value can not be printed in hexadecimal format"
>>> +fi
>>> +
>>> +exit 0
>>> -- 
>>> 2.25.1
>>>
>>
>>
> 


_______________________________________________
linux-riscv mailing list
linux-riscv@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-riscv

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH v10 4/8] arm64: ftrace: Enable HAVE_FUNCTION_GRAPH_RETVAL
  2023-03-31 12:47 ` [PATCH v10 4/8] arm64: " Donglin Peng
@ 2023-04-03  8:13   ` Mark Rutland
  0 siblings, 0 replies; 19+ messages in thread
From: Mark Rutland @ 2023-04-03  8:13 UTC (permalink / raw)
  To: Donglin Peng
  Cc: mhiramat, rostedt, linux, will, catalin.marinas, rmk+kernel,
	palmer, paul.walmsley, aou, tglx, dave.hansen, x86, bp, hpa,
	chenhuacai, zhangqing, kernel, mingo, peterz, xiehuan09, dinghui,
	huangcun, dolinux.peng, linux-trace-kernel, loongarch,
	linux-riscv, linux-arm-kernel, linux-kernel

On Fri, Mar 31, 2023 at 05:47:40AM -0700, Donglin Peng wrote:
> The previous patch ("function_graph: Support recording and printing
> the return value of function") has laid the groundwork for the for
> the funcgraph-retval, and this modification makes it available on
> the ARM64 platform.
> 
> We introduce a new structure called fgraph_ret_regs for the ARM64
> platform to hold return registers and the frame pointer. We then
> fill its content in the return_to_handler and pass its address to
> the function ftrace_return_to_handler to record the return value.
> 
> Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>

Thanks for working through all the feedback!

The structual changes all look good to me, and I've given this a spin to check
that it doesn't break graph tracing, so:

Reviewed-by: Mark Rutland <mark.rutland@arm.com>
Tested-by: Mark Rutland <mark.rutland@arm.com>

Mark.

> ---
> v10:
>  - Use CONFIG_FUNCTION_GRAPH_TRACER to control fgraph_ret_regs definition
> 
> v9:
>  - Update the commit message
> 
> v8:
>  - Fix issues in ARM64 asm code
>  - Modify the control range of CONFIG_HAVE_FUNCTION_GRAPH_RETVAL
> ---
>  arch/arm64/Kconfig               |  1 +
>  arch/arm64/include/asm/ftrace.h  | 22 ++++++++++++++++++++++
>  arch/arm64/kernel/asm-offsets.c  | 13 +++++++++++++
>  arch/arm64/kernel/entry-ftrace.S | 27 ++++++++++++++-------------
>  4 files changed, 50 insertions(+), 13 deletions(-)
> 
> diff --git a/arch/arm64/Kconfig b/arch/arm64/Kconfig
> index 1023e896d46b..48856d230800 100644
> --- a/arch/arm64/Kconfig
> +++ b/arch/arm64/Kconfig
> @@ -195,6 +195,7 @@ config ARM64
>  	select HAVE_FTRACE_MCOUNT_RECORD
>  	select HAVE_FUNCTION_TRACER
>  	select HAVE_FUNCTION_ERROR_INJECTION
> +	select HAVE_FUNCTION_GRAPH_RETVAL if HAVE_FUNCTION_GRAPH_TRACER
>  	select HAVE_FUNCTION_GRAPH_TRACER
>  	select HAVE_GCC_PLUGINS
>  	select HAVE_HW_BREAKPOINT if PERF_EVENTS
> diff --git a/arch/arm64/include/asm/ftrace.h b/arch/arm64/include/asm/ftrace.h
> index 1c2672bbbf37..657adcbd80a4 100644
> --- a/arch/arm64/include/asm/ftrace.h
> +++ b/arch/arm64/include/asm/ftrace.h
> @@ -170,4 +170,26 @@ static inline bool arch_syscall_match_sym_name(const char *sym,
>  }
>  #endif /* ifndef __ASSEMBLY__ */
>  
> +#ifndef __ASSEMBLY__
> +#ifdef CONFIG_FUNCTION_GRAPH_TRACER
> +struct fgraph_ret_regs {
> +	/* x0 - x7 */
> +	unsigned long regs[8];
> +
> +	unsigned long fp;
> +	unsigned long __unused;
> +};
> +
> +static inline unsigned long fgraph_ret_regs_return_value(struct fgraph_ret_regs *ret_regs)
> +{
> +	return ret_regs->regs[0];
> +}
> +
> +static inline unsigned long fgraph_ret_regs_frame_pointer(struct fgraph_ret_regs *ret_regs)
> +{
> +	return ret_regs->fp;
> +}
> +#endif /* ifdef CONFIG_FUNCTION_GRAPH_TRACER  */
> +#endif
> +
>  #endif /* __ASM_FTRACE_H */
> diff --git a/arch/arm64/kernel/asm-offsets.c b/arch/arm64/kernel/asm-offsets.c
> index ae345b06e9f7..75082e0409bf 100644
> --- a/arch/arm64/kernel/asm-offsets.c
> +++ b/arch/arm64/kernel/asm-offsets.c
> @@ -197,6 +197,19 @@ int main(void)
>  #endif
>  #ifdef CONFIG_FUNCTION_TRACER
>    DEFINE(FTRACE_OPS_FUNC,		offsetof(struct ftrace_ops, func));
> +#endif
> +  BLANK();
> +#ifdef CONFIG_FUNCTION_GRAPH_TRACER
> +  DEFINE(FGRET_REGS_X0,			offsetof(struct fgraph_ret_regs, regs[0]));
> +  DEFINE(FGRET_REGS_X1,			offsetof(struct fgraph_ret_regs, regs[1]));
> +  DEFINE(FGRET_REGS_X2,			offsetof(struct fgraph_ret_regs, regs[2]));
> +  DEFINE(FGRET_REGS_X3,			offsetof(struct fgraph_ret_regs, regs[3]));
> +  DEFINE(FGRET_REGS_X4,			offsetof(struct fgraph_ret_regs, regs[4]));
> +  DEFINE(FGRET_REGS_X5,			offsetof(struct fgraph_ret_regs, regs[5]));
> +  DEFINE(FGRET_REGS_X6,			offsetof(struct fgraph_ret_regs, regs[6]));
> +  DEFINE(FGRET_REGS_X7,			offsetof(struct fgraph_ret_regs, regs[7]));
> +  DEFINE(FGRET_REGS_FP,			offsetof(struct fgraph_ret_regs, fp));
> +  DEFINE(FGRET_REGS_SIZE,		sizeof(struct fgraph_ret_regs));
>  #endif
>    return 0;
>  }
> diff --git a/arch/arm64/kernel/entry-ftrace.S b/arch/arm64/kernel/entry-ftrace.S
> index 350ed81324ac..da1443bcf776 100644
> --- a/arch/arm64/kernel/entry-ftrace.S
> +++ b/arch/arm64/kernel/entry-ftrace.S
> @@ -270,22 +270,23 @@ SYM_FUNC_END(ftrace_stub_graph)
>   */
>  SYM_CODE_START(return_to_handler)
>  	/* save return value regs */
> -	sub sp, sp, #64
> -	stp x0, x1, [sp]
> -	stp x2, x3, [sp, #16]
> -	stp x4, x5, [sp, #32]
> -	stp x6, x7, [sp, #48]
> +	sub sp, sp, #FGRET_REGS_SIZE
> +	stp x0, x1, [sp, #FGRET_REGS_X0]
> +	stp x2, x3, [sp, #FGRET_REGS_X2]
> +	stp x4, x5, [sp, #FGRET_REGS_X4]
> +	stp x6, x7, [sp, #FGRET_REGS_X6]
> +	str x29,    [sp, #FGRET_REGS_FP]	// parent's fp
>  
> -	mov	x0, x29			//     parent's fp
> -	bl	ftrace_return_to_handler// addr = ftrace_return_to_hander(fp);
> -	mov	x30, x0			// restore the original return address
> +	mov	x0, sp
> +	bl	ftrace_return_to_handler	// addr = ftrace_return_to_hander(regs);
> +	mov	x30, x0				// restore the original return address
>  
>  	/* restore return value regs */
> -	ldp x0, x1, [sp]
> -	ldp x2, x3, [sp, #16]
> -	ldp x4, x5, [sp, #32]
> -	ldp x6, x7, [sp, #48]
> -	add sp, sp, #64
> +	ldp x0, x1, [sp, #FGRET_REGS_X0]
> +	ldp x2, x3, [sp, #FGRET_REGS_X2]
> +	ldp x4, x5, [sp, #FGRET_REGS_X4]
> +	ldp x6, x7, [sp, #FGRET_REGS_X6]
> +	add sp, sp, #FGRET_REGS_SIZE
>  
>  	ret
>  SYM_CODE_END(return_to_handler)
> -- 
> 2.25.1
> 

_______________________________________________
linux-riscv mailing list
linux-riscv@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-riscv

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH v10 2/8] tracing: Add documentation for funcgraph-retval and funcgraph-retval-hex
  2023-03-31 12:47 ` [PATCH v10 2/8] tracing: Add documentation for funcgraph-retval and funcgraph-retval-hex Donglin Peng
  2023-04-01 22:17   ` Masami Hiramatsu
@ 2023-04-03  8:30   ` Mark Rutland
  2023-04-04 12:02     ` Donglin Peng
  1 sibling, 1 reply; 19+ messages in thread
From: Mark Rutland @ 2023-04-03  8:30 UTC (permalink / raw)
  To: Donglin Peng
  Cc: mhiramat, rostedt, linux, will, catalin.marinas, rmk+kernel,
	palmer, paul.walmsley, aou, tglx, dave.hansen, x86, bp, hpa,
	chenhuacai, zhangqing, kernel, mingo, peterz, xiehuan09, dinghui,
	huangcun, dolinux.peng, linux-trace-kernel, loongarch,
	linux-riscv, linux-arm-kernel, linux-kernel

On Fri, Mar 31, 2023 at 05:47:38AM -0700, Donglin Peng wrote:
> Add documentation for the two newly introduced options for the
> function_graph tracer. The funcgraph-retval option is used to
> control whether or not to display the return value, while the
> funcgraph-retval-hex option is used to control the display
> format of the return value.
> 
> Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
> ---
> v9:
>  - Update limitation description
> 
> v7:
>  - Rename trace option 'graph_retval_hex' to 'funcgraph-retval-hex'
>  - Update documentation description
> 
> v6:
>  - Modify the limitations for funcgraph-retval
>  - Optimize the English expression
> 
> v5:
>  - Describe the limitations of funcgraph-retval
> ---
>  Documentation/trace/ftrace.rst | 74 ++++++++++++++++++++++++++++++++++
>  1 file changed, 74 insertions(+)
> 
> diff --git a/Documentation/trace/ftrace.rst b/Documentation/trace/ftrace.rst
> index b927fb2b94dc..f572ae419219 100644
> --- a/Documentation/trace/ftrace.rst
> +++ b/Documentation/trace/ftrace.rst
> @@ -1328,6 +1328,19 @@ Options for function_graph tracer:
>  	only a closing curly bracket "}" is displayed for
>  	the return of a function.
>  
> +  funcgraph-retval
> +	When set, the return value of each traced function
> +	will be printed after an equal sign "=". By default
> +	this is off.
> +
> +  funcgraph-retval-hex
> +	When set, the return value will always be printed
> +	in hexadecimal format. If the option is not set and
> +	the return value is an error code, it will be printed
> +	in signed decimal format; otherwise it will also be
> +	printed in hexadecimal format. By default, this option
> +	is off.
> +
>    sleep-time
>  	When running function graph tracer, to include
>  	the time a task schedules out in its function.
> @@ -2673,6 +2686,67 @@ It is default disabled.
>      0)   1.757 us    |        } /* kmem_cache_free() */
>      0)   2.861 us    |      } /* putname() */
>  
> +The return value of each traced function can be displayed after
> +an equal sign "=". When encountering system call failures, it
> +can be verfy helpful to quickly locate the function that first
> +returns an error code.
> +
> +	- hide: echo nofuncgraph-retval > trace_options
> +	- show: echo funcgraph-retval > trace_options
> +
> +  Example with funcgraph-retval::
> +
> +    1)               |    cgroup_migrate() {
> +    1)   0.651 us    |      cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
> +    1)               |      cgroup_migrate_execute() {
> +    1)               |        cpu_cgroup_can_attach() {
> +    1)               |          cgroup_taskset_first() {
> +    1)   0.732 us    |            cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
> +    1)   1.232 us    |          } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
> +    1)   0.380 us    |          sched_rt_can_attach(); /* = 0x0 */
> +    1)   2.335 us    |        } /* cpu_cgroup_can_attach = -22 */
> +    1)   4.369 us    |      } /* cgroup_migrate_execute = -22 */
> +    1)   7.143 us    |    } /* cgroup_migrate = -22 */
> +
> +The above example shows that the function cpu_cgroup_can_attach
> +returned the error code -22 firstly, then we can read the code
> +of this function to get the root cause.
> +
> +When the option funcgraph-retval-hex is not set, the return value can
> +be displayed in a smart way. Specifically, if it is an error code,
> +it will be printed in signed decimal format, otherwise it will
> +printed in hexadecimal format.
> +
> +	- smart: echo nofuncgraph-retval-hex > trace_options
> +	- hexadecimal always: echo funcgraph-retval-hex > trace_options
> +
> +  Example with funcgraph-retval-hex::
> +
> +    1)               |      cgroup_migrate() {
> +    1)   0.651 us    |        cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
> +    1)               |        cgroup_migrate_execute() {
> +    1)               |          cpu_cgroup_can_attach() {
> +    1)               |            cgroup_taskset_first() {
> +    1)   0.732 us    |              cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
> +    1)   1.232 us    |            } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
> +    1)   0.380 us    |            sched_rt_can_attach(); /* = 0x0 */
> +    1)   2.335 us    |          } /* cpu_cgroup_can_attach = 0xffffffea */
> +    1)   4.369 us    |        } /* cgroup_migrate_execute = 0xffffffea */
> +    1)   7.143 us    |      } /* cgroup_migrate = 0xffffffea */
> +
> +At present, there are some limitations when using the funcgraph-retval
> +option, and these limitations will be eliminated in the future:
> +
> +- Even if the function return type is void, a return value will still
> +  be printed, and you can just ignore it.
> +
> +- Even if return values are stored in multiple registers, only the
> +  value contained in the first register will be recorded and printed.
> +  To illustrate, in the x86 architecture, eax and edx are used to store
> +  a 64-bit return value, with the lower 32 bits saved in eax and the
> +  upper 32 bits saved in edx. However, only the value stored in eax
> +  will be recorded and printed.

With some procedure call standards (e.g. arm64's AAPCS64), when a type is
smaller than a GPR it's up to the consumer to perform the narrowing, and the
upport bits may contain UNKNOWN values. For example, with a u8 in a 64-bit GPR,
bits [3:8] may contain arbitrary values.

It's probably worth noting that this means *some* manual processing will always
be necessary for such cases.

That's mostly visible around where largelr types get truncated (whether
explciitly or implicitly), e.g.

	u8 narrow_to_u8(u64 val)
	{
		// implicitly truncated
		return val;
	}

... could be compiled to:

	narrow_to_u8:
		< ... ftrace instrumentation ... >
		RET

... and so:
	
	narrow_to_u8(0x123456789abcdef);

... might be recorded as returning 0x123456789abcdef rather than 0xef.


That can happen in surprising ways, e.g.

	int error_if_not_4g_aligned(u64 val)
	{
		if (val & GENMASK(63, 32))
			return -EINVAL;

		return 0;
	}

... could be compiled to:

	error_if_not_4g_aligned:
		CBNZ	w0, .Lnot_aligned
		RET				// bits [31:0] are zero, bits
						// [63:32] are UNKNOWN
	.Lnot_aligned:
		MOV	x0, #-EINVAL
		RET

.... and so:

	error_if_not_4g_aligned(SZ_8G)

... could return with bits [63:32] non-zero

Thanks,
Mark.

_______________________________________________
linux-riscv mailing list
linux-riscv@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-riscv

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH v10 2/8] tracing: Add documentation for funcgraph-retval and funcgraph-retval-hex
  2023-04-03  8:30   ` Mark Rutland
@ 2023-04-04 12:02     ` Donglin Peng
  2023-04-04 12:52       ` Mark Rutland
  0 siblings, 1 reply; 19+ messages in thread
From: Donglin Peng @ 2023-04-04 12:02 UTC (permalink / raw)
  To: Mark Rutland
  Cc: mhiramat, rostedt, linux, will, catalin.marinas, rmk+kernel,
	palmer, paul.walmsley, aou, tglx, dave.hansen, x86, bp, hpa,
	chenhuacai, zhangqing, kernel, mingo, peterz, xiehuan09, dinghui,
	huangcun, dolinux.peng, linux-trace-kernel, loongarch,
	linux-riscv, linux-arm-kernel, linux-kernel

On 2023/4/3 16:30, Mark Rutland wrote:
> On Fri, Mar 31, 2023 at 05:47:38AM -0700, Donglin Peng wrote:
>> Add documentation for the two newly introduced options for the
>> function_graph tracer. The funcgraph-retval option is used to
>> control whether or not to display the return value, while the
>> funcgraph-retval-hex option is used to control the display
>> format of the return value.
>>
>> Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
>> ---
>> v9:
>>   - Update limitation description
>>
>> v7:
>>   - Rename trace option 'graph_retval_hex' to 'funcgraph-retval-hex'
>>   - Update documentation description
>>
>> v6:
>>   - Modify the limitations for funcgraph-retval
>>   - Optimize the English expression
>>
>> v5:
>>   - Describe the limitations of funcgraph-retval
>> ---
>>   Documentation/trace/ftrace.rst | 74 ++++++++++++++++++++++++++++++++++
>>   1 file changed, 74 insertions(+)
>>
>> diff --git a/Documentation/trace/ftrace.rst b/Documentation/trace/ftrace.rst
>> index b927fb2b94dc..f572ae419219 100644
>> --- a/Documentation/trace/ftrace.rst
>> +++ b/Documentation/trace/ftrace.rst
>> @@ -1328,6 +1328,19 @@ Options for function_graph tracer:
>>   	only a closing curly bracket "}" is displayed for
>>   	the return of a function.
>>   
>> +  funcgraph-retval
>> +	When set, the return value of each traced function
>> +	will be printed after an equal sign "=". By default
>> +	this is off.
>> +
>> +  funcgraph-retval-hex
>> +	When set, the return value will always be printed
>> +	in hexadecimal format. If the option is not set and
>> +	the return value is an error code, it will be printed
>> +	in signed decimal format; otherwise it will also be
>> +	printed in hexadecimal format. By default, this option
>> +	is off.
>> +
>>     sleep-time
>>   	When running function graph tracer, to include
>>   	the time a task schedules out in its function.
>> @@ -2673,6 +2686,67 @@ It is default disabled.
>>       0)   1.757 us    |        } /* kmem_cache_free() */
>>       0)   2.861 us    |      } /* putname() */
>>   
>> +The return value of each traced function can be displayed after
>> +an equal sign "=". When encountering system call failures, it
>> +can be verfy helpful to quickly locate the function that first
>> +returns an error code.
>> +
>> +	- hide: echo nofuncgraph-retval > trace_options
>> +	- show: echo funcgraph-retval > trace_options
>> +
>> +  Example with funcgraph-retval::
>> +
>> +    1)               |    cgroup_migrate() {
>> +    1)   0.651 us    |      cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
>> +    1)               |      cgroup_migrate_execute() {
>> +    1)               |        cpu_cgroup_can_attach() {
>> +    1)               |          cgroup_taskset_first() {
>> +    1)   0.732 us    |            cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
>> +    1)   1.232 us    |          } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
>> +    1)   0.380 us    |          sched_rt_can_attach(); /* = 0x0 */
>> +    1)   2.335 us    |        } /* cpu_cgroup_can_attach = -22 */
>> +    1)   4.369 us    |      } /* cgroup_migrate_execute = -22 */
>> +    1)   7.143 us    |    } /* cgroup_migrate = -22 */
>> +
>> +The above example shows that the function cpu_cgroup_can_attach
>> +returned the error code -22 firstly, then we can read the code
>> +of this function to get the root cause.
>> +
>> +When the option funcgraph-retval-hex is not set, the return value can
>> +be displayed in a smart way. Specifically, if it is an error code,
>> +it will be printed in signed decimal format, otherwise it will
>> +printed in hexadecimal format.
>> +
>> +	- smart: echo nofuncgraph-retval-hex > trace_options
>> +	- hexadecimal always: echo funcgraph-retval-hex > trace_options
>> +
>> +  Example with funcgraph-retval-hex::
>> +
>> +    1)               |      cgroup_migrate() {
>> +    1)   0.651 us    |        cgroup_migrate_add_task(); /* = 0xffff93fcfd346c00 */
>> +    1)               |        cgroup_migrate_execute() {
>> +    1)               |          cpu_cgroup_can_attach() {
>> +    1)               |            cgroup_taskset_first() {
>> +    1)   0.732 us    |              cgroup_taskset_next(); /* = 0xffff93fc8fb20000 */
>> +    1)   1.232 us    |            } /* cgroup_taskset_first = 0xffff93fc8fb20000 */
>> +    1)   0.380 us    |            sched_rt_can_attach(); /* = 0x0 */
>> +    1)   2.335 us    |          } /* cpu_cgroup_can_attach = 0xffffffea */
>> +    1)   4.369 us    |        } /* cgroup_migrate_execute = 0xffffffea */
>> +    1)   7.143 us    |      } /* cgroup_migrate = 0xffffffea */
>> +
>> +At present, there are some limitations when using the funcgraph-retval
>> +option, and these limitations will be eliminated in the future:
>> +
>> +- Even if the function return type is void, a return value will still
>> +  be printed, and you can just ignore it.
>> +
>> +- Even if return values are stored in multiple registers, only the
>> +  value contained in the first register will be recorded and printed.
>> +  To illustrate, in the x86 architecture, eax and edx are used to store
>> +  a 64-bit return value, with the lower 32 bits saved in eax and the
>> +  upper 32 bits saved in edx. However, only the value stored in eax
>> +  will be recorded and printed.
> 
> With some procedure call standards (e.g. arm64's AAPCS64), when a type is
> smaller than a GPR it's up to the consumer to perform the narrowing, and the
> upport bits may contain UNKNOWN values. For example, with a u8 in a 64-bit GPR,
> bits [3:8] may contain arbitrary values.

Thank you. Just to clarify, Should it be that bits [63:8] may contain
arbitrary values in such cases?

> 
> It's probably worth noting that this means *some* manual processing will always
> be necessary for such cases.
> 
> That's mostly visible around where largelr types get truncated (whether
> explciitly or implicitly), e.g.
> 
> 	u8 narrow_to_u8(u64 val)
> 	{
> 		// implicitly truncated
> 		return val;
> 	}
> 
> ... could be compiled to:
> 
> 	narrow_to_u8:
> 		< ... ftrace instrumentation ... >
> 		RET
> 
> ... and so:
> 	
> 	narrow_to_u8(0x123456789abcdef);
> 
> ... might be recorded as returning 0x123456789abcdef rather than 0xef.
> 
> 
> That can happen in surprising ways, e.g.
> 
> 	int error_if_not_4g_aligned(u64 val)
> 	{
> 		if (val & GENMASK(63, 32))

Should it be GENMASK(31, 0)?

> 			return -EINVAL;
> 
> 		return 0;
> 	}
> 
> ... could be compiled to:
> 
> 	error_if_not_4g_aligned:
> 		CBNZ	w0, .Lnot_aligned
> 		RET				// bits [31:0] are zero, bits
> 						// [63:32] are UNKNOWN
> 	.Lnot_aligned:
> 		MOV	x0, #-EINVAL
> 		RET
> 
> .... and so:
> 
> 	error_if_not_4g_aligned(SZ_8G)
> 
> ... could return with bits [63:32] non-zero
> 
> Thanks,
> Mark.

Thank you for sharing this note. I will append the following limitation.

In certain procedure call standards, such as arm64's AAPCS64, when a
type is smaller than a GPR, it is the responsibility of the consumer to
perform the narrowing, and the upper bits may contain UNKNOWN values.
Therefore, it is advisable to check the code for such cases. For
instance,when using a u8 in a 64-bit GPR, bits [63:8] may contain
arbitrary values, especially when larger types are truncated, whether
explicitly or implicitly. Here are some specific cases to illustrate
this point:

  - Case One:

   The function narrow_to_u8 is defined as follows:

  	u8 narrow_to_u8(u64 val)
	{
		// implicitly truncated
		return val;
	}

   It may be compiled to:

	narrow_to_u8:
		< ... ftrace instrumentation ... >
		RET

   If you pass 0x123456789abcdef to this function and want to narrow it,
   it may be recorded as 0x123456789abcdef instead of 0xef.

   - Case Two:

   The function error_if_not_4g_aligned is defined as follows:

	int error_if_not_4g_aligned(u64 val)
	{
		if (val & GENMASK(31, 0))
			return -EINVAL;

		return 0;
	}

   It could be compile to:

	error_if_not_4g_aligned:
		CBNZ	w0, .Lnot_aligned
		RET				// bits [31:0] are zero, bits
						// [63:32] are UNKNOWN
	.Lnot_aligned:
		MOV	x0, #-EINVAL
		RET

   When passing 0x2_0000_0000 to it, the return value may be recorded as
   0x2_0000_0000 instead of 0.

_______________________________________________
linux-riscv mailing list
linux-riscv@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-riscv

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH v10 2/8] tracing: Add documentation for funcgraph-retval and funcgraph-retval-hex
  2023-04-04 12:02     ` Donglin Peng
@ 2023-04-04 12:52       ` Mark Rutland
  0 siblings, 0 replies; 19+ messages in thread
From: Mark Rutland @ 2023-04-04 12:52 UTC (permalink / raw)
  To: Donglin Peng
  Cc: mhiramat, rostedt, linux, will, catalin.marinas, rmk+kernel,
	palmer, paul.walmsley, aou, tglx, dave.hansen, x86, bp, hpa,
	chenhuacai, zhangqing, kernel, mingo, peterz, xiehuan09, dinghui,
	huangcun, dolinux.peng, linux-trace-kernel, loongarch,
	linux-riscv, linux-arm-kernel, linux-kernel

On Tue, Apr 04, 2023 at 08:02:44PM +0800, Donglin Peng wrote:
> On 2023/4/3 16:30, Mark Rutland wrote:
> > On Fri, Mar 31, 2023 at 05:47:38AM -0700, Donglin Peng wrote:

> > > +At present, there are some limitations when using the funcgraph-retval
> > > +option, and these limitations will be eliminated in the future:
> > > +
> > > +- Even if the function return type is void, a return value will still
> > > +  be printed, and you can just ignore it.
> > > +
> > > +- Even if return values are stored in multiple registers, only the
> > > +  value contained in the first register will be recorded and printed.
> > > +  To illustrate, in the x86 architecture, eax and edx are used to store
> > > +  a 64-bit return value, with the lower 32 bits saved in eax and the
> > > +  upper 32 bits saved in edx. However, only the value stored in eax
> > > +  will be recorded and printed.
> > 
> > With some procedure call standards (e.g. arm64's AAPCS64), when a type is
> > smaller than a GPR it's up to the consumer to perform the narrowing, and the
> > upport bits may contain UNKNOWN values. For example, with a u8 in a 64-bit GPR,
> > bits [3:8] may contain arbitrary values.
> 
> Thank you. Just to clarify, Should it be that bits [63:8] may contain
> arbitrary values in such cases?

Yes; I meant to say bits [63:8].

> > It's probably worth noting that this means *some* manual processing will always
> > be necessary for such cases.
> > 
> > That's mostly visible around where largelr types get truncated (whether
> > explciitly or implicitly), e.g.
> > 
> > 	u8 narrow_to_u8(u64 val)
> > 	{
> > 		// implicitly truncated
> > 		return val;
> > 	}
> > 
> > ... could be compiled to:
> > 
> > 	narrow_to_u8:
> > 		< ... ftrace instrumentation ... >
> > 		RET
> > 
> > ... and so:
> > 	
> > 	narrow_to_u8(0x123456789abcdef);
> > 
> > ... might be recorded as returning 0x123456789abcdef rather than 0xef.
> > 
> > 
> > That can happen in surprising ways, e.g.
> > 
> > 	int error_if_not_4g_aligned(u64 val)
> > 	{
> > 		if (val & GENMASK(63, 32))
> 
> Should it be GENMASK(31, 0)?

Yes; whoops!

> > 			return -EINVAL;
> > 
> > 		return 0;
> > 	}
> > 
> > ... could be compiled to:
> > 
> > 	error_if_not_4g_aligned:
> > 		CBNZ	w0, .Lnot_aligned
> > 		RET				// bits [31:0] are zero, bits
> > 						// [63:32] are UNKNOWN
> > 	.Lnot_aligned:
> > 		MOV	x0, #-EINVAL
> > 		RET
> > 
> > .... and so:
> > 
> > 	error_if_not_4g_aligned(SZ_8G)
> > 
> > ... could return with bits [63:32] non-zero
> > 
> > Thanks,
> > Mark.
> 
> Thank you for sharing this note. I will append the following limitation.

That looks great; thanks!

> In certain procedure call standards, such as arm64's AAPCS64, when a
> type is smaller than a GPR, it is the responsibility of the consumer to
> perform the narrowing, and the upper bits may contain UNKNOWN values.
> Therefore, it is advisable to check the code for such cases. For
> instance,when using a u8 in a 64-bit GPR, bits [63:8] may contain
          ^
Minor nit: missing space here.

> arbitrary values, especially when larger types are truncated, whether
> explicitly or implicitly. Here are some specific cases to illustrate
> this point:
> 
>  - Case One:
> 
>   The function narrow_to_u8 is defined as follows:
> 
>  	u8 narrow_to_u8(u64 val)
> 	{
> 		// implicitly truncated
> 		return val;
> 	}
> 
>   It may be compiled to:
> 
> 	narrow_to_u8:
> 		< ... ftrace instrumentation ... >
> 		RET
> 
>   If you pass 0x123456789abcdef to this function and want to narrow it,
>   it may be recorded as 0x123456789abcdef instead of 0xef.
> 
>   - Case Two:
> 
>   The function error_if_not_4g_aligned is defined as follows:
> 
> 	int error_if_not_4g_aligned(u64 val)
> 	{
> 		if (val & GENMASK(31, 0))
> 			return -EINVAL;
> 
> 		return 0;
> 	}
> 
>   It could be compile to:
                ^^^^^^^

Minor nit: s/compile/compiled here.

Thanks,
Mark.

> 
> 	error_if_not_4g_aligned:
> 		CBNZ	w0, .Lnot_aligned
> 		RET				// bits [31:0] are zero, bits
> 						// [63:32] are UNKNOWN
> 	.Lnot_aligned:
> 		MOV	x0, #-EINVAL
> 		RET
> 
>   When passing 0x2_0000_0000 to it, the return value may be recorded as
>   0x2_0000_0000 instead of 0.

_______________________________________________
linux-riscv mailing list
linux-riscv@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-riscv

^ permalink raw reply	[flat|nested] 19+ messages in thread

* Re: [PATCH v10 8/8] selftests/ftrace: Add funcgraph-retval test case
  2023-04-03  5:01       ` Donglin Peng
@ 2023-04-06 10:35         ` Donglin Peng
  0 siblings, 0 replies; 19+ messages in thread
From: Donglin Peng @ 2023-04-06 10:35 UTC (permalink / raw)
  To: Masami Hiramatsu (Google)
  Cc: rostedt, linux, mark.rutland, will, catalin.marinas, rmk+kernel,
	palmer, paul.walmsley, aou, tglx, dave.hansen, x86, bp, hpa,
	chenhuacai, zhangqing, kernel, mingo, peterz, xiehuan09, dinghui,
	huangcun, dolinux.peng, linux-trace-kernel, loongarch,
	linux-riscv, linux-arm-kernel, linux-kernel

On 2023/4/3 13:01, Donglin Peng wrote:
> On 2023/4/3 10:33, Donglin Peng wrote:
>> On 2023/4/2 6:04, Masami Hiramatsu (Google) wrote:
>>> On Fri, 31 Mar 2023 05:47:44 -0700
>>> Donglin Peng <pengdonglin@sangfor.com.cn> wrote:
>>>
>>>> Add a test case for the funcgraph-retval and funcgraph-retval-hex
>>>> trace options.
>>>>
>>>> Signed-off-by: Donglin Peng <pengdonglin@sangfor.com.cn>
>>>> ---
>>>> v10:
>>>>   - Fix issues in selftest
>>>>
>>>> v8:
>>>>   - Fix issues in selftest
>>>> ---
>>>>   .../ftrace/test.d/ftrace/fgraph-retval.tc     | 43 
>>>> +++++++++++++++++++
>>>>   1 file changed, 43 insertions(+)
>>>>   create mode 100644 
>>>> tools/testing/selftests/ftrace/test.d/ftrace/fgraph-retval.tc
>>>>
>>>> diff --git 
>>>> a/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-retval.tc 
>>>> b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-retval.tc
>>>> new file mode 100644
>>>> index 000000000000..5819aa2dd6ad
>>>> --- /dev/null
>>>> +++ b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-retval.tc
>>>> @@ -0,0 +1,43 @@
>>>> +#!/bin/sh
>>>> +# SPDX-License-Identifier: GPL-2.0
>>>> +# description: ftrace - function graph print function return value
>>>> +# requires: options/funcgraph-retval options/funcgraph-retval-hex 
>>>> function_graph:tracer
>>>> +
>>>> +# Make sure that funcgraph-retval works
>>>> +
>>>> +fail() { # msg
>>>> +    echo $1
>>>> +    exit_fail
>>>> +}
>>>> +
>>>> +disable_tracing
>>>> +clear_trace
>>>> +
>>>> +read PID _ < /proc/self/stat
>>>
>>> You can use "$$" for self pid.
>>
>> Yeah, I will fix it.
> 
> I found that ftracetest used () to launch a new child process for
> executing a .tc script file, however the $$ value remains unchanged,
> so we can not use $$ here, because it is PPID. Therefore I think we
> have to get PID from /proc/self/stat.
> 
> Here is the code from ftracetest that launches a child shell for 
> executing the .tc file.
> 
> __run_test() { # testfile
>    # setup PID and PPID, $$ is *not* updated.
>    (cd $TRACING_DIR; read PID _ < /proc/self/stat; set -e; set -x;
>     checkreq $1; initialize_ftrace; . $1)
>    [ $? -ne 0 ] && kill -s $SIG_FAIL $SIG_PID
> }
> 
>>
>>>
>>>> +[ -f set_ftrace_pid ] && echo ${PID} > set_ftrace_pid
>>>> +[ -f set_ftrace_filter ] && echo proc_reg_write > set_ftrace_filter
>>>> +[ -f set_graph_function ] && echo proc_reg_write > set_graph_function
>>>
>>> You should set the required files for this test, so that the test result
>>> is always same. BTW, you need to set either 'set_ftrace_filter' or
>>> 'set_graph_function'.
>>
>> Yes, but I discovered that set_ftrace_filter and set_graph_function 
>> rely on the CONFIG_DYNAMIC_FTRACE configuration, which means that 
>> these two files are not present when CONFIG_DYNAMIC_FTRACE is 
>> disabled, even if CONFIG_FUNCTION_GRAPH_RETVAL is enabled. Therefore, 
>> I think that these two trace files are not necessary for this test.
>>
>> I will modify the above like this:
>>
>> [ -f set_ftrace_pid ] && echo $$ > set_ftrace_pid
>> [ -f set_ftrace_filter ] && echo proc_reg_write > set_ftrace_filter
>>
>>>
>>>> +echo function_graph > current_tracer
>>>> +echo funcgraph-retval > trace_options
>>>> +
>>>> +set +e
>>>> +enable_tracing
>>>> +echo > /proc/interrupts
>>>> +disable_tracing
>>>> +set -e
>>>> +
>>>> +: "Test printing the error code in signed decimal format"
>>>> +echo nofuncgraph-retval-hex > trace_options
>>>
>>> echo 0 > options/funcgraph-retval-hex
>>>
>>> If you require 'options/funcgraph-retval-hex' file, you can use the
>>> file to set it or clear it.
>>
>> Yeah.
>>
>>>
>>>> +count=`cat trace | grep 'proc_reg_write' | grep '= -5' | wc -l`
>>>> +if [ $count -eq 0 ]; then
>>>> +    fail "Return value can not be printed in signed decimal format"
>>>> +fi
>>>> +
>>>> +: "Test printing the error code in hexadecimal format"
>>>> +echo funcgraph-retval-hex > trace_options
>>>
>>> Ditto.
>>
>> Thanks.
>>
>>>
>>> Thanks,
>>>
>>>> +count=`cat trace | grep 'proc_reg_write' | grep 'fffffffb' | wc -l`
>>>> +if [ $count -eq 0 ]; then
>>>> +    fail "Return value can not be printed in hexadecimal format"
>>>> +fi
>>>> +
>>>> +exit 0
>>>> -- 
>>>> 2.25.1
>>>>
>>>
>>>
>>
> 

Hi Masami,

I will update the selftest as follows, according to the comments:

#!/bin/sh
# SPDX-License-Identifier: GPL-2.0
# description: ftrace - function graph print function return value
# requires: options/funcgraph-retval options/funcgraph-retval-hex 
function_graph:tracer

# Make sure that funcgraph-retval works

fail() { # msg
     echo $1
     exit_fail
}

disable_tracing
clear_trace

# get self PID, can not use $$, because it is PPID
read PID _ < /proc/self/stat

[ -f set_ftrace_filter ] && echo proc_reg_write > set_ftrace_filter
[ -f set_ftrace_pid ] && echo ${PID} > set_ftrace_pid
echo function_graph > current_tracer
echo 1 > options/funcgraph-retval

set +e
enable_tracing
echo > /proc/interrupts
disable_tracing
set -e

: "Test printing the error code in signed decimal format"
echo 0 > options/funcgraph-retval-hex
count=`cat trace | grep 'proc_reg_write' | grep '= -5' | wc -l`
if [ $count -eq 0 ]; then
     fail "Return value can not be printed in signed decimal format"
fi

: "Test printing the error code in hexadecimal format"
echo 1 > options/funcgraph-retval-hex
count=`cat trace | grep 'proc_reg_write' | grep 'fffffffb' | wc -l`
if [ $count -eq 0 ]; then
     fail "Return value can not be printed in hexadecimal format"
fi

exit 0




_______________________________________________
linux-riscv mailing list
linux-riscv@lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-riscv

^ permalink raw reply	[flat|nested] 19+ messages in thread

end of thread, other threads:[~2023-04-06 10:36 UTC | newest]

Thread overview: 19+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2023-03-31 12:47 [PATCH v10 0/8] function_graph: Support recording and printing the return value of function Donglin Peng
2023-03-31 12:47 ` [PATCH v10 1/8] " Donglin Peng
2023-03-31 12:47 ` [PATCH v10 2/8] tracing: Add documentation for funcgraph-retval and funcgraph-retval-hex Donglin Peng
2023-04-01 22:17   ` Masami Hiramatsu
2023-04-03  8:30   ` Mark Rutland
2023-04-04 12:02     ` Donglin Peng
2023-04-04 12:52       ` Mark Rutland
2023-03-31 12:47 ` [PATCH v10 3/8] ARM: ftrace: Enable HAVE_FUNCTION_GRAPH_RETVAL Donglin Peng
2023-03-31 12:47 ` [PATCH v10 4/8] arm64: " Donglin Peng
2023-04-03  8:13   ` Mark Rutland
2023-03-31 12:47 ` [PATCH v10 5/8] riscv: " Donglin Peng
2023-03-31 12:47 ` [PATCH v10 6/8] x86/ftrace: " Donglin Peng
2023-03-31 12:47 ` [PATCH v10 7/8] LoongArch: ftrace: " Donglin Peng
2023-04-03  0:54   ` Huacai Chen
2023-03-31 12:47 ` [PATCH v10 8/8] selftests/ftrace: Add funcgraph-retval test case Donglin Peng
2023-04-01 22:04   ` Masami Hiramatsu
2023-04-03  2:33     ` Donglin Peng
2023-04-03  5:01       ` Donglin Peng
2023-04-06 10:35         ` Donglin Peng

This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).