[v2,24/32] selftests/ftrace: Add max stack tracer testcase
diff mbox series

Message ID 153443763074.23257.4052504725796725062.stgit@devbox
State Superseded
Headers show
Series
  • selftests/ftrace: Improve ftracetest with coverage check
Related show

Commit Message

Masami Hiramatsu Aug. 16, 2018, 4:40 p.m. UTC
Add a testcase for max stack tracer, which checks basic
max stack usage tracing and its filter feature.

Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
---
 .../ftrace/test.d/ftrace/func_stack_tracer.tc      |   39 ++++++++++++++++++++
 1 file changed, 39 insertions(+)
 create mode 100644 tools/testing/selftests/ftrace/test.d/ftrace/func_stack_tracer.tc

Comments

Steven Rostedt Aug. 24, 2018, 11:23 p.m. UTC | #1
On Fri, 17 Aug 2018 01:40:30 +0900
Masami Hiramatsu <mhiramat@kernel.org> wrote:

> Add a testcase for max stack tracer, which checks basic
> max stack usage tracing and its filter feature.
> 
> Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
> ---
>  .../ftrace/test.d/ftrace/func_stack_tracer.tc      |   39 ++++++++++++++++++++
>  1 file changed, 39 insertions(+)
>  create mode 100644 tools/testing/selftests/ftrace/test.d/ftrace/func_stack_tracer.tc
> 
> diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func_stack_tracer.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func_stack_tracer.tc
> new file mode 100644
> index 000000000000..b414f0e3c646
> --- /dev/null
> +++ b/tools/testing/selftests/ftrace/test.d/ftrace/func_stack_tracer.tc
> @@ -0,0 +1,39 @@
> +#!/bin/sh
> +# SPDX-License-Identifier: GPL-2.0
> +# description: ftrace - Max stack tracer
> +# Test the basic function of max-stack usage tracing
> +
> +if [ ! -f stack_trace ]; then
> +  echo "Max stack tracer is not supported - please make CONFIG_STACK_TRACER=y"
> +  exit_unsupported
> +fi
> +
> +echo > stack_trace_filter
> +echo 0 > stack_max_size
> +echo 1 > /proc/sys/kernel/stack_tracer_enabled
> +
> +: "Fork and wait for the first entry become !lock"
> +timeout=10
> +while [ $timeout -ne 0 ]; do
> +  ( echo "forked" )
> +  FL=`grep " 0)" stack_trace`
> +  echo $FL | grep -q "lock" || break;
> +  timeout=$((timeout - 1))
> +done
> +echo 0 > /proc/sys/kernel/stack_tracer_enabled
> +
> +echo '*lock*' > stack_trace_filter
> +test `cat stack_trace_filter | wc -l` -eq `grep lock stack_trace_filter | wc -l`
> +
> +echo 0 > stack_max_size
> +echo 1 > /proc/sys/kernel/stack_tracer_enabled

This test fails quite a bit because it doesn't guarantee that another
stack trace gets in that is bigger, and we don't find the "lock".

-- Steve

> +
> +: "Fork and always the first entry including lock"
> +timeout=10
> +while [ $timeout -ne 0 ]; do
> +  ( echo "forked" )
> +  FL=`grep " 0)" stack_trace`
> +  echo $FL | grep -q "lock"
> +  timeout=$((timeout - 1))
> +done
> +echo 0 > /proc/sys/kernel/stack_tracer_enabled
Masami Hiramatsu Aug. 25, 2018, 1:45 a.m. UTC | #2
On Fri, 24 Aug 2018 19:23:52 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:

> On Fri, 17 Aug 2018 01:40:30 +0900
> Masami Hiramatsu <mhiramat@kernel.org> wrote:
> 
> > Add a testcase for max stack tracer, which checks basic
> > max stack usage tracing and its filter feature.
> > 
> > Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
> > ---
> >  .../ftrace/test.d/ftrace/func_stack_tracer.tc      |   39 ++++++++++++++++++++
> >  1 file changed, 39 insertions(+)
> >  create mode 100644 tools/testing/selftests/ftrace/test.d/ftrace/func_stack_tracer.tc
> > 
> > diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func_stack_tracer.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func_stack_tracer.tc
> > new file mode 100644
> > index 000000000000..b414f0e3c646
> > --- /dev/null
> > +++ b/tools/testing/selftests/ftrace/test.d/ftrace/func_stack_tracer.tc
> > @@ -0,0 +1,39 @@
> > +#!/bin/sh
> > +# SPDX-License-Identifier: GPL-2.0
> > +# description: ftrace - Max stack tracer
> > +# Test the basic function of max-stack usage tracing
> > +
> > +if [ ! -f stack_trace ]; then
> > +  echo "Max stack tracer is not supported - please make CONFIG_STACK_TRACER=y"
> > +  exit_unsupported
> > +fi
> > +
> > +echo > stack_trace_filter
> > +echo 0 > stack_max_size
> > +echo 1 > /proc/sys/kernel/stack_tracer_enabled
> > +
> > +: "Fork and wait for the first entry become !lock"
> > +timeout=10
> > +while [ $timeout -ne 0 ]; do
> > +  ( echo "forked" )
> > +  FL=`grep " 0)" stack_trace`
> > +  echo $FL | grep -q "lock" || break;
> > +  timeout=$((timeout - 1))
> > +done
> > +echo 0 > /proc/sys/kernel/stack_tracer_enabled
> > +
> > +echo '*lock*' > stack_trace_filter
> > +test `cat stack_trace_filter | wc -l` -eq `grep lock stack_trace_filter | wc -l`
> > +
> > +echo 0 > stack_max_size
> > +echo 1 > /proc/sys/kernel/stack_tracer_enabled
> 
> This test fails quite a bit because it doesn't guarantee that another
> stack trace gets in that is bigger, and we don't find the "lock".

Hmm, maybe I misunderstand what is the stack_trace_filter.
I thought it filtered the function that triggered stack trace,
so the top of stack trace was always filtered function.
If not, what does this filter?

Thank you,

> 
> -- Steve
> 
> > +
> > +: "Fork and always the first entry including lock"
> > +timeout=10
> > +while [ $timeout -ne 0 ]; do
> > +  ( echo "forked" )
> > +  FL=`grep " 0)" stack_trace`
> > +  echo $FL | grep -q "lock"
> > +  timeout=$((timeout - 1))
> > +done
> > +echo 0 > /proc/sys/kernel/stack_tracer_enabled
>
Steven Rostedt Aug. 25, 2018, 2:41 a.m. UTC | #3
On Sat, 25 Aug 2018 10:45:09 +0900
Masami Hiramatsu <mhiramat@kernel.org> wrote:

> On Fri, 24 Aug 2018 19:23:52 -0400
> Steven Rostedt <rostedt@goodmis.org> wrote:
> 
> > On Fri, 17 Aug 2018 01:40:30 +0900
> > Masami Hiramatsu <mhiramat@kernel.org> wrote:
> >   
> > > Add a testcase for max stack tracer, which checks basic
> > > max stack usage tracing and its filter feature.
> > > 
> > > Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
> > > ---
> > >  .../ftrace/test.d/ftrace/func_stack_tracer.tc      |   39 ++++++++++++++++++++
> > >  1 file changed, 39 insertions(+)
> > >  create mode 100644 tools/testing/selftests/ftrace/test.d/ftrace/func_stack_tracer.tc
> > > 
> > > diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func_stack_tracer.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func_stack_tracer.tc
> > > new file mode 100644
> > > index 000000000000..b414f0e3c646
> > > --- /dev/null
> > > +++ b/tools/testing/selftests/ftrace/test.d/ftrace/func_stack_tracer.tc
> > > @@ -0,0 +1,39 @@
> > > +#!/bin/sh
> > > +# SPDX-License-Identifier: GPL-2.0
> > > +# description: ftrace - Max stack tracer
> > > +# Test the basic function of max-stack usage tracing
> > > +
> > > +if [ ! -f stack_trace ]; then
> > > +  echo "Max stack tracer is not supported - please make CONFIG_STACK_TRACER=y"
> > > +  exit_unsupported
> > > +fi
> > > +
> > > +echo > stack_trace_filter
> > > +echo 0 > stack_max_size
> > > +echo 1 > /proc/sys/kernel/stack_tracer_enabled
> > > +
> > > +: "Fork and wait for the first entry become !lock"
> > > +timeout=10
> > > +while [ $timeout -ne 0 ]; do
> > > +  ( echo "forked" )
> > > +  FL=`grep " 0)" stack_trace`
> > > +  echo $FL | grep -q "lock" || break;
> > > +  timeout=$((timeout - 1))
> > > +done
> > > +echo 0 > /proc/sys/kernel/stack_tracer_enabled
> > > +
> > > +echo '*lock*' > stack_trace_filter
> > > +test `cat stack_trace_filter | wc -l` -eq `grep lock stack_trace_filter | wc -l`
> > > +
> > > +echo 0 > stack_max_size
> > > +echo 1 > /proc/sys/kernel/stack_tracer_enabled  
> > 
> > This test fails quite a bit because it doesn't guarantee that another
> > stack trace gets in that is bigger, and we don't find the "lock".  
> 
> Hmm, maybe I misunderstand what is the stack_trace_filter.
> I thought it filtered the function that triggered stack trace,
> so the top of stack trace was always filtered function.
> If not, what does this filter?

Ah, I missed the filter part, no its correct, and actually found a
bug ;-) By adding this patch, it works again:

diff --git a/kernel/trace/trace_stack.c b/kernel/trace/trace_stack.c
index 4237eba4ef20..2b0d1ee3241c 100644
--- a/kernel/trace/trace_stack.c
+++ b/kernel/trace/trace_stack.c
@@ -111,7 +111,7 @@ check_stack(unsigned long ip, unsigned long *stack)
 	stack_trace_max_size = this_size;
 
 	stack_trace_max.nr_entries = 0;
-	stack_trace_max.skip = 3;
+	stack_trace_max.skip = 0;
 
 	save_stack_trace(&stack_trace_max);
 


-- Steve

> >   
> > > +
> > > +: "Fork and always the first entry including lock"
> > > +timeout=10
> > > +while [ $timeout -ne 0 ]; do
> > > +  ( echo "forked" )
> > > +  FL=`grep " 0)" stack_trace`
> > > +  echo $FL | grep -q "lock"
> > > +  timeout=$((timeout - 1))
> > > +done
> > > +echo 0 > /proc/sys/kernel/stack_tracer_enabled  
> >   
> 
>
Masami Hiramatsu Aug. 26, 2018, 8:42 a.m. UTC | #4
On Fri, 24 Aug 2018 22:41:22 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:

> On Sat, 25 Aug 2018 10:45:09 +0900
> Masami Hiramatsu <mhiramat@kernel.org> wrote:
> 
> > On Fri, 24 Aug 2018 19:23:52 -0400
> > Steven Rostedt <rostedt@goodmis.org> wrote:
> > 
> > > On Fri, 17 Aug 2018 01:40:30 +0900
> > > Masami Hiramatsu <mhiramat@kernel.org> wrote:
> > >   
> > > > Add a testcase for max stack tracer, which checks basic
> > > > max stack usage tracing and its filter feature.
> > > > 
> > > > Signed-off-by: Masami Hiramatsu <mhiramat@kernel.org>
> > > > ---
> > > >  .../ftrace/test.d/ftrace/func_stack_tracer.tc      |   39 ++++++++++++++++++++
> > > >  1 file changed, 39 insertions(+)
> > > >  create mode 100644 tools/testing/selftests/ftrace/test.d/ftrace/func_stack_tracer.tc
> > > > 
> > > > diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func_stack_tracer.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func_stack_tracer.tc
> > > > new file mode 100644
> > > > index 000000000000..b414f0e3c646
> > > > --- /dev/null
> > > > +++ b/tools/testing/selftests/ftrace/test.d/ftrace/func_stack_tracer.tc
> > > > @@ -0,0 +1,39 @@
> > > > +#!/bin/sh
> > > > +# SPDX-License-Identifier: GPL-2.0
> > > > +# description: ftrace - Max stack tracer
> > > > +# Test the basic function of max-stack usage tracing
> > > > +
> > > > +if [ ! -f stack_trace ]; then
> > > > +  echo "Max stack tracer is not supported - please make CONFIG_STACK_TRACER=y"
> > > > +  exit_unsupported
> > > > +fi
> > > > +
> > > > +echo > stack_trace_filter
> > > > +echo 0 > stack_max_size
> > > > +echo 1 > /proc/sys/kernel/stack_tracer_enabled
> > > > +
> > > > +: "Fork and wait for the first entry become !lock"
> > > > +timeout=10
> > > > +while [ $timeout -ne 0 ]; do
> > > > +  ( echo "forked" )
> > > > +  FL=`grep " 0)" stack_trace`
> > > > +  echo $FL | grep -q "lock" || break;
> > > > +  timeout=$((timeout - 1))
> > > > +done
> > > > +echo 0 > /proc/sys/kernel/stack_tracer_enabled
> > > > +
> > > > +echo '*lock*' > stack_trace_filter
> > > > +test `cat stack_trace_filter | wc -l` -eq `grep lock stack_trace_filter | wc -l`
> > > > +
> > > > +echo 0 > stack_max_size
> > > > +echo 1 > /proc/sys/kernel/stack_tracer_enabled  
> > > 
> > > This test fails quite a bit because it doesn't guarantee that another
> > > stack trace gets in that is bigger, and we don't find the "lock".  
> > 
> > Hmm, maybe I misunderstand what is the stack_trace_filter.
> > I thought it filtered the function that triggered stack trace,
> > so the top of stack trace was always filtered function.
> > If not, what does this filter?
> 
> Ah, I missed the filter part, no its correct, and actually found a
> bug ;-) By adding this patch, it works again:

Great! this shows ftracetest really works :)
Anyway, with this fix, we don't need the timeout things anymore.

Thanks!

> 
> diff --git a/kernel/trace/trace_stack.c b/kernel/trace/trace_stack.c
> index 4237eba4ef20..2b0d1ee3241c 100644
> --- a/kernel/trace/trace_stack.c
> +++ b/kernel/trace/trace_stack.c
> @@ -111,7 +111,7 @@ check_stack(unsigned long ip, unsigned long *stack)
>  	stack_trace_max_size = this_size;
>  
>  	stack_trace_max.nr_entries = 0;
> -	stack_trace_max.skip = 3;
> +	stack_trace_max.skip = 0;
>  
>  	save_stack_trace(&stack_trace_max);
>  
> 
> 
> -- Steve
> 
> > >   
> > > > +
> > > > +: "Fork and always the first entry including lock"
> > > > +timeout=10
> > > > +while [ $timeout -ne 0 ]; do
> > > > +  ( echo "forked" )
> > > > +  FL=`grep " 0)" stack_trace`
> > > > +  echo $FL | grep -q "lock"
> > > > +  timeout=$((timeout - 1))
> > > > +done
> > > > +echo 0 > /proc/sys/kernel/stack_tracer_enabled  
> > >   
> > 
> > 
>

Patch
diff mbox series

diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func_stack_tracer.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func_stack_tracer.tc
new file mode 100644
index 000000000000..b414f0e3c646
--- /dev/null
+++ b/tools/testing/selftests/ftrace/test.d/ftrace/func_stack_tracer.tc
@@ -0,0 +1,39 @@ 
+#!/bin/sh
+# SPDX-License-Identifier: GPL-2.0
+# description: ftrace - Max stack tracer
+# Test the basic function of max-stack usage tracing
+
+if [ ! -f stack_trace ]; then
+  echo "Max stack tracer is not supported - please make CONFIG_STACK_TRACER=y"
+  exit_unsupported
+fi
+
+echo > stack_trace_filter
+echo 0 > stack_max_size
+echo 1 > /proc/sys/kernel/stack_tracer_enabled
+
+: "Fork and wait for the first entry become !lock"
+timeout=10
+while [ $timeout -ne 0 ]; do
+  ( echo "forked" )
+  FL=`grep " 0)" stack_trace`
+  echo $FL | grep -q "lock" || break;
+  timeout=$((timeout - 1))
+done
+echo 0 > /proc/sys/kernel/stack_tracer_enabled
+
+echo '*lock*' > stack_trace_filter
+test `cat stack_trace_filter | wc -l` -eq `grep lock stack_trace_filter | wc -l`
+
+echo 0 > stack_max_size
+echo 1 > /proc/sys/kernel/stack_tracer_enabled
+
+: "Fork and always the first entry including lock"
+timeout=10
+while [ $timeout -ne 0 ]; do
+  ( echo "forked" )
+  FL=`grep " 0)" stack_trace`
+  echo $FL | grep -q "lock"
+  timeout=$((timeout - 1))
+done
+echo 0 > /proc/sys/kernel/stack_tracer_enabled