ftrace: selftests: Add full glob matching and update ftracetest

Hi,

Here is a series of patches to add full glob matching support in ftrace and update ftracetest to test the glob matching and hexadecimal types.

The first patch is same one as I sent before
(https://lkml.org/lkml/2016/10/5/149)
I've added patches for updating ftracetest to test this feature and previous hexadecimal type feature. Since I've found an issue (if tracing_on is set to 0, some test cases fail) on ftracetest, this also fixes the issue.

[1/5] Add full glob matching support on ftrace's
function filter and event filter expression.
[2/5] Fix some testcases to enable tracing_on before
start tracing.
[3/5] Introduce temporary directory for test cases,
which is used for storing temporary test data.
[4/5] Add a testcase for function-name glob matching [5/5] Add a testcase for types of event arguments

Thanks,
---

Masami Hiramatsu (5):
ftrace: Support full glob matching
selftests: ftrace: Fix test cases to enable tracing
selftests: ftrace: Introduce TMPDIR for temporary files
selftests: ftrace: Add a testcase for function filter glob match
selftests: ftrace: Add a testcase for types of kprobe event

 Documentation/trace/events.txt                     |    9 +---
 Documentation/trace/ftrace.txt                     |    9 +---
 kernel/trace/Kconfig                               |    2 +
 kernel/trace/ftrace.c                              |    4 ++
 kernel/trace/trace.c                               |    2 -
 kernel/trace/trace.h                               |    2 +
 kernel/trace/trace_events_filter.c                 |   17 +++++++
 tools/testing/selftests/ftrace/ftracetest          |    2 +
 .../selftests/ftrace/test.d/event/event-enable.tc  |    1 
 .../selftests/ftrace/test.d/event/event-pid.tc     |    1 
 .../ftrace/test.d/event/subsystem-enable.tc        |    1 
 .../ftrace/test.d/event/toplevel-enable.tc         |    1 
 .../ftrace/test.d/ftrace/func-filter-glob.tc       |   49 ++++++++++++++++++++
 .../ftrace/test.d/ftrace/func_profiler.tc          |    1 
 .../ftrace/test.d/kprobe/kprobe_args_type.tc       |   37 +++++++++++++++
 .../ftrace/test.d/kprobe/kprobe_ftrace.tc          |    1 
 16 files changed, 125 insertions(+), 14 deletions(-)
 create mode 100644 tools/testing/selftests/ftrace/test.d/ftrace/func-filter-glob.tc
 create mode 100644 tools/testing/selftests/ftrace/test.d/kprobe/kprobe_args_type.tc

--
Masami Hiramatsu (Linaro Ltd.) <[email protected]>

Use glob_match() to support flexible glob wildcards (*,?) and character classes ([) for ftrace.
Since the full glob matching is slower than the current partial matching routines(*pat, pat*, *pat*), this leaves those routines and just add MATCH_GLOB for complex glob expression.

e.g.
----
[root@localhost tracing]# echo 'sched*group' > set_ftrace_filter [root@localhost tracing]# cat set_ftrace_filter sched_free_group
sched_change_group
sched_create_group
sched_online_group
sched_destroy_group
sched_offline_group
[root@localhost tracing]# echo '[Ss]y[Ss]_*' > set_ftrace_filter [root@localhost tracing]# head set_ftrace_filter sys_arch_prctl
sys_rt_sigreturn
sys_ioperm
SyS_iopl
sys_modify_ldt
SyS_mmap
SyS_set_thread_area
SyS_get_thread_area
SyS_set_tid_address
sys_fork
----

---
 Documentation/trace/events.txt     |    9 +++------
 Documentation/trace/ftrace.txt     |    9 +++------
 kernel/trace/Kconfig               |    2 ++
 kernel/trace/ftrace.c              |    4 ++++
 kernel/trace/trace.c               |    2 +-
 kernel/trace/trace.h               |    2 ++
 kernel/trace/trace_events_filter.c |   17 ++++++++++++++++-
 7 files changed, 31 insertions(+), 14 deletions(-)

index 08d74d7..2cc08d4 100644
@@ -189,16 +189,13 @@ And for string fields they are:
 
 ==, !=, ~
 
-The glob (~) only accepts a wild card character (*) at the start and or
-end of the string. For example:
+The glob (~) accepts a wild card character (*,?) and character classes
+([). For example:
 
   prev_comm ~ "*sh"
   prev_comm ~ "sh*"
   prev_comm ~ "*sh*"
-
-But does not allow for it to be within the string:
-
-  prev_comm ~ "ba*sh"   <-- is invalid
+  prev_comm ~ "ba*sh"
 
 5.2 Setting filters
 -------------------

index a6b3705..b26abc7 100644
@@ -2218,16 +2218,13 @@ hrtimer_interrupt
 sys_nanosleep
 
 
-Perhaps this is not enough. The filters also allow simple wild
-cards. Only the following are currently available
+Perhaps this is not enough. The filters also allow glob(7) matching.
 
   <match>*  - will match functions that begin with <match>
   *<match>  - will match functions that end with <match>
   *<match>* - will match functions that have <match> in it
-
-These are the only wild cards which are supported.
-
-  <match>*<match> will not work.
+  <match1>*<match2> - will match functions that begin with
+                      <match1> and end with <match2>
 
 Note: It is better to use quotes to enclose the wild cards,
       otherwise the shell may expand the parameters into names

index ba33267..aa6eb15 100644
@@ -70,6 +70,7 @@ config FTRACE_NMI_ENTER
 
 config EVENT_TRACING
 	select CONTEXT_SWITCH_TRACER
+        select GLOB
 	bool
 
 config CONTEXT_SWITCH_TRACER

@@ -133,6 +134,7 @@ config FUNCTION_TRACER
 	select KALLSYMS
 	select GENERIC_TRACER
 	select CONTEXT_SWITCH_TRACER
+        select GLOB
 	help
 	  Enable the kernel to trace every kernel function. This is done
 	  by using a compiler feature to insert a small, 5-byte No-Operation

index 84752c8..5741184 100644
@@ -3493,6 +3493,10 @@ static int ftrace_match(char *str, struct ftrace_glob *g)
 		    memcmp(str + slen - g->len, g->search, g->len) == 0)
 			matched = 1;
 		break;
+	case MATCH_GLOB:
+		if (glob_match(g->search, str))
+			matched = 1;
+		break;
 	}
 
 	return matched;

index 37824d9..ae343e7 100644
@@ -4065,7 +4065,7 @@ static const char readme_msg[] =
 	"\n  available_filter_functions - list of functions that can be filtered on\n"
 	"  set_ftrace_filter\t- echo function name in here to only trace these\n"
 	"\t\t\t  functions\n"
-	"\t     accepts: func_full_name, *func_end, func_begin*, *func_middle*\n"
+	"\t     accepts: func_full_name or glob-matching-pattern\n"
 	"\t     modules: Can select a group via module\n"
 	"\t      Format: :mod:<module-name>\n"
 	"\t     example: echo :mod:ext3 > set_ftrace_filter\n"

index f783df4..eac2eda 100644
@@ -15,6 +15,7 @@
 #include <linux/trace_events.h>
 #include <linux/compiler.h>
 #include <linux/trace_seq.h>
+#include <linux/glob.h>
 
 #ifdef CONFIG_FTRACE_SYSCALLS
 #include <asm/unistd.h>		/* For NR_SYSCALLS	     */

@@ -1252,6 +1253,7 @@ enum regex_type {
 	MATCH_FRONT_ONLY,
 	MATCH_MIDDLE_ONLY,
 	MATCH_END_ONLY,
+	MATCH_GLOB,
 };
 
 struct regex {

index 9daa9b3..e1c7e2c 100644
@@ -344,6 +344,12 @@ static int regex_match_end(char *str, struct regex *r, int len)
 	return 0;
 }
 
+static int regex_match_glob(char *str, struct regex *r, int len __maybe_unused)
+{
+	if (glob_match(r->pattern, str))
+		return 1;
+	return 0;
+}
 /**
  * filter_parse_regex - parse a basic regex
  * @buff:   the raw regex

@@ -380,14 +386,20 @@ enum regex_type filter_parse_regex(char *buff, int len, char **search, int *not)
 			if (!i) {
 				*search = buff + 1;
 				type = MATCH_END_ONLY;
-			} else {
+			} else if (i == len - 1) {
 				if (type == MATCH_END_ONLY)
 					type = MATCH_MIDDLE_ONLY;
 				else
 					type = MATCH_FRONT_ONLY;
 				buff[i] = 0;
 				break;
+			} else {	/* pattern continues, use full glob */
+				type = MATCH_GLOB;
+				break;
 			}
+		} else if (strchr("[?\\", buff[i])) {
+			type = MATCH_GLOB;
+			break;
 		}
 	}
 

@@ -420,6 +432,9 @@ static void filter_build_regex(struct filter_pred *pred)
 	case MATCH_END_ONLY:
 		r->match = regex_match_end;
 		break;
+	case MATCH_GLOB:
+		r->match = regex_match_glob;
+		break;
 	}
 
 	pred->not ^= not;

Hi Masami,

Is this any different than your last patch, as I already pulled it into my queue. I haven't been able to test it much, as I found that 4.9-rc1 is failing my tests, and I can't add new code to linux-next till 4.9 is stable.

-- Steve

This patch is completely same as the last patch. If you already queued it, please ignore this [1/5].

And OK, what kind of tests are failed on 4.9-rc1? I though a possible kernel freeze in 4.8 when I ran ftracetest, but it seemed disappeared in 4.9-rc1.

Thanks,

Masami Hiramatsu <[email protected]>

The kernel crashed on enabling the mmiotracer, which disables CPUs. That tracer is notorious for finding CPU hotplug bugs. There's a fix in tip/urgent that I pulled in, which lets it pass. I rather wait till rc2 to base changes on where I don't need to add commits to make my tests pass.

-- Steve

Ah, I think this should same as what I hit :)
I've tested this series on tip/master, so it was fixed at that point.

Thanks,

Masami Hiramatsu <[email protected]>

Fix some test cases to enable tracing before starting trace test. This can avoid false-positive failure when previous testcase fails while disabling tracing.

---
 .../selftests/ftrace/test.d/event/event-enable.tc  |    1 +
 .../selftests/ftrace/test.d/event/event-pid.tc     |    1 +
 .../ftrace/test.d/event/subsystem-enable.tc        |    1 +
 .../ftrace/test.d/event/toplevel-enable.tc         |    1 +
 .../ftrace/test.d/ftrace/func_profiler.tc          |    1 +
 .../ftrace/test.d/kprobe/kprobe_ftrace.tc          |    1 +
 6 files changed, 6 insertions(+)

index 87eb9d6..ee7ea0a 100644
@@ -23,6 +23,7 @@ fi
 
 reset_tracer
 do_reset
+enable_tracing
 
 echo 'sched:sched_switch' > set_event
 

index d4ab27b..1477e5e 100644
@@ -30,6 +30,7 @@ fi
 
 reset_tracer
 do_reset
+enable_tracing
 
 echo 1 > events/sched/sched_switch/enable
 

index ced27ef..f4a64f9 100644
@@ -23,6 +23,7 @@ fi
 
 reset_tracer
 do_reset
+enable_tracing
 
 echo 'sched:*' > set_event
 

index 0bb5df3..037a82e 100644
@@ -23,6 +23,7 @@ fi
 
 reset_tracer
 do_reset
+enable_tracing
 
 echo '*:*' > set_event
 

index 7808336..d10d6e0 100644
@@ -36,6 +36,7 @@ fail() { # mesg
 
 echo "Testing function tracer with profiler:"
 echo "enable function tracer"
+enable_tracing
 echo function > current_tracer
 echo "enable profiler"
 echo 1 > function_profile_enabled

index d6f2f49..bdbd385 100644
@@ -10,6 +10,7 @@ echo _do_fork > set_ftrace_filter
 echo 0 > events/enable
 echo > kprobe_events
 echo 'p:testprobe _do_fork' > kprobe_events
+enable_tracing
 
 # kprobe on / ftrace off
 echo 1 > events/kprobes/testprobe/enable

I wonder if this would be better to do the enabling from the ftracetest script instead. Then the tests would need to worry about it.

-- Steve

Hi Steve,

Hm, sounds reasonable. Also some other options should be reset for avoiding unexpected failure. I'll try that.

Thanks!

Masami Hiramatsu <[email protected]>

Introduce TMPDIR variable which is removed after each test is done, so that the test script can put their temporary files in that.

---
 tools/testing/selftests/ftrace/ftracetest |    2 ++
 1 file changed, 2 insertions(+)

index 4c6a0bf..172750f 100755
@@ -236,6 +236,7 @@ __run_test() { # testfile
 run_test() { # testfile
   local testname=`basename $1`
   local testlog=`mktemp $LOG_DIR/${testname}-log.XXXXXX`
+  export TMPDIR=`mktemp -d /tmp/ftracetest-dir.XXXXXX`
   testcase $1
   echo "execute: "$1 > $testlog
   SIG_RESULT=0

@@ -252,6 +253,7 @@ run_test() { # testfile
     catlog $testlog
     TOTAL_RESULT=1
   fi
+  rm -rf $TMPDIR
 }
 
 # load in the helper functions

Add function filter glob matching test case. This checks whether the kernel supports glob matching (front match, end match, middle match, side match, character class and '?').

Here is the test result.
-----
./ftracetest test.d/ftrace/func-filter-glob.tc
=== Ftrace unit tests ===
[1] ftrace - function glob filters [PASS]

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

---
 .../ftrace/test.d/ftrace/func-filter-glob.tc       |   49 ++++++++++++++++++++
 1 file changed, 49 insertions(+)
 create mode 100644 tools/testing/selftests/ftrace/test.d/ftrace/func-filter-glob.tc

new file mode 100644
index 0000000..9dcd0ca
@@ -0,0 +1,49 @@
+#!/bin/sh
+# description: ftrace - function glob filters
+
+# Make sure that function glob matching filter works.
+
+if ! grep -q function available_tracers; then
+    echo "no function tracer configured"
+    exit_unsupported
+fi
+
+disable_tracing
+clear_trace
+
+# filter by ?, schedule is always good
+if ! echo "sch?dule" > set_ftrace_filter; then
+    # test for powerpc 64
+    if ! echo ".sch?dule" > set_ftrace_filter; then
+	fail "can not enable schedule filter"
+    fi
+    cat set_ftrace_filter | grep '^.schedule$'
+else
+    cat set_ftrace_filter | grep '^schedule$'
+fi
+
+ftrace_filter_check() { # glob grep
+  echo "$1" > set_ftrace_filter
+  cut -f1 -d" " set_ftrace_filter > $TMPDIR/actual
+  cut -f1 -d" " available_filter_functions | grep "$2" > $TMPDIR/expected
+  DIFF=`diff $TMPDIR/actual $TMPDIR/expected`
+  test -z "$DIFF"
+}
+
+# filter by *, front match
+ftrace_filter_check '*schedule' '^.*schedule$'
+
+# filter by *, middle match
+ftrace_filter_check '*schedule*' '^.*schedule.*$'
+
+# filter by *, end match
+ftrace_filter_check 'schedule*' '^schedule.*$'
+
+# filter by *, both side match
+ftrace_filter_check 'sch*ule' '^sch.*ule$'
+
+# filter by char class.
+ftrace_filter_check '[Ss]y[Ss]_*' '^[Ss]y[Ss]_.*$'
+
+echo > set_ftrace_filter
+enable_tracing

Add a testcase for types of kprobe event. This checks kprobe event can accept and correctly expressed the arguments typed as s32, u32, x32 and bitfield.

Here is the test result.
-----

  # ./ftracetest test.d/kprobe/kprobe_args_type.tc
  === Ftrace unit tests ===
  [1] Kprobes event arguments with types	[PASS]

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

---
 .../ftrace/test.d/kprobe/kprobe_args_type.tc       |   37 ++++++++++++++++++++
 1 file changed, 37 insertions(+)
 create mode 100644 tools/testing/selftests/ftrace/test.d/kprobe/kprobe_args_type.tc

new file mode 100644
index 0000000..0a78705
@@ -0,0 +1,37 @@
+#!/bin/sh
+# description: Kprobes event arguments with types
+
+[ -f kprobe_events ] || exit_unsupported # this is configurable
+
+grep "x8/16/32/64" README > /dev/null || exit_unsupported # version issue
+
+echo 0 > events/enable
+echo > kprobe_events
+enable_tracing
+
+echo 'p:testprobe _do_fork $stack0:s32 $stack0:u32 $stack0:x32 $stack0:b8@4/32' > kprobe_events
+grep testprobe kprobe_events
+test -d events/kprobes/testprobe
+
+echo 1 > events/kprobes/testprobe/enable
+( echo "forked")
+echo 0 > events/kprobes/testprobe/enable
+ARGS=`tail -n 1 trace | sed -e 's/.* arg1=\(.*\) arg2=\(.*\) arg3=\(.*\) arg4=\(.*\)/\1 \2 \3 \4/'`
+
+check_types() {
+  X1=`printf "%x" $1 | tail -c 8`
+  X2=`printf "%x" $2`
+  X3=`printf "%x" $3`
+  test $X1 = $X2
+  test $X2 = $X3
+  test 0x$X3 = $3
+
+  B4=`printf "%x" $4`
+  B3=`echo -n $X3 | tail -c 3 | head -c 2`
+  test $B3 = $B4
+}
+check_types $ARGS
+
+echo "-:testprobe" >> kprobe_events
+clear_trace
+test -d events/kprobes/testprobe && exit 1 || exit 0