tracing: Fixes for v4.17-rc1

Linus,

Following tracing fixes:

- Add workqueue forward declaration (for new work, but a nice clean up)

- seftest fixes for the new histogram code

- Print output fix for hwlat tracer

- Fix missing system call events - due to change in x86 syscall naming

- Fix kprobe address being used by perf being hashed

Please pull the latest trace-v4.17-rc1 tree, which can be found at:

git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git
trace-v4.17-rc1

Tag SHA1: c9521e0e3e53b547e39eff37bf58baf2ec146c9d Head SHA1: 9a0fd675304d410f3a9586e1b333e16f4658d56c

Ahbong Chang (1):
tracing: Add missing forward declaration

Masami Hiramatsu (2):
selftests: ftrace: Fix trigger extended error testcase
selftests: ftrace: Add a testcase for multiple actions on trigger

Peter Xu (1):
tracing: Fix missing tab for hwlat_detector print format

Ravi Bangoria (1):
tracing: Fix kernel crash while using empty filter with perf

Steven Rostedt (VMware) (1):
tracing/x86: Update syscall trace events to handle new prefixed syscall func names

Thomas Richter (1):
kprobes: Fix random address output of blacklist file

----

 arch/x86/include/asm/ftrace.h                      | 19 +++++++++-
 include/trace/events/workqueue.h                   |  2 +
 kernel/kprobes.c                                   |  2 +-
 kernel/trace/trace_entries.h                       |  2 +-
 kernel/trace/trace_events_filter.c                 | 14 +++----
 .../inter-event/trigger-extended-error-support.tc  |  2 +-
 .../inter-event/trigger-multi-actions-accept.tc    | 44 ++++++++++++++++++++++
 7 files changed, 73 insertions(+), 12 deletions(-)
 create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-multi-actions-accept.tc

From: Ahbong Chang <[email protected]>

Without this forward declaration compile may fail if this header is included only for registering other probe event without struct pool_workqueue.

---
 include/trace/events/workqueue.h | 2 ++
 1 file changed, 2 insertions(+)

index 2f057a494d93..9a761bc6a251 100644
@@ -25,6 +25,8 @@ DECLARE_EVENT_CLASS(workqueue_work,
 	TP_printk("work struct %p", __entry->work)
 );
 
+struct pool_workqueue;
+
 /**
  * workqueue_queue_work - called when a work gets queued
  * @req_cpu:	the requested cpu

2.16.3

From: "Steven Rostedt (VMware)" <[email protected]>

Arnaldo noticed that the latest kernel is missing the syscall event system directory in x86. I bisected it down to d5a00528b58c ("syscalls/core, syscalls/x86: Rename struct pt_regs-based sys_*() to __x64_sys_*()").

The system call trace events are special, as there is only one trace event for all system calls (the raw_syscalls). But a macro that wraps the system calls creates meta data for them that copies the name to find the system call that maps to the system call table (the number). At boot up, it does a kallsyms lookup of the system call table to find the function that maps to the meta data of the system call. If it does not find a function, then that system call is ignored.

Because the x86 system calls had "__x64_", or "__ia32_" prefixed to the "sys" for the names, they do not match the default compare algorithm. As this was a problem for power pc, the algorithm can be overwritten by the architecture. The solution is to have x86 have its own algorithm to do the compare and this brings back the system call trace events.

---
 arch/x86/include/asm/ftrace.h | 19 +++++++++++++++++--
 1 file changed, 17 insertions(+), 2 deletions(-)

index 09ad88572746..cc8f8fcf9b4a 100644
@@ -46,7 +46,21 @@ int ftrace_int3_handler(struct pt_regs *regs);
 #endif /* CONFIG_FUNCTION_TRACER */
 
 
-#if !defined(__ASSEMBLY__) && !defined(COMPILE_OFFSETS)
+#ifndef __ASSEMBLY__
+
+#define ARCH_HAS_SYSCALL_MATCH_SYM_NAME
+static inline bool arch_syscall_match_sym_name(const char *sym, const char *name)
+{
+	/*
+	 * Compare the symbol name with the system call name. Skip the
+	 * "__x64_sys", "__ia32_sys" or simple "sys" prefix.
+	 */
+	return !strcmp(sym + 3, name + 3) ||
+		(!strncmp(sym, "__x64_", 6) && !strcmp(sym + 9, name + 3)) ||
+		(!strncmp(sym, "__ia32_", 7) && !strcmp(sym + 10, name + 3));
+}
+
+#ifndef COMPILE_OFFSETS
 
 #if defined(CONFIG_FTRACE_SYSCALLS) && defined(CONFIG_IA32_EMULATION)
 #include <asm/compat.h>

@@ -67,6 +81,7 @@ static inline bool arch_trace_is_compat_syscall(struct pt_regs *regs)
 	return false;
 }
 #endif /* CONFIG_FTRACE_SYSCALLS && CONFIG_IA32_EMULATION */
-#endif /* !__ASSEMBLY__  && !COMPILE_OFFSETS */
+#endif /* !COMPILE_OFFSETS */
+#endif /* !__ASSEMBLY__ */
 
 #endif /* _ASM_X86_FTRACE_H */

2.16.3

From: Ravi Bangoria <[email protected]>

Kernel is crashing when user tries to record 'ftrace:function' event with empty filter:

  # perf record -e ftrace:function --filter="" ls

  # dmesg
  BUG: unable to handle kernel NULL pointer dereference at 0000000000000008
  Oops: 0000 [#1] SMP PTI
  ...
  RIP: 0010:ftrace_profile_set_filter+0x14b/0x2d0
  RSP: 0018:ffffa4a7c0da7d20 EFLAGS: 00010246
  RAX: ffffa4a7c0da7d64 RBX: 0000000000000000 RCX: 0000000000000006
  RDX: 0000000000000000 RSI: 0000000000000092 RDI: ffff8c48ffc968f0
  ...
  Call Trace:
   _perf_ioctl+0x54a/0x6b0
   ? rcu_all_qs+0x5/0x30
  ...

After patch:

  # perf record -e ftrace:function --filter="" ls
  failed to set filter "" on event ftrace:function with 22 (Invalid argument)

Also, if user tries to echo "" > filter, it used to throw an error. This behavior got changed by commit 80765597bc58 ("tracing: Rewrite filter logic to be simpler and faster"). This patch restores the behavior as a side effect:

Before patch:

  # echo "" > filter
  #

After patch:

  # echo "" > filter
  bash: echo: write error: Invalid argument
  #

---
 kernel/trace/trace_events_filter.c | 14 +++++++-------
 1 file changed, 7 insertions(+), 7 deletions(-)

index 9b4716bb8bb0..1f951b3df60c 100644
@@ -1499,14 +1499,14 @@ static int process_preds(struct trace_event_call *call,
 		return ret;
 	}
 
-	if (!nr_preds) {
-		prog = NULL;
-	} else {
-		prog = predicate_parse(filter_string, nr_parens, nr_preds,
+	if (!nr_preds)
+		return -EINVAL;
+
+	prog = predicate_parse(filter_string, nr_parens, nr_preds,
 			       parse_pred, call, pe);
-		if (IS_ERR(prog))
-			return PTR_ERR(prog);
-	}
+	if (IS_ERR(prog))
+		return PTR_ERR(prog);
+
 	rcu_assign_pointer(filter->prog, prog);
 	return 0;
 }

2.16.3

From: Thomas Richter <[email protected]>

File /sys/kernel/debug/kprobes/blacklist displays random addresses:

[root@s8360046 linux]# cat /sys/kernel/debug/kprobes/blacklist
0x0000000047149a90-0x00000000bfcb099a print_type_x8
....

This breaks 'perf probe' which uses the blacklist file to prohibit probes on certain functions by checking the address range.

Fix this by printing the correct (unhashed) address.

The file mode is read all but this is not an issue as the file hierarchy points out:

 # ls -ld /sys/ /sys/kernel/ /sys/kernel/debug/ /sys/kernel/debug/kprobes/
	/sys/kernel/debug/kprobes/blacklist
dr-xr-xr-x 12 root root 0 Apr 19 07:56 /sys/
drwxr-xr-x  8 root root 0 Apr 19 07:56 /sys/kernel/
drwx------ 16 root root 0 Apr 19 06:56 /sys/kernel/debug/
drwxr-xr-x  2 root root 0 Apr 19 06:56 /sys/kernel/debug/kprobes/
-r--r--r--  1 root root 0 Apr 19 06:56 /sys/kernel/debug/kprobes/blacklist

Everything in and below /sys/kernel/debug is rwx to root only, no group or others have access.

Background:
Directory /sys/kernel/debug/kprobes is created by debugfs_create_dir() which sets the mode bits to rwxr-xr-x. Maybe change that to use the parent's directory mode bits instead?

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

index 102160ff5c66..ea619021d901 100644
@@ -2428,7 +2428,7 @@ static int kprobe_blacklist_seq_show(struct seq_file *m, void *v)
 	struct kprobe_blacklist_entry *ent =
 		list_entry(v, struct kprobe_blacklist_entry, list);
 
-	seq_printf(m, "0x%p-0x%p\t%ps\n", (void *)ent->start_addr,
+	seq_printf(m, "0x%px-0x%px\t%ps\n", (void *)ent->start_addr,
 		   (void *)ent->end_addr, (void *)ent->start_addr);
 	return 0;
 }

2.16.3

From: Masami Hiramatsu <[email protected]>

Previous testcase redirects echo-out into /dev/null using "&>" as below

echo "trigger-command" >> trigger &> /dev/null

But this means redirecting both stdout and stderr into /dev/null because it is same as below

echo "trigger-command" >> trigger > /dev/null 2>&1

So ">> trigger" redirects stdout to trigger file, but next "> /dev/null" redirects stdout to /dev/null again and the last "2>/&1" redirects stderr to stdout (/dev/null)

This fixes it by "2> /dev/null". And also, since it must fail, add "!" to echo command.

---
 .../ftrace/test.d/trigger/inter-event/trigger-extended-error-support.tc | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

index 786dce7e48be..2aabab363cfb 100644
@@ -29,7 +29,7 @@ do_reset
 
 echo "Test extended error support"
 echo 'hist:keys=pid:ts0=common_timestamp.usecs if comm=="ping"' > events/sched/sched_wakeup/trigger
-echo 'hist:keys=pid:ts0=common_timestamp.usecs if comm=="ping"' >> events/sched/sched_wakeup/trigger &>/dev/null
+! echo 'hist:keys=pid:ts0=common_timestamp.usecs if comm=="ping"' >> events/sched/sched_wakeup/trigger 2> /dev/null
 if ! grep -q "ERROR:" events/sched/sched_wakeup/hist; then
     fail "Failed to generate extended error in histogram"
 fi

2.16.3

From: Masami Hiramatsu <[email protected]>

Add a testcase for multiple actions with different parameters on an event trigger, which has been fixed by commit 192c283e93bd ("tracing: Add action comparisons
when testing matching hist triggers").

---
 .../inter-event/trigger-multi-actions-accept.tc    | 44 ++++++++++++++++++++++
 1 file changed, 44 insertions(+)
 create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-multi-actions-accept.tc

new file mode 100644
index 000000000000..c193dce611a2
@@ -0,0 +1,44 @@
+#!/bin/sh
+# description: event trigger - test multiple actions on hist trigger
+
+
+do_reset() {
+    reset_trigger
+    echo > set_event
+    clear_trace
+}
+
+fail() { #msg
+    do_reset
+    echo $1
+    exit_fail
+}
+
+if [ ! -f set_event ]; then
+    echo "event tracing is not supported"
+    exit_unsupported
+fi
+
+if [ ! -f synthetic_events ]; then
+    echo "synthetic event is not supported"
+    exit_unsupported
+fi
+
+clear_synthetic_events
+reset_tracer
+do_reset
+
+echo "Test multiple actions on hist trigger"
+echo 'wakeup_latency u64 lat; pid_t pid' >> synthetic_events
+TRIGGER1=events/sched/sched_wakeup/trigger
+TRIGGER2=events/sched/sched_switch/trigger
+
+echo 'hist:keys=pid:ts0=common_timestamp.usecs if comm=="cyclictest"' > $TRIGGER1
+echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0 if next_comm=="cyclictest"' >> $TRIGGER2
+echo 'hist:keys=next_pid:onmatch(sched.sched_wakeup).wakeup_latency(sched.sched_switch.$wakeup_lat,next_pid) if next_comm=="cyclictest"' >> $TRIGGER2
+echo 'hist:keys=next_pid:onmatch(sched.sched_wakeup).wakeup_latency(sched.sched_switch.$wakeup_lat,prev_pid) if next_comm=="cyclictest"' >> $TRIGGER2
+echo 'hist:keys=next_pid if next_comm=="cyclictest"' >> $TRIGGER2
+
+do_reset
+
+exit 0

2.16.3

From: Peter Xu <[email protected]>

It's been missing for a while but no one is touching that up. Fix it.

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

index e954ae3d82c0..e3a658bac10f 100644
@@ -356,7 +356,7 @@ FTRACE_ENTRY(hwlat, hwlat_entry,
 		__field(	unsigned int,		seqnum		)
 	),
 
-	F_printk("cnt:%u\tts:%010llu.%010lu\tinner:%llu\touter:%llunmi-ts:%llu\tnmi-count:%u\n",
+	F_printk("cnt:%u\tts:%010llu.%010lu\tinner:%llu\touter:%llu\tnmi-ts:%llu\tnmi-count:%u\n",
 		 __entry->seqnum,
 		 __entry->tv_sec,
 		 __entry->tv_nsec,

2.16.3