| Message ID | 153443763074.23257.4052504725796725062.stgit@devbox (mailing list archive) |
|---|---|
| State | Superseded |
| Headers | show |
| Series | selftests/ftrace: Improve ftracetest with coverage check | expand |
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
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 >
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 > > > >
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 > > > > > > > >
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
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