[for-next][PATCH 0/5] selftests: ftrace: Tracing updates to allow instance testing

[for-next][PATCH 0/5] selftests: ftrace: Tracing updates to allow instance testing

[Steven Rostedt]

  git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git
for-next

Head SHA1: d6322f6cc483bd512efd3360fa76d0286a5b528b


Steven Rostedt (VMware) (5):
      selftests: ftrace: Allow some tests to be run in a tracing instance
      selftests: ftrace: Make func_event_triggers and func_traceonoff_triggers tests do instances
      selftests: ftrace: Have event tests also run in an tracing instance
      selftests: ftrace: Have some basic tests run in a tracing instance too
      selftests: ftrace: Allow some event trigger tests to run in an instance

----
 tools/testing/selftests/ftrace/ftracetest              | 18 +++++++++++++++++-
 .../testing/selftests/ftrace/test.d/00basic/basic2.tc  |  1 +
 .../testing/selftests/ftrace/test.d/00basic/basic3.tc  |  1 +
 .../selftests/ftrace/test.d/event/event-enable.tc      |  1 +
 .../testing/selftests/ftrace/test.d/event/event-pid.tc |  1 +
 .../selftests/ftrace/test.d/event/subsystem-enable.tc  |  1 +
 .../ftrace/test.d/ftrace/func_event_triggers.tc        |  1 +
 .../ftrace/test.d/ftrace/func_traceonoff_triggers.tc   |  1 +
 .../ftrace/test.d/trigger/trigger-eventonoff.tc        |  1 +
 .../selftests/ftrace/test.d/trigger/trigger-filter.tc  |  1 +
 .../ftrace/test.d/trigger/trigger-hist-mod.tc          |  1 +
 .../selftests/ftrace/test.d/trigger/trigger-hist.tc    |  1 +
 .../ftrace/test.d/trigger/trigger-multihist.tc         |  1 +
 13 files changed, 29 insertions(+), 1 deletion(-)

[for-next][PATCH 1/5] selftests: ftrace: Allow some tests to be run in a tracing instance

[Steven Rostedt]

[-- Attachment #1: 0001-selftests-ftrace-Allow-some-tests-to-be-run-in-a-tra.patch --]
[-- Type: text/plain, Size: 2118 bytes --]

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

An tracing instance has several of the same capabilities as the top level
instance, but may be implemented slightly different. Instead of just writing
tests that duplicat the same test cases of the top level instance, allow a
test to be written for both the top level as well as for an instance.

If a test case can be run in both the top level as well as in an tracing
instance directory, then it should add a tag "# flags: instance" in the
header of the test file. Then after all tests have run, any test that has an
instance flag set, will run again within a tracing instance.

Link: http://lkml.kernel.org/r/20170421233850.1d0e9e05@gandalf.local.home

Cc: Shuah Khan <shuah@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Acked-by: Masami Hiramatsu <mhiramat@kernel.org>
Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
---
 tools/testing/selftests/ftrace/ftracetest | 18 +++++++++++++++++-
 1 file changed, 17 insertions(+), 1 deletion(-)

diff --git a/tools/testing/selftests/ftrace/ftracetest b/tools/testing/selftests/ftrace/ftracetest
index a8631d978725..32e6211e1c6e 100755
--- a/tools/testing/selftests/ftrace/ftracetest
+++ b/tools/testing/selftests/ftrace/ftracetest
@@ -150,11 +150,16 @@ XFAILED_CASES=
 UNDEFINED_CASES=
 TOTAL_RESULT=0
 
+INSTANCE=
 CASENO=0
 testcase() { # testfile
   CASENO=$((CASENO+1))
   desc=`grep "^#[ \t]*description:" $1 | cut -f2 -d:`
-  prlog -n "[$CASENO]$desc"
+  prlog -n "[$CASENO]$INSTANCE$desc"
+}
+
+test_on_instance() { # testfile
+  grep -q "^#[ \t]*flags:.*instance" $1
 }
 
 eval_result() { # sigval
@@ -271,6 +276,17 @@ for t in $TEST_CASES; do
   run_test $t
 done
 
+# Test on instance loop
+INSTANCE=" (instance) "
+for t in $TEST_CASES; do
+  test_on_instance $t || continue
+  SAVED_TRACING_DIR=$TRACING_DIR
+  export TRACING_DIR=`mktemp -d $TRACING_DIR/instances/ftracetest.XXXXXX`
+  run_test $t
+  rmdir $TRACING_DIR
+  TRACING_DIR=$SAVED_TRACING_DIR
+done
+
 prlog ""
 prlog "# of passed: " `echo $PASSED_CASES | wc -w`
 prlog "# of failed: " `echo $FAILED_CASES | wc -w`
-- 
2.10.2

[for-next][PATCH 2/5] selftests: ftrace: Make func_event_triggers and func_traceonoff_triggers tests do instances

[Steven Rostedt]

[-- Attachment #1: 0002-selftests-ftrace-Make-func_event_triggers-and-func_t.patch --]
[-- Type: text/plain, Size: 1733 bytes --]

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

Both the func_event_triggers and func_traceonoff_triggers tests can be
performed in both the toplevel instance as well as for individual instances.
Have their tests run in both cases.

Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
---
 tools/testing/selftests/ftrace/test.d/ftrace/func_event_triggers.tc      | 1 +
 tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc | 1 +
 2 files changed, 2 insertions(+)

diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func_event_triggers.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func_event_triggers.tc
index 5c60afca24a6..07bb3e5930b4 100644
--- a/tools/testing/selftests/ftrace/test.d/ftrace/func_event_triggers.tc
+++ b/tools/testing/selftests/ftrace/test.d/ftrace/func_event_triggers.tc
@@ -1,5 +1,6 @@
 #!/bin/sh
 # description: ftrace - test for function event triggers
+# flags: instance
 #
 # Ftrace allows to add triggers to functions, such as enabling or disabling
 # tracing, enabling or disabling trace events, or recording a stack trace
diff --git a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc
index 3c60ca61fee3..c8e02ec01eaf 100644
--- a/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc
+++ b/tools/testing/selftests/ftrace/test.d/ftrace/func_traceonoff_triggers.tc
@@ -1,5 +1,6 @@
 #!/bin/sh
 # description: ftrace - test for function traceon/off triggers
+# flags: instance
 #
 # Ftrace allows to add triggers to functions, such as enabling or disabling
 # tracing, enabling or disabling trace events, or recording a stack trace
-- 
2.10.2

[for-next][PATCH 3/5] selftests: ftrace: Have event tests also run in an tracing instance

[Steven Rostedt]

[-- Attachment #1: 0003-selftests-ftrace-Have-event-tests-also-run-in-an-tra.patch --]
[-- Type: text/plain, Size: 1941 bytes --]

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

The ftrace selftests of events: event-enable, event-pid, and
subsystem-enable can all be run inside an instance. Change their tests to do
both a toplevel run an an instance run.

Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
---
 tools/testing/selftests/ftrace/test.d/event/event-enable.tc     | 1 +
 tools/testing/selftests/ftrace/test.d/event/event-pid.tc        | 1 +
 tools/testing/selftests/ftrace/test.d/event/subsystem-enable.tc | 1 +
 3 files changed, 3 insertions(+)

diff --git a/tools/testing/selftests/ftrace/test.d/event/event-enable.tc b/tools/testing/selftests/ftrace/test.d/event/event-enable.tc
index 87eb9d6dd4ca..283b45ecb199 100644
--- a/tools/testing/selftests/ftrace/test.d/event/event-enable.tc
+++ b/tools/testing/selftests/ftrace/test.d/event/event-enable.tc
@@ -1,5 +1,6 @@
 #!/bin/sh
 # description: event tracing - enable/disable with event level files
+# flags: instance
 
 do_reset() {
     echo > set_event
diff --git a/tools/testing/selftests/ftrace/test.d/event/event-pid.tc b/tools/testing/selftests/ftrace/test.d/event/event-pid.tc
index d4ab27b522f8..96c1a95be4f7 100644
--- a/tools/testing/selftests/ftrace/test.d/event/event-pid.tc
+++ b/tools/testing/selftests/ftrace/test.d/event/event-pid.tc
@@ -1,5 +1,6 @@
 #!/bin/sh
 # description: event tracing - restricts events based on pid
+# flags: instance
 
 do_reset() {
     echo > set_event
diff --git a/tools/testing/selftests/ftrace/test.d/event/subsystem-enable.tc b/tools/testing/selftests/ftrace/test.d/event/subsystem-enable.tc
index ced27ef0638f..b8fe2e5b9e67 100644
--- a/tools/testing/selftests/ftrace/test.d/event/subsystem-enable.tc
+++ b/tools/testing/selftests/ftrace/test.d/event/subsystem-enable.tc
@@ -1,5 +1,6 @@
 #!/bin/sh
 # description: event tracing - enable/disable with subsystem level files
+# flags: instance
 
 do_reset() {
     echo > set_event
-- 
2.10.2

[for-next][PATCH 4/5] selftests: ftrace: Have some basic tests run in a tracing instance too

[Steven Rostedt]

[-- Attachment #1: 0004-selftests-ftrace-Have-some-basic-tests-run-in-a-trac.patch --]
[-- Type: text/plain, Size: 1452 bytes --]

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

Some of the basic ftrace selftests should also be run in an instance. These
test a quick case of running all tracers in the available_tracers file
within the instance. The other is testing the clock used for the instance.

Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
---
 tools/testing/selftests/ftrace/test.d/00basic/basic2.tc | 1 +
 tools/testing/selftests/ftrace/test.d/00basic/basic3.tc | 1 +
 2 files changed, 2 insertions(+)

diff --git a/tools/testing/selftests/ftrace/test.d/00basic/basic2.tc b/tools/testing/selftests/ftrace/test.d/00basic/basic2.tc
index bf9a7b037924..ebfce83f35b4 100644
--- a/tools/testing/selftests/ftrace/test.d/00basic/basic2.tc
+++ b/tools/testing/selftests/ftrace/test.d/00basic/basic2.tc
@@ -1,5 +1,6 @@
 #!/bin/sh
 # description: Basic test for tracers
+# flags: instance
 test -f available_tracers
 for t in `cat available_tracers`; do
   echo $t > current_tracer
diff --git a/tools/testing/selftests/ftrace/test.d/00basic/basic3.tc b/tools/testing/selftests/ftrace/test.d/00basic/basic3.tc
index bde6625d9785..9e33f841812f 100644
--- a/tools/testing/selftests/ftrace/test.d/00basic/basic3.tc
+++ b/tools/testing/selftests/ftrace/test.d/00basic/basic3.tc
@@ -1,5 +1,6 @@
 #!/bin/sh
 # description: Basic trace clock test
+# flags: instance
 test -f trace_clock
 for c in `cat trace_clock | tr  -d \[\]`; do
   echo $c > trace_clock
-- 
2.10.2

[for-next][PATCH 5/5] selftests: ftrace: Allow some event trigger tests to run in an instance

[Steven Rostedt]

[-- Attachment #1: 0005-selftests-ftrace-Allow-some-event-trigger-tests-to-r.patch --]
[-- Type: text/plain, Size: 3176 bytes --]

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

Some of the event triggers can run fine in an instance. Have them tested in
one as well. The ones that still need work are the snapshot, stacktrace and
traceon/off triggers, as they don't currently pass a handle to the
trace_array they are attached to. But that can be for a future project.

Signed-off-by: Steven Rostedt (VMware) <rostedt@goodmis.org>
---
 tools/testing/selftests/ftrace/test.d/trigger/trigger-eventonoff.tc | 1 +
 tools/testing/selftests/ftrace/test.d/trigger/trigger-filter.tc     | 1 +
 tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-mod.tc   | 1 +
 tools/testing/selftests/ftrace/test.d/trigger/trigger-hist.tc       | 1 +
 tools/testing/selftests/ftrace/test.d/trigger/trigger-multihist.tc  | 1 +
 5 files changed, 5 insertions(+)

diff --git a/tools/testing/selftests/ftrace/test.d/trigger/trigger-eventonoff.tc b/tools/testing/selftests/ftrace/test.d/trigger/trigger-eventonoff.tc
index 1a9445021bf1..c5435adfdd93 100644
--- a/tools/testing/selftests/ftrace/test.d/trigger/trigger-eventonoff.tc
+++ b/tools/testing/selftests/ftrace/test.d/trigger/trigger-eventonoff.tc
@@ -1,5 +1,6 @@
 #!/bin/sh
 # description: event trigger - test event enable/disable trigger
+# flags: instance
 
 do_reset() {
     reset_trigger
diff --git a/tools/testing/selftests/ftrace/test.d/trigger/trigger-filter.tc b/tools/testing/selftests/ftrace/test.d/trigger/trigger-filter.tc
index 514e466e198b..48849a8d577f 100644
--- a/tools/testing/selftests/ftrace/test.d/trigger/trigger-filter.tc
+++ b/tools/testing/selftests/ftrace/test.d/trigger/trigger-filter.tc
@@ -1,5 +1,6 @@
 #!/bin/sh
 # description: event trigger - test trigger filter
+# flags: instance
 
 do_reset() {
     reset_trigger
diff --git a/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-mod.tc b/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-mod.tc
index 400e98b64948..b7f86d10b549 100644
--- a/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-mod.tc
+++ b/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-mod.tc
@@ -1,5 +1,6 @@
 #!/bin/sh
 # description: event trigger - test histogram modifiers
+# flags: instance
 
 do_reset() {
     reset_trigger
diff --git a/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist.tc b/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist.tc
index a00184cd9c95..fb66f7d9339d 100644
--- a/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist.tc
+++ b/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist.tc
@@ -1,5 +1,6 @@
 #!/bin/sh
 # description: event trigger - test histogram trigger
+# flags: instance
 
 do_reset() {
     reset_trigger
diff --git a/tools/testing/selftests/ftrace/test.d/trigger/trigger-multihist.tc b/tools/testing/selftests/ftrace/test.d/trigger/trigger-multihist.tc
index 3478b00ead57..f9153087dd7c 100644
--- a/tools/testing/selftests/ftrace/test.d/trigger/trigger-multihist.tc
+++ b/tools/testing/selftests/ftrace/test.d/trigger/trigger-multihist.tc
@@ -1,5 +1,6 @@
 #!/bin/sh
 # description: event trigger - test multiple histogram triggers
+# flags: instance
 
 do_reset() {
     reset_trigger
-- 
2.10.2

Re: [for-next][PATCH 0/5] selftests: ftrace: Tracing updates to allow instance testing

[Masami Hiramatsu]

On Tue, 25 Apr 2017 09:24:40 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:

>   git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git
> for-next
> 
> Head SHA1: d6322f6cc483bd512efd3360fa76d0286a5b528b
> 
> 
> Steven Rostedt (VMware) (5):
>       selftests: ftrace: Allow some tests to be run in a tracing instance
>       selftests: ftrace: Make func_event_triggers and func_traceonoff_triggers tests do instances
>       selftests: ftrace: Have event tests also run in an tracing instance
>       selftests: ftrace: Have some basic tests run in a tracing instance too
>       selftests: ftrace: Allow some event trigger tests to run in an instance
> 
> ----
>  tools/testing/selftests/ftrace/ftracetest              | 18 +++++++++++++++++-
>  .../testing/selftests/ftrace/test.d/00basic/basic2.tc  |  1 +
>  .../testing/selftests/ftrace/test.d/00basic/basic3.tc  |  1 +
>  .../selftests/ftrace/test.d/event/event-enable.tc      |  1 +
>  .../testing/selftests/ftrace/test.d/event/event-pid.tc |  1 +
>  .../selftests/ftrace/test.d/event/subsystem-enable.tc  |  1 +
>  .../ftrace/test.d/ftrace/func_event_triggers.tc        |  1 +
>  .../ftrace/test.d/ftrace/func_traceonoff_triggers.tc   |  1 +
>  .../ftrace/test.d/trigger/trigger-eventonoff.tc        |  1 +
>  .../selftests/ftrace/test.d/trigger/trigger-filter.tc  |  1 +
>  .../ftrace/test.d/trigger/trigger-hist-mod.tc          |  1 +
>  .../selftests/ftrace/test.d/trigger/trigger-hist.tc    |  1 +
>  .../ftrace/test.d/trigger/trigger-multihist.tc         |  1 +
>  13 files changed, 29 insertions(+), 1 deletion(-)

I've reviewed & tested the series. Looks good to me.

Acked-by: Masami Hiramatsu <mhiramat@kernel.org>

for the series.

Tue Apr 25 16:02:40 UTC 2017
=== Ftrace unit tests ===
[1] Basic trace file check	[PASS]
[2] Basic test for tracers	[PASS]
[3] Basic trace clock test	[PASS]
[4] Basic event tracing check	[PASS]
[5] event tracing - enable/disable with event level files	[PASS]
[6] event tracing - restricts events based on pid	[PASS]
[7] event tracing - enable/disable with subsystem level files	[PASS]
[8] event tracing - enable/disable with top level files	[PASS]
[9] ftrace - function graph filters with stack tracer	[PASS]
[10] ftrace - function graph filters	[PASS]
[11] ftrace - function glob filters	[PASS]
[12] ftrace - function pid filters	[PASS]
[13] ftrace - test for function event triggers	[PASS]
[14] ftrace - function profiler with function tracing	[PASS]
[15] ftrace - test reading of set_ftrace_filter	[PASS]
[16] ftrace - test for function traceon/off triggers	[PASS]
[17] Test creation and deletion of trace instances while setting an event	[PASS]
[18] Test creation and deletion of trace instances	[PASS]
[19] Kprobe dynamic event - adding and removing	[PASS]
[20] Kprobe dynamic event - busy event check	[PASS]
[21] Kprobe dynamic event with arguments	[PASS]
[22] Kprobes event arguments with types	[PASS]
[23] Kprobe dynamic event with function tracer	[PASS]
[24] Kretprobe dynamic event with arguments	[PASS]
[25] Kretprobe dynamic event with maxactive	[PASS]
[26] event trigger - test event enable/disable trigger	[PASS]
[27] event trigger - test trigger filter	[PASS]
[28] event trigger - test histogram modifiers	[PASS]
[29] event trigger - test histogram trigger	[PASS]
[30] event trigger - test multiple histogram triggers	[PASS]
[31] event trigger - test snapshot-trigger	[PASS]
[32] event trigger - test stacktrace-trigger	[PASS]
[33] event trigger - test traceon/off trigger	[PASS]
[34] (instance)  Basic test for tracers	[PASS]
[35] (instance)  Basic trace clock test	[PASS]
[36] (instance)  event tracing - enable/disable with event level files	[PASS]
[37] (instance)  event tracing - restricts events based on pid	[PASS]
[38] (instance)  event tracing - enable/disable with subsystem level files	[PASS]
[39] (instance)  ftrace - test for function event triggers	[PASS]
[40] (instance)  ftrace - test for function traceon/off triggers	[PASS]
[41] (instance)  event trigger - test event enable/disable trigger	[PASS]
[42] (instance)  event trigger - test trigger filter	[PASS]
[43] (instance)  event trigger - test histogram modifiers	[PASS]
[44] (instance)  event trigger - test histogram trigger	[PASS]
[45] (instance)  event trigger - test multiple histogram triggers	[PASS]

# of passed:  45
# of failed:  0
# of unresolved:  0
# of untested:  0
# of unsupported:  0
# of xfailed:  0
# of undefined(test bug):  0

Thank you,

-- 
Masami Hiramatsu <mhiramat@kernel.org>

Re: [for-next][PATCH 0/5] selftests: ftrace: Tracing updates to allow instance testing

[Namhyung Kim]

Hi Steve,

On Tue, Apr 25, 2017 at 09:24:40AM -0400, Steven Rostedt wrote:
>   git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git
> for-next
> 
> Head SHA1: d6322f6cc483bd512efd3360fa76d0286a5b528b
> 
> 
> Steven Rostedt (VMware) (5):
>       selftests: ftrace: Allow some tests to be run in a tracing instance
>       selftests: ftrace: Make func_event_triggers and func_traceonoff_triggers tests do instances
>       selftests: ftrace: Have event tests also run in an tracing instance
>       selftests: ftrace: Have some basic tests run in a tracing instance too
>       selftests: ftrace: Allow some event trigger tests to run in an instance

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


But I saw a warning during the below test.  I used the for-next branch
but the commit id was different:

c486bbae781cce337a31cbbbc609f2313ab54542 ("Merge branch
'trace/ftrace/core' into trace/ftrace/next").

Thanks,
Namhyung


[2] Basic test for tracers
[  908.674961] 
[  908.675178] ===============================
[  908.675611] [ ERR: suspicious RCU usage.  ]
[  908.675922] 4.11.0-rc5kvm+ #230 Tainted: G        W      
[  908.675922] -------------------------------
[  908.675922] /home/namhyung/project/linux/include/linux/rcupdate.h:842 rcu_read_lock() used illegally while idle!
[  908.675922] 
[  908.675922] other info that might help us debug this:
[  908.675922] 
[  908.675922] 
[  908.675922] RCU used illegally from idle CPU!
[  908.675922] rcu_scheduler_active = 2, debug_locks = 0
[  908.675922] RCU used illegally from extended quiescent state!
[  908.675922] 2 locks held by swapper/0/0:
[  908.675922]  #0:  (max_trace_lock){......}, at: [<ffffffff81143c33>] check_critical_timing+0xa3/0x150
[  908.675922]  #1:  (rcu_read_lock){......}, at: [<ffffffff8111f9b5>] __is_insn_slot_addr+0x5/0x120
[  908.675922] 
[  908.675922] stack backtrace:
[  908.675922] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W       4.11.0-rc5kvm+ #230
[  908.675922] Call Trace:
[  908.675922]  dump_stack+0x68/0x93
[  908.675922]  lockdep_rcu_suspicious+0xe0/0x100
[  908.675922]  ? start_kernel+0x3b7/0x3c4
[  908.675922]  __is_insn_slot_addr+0xe4/0x120
[  908.675922]  ? start_kernel+0x3b7/0x3c4
[  908.675922]  __kernel_text_address+0x69/0xb0
[  908.675922]  ? start_kernel+0x3b7/0x3c4
[  908.675922]  unwind_get_return_address+0x47/0x60
[  908.675922]  __save_stack_trace+0x83/0xd0
[  908.675922]  save_stack_trace+0x1b/0x20
[  908.675922]  __ftrace_trace_stack+0x22e/0x240
[  908.675922]  __trace_stack+0x10/0x20
[  908.675922]  check_critical_timing+0xe9/0x150
[  908.675922]  ? do_idle+0x88/0x120
[  908.675922]  ? default_idle_call+0x23/0x37
[  908.675922]  ? do_idle+0x88/0x120
[  908.675922]  stop_critical_timings+0xcf/0xe0
[  908.675922]  default_idle_call+0x23/0x37
[  908.675922]  do_idle+0x88/0x120
[  908.675922]  cpu_startup_entry+0x1d/0x20
[  908.675922]  rest_init+0x130/0x140
[  908.675922]  start_kernel+0x3b7/0x3c4
[  908.675922]  x86_64_start_reservations+0x2f/0x31
[  908.675922]  x86_64_start_kernel+0x17d/0x190
[  908.675922]  start_cpu+0x14/0x14
[  908.675922]  ? start_cpu+0x14/0x14
	[PASS]

Re: [for-next][PATCH 0/5] selftests: ftrace: Tracing updates to allow instance testing

[Steven Rostedt]

On Wed, 26 Apr 2017 11:07:52 +0900
Namhyung Kim <namhyung@kernel.org> wrote:

> Hi Steve,
> 
> On Tue, Apr 25, 2017 at 09:24:40AM -0400, Steven Rostedt wrote:
> >   git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git
> > for-next
> > 
> > Head SHA1: d6322f6cc483bd512efd3360fa76d0286a5b528b
> > 
> > 
> > Steven Rostedt (VMware) (5):
> >       selftests: ftrace: Allow some tests to be run in a tracing instance
> >       selftests: ftrace: Make func_event_triggers and func_traceonoff_triggers tests do instances
> >       selftests: ftrace: Have event tests also run in an tracing instance
> >       selftests: ftrace: Have some basic tests run in a tracing instance too
> >       selftests: ftrace: Allow some event trigger tests to run in an instance  
> 
> Acked-by: Namhyung Kim <namhyung@kernel.org>
> 
> 
> But I saw a warning during the below test.  I used the for-next branch
> but the commit id was different:
> 
> c486bbae781cce337a31cbbbc609f2313ab54542 ("Merge branch
> 'trace/ftrace/core' into trace/ftrace/next").

Yeah, my for-next branch is a merge of urgent and my branch. I don't do
rebases, but this is actually a reset, of a new merge between my two
branches.

> 
> Thanks,
> Namhyung
> 
> 
> [2] Basic test for tracers
> [  908.674961] 
> [  908.675178] ===============================
> [  908.675611] [ ERR: suspicious RCU usage.  ]
> [  908.675922] 4.11.0-rc5kvm+ #230 Tainted: G        W      
> [  908.675922] -------------------------------
> [  908.675922] /home/namhyung/project/linux/include/linux/rcupdate.h:842 rcu_read_lock() used illegally while idle!
> [  908.675922] 
> [  908.675922] other info that might help us debug this:
> [  908.675922] 
> [  908.675922] 
> [  908.675922] RCU used illegally from idle CPU!
> [  908.675922] rcu_scheduler_active = 2, debug_locks = 0
> [  908.675922] RCU used illegally from extended quiescent state!
> [  908.675922] 2 locks held by swapper/0/0:
> [  908.675922]  #0:  (max_trace_lock){......}, at: [<ffffffff81143c33>] check_critical_timing+0xa3/0x150
> [  908.675922]  #1:  (rcu_read_lock){......}, at: [<ffffffff8111f9b5>] __is_insn_slot_addr+0x5/0x120
> [  908.675922] 
> [  908.675922] stack backtrace:
> [  908.675922] CPU: 0 PID: 0 Comm: swapper/0 Tainted: G        W       4.11.0-rc5kvm+ #230
> [  908.675922] Call Trace:
> [  908.675922]  dump_stack+0x68/0x93
> [  908.675922]  lockdep_rcu_suspicious+0xe0/0x100
> [  908.675922]  ? start_kernel+0x3b7/0x3c4
> [  908.675922]  __is_insn_slot_addr+0xe4/0x120
> [  908.675922]  ? start_kernel+0x3b7/0x3c4
> [  908.675922]  __kernel_text_address+0x69/0xb0
> [  908.675922]  ? start_kernel+0x3b7/0x3c4
> [  908.675922]  unwind_get_return_address+0x47/0x60
> [  908.675922]  __save_stack_trace+0x83/0xd0
> [  908.675922]  save_stack_trace+0x1b/0x20
> [  908.675922]  __ftrace_trace_stack+0x22e/0x240
> [  908.675922]  __trace_stack+0x10/0x20
> [  908.675922]  check_critical_timing+0xe9/0x150

Ah, this is a different issue from the stack tracing one. This is irq
tracing. I wonder if we should have that stop latency tracing when RCU
is not functioning.

-- Steve

> [  908.675922]  ? do_idle+0x88/0x120
> [  908.675922]  ? default_idle_call+0x23/0x37
> [  908.675922]  ? do_idle+0x88/0x120
> [  908.675922]  stop_critical_timings+0xcf/0xe0
> [  908.675922]  default_idle_call+0x23/0x37
> [  908.675922]  do_idle+0x88/0x120
> [  908.675922]  cpu_startup_entry+0x1d/0x20
> [  908.675922]  rest_init+0x130/0x140
> [  908.675922]  start_kernel+0x3b7/0x3c4
> [  908.675922]  x86_64_start_reservations+0x2f/0x31
> [  908.675922]  x86_64_start_kernel+0x17d/0x190
> [  908.675922]  start_cpu+0x14/0x14
> [  908.675922]  ? start_cpu+0x14/0x14
> 	[PASS]