Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]


Groups > linux.kernel > #1471521 > unrolled thread

[PATCH] ftrace: Access ret_stack->subtime only in the function profiler

Started byNamhyung Kim <namhyung@kernel.org>
First post2016-08-29 05:10 +0200
Last post2016-08-31 04:20 +0200
Articles 6 — 2 participants

Back to article view | Back to linux.kernel


Contents

  [PATCH] ftrace: Access ret_stack->subtime only in the function profiler Namhyung Kim <namhyung@kernel.org> - 2016-08-29 05:10 +0200
    Re: [PATCH] ftrace: Access ret_stack->subtime only in the function  profiler Steven Rostedt <rostedt@goodmis.org> - 2016-08-29 22:10 +0200
      Re: [PATCH] ftrace: Access ret_stack->subtime only in the function  profiler Namhyung Kim <namhyung@kernel.org> - 2016-08-30 03:40 +0200
        Re: [PATCH] ftrace: Access ret_stack->subtime only in the function  profiler Steven Rostedt <rostedt@goodmis.org> - 2016-08-31 04:20 +0200
          Re: [PATCH] ftrace: Access ret_stack->subtime only in the function  profiler Namhyung Kim <namhyung@kernel.org> - 2016-08-31 04:40 +0200
        Re: [PATCH] ftrace: Access ret_stack->subtime only in the function  profiler Namhyung Kim <namhyung@kernel.org> - 2016-08-31 04:20 +0200

#1471521 — [PATCH] ftrace: Access ret_stack->subtime only in the function profiler

FromNamhyung Kim <namhyung@kernel.org>
Date2016-08-29 05:10 +0200
Subject[PATCH] ftrace: Access ret_stack->subtime only in the function profiler
Message-ID<sbl7r-1TO-3@gated-at.bofh.it>
The subtime is used only for function profiler with function graph
tracer enabled.  Move the definition of subtime under
CONFIG_FUNCTION_PROFILER to reduce the memory usage.  Also move the
initialization of subtime into the graph entry callback.

Cc: Josh Poimboeuf <jpoimboe@redhat.com>
Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
 include/linux/ftrace.h               | 2 ++
 kernel/trace/ftrace.c                | 6 ++++++
 kernel/trace/trace_functions_graph.c | 1 -
 3 files changed, 8 insertions(+), 1 deletion(-)

diff --git a/include/linux/ftrace.h b/include/linux/ftrace.h
index 6f93ac46e7f0..b3d34d3e0e7e 100644
--- a/include/linux/ftrace.h
+++ b/include/linux/ftrace.h
@@ -794,7 +794,9 @@ struct ftrace_ret_stack {
 	unsigned long ret;
 	unsigned long func;
 	unsigned long long calltime;
+#ifdef CONFIG_FUNCTION_PROFILER
 	unsigned long long subtime;
+#endif
 #ifdef HAVE_FUNCTION_GRAPH_FP_TEST
 	unsigned long fp;
 #endif
diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
index 84752c8e28b5..2050a7652a86 100644
--- a/kernel/trace/ftrace.c
+++ b/kernel/trace/ftrace.c
@@ -872,7 +872,13 @@ function_profile_call(unsigned long ip, unsigned long parent_ip,
 #ifdef CONFIG_FUNCTION_GRAPH_TRACER
 static int profile_graph_entry(struct ftrace_graph_ent *trace)
 {
+	int index = trace->depth;
+
 	function_profile_call(trace->func, 0, NULL, NULL);
+
+	if (index >= 0 && index < FTRACE_RETFUNC_DEPTH)
+		current->ret_stack[index].subtime = 0;
+
 	return 1;
 }
 
diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
index 0cbe38a844fa..9c7ffa4df5a8 100644
--- a/kernel/trace/trace_functions_graph.c
+++ b/kernel/trace/trace_functions_graph.c
@@ -170,7 +170,6 @@ ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth,
 	current->ret_stack[index].ret = ret;
 	current->ret_stack[index].func = func;
 	current->ret_stack[index].calltime = calltime;
-	current->ret_stack[index].subtime = 0;
 #ifdef HAVE_FUNCTION_GRAPH_FP_TEST
 	current->ret_stack[index].fp = frame_pointer;
 #endif
-- 
2.9.3

[toc] | [next] | [standalone]


#1472093 — Re: [PATCH] ftrace: Access ret_stack->subtime only in the function profiler

FromSteven Rostedt <rostedt@goodmis.org>
Date2016-08-29 22:10 +0200
SubjectRe: [PATCH] ftrace: Access ret_stack->subtime only in the function profiler
Message-ID<sbB2y-3pN-17@gated-at.bofh.it>
In reply to#1471521
On Mon, 29 Aug 2016 12:05:18 +0900
Namhyung Kim <namhyung@kernel.org> wrote:

> The subtime is used only for function profiler with function graph
> tracer enabled.  Move the definition of subtime under
> CONFIG_FUNCTION_PROFILER to reduce the memory usage.  Also move the
> initialization of subtime into the graph entry callback.

Hmm, I think documentation needs to be updated. Although it was never
implemented, I believe I added the subtime to not only work with the
profiler, but also with the normal tracing (to have the time of the
internal functions subtracted from the upper level functions). But it
appears that part was never implemented.

I'm fine with the patch, or actually implementing what graph-time
states in Documentation/ftrace.txt. If we take this patch, that comment
needs to be made to only mention the profiler (and the option should
only be shown when the profiler is enabled).

-- Steve

> 
> Cc: Josh Poimboeuf <jpoimboe@redhat.com>
> Signed-off-by: Namhyung Kim <namhyung@kernel.org>
> ---
>  include/linux/ftrace.h               | 2 ++
>  kernel/trace/ftrace.c                | 6 ++++++
>  kernel/trace/trace_functions_graph.c | 1 -
>  3 files changed, 8 insertions(+), 1 deletion(-)
> 
> diff --git a/include/linux/ftrace.h b/include/linux/ftrace.h
> index 6f93ac46e7f0..b3d34d3e0e7e 100644
> --- a/include/linux/ftrace.h
> +++ b/include/linux/ftrace.h
> @@ -794,7 +794,9 @@ struct ftrace_ret_stack {
>  	unsigned long ret;
>  	unsigned long func;
>  	unsigned long long calltime;
> +#ifdef CONFIG_FUNCTION_PROFILER
>  	unsigned long long subtime;
> +#endif
>  #ifdef HAVE_FUNCTION_GRAPH_FP_TEST
>  	unsigned long fp;
>  #endif
> diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
> index 84752c8e28b5..2050a7652a86 100644
> --- a/kernel/trace/ftrace.c
> +++ b/kernel/trace/ftrace.c
> @@ -872,7 +872,13 @@ function_profile_call(unsigned long ip, unsigned long parent_ip,
>  #ifdef CONFIG_FUNCTION_GRAPH_TRACER
>  static int profile_graph_entry(struct ftrace_graph_ent *trace)
>  {
> +	int index = trace->depth;
> +
>  	function_profile_call(trace->func, 0, NULL, NULL);
> +
> +	if (index >= 0 && index < FTRACE_RETFUNC_DEPTH)
> +		current->ret_stack[index].subtime = 0;
> +
>  	return 1;
>  }
>  
> diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
> index 0cbe38a844fa..9c7ffa4df5a8 100644
> --- a/kernel/trace/trace_functions_graph.c
> +++ b/kernel/trace/trace_functions_graph.c
> @@ -170,7 +170,6 @@ ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth,
>  	current->ret_stack[index].ret = ret;
>  	current->ret_stack[index].func = func;
>  	current->ret_stack[index].calltime = calltime;
> -	current->ret_stack[index].subtime = 0;
>  #ifdef HAVE_FUNCTION_GRAPH_FP_TEST
>  	current->ret_stack[index].fp = frame_pointer;
>  #endif

[toc] | [prev] | [next] | [standalone]


#1472190 — Re: [PATCH] ftrace: Access ret_stack->subtime only in the function profiler

FromNamhyung Kim <namhyung@kernel.org>
Date2016-08-30 03:40 +0200
SubjectRe: [PATCH] ftrace: Access ret_stack->subtime only in the function profiler
Message-ID<sbGbT-6xL-3@gated-at.bofh.it>
In reply to#1472093
Hi Steve,

On Mon, Aug 29, 2016 at 04:07:00PM -0400, Steven Rostedt wrote:
> On Mon, 29 Aug 2016 12:05:18 +0900
> Namhyung Kim <namhyung@kernel.org> wrote:
> 
> > The subtime is used only for function profiler with function graph
> > tracer enabled.  Move the definition of subtime under
> > CONFIG_FUNCTION_PROFILER to reduce the memory usage.  Also move the
> > initialization of subtime into the graph entry callback.
> 
> Hmm, I think documentation needs to be updated. Although it was never
> implemented, I believe I added the subtime to not only work with the
> profiler, but also with the normal tracing (to have the time of the
> internal functions subtracted from the upper level functions). But it
> appears that part was never implemented.
> 
> I'm fine with the patch, or actually implementing what graph-time
> states in Documentation/ftrace.txt. If we take this patch, that comment
> needs to be made to only mention the profiler (and the option should
> only be shown when the profiler is enabled).

Ah, missed the documentation part.  To implement it in the normal
tracing, I think we need to add 'subtime' field to struct
ftrace_graph_ret which will increase disk size.  Are you ok with this?

Thanks,
Namhyung


> 
> > 
> > Cc: Josh Poimboeuf <jpoimboe@redhat.com>
> > Signed-off-by: Namhyung Kim <namhyung@kernel.org>
> > ---
> >  include/linux/ftrace.h               | 2 ++
> >  kernel/trace/ftrace.c                | 6 ++++++
> >  kernel/trace/trace_functions_graph.c | 1 -
> >  3 files changed, 8 insertions(+), 1 deletion(-)
> > 
> > diff --git a/include/linux/ftrace.h b/include/linux/ftrace.h
> > index 6f93ac46e7f0..b3d34d3e0e7e 100644
> > --- a/include/linux/ftrace.h
> > +++ b/include/linux/ftrace.h
> > @@ -794,7 +794,9 @@ struct ftrace_ret_stack {
> >  	unsigned long ret;
> >  	unsigned long func;
> >  	unsigned long long calltime;
> > +#ifdef CONFIG_FUNCTION_PROFILER
> >  	unsigned long long subtime;
> > +#endif
> >  #ifdef HAVE_FUNCTION_GRAPH_FP_TEST
> >  	unsigned long fp;
> >  #endif
> > diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
> > index 84752c8e28b5..2050a7652a86 100644
> > --- a/kernel/trace/ftrace.c
> > +++ b/kernel/trace/ftrace.c
> > @@ -872,7 +872,13 @@ function_profile_call(unsigned long ip, unsigned long parent_ip,
> >  #ifdef CONFIG_FUNCTION_GRAPH_TRACER
> >  static int profile_graph_entry(struct ftrace_graph_ent *trace)
> >  {
> > +	int index = trace->depth;
> > +
> >  	function_profile_call(trace->func, 0, NULL, NULL);
> > +
> > +	if (index >= 0 && index < FTRACE_RETFUNC_DEPTH)
> > +		current->ret_stack[index].subtime = 0;
> > +
> >  	return 1;
> >  }
> >  
> > diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
> > index 0cbe38a844fa..9c7ffa4df5a8 100644
> > --- a/kernel/trace/trace_functions_graph.c
> > +++ b/kernel/trace/trace_functions_graph.c
> > @@ -170,7 +170,6 @@ ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth,
> >  	current->ret_stack[index].ret = ret;
> >  	current->ret_stack[index].func = func;
> >  	current->ret_stack[index].calltime = calltime;
> > -	current->ret_stack[index].subtime = 0;
> >  #ifdef HAVE_FUNCTION_GRAPH_FP_TEST
> >  	current->ret_stack[index].fp = frame_pointer;
> >  #endif
> 

[toc] | [prev] | [next] | [standalone]


#1472980 — Re: [PATCH] ftrace: Access ret_stack->subtime only in the function profiler

FromSteven Rostedt <rostedt@goodmis.org>
Date2016-08-31 04:20 +0200
SubjectRe: [PATCH] ftrace: Access ret_stack->subtime only in the function profiler
Message-ID<sc3i9-4Nf-5@gated-at.bofh.it>
In reply to#1472190
On Wed, 31 Aug 2016 11:11:38 +0900
Namhyung Kim <namhyung@kernel.org> wrote:

> On Tue, Aug 30, 2016 at 10:34:41AM +0900, Namhyung Kim wrote:
> > Hi Steve,
> > 
> > On Mon, Aug 29, 2016 at 04:07:00PM -0400, Steven Rostedt wrote:  
> > > On Mon, 29 Aug 2016 12:05:18 +0900
> > > Namhyung Kim <namhyung@kernel.org> wrote:
> > >   
> > > > The subtime is used only for function profiler with function graph
> > > > tracer enabled.  Move the definition of subtime under
> > > > CONFIG_FUNCTION_PROFILER to reduce the memory usage.  Also move the
> > > > initialization of subtime into the graph entry callback.  
> > > 
> > > Hmm, I think documentation needs to be updated. Although it was never
> > > implemented, I believe I added the subtime to not only work with the
> > > profiler, but also with the normal tracing (to have the time of the
> > > internal functions subtracted from the upper level functions). But it
> > > appears that part was never implemented.
> > > 
> > > I'm fine with the patch, or actually implementing what graph-time
> > > states in Documentation/ftrace.txt. If we take this patch, that comment
> > > needs to be made to only mention the profiler (and the option should
> > > only be shown when the profiler is enabled).  
> > 
> > Ah, missed the documentation part.  To implement it in the normal
> > tracing, I think we need to add 'subtime' field to struct
> > ftrace_graph_ret which will increase disk size.  Are you ok with this?  
> 
> On second thought, I think I can do it by just adding value of subtime
> to ftrace_graph_ret.calltime when graph-time is off.  Then the
> calltime would not be the timestamp at function entry, but it seems
> not guaranteed due to the sleep-time anyway.  Now I wonder why it
> doesn't have 'duration' in the ftrace_graph_ret instead of having
> calltime and rettime.
> 

As it hasn't worked, like forever, I'm thinking of nuking it. Nobody
seemed to have noticed. I haven't needed to use it, and apparently
nobody else has either. Why support a feature that nobody uses?

I have used it for profiling, but not normal function graph tracing.
You can see the function times inside and do the logic post processing.

Best bet is to just update the documentation to what the current code
does.

-- Steve

[toc] | [prev] | [next] | [standalone]


#1472987 — Re: [PATCH] ftrace: Access ret_stack->subtime only in the function profiler

FromNamhyung Kim <namhyung@kernel.org>
Date2016-08-31 04:40 +0200
SubjectRe: [PATCH] ftrace: Access ret_stack->subtime only in the function profiler
Message-ID<sc3Bw-4VN-9@gated-at.bofh.it>
In reply to#1472980
On Tue, Aug 30, 2016 at 10:16:47PM -0400, Steven Rostedt wrote:
> On Wed, 31 Aug 2016 11:11:38 +0900
> Namhyung Kim <namhyung@kernel.org> wrote:
> 
> > On Tue, Aug 30, 2016 at 10:34:41AM +0900, Namhyung Kim wrote:
> > > Hi Steve,
> > > 
> > > On Mon, Aug 29, 2016 at 04:07:00PM -0400, Steven Rostedt wrote:  
> > > > On Mon, 29 Aug 2016 12:05:18 +0900
> > > > Namhyung Kim <namhyung@kernel.org> wrote:
> > > >   
> > > > > The subtime is used only for function profiler with function graph
> > > > > tracer enabled.  Move the definition of subtime under
> > > > > CONFIG_FUNCTION_PROFILER to reduce the memory usage.  Also move the
> > > > > initialization of subtime into the graph entry callback.  
> > > > 
> > > > Hmm, I think documentation needs to be updated. Although it was never
> > > > implemented, I believe I added the subtime to not only work with the
> > > > profiler, but also with the normal tracing (to have the time of the
> > > > internal functions subtracted from the upper level functions). But it
> > > > appears that part was never implemented.
> > > > 
> > > > I'm fine with the patch, or actually implementing what graph-time
> > > > states in Documentation/ftrace.txt. If we take this patch, that comment
> > > > needs to be made to only mention the profiler (and the option should
> > > > only be shown when the profiler is enabled).  
> > > 
> > > Ah, missed the documentation part.  To implement it in the normal
> > > tracing, I think we need to add 'subtime' field to struct
> > > ftrace_graph_ret which will increase disk size.  Are you ok with this?  
> > 
> > On second thought, I think I can do it by just adding value of subtime
> > to ftrace_graph_ret.calltime when graph-time is off.  Then the
> > calltime would not be the timestamp at function entry, but it seems
> > not guaranteed due to the sleep-time anyway.  Now I wonder why it
> > doesn't have 'duration' in the ftrace_graph_ret instead of having
> > calltime and rettime.
> > 
> 
> As it hasn't worked, like forever, I'm thinking of nuking it. Nobody
> seemed to have noticed. I haven't needed to use it, and apparently
> nobody else has either. Why support a feature that nobody uses?
> 
> I have used it for profiling, but not normal function graph tracing.
> You can see the function times inside and do the logic post processing.
> 
> Best bet is to just update the documentation to what the current code
> does.

Ok, will send v2.

Thanks,
Namhyung

[toc] | [prev] | [next] | [standalone]


#1472981 — Re: [PATCH] ftrace: Access ret_stack->subtime only in the function profiler

FromNamhyung Kim <namhyung@kernel.org>
Date2016-08-31 04:20 +0200
SubjectRe: [PATCH] ftrace: Access ret_stack->subtime only in the function profiler
Message-ID<sc3i9-4Nf-3@gated-at.bofh.it>
In reply to#1472190
On Tue, Aug 30, 2016 at 10:34:41AM +0900, Namhyung Kim wrote:
> Hi Steve,
> 
> On Mon, Aug 29, 2016 at 04:07:00PM -0400, Steven Rostedt wrote:
> > On Mon, 29 Aug 2016 12:05:18 +0900
> > Namhyung Kim <namhyung@kernel.org> wrote:
> > 
> > > The subtime is used only for function profiler with function graph
> > > tracer enabled.  Move the definition of subtime under
> > > CONFIG_FUNCTION_PROFILER to reduce the memory usage.  Also move the
> > > initialization of subtime into the graph entry callback.
> > 
> > Hmm, I think documentation needs to be updated. Although it was never
> > implemented, I believe I added the subtime to not only work with the
> > profiler, but also with the normal tracing (to have the time of the
> > internal functions subtracted from the upper level functions). But it
> > appears that part was never implemented.
> > 
> > I'm fine with the patch, or actually implementing what graph-time
> > states in Documentation/ftrace.txt. If we take this patch, that comment
> > needs to be made to only mention the profiler (and the option should
> > only be shown when the profiler is enabled).
> 
> Ah, missed the documentation part.  To implement it in the normal
> tracing, I think we need to add 'subtime' field to struct
> ftrace_graph_ret which will increase disk size.  Are you ok with this?

On second thought, I think I can do it by just adding value of subtime
to ftrace_graph_ret.calltime when graph-time is off.  Then the
calltime would not be the timestamp at function entry, but it seems
not guaranteed due to the sleep-time anyway.  Now I wonder why it
doesn't have 'duration' in the ftrace_graph_ret instead of having
calltime and rettime.

Thanks,
Namhyung


> 
> > 
> > > 
> > > Cc: Josh Poimboeuf <jpoimboe@redhat.com>
> > > Signed-off-by: Namhyung Kim <namhyung@kernel.org>
> > > ---
> > >  include/linux/ftrace.h               | 2 ++
> > >  kernel/trace/ftrace.c                | 6 ++++++
> > >  kernel/trace/trace_functions_graph.c | 1 -
> > >  3 files changed, 8 insertions(+), 1 deletion(-)
> > > 
> > > diff --git a/include/linux/ftrace.h b/include/linux/ftrace.h
> > > index 6f93ac46e7f0..b3d34d3e0e7e 100644
> > > --- a/include/linux/ftrace.h
> > > +++ b/include/linux/ftrace.h
> > > @@ -794,7 +794,9 @@ struct ftrace_ret_stack {
> > >  	unsigned long ret;
> > >  	unsigned long func;
> > >  	unsigned long long calltime;
> > > +#ifdef CONFIG_FUNCTION_PROFILER
> > >  	unsigned long long subtime;
> > > +#endif
> > >  #ifdef HAVE_FUNCTION_GRAPH_FP_TEST
> > >  	unsigned long fp;
> > >  #endif
> > > diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
> > > index 84752c8e28b5..2050a7652a86 100644
> > > --- a/kernel/trace/ftrace.c
> > > +++ b/kernel/trace/ftrace.c
> > > @@ -872,7 +872,13 @@ function_profile_call(unsigned long ip, unsigned long parent_ip,
> > >  #ifdef CONFIG_FUNCTION_GRAPH_TRACER
> > >  static int profile_graph_entry(struct ftrace_graph_ent *trace)
> > >  {
> > > +	int index = trace->depth;
> > > +
> > >  	function_profile_call(trace->func, 0, NULL, NULL);
> > > +
> > > +	if (index >= 0 && index < FTRACE_RETFUNC_DEPTH)
> > > +		current->ret_stack[index].subtime = 0;
> > > +
> > >  	return 1;
> > >  }
> > >  
> > > diff --git a/kernel/trace/trace_functions_graph.c b/kernel/trace/trace_functions_graph.c
> > > index 0cbe38a844fa..9c7ffa4df5a8 100644
> > > --- a/kernel/trace/trace_functions_graph.c
> > > +++ b/kernel/trace/trace_functions_graph.c
> > > @@ -170,7 +170,6 @@ ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth,
> > >  	current->ret_stack[index].ret = ret;
> > >  	current->ret_stack[index].func = func;
> > >  	current->ret_stack[index].calltime = calltime;
> > > -	current->ret_stack[index].subtime = 0;
> > >  #ifdef HAVE_FUNCTION_GRAPH_FP_TEST
> > >  	current->ret_stack[index].fp = frame_pointer;
> > >  #endif
> > 

[toc] | [prev] | [standalone]


Back to top | Article view | linux.kernel


csiph-web