| Message ID | 20211025200852.3002369-8-kaleshsingh@google.com (mailing list archive) |
|---|---|
| State | New |
| Headers | show |
| Series | tracing: Extend histogram triggers expression parsing | expand |
Hi Kalesh, On Mon, 25 Oct 2021 13:08:39 -0700 Kalesh Singh <kaleshsingh@google.com> wrote: > Add tests for the parsing of hist trigger expressions; and to > validate expression evaluation. > > Signed-off-by: Kalesh Singh <kaleshsingh@google.com> > Reviewed-by: Namhyung Kim <namhyung@kernel.org> > --- > > Changes in v3: > - Remove .sym-offset error check tests > > Changes in v2: > - Add Namhyung's Reviewed-by > - Update comment to clarify err_pos in "Too many subexpressions" test > > > .../testing/selftests/ftrace/test.d/functions | 4 +- > .../trigger/trigger-hist-expressions.tc | 72 +++++++++++++++++++ > 2 files changed, 74 insertions(+), 2 deletions(-) > create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-expressions.tc > > diff --git a/tools/testing/selftests/ftrace/test.d/functions b/tools/testing/selftests/ftrace/test.d/functions > index 000fd05e84b1..1855a63559ad 100644 > --- a/tools/testing/selftests/ftrace/test.d/functions > +++ b/tools/testing/selftests/ftrace/test.d/functions > @@ -16,13 +16,13 @@ reset_tracer() { # reset the current tracer > > reset_trigger_file() { > # remove action triggers first > - grep -H ':on[^:]*(' $@ | > + grep -H ':on[^:]*(' $@ | tac | > while read line; do > cmd=`echo $line | cut -f2- -d: | cut -f1 -d"["` > file=`echo $line | cut -f1 -d:` > echo "!$cmd" >> $file > done > - grep -Hv ^# $@ | > + grep -Hv ^# $@ | tac | > while read line; do > cmd=`echo $line | cut -f2- -d: | cut -f1 -d"["` > file=`echo $line | cut -f1 -d:` If this update has any meaning, please make a separate patch for this part. > diff --git a/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-expressions.tc b/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-expressions.tc > new file mode 100644 > index 000000000000..e715641c54d3 > --- /dev/null > +++ b/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-expressions.tc > @@ -0,0 +1,72 @@ > +#!/bin/sh > +# SPDX-License-Identifier: GPL-2.0 > +# description: event trigger - test histogram expression parsing > +# requires: set_event events/sched/sched_process_fork/trigger events/sched/sched_process_fork/hist error_log Hmm, are there any way to check the running kernel supports this feature? Because the latest version of the kselftest is expected to run on the old stable kernel for testing, the testcase should check whether the kernel supports this testing feature or not. (That's why the requires tag supports README pattern check) So, at first if you didn't update the <tracefs>/README, please update it first to show the new syntax is supported, and add "SOME-PATTERN":README to the requires tag. Thank you, > + > + > +fail() { #msg > + echo $1 > + exit_fail > +} > + > +get_hist_var() { #var_name hist_path > + hist_output=`grep -m1 "$1: " $2` > + hitcount=`echo $hist_output | awk '{ for (i=1; i<=NF; ++i) { if ($i ~ "hitcount:") print $(i+1)} }'` > + var_sum=`echo $hist_output | awk '{ for (i=1; i<=NF; ++i) { if ($i ~ "'$1':") print $(i+1)} }'` > + var_val=$(( var_sum / hitcount )) > + echo $var_val > +} > + > +test_hist_expr() { # test_name expression expected_val > + reset_trigger > + > + echo "Test hist trigger expressions - $1" > + > + echo "hist:keys=common_pid:x=$2" > events/sched/sched_process_fork/trigger > + echo 'hist:keys=common_pid:vals=$x' >> events/sched/sched_process_fork/trigger > + for i in `seq 1 10` ; do ( echo "forked" > /dev/null); done > + > + actual=`get_hist_var x events/sched/sched_process_fork/hist` > + > + if [ $actual != $3 ]; then > + fail "Failed hist trigger expression evaluation: Expression: $2 Expected: $3, Actual: $actual" > + fi > + > + reset_trigger > +} > + > +check_error() { # test_name command-with-error-pos-by-^ > + reset_trigger > + > + echo "Test hist trigger expressions - $1" > + ftrace_errlog_check 'hist:sched:sched_process_fork' "$2" 'events/sched/sched_process_fork/trigger' > + > + reset_trigger > +} > + > +test_hist_expr "Variable assignment" "123" "123" > + > +test_hist_expr "Subtraction not associative" "16-8-4-2" "2" > + > +test_hist_expr "Division not associative" "64/8/4/2" "1" > + > +test_hist_expr "Same precedence operators (+,-) evaluated left to right" "16-8+4+2" "14" > + > +test_hist_expr "Same precedence operators (*,/) evaluated left to right" "4*3/2*2" "12" > + > +test_hist_expr "Multiplication evaluated before addition/subtraction" "4+3*2-2" "8" > + > +test_hist_expr "Division evaluated before addition/subtraction" "4+6/2-2" "5" > + > +# Division by zero returns -1 > +test_hist_expr "Handles division by zero" "3/0" "-1" > + > +# err pos for "too many subexpressions" is dependent on where > +# the last subexpression was detected. This can vary depending > +# on how the expression tree was generated. > +check_error "Too many subexpressions" 'hist:keys=common_pid:x=32+^10*3/20-4' > +check_error "Too many subexpressions" 'hist:keys=common_pid:x=^1+2+3+4+5' > + > +check_error "Unary minus not supported in subexpression" 'hist:keys=common_pid:x=-(^1)+2' > + > +exit 0 > -- > 2.33.0.1079.g6e70778dc9-goog >
On Tue, Oct 26, 2021 at 5:43 AM Masami Hiramatsu <mhiramat@kernel.org> wrote: > > Hi Kalesh, > > On Mon, 25 Oct 2021 13:08:39 -0700 > Kalesh Singh <kaleshsingh@google.com> wrote: > > > Add tests for the parsing of hist trigger expressions; and to > > validate expression evaluation. > > > > Signed-off-by: Kalesh Singh <kaleshsingh@google.com> > > Reviewed-by: Namhyung Kim <namhyung@kernel.org> > > --- > > > > Changes in v3: > > - Remove .sym-offset error check tests > > > > Changes in v2: > > - Add Namhyung's Reviewed-by > > - Update comment to clarify err_pos in "Too many subexpressions" test > > > > > > .../testing/selftests/ftrace/test.d/functions | 4 +- > > .../trigger/trigger-hist-expressions.tc | 72 +++++++++++++++++++ > > 2 files changed, 74 insertions(+), 2 deletions(-) > > create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-expressions.tc > > > > diff --git a/tools/testing/selftests/ftrace/test.d/functions b/tools/testing/selftests/ftrace/test.d/functions > > index 000fd05e84b1..1855a63559ad 100644 > > --- a/tools/testing/selftests/ftrace/test.d/functions > > +++ b/tools/testing/selftests/ftrace/test.d/functions > > @@ -16,13 +16,13 @@ reset_tracer() { # reset the current tracer > > > > reset_trigger_file() { > > # remove action triggers first > > - grep -H ':on[^:]*(' $@ | > > + grep -H ':on[^:]*(' $@ | tac | > > while read line; do > > cmd=`echo $line | cut -f2- -d: | cut -f1 -d"["` > > file=`echo $line | cut -f1 -d:` > > echo "!$cmd" >> $file > > done > > - grep -Hv ^# $@ | > > + grep -Hv ^# $@ | tac | > > while read line; do > > cmd=`echo $line | cut -f2- -d: | cut -f1 -d"["` > > file=`echo $line | cut -f1 -d:` > > If this update has any meaning, please make a separate patch for this part. Hi Masami, Thanks for the feedback. The above change is to ensure we remove triggers in the reverse order that we created them - important when one trigger depends on another. I can split it out into a separate patch and will add a README pattern check to the requires tag for these tests. Thanks, Kalesh > > > diff --git a/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-expressions.tc b/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-expressions.tc > > new file mode 100644 > > index 000000000000..e715641c54d3 > > --- /dev/null > > +++ b/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-expressions.tc > > @@ -0,0 +1,72 @@ > > +#!/bin/sh > > +# SPDX-License-Identifier: GPL-2.0 > > +# description: event trigger - test histogram expression parsing > > +# requires: set_event events/sched/sched_process_fork/trigger events/sched/sched_process_fork/hist error_log > > Hmm, are there any way to check the running kernel supports this feature? > Because the latest version of the kselftest is expected to run on the old stable > kernel for testing, the testcase should check whether the kernel supports this > testing feature or not. (That's why the requires tag supports README pattern check) > > So, at first if you didn't update the <tracefs>/README, please update it first > to show the new syntax is supported, and add "SOME-PATTERN":README to the > requires tag. > > Thank you, > > > + > > + > > +fail() { #msg > > + echo $1 > > + exit_fail > > +} > > + > > +get_hist_var() { #var_name hist_path > > + hist_output=`grep -m1 "$1: " $2` > > + hitcount=`echo $hist_output | awk '{ for (i=1; i<=NF; ++i) { if ($i ~ "hitcount:") print $(i+1)} }'` > > + var_sum=`echo $hist_output | awk '{ for (i=1; i<=NF; ++i) { if ($i ~ "'$1':") print $(i+1)} }'` > > + var_val=$(( var_sum / hitcount )) > > + echo $var_val > > +} > > + > > +test_hist_expr() { # test_name expression expected_val > > + reset_trigger > > + > > + echo "Test hist trigger expressions - $1" > > + > > + echo "hist:keys=common_pid:x=$2" > events/sched/sched_process_fork/trigger > > + echo 'hist:keys=common_pid:vals=$x' >> events/sched/sched_process_fork/trigger > > + for i in `seq 1 10` ; do ( echo "forked" > /dev/null); done > > + > > + actual=`get_hist_var x events/sched/sched_process_fork/hist` > > + > > + if [ $actual != $3 ]; then > > + fail "Failed hist trigger expression evaluation: Expression: $2 Expected: $3, Actual: $actual" > > + fi > > + > > + reset_trigger > > +} > > + > > +check_error() { # test_name command-with-error-pos-by-^ > > + reset_trigger > > + > > + echo "Test hist trigger expressions - $1" > > + ftrace_errlog_check 'hist:sched:sched_process_fork' "$2" 'events/sched/sched_process_fork/trigger' > > + > > + reset_trigger > > +} > > + > > +test_hist_expr "Variable assignment" "123" "123" > > + > > +test_hist_expr "Subtraction not associative" "16-8-4-2" "2" > > + > > +test_hist_expr "Division not associative" "64/8/4/2" "1" > > + > > +test_hist_expr "Same precedence operators (+,-) evaluated left to right" "16-8+4+2" "14" > > + > > +test_hist_expr "Same precedence operators (*,/) evaluated left to right" "4*3/2*2" "12" > > + > > +test_hist_expr "Multiplication evaluated before addition/subtraction" "4+3*2-2" "8" > > + > > +test_hist_expr "Division evaluated before addition/subtraction" "4+6/2-2" "5" > > + > > +# Division by zero returns -1 > > +test_hist_expr "Handles division by zero" "3/0" "-1" > > + > > +# err pos for "too many subexpressions" is dependent on where > > +# the last subexpression was detected. This can vary depending > > +# on how the expression tree was generated. > > +check_error "Too many subexpressions" 'hist:keys=common_pid:x=32+^10*3/20-4' > > +check_error "Too many subexpressions" 'hist:keys=common_pid:x=^1+2+3+4+5' > > + > > +check_error "Unary minus not supported in subexpression" 'hist:keys=common_pid:x=-(^1)+2' > > + > > +exit 0 > > -- > > 2.33.0.1079.g6e70778dc9-goog > > > > > -- > Masami Hiramatsu <mhiramat@kernel.org>
On Tue, 26 Oct 2021 21:43:11 +0900 Masami Hiramatsu <mhiramat@kernel.org> wrote: > > diff --git a/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-expressions.tc b/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-expressions.tc > > new file mode 100644 > > index 000000000000..e715641c54d3 > > --- /dev/null > > +++ b/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-expressions.tc > > @@ -0,0 +1,72 @@ > > +#!/bin/sh > > +# SPDX-License-Identifier: GPL-2.0 > > +# description: event trigger - test histogram expression parsing > > +# requires: set_event events/sched/sched_process_fork/trigger events/sched/sched_process_fork/hist error_log > > Hmm, are there any way to check the running kernel supports this feature? > Because the latest version of the kselftest is expected to run on the old stable > kernel for testing, the testcase should check whether the kernel supports this > testing feature or not. (That's why the requires tag supports README pattern check) > > So, at first if you didn't update the <tracefs>/README, please update it first > to show the new syntax is supported, and add "SOME-PATTERN":README to the > requires tag. Yes, please update the README in kernel/trace/trace.c readme_msg[]. I'll look at the other patches, and if they are fine, I may just apply them. -- Steve
On Tue, 26 Oct 2021 07:28:39 -0700 Kalesh Singh <kaleshsingh@google.com> wrote: > > If this update has any meaning, please make a separate patch for this part. > > Hi Masami, > > Thanks for the feedback. The above change is to ensure we remove > triggers in the reverse order that we created them - important when > one trigger depends on another. I can split it out into a separate > patch and will add a README pattern check to the requires tag for > these tests. Also make sure to run all the ftracetests. When I ran it with this update, most of the other histogram tests failed. Even with your patches applied to the running kernel. -- Steve
On Tue, Oct 26, 2021 at 2:44 PM Steven Rostedt <rostedt@goodmis.org> wrote: > > On Tue, 26 Oct 2021 07:28:39 -0700 > Kalesh Singh <kaleshsingh@google.com> wrote: > > > > If this update has any meaning, please make a separate patch for this part. > > > > Hi Masami, > > > > Thanks for the feedback. The above change is to ensure we remove > > triggers in the reverse order that we created them - important when > > one trigger depends on another. I can split it out into a separate > > patch and will add a README pattern check to the requires tag for > > these tests. > > Also make sure to run all the ftracetests. When I ran it with this update, > most of the other histogram tests failed. Even with your patches applied to > the running kernel. Hi Steve, On my setup I without any of the changes applied (config hist triggers enabled): ./ftracetests # of passed: 41 # of failed: 40 # of unresolved: 0 # of untested: 0 # of unsupported: 32 # of xfailed: 0 # of undefined(test bug): 0 Do all the tests pass for you, before any of the changes in this series? Maybe some of the tests need updating? - Kalesh > > -- Steve
On Tue, 26 Oct 2021 16:36:03 -0700 Kalesh Singh <kaleshsingh@google.com> wrote: > On my setup I without any of the changes applied (config hist triggers enabled): > > ./ftracetests > > # of passed: 41 > # of failed: 40 > # of unresolved: 0 > # of untested: 0 > # of unsupported: 32 > # of xfailed: 0 > # of undefined(test bug): 0 > > Do all the tests pass for you, before any of the changes in this > series? Maybe some of the tests need updating? All my tests past, and I don't push any code if they fail. I'd like to understand why you have these failures. Are the test from the kernel you are testing? -- Steve
On Tue, Oct 26, 2021 at 5:20 PM Steven Rostedt <rostedt@goodmis.org> wrote: > > On Tue, 26 Oct 2021 16:36:03 -0700 > Kalesh Singh <kaleshsingh@google.com> wrote: > > > On my setup I without any of the changes applied (config hist triggers enabled): > > > > ./ftracetests > > > > # of passed: 41 > > # of failed: 40 > > # of unresolved: 0 > > # of untested: 0 > > # of unsupported: 32 > > # of xfailed: 0 > > # of undefined(test bug): 0 > > > > Do all the tests pass for you, before any of the changes in this > > series? Maybe some of the tests need updating? > > All my tests past, and I don't push any code if they fail. > > I'd like to understand why you have these failures. Are the test from > the kernel you are testing? The results are from the kernel before I apply any of the patches. I am testing on an Android emulator (cuttlefish) with 5.15.0-rc6 kernel. The tests clearly work so it must be something on my end. I'll investigate and get back to you. Thanks, Kalesh > > -- Steve
On Tue, 26 Oct 2021 07:28:39 -0700 Kalesh Singh <kaleshsingh@google.com> wrote: > On Tue, Oct 26, 2021 at 5:43 AM Masami Hiramatsu <mhiramat@kernel.org> wrote: > > > > Hi Kalesh, > > > > On Mon, 25 Oct 2021 13:08:39 -0700 > > Kalesh Singh <kaleshsingh@google.com> wrote: > > > > > Add tests for the parsing of hist trigger expressions; and to > > > validate expression evaluation. > > > > > > Signed-off-by: Kalesh Singh <kaleshsingh@google.com> > > > Reviewed-by: Namhyung Kim <namhyung@kernel.org> > > > --- > > > > > > Changes in v3: > > > - Remove .sym-offset error check tests > > > > > > Changes in v2: > > > - Add Namhyung's Reviewed-by > > > - Update comment to clarify err_pos in "Too many subexpressions" test > > > > > > > > > .../testing/selftests/ftrace/test.d/functions | 4 +- > > > .../trigger/trigger-hist-expressions.tc | 72 +++++++++++++++++++ > > > 2 files changed, 74 insertions(+), 2 deletions(-) > > > create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-expressions.tc > > > > > > diff --git a/tools/testing/selftests/ftrace/test.d/functions b/tools/testing/selftests/ftrace/test.d/functions > > > index 000fd05e84b1..1855a63559ad 100644 > > > --- a/tools/testing/selftests/ftrace/test.d/functions > > > +++ b/tools/testing/selftests/ftrace/test.d/functions > > > @@ -16,13 +16,13 @@ reset_tracer() { # reset the current tracer > > > > > > reset_trigger_file() { > > > # remove action triggers first > > > - grep -H ':on[^:]*(' $@ | > > > + grep -H ':on[^:]*(' $@ | tac | > > > while read line; do > > > cmd=`echo $line | cut -f2- -d: | cut -f1 -d"["` > > > file=`echo $line | cut -f1 -d:` > > > echo "!$cmd" >> $file > > > done > > > - grep -Hv ^# $@ | > > > + grep -Hv ^# $@ | tac | > > > while read line; do > > > cmd=`echo $line | cut -f2- -d: | cut -f1 -d"["` > > > file=`echo $line | cut -f1 -d:` > > > > If this update has any meaning, please make a separate patch for this part. > > Hi Masami, > > Thanks for the feedback. The above change is to ensure we remove > triggers in the reverse order that we created them - important when > one trigger depends on another. Hi Kalesh, That's a good reason to make this an independent patch :) > I can split it out into a separate > patch and will add a README pattern check to the requires tag for > these tests. Thank you!
Hi Kalesh, On Tue, 26 Oct 2021 18:15:34 -0700 Kalesh Singh <kaleshsingh@google.com> wrote: > On Tue, Oct 26, 2021 at 5:20 PM Steven Rostedt <rostedt@goodmis.org> wrote: > > > > On Tue, 26 Oct 2021 16:36:03 -0700 > > Kalesh Singh <kaleshsingh@google.com> wrote: > > > > > On my setup I without any of the changes applied (config hist triggers enabled): > > > > > > ./ftracetests > > > > > > # of passed: 41 > > > # of failed: 40 > > > # of unresolved: 0 > > > # of untested: 0 > > > # of unsupported: 32 > > > # of xfailed: 0 > > > # of undefined(test bug): 0 > > > > > > Do all the tests pass for you, before any of the changes in this > > > series? Maybe some of the tests need updating? > > > > All my tests past, and I don't push any code if they fail. > > > > I'd like to understand why you have these failures. Are the test from > > the kernel you are testing? > > The results are from the kernel before I apply any of the patches. I > am testing on an Android emulator (cuttlefish) with 5.15.0-rc6 kernel. > The tests clearly work so it must be something on my end. I'll > investigate and get back to you. Interesting. There should be test logs under logs/ directory in the ftracetest. Can you share the logs/*/ftracetest.log and your kernel kconfig? Thank you,
On Tue, 26 Oct 2021 21:27:00 -0700 Kalesh Singh <kaleshsingh@google.com> wrote: > > Interesting. There should be test logs under logs/ directory in the > > ftracetest. Can you share the logs/*/ftracetest.log and your kernel kconfig? > > > > Thank you, > > > Hi Masami, > > I have attached the config and ftracetest.log here. Actually, could you attach the other files in that log? tar cvjf log.tar.bz2 logs/<date>/ Where <date> is the value for the log that failed. That will give me more information to why the tests failed. I'm currently going to test the config you sent. Thanks! -- Steve
On Wed, 27 Oct 2021 10:31:19 -0400 Steven Rostedt <rostedt@goodmis.org> wrote: > On Tue, 26 Oct 2021 21:27:00 -0700 > Kalesh Singh <kaleshsingh@google.com> wrote: > > > > Interesting. There should be test logs under logs/ directory in the > > > ftracetest. Can you share the logs/*/ftracetest.log and your kernel kconfig? > > > > > > Thank you, > > > > > Hi Masami, > > > > I have attached the config and ftracetest.log here. Thanks! but it seems that the tests were randomely failed... > > > Actually, could you attach the other files in that log? > > tar cvjf log.tar.bz2 logs/<date>/ > > Where <date> is the value for the log that failed. > > That will give me more information to why the tests failed. > > I'm currently going to test the config you sent. I'm also trying to reproduce it, but it seems to need full qemu mode. If you share the above logs, it is easier to check why the tests have been failed. > > Thanks! > > -- Steve
On Wed, 27 Oct 2021 23:52:29 +0900 Masami Hiramatsu <mhiramat@kernel.org> wrote: > > I'm currently going to test the config you sent. > > I'm also trying to reproduce it, but it seems to need full qemu mode. > If you share the above logs, it is easier to check why the tests have > been failed. And my build failed with: make[2]: *** No rule to make target 'kernel/drivers/char/hw_random/tpm-rng.o', needed by 'modules-only.symvers'. Stop. make[1]: *** [/work/git/linux-test.git/Makefile:1783: modules] Error 2 I'll tweak the config to go further. -- Steve
On Wed, 27 Oct 2021 11:01:49 -0400 Steven Rostedt <rostedt@goodmis.org> wrote: > And my build failed with: > > make[2]: *** No rule to make target 'kernel/drivers/char/hw_random/tpm-rng.o', needed by 'modules-only.symvers'. Stop. > make[1]: *** [/work/git/linux-test.git/Makefile:1783: modules] Error 2 > > I'll tweak the config to go further. I got it booted, but also had to disable selinux. I wonder if that caused any issues? It did find a minor bug. A warning happens if you try to connect an event-probe to an event that does not exist. That should not warn. I'll go fix that, but it would still be good to see the logs. Thanks, -- Steve
On Wed, 27 Oct 2021 08:55:39 -0700
Kalesh Singh <kaleshsingh@google.com> wrote:
> Thanks for looking into this. I've attached the full logs here.
Just looking at:
11-add_remove_kprobe.tc-log.vQWAmF
I see the failure of:
+ echo
+ PLACE=_do_fork
+ >>dynamic_events
+ echo 'p:myevent1 _do_fork'
Where "_do_fork" no longer exists and the tests have been updated.
I'm guessing you are running outdated tests. Please make sure that the
tests you run are the latest from the kernel tree.
Thanks!
-- Steve
On Wed, 27 Oct 2021 11:34:16 +0900 Masami Hiramatsu <mhiramat@kernel.org> wrote: > > Hi Masami, > > > > Thanks for the feedback. The above change is to ensure we remove > > triggers in the reverse order that we created them - important when > > one trigger depends on another. > > Hi Kalesh, > That's a good reason to make this an independent patch :) > > > I can split it out into a separate > > patch and will add a README pattern check to the requires tag for > > these tests. Kalesh, As you may have noticed, I pulled in all the patches in this series but this selftests patch. Please rebase your updates as requested by Masami on top of my for-next branch, which can be found here: git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git Thanks! -- Steve
Hi, On Fri, 29 Oct 2021 14:48:18 +0800 kernel test robot <oliver.sang@intel.com> wrote: > > > Greeting, > > FYI, we noticed the following commit (built with gcc-9): > > commit: cfece71411dbca5dc5e1fa2d9ce5a3f38e55d4fe ("[PATCH v4 7/8] tracing/selftests: Add tests for hist trigger expression parsing") > url: https://github.com/0day-ci/linux/commits/Kalesh-Singh/tracing-Extend-histogram-triggers-expression-parsing/20211026-042529 > > > in testcase: kernel-selftests > version: kernel-selftests-x86_64-c8c9111a-1_20210929 > with following parameters: > > group: ftrace > ucode: 0xe2 > > test-description: The kernel contains a set of "self tests" under the tools/testing/selftests/ directory. These are intended to be small unit tests to exercise individual code paths in the kernel. > test-url: https://www.kernel.org/doc/Documentation/kselftest.txt Thanks! This issue has been found and will be fixed next version. BTW, I have some questions about this bot; > > > on test machine: 4 threads Intel(R) Core(TM) i5-6500 CPU @ 3.20GHz with 32G memory > > caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace): > > > > If you fix the issue, kindly add following tag > Reported-by: kernel test robot <oliver.sang@intel.com> > > > > TAP version 13 > 1..1 > # selftests: ftrace: ftracetest > # === Ftrace unit tests === > # [1] Basic trace file check [PASS] > ... > <<< [1] - [67] have same results as parent, i.e. both PASS or both FAIL >>> At first, I guess the robot just checks the "[number]" instead of the test description, but the ftracetest doesn't fix the "[number]" for each test, Thus, it can be different when updated it. So if you compare the result, please check the descriptions too. > ... > # [67] event trigger - test multiple actions on hist trigger [PASS] > > >>> [68] - [72] can PASS on parent > # [68] event trigger - test inter-event histogram trigger onchange action [FAIL] > # [69] event trigger - test inter-event histogram trigger onmatch action [FAIL] > # [70] event trigger - test inter-event histogram trigger onmatch-onmax action [FAIL] > # [71] event trigger - test inter-event histogram trigger onmax action [FAIL] > # [72] event trigger - test inter-event histogram trigger snapshot action [FAIL] > > >>> [73] fail on parent, too > # [73] event trigger - test inter-event histogram trigger eprobe on synthetic event [FAIL] > > >>> [74] - [92] can PASS on parent > # [74] event trigger - test synthetic event create remove [FAIL] > # [75] event trigger - test inter-event histogram trigger trace action with dynamic string param [FAIL] > # [76] event trigger - test synthetic_events syntax parser [FAIL] > # [77] event trigger - test synthetic_events syntax parser errors [FAIL] > # [78] event trigger - test inter-event histogram trigger trace action [FAIL] > # [79] event trigger - test event enable/disable trigger [FAIL] > # [80] event trigger - test trigger filter [FAIL] > # [81] event trigger - test histogram expression parsing [FAIL] > # [82] event trigger - test histogram modifiers [FAIL] > # [83] event trigger - test histogram parser errors [FAIL] > # [84] event trigger - test histogram trigger [FAIL] > # [85] event trigger - test multiple histogram triggers [FAIL] > # [86] event trigger - test snapshot-trigger [FAIL] > # [87] event trigger - test stacktrace-trigger [FAIL] > # [88] trace_marker trigger - test histogram trigger [FAIL] > # [89] trace_marker trigger - test snapshot trigger [FAIL] > # [90] trace_marker trigger - test histogram with synthetic event against kernel event [FAIL] > # [91] trace_marker trigger - test histogram with synthetic event [FAIL] > # [92] event trigger - test traceon/off trigger [FAIL] > # [93] (instance) Basic test for tracers [PASS] > ... > <<< [93] - [112] have same results as parent, all PASS >>> > ... > # [112] (instance) trace_marker trigger - test histogram trigger [PASS] > > >>> parent has no [113] > # [113] (instance) trace_marker trigger - test snapshot trigger [PASS] And next, some patch series may *ADD* new testcases if the series add a new feature, so if you find the difference which is not in the parent commit but it is passed, please ignore that. > # tac: failed to create temporary file in '/tmp/ftracetest-dir.o54lNh': No such file or directory > # tac: failed to create temporary file in '/tmp/ftracetest-dir.o54lNh': No such file or directory > # tac: failed to create temporary file in '/tmp/ftracetest-dir.o54lNh': No such file or directory > # tac: failed to create temporary file in '/tmp/ftracetest-dir.o54lNh': No such file or directory And if you find this kind of new error message like above, please report it. This is more important for us. > # > # > # # of passed: 85 > # # of failed: 26 > # # of unresolved: 1 > # # of untested: 0 > # # of unsupported: 0 > # # of xfailed: 1 > # # of undefined(test bug): 0 > not ok 1 selftests: ftrace: ftracetest # exit=1 Also, please configure your running environment correctly so that all ftracetest passes. If you unsure how to do, please ask me. Thank you, > > > > To reproduce: > > git clone https://github.com/intel/lkp-tests.git > cd lkp-tests > sudo bin/lkp install job.yaml # job file is attached in this email > bin/lkp split-job --compatible job.yaml # generate the yaml file for lkp run > sudo bin/lkp run generated-yaml-file > > # if come across any failure that blocks the test, > # please remove ~/.lkp and /lkp dir to run from a clean state. > > > > --- > 0DAY/LKP+ Test Infrastructure Open Source Technology Center > https://lists.01.org/hyperkitty/list/lkp@lists.01.org Intel Corporation > > Thanks, > Oliver Sang >
On Fri, 29 Oct 2021 21:00:56 +0900 Masami Hiramatsu <mhiramat@kernel.org> wrote: > > # # of passed: 85 > > # # of failed: 26 > > # # of unresolved: 1 > > # # of untested: 0 > > # # of unsupported: 0 > > # # of xfailed: 1 > > # # of undefined(test bug): 0 > > not ok 1 selftests: ftrace: ftracetest # exit=1 > > Also, please configure your running environment correctly so that all > ftracetest passes. If you unsure how to do, please ask me. Although I think it's good to test with different configurations, where not all tests pass. Because then there's times when a test will fail when it should have been ignored, and that will let us know that there's a bug in the test. Or, different configurations might make a test fail that should have passed, where a missing dependency was made. I had someone report a bug that I never caught because it only happened when something was configured off, and because I tested with everything on, I never hit that bug. -- Steve
On 29/10/2021 20:00, Masami Hiramatsu wrote: > >> >> TAP version 13 >> 1..1 >> # selftests: ftrace: ftracetest >> # === Ftrace unit tests === >> # [1] Basic trace file check [PASS] >> ... >> <<< [1] - [67] have same results as parent, i.e. both PASS or both FAIL >>> > At first, I guess the robot just checks the "[number]" instead > of the test description, but the ftracetest doesn't fix the "[number]" > for each test, Thus, it can be different when updated it. Hi Masami Good catch, thanks for these information, we will improve the robot. Thanks Zhjian > So if you compare the result, please check the descriptions too. > >> ... >> # [67] event trigger - test multiple actions on hist trigger [PASS] >> >>>>> [68] - [72] can PASS on parent >> # [68] event trigger - test inter-event histogram trigger onchange action [FAIL] >> # [69] event trigger - test inter-event histogram trigger onmatch action [FAIL] >> # [70] event trigger - test inter-event histogram trigger onmatch-onmax action [FAIL] >> # [71] event trigger - test inter-event histogram trigger onmax action [FAIL] >> # [72] event trigger - test inter-event histogram trigger snapshot action [FAIL] >> >>>>> [73] fail on parent, too >> # [73] event trigger - test inter-event histogram trigger eprobe on synthetic event [FAIL] >> >>>>> [74] - [92] can PASS on parent >> # [74] event trigger - test synthetic event create remove [FAIL] >> # [75] event trigger - test inter-event histogram trigger trace action with dynamic string param [FAIL] >> # [76] event trigger - test synthetic_events syntax parser [FAIL] >> # [77] event trigger - test synthetic_events syntax parser errors [FAIL] >> # [78] event trigger - test inter-event histogram trigger trace action [FAIL] >> # [79] event trigger - test event enable/disable trigger [FAIL] >> # [80] event trigger - test trigger filter [FAIL] >> # [81] event trigger - test histogram expression parsing [FAIL] >> # [82] event trigger - test histogram modifiers [FAIL] >> # [83] event trigger - test histogram parser errors [FAIL] >> # [84] event trigger - test histogram trigger [FAIL] >> # [85] event trigger - test multiple histogram triggers [FAIL] >> # [86] event trigger - test snapshot-trigger [FAIL] >> # [87] event trigger - test stacktrace-trigger [FAIL] >> # [88] trace_marker trigger - test histogram trigger [FAIL] >> # [89] trace_marker trigger - test snapshot trigger [FAIL] >> # [90] trace_marker trigger - test histogram with synthetic event against kernel event [FAIL] >> # [91] trace_marker trigger - test histogram with synthetic event [FAIL] >> # [92] event trigger - test traceon/off trigger [FAIL] >> # [93] (instance) Basic test for tracers [PASS] >> ... >> <<< [93] - [112] have same results as parent, all PASS >>> >> ... >> # [112] (instance) trace_marker trigger - test histogram trigger [PASS] >> >>>>> parent has no [113] >> # [113] (instance) trace_marker trigger - test snapshot trigger [PASS] > And next, some patch series may *ADD* new testcases if the series add > a new feature, so if you find the difference which is not in the > parent commit but it is passed, please ignore that. > >> # tac: failed to create temporary file in '/tmp/ftracetest-dir.o54lNh': No such file or directory >> # tac: failed to create temporary file in '/tmp/ftracetest-dir.o54lNh': No such file or directory >> # tac: failed to create temporary file in '/tmp/ftracetest-dir.o54lNh': No such file or directory >> # tac: failed to create temporary file in '/tmp/ftracetest-dir.o54lNh': No such file or directory > And if you find this kind of new error message like above, please report it. > This is more important for us. > >> # >> # >> # # of passed: 85 >> # # of failed: 26 >> # # of unresolved: 1 >> # # of untested: 0 >> # # of unsupported: 0 >> # # of xfailed: 1 >> # # of undefined(test bug): 0 >> not ok 1 selftests: ftrace: ftracetest # exit=1 > Also, please configure your running environment correctly so that all > ftracetest passes. If you unsure how to do, please ask me. > > Thank you, > >> >> >> To reproduce: >> >> git clone https://github.com/intel/lkp-tests.git >> cd lkp-tests >> sudo bin/lkp install job.yaml # job file is attached in this email >> bin/lkp split-job --compatible job.yaml # generate the yaml file for lkp run >> sudo bin/lkp run generated-yaml-file >> >> # if come across any failure that blocks the test, >> # please remove ~/.lkp and /lkp dir to run from a clean state. >> >> >> >> --- >> 0DAY/LKP+ Test Infrastructure Open Source Technology Center >> https://lists.01.org/hyperkitty/list/lkp@lists.01.org Intel Corporation >> >> Thanks, >> Oliver Sang >> >
diff --git a/tools/testing/selftests/ftrace/test.d/functions b/tools/testing/selftests/ftrace/test.d/functions index 000fd05e84b1..1855a63559ad 100644 --- a/tools/testing/selftests/ftrace/test.d/functions +++ b/tools/testing/selftests/ftrace/test.d/functions @@ -16,13 +16,13 @@ reset_tracer() { # reset the current tracer reset_trigger_file() { # remove action triggers first - grep -H ':on[^:]*(' $@ | + grep -H ':on[^:]*(' $@ | tac | while read line; do cmd=`echo $line | cut -f2- -d: | cut -f1 -d"["` file=`echo $line | cut -f1 -d:` echo "!$cmd" >> $file done - grep -Hv ^# $@ | + grep -Hv ^# $@ | tac | while read line; do cmd=`echo $line | cut -f2- -d: | cut -f1 -d"["` file=`echo $line | cut -f1 -d:` diff --git a/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-expressions.tc b/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-expressions.tc new file mode 100644 index 000000000000..e715641c54d3 --- /dev/null +++ b/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-expressions.tc @@ -0,0 +1,72 @@ +#!/bin/sh +# SPDX-License-Identifier: GPL-2.0 +# description: event trigger - test histogram expression parsing +# requires: set_event events/sched/sched_process_fork/trigger events/sched/sched_process_fork/hist error_log + + +fail() { #msg + echo $1 + exit_fail +} + +get_hist_var() { #var_name hist_path + hist_output=`grep -m1 "$1: " $2` + hitcount=`echo $hist_output | awk '{ for (i=1; i<=NF; ++i) { if ($i ~ "hitcount:") print $(i+1)} }'` + var_sum=`echo $hist_output | awk '{ for (i=1; i<=NF; ++i) { if ($i ~ "'$1':") print $(i+1)} }'` + var_val=$(( var_sum / hitcount )) + echo $var_val +} + +test_hist_expr() { # test_name expression expected_val + reset_trigger + + echo "Test hist trigger expressions - $1" + + echo "hist:keys=common_pid:x=$2" > events/sched/sched_process_fork/trigger + echo 'hist:keys=common_pid:vals=$x' >> events/sched/sched_process_fork/trigger + for i in `seq 1 10` ; do ( echo "forked" > /dev/null); done + + actual=`get_hist_var x events/sched/sched_process_fork/hist` + + if [ $actual != $3 ]; then + fail "Failed hist trigger expression evaluation: Expression: $2 Expected: $3, Actual: $actual" + fi + + reset_trigger +} + +check_error() { # test_name command-with-error-pos-by-^ + reset_trigger + + echo "Test hist trigger expressions - $1" + ftrace_errlog_check 'hist:sched:sched_process_fork' "$2" 'events/sched/sched_process_fork/trigger' + + reset_trigger +} + +test_hist_expr "Variable assignment" "123" "123" + +test_hist_expr "Subtraction not associative" "16-8-4-2" "2" + +test_hist_expr "Division not associative" "64/8/4/2" "1" + +test_hist_expr "Same precedence operators (+,-) evaluated left to right" "16-8+4+2" "14" + +test_hist_expr "Same precedence operators (*,/) evaluated left to right" "4*3/2*2" "12" + +test_hist_expr "Multiplication evaluated before addition/subtraction" "4+3*2-2" "8" + +test_hist_expr "Division evaluated before addition/subtraction" "4+6/2-2" "5" + +# Division by zero returns -1 +test_hist_expr "Handles division by zero" "3/0" "-1" + +# err pos for "too many subexpressions" is dependent on where +# the last subexpression was detected. This can vary depending +# on how the expression tree was generated. +check_error "Too many subexpressions" 'hist:keys=common_pid:x=32+^10*3/20-4' +check_error "Too many subexpressions" 'hist:keys=common_pid:x=^1+2+3+4+5' + +check_error "Unary minus not supported in subexpression" 'hist:keys=common_pid:x=-(^1)+2' + +exit 0