perf test: Silence tracepoint event failures

Currently, when perf test is run by a normal user, it'll fail to access tracepoint events. However the output is somewhat messy since it tries to be nice with long error messages and hints. IMHO it's not needed for 'perf test' by default and AFAIK the perf test uses pr_debug() rather than pr_err() for such messages so that one can use -v option to see further details on failed testcases if needed.

Before:

  $ perf test
   1: vmlinux symtab matches kallsyms                          : FAILED!
   2: detect openat syscall event                              :Error:
  No permissions to read
  /sys/kernel/debug/tracing/events/syscalls/sys_enter_openat
  Hint:	Try 'sudo mount -o remount,mode=755 /sys/kernel/debug/tracing'
  FAILED!
   3: detect openat syscall event on all cpus                  :Error:
  No permissions to read
  /sys/kernel/debug/tracing/events/syscalls/sys_enter_openat
  Hint:	Try 'sudo mount -o remount,mode=755 /sys/kernel/debug/tracing'
  FAILED!
   ...

After:

  $ perf test
   1: vmlinux symtab matches kallsyms                          : FAILED!
   2: detect openat syscall event                              : FAILED!
   3: detect openat syscall event on all cpus                  : FAILED!
   ...

  $ perf test -v 2
   2: detect openat syscall event                              :
  --- start ---
  test child forked, pid 30575
  Error:	    No permissions to read
  /sys/kernel/debug/tracing/events/syscalls/sys_enter_openat
  Hint:  Try 'sudo mount -o remount,mode=755 /sys/kernel/debug/tracing'

test child finished with -1
---- end ----
detect openat syscall event: FAILED!

---
 tools/perf/tests/openat-syscall-all-cpus.c  | 2 +-
 tools/perf/tests/openat-syscall-tp-fields.c | 2 +-
 tools/perf/tests/openat-syscall.c           | 2 +-
 3 files changed, 3 insertions(+), 3 deletions(-)

index 9e104a2e973d..2006485a2859 100644
@@ -34,7 +34,7 @@ int test__openat_syscall_event_on_all_cpus(void)
 	evsel = perf_evsel__newtp("syscalls", "sys_enter_openat");
 	if (IS_ERR(evsel)) {
 		tracing_path__strerror_open_tp(errno, errbuf, sizeof(errbuf), "syscalls", "sys_enter_openat");
-		pr_err("%s\n", errbuf);
+		pr_debug("%s\n", errbuf);
 		goto out_thread_map_delete;
 	}
 

index 473d3869727e..5e811cd8f1c3 100644
@@ -89,7 +89,7 @@ int test__syscall_openat_tp_fields(void)
 
 				err = perf_evsel__parse_sample(evsel, event, &sample);
 				if (err) {
-					pr_err("Can't parse sample, err = %d\n", err);
+					pr_debug("Can't parse sample, err = %d\n", err);
 					goto out_delete_evlist;
 				}
 

index 7b1db8306098..033b54797b8a 100644
@@ -22,7 +22,7 @@ int test__openat_syscall_event(void)
 	evsel = perf_evsel__newtp("syscalls", "sys_enter_openat");
 	if (IS_ERR(evsel)) {
 		tracing_path__strerror_open_tp(errno, errbuf, sizeof(errbuf), "syscalls", "sys_enter_openat");
-		pr_err("%s\n", errbuf);
+		pr_debug("%s\n", errbuf);
 		goto out_thread_map_delete;
 	}
 

2.6.0

Currently libtraceevent emits warning on unsupported event formats. However it'd be better to see them only -v option is given. To do that, it needs to override the warning() function which is used in the libtracevent. Thus add set_warning_routine() same as set_die_routine() and check the verbose flag in our warning routine.

Before:

  # perf test 5
   5: parse events tests                                       :
    Warning: [kvmmmu:kvm_mmu_get_page] bad op token {
    Warning: [kvmmmu:kvm_mmu_sync_page] bad op token {
    Warning: [kvmmmu:kvm_mmu_unsync_page] bad op token {
    Warning: [kvmmmu:kvm_mmu_prepare_zap_page] bad op token {
    Warning: [kvmmmu:fast_page_fault] function is_writable_pte not defined
    ...
   Ok

After:

  # perf test 5
   5: parse events tests                                       : Ok

---
 tools/perf/tests/parse-events.c | 14 ++++++++++++++
 tools/perf/util/usage.c         |  5 +++++
 tools/perf/util/util.h          |  1 +
 3 files changed, 20 insertions(+)

index 0648b84a9171..636d7b42d844 100644
@@ -5,6 +5,7 @@
 #include <api/fs/fs.h>
 #include "tests.h"
 #include "debug.h"
+#include "util.h"
 #include <linux/hw_breakpoint.h>
 #include <api/fs/fs.h>
 

@@ -1753,6 +1754,17 @@ static int test_pmu_events(void)
 	return ret;
 }
 
+static void debug_warn(const char *warn, va_list params)
+{
+	char msg[1024];
+
+	if (!verbose)
+		return;
+
+	vsnprintf(msg, sizeof(msg), warn, params);
+	fprintf(stderr, " Warning: %s\n", msg);
+}
+
 int test__parse_events(void)
 {
 	int ret1, ret2 = 0;

@@ -1764,6 +1776,8 @@ do {							\
 		ret2 = ret1;				\
 } while (0)
 
+	set_warning_routine(debug_warn);
+
 	TEST_EVENTS(test__events);
 
 	if (test_pmu())

index 4007aca8e0ca..6adfa18cdd4e 100644
@@ -50,6 +50,11 @@ void set_die_routine(void (*routine)(const char *err, va_list params) NORETURN)
 	die_routine = routine;
 }
 
+void set_warning_routine(void (*routine)(const char *err, va_list params))
+{
+	warn_routine = routine;
+}
+
 void usage(const char *err)
 {
 	usage_routine(err);

index 3d5b01e8978f..4cfb913aa9e0 100644
@@ -145,6 +145,7 @@ extern void warning(const char *err, ...) __attribute__((format (printf, 1, 2)))
 
 
 extern void set_die_routine(void (*routine)(const char *err, va_list params) NORETURN);
+extern void set_warning_routine(void (*routine)(const char *err, va_list params));
 
 extern int prefixcmp(const char *str, const char *prefix);
 extern void set_buildid_dir(const char *dir);

2.6.0

Em Mon, Oct 19, 2015 at 10:09:26AM -0600, David Ahern escreveu:

Tested, applied.

- Arnaldo

-----8<-----

Em Tue, Oct 20, 2015 at 12:23:48AM +0900, Namhyung Kim escreveu:

Here I get useless informational messages about registering plugins, guess those should move to pr_debug2, no?

Anyway, applying the patch, the common case is to run 'perf test'.

[acme@zoo linux]$ perf test -v 2
2: detect openat syscall event :
--- start ---
test child forked, pid 22866
registering plugin: /home/acme/.traceevent/plugins/plugin_function.so registering plugin: /home/acme/.traceevent/plugins/plugin_mac80211.so registering plugin: /home/acme/.traceevent/plugins/plugin_scsi.so registering plugin: /home/acme/.traceevent/plugins/plugin_hrtimer.so registering plugin: /home/acme/.traceevent/plugins/plugin_sched_switch.so registering plugin: /home/acme/.traceevent/plugins/plugin_cfg80211.so registering plugin: /home/acme/.traceevent/plugins/plugin_kmem.so registering plugin: /home/acme/.traceevent/plugins/plugin_kvm.so registering plugin: /home/acme/.traceevent/plugins/plugin_xen.so registering plugin: /home/acme/.traceevent/plugins/plugin_jbd2.so
Error: No permissions to read /sys/kernel/debug/tracing/events/syscalls/sys_enter_openat
Hint: Try 'sudo mount -o remount,mode=755 /sys/kernel/debug/tracing'

test child finished with -1
---- end ----
detect openat syscall event: FAILED!
[acme@zoo linux]$