linux-trace-devel.vger.kernel.org archive mirror
 help / color / mirror / Atom feed
* [PATCH v2 0/2] trace-cmd ftrace: support function retval feature in function_graph
@ 2024-05-21 21:37 Jianfeng Wang
  2024-05-21 21:37 ` [PATCH v2 1/2] trace-cmd ftrace: print function retval " Jianfeng Wang
  2024-05-21 21:37 ` [PATCH v2 2/2] trace-cmd: Add ftrace options for the fgraph retval feature Jianfeng Wang
  0 siblings, 2 replies; 7+ messages in thread
From: Jianfeng Wang @ 2024-05-21 21:37 UTC (permalink / raw)
  To: linux-trace-devel; +Cc: rostedt, jianfeng.w.wang, junxiao.bi

The upstream Linux kernel has introduced a funcgraph retval feature
for the function_graph tracer. (Commit ID:
a1be9ccc57f07d54278be34eed6bd679bc941c97). This patchset is to utilize
this feature to support printing each function's return value in
'trace-cmd report'. Add two fgraph options so that users can skip
the printing or force the return values to be printed in hex.

Change history:
===============
v2:
- Check if a retval is an error code: if not, print it in hex.
- Make this retval feature on by default.
- Add fgraph:retval-skip and fgraph:retval-hex options.

v1: https://lore.kernel.org/linux-trace-devel/20240415154921.4998-1-jianfeng.w.wang@oracle.com


Jianfeng Wang (2):
  trace-cmd ftrace: print function retval in function_graph
  trace-cmd: Add ftrace options for the fgraph retval feature

 lib/trace-cmd/trace-ftrace.c | 51 ++++++++++++++++++++++++++++++++++++
 1 file changed, 51 insertions(+)

-- 
2.42.1


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

* [PATCH v2 1/2] trace-cmd ftrace: print function retval in function_graph
  2024-05-21 21:37 [PATCH v2 0/2] trace-cmd ftrace: support function retval feature in function_graph Jianfeng Wang
@ 2024-05-21 21:37 ` Jianfeng Wang
  2024-07-17 18:48   ` Steven Rostedt
  2024-05-21 21:37 ` [PATCH v2 2/2] trace-cmd: Add ftrace options for the fgraph retval feature Jianfeng Wang
  1 sibling, 1 reply; 7+ messages in thread
From: Jianfeng Wang @ 2024-05-21 21:37 UTC (permalink / raw)
  To: linux-trace-devel; +Cc: rostedt, jianfeng.w.wang, junxiao.bi

The upstream Linux kernel has introduced a new feature, i.e.
funcgraph-retval for the function_graph tracer. (Commit ID:
a1be9ccc57f07d54278be34eed6bd679bc941c97). With this feature, the
function_graph tracer can record each function's return value along
with its execution time at the function_graph exit handler. This is
useful for debugging kernel issues, such as syscall errors.

This commit enhances 'trace-cmd report' by supporting the
function_graph retval feature if the underlying kernel supports it.
Once the feature is supported, 'trace-cmd report' will print each
function's return value in this format: '(ret=retval)" at the end
of every funcgraph leaf entry and exit event.

Example usage:
*  Record
> trace-cmd record -p function_graph -P <pid>

The recording process is not changed: trace-cmd can communicate
with the kernel to get the actual funcgraph_exit event format.
If the kernel supports ftrace-retval, trace-cmd will use the
updated event format that has "retval" field.

* Report
> trace-cmd report -O fgraph:depth -O fgraph:tailprint

If the kernel supports this feature, the output looks like this:

 <...>-1136215 [006] ..... 1724848.377495: funcgraph_entry:                   |        __cond_resched() { (3)
 <...>-1136215 [006] ..... 1724848.377495: funcgraph_entry:        0.200 us   |          rcu_all_qs(); (4) (ret=0x0)
 <...>-1136215 [006] ..... 1724848.377496: funcgraph_exit:         0.601 us   |        } /* __cond_resched */ (3) (ret=0x0)
 <...>-1136215 [006] ..... 1724848.377496: funcgraph_entry:        0.581 us   |        proc_reg_write(); (3) (ret=-5)
 <...>-1136215 [006] ..... 1724848.377497: funcgraph_exit:         5.059 us   |      } /* vfs_write */ (2) (ret=-5)
 <...>-1136215 [006] ..... 1724848.377497: funcgraph_exit:         6.332 us   |    } /* ksys_write */ (1) (ret=-5)
 <...>-1136215 [006] ..... 1724848.377497: funcgraph_exit:       + 18.414 us  |  } /* __x64_sys_write */ (0) (ret=-5)

Signed-off-by: Jianfeng Wang <jianfeng.w.wang@oracle.com>
---
 lib/trace-cmd/trace-ftrace.c | 37 ++++++++++++++++++++++++++++++++++++
 1 file changed, 37 insertions(+)

diff --git a/lib/trace-cmd/trace-ftrace.c b/lib/trace-cmd/trace-ftrace.c
index 89e46c3d..2b4e49a5 100644
--- a/lib/trace-cmd/trace-ftrace.c
+++ b/lib/trace-cmd/trace-ftrace.c
@@ -10,6 +10,9 @@
 
 #include "trace-cmd-private.h"
 
+#define MAX_LINUX_ERRNO   4095
+#define IS_LINUX_ERR_VALUE(x) ((unsigned long long)(void *)(x) >= (unsigned long long)-MAX_LINUX_ERRNO)
+
 struct tep_plugin_option trace_ftrace_options[] = {
 	{
 		.name = "tailprint",
@@ -185,6 +188,8 @@ print_graph_entry_leaf(struct trace_seq *s,
 	unsigned long long rettime, calltime;
 	unsigned long long duration, depth;
 	unsigned long long val;
+	unsigned long long retval;
+	bool fgraph_retval_supported = true;
 	const char *func;
 	int ret;
 	int i;
@@ -195,6 +200,13 @@ print_graph_entry_leaf(struct trace_seq *s,
 	if (tep_get_field_val(s, finfo->fgraph_ret_event, "calltime", ret_rec, &calltime, 1))
 		return trace_seq_putc(s, '!');
 
+	if (!tep_find_field(finfo->fgraph_ret_event, "retval"))
+		fgraph_retval_supported = false;
+	else {
+		if (tep_get_field_val(s, finfo->fgraph_ret_event, "retval", ret_rec, &retval, 1))
+			return trace_seq_putc(s, '!');
+	}
+
 	duration = rettime - calltime;
 
 	/* Overhead */
@@ -222,6 +234,14 @@ print_graph_entry_leaf(struct trace_seq *s,
 	if (ret && fgraph_depth->set)
 		ret = trace_seq_printf(s, " (%lld)", depth);
 
+	/* Return Value */
+	if (ret && fgraph_retval_supported) {
+		if (!IS_LINUX_ERR_VALUE(retval))
+			ret = trace_seq_printf(s, " (ret=0x%llx)", retval);
+		else
+			ret = trace_seq_printf(s, " (ret=%lld)", retval);
+	}
+
 	return ret;
 }
 
@@ -316,6 +336,8 @@ fgraph_ret_handler(struct trace_seq *s, struct tep_record *record,
 	unsigned long long duration, depth;
 	unsigned long long val;
 	const char *func;
+	unsigned long long retval;
+	bool fgraph_retval_supported = true;
 	int i;
 
 	ret_event_check(finfo, event->tep);
@@ -326,6 +348,13 @@ fgraph_ret_handler(struct trace_seq *s, struct tep_record *record,
 	if (tep_get_field_val(s, event, "calltime", record, &calltime, 1))
 		return trace_seq_putc(s, '!');
 
+	if (!tep_find_field(event, "retval"))
+		fgraph_retval_supported = false;
+	else {
+		if (tep_get_field_val(s, event, "retval", record, &retval, 1))
+			return trace_seq_putc(s, '!');
+	}
+
 	duration = rettime - calltime;
 
 	/* Overhead */
@@ -355,6 +384,14 @@ fgraph_ret_handler(struct trace_seq *s, struct tep_record *record,
 	if (fgraph_depth->set)
 		trace_seq_printf(s, " (%lld)", depth);
 
+	/* Return Value */
+	if (fgraph_retval_supported) {
+		if (!IS_LINUX_ERR_VALUE(retval))
+			trace_seq_printf(s, " (ret=0x%llx)", retval);
+		else
+			trace_seq_printf(s, " (ret=%lld)", retval);
+	}
+
 	return 0;
 }
 
-- 
2.42.1


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

* [PATCH v2 2/2] trace-cmd: Add ftrace options for the fgraph retval feature
  2024-05-21 21:37 [PATCH v2 0/2] trace-cmd ftrace: support function retval feature in function_graph Jianfeng Wang
  2024-05-21 21:37 ` [PATCH v2 1/2] trace-cmd ftrace: print function retval " Jianfeng Wang
@ 2024-05-21 21:37 ` Jianfeng Wang
  2024-07-17 18:50   ` Steven Rostedt
  1 sibling, 1 reply; 7+ messages in thread
From: Jianfeng Wang @ 2024-05-21 21:37 UTC (permalink / raw)
  To: linux-trace-devel; +Cc: rostedt, jianfeng.w.wang, junxiao.bi

Add two internal options for fgraph: fgraph:retval-skip and
fgraph:retval-hex. By default, trace-cmd will print each function's
return value at the function_graph exit point, if the kernel supports
the fgraph-retval feature. If users want to skip the output of
functions' return values, then set fgraph:retval-skip. Alternatively,
users can set fgraph:retval-hex to force the return values to be
printed in hex format.

Here are example commands:
> trace-cmd report -O fgraph:retval-skip
> trace-cmd report -O fgraph:retval-hex

Signed-off-by: Jianfeng Wang <jianfeng.w.wang@oracle.com>
---
 lib/trace-cmd/trace-ftrace.c | 22 ++++++++++++++++++----
 1 file changed, 18 insertions(+), 4 deletions(-)

diff --git a/lib/trace-cmd/trace-ftrace.c b/lib/trace-cmd/trace-ftrace.c
index 2b4e49a5..d2378833 100644
--- a/lib/trace-cmd/trace-ftrace.c
+++ b/lib/trace-cmd/trace-ftrace.c
@@ -26,6 +26,18 @@ struct tep_plugin_option trace_ftrace_options[] = {
 		.description =
 		"Show the depth of each entry",
 	},
+	{
+		.name = "retval-skip",
+		.plugin_alias = "fgraph",
+		.description =
+		"Skip printing function retval in function graph",
+	},
+	{
+		.name = "retval-hex",
+		.plugin_alias = "fgraph",
+		.description =
+		"Print function retval in hex at function exit in function graph",
+	},
 	{
 		.name = NULL,
 	}
@@ -33,6 +45,8 @@ struct tep_plugin_option trace_ftrace_options[] = {
 
 static struct tep_plugin_option *fgraph_tail = &trace_ftrace_options[0];
 static struct tep_plugin_option *fgraph_depth = &trace_ftrace_options[1];
+static struct tep_plugin_option *fgraph_retval_skip = &trace_ftrace_options[2];
+static struct tep_plugin_option *fgraph_retval_hex = &trace_ftrace_options[3];
 
 static int find_ret_event(struct tracecmd_ftrace *finfo, struct tep_handle *pevent)
 {
@@ -235,8 +249,8 @@ print_graph_entry_leaf(struct trace_seq *s,
 		ret = trace_seq_printf(s, " (%lld)", depth);
 
 	/* Return Value */
-	if (ret && fgraph_retval_supported) {
-		if (!IS_LINUX_ERR_VALUE(retval))
+	if (ret && fgraph_retval_supported && !fgraph_retval_skip->set) {
+		if (fgraph_retval_hex->set || !IS_LINUX_ERR_VALUE(retval))
 			ret = trace_seq_printf(s, " (ret=0x%llx)", retval);
 		else
 			ret = trace_seq_printf(s, " (ret=%lld)", retval);
@@ -385,8 +399,8 @@ fgraph_ret_handler(struct trace_seq *s, struct tep_record *record,
 		trace_seq_printf(s, " (%lld)", depth);
 
 	/* Return Value */
-	if (fgraph_retval_supported) {
-		if (!IS_LINUX_ERR_VALUE(retval))
+	if (fgraph_retval_supported && !fgraph_retval_skip->set) {
+		if (fgraph_retval_hex->set || !IS_LINUX_ERR_VALUE(retval))
 			trace_seq_printf(s, " (ret=0x%llx)", retval);
 		else
 			trace_seq_printf(s, " (ret=%lld)", retval);
-- 
2.42.1


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

* Re: [PATCH v2 1/2] trace-cmd ftrace: print function retval in function_graph
  2024-05-21 21:37 ` [PATCH v2 1/2] trace-cmd ftrace: print function retval " Jianfeng Wang
@ 2024-07-17 18:48   ` Steven Rostedt
  0 siblings, 0 replies; 7+ messages in thread
From: Steven Rostedt @ 2024-07-17 18:48 UTC (permalink / raw)
  To: Jianfeng Wang; +Cc: linux-trace-devel, junxiao.bi


Sorry for the late reply, I'm finally able to look at userspace tooling.

First little nit, please start the subject with a capital letter:

  trace-cmd report: Print function retval in function_graph

Also note that it's for the report command.

On Tue, 21 May 2024 14:37:29 -0700
Jianfeng Wang <jianfeng.w.wang@oracle.com> wrote:

> The upstream Linux kernel has introduced a new feature, i.e.
> funcgraph-retval for the function_graph tracer. (Commit ID:
> a1be9ccc57f07d54278be34eed6bd679bc941c97). With this feature, the
> function_graph tracer can record each function's return value along
> with its execution time at the function_graph exit handler. This is
> useful for debugging kernel issues, such as syscall errors.
> 
> This commit enhances 'trace-cmd report' by supporting the
> function_graph retval feature if the underlying kernel supports it.
> Once the feature is supported, 'trace-cmd report' will print each
> function's return value in this format: '(ret=retval)" at the end
> of every funcgraph leaf entry and exit event.
> 
> Example usage:
> *  Record
> > trace-cmd record -p function_graph -P <pid>  
> 
> The recording process is not changed: trace-cmd can communicate
> with the kernel to get the actual funcgraph_exit event format.
> If the kernel supports ftrace-retval, trace-cmd will use the
> updated event format that has "retval" field.
> 
> * Report
> > trace-cmd report -O fgraph:depth -O fgraph:tailprint  
> 
> If the kernel supports this feature, the output looks like this:
> 
>  <...>-1136215 [006] ..... 1724848.377495: funcgraph_entry:                   |        __cond_resched() { (3)
>  <...>-1136215 [006] ..... 1724848.377495: funcgraph_entry:        0.200 us   |          rcu_all_qs(); (4) (ret=0x0)
>  <...>-1136215 [006] ..... 1724848.377496: funcgraph_exit:         0.601 us   |        } /* __cond_resched */ (3) (ret=0x0)
>  <...>-1136215 [006] ..... 1724848.377496: funcgraph_entry:        0.581 us   |        proc_reg_write(); (3) (ret=-5)
>  <...>-1136215 [006] ..... 1724848.377497: funcgraph_exit:         5.059 us   |      } /* vfs_write */ (2) (ret=-5)
>  <...>-1136215 [006] ..... 1724848.377497: funcgraph_exit:         6.332 us   |    } /* ksys_write */ (1) (ret=-5)
>  <...>-1136215 [006] ..... 1724848.377497: funcgraph_exit:       + 18.414 us  |  } /* __x64_sys_write */ (0) (ret=-5)
> 
> Signed-off-by: Jianfeng Wang <jianfeng.w.wang@oracle.com>
> ---
>  lib/trace-cmd/trace-ftrace.c | 37 ++++++++++++++++++++++++++++++++++++
>  1 file changed, 37 insertions(+)
> 
> diff --git a/lib/trace-cmd/trace-ftrace.c b/lib/trace-cmd/trace-ftrace.c
> index 89e46c3d..2b4e49a5 100644
> --- a/lib/trace-cmd/trace-ftrace.c
> +++ b/lib/trace-cmd/trace-ftrace.c
> @@ -10,6 +10,9 @@
>  
>  #include "trace-cmd-private.h"
>  
> +#define MAX_LINUX_ERRNO   4095
> +#define IS_LINUX_ERR_VALUE(x) ((unsigned long long)(void *)(x) >= (unsigned long long)-MAX_LINUX_ERRNO)
> +
>  struct tep_plugin_option trace_ftrace_options[] = {
>  	{
>  		.name = "tailprint",
> @@ -185,6 +188,8 @@ print_graph_entry_leaf(struct trace_seq *s,
>  	unsigned long long rettime, calltime;
>  	unsigned long long duration, depth;
>  	unsigned long long val;
> +	unsigned long long retval;
> +	bool fgraph_retval_supported = true;
>  	const char *func;
>  	int ret;
>  	int i;
> @@ -195,6 +200,13 @@ print_graph_entry_leaf(struct trace_seq *s,
>  	if (tep_get_field_val(s, finfo->fgraph_ret_event, "calltime", ret_rec, &calltime, 1))
>  		return trace_seq_putc(s, '!');
>  
> +	if (!tep_find_field(finfo->fgraph_ret_event, "retval"))
> +		fgraph_retval_supported = false;
> +	else {

This should follow Linux kernel syntax rules. That is, if one block of
a if statement has brackets, then the other should too.

Thanks,

-- Steve

> +		if (tep_get_field_val(s, finfo->fgraph_ret_event, "retval", ret_rec, &retval, 1))
> +			return trace_seq_putc(s, '!');
> +	}
> +
>  	duration = rettime - calltime;

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

* Re: [PATCH v2 2/2] trace-cmd: Add ftrace options for the fgraph retval feature
  2024-05-21 21:37 ` [PATCH v2 2/2] trace-cmd: Add ftrace options for the fgraph retval feature Jianfeng Wang
@ 2024-07-17 18:50   ` Steven Rostedt
  2024-07-17 20:44     ` Jianfeng Wang
  0 siblings, 1 reply; 7+ messages in thread
From: Steven Rostedt @ 2024-07-17 18:50 UTC (permalink / raw)
  To: Jianfeng Wang; +Cc: linux-trace-devel, junxiao.bi

On Tue, 21 May 2024 14:37:30 -0700
Jianfeng Wang <jianfeng.w.wang@oracle.com> wrote:

> Add two internal options for fgraph: fgraph:retval-skip and
> fgraph:retval-hex. By default, trace-cmd will print each function's
> return value at the function_graph exit point, if the kernel supports
> the fgraph-retval feature. If users want to skip the output of
> functions' return values, then set fgraph:retval-skip. Alternatively,
> users can set fgraph:retval-hex to force the return values to be
> printed in hex format.
> 
> Here are example commands:
> > trace-cmd report -O fgraph:retval-skip
> > trace-cmd report -O fgraph:retval-hex  

I would like to see a -O fgraph:retval-dec

As by default most is shown in hex, having an option to do that would
be great.

-- Steve


> 
> Signed-off-by: Jianfeng Wang <jianfeng.w.wang@oracle.com>
> ---
>  lib/trace-cmd/trace-ftrace.c | 22 ++++++++++++++++++----
>  1 file changed, 18 insertions(+), 4 deletions(-)
> 
> diff --git a/lib/trace-cmd/trace-ftrace.c b/lib/trace-cmd/trace-ftrace.c
> index 2b4e49a5..d2378833 100644
> --- a/lib/trace-cmd/trace-ftrace.c
> +++ b/lib/trace-cmd/trace-ftrace.c
> @@ -26,6 +26,18 @@ struct tep_plugin_option trace_ftrace_options[] = {
>  		.description =
>  		"Show the depth of each entry",
>  	},
> +	{
> +		.name = "retval-skip",
> +		.plugin_alias = "fgraph",
> +		.description =
> +		"Skip printing function retval in function graph",
> +	},
> +	{
> +		.name = "retval-hex",
> +		.plugin_alias = "fgraph",
> +		.description =
> +		"Print function retval in hex at function exit in function graph",
> +	},
>  	{
>  		.name = NULL,
>  	}
> @@ -33,6 +45,8 @@ struct tep_plugin_option trace_ftrace_options[] = {
>  
>  static struct tep_plugin_option *fgraph_tail = &trace_ftrace_options[0];
>  static struct tep_plugin_option *fgraph_depth = &trace_ftrace_options[1];
> +static struct tep_plugin_option *fgraph_retval_skip = &trace_ftrace_options[2];
> +static struct tep_plugin_option *fgraph_retval_hex = &trace_ftrace_options[3];
>  
>  static int find_ret_event(struct tracecmd_ftrace *finfo, struct tep_handle *pevent)
>  {
> @@ -235,8 +249,8 @@ print_graph_entry_leaf(struct trace_seq *s,
>  		ret = trace_seq_printf(s, " (%lld)", depth);
>  
>  	/* Return Value */
> -	if (ret && fgraph_retval_supported) {
> -		if (!IS_LINUX_ERR_VALUE(retval))
> +	if (ret && fgraph_retval_supported && !fgraph_retval_skip->set) {
> +		if (fgraph_retval_hex->set || !IS_LINUX_ERR_VALUE(retval))
>  			ret = trace_seq_printf(s, " (ret=0x%llx)", retval);
>  		else
>  			ret = trace_seq_printf(s, " (ret=%lld)", retval);
> @@ -385,8 +399,8 @@ fgraph_ret_handler(struct trace_seq *s, struct tep_record *record,
>  		trace_seq_printf(s, " (%lld)", depth);
>  
>  	/* Return Value */
> -	if (fgraph_retval_supported) {
> -		if (!IS_LINUX_ERR_VALUE(retval))
> +	if (fgraph_retval_supported && !fgraph_retval_skip->set) {
> +		if (fgraph_retval_hex->set || !IS_LINUX_ERR_VALUE(retval))
>  			trace_seq_printf(s, " (ret=0x%llx)", retval);
>  		else
>  			trace_seq_printf(s, " (ret=%lld)", retval);


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

* Re: [PATCH v2 2/2] trace-cmd: Add ftrace options for the fgraph retval feature
  2024-07-17 18:50   ` Steven Rostedt
@ 2024-07-17 20:44     ` Jianfeng Wang
  2024-07-17 20:58       ` Steven Rostedt
  0 siblings, 1 reply; 7+ messages in thread
From: Jianfeng Wang @ 2024-07-17 20:44 UTC (permalink / raw)
  To: Steven Rostedt; +Cc: linux-trace-devel



On 7/17/24 11:50 AM, Steven Rostedt wrote:
> On Tue, 21 May 2024 14:37:30 -0700
> Jianfeng Wang <jianfeng.w.wang@oracle.com> wrote:
> 
>> Add two internal options for fgraph: fgraph:retval-skip and
>> fgraph:retval-hex. By default, trace-cmd will print each function's
>> return value at the function_graph exit point, if the kernel supports
>> the fgraph-retval feature. If users want to skip the output of
>> functions' return values, then set fgraph:retval-skip. Alternatively,
>> users can set fgraph:retval-hex to force the return values to be
>> printed in hex format.
>>
>> Here are example commands:
>>> trace-cmd report -O fgraph:retval-skip
>>> trace-cmd report -O fgraph:retval-hex  
> 
> I would like to see a -O fgraph:retval-dec
> 
> As by default most is shown in hex, having an option to do that would
> be great.
> 
> -- Steve
> 
> 

Hi Steve,

Sorry, I am confused about this.

Do you suggesting adding one more option fgraph:retval-dec or
replacing fgraph:retval-hex with fgraph:retval-dec (and making the hex
format as the default)?

Currently, the patch prints return values in decimal by default
(without any input), while users can specify fgraph:retval-hex to let
numbers printed in hex.

Thanks for your comments.

Best,
-Jianfeng

>>
>> Signed-off-by: Jianfeng Wang <jianfeng.w.wang@oracle.com>
>> ---
>>  lib/trace-cmd/trace-ftrace.c | 22 ++++++++++++++++++----
>>  1 file changed, 18 insertions(+), 4 deletions(-)
>>
>> diff --git a/lib/trace-cmd/trace-ftrace.c b/lib/trace-cmd/trace-ftrace.c
>> index 2b4e49a5..d2378833 100644
>> --- a/lib/trace-cmd/trace-ftrace.c
>> +++ b/lib/trace-cmd/trace-ftrace.c
>> @@ -26,6 +26,18 @@ struct tep_plugin_option trace_ftrace_options[] = {
>>  		.description =
>>  		"Show the depth of each entry",
>>  	},
>> +	{
>> +		.name = "retval-skip",
>> +		.plugin_alias = "fgraph",
>> +		.description =
>> +		"Skip printing function retval in function graph",
>> +	},
>> +	{
>> +		.name = "retval-hex",
>> +		.plugin_alias = "fgraph",
>> +		.description =
>> +		"Print function retval in hex at function exit in function graph",
>> +	},
>>  	{
>>  		.name = NULL,
>>  	}
>> @@ -33,6 +45,8 @@ struct tep_plugin_option trace_ftrace_options[] = {
>>  
>>  static struct tep_plugin_option *fgraph_tail = &trace_ftrace_options[0];
>>  static struct tep_plugin_option *fgraph_depth = &trace_ftrace_options[1];
>> +static struct tep_plugin_option *fgraph_retval_skip = &trace_ftrace_options[2];
>> +static struct tep_plugin_option *fgraph_retval_hex = &trace_ftrace_options[3];
>>  
>>  static int find_ret_event(struct tracecmd_ftrace *finfo, struct tep_handle *pevent)
>>  {
>> @@ -235,8 +249,8 @@ print_graph_entry_leaf(struct trace_seq *s,
>>  		ret = trace_seq_printf(s, " (%lld)", depth);
>>  
>>  	/* Return Value */
>> -	if (ret && fgraph_retval_supported) {
>> -		if (!IS_LINUX_ERR_VALUE(retval))
>> +	if (ret && fgraph_retval_supported && !fgraph_retval_skip->set) {
>> +		if (fgraph_retval_hex->set || !IS_LINUX_ERR_VALUE(retval))
>>  			ret = trace_seq_printf(s, " (ret=0x%llx)", retval);
>>  		else
>>  			ret = trace_seq_printf(s, " (ret=%lld)", retval);
>> @@ -385,8 +399,8 @@ fgraph_ret_handler(struct trace_seq *s, struct tep_record *record,
>>  		trace_seq_printf(s, " (%lld)", depth);
>>  
>>  	/* Return Value */
>> -	if (fgraph_retval_supported) {
>> -		if (!IS_LINUX_ERR_VALUE(retval))
>> +	if (fgraph_retval_supported && !fgraph_retval_skip->set) {
>> +		if (fgraph_retval_hex->set || !IS_LINUX_ERR_VALUE(retval))
>>  			trace_seq_printf(s, " (ret=0x%llx)", retval);
>>  		else
>>  			trace_seq_printf(s, " (ret=%lld)", retval);
> 

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

* Re: [PATCH v2 2/2] trace-cmd: Add ftrace options for the fgraph retval feature
  2024-07-17 20:44     ` Jianfeng Wang
@ 2024-07-17 20:58       ` Steven Rostedt
  0 siblings, 0 replies; 7+ messages in thread
From: Steven Rostedt @ 2024-07-17 20:58 UTC (permalink / raw)
  To: Jianfeng Wang; +Cc: linux-trace-devel

On Wed, 17 Jul 2024 13:44:43 -0700
Jianfeng Wang <jianfeng.w.wang@oracle.com> wrote:

> On 7/17/24 11:50 AM, Steven Rostedt wrote:
> > On Tue, 21 May 2024 14:37:30 -0700
> > Jianfeng Wang <jianfeng.w.wang@oracle.com> wrote:
> >   
> >> Add two internal options for fgraph: fgraph:retval-skip and
> >> fgraph:retval-hex. By default, trace-cmd will print each function's
> >> return value at the function_graph exit point, if the kernel supports
> >> the fgraph-retval feature. If users want to skip the output of
> >> functions' return values, then set fgraph:retval-skip. Alternatively,
> >> users can set fgraph:retval-hex to force the return values to be
> >> printed in hex format.
> >>
> >> Here are example commands:  
> >>> trace-cmd report -O fgraph:retval-skip
> >>> trace-cmd report -O fgraph:retval-hex    
> > 
> > I would like to see a -O fgraph:retval-dec
> > 
> > As by default most is shown in hex, having an option to do that would
> > be great.
> > 
> > -- Steve
> > 
> >   
> 
> Hi Steve,
> 
> Sorry, I am confused about this.
> 
> Do you suggesting adding one more option fgraph:retval-dec or
> replacing fgraph:retval-hex with fgraph:retval-dec (and making the hex
> format as the default)?

I'd be happy to add both.

> 
> Currently, the patch prints return values in decimal by default
> (without any input), while users can specify fgraph:retval-hex to let
> numbers printed in hex.

It does?

I don't see that:

 $ trace-cmd report
[..]
           sleep-898   [006] ...1.   206.855186: funcgraph_entry:                   |  mutex_unlock() {
           sleep-898   [006] ...1.   206.855188: funcgraph_entry:        1.439 us   |    __mutex_unlock_slowpath(); (ret=0x0)
           sleep-898   [006] .....   206.855191: funcgraph_exit:         4.828 us   |  } (ret=0x0)
           sleep-898   [006] ...1.   206.855192: funcgraph_entry:        0.781 us   |  preempt_count_add(); (ret=0x202)
           sleep-898   [006] ...2.   206.855193: funcgraph_entry:                   |  rcu_read_lock_any_held() {
           sleep-898   [006] ...2.   206.855194: funcgraph_entry:        0.738 us   |    rcu_lockdep_current_cpu_online(); (ret=0x1)
           sleep-898   [006] ...1.   206.855195: funcgraph_exit:         2.243 us   |  } (ret=0x1)
           sleep-898   [006] ...2.   206.855196: funcgraph_entry:        0.814 us   |  preempt_count_sub(); (ret=0x2f3e8)
           sleep-898   [006] ...1.   206.855198: funcgraph_entry:                   |  __f_unlock_pos() {
           sleep-898   [006] ...1.   206.855199: funcgraph_entry:                   |    mutex_unlock() {
           sleep-898   [006] ...1.   206.855199: funcgraph_entry:        0.851 us   |      __mutex_unlock_slowpath(); (ret=0x0)
           sleep-898   [006] .....   206.855201: funcgraph_exit:         2.426 us   |    } (ret=0x0)
           sleep-898   [006] .....   206.855202: funcgraph_exit:         3.994 us   |  } (ret=0x0)

> >> @@ -235,8 +249,8 @@ print_graph_entry_leaf(struct trace_seq *s,
> >>  		ret = trace_seq_printf(s, " (%lld)", depth);
> >>  
> >>  	/* Return Value */
> >> -	if (ret && fgraph_retval_supported) {
> >> -		if (!IS_LINUX_ERR_VALUE(retval))
> >> +	if (ret && fgraph_retval_supported && !fgraph_retval_skip->set) {
> >> +		if (fgraph_retval_hex->set || !IS_LINUX_ERR_VALUE(retval))

It prints out hex if the value is not an error. Only errors show
decimal output.

-- Steve

> >>  			ret = trace_seq_printf(s, " (ret=0x%llx)", retval);
> >>  		else
> >>  			ret = trace_seq_printf(s, " (ret=%lld)", retval);
> >> @@ -385,8 +399,8 @@ fgraph_ret_handler(struct trace_seq *s, struct tep_record *record,
> >>  		trace_seq_printf(s, " (%lld)", depth);
> >>  
> >>  	/* Return Value */
> >> -	if (fgraph_retval_supported) {
> >> -		if (!IS_LINUX_ERR_VALUE(retval))
> >> +	if (fgraph_retval_supported && !fgraph_retval_skip->set) {
> >> +		if (fgraph_retval_hex->set || !IS_LINUX_ERR_VALUE(retval))
> >>  			trace_seq_printf(s, " (ret=0x%llx)", retval);
> >>  		else
> >>  			trace_seq_printf(s, " (ret=%lld)", retval);  
> >   


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

end of thread, other threads:[~2024-07-17 20:58 UTC | newest]

Thread overview: 7+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2024-05-21 21:37 [PATCH v2 0/2] trace-cmd ftrace: support function retval feature in function_graph Jianfeng Wang
2024-05-21 21:37 ` [PATCH v2 1/2] trace-cmd ftrace: print function retval " Jianfeng Wang
2024-07-17 18:48   ` Steven Rostedt
2024-05-21 21:37 ` [PATCH v2 2/2] trace-cmd: Add ftrace options for the fgraph retval feature Jianfeng Wang
2024-07-17 18:50   ` Steven Rostedt
2024-07-17 20:44     ` Jianfeng Wang
2024-07-17 20:58       ` Steven Rostedt

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).