diff mbox series

[2/2] trace-cmd: Add ftrace options with fgraph retval option

Message ID 20240415154921.4998-3-jianfeng.w.wang@oracle.com (mailing list archive)
State New
Headers show
Series trace-cmd ftrace: support function retval feature in function_graph | expand

Commit Message

Jianfeng Wang April 15, 2024, 3:49 p.m. UTC
Added internal options for ftrace, and included a fgraph:retval
option that will print the function names at the function exit.
When the option is set and the function_graph retval feature is
supported by the kernel, each function's return value will be
printed as '(ret=retval)'.

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

Comments

Jianfeng Wang April 30, 2024, 10:45 p.m. UTC | #1
On 4/15/24 8:49 AM, Jianfeng Wang wrote:
> Added internal options for ftrace, and included a fgraph:retval
> option that will print the function names at the function exit.
> When the option is set and the function_graph retval feature is
> supported by the kernel, each function's return value will be
> printed as '(ret=retval)'.
> 
> Signed-off-by: Jianfeng Wang <jianfeng.w.wang@oracle.com>
> ---
>  lib/trace-cmd/trace-ftrace.c | 11 +++++++++--
>  1 file changed, 9 insertions(+), 2 deletions(-)
> 
> diff --git a/lib/trace-cmd/trace-ftrace.c b/lib/trace-cmd/trace-ftrace.c
> index cb05d88c..fecc3d69 100644
> --- a/lib/trace-cmd/trace-ftrace.c
> +++ b/lib/trace-cmd/trace-ftrace.c
> @@ -23,6 +23,12 @@ struct tep_plugin_option trace_ftrace_options[] = {
>  		.description =
>  		"Show the depth of each entry",
>  	},
> +	{
> +		.name = "retval",
> +		.plugin_alias = "fgraph",
> +		.description =
> +		"Print function retval at function exit in function graph",
> +	},
>  	{
>  		.name = NULL,
>  	}
> @@ -30,6 +36,7 @@ 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 = &trace_ftrace_options[2];
>  
>  static int find_ret_event(struct tracecmd_ftrace *finfo, struct tep_handle *pevent)
>  {
> @@ -232,7 +239,7 @@ print_graph_entry_leaf(struct trace_seq *s,
>  		ret = trace_seq_printf(s, " (%lld)", depth);
>  
>  	/* Return Value */
> -	if (ret && fgraph_retval_supported)
> +	if (ret && fgraph_retval->set && fgraph_retval_supported)
>  		ret = trace_seq_printf(s, " (ret=%lld)", retval);
>  
>  	return ret;
> @@ -378,7 +385,7 @@ fgraph_ret_handler(struct trace_seq *s, struct tep_record *record,
>  		trace_seq_printf(s, " (%lld)", depth);
>  
>  	/* Return Value */
> -	if (fgraph_retval_supported)
> +	if (fgraph_retval->set && fgraph_retval_supported)
>  		trace_seq_printf(s, " (ret=%lld)", retval);
>  
>  	return 0;

Kindly ask for reviews on this patchset :)

Here, I include a more detailed effect of this patchset.

* Record process
The trace-cmd record process is not changed.

# trace-cmd record -p function_graph -P 4331

trace-cmd can communicate with the kernel to get the actual funcgraph_exit
event format. If the kernel supports ftrace-retval, then trace-cmd will
use the updated event format that has "retval" field.

* Report process
By default, trace-cmd won't print each function's retval.

# trace-cmd report

However, if one wants to turn it on and the kernel supports the feature,
do the following (through fgraph plugin options):

# trace-cmd report -O fgraph:depth -O fgraph:tailprint -O fgraph:retval

The output looks like this:

  <idle>-0     [012] d....   361.071503: funcgraph_entry:                   |  switch_mm_irqs_off() { (0)
  <idle>-0     [012] d....   361.071507: funcgraph_entry:        0.491 us   |    load_new_mm_cr3(); (1) (ret=0)
  <idle>-0     [012] d....   361.071508: funcgraph_entry:        0.251 us   |    switch_ldt(); (1) (ret=0)
  <idle>-0     [012] d....   361.071508: funcgraph_exit:         5.901 us   |  } /* switch_mm_irqs_off */ (0) (ret=0)

Each function's return value will be printed at the function's return point.
Steven Rostedt April 30, 2024, 11:06 p.m. UTC | #2
On Tue, 30 Apr 2024 15:45:43 -0700
Jianfeng Wang <jianfeng.w.wang@oracle.com> wrote:

> Kindly ask for reviews on this patchset :)

I haven't forgotten these patches ;-)

I was hoping to get to the userspace side this month, but things came up on
the kernel side I had to take care of.

I'm hoping to get to them in then next week or so.

Thanks,

-- Steve
Steven Rostedt May 17, 2024, 12:53 a.m. UTC | #3
Finally got the time to look at these patches ;-)

On Mon, 15 Apr 2024 08:49:21 -0700
Jianfeng Wang <jianfeng.w.wang@oracle.com> wrote:

> +++ b/lib/trace-cmd/trace-ftrace.c
> @@ -23,6 +23,12 @@ struct tep_plugin_option trace_ftrace_options[] = {
>  		.description =
>  		"Show the depth of each entry",
>  	},
> +	{
> +		.name = "retval",
> +		.plugin_alias = "fgraph",
> +		.description =
> +		"Print function retval at function exit in function graph",
> +	},

Honestly, I don't think this should be an option. Or if it is, it
should be default on. If the retval exists in the trace, it should just
be printed. Why ask the user to show it when they spent the time to
enable it in the recording?

Thanks!

-- Steve

>  	{
>  		.name = NULL,
>  	}
Jianfeng Wang May 17, 2024, 6:50 p.m. UTC | #4
On 5/16/24 5:53 PM, Steven Rostedt wrote:
> 
> Finally got the time to look at these patches ;-)
> 
> On Mon, 15 Apr 2024 08:49:21 -0700
> Jianfeng Wang <jianfeng.w.wang@oracle.com> wrote:
> 
>> +++ b/lib/trace-cmd/trace-ftrace.c
>> @@ -23,6 +23,12 @@ struct tep_plugin_option trace_ftrace_options[] = {
>>  		.description =
>>  		"Show the depth of each entry",
>>  	},
>> +	{
>> +		.name = "retval",
>> +		.plugin_alias = "fgraph",
>> +		.description =
>> +		"Print function retval at function exit in function graph",
>> +	},
> 
> Honestly, I don't think this should be an option. Or if it is, it
> should be default on. If the retval exists in the trace, it should just
> be printed. Why ask the user to show it when they spent the time to
> enable it in the recording?
> 
> Thanks!
> 
> -- Steve
> 

Thanks for your response!

I make it a default-off option because the feature changes the output format of
the 'trace-cmd report'. So to be on the safe side, keep the original format by
default. Also, the kernel has options (i.e., options/funcgraph-retval and
options/funcgraph-retval-hex) to enable printing functions' retval in trace.log

From my point of view, I'd like to see the retval on by default. If you are
okay, I'd like to make it default on and add an option to display retval in hex.

>>  	{
>>  		.name = NULL,
>>  	}
Steven Rostedt May 17, 2024, 7 p.m. UTC | #5
On Fri, 17 May 2024 11:50:29 -0700
Jianfeng Wang <jianfeng.w.wang@oracle.com> wrote:

> > Honestly, I don't think this should be an option. Or if it is, it
> > should be default on. If the retval exists in the trace, it should just
> > be printed. Why ask the user to show it when they spent the time to
> > enable it in the recording?
> > 

> 
> I make it a default-off option because the feature changes the output format of
> the 'trace-cmd report'. So to be on the safe side, keep the original format by
> default. Also, the kernel has options (i.e., options/funcgraph-retval and
> options/funcgraph-retval-hex) to enable printing functions' retval in trace.log
> 
> >From my point of view, I'd like to see the retval on by default. If you are  
> okay, I'd like to make it default on and add an option to display retval in hex.

Yeah, we can keep both as an option, but make the retval default on.

It will not change default behavior, as it should only be shown if retval
was recorded in the first place. If it wasn't recorded, the behavior should
be the same regardless of if the retval option is enabled or not in the
trace-cmd output.

-- Steve
Jianfeng Wang May 17, 2024, 7:23 p.m. UTC | #6
On 5/17/24 12:00 PM, Steven Rostedt wrote:
> On Fri, 17 May 2024 11:50:29 -0700
> Jianfeng Wang <jianfeng.w.wang@oracle.com> wrote:
> 
>>> Honestly, I don't think this should be an option. Or if it is, it
>>> should be default on. If the retval exists in the trace, it should just
>>> be printed. Why ask the user to show it when they spent the time to
>>> enable it in the recording?
>>>
> 
>>
>> I make it a default-off option because the feature changes the output format of
>> the 'trace-cmd report'. So to be on the safe side, keep the original format by
>> default. Also, the kernel has options (i.e., options/funcgraph-retval and
>> options/funcgraph-retval-hex) to enable printing functions' retval in trace.log
>>
>> >From my point of view, I'd like to see the retval on by default. If you are  
>> okay, I'd like to make it default on and add an option to display retval in hex.
> 
> Yeah, we can keep both as an option, but make the retval default on.
> 
> It will not change default behavior, as it should only be shown if retval
> was recorded in the first place. If it wasn't recorded, the behavior should
> be the same regardless of if the retval option is enabled or not in the
> trace-cmd output.
> 
> -- Steve

SGTM. I will send a v2.

Thanks,
Jianfeng
diff mbox series

Patch

diff --git a/lib/trace-cmd/trace-ftrace.c b/lib/trace-cmd/trace-ftrace.c
index cb05d88c..fecc3d69 100644
--- a/lib/trace-cmd/trace-ftrace.c
+++ b/lib/trace-cmd/trace-ftrace.c
@@ -23,6 +23,12 @@  struct tep_plugin_option trace_ftrace_options[] = {
 		.description =
 		"Show the depth of each entry",
 	},
+	{
+		.name = "retval",
+		.plugin_alias = "fgraph",
+		.description =
+		"Print function retval at function exit in function graph",
+	},
 	{
 		.name = NULL,
 	}
@@ -30,6 +36,7 @@  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 = &trace_ftrace_options[2];
 
 static int find_ret_event(struct tracecmd_ftrace *finfo, struct tep_handle *pevent)
 {
@@ -232,7 +239,7 @@  print_graph_entry_leaf(struct trace_seq *s,
 		ret = trace_seq_printf(s, " (%lld)", depth);
 
 	/* Return Value */
-	if (ret && fgraph_retval_supported)
+	if (ret && fgraph_retval->set && fgraph_retval_supported)
 		ret = trace_seq_printf(s, " (ret=%lld)", retval);
 
 	return ret;
@@ -378,7 +385,7 @@  fgraph_ret_handler(struct trace_seq *s, struct tep_record *record,
 		trace_seq_printf(s, " (%lld)", depth);
 
 	/* Return Value */
-	if (fgraph_retval_supported)
+	if (fgraph_retval->set && fgraph_retval_supported)
 		trace_seq_printf(s, " (ret=%lld)", retval);
 
 	return 0;