[PATCH 0/2 v3] ftracetest: Add ftrace tests to ftracetests

[PATCH 0/2 v3] ftracetest: Add ftrace tests to ftracetests

[Steven Rostedt]

Third attempt. Moved helper functions into a single patch. Removed the
extra check of schedule in the trace file.

Not an RFC this time. I'm hoping this is "good enough" ;-)

Steven Rostedt (Red Hat) (2):
      ftracetest: Add functions file that holds helper functions
      ftracetest: Add a couple of ftrace test cases

----
 tools/testing/selftests/ftrace/ftracetest          |  3 +
 .../ftrace/test.d/ftrace/fgraph-filter-stack.tc    | 88 ++++++++++++++++++++++
 .../ftrace/test.d/ftrace/fgraph-filter.tc          | 49 ++++++++++++
 .../ftrace/test.d/ftrace/func_profiler.tc          | 76 +++++++++++++++++++
 tools/testing/selftests/ftrace/test.d/functions    | 16 ++++
 5 files changed, 232 insertions(+)

[PATCH 1/2 v3] ftracetest: Add functions file that holds helper functions

[Steven Rostedt]

[-- Attachment #1: 0001-ftracetest-Add-functions-file-that-holds-helper-func.patch --]
[-- Type: text/plain, Size: 1981 bytes --]

From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>

Created the file tools/testing/ftrace/test.d/functions that will
hold helper functions.

Current helper functions include:

 Add clear_trace() helper to reset the trace file

   Used as a descriptive name to show that "echo > trace" is clearing
   the trace file.

 Add disable/enable_tracing() helper calls

   Add calls that disable and enable tracing respectively by echoing
   0 or 1 into tracing_on.

 Add helper reset_tracer() function

    Add a helper function reset_tracer() that will clear the current_tracer
    (echo nop > current_tracer).

Link: http://lkml.kernel.org/r/20141103212737.696365174@goodmis.org

Acked-by: Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 tools/testing/selftests/ftrace/ftracetest       |  3 +++
 tools/testing/selftests/ftrace/test.d/functions | 16 ++++++++++++++++
 2 files changed, 19 insertions(+)
 create mode 100644 tools/testing/selftests/ftrace/test.d/functions

diff --git a/tools/testing/selftests/ftrace/ftracetest b/tools/testing/selftests/ftrace/ftracetest
index f15c0da07aca..c6381a9faf83 100755
--- a/tools/testing/selftests/ftrace/ftracetest
+++ b/tools/testing/selftests/ftrace/ftracetest
@@ -235,6 +235,9 @@ run_test() { # testfile
   fi
 }
 
+# load in the helper functions
+. $TEST_DIR/functions
+
 # Main loop
 for t in $TEST_CASES; do
   run_test $t
diff --git a/tools/testing/selftests/ftrace/test.d/functions b/tools/testing/selftests/ftrace/test.d/functions
new file mode 100644
index 000000000000..5d8cd06d920f
--- /dev/null
+++ b/tools/testing/selftests/ftrace/test.d/functions
@@ -0,0 +1,16 @@
+
+clear_trace() { # reset trace output
+    echo > trace
+}
+
+disable_tracing() { # stop trace recording
+    echo 0 > tracing_on
+}
+
+enable_tracing() { # start trace recording
+    echo 1 > tracing_on
+}
+
+reset_tracer() { # reset the current tracer
+    echo nop > current_tracer
+}
-- 
2.1.1

[PATCH 2/2 v3] ftracetest: Add a couple of ftrace test cases

[Steven Rostedt]

[-- Attachment #1: 0002-ftracetest-Add-a-couple-of-ftrace-test-cases.patch --]
[-- Type: text/plain, Size: 7170 bytes --]

From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>

Added three test cases to get the feel of adding tests to ftracetest.
The three cases are:

  function profiling test, to make sure function profiling still works
   with function tracing (was a regression)

  function graph filter test to make sure that function graph filtering works.

  function graph filter with stack tracing test to make sure that the function
   graph filter does filter and also continues to filter when another function tracer
   is running (like the stack tracer)

Link: http://lkml.kernel.org/r/20141103212737.696365174@goodmis.org

Acked-by: Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 .../ftrace/test.d/ftrace/fgraph-filter-stack.tc    | 88 ++++++++++++++++++++++
 .../ftrace/test.d/ftrace/fgraph-filter.tc          | 49 ++++++++++++
 .../ftrace/test.d/ftrace/func_profiler.tc          | 76 +++++++++++++++++++
 3 files changed, 213 insertions(+)
 create mode 100644 tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc
 create mode 100644 tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter.tc
 create mode 100644 tools/testing/selftests/ftrace/test.d/ftrace/func_profiler.tc

diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc
new file mode 100644
index 000000000000..216d5c55776a
--- /dev/null
+++ b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc
@@ -0,0 +1,88 @@
+#!/bin/sh
+# description: ftrace - function graph filters with stack tracer
+
+# Make sure that function graph filtering works, and is not
+# affected by other tracers enabled (like stack tracer)
+
+if ! grep -q function_graph available_tracers; then
+    echo "no function graph tracer configured"
+    exit_unsupported
+fi
+
+if [ ! -f set_ftrace_filter ]; then
+    echo "set_ftrace_filter not found? Is dynamic ftrace not set?"
+    exit_unsupported
+fi
+
+do_reset() {
+    reset_tracer
+    echo 0 > /proc/sys/kernel/stack_tracer_enabled
+    enable_tracing
+    clear_trace
+    echo > set_ftrace_filter
+}
+
+disable_tracing
+clear_trace;
+
+# filter something, schedule is always good
+if ! echo "schedule" > set_ftrace_filter; then
+    # test for powerpc 64
+    if ! echo ".schedule" > set_ftrace_filter; then
+	echo "can not enable schedule filter"
+	exit -1
+    fi
+fi
+
+echo function_graph > current_tracer
+
+if [ ! -f stack_trace ]; then
+    echo "Stack tracer not configured"
+    do_reset
+    exit_unsupported;
+fi
+
+echo "Now testing with stack tracer"
+
+echo 1 > /proc/sys/kernel/stack_tracer_enabled
+
+disable_tracing
+clear_trace
+enable_tracing
+sleep 1
+
+count=`cat trace | grep '()' | grep -v schedule | wc -l`
+
+if [ $count -ne 0 ]; then
+    echo "Graph filtering not working with stack tracer?"
+    exit -1
+fi
+
+# Make sure we did find something
+count=`cat trace | grep 'schedule()' | wc -l` 
+if [ $count -eq 0 ]; then
+    echo "No schedule traces found?"
+    exit -1
+fi
+
+echo 0 > /proc/sys/kernel/stack_tracer_enabled
+clear_trace
+sleep 1
+
+
+count=`cat trace | grep '()' | grep -v schedule | wc -l`
+
+if [ $count -ne 0 ]; then
+    echo "Graph filtering not working after stack tracer disabled?"
+    exit -1
+fi
+
+count=`cat trace | grep 'schedule()' | wc -l` 
+if [ $count -eq 0 ]; then
+    echo "No schedule traces found?"
+    exit -1
+fi
+
+do_reset
+
+exit 0
diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter.tc b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter.tc
new file mode 100644
index 000000000000..18bda31c4c54
--- /dev/null
+++ b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter.tc
@@ -0,0 +1,49 @@
+#!/bin/sh
+# description: ftrace - function graph filters
+
+# Make sure that function graph filtering works
+
+if ! grep -q function_graph available_tracers; then
+    echo "no function graph tracer configured"
+    exit_unsupported
+fi
+
+do_reset() {
+    reset_tracer
+    enable_tracing
+    clear_trace
+}
+
+disable_tracing
+clear_trace
+
+# filter something, schedule is always good
+if ! echo "schedule" > set_ftrace_filter; then
+    # test for powerpc 64
+    if ! echo ".schedule" > set_ftrace_filter; then
+	echo "can not enable schedule filter"
+	exit -1
+    fi
+fi
+
+echo function_graph > current_tracer
+enable_tracing
+sleep 1
+# search for functions (has "()" on the line), and make sure
+# that only the schedule function was found
+count=`cat trace | grep '()' | grep -v schedule | wc -l`
+if [ $count -ne 0 ]; then
+    echo "Graph filtering not working by itself?"
+    exit -1;
+fi
+
+# Make sure we did find something
+count=`cat trace | grep 'schedule()' | wc -l` 
+if [ $count -eq 0 ]; then
+    echo "No schedule traces found?"
+    exit -1
+fi
+
+do_reset
+
+exit 0
diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func_profiler.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func_profiler.tc
new file mode 100644
index 000000000000..d09d9a676530
--- /dev/null
+++ b/tools/testing/selftests/ftrace/test.d/ftrace/func_profiler.tc
@@ -0,0 +1,76 @@
+#!/bin/sh
+# description: ftrace - function profiler with function tracing
+
+# There was a bug after a rewrite of the ftrace infrastructure that
+# caused the function_profiler not to be able to run with the function
+# tracer, because the function_profiler used the function_graph tracer
+# and it was assumed the two could not run simultaneously.
+#
+# There was another related bug where the solution to the first bug
+# broke the way filtering of the function tracer worked.
+#
+# This test triggers those bugs on those kernels.
+#
+# We need function_graph and profiling to to run this test
+if ! grep -q function_graph available_tracers; then
+    echo "no function graph tracer configured"
+    exit_unsupported;
+fi
+
+if [ ! -f set_ftrace_filter ]; then
+    echo "set_ftrace_filter not found? Is dynamic ftrace not set?"
+    exit_unsupported
+fi
+
+if [ ! -f function_profile_enabled ]; then
+    echo "function_profile_enabled not found, function profiling enabled?"
+    exit_unsupported
+fi
+
+echo "Testing function tracer with profiler:"
+echo "enable function tracer"
+echo function > current_tracer
+echo "enable profiler"
+echo 1 > function_profile_enabled
+
+sleep 1
+
+echo "Now filter on just schedule"
+echo '*schedule' > set_ftrace_filter
+clear_trace
+
+echo "Now disable function profiler"
+echo 0 > function_profile_enabled
+
+sleep 1
+
+# make sure only schedule functions exist
+
+echo "testing if only schedule is being traced"
+if grep -v -e '^#' -e 'schedule' trace; then
+	echo "more than schedule was found"
+	exit 1
+fi
+
+echo "Make sure schedule was traced"
+if ! grep -e 'schedule' trace > /dev/null; then
+	cat trace
+	echo "can not find schedule in trace"
+	exit 1
+fi
+
+echo > set_ftrace_filter
+clear_trace
+
+sleep 1
+
+echo "make sure something other than scheduler is being traced"
+if ! grep -v -e '^#' -e 'schedule' trace > /dev/null; then
+	cat trace
+	echo "no other functions besides schedule was found"
+	exit 1
+fi
+
+reset_tracer
+
+exit 0
-- 
2.1.1

Re: [PATCH 2/2 v3] ftracetest: Add a couple of ftrace test cases

[Namhyung Kim]

Hi Steve,

On Tue, 04 Nov 2014 10:28:47 -0500, Steven Rostedt wrote:
> +count=`cat trace | grep '()' | grep -v schedule | wc -l`
> +
> +if [ $count -ne 0 ]; then
> +    echo "Graph filtering not working after stack tracer disabled?"
> +    exit -1
> +fi
> +
> +count=`cat trace | grep 'schedule()' | wc -l` 
> +if [ $count -eq 0 ]; then
> +    echo "No schedule traces found?"
> +    exit -1

Hmm.. in this case don't we need to call do_reset especially for the
last testcase?  Maybe we could define a simple function like:

fail() { # msg
	do_reset
	echo $1
	exit -1
}

Thanks,
Namhyung


> +fi
> +
> +do_reset
> +
> +exit 0

Re: [PATCH 2/2 v3] ftracetest: Add a couple of ftrace test cases

[Masami Hiramatsu]

(2014/11/05 16:52), Namhyung Kim wrote:
> Hi Steve,
> 
> On Tue, 04 Nov 2014 10:28:47 -0500, Steven Rostedt wrote:
>> +count=`cat trace | grep '()' | grep -v schedule | wc -l`
>> +
>> +if [ $count -ne 0 ]; then
>> +    echo "Graph filtering not working after stack tracer disabled?"
>> +    exit -1
>> +fi
>> +
>> +count=`cat trace | grep 'schedule()' | wc -l` 
>> +if [ $count -eq 0 ]; then
>> +    echo "No schedule traces found?"
>> +    exit -1
> 
> Hmm.. in this case don't we need to call do_reset especially for the
> last testcase?  Maybe we could define a simple function like:
> 
> fail() { # msg
> 	do_reset
> 	echo $1
> 	exit -1
> }

If you want to call do_reset always on exit, you can also use "trap do_reset 0" too.

Thank you,

-- 
Masami HIRAMATSU
Software Platform Research Dept. Linux Technology Research Center
Hitachi, Ltd., Yokohama Research Laboratory
E-mail: masami.hiramatsu.pt@hitachi.com

Re: [PATCH 2/2 v3] ftracetest: Add a couple of ftrace test cases

[Steven Rostedt]

On Wed, 05 Nov 2014 17:41:15 +0900
Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com> wrote:

> (2014/11/05 16:52), Namhyung Kim wrote:
> > Hi Steve,
> > 
> > On Tue, 04 Nov 2014 10:28:47 -0500, Steven Rostedt wrote:
> >> +count=`cat trace | grep '()' | grep -v schedule | wc -l`
> >> +
> >> +if [ $count -ne 0 ]; then
> >> +    echo "Graph filtering not working after stack tracer disabled?"
> >> +    exit -1
> >> +fi
> >> +
> >> +count=`cat trace | grep 'schedule()' | wc -l` 
> >> +if [ $count -eq 0 ]; then
> >> +    echo "No schedule traces found?"
> >> +    exit -1
> > 
> > Hmm.. in this case don't we need to call do_reset especially for the
> > last testcase?  Maybe we could define a simple function like:
> > 
> > fail() { # msg
> > 	do_reset
> > 	echo $1
> > 	exit -1
> > }
> 
> If you want to call do_reset always on exit, you can also use "trap do_reset 0" too.

Cool, I didn't know that. But I like the "fail" command, as it is a bit
more verbose.

I'll update.

Thanks,

-- Steve

[PATCH 2/2 v4] ftracetest: Add a couple of ftrace test cases

[Steven Rostedt]

Added three test cases to get the feel of adding tests to ftracetest.
The three cases are:

  function profiling test, to make sure function profiling still works
   with function tracing (was a regression)

  function graph filter test to make sure that function graph filtering works.

  function graph filter with stack tracing test to make sure that the function
   graph filter does filter and also continues to filter when another function tracer
   is running (like the stack tracer)

Link: http://lkml.kernel.org/r/20141103212737.696365174@goodmis.org

Acked-by: Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 .../ftrace/test.d/ftrace/fgraph-filter-stack.tc    | 89 ++++++++++++++++++++++
 .../ftrace/test.d/ftrace/fgraph-filter.tc          | 52 +++++++++++++
 .../ftrace/test.d/ftrace/func_profiler.tc          | 80 +++++++++++++++++++
 3 files changed, 221 insertions(+)
 create mode 100644 tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc
 create mode 100644 tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter.tc
 create mode 100644 tools/testing/selftests/ftrace/test.d/ftrace/func_profiler.tc

diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc
new file mode 100644
index 000000000000..c15e018e0220
--- /dev/null
+++ b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter-stack.tc
@@ -0,0 +1,89 @@
+#!/bin/sh
+# description: ftrace - function graph filters with stack tracer
+
+# Make sure that function graph filtering works, and is not
+# affected by other tracers enabled (like stack tracer)
+
+if ! grep -q function_graph available_tracers; then
+    echo "no function graph tracer configured"
+    exit_unsupported
+fi
+
+if [ ! -f set_ftrace_filter ]; then
+    echo "set_ftrace_filter not found? Is dynamic ftrace not set?"
+    exit_unsupported
+fi
+
+do_reset() {
+    reset_tracer
+    echo 0 > /proc/sys/kernel/stack_tracer_enabled
+    enable_tracing
+    clear_trace
+    echo > set_ftrace_filter
+}
+
+fail() { # msg
+    do_reset
+    echo $1
+    exit -1
+}
+
+disable_tracing
+clear_trace;
+
+# filter something, schedule is always good
+if ! echo "schedule" > set_ftrace_filter; then
+    # test for powerpc 64
+    if ! echo ".schedule" > set_ftrace_filter; then
+	fail "can not enable schedule filter"
+    fi
+fi
+
+echo function_graph > current_tracer
+
+if [ ! -f stack_trace ]; then
+    echo "Stack tracer not configured"
+    do_reset
+    exit_unsupported;
+fi
+
+echo "Now testing with stack tracer"
+
+echo 1 > /proc/sys/kernel/stack_tracer_enabled
+
+disable_tracing
+clear_trace
+enable_tracing
+sleep 1
+
+count=`cat trace | grep '()' | grep -v schedule | wc -l`
+
+if [ $count -ne 0 ]; then
+    fail "Graph filtering not working with stack tracer?"
+fi
+
+# Make sure we did find something
+count=`cat trace | grep 'schedule()' | wc -l` 
+if [ $count -eq 0 ]; then
+    fail "No schedule traces found?"
+fi
+
+echo 0 > /proc/sys/kernel/stack_tracer_enabled
+clear_trace
+sleep 1
+
+
+count=`cat trace | grep '()' | grep -v schedule | wc -l`
+
+if [ $count -ne 0 ]; then
+    fail "Graph filtering not working after stack tracer disabled?"
+fi
+
+count=`cat trace | grep 'schedule()' | wc -l` 
+if [ $count -eq 0 ]; then
+    fail "No schedule traces found?"
+fi
+
+do_reset
+
+exit 0
diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter.tc b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter.tc
new file mode 100644
index 000000000000..6af5f6360b18
--- /dev/null
+++ b/tools/testing/selftests/ftrace/test.d/ftrace/fgraph-filter.tc
@@ -0,0 +1,52 @@
+#!/bin/sh
+# description: ftrace - function graph filters
+
+# Make sure that function graph filtering works
+
+if ! grep -q function_graph available_tracers; then
+    echo "no function graph tracer configured"
+    exit_unsupported
+fi
+
+do_reset() {
+    reset_tracer
+    enable_tracing
+    clear_trace
+}
+
+fail() { # msg
+    do_reset
+    echo $1
+    exit -1
+}
+
+disable_tracing
+clear_trace
+
+# filter something, schedule is always good
+if ! echo "schedule" > set_ftrace_filter; then
+    # test for powerpc 64
+    if ! echo ".schedule" > set_ftrace_filter; then
+	fail "can not enable schedule filter"
+    fi
+fi
+
+echo function_graph > current_tracer
+enable_tracing
+sleep 1
+# search for functions (has "()" on the line), and make sure
+# that only the schedule function was found
+count=`cat trace | grep '()' | grep -v schedule | wc -l`
+if [ $count -ne 0 ]; then
+    fail "Graph filtering not working by itself?"
+fi
+
+# Make sure we did find something
+count=`cat trace | grep 'schedule()' | wc -l` 
+if [ $count -eq 0 ]; then
+    fail "No schedule traces found?"
+fi
+
+do_reset
+
+exit 0
diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func_profiler.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func_profiler.tc
new file mode 100644
index 000000000000..2e719cb1fc4d
--- /dev/null
+++ b/tools/testing/selftests/ftrace/test.d/ftrace/func_profiler.tc
@@ -0,0 +1,80 @@
+#!/bin/sh
+# description: ftrace - function profiler with function tracing
+
+# There was a bug after a rewrite of the ftrace infrastructure that
+# caused the function_profiler not to be able to run with the function
+# tracer, because the function_profiler used the function_graph tracer
+# and it was assumed the two could not run simultaneously.
+#
+# There was another related bug where the solution to the first bug
+# broke the way filtering of the function tracer worked.
+#
+# This test triggers those bugs on those kernels.
+#
+# We need function_graph and profiling to to run this test
+if ! grep -q function_graph available_tracers; then
+    echo "no function graph tracer configured"
+    exit_unsupported;
+fi
+
+if [ ! -f set_ftrace_filter ]; then
+    echo "set_ftrace_filter not found? Is dynamic ftrace not set?"
+    exit_unsupported
+fi
+
+if [ ! -f function_profile_enabled ]; then
+    echo "function_profile_enabled not found, function profiling enabled?"
+    exit_unsupported
+fi
+
+fail() { # mesg
+    reset_tracer
+    echo > set_ftrace_filter
+    echo $1
+    exit -1
+}
+
+echo "Testing function tracer with profiler:"
+echo "enable function tracer"
+echo function > current_tracer
+echo "enable profiler"
+echo 1 > function_profile_enabled
+
+sleep 1
+
+echo "Now filter on just schedule"
+echo '*schedule' > set_ftrace_filter
+clear_trace
+
+echo "Now disable function profiler"
+echo 0 > function_profile_enabled
+
+sleep 1
+
+# make sure only schedule functions exist
+
+echo "testing if only schedule is being traced"
+if grep -v -e '^#' -e 'schedule' trace; then
+	fail "more than schedule was found"
+fi
+
+echo "Make sure schedule was traced"
+if ! grep -e 'schedule' trace > /dev/null; then
+	cat trace
+	fail "can not find schedule in trace"
+fi
+
+echo > set_ftrace_filter
+clear_trace
+
+sleep 1
+
+echo "make sure something other than scheduler is being traced"
+if ! grep -v -e '^#' -e 'schedule' trace > /dev/null; then
+	cat trace
+	fail "no other functions besides schedule was found"
+fi
+
+reset_tracer
+
+exit 0
-- 
1.8.1.4

Re: [PATCH 2/2 v4] ftracetest: Add a couple of ftrace test cases

[Namhyung Kim]

Hi Steve,

On Thu, Nov 6, 2014 at 8:05 AM, Steven Rostedt <rostedt@goodmis.org> wrote:
>
> Added three test cases to get the feel of adding tests to ftracetest.
> The three cases are:
>
>   function profiling test, to make sure function profiling still works
>    with function tracing (was a regression)
>
>   function graph filter test to make sure that function graph filtering works.
>
>   function graph filter with stack tracing test to make sure that the function
>    graph filter does filter and also continues to filter when another function tracer
>    is running (like the stack tracer)
>
> Link: http://lkml.kernel.org/r/20141103212737.696365174@goodmis.org
>
> Acked-by: Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>
> Signed-off-by: Steven Rostedt <rostedt@goodmis.org>

For this and previous patch 1/2,

Acked-by: Namhyung Kim <namhyung@kernel.org>

Thanks,
Namhyung