tracing: Hopefully last update for merge window

Some last minute additions.

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

Head SHA1: 772b020609258144b80a853d7305b5723125f4ca

Marcin Nowakowski (2):
tracing/kprobes: Add a helper method to return number of probe hits kprobes/trace: Fix kprobe selftest for newer gcc

Masami Hiramatsu (1):
selftests: ftrace: Shift down default message verbosity

Pavankumar Kondeti (1):
tracing: Use SOFTIRQ_OFFSET for softirq dectection for more accurate results

Sebastian Andrzej Siewior (1):
tracing/rb: Init the CPU mask on allocation

----

 kernel/trace/ring_buffer.c                |  2 +-
 kernel/trace/trace.c                      |  2 +-
 kernel/trace/trace_kprobe.c               | 47 +++++++++++++++++++++++--------
 tools/testing/selftests/ftrace/ftracetest | 18 +++++-------
 4 files changed, 45 insertions(+), 24 deletions(-)

From: Pavankumar Kondeti <[email protected]>

The 's' flag is supposed to indicate that a softirq is running. This can be detected by testing the preempt_count with SOFTIRQ_OFFSET.

The current code tests the preempt_count with SOFTIRQ_MASK, which would be true even when softirqs are disabled but not serving a softirq.

---
 kernel/trace/trace.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

index 6f420d7b703b..970aafe80b49 100644
@@ -1949,7 +1949,7 @@ tracing_generic_entry_update(struct trace_entry *entry, unsigned long flags,
 #endif
 		((pc & NMI_MASK    ) ? TRACE_FLAG_NMI     : 0) |
 		((pc & HARDIRQ_MASK) ? TRACE_FLAG_HARDIRQ : 0) |
-		((pc & SOFTIRQ_MASK) ? TRACE_FLAG_SOFTIRQ : 0) |
+		((pc & SOFTIRQ_OFFSET) ? TRACE_FLAG_SOFTIRQ : 0) |
 		(tif_need_resched() ? TRACE_FLAG_NEED_RESCHED : 0) |
 		(test_preempt_need_resched() ? TRACE_FLAG_PREEMPT_RESCHED : 0);
 }

2.10.2

From: Sebastian Andrzej Siewior <[email protected]>

Before commit b32614c03413 ("tracing/rb: Convert to hotplug state machine") the allocated cpumask was initialized to the mask of ONLINE or POSSIBLE CPUs. After the CPU hotplug changes the buffer initialisation moved to trace_rb_cpu_prepare() but I forgot to initially set the cpumask to zero. This is done now.

---
 kernel/trace/ring_buffer.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

index f17476f9d7f4..7edfd41d506c 100644
@@ -1303,7 +1303,7 @@ struct ring_buffer *__ring_buffer_alloc(unsigned long size, unsigned flags,
 	if (!buffer)
 		return NULL;
 
-	if (!alloc_cpumask_var(&buffer->cpumask, GFP_KERNEL))
+	if (!zalloc_cpumask_var(&buffer->cpumask, GFP_KERNEL))
 		goto fail_free_buffer;
 
 	nr_pages = DIV_ROUND_UP(size, BUF_PAGE_SIZE);

2.10.2

From: Marcin Nowakowski <[email protected]>

The number of probe hits is stored in a percpu variable and therefore can't be read directly. Add a helper method trace_kprobe_nhit() that performs the required calculation.

It will be used in a follow-up commit that changes kprobe selftests to verify the number of probe hits.

---
 kernel/trace/trace_kprobe.c | 19 +++++++++++++------
 1 file changed, 13 insertions(+), 6 deletions(-)

index eb6c9f1d3a93..a2af1bceca29 100644
@@ -73,6 +73,17 @@ static nokprobe_inline bool trace_kprobe_is_on_module(struct trace_kprobe *tk)
 	return !!strchr(trace_kprobe_symbol(tk), ':');
 }
 
+static nokprobe_inline unsigned long trace_kprobe_nhit(struct trace_kprobe *tk)
+{
+	unsigned long nhit = 0;
+	int cpu;
+
+	for_each_possible_cpu(cpu)
+		nhit += *per_cpu_ptr(tk->nhit, cpu);
+
+	return nhit;
+}
+
 static int register_kprobe_event(struct trace_kprobe *tk);
 static int unregister_kprobe_event(struct trace_kprobe *tk);
 

@@ -882,14 +893,10 @@ static const struct file_operations kprobe_events_ops = {
 static int probes_profile_seq_show(struct seq_file *m, void *v)
 {
 	struct trace_kprobe *tk = v;
-	unsigned long nhit = 0;
-	int cpu;
-
-	for_each_possible_cpu(cpu)
-		nhit += *per_cpu_ptr(tk->nhit, cpu);
 
 	seq_printf(m, "  %-44s %15lu %15lu\n",
-		   trace_event_name(&tk->tp.call), nhit,
+		   trace_event_name(&tk->tp.call),
+		   trace_kprobe_nhit(tk),
 		   tk->rp.kp.nmissed);
 
 	return 0;

2.10.2

From: Marcin Nowakowski <[email protected]>

Commit 265a5b7ee3eb ("kprobes/trace: Fix kprobe selftest for gcc 4.6") has added __used attribute to kprobe_trace_selftest_target to ensure that the method is listed in kallsyms table.

However, even though the method remains in the kernel image, the actual call is optimized away as there are no side effects and the return value is never checked.

Add a return value check and a 'noinline' attribute to ensure that an inlined copy of the method is not used by the caller. Also add checks that verify that the kprobe was really hit, as at the moment the tests show positive results despite the test method being optimized away.

Finally, add __init annotations to find_trace_probe_file() and kprobe_trace_selftest_target() as they are only called from within an __init method.

---
 kernel/trace/trace_kprobe.c | 28 +++++++++++++++++++++++-----
 1 file changed, 23 insertions(+), 5 deletions(-)

index a2af1bceca29..a133ecd741e4 100644
@@ -1361,18 +1361,18 @@ fs_initcall(init_kprobe_trace);
 
 
 #ifdef CONFIG_FTRACE_STARTUP_TEST
-
 /*
  * The "__used" keeps gcc from removing the function symbol
- * from the kallsyms table.
+ * from the kallsyms table. 'noinline' makes sure that there
+ * isn't an inlined version used by the test method below
  */
-static __used int kprobe_trace_selftest_target(int a1, int a2, int a3,
-					       int a4, int a5, int a6)
+static __used __init noinline int
+kprobe_trace_selftest_target(int a1, int a2, int a3, int a4, int a5, int a6)
 {
 	return a1 + a2 + a3 + a4 + a5 + a6;
 }
 
-static struct trace_event_file *
+static struct __init trace_event_file *
 find_trace_probe_file(struct trace_kprobe *tk, struct trace_array *tr)
 {
 	struct trace_event_file *file;

@@ -1450,12 +1450,25 @@ static __init int kprobe_trace_self_tests_init(void)
 
 	ret = target(1, 2, 3, 4, 5, 6);
 
+	/*
+	 * Not expecting an error here, the check is only to prevent the
+	 * optimizer from removing the call to target() as otherwise there
+	 * are no side-effects and the call is never performed.
+	 */
+	if (ret != 21)
+		warn++;
+
 	/* Disable trace points before removing it */
 	tk = find_trace_kprobe("testprobe", KPROBE_EVENT_SYSTEM);
 	if (WARN_ON_ONCE(tk == NULL)) {
 		pr_warn("error on getting test probe.\n");
 		warn++;
 	} else {
+		if (trace_kprobe_nhit(tk) != 1) {
+			pr_warn("incorrect number of testprobe hits\n");
+			warn++;
+		}
+
 		file = find_trace_probe_file(tk, top_trace_array());
 		if (WARN_ON_ONCE(file == NULL)) {
 			pr_warn("error on getting probe file.\n");

@@ -1469,6 +1482,11 @@ static __init int kprobe_trace_self_tests_init(void)
 		pr_warn("error on getting 2nd test probe.\n");
 		warn++;
 	} else {
+		if (trace_kprobe_nhit(tk) != 1) {
+			pr_warn("incorrect number of testprobe2 hits\n");
+			warn++;
+		}
+
 		file = find_trace_probe_file(tk, top_trace_array());
 		if (WARN_ON_ONCE(file == NULL)) {
 			pr_warn("error on getting probe file.\n");

2.10.2

From: Masami Hiramatsu <[email protected]>

Shift down default message verbosity, where it does not show error results in stdout by default. Since that behavior is the same as giving the --quiet option, this patch removes --quiet and makes --verbose increasing verbosity.

In other words, this changes verbosity options as below. ftracetest -q -> ftracetest
ftracetest -> ftracetest -v
ftracetest -v -> ftracetest -v -v (or -vv)

---
 tools/testing/selftests/ftrace/ftracetest | 18 +++++++-----------
 1 file changed, 7 insertions(+), 11 deletions(-)

index 685376b485a2..52e3c4df28d6 100755
@@ -13,8 +13,8 @@ echo "Usage: ftracetest [options] [testcase(s)] [testcase-directory(s)]"
 echo " Options:"
 echo "		-h|--help  Show help message"
 echo "		-k|--keep  Keep passed test logs"
-echo "		-v|--verbose Show all stdout messages in testcases"
-echo "		-q|--quiet Do not show error log on stdout"
+echo "		-v|--verbose Increase verbosity of test messages"
+echo "		-vv        Alias of -v -v (Show all results in stdout)"
 echo "		-d|--debug Debug mode (trace all shell commands)"
 exit $1
 }

@@ -55,12 +55,9 @@ parse_opts() { # opts
       KEEP_LOG=1
       shift 1
     ;;
-    --verbose|-v)
-      VERBOSE=1
-      shift 1
-    ;;
-    --quiet|-q)
-      BE_QUIET=1
+    --verbose|-v|-vv)
+      VERBOSE=$((VERBOSE + 1))
+      [ $1 == '-vv' ] && VERBOSE=$((VERBOSE + 1))
       shift 1
     ;;
     --debug|-d)

@@ -106,7 +103,6 @@ LOG_DIR=$TOP_DIR/logs/`date +%Y%m%d-%H%M%S`/
 KEEP_LOG=0
 DEBUG=0
 VERBOSE=0
-BE_QUIET=0
 # Parse command-line options
 parse_opts $*
 

@@ -246,7 +242,7 @@ run_test() { # testfile
   testcase $1
   echo "execute: "$1 > $testlog
   SIG_RESULT=0
-  if [ $VERBOSE -ne 0 ]; then
+  if [ $VERBOSE -ge 2 ]; then
     __run_test $1 2>> $testlog | tee -a $testlog
   else
     __run_test $1 >> $testlog 2>&1

@@ -256,7 +252,7 @@ run_test() { # testfile
     # Remove test log if the test was done as it was expected.
     [ $KEEP_LOG -eq 0 ] && rm $testlog
   else
-    [ $BE_QUIET -eq 0 ] && catlog $testlog
+    [ $VERBOSE -ge 1 ] && catlog $testlog
     TOTAL_RESULT=1
   fi
   rm -rf $TMPDIR

2.10.2

[ Rebased to add Shuah's ack ]

From: Masami Hiramatsu <[email protected]>
Date: Fri, 25 Nov 2016 21:58:48 +0900
Subject: [PATCH] selftests: ftrace: Shift down default message verbosity

Shift down default message verbosity, where it does not show error results in stdout by default. Since that behavior is the same as giving the --quiet option, this patch removes --quiet and makes --verbose increasing verbosity.

In other words, this changes verbosity options as below. ftracetest -q -> ftracetest
ftracetest -> ftracetest -v
ftracetest -v -> ftracetest -v -v (or -vv)

---
 tools/testing/selftests/ftrace/ftracetest | 18 +++++++-----------
 1 file changed, 7 insertions(+), 11 deletions(-)

index 685376b485a2..52e3c4df28d6 100755
@@ -13,8 +13,8 @@ echo "Usage: ftracetest [options] [testcase(s)] [testcase-directory(s)]"
 echo " Options:"
 echo "		-h|--help  Show help message"
 echo "		-k|--keep  Keep passed test logs"
-echo "		-v|--verbose Show all stdout messages in testcases"
-echo "		-q|--quiet Do not show error log on stdout"
+echo "		-v|--verbose Increase verbosity of test messages"
+echo "		-vv        Alias of -v -v (Show all results in stdout)"
 echo "		-d|--debug Debug mode (trace all shell commands)"
 exit $1
 }

@@ -55,12 +55,9 @@ parse_opts() { # opts
       KEEP_LOG=1
       shift 1
     ;;
-    --verbose|-v)
-      VERBOSE=1
-      shift 1
-    ;;
-    --quiet|-q)
-      BE_QUIET=1
+    --verbose|-v|-vv)
+      VERBOSE=$((VERBOSE + 1))
+      [ $1 == '-vv' ] && VERBOSE=$((VERBOSE + 1))
       shift 1
     ;;
     --debug|-d)

@@ -106,7 +103,6 @@ LOG_DIR=$TOP_DIR/logs/`date +%Y%m%d-%H%M%S`/
 KEEP_LOG=0
 DEBUG=0
 VERBOSE=0
-BE_QUIET=0
 # Parse command-line options
 parse_opts $*
 

@@ -246,7 +242,7 @@ run_test() { # testfile
   testcase $1
   echo "execute: "$1 > $testlog
   SIG_RESULT=0
-  if [ $VERBOSE -ne 0 ]; then
+  if [ $VERBOSE -ge 2 ]; then
     __run_test $1 2>> $testlog | tee -a $testlog
   else
     __run_test $1 >> $testlog 2>&1

@@ -256,7 +252,7 @@ run_test() { # testfile
     # Remove test log if the test was done as it was expected.
     [ $KEEP_LOG -eq 0 ] && rm $testlog
   else
-    [ $BE_QUIET -eq 0 ] && catlog $testlog
+    [ $VERBOSE -ge 1 ] && catlog $testlog
     TOTAL_RESULT=1
   fi
   rm -rf $TMPDIR

2.1.0