[PATCH 1/2] perf test: Silence tracepoint event failures

[PATCH 1/2] perf test: Silence tracepoint event failures

[Namhyung Kim]

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!

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
 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(-)

diff --git a/tools/perf/tests/openat-syscall-all-cpus.c b/tools/perf/tests/openat-syscall-all-cpus.c
index 9e104a2e973d..2006485a2859 100644
--- a/tools/perf/tests/openat-syscall-all-cpus.c
+++ b/tools/perf/tests/openat-syscall-all-cpus.c
@@ -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;
 	}
 
diff --git a/tools/perf/tests/openat-syscall-tp-fields.c b/tools/perf/tests/openat-syscall-tp-fields.c
index 473d3869727e..5e811cd8f1c3 100644
--- a/tools/perf/tests/openat-syscall-tp-fields.c
+++ b/tools/perf/tests/openat-syscall-tp-fields.c
@@ -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;
 				}
 
diff --git a/tools/perf/tests/openat-syscall.c b/tools/perf/tests/openat-syscall.c
index 7b1db8306098..033b54797b8a 100644
--- a/tools/perf/tests/openat-syscall.c
+++ b/tools/perf/tests/openat-syscall.c
@@ -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

[PATCH 2/2] perf test: Suppress libtraceevent warnings

[Namhyung Kim]

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

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
---
 tools/perf/tests/parse-events.c | 14 ++++++++++++++
 tools/perf/util/usage.c         |  5 +++++
 tools/perf/util/util.h          |  1 +
 3 files changed, 20 insertions(+)

diff --git a/tools/perf/tests/parse-events.c b/tools/perf/tests/parse-events.c
index 0648b84a9171..636d7b42d844 100644
--- a/tools/perf/tests/parse-events.c
+++ b/tools/perf/tests/parse-events.c
@@ -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())
diff --git a/tools/perf/util/usage.c b/tools/perf/util/usage.c
index 4007aca8e0ca..6adfa18cdd4e 100644
--- a/tools/perf/util/usage.c
+++ b/tools/perf/util/usage.c
@@ -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);
diff --git a/tools/perf/util/util.h b/tools/perf/util/util.h
index 3d5b01e8978f..4cfb913aa9e0 100644
--- a/tools/perf/util/util.h
+++ b/tools/perf/util/util.h
@@ -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

Re: [PATCH 1/2] perf test: Silence tracepoint event failures

[David Ahern]

On 10/19/15 9:23 AM, Namhyung Kim wrote:
> 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.
>
-----8<-----
>
> Signed-off-by: Namhyung Kim <namhyung@kernel.org>
> ---
>   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(-)
>

Acked-by: David Ahern <dsahern@gmail.com>

Re: [PATCH 2/2] perf test: Suppress libtraceevent warnings

[David Ahern]

On 10/19/15 9:23 AM, Namhyung Kim wrote:
> 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
>
> Signed-off-by: Namhyung Kim <namhyung@kernel.org>
> ---
>   tools/perf/tests/parse-events.c | 14 ++++++++++++++
>   tools/perf/util/usage.c         |  5 +++++
>   tools/perf/util/util.h          |  1 +
>   3 files changed, 20 insertions(+)
>

Acked-by: David Ahern <dsahern@gmail.com>

Re: [PATCH 1/2] perf test: Silence tracepoint event failures

[Arnaldo Carvalho de Melo]

Em Tue, Oct 20, 2015 at 12:23:48AM +0900, Namhyung Kim escreveu:
> 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!


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]$

Re: [PATCH 2/2] perf test: Suppress libtraceevent warnings

[Arnaldo Carvalho de Melo]

Em Mon, Oct 19, 2015 at 10:09:26AM -0600, David Ahern escreveu:
> On 10/19/15 9:23 AM, Namhyung Kim wrote:
> >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 {
> >     ...
> >    Ok

> >After:
> >   # perf test 5
> >    5: parse events tests                                       : Ok
 
> Acked-by: David Ahern <dsahern@gmail.com>

Tested, applied.

- Arnaldo

[tip:perf/core] perf test: Silence tracepoint event failures

[tip-bot for Namhyung Kim]

Commit-ID:  8719138318316656988dbd422461c1addc9a9159
Gitweb:     http://git.kernel.org/tip/8719138318316656988dbd422461c1addc9a9159
Author:     Namhyung Kim <namhyung@kernel.org>
AuthorDate: Tue, 20 Oct 2015 00:23:48 +0900
Committer:  Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Mon, 19 Oct 2015 14:57:49 -0300

perf test: Silence tracepoint event failures

Currently, when 'perf test' is run by a normal user, it'll fail to
access tracepoint events.  The output becomes somewhat messy because it
tries to be nice with long error messages and hints.

IMHO this is not needed for 'perf test' by default and AFAIK '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!

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Acked-by: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/r/1445268229-1601-1-git-send-email-namhyung@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 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(-)

diff --git a/tools/perf/tests/openat-syscall-all-cpus.c b/tools/perf/tests/openat-syscall-all-cpus.c
index 9e104a2..2006485 100644
--- a/tools/perf/tests/openat-syscall-all-cpus.c
+++ b/tools/perf/tests/openat-syscall-all-cpus.c
@@ -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;
 	}
 
diff --git a/tools/perf/tests/openat-syscall-tp-fields.c b/tools/perf/tests/openat-syscall-tp-fields.c
index 473d386..5e811cd 100644
--- a/tools/perf/tests/openat-syscall-tp-fields.c
+++ b/tools/perf/tests/openat-syscall-tp-fields.c
@@ -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;
 				}
 
diff --git a/tools/perf/tests/openat-syscall.c b/tools/perf/tests/openat-syscall.c
index 7b1db83..033b547 100644
--- a/tools/perf/tests/openat-syscall.c
+++ b/tools/perf/tests/openat-syscall.c
@@ -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;
 	}
 

[tip:perf/core] perf test: Suppress libtraceevent warnings

[tip-bot for Namhyung Kim]

Commit-ID:  2690c730935873065175de33f59cce5bb221b9dc
Gitweb:     http://git.kernel.org/tip/2690c730935873065175de33f59cce5bb221b9dc
Author:     Namhyung Kim <namhyung@kernel.org>
AuthorDate: Tue, 20 Oct 2015 00:23:49 +0900
Committer:  Arnaldo Carvalho de Melo <acme@redhat.com>
CommitDate: Mon, 19 Oct 2015 14:58:10 -0300

perf test: Suppress libtraceevent warnings

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

Signed-off-by: Namhyung Kim <namhyung@kernel.org>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Acked-by: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/r/1445268229-1601-2-git-send-email-namhyung@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
---
 tools/perf/tests/parse-events.c | 14 ++++++++++++++
 tools/perf/util/usage.c         |  5 +++++
 tools/perf/util/util.h          |  1 +
 3 files changed, 20 insertions(+)

diff --git a/tools/perf/tests/parse-events.c b/tools/perf/tests/parse-events.c
index 0648b84..636d7b4 100644
--- a/tools/perf/tests/parse-events.c
+++ b/tools/perf/tests/parse-events.c
@@ -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())
diff --git a/tools/perf/util/usage.c b/tools/perf/util/usage.c
index 4007aca..6adfa18 100644
--- a/tools/perf/util/usage.c
+++ b/tools/perf/util/usage.c
@@ -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);
diff --git a/tools/perf/util/util.h b/tools/perf/util/util.h
index 3d5b01e..4cfb913 100644
--- a/tools/perf/util/util.h
+++ b/tools/perf/util/util.h
@@ -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);