[PATCH v2 0/2] tracing/kselftest: histogram trigger expression tests

[PATCH v2 0/2] tracing/kselftest: histogram trigger expression tests

[Kalesh Singh]

This series adds kselftest for histogram trigger expressions and is
dependent on the series at [1] and can be applied on top of those after
dropping the patch 7 in [1].

This version drops the changes to reset_trigger_file().

[1] https://lore.kernel.org/r/20211025200852.3002369-1-kaleshsingh@google.com/

Kalesh Singh (2):
  tracing/histogram: Document hist trigger variables (v2)
  tracing/selftests: Add tests for hist trigger expression parsing (v6)

 kernel/trace/trace.c                          | 11 ++++
 .../trigger/trigger-hist-expressions.tc       | 65 +++++++++++++++++++
 2 files changed, 76 insertions(+)
 create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-expressions.tc

-- 
2.33.0.1079.g6e70778dc9-goog

[PATCH v2 1/2] tracing/histogram: Document hist trigger variables

[Kalesh Singh]

Update the tracefs README to describe how hist trigger variables
can be created.

Signed-off-by: Kalesh Singh <kaleshsingh@google.com>
Acked-by: Masami Hiramatsu <mhiramat@kernel.org>
---
Changes in v2:
  - Add Masami's Acked-by.

 kernel/trace/trace.c | 11 +++++++++++
 1 file changed, 11 insertions(+)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index bc677cd64224..c41b3786401d 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -5628,6 +5628,7 @@ static const char readme_msg[] =
 #ifdef CONFIG_HIST_TRIGGERS
 	"      hist trigger\t- If set, event hits are aggregated into a hash table\n"
 	"\t    Format: hist:keys=<field1[,field2,...]>\n"
+	"\t            [:<var1>=<field|var_ref|numeric_literal>[,<var2>=...]]\n"
 	"\t            [:values=<field1[,field2,...]>]\n"
 	"\t            [:sort=<field1[,field2,...]>]\n"
 	"\t            [:size=#entries]\n"
@@ -5639,6 +5640,16 @@ static const char readme_msg[] =
 	"\t            common_timestamp - to record current timestamp\n"
 	"\t            common_cpu - to record the CPU the event happened on\n"
 	"\n"
+	"\t    A hist trigger variable can be:\n"
+	"\t        - a reference to a field e.g. x=current_timestamp,\n"
+	"\t        - a reference to another variable e.g. y=$x,\n"
+	"\t        - a numeric literal: e.g. ms_per_sec=1000,\n"
+	"\t        - an arithmetic expression: e.g. time_secs=current_timestamp/1000\n"
+	"\n"
+	"\t    hist trigger aritmethic expressions support addition(+), subtraction(-),\n"
+	"\t    multiplication(*) and division(/) operators. An operand can be either a\n"
+	"\t    variable reference, field or numeric literal.\n"
+	"\n"
 	"\t    When a matching event is hit, an entry is added to a hash\n"
 	"\t    table using the key(s) and value(s) named, and the value of a\n"
 	"\t    sum called 'hitcount' is incremented.  Keys and values\n"
-- 
2.33.0.1079.g6e70778dc9-goog

[PATCH v6 2/2] tracing/selftests: Add tests for hist trigger expression parsing

[Kalesh Singh]

Add tests for the parsing of hist trigger expressions; and to
validate expression evaluation.

Signed-off-by: Kalesh Singh <kaleshsingh@google.com>
---
Changes in v6:
  - Read the expression result from the trigger file,
    instead of creating a histogram to print the value.

Changes in v5:
  - Add README pattern to requires tag, per Masami

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


 .../trigger/trigger-hist-expressions.tc       | 65 +++++++++++++++++++
 1 file changed, 65 insertions(+)
 create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-expressions.tc

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..33eb79589b32
--- /dev/null
+++ b/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-expressions.tc
@@ -0,0 +1,65 @@
+#!/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 "<var1>=<field|var_ref|numeric_literal>":README
+
+
+fail() { #msg
+    echo $1
+    exit_fail
+}
+
+test_hist_expr() { # test_name expression expected_val
+    trigger="events/sched/sched_process_fork/trigger"
+
+    reset_trigger_file $trigger
+
+    echo "Test hist trigger expressions - $1"
+
+    echo "hist:keys=common_pid:x=$2" > $trigger
+
+    for i in `seq 1 10` ; do ( echo "forked" > /dev/null); done
+
+    x=`grep -o 'x=[[:digit:]]*' $trigger | awk -F= '{ print $2 }'`
+    actual=$(( x + 0 )) # To print negative numbers correctly
+
+    if [ $actual != $3 ]; then
+        fail "Failed hist trigger expression evaluation: Expression: $2 Expected: $3, Actual: $actual"
+    fi
+
+    reset_trigger_file $trigger
+}
+
+check_error() { # test_name command-with-error-pos-by-^
+    trigger="events/sched/sched_process_fork/trigger"
+
+    echo "Test hist trigger expressions - $1"
+    ftrace_errlog_check 'hist:sched:sched_process_fork' "$2" $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

Re: [PATCH v6 2/2] tracing/selftests: Add tests for hist trigger expression parsing

[Masami Hiramatsu]

On Thu, 28 Oct 2021 12:57:58 -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>

This looks good to me.

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

Thank you!

> ---
> Changes in v6:
>   - Read the expression result from the trigger file,
>     instead of creating a histogram to print the value.
> 
> Changes in v5:
>   - Add README pattern to requires tag, per Masami
> 
> 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
> 
> 
>  .../trigger/trigger-hist-expressions.tc       | 65 +++++++++++++++++++
>  1 file changed, 65 insertions(+)
>  create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-expressions.tc
> 
> 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..33eb79589b32
> --- /dev/null
> +++ b/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-expressions.tc
> @@ -0,0 +1,65 @@
> +#!/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 "<var1>=<field|var_ref|numeric_literal>":README
> +
> +
> +fail() { #msg
> +    echo $1
> +    exit_fail
> +}
> +
> +test_hist_expr() { # test_name expression expected_val
> +    trigger="events/sched/sched_process_fork/trigger"
> +
> +    reset_trigger_file $trigger
> +
> +    echo "Test hist trigger expressions - $1"
> +
> +    echo "hist:keys=common_pid:x=$2" > $trigger
> +
> +    for i in `seq 1 10` ; do ( echo "forked" > /dev/null); done
> +
> +    x=`grep -o 'x=[[:digit:]]*' $trigger | awk -F= '{ print $2 }'`
> +    actual=$(( x + 0 )) # To print negative numbers correctly
> +
> +    if [ $actual != $3 ]; then
> +        fail "Failed hist trigger expression evaluation: Expression: $2 Expected: $3, Actual: $actual"
> +    fi
> +
> +    reset_trigger_file $trigger
> +}
> +
> +check_error() { # test_name command-with-error-pos-by-^
> +    trigger="events/sched/sched_process_fork/trigger"
> +
> +    echo "Test hist trigger expressions - $1"
> +    ftrace_errlog_check 'hist:sched:sched_process_fork' "$2" $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>