Commit Graph

415 Commits

Author SHA1 Message Date
David Ahern aa07df6eb5 perf trace: Update tid/pid filtering option to leverage symbol_conf
Leverage pid/tid filtering done by symbol_conf hooks.

Signed-off-by: David Ahern <dsahern@gmail.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Link: http://lkml.kernel.org/r/1480091392-35645-1-git-send-email-dsa@cumulusnetworks.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-11-25 16:04:22 -03:00
Arnaldo Carvalho de Melo ecf1e2253e perf trace: Use the syscall raw_syscalls:sys_enter timestamp
Instead of the one when another syscall takes place while another is being
processed (in another CPU, but we show it serialized, so need to "interrupt"
the other), and also when finally showing the sys_enter + sys_exit + duration,
where we were showing the sample->time for the sys_exit, duh.

Before:

  # perf trace sleep 1
  <SNIP>
     0.373 (   0.001 ms): close(fd: 3                   ) = 0
  1000.626 (1000.211 ms): nanosleep(rqtp: 0x7ffd6ddddfb0) = 0
  1000.653 (   0.003 ms): close(fd: 1                   ) = 0
  1000.657 (   0.002 ms): close(fd: 2                   ) = 0
  1000.667 (   0.000 ms): exit_group(                   )
  #

After:

  # perf trace sleep 1
  <SNIP>
     0.336 (   0.001 ms): close(fd: 3                   ) = 0
     0.373 (1000.086 ms): nanosleep(rqtp: 0x7ffe303e9550) = 0
  1000.481 (   0.002 ms): close(fd: 1                   ) = 0
  1000.485 (   0.001 ms): close(fd: 2                   ) = 0
  1000.494 (   0.000 ms): exit_group(                   )
[root@jouet linux]#

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-ecbzgmu2ni6glc6zkw8p1zmx@git.kernel.org
Fixes: 752fde44fd ("perf trace: Support interrupted syscalls")
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-10-24 11:07:46 -03:00
Arnaldo Carvalho de Melo 1f36946019 perf trace: Remove thread_trace->exit_time
Not used at all, we need just the entry_time to calculate the syscall
duration.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-js6r09zdwlzecvaei7t4l3vd@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-10-24 11:07:45 -03:00
Alexis Berlemont e36b7821a9 perf trace: Implement --delay
In the perf wiki todo-list[1], there is an entry regarding initial-delay
and 'perf trace'; the following small patch tries to fulfill this point.
It has been generated against the branch tip/perf/core.

It has only been implemented in the "trace__run" case.

Ex.:

  $ sudo strace -- ./perf trace --delay 5 sleep 1 2>&1
  ...
  fcntl(7, F_SETFL, O_RDONLY|O_NONBLOCK)  = 0
  ioctl(7, PERF_EVENT_IOC_ID, 0x7ffc8fd35718) = 0
  ioctl(11, PERF_EVENT_IOC_SET_OUTPUT, 0x7) = 0
  fcntl(11, F_SETFL, O_RDONLY|O_NONBLOCK) = 0
  ioctl(11, PERF_EVENT_IOC_ID, 0x7ffc8fd35718) = 0
  write(6, "\0", 1)                       = 1
  close(6)                                = 0
  nanosleep({0, 5000000}, NULL)           = 0  # DELAY OF 5 MS BEFORE ENABLING THE EVENTS
  ioctl(3, PERF_EVENT_IOC_ENABLE, 0)      = 0
  ioctl(4, PERF_EVENT_IOC_ENABLE, 0)      = 0
  ioctl(5, PERF_EVENT_IOC_ENABLE, 0)      = 0
  ioctl(7, PERF_EVENT_IOC_ENABLE, 0)      = 0
  ...

[1]: https://perf.wiki.kernel.org/index.php/Todo

Signed-off-by: Alexis Berlemont <alexis.berlemont@gmail.com>
Suggested-and-Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lkml.kernel.org/r/20161010054328.4028-2-alexis.berlemont@gmail.com
[ Add entry to the manpage, cut'n'pasted from stat's and record's ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-10-24 11:07:43 -03:00
Mathieu Poirier 3541c034d9 perf evsel: New tracepoint specific function
Making function perf_evsel__append_filter() static and introducing a new
tracepoint specific function to append filters.  That way we eliminate
redundant code and avoid formatting mistake.

Signed-off-by: Mathieu Poirier <mathieu.poirier@linaro.org>
Acked-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: linux-arm-kernel@lists.infradead.org
Link: http://lkml.kernel.org/r/1474037045-31730-3-git-send-email-mathieu.poirier@linaro.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-09-29 11:16:59 -03:00
Mathieu Poirier b15d0a4c82 perf tools: Make perf_evsel__append_filter() generic
By making function perf_evsel__append_filter() take a format rather than
an operator it is possible to reuse the code for other purposes (ex.
Intel PT and CoreSight) than tracepoints.

Signed-off-by: Mathieu Poirier <mathieu.poirier@linaro.org>
Acked-by: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: linux-arm-kernel@lists.infradead.org
Link: http://lkml.kernel.org/r/1474037045-31730-2-git-send-email-mathieu.poirier@linaro.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-09-29 11:16:58 -03:00
Arnaldo Carvalho de Melo f0bbd60226 perf trace: Beautify sched_[gs]et_attr return value
Both return errno, show the string associated then.

More work needed to capture the sched_attr arg to beautify it in turn,
probably using BPF.

Before:

     0.210 ( 0.001 ms): sched_setattr(uattr: 0x7ffc684f02b0) = -22

After the patch, for this sched_attr, all other parms are zero, so not
shown:

        struct sched_attr attr = {
                .size           = sizeof(attr),
                .sched_policy   = SCHED_DEADLINE,
                .sched_runtime  = 10 * USECS_PER_SEC,
                .sched_period   = 30 * USECS_PER_SEC,
                .sched_deadline = attr.sched_period,
        };

     0.321 ( 0.002 ms): sched_setattr(uattr: 0x7ffc44116da0) = -1 EINVAL Invalid argument

  [root@jouet c]# perf trace -e sched_setattr ./sched_deadline
  Couldn't negotiate deadline: Invalid argument
     0.229 ( 0.003 ms): sched_setattr(uattr: 0x7ffd8dcd8df0) = -1 EINVAL Invalid argument
  [root@jouet c]#

Now to figure out the reason for this EINVAL.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Clark Williams <williams@redhat.com>
Cc: Daniel Bristot de Oliveira <bristot@redhat.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-tyot2n7e48zm8pdw8tbcm3sl@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-09-28 13:48:04 -03:00
Arnaldo Carvalho de Melo bd48c63eb0 tools: Introduce tools/include/linux/time64.h for *SEC_PER_*SEC macros
And remove it from tools/perf/{perf,util}.h, making code that needs
these macros to include linux/time64.h instead, to match how this is
used in the kernel sources.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-e69fc1pvkgt57yvxqt6eunyg@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-08-23 15:37:33 -03:00
Arnaldo Carvalho de Melo e3e1d7e077 perf trace: Remove unused sys/ptrace.h include
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-ogtjqc0hxm961djgiwboe2q7@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-07-12 15:20:35 -03:00
Arnaldo Carvalho de Melo 48e1f91ad2 perf trace: Add conditional define for AT_FDCWD
This one was only defined if _GNU_SOURCE was set in older glibc
versions, check that and provide the define in such cases.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-ilsgsysr6s3mru7rf2befnu5@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-07-12 15:19:53 -03:00
Arnaldo Carvalho de Melo c8b5f2c96d tools: Introduce str_error_r()
The tools so far have been using the strerror_r() GNU variant, that
returns a string, be it the buffer passed or something else.

But that, besides being tricky in cases where we expect that the
function using strerror_r() returns the error formatted in a provided
buffer (we have to check if it returned something else and copy that
instead), breaks the build on systems not using glibc, like Alpine
Linux, where musl libc is used.

So, introduce yet another wrapper, str_error_r(), that has the GNU
interface, but uses the portable XSI variant of strerror_r(), so that
users rest asured that the provided buffer is used and it is what is
returned.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-d4t42fnf48ytlk8rjxs822tf@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-07-12 15:19:47 -03:00
Arnaldo Carvalho de Melo 98a91837dd perf rb_resort: Rename for_each() macros to for_each_entry()
To match the semantics for list.h in the kernel, that are the
interface we use in them.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Taeung Song <treeze.taeung@gmail.com>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-iaxuq2yu43mtb504j96q0axs@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-06-23 11:35:07 -03:00
Arnaldo Carvalho de Melo 602a1f4daa perf tools: Rename strlist_for_each() macros to for_each_entry()
To match the semantics for list.h in the kernel, that are the
interface we use in them.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Taeung Song <treeze.taeung@gmail.com>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-0b5i2ki9c3di6706fxpticsb@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-06-23 11:35:01 -03:00
Arnaldo Carvalho de Melo e5cadb93d0 perf evlist: Rename for_each() macros to for_each_entry()
To match the semantics for list.h in the kernel, that are used to
implement those macros.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Taeung Song <treeze.taeung@gmail.com>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-qbcjlgj0ffxquxscahbpddi3@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-06-23 11:26:15 -03:00
Arnaldo Carvalho de Melo 12f3ca4fc8 perf trace: Use the ptr->name beautifier as default for "filename" args
Auto-attach the ptr->name beautifier to syscall args "filename", "path"
and "pathname" if they are of type "const char *".

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-jxii4qmcgoppftv0zdvml9d7@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-05-23 16:41:00 -03:00
Arnaldo Carvalho de Melo b6565c908a perf trace: Use the fd->name beautifier as default for "fd" args
Noticed when the 'setsockopt' 'fd' arg wasn't being formatted via
the SCA_FD beautifier, so just remove the setting of "fd" args to
SCA_FD and do it when reading the syscall info, like we do for
args of type "pid_t", i.e. "fd" as the name should be enough as
the decision to use the SFA_FD beautifier. For odd cases we can
just do it explicitely.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-0qissgetiuqmqyj4b6ancmpn@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-05-23 16:41:00 -03:00
Arnaldo Carvalho de Melo caa36ed7ba perf trace: Only auto set call-graph to "dwarf" when syscalls are being traced
When --min-stack or --max-stack is passwd but --no-syscalls is also in
effect, there is no point in automatically setting '--call-graph dwarf'.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-pq922i7h9wef0pho1dqpttvn@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-05-20 11:43:57 -03:00
Arnaldo Carvalho de Melo fe176085a4 perf tools: Fix usage of max_stack sysctl
We cannot limit processing stacks from the current value of the sysctl,
as we may be processing perf.data files, possibly from other machines.

Instead use the old PERF_MAX_STACK_DEPTH, the sysctl default, that can
be overriden using --max-stack or equivalent.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexander Shishkin <alexander.shishkin@linux.intel.com>
Cc: Alexei Starovoitov <ast@kernel.org>
Cc: Brendan Gregg <brendan.d.gregg@gmail.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: He Kuang <hekuang@huawei.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Masami Hiramatsu <mhiramat@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Cc: Thomas Gleixner <tglx@linutronix.de>
Cc: Vince Weaver <vincent.weaver@maine.edu>
Cc: Wang Nan <wangnan0@huawei.com>
Cc: Zefan Li <lizefan@huawei.com>
Fixes: 4cb93446c5 ("perf tools: Set the maximum allowed stack from /proc/sys/kernel/perf_event_max_stack")
Link: http://lkml.kernel.org/n/tip-eqeutsr7n7wy0c36z24ytvii@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-05-20 11:43:56 -03:00
Arnaldo Carvalho de Melo c008f78f93 perf trace: Fix exit_group() formatting
This doesn't return, so there is no raw_syscalls:sys_exit for it, add
the ending ')', without any return value, since it is void.

Reported-by: Ingo Molnar <mingo@kernel.org>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-vh2mii0g4qlveuc4joufbipu@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-05-20 11:43:55 -03:00
Arnaldo Carvalho de Melo caf8a0d049 perf trace: Warn when trying to resolve kernel addresses with kptr_restrict=1
Hook into the libtraceevent plugin kernel symbol resolver to warn the
user that that can't happen with kptr_restrict=1.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-9gc412xx1gl0lvqj1d1xwlyb@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-05-20 11:43:54 -03:00
Arnaldo Carvalho de Melo f5cd95ea60 perf trace: Move seccomp args beautifiers to tools/perf/trace/beauty/
To reduce the size of builtin-trace.c.

Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Link: http://lkml.kernel.org/n/tip-ovxifncj34ynrjjseg33lil3@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-05-11 13:06:00 -03:00
Arnaldo Carvalho de Melo 8bf382ce0a perf trace: Move flock op beautifier to tools/perf/trace/beauty/
To reduce the size of builtin-trace.c.

Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Link: http://lkml.kernel.org/n/tip-c4c47w2a2jx13terl2p2hros@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-05-11 12:24:59 -03:00
Arnaldo Carvalho de Melo d5d71e86d2 perf trace: Move futex_op beautifier to tools/perf/trace/beauty/
To reduce the size of builtin-trace.c.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-vb8dpy7bptkf219q5c25ulfp@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-05-06 13:00:59 -03:00
Arnaldo Carvalho de Melo 8f48df69b4 perf trace: Move open_flags beautifier to tools/perf/trace/beauty/
To reduce the size of builtin-trace.c.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-jt293541hv9od7gqw6lilioh@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-05-06 13:00:58 -03:00
Arnaldo Carvalho de Melo 12199d8e20 perf trace: Move signum beautifier to tools/perf/trace/beauty/
To reduce the size of builtin-trace.c.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-qecqxwwtreio6eaatfv58yq5@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-05-06 13:00:57 -03:00
Arnaldo Carvalho de Melo 4c4d6e5190 perf trace: Do not print raw args list for syscalls with no args
The test to check if the arg format had been read from the
syscall:sys_enter_name/format file was looking at the list of non-commom
fields, and if that is empty, it would think it had failed to read it,
because it doesn't exist, for instance, for the clone() syscall.

So instead before dumping the raw syscall args list check
IS_ERR(sc->tp_format), if that is true, then an attempt was made to read
the format file and failed, in which case dump the raw arg list values.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-ls7pmdqb2xy9339vdburwvnk@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-05-06 08:44:30 -03:00
Arnaldo Carvalho de Melo 03548ebf6d perf trace: Do not show the runtime_ms for a thread when not collecting it
That field is only updated when we use the "sched:sched_stat_runtime"
tracepoint, and that is only done so far when we use the '--stat' command line
option, without it we get just zeros, confusing the users:

Without this patch:

  # trace -a -s sleep 1
  <SNIP>
   qemu-system-x86 (9931), 468 events, 9.6%, 0.000 msec

     syscall     calls    total       min       avg       max      stddev
                          (msec)    (msec)    (msec)    (msec)        (%)
     ---------- ------ --------- --------- --------- ---------     ------
     ppoll          98   982.374     0.000    10.024    29.983     12.65%
     write          34     0.401     0.005     0.012     0.027      5.49%
     ioctl         102     0.347     0.002     0.003     0.007      3.08%

   firefox (10871), 1856 events, 38.2%, 0.000 msec

                          (msec)    (msec)    (msec)    (msec)        (%)
     ---------- ------ --------- --------- --------- ---------     ------
     poll          395   934.873     0.000     2.367    17.120     11.51%
     recvmsg       395     0.988     0.001     0.003     0.021      4.20%
     read          106     0.460     0.002     0.004     0.007      3.17%
     futex          24     0.108     0.001     0.004     0.010     10.05%
     mmap            2     0.041     0.016     0.021     0.026     23.92%
     write           6     0.027     0.004     0.004     0.005      2.52%

After this patch that ', 0.000 msecs' gets suppressed when --stat is not
in use.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-p7emqrsw7900tdkg43v9l1e1@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-05-05 21:03:57 -03:00
Arnaldo Carvalho de Melo b535d523dc perf trace: Sort syscalls stats by msecs in --summary
# trace -a -s sleep 1
  <SNIP>
   Xorg (1965), 788 events, 19.0%, 0.000 msec

     syscall            calls    total       min       avg       max      stddev
                                 (msec)    (msec)    (msec)    (msec)        (%)
     --------------- -------- --------- --------- --------- ---------     ------
     select                89   731.038     0.000     8.214   175.218     36.71%
     ioctl                 22     0.661     0.010     0.030     0.072     10.43%
     writev                42     0.253     0.002     0.006     0.011      5.94%
     recvmsg               60     0.185     0.001     0.003     0.009      5.90%
     setitimer             60     0.127     0.001     0.002     0.006      6.14%
     read                  52     0.102     0.001     0.002     0.005      8.55%
     rt_sigprocmask        45     0.092     0.001     0.002     0.023     23.65%
     poll                  12     0.021     0.001     0.002     0.003      7.21%
     epoll_wait            12     0.019     0.001     0.002     0.002      2.71%

   firefox (10871), 1080 events, 26.1%, 0.000 msec

     syscall            calls    total       min       avg       max      stddev
                                 (msec)    (msec)    (msec)    (msec)        (%)
     --------------- -------- --------- --------- --------- ---------     ------
     poll                 240   979.562     0.000     4.082    17.132     11.33%
     recvmsg              240     0.532     0.001     0.002     0.007      3.69%
     read                  60     0.303     0.003     0.005     0.029      8.50%

Suggested-by: Milian Wolff <milian.wolff@kdab.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-52kdkuyxihq0kvc0n2aalhay@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-05-05 21:03:56 -03:00
Arnaldo Carvalho de Melo 96c1445122 perf trace: Sort summary output by number of events
# trace -a -s sleep 1 |& grep events | tail
   gmain (1733), 34 events, 1.0%, 0.000 msec
   hexchat (9765), 46 events, 1.4%, 0.000 msec
   ssh (11109), 80 events, 2.4%, 0.000 msec
   sleep (32631), 81 events, 2.4%, 0.000 msec
   qemu-system-x86 (10021), 272 events, 8.2%, 0.000 msec
   Xorg (1965), 322 events, 9.7%, 0.000 msec
   SoftwareVsyncTh (10922), 366 events, 11.1%, 0.000 msec
   gnome-shell (2231), 446 events, 13.5%, 0.000 msec
   qemu-system-x86 (9931), 468 events, 14.1%, 0.000 msec
   firefox (10871), 1098 events, 33.2%, 0.000 msec
  [root@jouet ~]#

Suggested-by: Milian Wolff <milian.wolff@kdab.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-ye4cnprhfeiq32ar4lt60dqs@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-05-05 21:03:56 -03:00
Arnaldo Carvalho de Melo a30e6259b5 perf trace: Move msg_flags beautifier to tools/perf/trace/beauty/
To reduce the size of builtin-trace.c.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-11zxg3qitk6bw2x30135k9z4@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-28 09:58:59 -03:00
Arnaldo Carvalho de Melo 4cb93446c5 perf tools: Set the maximum allowed stack from /proc/sys/kernel/perf_event_max_stack
There is an upper limit to what tooling considers a valid callchain,
and it was tied to the hardcoded value in the kernel,
PERF_MAX_STACK_DEPTH (127), now that this can be tuned via a sysctl,
make it read it and use that as the upper limit, falling back to
PERF_MAX_STACK_DEPTH for kernels where this sysctl isn't present.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Brendan Gregg <brendan.d.gregg@gmail.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-yjqsd30nnkogvj5oyx9ghir9@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-27 10:29:07 -03:00
Arnaldo Carvalho de Melo ccd9b2a7f8 perf trace: Do not beautify the 'pid' parameter as a simple integer
Leave it alone so that it ends up assigned to SCA_PID via its type,
'pid_t', that will look up the pid on the machine thread rb_tree and
possibly find its COMM.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-r7dujgmhtxxfajuunpt1bkuo@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-26 13:14:59 -03:00
Arnaldo Carvalho de Melo 62de344e4f perf trace: Move perf_flags beautifier to tools/perf/trace/beauty/
To reduce the size of builtin-trace.c.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-8r3gmymyn3r0ynt4yuzspp9g@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-26 13:14:59 -03:00
Arnaldo Carvalho de Melo 1df5429046 perf trace: Make --pf honour --min-stack too
To check deeply nested page fault callchains.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-wuji34xx003kr88nmqt6jkgf@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-25 12:49:17 -03:00
Arnaldo Carvalho de Melo 7ad3561595 perf trace: Make --event honour --min-stack too
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-shj0fazntmskhjild5i6x73l@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-25 12:49:17 -03:00
Arnaldo Carvalho de Melo 0c3a6ef4ea perf trace: Make --pf maj/min/all use callchains too
Forgot about page faults, a software event, when adding support for callchains,
fix it:

  # trace --no-syscalls --pf maj --call dwarf
     0.000 ( 0.000 ms): Xorg/2068 majfault [sfbSegment1+0x0] => /usr/lib64/xorg/modules/drivers/intel_drv.so@0x11b490 (x.)
                                       sfbSegment1+0x0 (/usr/lib64/xorg/modules/drivers/intel_drv.so)
                                       fbPolySegment32+0x361 (/usr/lib64/xorg/modules/drivers/intel_drv.so)
                                       sna_poly_segment+0x743 (/usr/lib64/xorg/modules/drivers/intel_drv.so)
                                       damagePolySegment+0x77 (/usr/libexec/Xorg)
                                       ProcPolySegment+0xe7 (/usr/libexec/Xorg)
                                       Dispatch+0x25f (/usr/libexec/Xorg)
                                       dix_main+0x3c3 (/usr/libexec/Xorg)
                                       __libc_start_main+0xf0 (/usr/lib64/libc-2.22.so)
                                       _start+0x29 (/usr/libexec/Xorg)
     0.257 ( 0.000 ms): Xorg/2068 majfault [miZeroClipLine+0x0] => /usr/libexec/Xorg@0x18e830 (x.)
                                       miZeroClipLine+0x0 (/usr/libexec/Xorg)
                                       _fbSegment+0x2c0 (/usr/lib64/xorg/modules/drivers/intel_drv.so)
                                       sfbSegment1+0x67 (/usr/lib64/xorg/modules/drivers/intel_drv.so)
                                       fbPolySegment32+0x361 (/usr/lib64/xorg/modules/drivers/intel_drv.so)
                                       sna_poly_segment+0x743 (/usr/lib64/xorg/modules/drivers/intel_drv.so)
                                       damagePolySegment+0x77 (/usr/libexec/Xorg)
                                       ProcPolySegment+0xe7 (/usr/libexec/Xorg)
                                       Dispatch+0x25f (/usr/libexec/Xorg)
                                       dix_main+0x3c3 (/usr/libexec/Xorg)
                                       __libc_start_main+0xf0 (/usr/lib64/libc-2.22.so)
                                       _start+0x29 (/usr/libexec/Xorg)
^C#

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-8h6ssirw5z15qyhy2lwd6f89@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-25 12:49:17 -03:00
Arnaldo Carvalho de Melo 0ae537cb35 perf trace: Extract evsel contructor from perf_evlist__add_pgfault
Prep work for next patches, where we'll need access to the created
evsels, to possibly configure callchains.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-2pcgsgnkgellhlcao4aub8tu@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-25 12:49:17 -03:00
Arnaldo Carvalho de Melo 2ddd5c049e perf tools: Ditch record_opts.callgraph_set
We have callchain_param.enabled for that.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-silwqjc2t25ls42dsvg28pp5@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-18 12:26:27 -03:00
Arnaldo Carvalho de Melo ccd62a896f perf trace: Fix build when DWARF unwind isn't available
The variable is initialized and then conditionally set to a different
value, but not used when DWARF unwinding is not available, bummer, write
1000 times: "Run make -C tools/perf build-test"...

  builtin-trace.c: In function ‘cmd_trace’:
  builtin-trace.c:3112:6: error: variable ‘max_stack_user_set’ set but not
  used [-Werror=unused-but-set-variable]
    bool max_stack_user_set = true;
        ^
  cc1: all warnings being treated as err

Fix it by marking it as __maybe_unused.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Fixes: 0561499326 ("perf trace: Make --(min,max}-stack imply "--call-graph dwarf"")
Link: http://lkml.kernel.org/n/tip-85r40c5hhv6jnmph77l1hgsr@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-16 09:44:28 -03:00
Arnaldo Carvalho de Melo f3e459d16a perf trace: Bump --mmap-pages when --call-graph is used by the root user
To reduce the chances we'll overflow the mmap buffer, manual fine tuning
trumps this.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-wxygbxmp1v9mng1ea28wet02@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-15 17:52:34 -03:00
Arnaldo Carvalho de Melo 0561499326 perf trace: Make --(min,max}-stack imply "--call-graph dwarf"
If one uses:

  # perf trace --min-stack 16

Then it implicitly means that callgraphs should be enabled, and the best
option in terms of widespread availability is "dwarf".

Further work needed to choose a better alternative, LBR, in capable
systems.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-xtjmnpkyk42npekxz3kynzmx@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-15 16:41:19 -03:00
Arnaldo Carvalho de Melo 5cf9c84e21 perf trace: Introduce --min-stack filter
Counterpart to --max-stack, to help focusing on deeply nested calls. Can
be combined with --duration, etc.

E.g.:

  System wide syscall tracing looking for call stacks longer than 66:

  # trace --mmap-pages 32768 --filter-pid 2711 --call-graph dwarf,16384 --min-stack 66

  Or more compactly:

  # trace -m 32768 --filt 2711 --call dwarf,16384 --min-st 66
   363.027 ( 0.002 ms): gnome-shell/2287 poll(ufds: 0x7ffc5ea24230, nfds: 1, timeout_msecs: 4294967295         ) = 1
                                       [0xf6fdd] (/usr/lib64/libc-2.22.so)
                                       _xcb_conn_wait+0x92 (/usr/lib64/libxcb.so.1.1.0)
                                       _xcb_out_send+0x4d (/usr/lib64/libxcb.so.1.1.0)
                                       xcb_writev+0x45 (/usr/lib64/libxcb.so.1.1.0)
                                       _XSend+0x19e (/usr/lib64/libX11.so.6.3.0)
                                       _XReply+0x82 (/usr/lib64/libX11.so.6.3.0)
                                       XSync+0x4d (/usr/lib64/libX11.so.6.3.0)
                                       dri3_bind_tex_image+0x42 (/usr/lib64/libGL.so.1.2.0)
                                       _cogl_winsys_texture_pixmap_x11_update+0x117 (/usr/lib64/libcogl.so.20.4.1)
                                       _cogl_texture_pixmap_x11_update+0x67 (/usr/lib64/libcogl.so.20.4.1)
                                       _cogl_texture_pixmap_x11_pre_paint+0x13 (/usr/lib64/libcogl.so.20.4.1)
                                       _cogl_pipeline_layer_pre_paint+0x5e (/usr/lib64/libcogl.so.20.4.1)
                                       _cogl_rectangles_validate_layer_cb+0x1b (/usr/lib64/libcogl.so.20.4.1)
                                       cogl_pipeline_foreach_layer+0xbe (/usr/lib64/libcogl.so.20.4.1)
                                       _cogl_framebuffer_draw_multitextured_rectangles+0x77 (/usr/lib64/libcogl.so.20.4.1)
                                       cogl_framebuffer_draw_multitextured_rectangle+0x51 (/usr/lib64/libcogl.so.20.4.1)
                                       paint_clipped_rectangle+0xb6 (/usr/lib64/libmutter.so.0.0.0)
                                       meta_shaped_texture_paint+0x3e3 (/usr/lib64/libmutter.so.0.0.0)
                                       _g_closure_invoke_va+0xb2 (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit_valist+0xc0d (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit+0x8f (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       clutter_actor_continue_paint+0x2bb (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_paint.part.41+0x47b (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_real_paint+0x20 (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       _g_closure_invoke_va+0xb2 (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit_valist+0xc0d (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit+0x8f (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       clutter_actor_continue_paint+0x2bb (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_paint.part.41+0x47b (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_real_paint+0x20 (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       meta_window_actor_paint+0x14b (/usr/lib64/libmutter.so.0.0.0)
                                       _g_closure_invoke_va+0xb2 (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit_valist+0xc0d (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit+0x8f (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       clutter_actor_continue_paint+0x2bb (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_paint.part.41+0x47b (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_real_paint+0x20 (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       meta_window_group_paint+0x19f (/usr/lib64/libmutter.so.0.0.0)
                                       _g_closure_invoke_va+0xb2 (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit_valist+0xc0d (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit+0x8f (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       clutter_actor_continue_paint+0x2bb (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_paint.part.41+0x47b (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       [0x3d970] (/usr/lib64/gnome-shell/libgnome-shell.so)
                                       _g_closure_invoke_va+0xb2 (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit_valist+0xc0d (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit+0x8f (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       clutter_actor_continue_paint+0x2bb (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_paint.part.41+0x47b (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_stage_paint+0x3a (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       meta_stage_paint+0x45 (/usr/lib64/libmutter.so.0.0.0)
                                       _g_closure_invoke_va+0x164 (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit_valist+0xc0d (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit+0x8f (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       clutter_actor_continue_paint+0x2bb (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_paint.part.41+0x47b (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       _clutter_stage_do_paint+0x17b (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_stage_cogl_redraw+0x496 (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       _clutter_stage_do_update+0x117 (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_clock_dispatch+0x169 (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       g_main_context_dispatch+0x15a (/usr/lib64/libglib-2.0.so.0.4600.2)
                                       g_main_context_iterate.isra.29+0x1e0 (/usr/lib64/libglib-2.0.so.0.4600.2)
                                       g_main_loop_run+0xc2 (/usr/lib64/libglib-2.0.so.0.4600.2)
                                       meta_run+0x2c (/usr/lib64/libmutter.so.0.0.0)
                                       main+0x3f7 (/usr/bin/gnome-shell)
                                       __libc_start_main+0xf0 (/usr/lib64/libc-2.22.so)
                                       [0x2909] (/usr/bin/gnome-shell)
   363.038 ( 0.006 ms): gnome-shell/2287 writev(fd: 5<socket:[32540]>, vec: 0x7ffc5ea243a0, vlen: 3            ) = 4
                                       __GI___writev+0x2d (/usr/lib64/libc-2.22.so)
                                       _xcb_conn_wait+0x359 (/usr/lib64/libxcb.so.1.1.0)
                                       _xcb_out_send+0x4d (/usr/lib64/libxcb.so.1.1.0)
                                       xcb_writev+0x45 (/usr/lib64/libxcb.so.1.1.0)
                                       _XSend+0x19e (/usr/lib64/libX11.so.6.3.0)
                                       _XReply+0x82 (/usr/lib64/libX11.so.6.3.0)
                                       XSync+0x4d (/usr/lib64/libX11.so.6.3.0)
                                       dri3_bind_tex_image+0x42 (/usr/lib64/libGL.so.1.2.0)
                                       _cogl_winsys_texture_pixmap_x11_update+0x117 (/usr/lib64/libcogl.so.20.4.1)
                                       _cogl_texture_pixmap_x11_update+0x67 (/usr/lib64/libcogl.so.20.4.1)
                                       _cogl_texture_pixmap_x11_pre_paint+0x13 (/usr/lib64/libcogl.so.20.4.1)
                                       _cogl_pipeline_layer_pre_paint+0x5e (/usr/lib64/libcogl.so.20.4.1)
                                       _cogl_rectangles_validate_layer_cb+0x1b (/usr/lib64/libcogl.so.20.4.1)
                                       cogl_pipeline_foreach_layer+0xbe (/usr/lib64/libcogl.so.20.4.1)
                                       _cogl_framebuffer_draw_multitextured_rectangles+0x77 (/usr/lib64/libcogl.so.20.4.1)
                                       cogl_framebuffer_draw_multitextured_rectangle+0x51 (/usr/lib64/libcogl.so.20.4.1)
                                       paint_clipped_rectangle+0xb6 (/usr/lib64/libmutter.so.0.0.0)
                                       meta_shaped_texture_paint+0x3e3 (/usr/lib64/libmutter.so.0.0.0)
                                       _g_closure_invoke_va+0xb2 (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit_valist+0xc0d (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit+0x8f (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       clutter_actor_continue_paint+0x2bb (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_paint.part.41+0x47b (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_real_paint+0x20 (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       _g_closure_invoke_va+0xb2 (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit_valist+0xc0d (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit+0x8f (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       clutter_actor_continue_paint+0x2bb (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_paint.part.41+0x47b (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_real_paint+0x20 (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       meta_window_actor_paint+0x14b (/usr/lib64/libmutter.so.0.0.0)
                                       _g_closure_invoke_va+0xb2 (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit_valist+0xc0d (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit+0x8f (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       clutter_actor_continue_paint+0x2bb (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_paint.part.41+0x47b (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_real_paint+0x20 (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       meta_window_group_paint+0x19f (/usr/lib64/libmutter.so.0.0.0)
                                       _g_closure_invoke_va+0xb2 (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit_valist+0xc0d (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit+0x8f (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       clutter_actor_continue_paint+0x2bb (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_paint.part.41+0x47b (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       [0x3d970] (/usr/lib64/gnome-shell/libgnome-shell.so)
                                       _g_closure_invoke_va+0xb2 (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit_valist+0xc0d (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit+0x8f (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       clutter_actor_continue_paint+0x2bb (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_paint.part.41+0x47b (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_stage_paint+0x3a (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       meta_stage_paint+0x45 (/usr/lib64/libmutter.so.0.0.0)
                                       _g_closure_invoke_va+0x164 (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit_valist+0xc0d (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit+0x8f (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       clutter_actor_continue_paint+0x2bb (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_paint.part.41+0x47b (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       _clutter_stage_do_paint+0x17b (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_stage_cogl_redraw+0x496 (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       _clutter_stage_do_update+0x117 (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_clock_dispatch+0x169 (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       g_main_context_dispatch+0x15a (/usr/lib64/libglib-2.0.so.0.4600.2)
                                       g_main_context_iterate.isra.29+0x1e0 (/usr/lib64/libglib-2.0.so.0.4600.2)
                                       g_main_loop_run+0xc2 (/usr/lib64/libglib-2.0.so.0.4600.2)
                                       meta_run+0x2c (/usr/lib64/libmutter.so.0.0.0)
                                       main+0x3f7 (/usr/bin/gnome-shell)
                                       __libc_start_main+0xf0 (/usr/lib64/libc-2.22.so)
                                       [0x2909] (/usr/bin/gnome-shell)
   363.086 ( 0.042 ms): gnome-shell/2287 poll(ufds: 0x7ffc5ea24250, nfds: 1, timeout_msecs: 4294967295         ) = 1
                                       [0xf6fdd] (/usr/lib64/libc-2.22.so)
                                       _xcb_conn_wait+0x92 (/usr/lib64/libxcb.so.1.1.0)
                                       wait_for_reply+0xb7 (/usr/lib64/libxcb.so.1.1.0)
                                       xcb_wait_for_reply+0x61 (/usr/lib64/libxcb.so.1.1.0)
                                       _XReply+0x127 (/usr/lib64/libX11.so.6.3.0)
                                       XSync+0x4d (/usr/lib64/libX11.so.6.3.0)
                                       dri3_bind_tex_image+0x42 (/usr/lib64/libGL.so.1.2.0)
                                       _cogl_winsys_texture_pixmap_x11_update+0x117 (/usr/lib64/libcogl.so.20.4.1)
                                       _cogl_texture_pixmap_x11_update+0x67 (/usr/lib64/libcogl.so.20.4.1)
                                       _cogl_texture_pixmap_x11_pre_paint+0x13 (/usr/lib64/libcogl.so.20.4.1)
                                       _cogl_pipeline_layer_pre_paint+0x5e (/usr/lib64/libcogl.so.20.4.1)
                                       _cogl_rectangles_validate_layer_cb+0x1b (/usr/lib64/libcogl.so.20.4.1)
                                       cogl_pipeline_foreach_layer+0xbe (/usr/lib64/libcogl.so.20.4.1)
                                       _cogl_framebuffer_draw_multitextured_rectangles+0x77 (/usr/lib64/libcogl.so.20.4.1)
                                       cogl_framebuffer_draw_multitextured_rectangle+0x51 (/usr/lib64/libcogl.so.20.4.1)
                                       paint_clipped_rectangle+0xb6 (/usr/lib64/libmutter.so.0.0.0)
                                       meta_shaped_texture_paint+0x3e3 (/usr/lib64/libmutter.so.0.0.0)
                                       _g_closure_invoke_va+0xb2 (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit_valist+0xc0d (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit+0x8f (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       clutter_actor_continue_paint+0x2bb (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_paint.part.41+0x47b (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_real_paint+0x20 (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       _g_closure_invoke_va+0xb2 (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit_valist+0xc0d (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit+0x8f (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       clutter_actor_continue_paint+0x2bb (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_paint.part.41+0x47b (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_real_paint+0x20 (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       meta_window_actor_paint+0x14b (/usr/lib64/libmutter.so.0.0.0)
                                       _g_closure_invoke_va+0xb2 (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit_valist+0xc0d (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit+0x8f (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       clutter_actor_continue_paint+0x2bb (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_paint.part.41+0x47b (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_real_paint+0x20 (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       meta_window_group_paint+0x19f (/usr/lib64/libmutter.so.0.0.0)
                                       _g_closure_invoke_va+0xb2 (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit_valist+0xc0d (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit+0x8f (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       clutter_actor_continue_paint+0x2bb (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_paint.part.41+0x47b (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       [0x3d970] (/usr/lib64/gnome-shell/libgnome-shell.so)
                                       _g_closure_invoke_va+0xb2 (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit_valist+0xc0d (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit+0x8f (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       clutter_actor_continue_paint+0x2bb (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_paint.part.41+0x47b (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_stage_paint+0x3a (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       meta_stage_paint+0x45 (/usr/lib64/libmutter.so.0.0.0)
                                       _g_closure_invoke_va+0x164 (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit_valist+0xc0d (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       g_signal_emit+0x8f (/usr/lib64/libgobject-2.0.so.0.4600.2)
                                       clutter_actor_continue_paint+0x2bb (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_actor_paint.part.41+0x47b (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       _clutter_stage_do_paint+0x17b (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_stage_cogl_redraw+0x496 (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       _clutter_stage_do_update+0x117 (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       clutter_clock_dispatch+0x169 (/usr/lib64/libclutter-1.0.so.0.2400.2)
                                       g_main_context_dispatch+0x15a (/usr/lib64/libglib-2.0.so.0.4600.2)
                                       g_main_context_iterate.isra.29+0x1e0 (/usr/lib64/libglib-2.0.so.0.4600.2)
                                       g_main_loop_run+0xc2 (/usr/lib64/libglib-2.0.so.0.4600.2)
                                       meta_run+0x2c (/usr/lib64/libmutter.so.0.0.0)
                                       main+0x3f7 (/usr/bin/gnome-shell)
                                       __libc_start_main+0xf0 (/usr/lib64/libc-2.22.so)
                                       [0x2909] (/usr/bin/gnome-shell)

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-jncuxju9fibq2rl6olhqwjw6@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-15 13:14:20 -03:00
Arnaldo Carvalho de Melo e519bd9a07 perf trace: Do not print interrupted syscalls when using --duration
With multiple threads, e.g. a system wide trace session, and one syscall is
midway in a thread and another thread starts another syscall we must print the
start of the interrupted syscall followed by ..., but that can't be done that
way when we use the --duration filter, as we have to wait for the syscall exit
to calculate the duration and decide if it should be filtered, so we have to
disable the interrupted logic and only print at syscall exit, duh.

Before:

  # trace --duration 100
  <SNIP>
   9.248 (0.023 ms): gnome-shell/2287 poll(ufds: 0x7ffc5ea26580, nfds: 1, timeout_msecs: 4294967295) ...
   9.296 (0.001 ms): gnome-shell/2287 recvmsg(fd: 11<socket:[35818]>, msg: 0x7ffc5ea264a0          ) ...
   9.311 (0.008 ms): Xorg/2025 select(n: 512, inp: 0x83a8e0, tvp: 0x8316a0                         ) ...
   9.859 (0.023 ms): gnome-shell/2287 poll(ufds: 0x7ffc5ea24250, nfds: 1, timeout_msecs: 4294967295) ...
   9.942 (0.051 ms): Xorg/2025 select(n: 512, inp: 0x83a8e0, tvp: 0x8316a0                         ) ...
  10.467 (0.003 ms): gnome-shell/2287 poll(ufds: 0x55e623431220, nfds: 50, timeout_msecs: 4294967295) ...
  11.136 (0.382 ms): Xorg/2025 select(n: 512, inp: 0x83a8e0, tvp: 0x8316a0                         ) ...
  11.223 (0.023 ms): SoftwareVsyncT/24369 futex(uaddr: 0x7f5ec5df8c14, op: WAIT_BITSET|PRIV, val: 1, utime: 0x7f5ec5df8b68, val3: 4294967295) ...
  16.865 (5.501 ms): firefox/24321 poll(ufds: 0x7f5ec388b460, nfds: 6, timeout_msecs: 4294967295   ) ...
  22.571 (0.006 ms): Xorg/2025 select(n: 512, inp: 0x83a8e0, tvp: 0x8316a0                         ) ...
  26.793 (4.063 ms): gnome-shell/2287 poll(ufds: 0x55e623431220, nfds: 50, timeout_msecs: 4294967295) ...
  26.917 (0.080 ms): Xorg/2025 select(n: 512, inp: 0x83a8e0, tvp: 0x8316a0                         ) ...
  27.291 (0.355 ms): qemu-system-x8/10065 ppoll(ufds: 0x55c98b39e400, nfds: 72, tsp: 0x7fffe4e4fe60, sigsetsize: 8) ...
  27.336 (0.012 ms): SoftwareVsyncT/24369 futex(uaddr: 0x7f5ec5df8c14, op: WAIT_BITSET|PRIV, val: 1, utime: 0x7f5ec5df8b68, val3: 4294967295) ...
  33.370 (5.958 ms): firefox/24321 poll(ufds: 0x7f5ec388b460, nfds: 6, timeout_msecs: 4294967295) ...
  33.866 (0.021 ms): Xorg/2025 select(n: 512, inp: 0x83a8e0, tvp: 0x8316a0                      ) ...
  35.762 (1.611 ms): gnome-shell/2287 poll(ufds: 0x55e623431220, nfds: 50, timeout_msecs: 8     ) ...
  38.765 (2.910 ms): Xorg/2025 select(n: 512, inp: 0x83a8e0, tvp: 0x8316a0                      ) ...

After:

  # trace --duration 100

  238.292 (153.226 ms): hexchat/2786 poll(ufds: 0x559ea372f370, nfds: 6, timeout_msecs: 153) = 0 Timeout
  249.634 (199.433 ms): Xorg/2025 select(n: 512, inp: 0x83a8e0, tvp: 0x7ffdcbb63610        ) = 1
  385.583 (147.257 ms): hexchat/2786 poll(ufds: 0x559ea372f370, nfds: 6, timeout_msecs: 147) = 0 Timeout
  397.166 (110.779 ms): gnome-shell/2287 poll(ufds: 0x55e623431220, nfds: 50, timeout_msecs: 4294967295) = 1
  601.839 (132.066 ms): Xorg/2025 select(n: 512, inp: 0x83a8e0, tvp: 0x8316a0                          ) = 1
  602.445 (132.679 ms): gnome-shell/2287 poll(ufds: 0x55e623431220, nfds: 50, timeout_msecs: 4294967295) = 1
  686.122 (300.418 ms): hexchat/2786 poll(ufds: 0x559ea372f370, nfds: 6, timeout_msecs: 300) = 0 Timeout
  815.033 (184.641 ms): JS Helper/24352 futex(uaddr: 0x7f5ed98e584c, op: WAIT|PRIV, val: 1149859) = 0
  825.868 (195.469 ms): JS Helper/24351 futex(uaddr: 0x7f5ed98e584c, op: WAIT|PRIV, val: 1149860) = 0
  840.738 (210.335 ms): JS Helper/24350 futex(uaddr: 0x7f5ed98e584c, op: WAIT|PRIV, val: 1149861) = 0
  914.898 (158.692 ms): Compositor/24363 futex(uaddr: 0x7f5ec8dfebf4, op: WAIT|PRIV, val: 1) = 0
  915.199 (100.747 ms): Timer/24358 futex(uaddr: 0x7f5ed98e56cc, op: WAIT_BITSET|PRIV|CLKRT, val: 2545397, utime: 0x7f5ecdbfec30, val3: 4294967295) = 0
  986.639 (247.325 ms): hexchat/2786 poll(ufds: 0x559ea372f370, nfds: 6, timeout_msecs: 247) = 0 Timeout
  996.239 (500.591 ms): chrome/16237 poll(ufds: 0x3ecd739bd0, nfds: 5, timeout_msecs: 500) = 0 Timeout
 1042.890 (120.076 ms): Timer/24358 futex(uaddr: 0x7f5ed98e56cc, op: WAIT_BITSET|PRIV|CLKRT, val: 2545403, utime: 0x7f5ecdbfec30, val3: 4294967295) = -1 ETIMEDOUT Connection timed out

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-d2nay6kjax5ro991c9kelvi5@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-15 13:14:19 -03:00
Arnaldo Carvalho de Melo c6d4a494a2 perf trace: Add --max-stack knob
Similar to the one in the other tools (report, script, top).

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-lh7kk5a5t3erwxw31ah0cgar@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-14 19:46:58 -03:00
Arnaldo Carvalho de Melo d327e60cfa perf tools: Remove addr_location argument to sample__fprintf_callchain
Not used at all, nuke it.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-jf2w8ce8nl3wso3vuodg5jci@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-14 19:46:57 -03:00
Arnaldo Carvalho de Melo 6f736735e3 perf evsel: Require that callchains be resolved before calling fprintf_{sym,callchain}
This way the print routine merely does printing, not requiring access to
the resolving machinery, which helps disentangling the object files and
easing creating subsets with a limited functionality set.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-2ti2jbra8fypdfawwwm3aee3@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-14 19:46:56 -03:00
Arnaldo Carvalho de Melo bbf86c43ea perf trace: Move socket_type beautifier to tools/perf/trace/beauty/
To reduce the size of builtin-trace.c.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-ao91htwxdqwlwxr47gbluou1@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-14 13:53:10 -03:00
Arnaldo Carvalho de Melo ea8dc3cefb perf trace: Move eventfd beautifiers to trace/beauty/ directory
To better organize all these beautifiers.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-zrw5zz7cnrs44o5osouyutvt@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-14 08:57:53 -03:00
Arnaldo Carvalho de Melo df4cb1678e perf trace: Move mmap beautifiers to trace/beauty/ directory
To better organize all these beautifiers.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-zbr27mdy9ssdhux3ib2nfa7j@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-14 08:57:53 -03:00
Arnaldo Carvalho de Melo a355a61e43 perf trace: Add getrandom beautifier related defines for older systems
Were the detached tarball (make perf-tar-src-pkg) build was failing because
those definitions aren't available in the system headers.

On RHEL7, for instance:

  builtin-trace.c: In function ‘syscall_arg__scnprintf_getrandom_flags’:
  builtin-trace.c:1113:14: error: ‘GRND_RANDOM’ undeclared (first use in this function)
    P_FLAG(RANDOM);
                ^
  builtin-trace.c:1114:14: error: ‘GRND_NONBLOCK’ undeclared (first use in this function)
    P_FLAG(NONBLOCK);
              ^

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-r8496g24a3kbqynvk6617b0e@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-14 08:57:53 -03:00
Arnaldo Carvalho de Melo 6fb35b9515 perf trace: Add seccomp beautifier related defines for older systems
Were the detached tarball (make perf-tar-src-pkg) build was failing because
those definitions aren't available in the system headers.

On RHEL7, for instance:

  builtin-trace.c: In function ‘syscall_arg__scnprintf_seccomp_op’:
  builtin-trace.c:1069:7: error: ‘SECCOMP_SET_MODE_STRICT’ undeclared (first use in this function)
    P_SECCOMP_SET_MODE_OP(STRICT);
         ^
  builtin-trace.c:1069:7: note: each undeclared identifier is reported only once for each function it appears in
  builtin-trace.c:1070:7: error: ‘SECCOMP_SET_MODE_FILTER’ undeclared (first use in this function)
    P_SECCOMP_SET_MODE_OP(FILTER);
         ^
  builtin-trace.c: In function ‘syscall_arg__scnprintf_seccomp_flags’:
  builtin-trace.c:1091:14: error: ‘SECCOMP_FILTER_FLAG_TSYNC’ undeclared (first use in this function)
    P_FLAG(TSYNC);
                ^

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-4f8dzzwd7g6l5dzz693u7kul@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-14 08:57:53 -03:00
Arnaldo Carvalho de Melo 59247e33ff perf trace: Do not accept --no-syscalls together with -e
Doesn't make sense and was causing a segfault, fix it.

  # trace -e clone --no-syscalls --event sched:*exec firefox
  The -e option can't be used with --no-syscalls.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-ccrahezikdk2uebptzr1eyyi@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-13 10:11:52 -03:00
Arnaldo Carvalho de Melo e20ab86e51 perf evsel: Move some methods from session.[ch] to evsel.[ch]
Those were converted to be evsel methods long ago, move the
source to where it belongs.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-vja8rjmkw3gd5ungaeyb5s2j@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-13 10:11:52 -03:00
Arnaldo Carvalho de Melo 202ff9684a perf trace: Support callchains for --event too
We already were able to ask for callchains for a specific event:

  # trace -e nanosleep --call dwarf --event sched:sched_switch/call-graph=fp/ usleep 1

This would enable tracing just the "nanosleep" syscall, with callchains
at syscall exit and would ask the kernel for frame pointer callchains to
be enabled for the "sched:sched_switch" tracepoint event, its just that
we were not resolving the callchain and printing it in 'perf trace', do
it:

  # trace -e nanosleep --call dwarf --event sched:sched_switch/call-graph=fp/ usleep 1
     0.425 ( 0.013 ms): usleep/6718 nanosleep(rqtp: 0x7ffcc1d16e20) ...
     0.425 (         ): sched:sched_switch:usleep:6718 [120] S ==> swapper/2:0 [120])
                                       __schedule+0xfe200402 ([kernel.kallsyms])
                                       schedule+0xfe200035 ([kernel.kallsyms])
                                       do_nanosleep+0xfe20006f ([kernel.kallsyms])
                                       hrtimer_nanosleep+0xfe2000dc ([kernel.kallsyms])
                                       sys_nanosleep+0xfe20007a ([kernel.kallsyms])
                                       do_syscall_64+0xfe200062 ([kernel.kallsyms])
                                       return_from_SYSCALL_64+0xfe200000 ([kernel.kallsyms])
                                       __nanosleep+0xffff008b8cbe2010 (/usr/lib64/libc-2.22.so)
     0.486 ( 0.073 ms): usleep/6718  ... [continued]: nanosleep()) = 0
                                       __nanosleep+0x10 (/usr/lib64/libc-2.22.so)
                                       usleep+0x34 (/usr/lib64/libc-2.22.so)
                                       main+0x1eb (/usr/bin/usleep)
                                       __libc_start_main+0xf0 (/usr/lib64/libc-2.22.so)
                                       _start+0x29 (/usr/bin/usleep)
  #

Pretty compact, huh? DWARF callchains for raw_syscalls:sys_exit + frame
pointer callchains for a tracepoint, if your hardware supports LBR, go
wild with /call-graph=lbr/, guess the next step is to lift this from
'perf script':

  -F, --fields <str>    comma separated output fields prepend with 'type:'. Valid types: hw,sw,trace,raw.
                        Fields: comm,tid,pid,time,cpu,event,trace,ip,sym,dso,addr,symoff,period,iregs,brstack,brstacksym,flags

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-2e7yiv5hqdm8jywlmfivvx2v@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-13 10:11:50 -03:00
Arnaldo Carvalho de Melo 00768a2bd3 perf trace: Print unresolved symbol names as addresses
Instead of having "[unknown]" as the name used for unresolved symbols,
use the address in the callchain, in hexadecimal form:

  28.801 ( 0.007 ms): qemu-system-x8/10065 ppoll(ufds: 0x55c98b39e400, nfds: 72, tsp: 0x7fffe4e4fe60, sigsetsize: 8) = 0 Timeout
                                     ppoll+0x91 (/usr/lib64/libc-2.22.so)
                                     [0x337309] (/usr/bin/qemu-system-x86_64)
                                     [0x336ab4] (/usr/bin/qemu-system-x86_64)
                                     main+0x1724 (/usr/bin/qemu-system-x86_64)
                                     __libc_start_main+0xf0 (/usr/lib64/libc-2.22.so)
                                     [0xc59a9] (/usr/bin/qemu-system-x86_64)
  35.265 (14.805 ms): gnome-shell/2287  ... [continued]: poll()) = 1
                                     [0xf6fdd] (/usr/lib64/libc-2.22.so)
                                     g_main_context_iterate.isra.29+0x17c (/usr/lib64/libglib-2.0.so.0.4600.2)
                                     g_main_loop_run+0xc2 (/usr/lib64/libglib-2.0.so.0.4600.2)
                                     meta_run+0x2c (/usr/lib64/libmutter.so.0.0.0)
                                     main+0x3f7 (/usr/bin/gnome-shell)
                                     __libc_start_main+0xf0 (/usr/lib64/libc-2.22.so)
                                     [0x2909] (/usr/bin/gnome-shell)

Suggested-by: Milian Wolff <milian.wolff@kdab.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-fja1ods5vqpg42mdz09xcz3r@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-11 22:18:25 -03:00
Arnaldo Carvalho de Melo fde54b7860 perf trace: Make "--call-graph" affect just "raw_syscalls:sys_exit"
We don't need the callchains at the syscall enter tracepoint, just when
finishing it at syscall exit, so reduce the overhead by asking for
callchains just at syscall exit.

Suggested-by: Milian Wolff <milian.wolff@kdab.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-fja1ods5vqpg42mdz09xcz3r@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-11 22:18:23 -03:00
Arnaldo Carvalho de Melo e68ae9cf7d perf evsel: Do not use globals in config()
Instead receive a callchain_param pointer to configure callchain
aspects, not doing so if NULL is passed.

This will allow fine grained control over which evsels in an evlist
gets callchains enabled.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-2mupip6khc92mh5x4nw9to82@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-11 22:18:20 -03:00
Arnaldo Carvalho de Melo 44621819dd perf trace: Exclude the kernel part of the callchain leading to a syscall
The kernel parts are not that useful:

  # trace -m 512 -e nanosleep --call dwarf  usleep 1
     0.065 ( 0.065 ms): usleep/18732 nanosleep(rqtp: 0x7ffc4ee4e200) = 0
                                       syscall_slow_exit_work ([kernel.kallsyms])
                                       do_syscall_64 ([kernel.kallsyms])
                                       return_from_SYSCALL_64 ([kernel.kallsyms])
                                       __nanosleep (/usr/lib64/libc-2.22.so)
                                       usleep (/usr/lib64/libc-2.22.so)
                                       main (/usr/bin/usleep)
                                       __libc_start_main (/usr/lib64/libc-2.22.so)
                                       _start (/usr/bin/usleep)
  #

So lets just use perf_event_attr.exclude_callchain_kernel to avoid
collecting it in the ring buffer:

  # trace -m 512 -e nanosleep --call dwarf  usleep 1
     0.063 ( 0.063 ms): usleep/19212 nanosleep(rqtp: 0x7ffc3df10fb0) = 0
                                       __nanosleep (/usr/lib64/libc-2.22.so)
                                       usleep (/usr/lib64/libc-2.22.so)
                                       main (/usr/bin/usleep)
                                       __libc_start_main (/usr/lib64/libc-2.22.so)
                                       _start (/usr/bin/usleep)
  #

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-qctu3gqhpim0dfbcp9d86c91@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-11 22:18:19 -03:00
Arnaldo Carvalho de Melo ea4539652e perf evsel: Introduce fprintf_callchain() method out of fprintf_sym()
In 'perf trace' we're just interested in printing callchains, and we
don't want to use the symbol_conf.use_callchain, so move the callchain
part to a new method.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-kcn3romzivcpxb3u75s9nz33@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-11 22:18:18 -03:00
Arnaldo Carvalho de Melo ff0c107806 perf evsel: Rename print_ip() to fprintf_sym()
As it receives a FILE, and its more than just the IP, which can even be
requested not to be printed.

For consistency with other similar methods in tools/perf/, name it as
perf_evsel__fprintf_sym() and make it return the number of bytes
printed, just like 'fprintf(3)'

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-84gawlqa3lhk63nf0t9vnqnn@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-11 22:18:17 -03:00
Milian Wolff 566a08859f perf trace: Add support for printing call chains on sys_exit events.
Now, one can print the call chain for every encountered sys_exit event,
e.g.:

    $ perf trace -e nanosleep --call-graph dwarf path/to/ex_sleep
    1005.757 (1000.090 ms): ex_sleep/13167 nanosleep(...) = 0
                                             syscall_slow_exit_work ([kernel.kallsyms])
                                             syscall_return_slowpath ([kernel.kallsyms])
                                             int_ret_from_sys_call ([kernel.kallsyms])
                                             __nanosleep (/usr/lib/libc-2.23.so)
                                             [unknown] (/usr/lib/libQt5Core.so.5.6.0)
                                             QThread::sleep (/usr/lib/libQt5Core.so.5.6.0)
                                             main (path/to/ex_sleep)
                                             __libc_start_main (/usr/lib/libc-2.23.so)
                                             _start (path/to/ex_sleep)

Note that it is advised to increase the number of mmap pages to prevent
event losses when using this new feature. Often, adding `-m 10M` to the
`perf trace` invocation is enough.

This feature is also available in strace when built with libunwind via
`strace -k`. Performance wise, this solution is much better:

    $ time find path/to/linux &> /dev/null

    real    0m0.051s
    user    0m0.013s
    sys     0m0.037s

    $ time perf trace -m 800M --call-graph dwarf find path/to/linux &> /dev/null

    real    0m2.624s
    user    0m1.203s
    sys     0m1.333s

    $ time strace -k find path/to/linux  &> /dev/null

    real    0m35.398s
    user    0m10.403s
    sys     0m23.173s

Note that it is currently not possible to configure the print output.
Adding such a feature, similar to what is available in `perf script` via
its `--fields` knob can be added later on.

Signed-off-by: Milian Wolff <milian.wolff@kdab.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
LPU-Reference: 1460115255-17648-1-git-send-email-milian.wolff@kdab.com
[ Split from a larger patch, do not print the IP, left align,
  remove dup call symbol__init(), added man page entry ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-11 22:18:16 -03:00
Wang Nan d78885739a perf bpf: Clone bpf stdout events in multiple bpf scripts
This patch allows cloning bpf-output event configuration among multiple
bpf scripts. If there exist a map named '__bpf_output__' and not
configured using 'map:__bpf_output__.event=', this patch clones the
configuration of another '__bpf_stdout__' map. For example, following
command:

  # perf trace --ev bpf-output/no-inherit,name=evt/ \
               --ev ./test_bpf_trace.c/map:__bpf_stdout__.event=evt/ \
               --ev ./test_bpf_trace2.c usleep 100000

equals to:

  # perf trace --ev bpf-output/no-inherit,name=evt/ \
               --ev ./test_bpf_trace.c/map:__bpf_stdout__.event=evt/  \
               --ev ./test_bpf_trace2.c/map:__bpf_stdout__.event=evt/ \
               usleep 100000

Signed-off-by: Wang Nan <wangnan0@huawei.com>
Suggested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Zefan Li <lizefan@huawei.com>
Cc: pi3orama@163.com
Link: http://lkml.kernel.org/r/1460128045-97310-4-git-send-email-wangnan0@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-11 22:17:45 -03:00
Arnaldo Carvalho de Melo fd0db10268 perf trace: Move syscall table id <-> name routines to separate class
We're using libaudit for doing name to id and id to syscall name
translations, but that makes 'perf trace' to have to wait for newer
libaudit versions supporting recently added syscalls, such as
"userfaultfd" at the time of this changeset.

We have all the information right there, in the kernel sources, so move
this code to a separate place, wrapped behind functions that will
progressively use the kernel source files to extract the syscall table
for use in 'perf trace'.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-i38opd09ow25mmyrvfwnbvkj@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-08 09:58:13 -03:00
Arnaldo Carvalho de Melo ba2f22cf99 perf trace: Beautify mode_t arguments
When reading the syscall tracepoint /format file, look for arguments of type
"mode_t" and attach a beautifier:

  [root@jouet ~]# cat ~/bin/tp_with_fields_of_type
  #!/bin/bash
  grep -w $1 /sys/kernel/tracing/events/syscalls/*/format | sed -r 's%.*sys_enter_(.*)/format.*%\1%g' | paste -d, -s
  # tp_with_fields_of_type umode_t
  chmod,creat,fchmodat,fchmod,mkdirat,mkdir,mknodat,mknod,mq_open,openat,open
  #

Testing it:

  #define S_ISUID 0004000
  #define S_ISGID 0002000
  #define S_ISVTX 0001000
  #define S_IRWXU 0000700
  #define S_IRUSR 0000400
  #define S_IWUSR 0000200
  #define S_IXUSR 0000100

  #define S_IRWXG 0000070
  #define S_IRGRP 0000040
  #define S_IWGRP 0000020
  #define S_IXGRP 0000010

  #define S_IRWXO 0000007
  #define S_IROTH 0000004
  #define S_IWOTH 0000002
  #define S_IXOTH 0000001

  # for mode in 4000 2000 1000 700 400 200 100 70 40 20 10 7 4 2 1 ; do \
      echo -n $mode '->' ; trace --no-inherit -e chmod,fchmodat,fchmod chmod $mode x; \
    done
  4000 -> 0.338 ( 0.012 ms): fchmodat(dfd: CWD, filename: x, mode: ISUID) = 0
  2000 -> 0.438 ( 0.015 ms): fchmodat(dfd: CWD, filename: x, mode: ISGID) = 0
  1000 -> 0.677 ( 0.040 ms): fchmodat(dfd: CWD, filename: x, mode: ISVTX) = 0
   700 -> 0.394 ( 0.013 ms): fchmodat(dfd: CWD, filename: x, mode: IRWXU) = 0
   400 -> 0.337 ( 0.010 ms): fchmodat(dfd: CWD, filename: x, mode: IRUSR) = 0
   200 -> 0.259 ( 0.008 ms): fchmodat(dfd: CWD, filename: x, mode: IWUSR) = 0
   100 -> 0.249 ( 0.008 ms): fchmodat(dfd: CWD, filename: x, mode: IXUSR) = 0
    70 -> 0.266 ( 0.008 ms): fchmodat(dfd: CWD, filename: x, mode: IRWXG) = 0
    40 -> 0.329 ( 0.009 ms): fchmodat(dfd: CWD, filename: x, mode: IRGRP) = 0
    20 -> 0.250 ( 0.009 ms): fchmodat(dfd: CWD, filename: x, mode: IWGRP) = 0
    10 -> 0.259 ( 0.008 ms): fchmodat(dfd: CWD, filename: x, mode: IXGRP) = 0
     7 -> 0.249 ( 0.009 ms): fchmodat(dfd: CWD, filename: x, mode: IRWXO) = 0
     4 -> 0.278 ( 0.011 ms): fchmodat(dfd: CWD, filename: x, mode: IROTH) = 0
     2 -> 0.276 ( 0.009 ms): fchmodat(dfd: CWD, filename: x, mode: IWOTH) = 0
     1 -> 0.250 ( 0.008 ms): fchmodat(dfd: CWD, filename: x, mode: IXOTH) = 0
  #
  # trace --no-inherit -e chmod,fchmodat,fchmod chmod 7777 x
     0.258 ( 0.011 ms): fchmodat(dfd: CWD, filename: x, mode: IALLUGO) = 0
  # trace --no-inherit -e chmod,fchmodat,fchmod chmod 7770 x
     0.258 ( 0.008 ms): fchmodat(dfd: CWD, filename: x, mode: ISUID|ISGID|ISVTX|IRWXU|IRWXG) = 0
  # trace --no-inherit -e chmod,fchmodat,fchmod chmod 777 x
     0.293 ( 0.012 ms): fchmodat(dfd: CWD, filename: x, mode: IRWXUGO
  #

Now lets see if check by using the tracepoint for that specific syscall,
instead of raw_syscalls:sys_enter as 'trace' does for its strace fu:

  # trace --no-inherit --ev syscalls:sys_enter_fchmodat -e fchmodat chmod 666 x
     0.255 (         ): syscalls:sys_enter_fchmodat:dfd: 0xffffffffffffff9c, filename: 0x55db32a3f0f0, mode: 0x000001b6)
     0.268 ( 0.012 ms): fchmodat(dfd: CWD, filename: x, mode: IRUGO|IWUGO                     ) = 0
  #

Perfect, 0x1bc == 0666.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-18e8zfgbkj83xo87yoom43kd@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-08 09:58:13 -03:00
Arnaldo Carvalho de Melo d1d438a3b1 perf trace: Beautify pid_t arguments
When reading the syscall tracepoint /format file, look for arguments
of type "pid_t" and attach the PID beautifier, that will do a lookup
on the threads it knows, i.e. the ones that came from PERF_RECORD_COMM
events and add the COMM after the pid in such args:

Excerpt of a system wide trace for syscalls with pid_t args:

  55602.977 ( 0.006 ms): bash/12122 setpgid(pid: 24347 (bash), pgid: 24347 (bash)) = 0
  55603.024 ( 0.004 ms): bash/24347 setpgid(pid: 24347 (bash), pgid: 24347 (bash)) = 0
  55691.527 (88.397 ms): bash/12122 wait4(upid: -1, stat_addr: 0x7ffe0cee1720, options: UNTRACED|CONTINUED) ...
  55692.479 ( 0.952 ms): git/24347 wait4(upid: 24368, stat_addr: 0x7ffe030d5724) ...
  55694.549 ( 2.070 ms): pre-commit/24368 wait4(upid: -1, stat_addr: 0x7ffc94f4fc10) = 24369 (pre-commit)
  55694.575 ( 0.002 ms): pre-commit/24368 wait4(upid: -1, stat_addr: 0x7ffc94f4f650, options: NOHANG) = -1 ECHILD No child processes
  55695.934 ( 0.010 ms): pre-commit/24368 wait4(upid: -1, stat_addr: 0x7ffc94f4f2d0, options: NOHANG) = 24370 (git)
  55695.937 ( 0.001 ms): pre-commit/24368 wait4(upid: -1, stat_addr: 0x7ffc94f4f2d0, options: NOHANG) = -1 ECHILD No child processes
  55717.963 ( 0.000 ms): pre-commit/24371  ... [continued]: wait4()) = 24372
  55717.978 (21.468 ms): :24371/24371 wait4(upid: -1, stat_addr: 0x7ffc94f4f230) ...
  55718.087 ( 0.109 ms): pre-commit/24371 wait4(upid: -1, stat_addr: 0x7ffc94f4f230) = 24373 (tr)
  55718.187 ( 0.096 ms): pre-commit/24371 wait4(upid: -1, stat_addr: 0x7ffc94f4f230) = 24374 (wc)
  55718.218 ( 0.002 ms): pre-commit/24371 wait4(upid: -1, stat_addr: 0x7ffc94f4eed0, options: NOHANG) = -1 ECHILD No child processes
  55718.367 ( 0.005 ms): pre-commit/24368 wait4(upid: -1, stat_addr: 0x7ffc94f4f1d0, options: NOHANG) = 24371 (pre-commit)
  55718.369 ( 0.001 ms): pre-commit/24368 wait4(upid: -1, stat_addr: 0x7ffc94f4f1d0, options: NOHANG) = -1 ECHILD No child processes
  55741.021 (49.494 ms): git/24347  ... [continued]: wait4()) = 24368 (pre-commit)
  74146.427 (18319.601 ms): git/24347 wait4(upid: 24375 (git), stat_addr: 0x7ffe030d6824) ...
  74149.036 ( 0.891 ms): bash/24391 wait4(upid: -1, stat_addr: 0x7ffe0cee0560) = 24393 (sed)

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-75yl9hzjhb020iadc81gdj8t@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-06 19:36:30 -03:00
Arnaldo Carvalho de Melo c65f10701a perf trace: Beautify set_tid_address, getpid, getppid return values
Showing the COMM for that return, if available.

  # trace -e getpid,getppid,set_tid_address
    490.007 ( 0.005 ms): sh/8250 getpid(...) = 8250 (sh)
    490.014 ( 0.001 ms): sh/8250 getppid(...) = 7886 (make)
    491.156 ( 0.004 ms): install/8251 set_tid_address(tidptr: 0x7f204a9d4ad0) = 8251 (install)
  ^C

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-psbpplqupatom9x4uohbxid5@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-06 14:58:59 -03:00
Arnaldo Carvalho de Melo 11c8e39f51 perf trace: Infrastructure to show COMM strings for syscalls returning PIDs
Starting with clone, waitid and wait4:

  # trace -e waitid,wait4
     1.385 ( 1.385 ms): bash/12122 wait4(upid: -1, stat_addr: 0x7ffe0cee1720, options: UNTRACED|CONTINUED) = 1210 (ls)
     1.426 ( 0.002 ms): bash/12122 wait4(upid: -1, stat_addr: 0x7ffe0cee1150, options: NOHANG|UNTRACED|CONTINUED) = 0
     3.293 ( 0.604 ms): bash/1211 wait4(upid: -1, stat_addr: 0x7ffe0cee0560                             ) = 1214 (sed)
     3.342 ( 0.002 ms): bash/1211 wait4(upid: -1, stat_addr: 0x7ffe0cee01d0, options: NOHANG            ) = -1 ECHILD No child processes
     3.576 ( 0.016 ms): bash/12122 wait4(upid: -1, stat_addr: 0x7ffe0cee0550, options: NOHANG|UNTRACED|CONTINUED) = 1211 (bash)
  ^C# trace -e clone
     0.027 ( 0.000 ms): systemd/1  ... [continued]: clone()) = 1227 (systemd)
     0.050 ( 0.000 ms): systemd/1227  ... [continued]: clone()) = 0
  ^C[root@jouet ~]#

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-lyf5d3y5j15wikjb6pe6ukoi@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-06 14:37:25 -03:00
Arnaldo Carvalho de Melo 7206b900e6 perf trace: Beautify wait4/waitid 'options' argument
# trace -e waitid,wait4

   0.557 ( 0.557 ms): bash/27335 wait4(upid: -1, stat_addr: 0x7ffd02f449f0) = 27336
   1.250 ( 0.685 ms): bash/27335 wait4(upid: -1, stat_addr: 0x7ffd02f449f0) = 27337
   1.312 ( 0.002 ms): bash/27335 wait4(upid: -1, stat_addr: 0x7ffd02f44690, options: NOHANG) = -1 ECHILD No child processes
   1.550 ( 0.015 ms): bash/3856 wait4(upid: -1, stat_addr: 0x7ffd02f44990, options: NOHANG|UNTRACED|CONTINUED) = 27335
   1.552 ( 0.001 ms): bash/3856 wait4(upid: -1, stat_addr: 0x7ffd02f44990, options: NOHANG|UNTRACED|CONTINUED) = 0
  #

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-i5vlo5n5jv0amt8bkyicmdxh@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-06 14:13:43 -03:00
Arnaldo Carvalho de Melo a3bca91f2f perf trace: Beautify sched_setscheduler 'policy' argument
$ trace -e sched_setscheduler chrt -f 1 usleep 1
  chrt: failed to set pid 0's policy: Operation not permitted
     0.005 ( 0.005 ms): chrt/19189 sched_setscheduler(policy: FIFO, param: 0x7ffec5273d70) = -1 EPERM Operation not permitted
  $

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-i5vlo5n5jv0amt8bkyicmdxh@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-06 14:13:40 -03:00
Arnaldo Carvalho de Melo 8a07a8094b perf trace: Don't set the base timestamp using events without PERF_SAMPLE_TIME
This was causing bogus values to be shown at the timestamp column:

Before:

  # trace --ev bpf-output/no-inherit,name=evt/ --ev /home/acme/bpf/test_bpf_trace.c/map:channel.event=evt/ usleep 10
  94631143.385 ( 0.001 ms): brk(                                     ) = 0x555555757000
  94631143.398 ( 0.003 ms): mmap(len: 4096, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS, fd: -1) = 0x7ffff7ff6000
  94631143.406 ( 0.004 ms): access(filename: 0xf7df9e10, mode: R     ) = -1 ENOENT No such file or directory
  94631143.412 ( 0.004 ms): open(filename: 0xf7df8761, flags: CLOEXEC) = 3
  94631143.415 ( 0.002 ms): fstat(fd: 3, statbuf: 0x7fffffffd6b0     ) = 0
  94631143.419 ( 0.003 ms): mmap(len: 106798, prot: READ, flags: PRIVATE, fd: 3) = 0x7ffff7fdb000
  94631143.420 ( 0.001 ms): close(fd: 3                              ) = 0
  94631143.432 ( 0.004 ms): open(filename: 0xf7ff6640, flags: CLOEXEC) = 3
  <SNIP>

After:

  # trace --ev bpf-output/no-inherit,name=evt/ --ev /home/acme/bpf/test_bpf_trace.c/map:channel.event=evt/ usleep 10
  0.022 ( 0.001 ms): brk(                                     ) = 0x55d7668a6000
  0.037 ( 0.003 ms): mmap(len: 4096, prot: READ|WRITE, flags: PRIVATE|ANONYMOUS, fd: -1) = 0x7f8fbeb97000
  0.123 ( 0.083 ms): access(filename: 0xbe995e10, mode: R     ) = -1 ENOENT No such file or directory
  0.130 ( 0.004 ms): open(filename: 0xbe994761, flags: CLOEXEC) = 3
  0.133 ( 0.002 ms): fstat(fd: 3, statbuf: 0x7fff6487a890     ) = 0
  0.138 ( 0.003 ms): mmap(len: 106798, prot: READ, flags: PRIVATE, fd: 3) = 0x7f8fbeb7c000
  0.140 ( 0.001 ms): close(fd: 3                              ) = 0
  0.151 ( 0.004 ms): open(filename: 0xbeb97640, flags: CLOEXEC) = 3
  <SNIP>

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-p7m8llv81iv55ekxexdp5n57@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-01 18:46:25 -03:00
Arnaldo Carvalho de Melo e6001980c6 perf trace: Introduce function to set the base timestamp
That is used in both live runs, i.e.:

  # trace ls

As when processing events recorded in a perf.data file:

  # trace -i perf.data

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-901l6yebnzeqg7z8mbaf49xb@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-04-01 18:46:24 -03:00
Arnaldo Carvalho de Melo 39878d492c perf trace: Pretty print getrandom() args
# trace -e getrandom
  35622.560 ( 0.023 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
  35622.585 ( 0.006 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
  35622.594 ( 0.004 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
  35627.395 ( 0.010 ms): libvirtd/1353 getrandom(buf: 0x7f7a1bfa35c0, count: 16, flags: NONBLOCK    ) = 16
  35630.940 ( 0.013 ms): fwupd/16120 getrandom(buf: 0x7f63243aa5c0, count: 16, flags: NONBLOCK      ) = 16
  35718.613 ( 0.015 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
  35718.629 ( 0.005 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
  35718.637 ( 0.004 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
  35719.355 ( 0.010 ms): libvirtd/1353 getrandom(buf: 0x7f7a1bfa35c0, count: 16, flags: NONBLOCK    ) = 16
  35721.042 ( 0.030 ms): fwupd/16120 getrandom(buf: 0x7f63243aa5c0, count: 16, flags: NONBLOCK      ) = 16
  41090.830 ( 0.012 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
  41090.845 ( 0.004 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
  41090.851 ( 0.004 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
  41091.750 ( 0.010 ms): libvirtd/1353 getrandom(buf: 0x7f7a1bfa35c0, count: 16, flags: NONBLOCK    ) = 16
  41091.823 ( 0.006 ms): fwupd/16120 getrandom(buf: 0x7f63243aa5c0, count: 16, flags: NONBLOCK      ) = 16
  41122.078 ( 0.053 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
  41122.129 ( 0.009 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
  41122.139 ( 0.004 ms): systemd-udevd/631 getrandom(buf: 0x55621e3c18f0, count: 16, flags: NONBLOCK) = 16
  41124.492 ( 0.007 ms): libvirtd/1353 getrandom(buf: 0x7f7a1bfa35c0, count: 16, flags: NONBLOCK    ) = 16
  41124.470 ( 0.013 ms): fwupd/16120 getrandom(buf: 0x7f63243aa5c0, count: 16, flags: NONBLOCK      ) = 16
  41590.832 ( 0.014 ms): chrome/5957 getrandom(buf: 0x7fabac7b15b0, count: 16, flags: NONBLOCK      ) = 16
  41590.884 ( 0.004 ms): chrome/5957 getrandom(buf: 0x7fabac7b15c0, count: 16, flags: NONBLOCK      ) = 16

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-gca0n1p3aca3depey703ph2q@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-03-31 10:42:23 -03:00
Arnaldo Carvalho de Melo 997bba8cf1 perf trace: Pretty print seccomp() args
E.g:

  # trace -e seccomp
   200.061 (0.009 ms): :2441/2441 seccomp(op: FILTER, flags: TSYNC                       ) = -1 EFAULT Bad address
   200.910 (0.121 ms): :2441/2441 seccomp(op: FILTER, flags: TSYNC, uargs: 0x7fff57479fe0) = 0

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-t369uckshlwp4evkks4bcoo7@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-03-31 10:42:22 -03:00
Arnaldo Carvalho de Melo 3ed5ca2eff perf trace: Do not process PERF_RECORD_LOST twice
We catch this record to provide a visual indication that events are
getting lost, then call the default method to allow extra logging shared
with the other tools to take place.

This extra logging was done twice because we were continuing to the
"default" clause where machine__process_event() will end up calling
machine__process_lost_event() again, fix it.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-wus2zlhw3qo24ye84ewu4aqw@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-03-31 10:42:22 -03:00
Arnaldo Carvalho de Melo 473398a21d perf tools: Add cpumode to struct perf_sample
To avoid parsing event->header.misc in many locations.

This will also allow setting perf.sample.{ip,cpumode} in a single place,
from tracepoint fields, as needed by 'perf kvm' with PPC guests, where
the guest hardware counters is not available at the host.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Hemant Kumar <hemant@linux.vnet.ibm.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Naveen N. Rao <naveen.n.rao@linux.vnet.ibm.com>
Cc: Ravi Bangoria <ravi.bangoria@linux.vnet.ibm.com>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-qp3yradhyt6q3wl895b1aat0@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-03-23 12:03:07 -03:00
Taeung Song c42de706da perf trace: Check and discard not only 'nr' but also '__syscall_nr'
Format fields of a syscall have the first variable '__syscall_nr' or
'nr' that mean the syscall number.  But it isn't relevant here so drop
it.

'nr' among fields of syscall was renamed '__syscall_nr'.  So add
exception handling to drop '__syscall_nr' and modify the comment for
this excpetion handling.

Reported-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Signed-off-by: Taeung Song <treeze.taeung@gmail.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Steven Rostedt <rostedt@goodmis.org>
Link: http://lkml.kernel.org/r/1456492465-5946-1-git-send-email-treeze.taeung@gmail.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-02-29 11:34:28 -03:00
Wang Nan 1d6c9407d4 perf trace: Print content of bpf-output event
With this patch the contend of BPF output event is printed by
'perf trace'. For example:

 # ./perf trace -a --ev bpf-output/no-inherit,name=evt/ \
                   --ev ./test_bpf_trace.c/map:channel.event=evt/ \
                   usleep 100000
  ...
    1.787 ( 0.004 ms): usleep/3832 nanosleep(rqtp: 0x7ffc78b18980                                        ) ...
    1.787 (         ): evt:Raise a BPF event!..)
    1.788 (         ): perf_bpf_probe:func_begin:(ffffffff810e97d0))
  ...
  101.866 (87.038 ms): gmain/1654 poll(ufds: 0x7f57a80008c0, nfds: 2, timeout_msecs: 1000               ) ...
  101.866 (         ): evt:Raise a BPF event!..)
  101.867 (         ): perf_bpf_probe:func_end:(ffffffff810e97d0 <- ffffffff81796173))
  101.869 (100.087 ms): usleep/3832  ... [continued]: nanosleep()) = 0
  ...

 (There is an extra ')' at the end of several lines. However, it is
  another problem, unrelated to this commit.)

Where test_bpf_trace.c is:

  /************************ BEGIN **************************/
  #include <uapi/linux/bpf.h>
  struct bpf_map_def {
        unsigned int type;
        unsigned int key_size;
        unsigned int value_size;
        unsigned int max_entries;
  };
  #define SEC(NAME) __attribute__((section(NAME), used))
  static u64 (*ktime_get_ns)(void) =
        (void *)BPF_FUNC_ktime_get_ns;
  static int (*trace_printk)(const char *fmt, int fmt_size, ...) =
        (void *)BPF_FUNC_trace_printk;
  static int (*get_smp_processor_id)(void) =
        (void *)BPF_FUNC_get_smp_processor_id;
  static int (*perf_event_output)(void *, struct bpf_map_def *, int, void *, unsigned long) =
        (void *)BPF_FUNC_perf_event_output;

  struct bpf_map_def SEC("maps") channel = {
        .type = BPF_MAP_TYPE_PERF_EVENT_ARRAY,
        .key_size = sizeof(int),
        .value_size = sizeof(u32),
        .max_entries = __NR_CPUS__,
  };

  static inline int __attribute__((always_inline))
  func(void *ctx, int type)
  {
	char output_str[] = "Raise a BPF event!";
	char err_str[] = "BAD %d\n";
	int err;

        err = perf_event_output(ctx, &channel, get_smp_processor_id(),
			        &output_str, sizeof(output_str));
	if (err)
		trace_printk(err_str, sizeof(err_str), err);
        return 1;
  }
  SEC("func_begin=sys_nanosleep")
  int func_begin(void *ctx) {return func(ctx, 1);}
  SEC("func_end=sys_nanosleep%return")
  int func_end(void *ctx) { return func(ctx, 2);}
  char _license[] SEC("license") = "GPL";
  int _version SEC("version") = LINUX_VERSION_CODE;
  /************************* END ***************************/

Signed-off-by: Wang Nan <wangnan0@huawei.com>
Cc: Alexei Starovoitov <ast@kernel.org>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Li Zefan <lizefan@huawei.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: pi3orama@163.com
Link: http://lkml.kernel.org/r/1456479154-136027-8-git-send-email-wangnan0@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-02-26 19:57:07 -03:00
Wang Nan ba50423530 perf trace: Call bpf__apply_obj_config in 'perf trace'
Without this patch BPF map configuration is not applied.

Command like this:
 # ./perf trace --ev bpf-output/no-inherit,name=evt/ \
                --ev ./test_bpf_trace.c/map:channel.event=evt/ \
                usleep 100000

Load BPF files without error, but since map:channel.event=evt is not
applied, bpf-output event not work.

This patch allows 'perf trace' load and run BPF scripts.

Signed-off-by: Wang Nan <wangnan0@huawei.com>
Cc: Alexei Starovoitov <ast@kernel.org>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Li Zefan <lizefan@huawei.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: pi3orama@163.com
Link: http://lkml.kernel.org/r/1456479154-136027-7-git-send-email-wangnan0@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2016-02-26 19:50:40 -03:00
Josh Poimboeuf 4b6ab94eab perf subcmd: Create subcmd library
Move the subcommand-related files from perf to a new library named
libsubcmd.a.

Since we're moving files anyway, go ahead and rename 'exec_cmd.*' to
'exec-cmd.*' to be consistent with the naming of all the other files.

Signed-off-by: Josh Poimboeuf <jpoimboe@redhat.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lkml.kernel.org/r/c0a838d4c878ab17fee50998811612b2281355c1.1450193761.git.jpoimboe@redhat.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-12-17 14:27:14 -03:00
Arnaldo Carvalho de Melo 729a78417a perf trace: Add cmd string table to decode sys_bpf first arg
# perf trace -e bpf perf record -e /tmp/foo.o -a
   362.779 (0.130 ms): perf/3451 bpf(cmd: PROG_LOAD, uattr: 0x7ffe9a6825d0, size: 48) = 3

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Alexei Starovoitov <ast@plumgrid.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/n/tip-2b0nknu53baz9e0wj4thcdd8@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-10-29 11:48:18 -03:00
Jiri Olsa 8dd2a1317e perf evsel: Propagate error info from tp_format
Propagate error info from tp_format via ERR_PTR to get it all the way
down to the parse-event.c tracepoint adding routines. Following
functions now return pointer with encoded error:

  - tp_format
  - trace_event__tp_format
  - perf_evsel__newtp_idx
  - perf_evsel__newtp

This affects several other places in perf, that cannot use pointer check
anymore, but must utilize the err.h interface, when getting error
information from above functions list.

Signed-off-by: Jiri Olsa <jolsa@kernel.org>
Cc: David Ahern <dsahern@gmail.com>
Cc: Matt Fleming <matt@codeblueprint.co.uk>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Raphael Beamonte <raphael.beamonte@gmail.com>
Link: http://lkml.kernel.org/r/1441615087-13886-5-git-send-email-jolsa@kernel.org
[ Add two missing ERR_PTR() and one IS_ERR() ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-09-15 09:48:33 -03:00
Jiri Olsa 988bdb3192 tools lib api fs: Move debugfs__strerror_open into tracing_path.c object
Moving debugfs__strerror_open out of api/fs/debugfs.c, because it's not
debugfs specific. It'll be changed to consider tracefs mount as well in
following patches.

Renaming it into tracing_path__strerror_open_tp to fit into the
namespace. No functional change is intended.

Signed-off-by: Jiri Olsa <jolsa@kernel.org>
Reviewed-by: Matt Fleming <matt.fleming@intel.com>
Cc: Raphael Beamonte <raphael.beamonte@gmail.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Steven Rostedt <rostedt@goodmis.org>
Link: http://lkml.kernel.org/r/1441180605-24737-6-git-send-email-jolsa@kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-09-04 12:00:58 -03:00
Arnaldo Carvalho de Melo a598bb5e35 perf trace: Add header with copyright and background info
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-5yqtfs728r1j1u8zmg8ufxwm@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-08-28 14:53:48 -03:00
Arnaldo Carvalho de Melo 7f4f800131 perf trace: Move vfs_getname storage to per thread area
We were storing the vfs_getname payload (i.e. ptr->string) into
the trace wide storage area (struct trace), so that we could use the
last payload when setting up the fd->pathname per thread tables, oops,
not a good idea for multi cpu tracing sessions...

Fix it by moving it to the per thread area (struct thread_trace).

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-3j05ttqyaem7kh7oubvr1keo@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-08-14 13:16:27 -03:00
Arnaldo Carvalho de Melo b62bee1bde perf trace: Beautify keyctl's option arg
8.697 (0.103 ms): pool/2343 keyctl(option: GET_PERSISTENT, arg2: 1000, arg3: 4294967294, arg4: 140703061514067, arg5: 140703692383680) = 1023192809
 8.763 (0.049 ms): pool/2343 keyctl(option: SEARCH, arg2: 1023192809, arg3: 140703745767772, arg4: 140703745767832, arg5: 4294967294) = 140224497
 8.789 (0.016 ms): pool/2343 keyctl(option: SEARCH, arg2: 140224497, arg3: 140703745767814, arg4: 140703745767900) = 512300257
 8.807 (0.011 ms): pool/2343 keyctl(option: READ, arg2: 512300257                                  ) = 13
 8.822 (0.008 ms): pool/2343 keyctl(option: READ, arg2: 512300257, arg3: 140703061514000, arg4: 13 ) = 13
 8.837 (0.007 ms): pool/2343 keyctl(option: READ, arg2: 140224497                                  ) = 4
 8.852 (0.009 ms): pool/2343 keyctl(option: READ, arg2: 140224497, arg3: 140703061514000, arg4: 4  ) = 4
 8.869 (0.010 ms): pool/2343 keyctl(option: SEARCH, arg2: 140224497, arg3: 140703745767772, arg4: 140703061514032) = -1 ENOKEY Required key not available
 8.892 (0.017 ms): pool/2343 keyctl(option: DESCRIBE, arg2: 512300257                              ) = 43
 8.910 (0.012 ms): pool/2343 keyctl(option: DESCRIBE, arg2: 512300257, arg3: 140703061544384, arg4: 43) = 43

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-013ab219irsxngyumrf5gp8s@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-08-12 10:27:03 -03:00
Arnaldo Carvalho de Melo 8d8c66a248 perf trace: Use the FD beautifier for socket syscall fds
But we really should have something like 'strace -yy' here...

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-eyrt1ypfq68u4ljagyk2nj1i@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-08-12 10:27:03 -03:00
Arnaldo Carvalho de Melo 28ebb87c73 perf trace: Add missing clockid entries
We were missing:

  CLOCK_BOOTTIME, CLOCK_REALTIME_ALARM, CLOCK_BOOTTIME_ALARM,
  CLOCK_SGI_CYCLE and CLOCK_TAI.

Add them.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-d67rwqtwm9jyenwes98kr0cr@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-08-12 10:27:02 -03:00
Arnaldo Carvalho de Melo 090389b6d9 perf trace: Associate some more syscall args with the getname beautifier
This time using 'trinity' to test these:

  fchmodat, futimesat, llistxattr, lremovexattr, lstat, mknodat,
  mq_unlink, stat and vmsplice.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-a1uqu249nwwh0ixrhm80k4a4@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-08-12 10:26:53 -03:00
Milian Wolff 834fd46ddb perf trace: Add total time column to summary.
It is cumbersome to manually calculate the total time spent in a given
syscall by multiplying the average value with the number of calls.

Instead, we now do this directly inside perf trace.

Note that this is also done by 'strace', which even adds a column with
relative numbers - something we could do in the future.

Example:

  perf trace -s find /some/folder > /dev/null

   Summary of events:

   find (19976), 700123 events, 100.0%, 0.000 msec

     syscall            calls    total       min       avg       max      stddev
                                 (msec)    (msec)    (msec)    (msec)        (%)
     --------------- -------- --------- --------- --------- ---------     ------
     read                   4     0.006     0.001     0.002     0.003     27.42%
     write               8046     9.617     0.001     0.001     0.035      0.56%
     open               34196    40.384     0.001     0.001     0.071      0.30%
     close              68375    57.104     0.001     0.001     0.076      0.25%
     stat                   4     0.004     0.001     0.001     0.001      3.14%
     fstat              34189    27.518     0.001     0.001     0.060      0.34%
     mmap                  13     0.029     0.001     0.002     0.003     10.74%
     mprotect               6     0.018     0.002     0.003     0.005     17.04%
     munmap                 3     0.014     0.003     0.005     0.006     24.87%
     brk                   87     0.490     0.001     0.006     0.016      6.50%
     ioctl                  3     0.004     0.001     0.001     0.003     36.39%
     access                 1     0.004     0.004     0.004     0.004      0.00%
     uname                  1     0.001     0.001     0.001     0.001      0.00%
     getdents           68393   143.600     0.001     0.002     0.187      0.95%
     fchdir             68371    56.980     0.001     0.001     0.111      0.39%
     arch_prctl             1     0.001     0.001     0.001     0.001      0.00%
     openat             34184    41.737     0.001     0.001     0.102      0.41%
     newfstatat         34184    41.180     0.001     0.001     0.064      0.34%

Signed-off-by: Milian Wolff <milian.wolff@kdab.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
LPU-Reference: 1438853069-5902-1-git-send-email-milian.wolff@kdab.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-08-06 11:29:49 -03:00
Milian Wolff 007d66a0bd perf trace: Write to stderr by default
Without this patch, it is cumbersome to read the trace output but
ignoring the normal, potentially verbose, output of the debuggee.  One
common example is doing something like the following:

 perf trace -s find /tmp > /dev/null

Without this patch, the trace summary will be lost. Now, it will still
be printed at the end. This behavior is also applied by strace.

Cc: Milian Wolff <milian.wolff@kdab.com>
Cc: David Ahern <dsahern@gmail.com>
Link: http://lkml.kernel.org/n/tip-tqnks6y2cnvm5f9g2dsfr7zl@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-08-05 16:52:23 -03:00
Arnaldo Carvalho de Melo 34221118cb perf trace: Use vfs_getname syscall arg beautifier in more syscalls
Those were covered and tested in this cset:

 access, chdir, chmod, chown, chroot, creat, getxattr,
 inotify_add_watch, lchown, lgetxattr, listxattr,
 lsetxattr, mkdir, mkdirat, mknod, rmdir, faccessat,
 newfstatat, openat, readlink, readlinkat, removexattr,
 setxattr, statfs, swapon, swapoff, truncate, unlinkat,
 utime, utimes, utimensat.

E.g.:

  # trace -e statfs,access,mkdir mkdir /tmp/bla
   0.285 (0.020 ms): mkdir/2799 access(filename: /etc/ld.so.preload, mode: R         ) = -1 ENOENT No such file or directory
   1.070 (0.032 ms): mkdir/2799 statfs(pathname: /sys/fs/selinux, buf: 0x7ffeafbdc930) = 0
   1.087 (0.013 ms): mkdir/2799 statfs(pathname: /sys/fs/selinux, buf: 0x7ffeafbdc820) = 0
   1.189 (0.014 ms): mkdir/2799 access(filename: /etc/selinux/config                 ) = 0
   1.905 (0.610 ms): mkdir/2799 mkdir(pathname: /tmp/bla, mode: 511                  ) = 0
  #

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Milian Wolff <mail@milianw.de>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-wbqtnlktquun3wtpjdz3okul@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>

  and an empty message aborts the commit.
2015-08-05 12:50:11 -03:00
Arnaldo Carvalho de Melo f994592d93 perf trace: Deref sys_enter pointer args with contents from probe:vfs_getname
To work like strace and dereference syscall pointer args we need to
insert probes (or tracepoints) right after we copy those bytes from
userspace.

Since we're formatting the syscall args at raw_syscalls:sys_enter time,
we need to have a formatter that just stores the position where, later,
when we get the probe:vfs_getname, we can insert the pointer contents.

Now, if a probe:vfs_getname with this format is in place:

 # perf probe -l
  probe:vfs_getname (on getname_flags:72@/home/git/linux/fs/namei.c with pathname)

That was, in this case, put in place with:

 # perf probe 'vfs_getname=getname_flags:72 pathname=filename:string'
 Added new event:
  probe:vfs_getname    (on getname_flags:72 with pathname=filename:string)

 You can now use it in all perf tools, such as:

	perf record -e probe:vfs_getname -aR sleep 1
 #

Then 'perf trace' will notice that and do the pointer -> contents
expansion:

 # trace -e open touch /tmp/bla
  0.165 (0.010 ms): touch/17752 open(filename: /etc/ld.so.cache, flags: CLOEXEC) = 3
  0.195 (0.011 ms): touch/17752 open(filename: /lib64/libc.so.6, flags: CLOEXEC) = 3
  0.512 (0.012 ms): touch/17752 open(filename: /usr/lib/locale/locale-archive, flags: CLOEXEC) = 3
  0.582 (0.012 ms): touch/17752 open(filename: /tmp/bla, flags: CREAT|NOCTTY|NONBLOCK|WRONLY, mode: 438) = 3
 #

Roughly equivalent to strace's output:

 # strace -rT -e open touch /tmp/bla
  0.000000 open("/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 <0.000039>
  0.000317 open("/lib64/libc.so.6", O_RDONLY|O_CLOEXEC) = 3 <0.000102>
  0.001461 open("/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3 <0.000072>
  0.000405 open("/tmp/bla", O_WRONLY|O_CREAT|O_NOCTTY|O_NONBLOCK, 0666) = 3 <0.000055>
  0.000641 +++ exited with 0 +++
 #

Now we need to either look for at all syscalls that are marked as
pointers and have some well known names ("filename", "pathname", etc)
and set the arg formatter to the one used for the "open" syscall in this
patch.

This implementation works for syscalls with just a string being copied
from userspace, for matching syscalls with more than one string being
copied via the same probe/trace point (vfs_getname) we need to extend
the vfs_getname probe spec to include the pointer too, but there are
some problems with that in 'perf probe' or the kernel kprobes code, need
to investigate before considering supporting multiple strings per
syscall.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Milian Wolff <mail@milianw.de>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-xvuwx6nuj8cf389kf9s2ue2s@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-08-05 10:52:45 -03:00
Arnaldo Carvalho de Melo e4d44e830a perf trace: Use a constant for the syscall formatting buffer
We were using it as a magic number, 1024, fix that.

Eventually we need to stop doing it per line, and do it per
arg, traversing the args at output time, to avoid the memmove()
calls that will be used in the next cset to replace pointers
present at raw_syscalls:sys_enter time with its contents that
appear at probe:vfs_getname time, before raw_syscalls:sys_exit
time.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Milian Wolff <mail@milianw.de>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-4sz3wid39egay1pp8qmbur4u@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-08-05 10:52:40 -03:00
Arnaldo Carvalho de Melo 08c987763a perf trace: Remember if the vfs_getname tracepoint/kprobe is in place
So that we can later decide if we will store where to expand the
pathname once we are handling vfs_getname or if we should instead
just go on and straight away print the pointer.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Milian Wolff <mail@milianw.de>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-ytxk5s5jpc50wahffmlxgxuw@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-08-05 10:52:32 -03:00
Arnaldo Carvalho de Melo 2e5e5f8761 perf trace: Do not show syscall tracepoint filter in the --no-syscalls case
We were accessing trace->syscalls.events members even when that struct
wasn't initialized, i.e. --no-syscalls was specified on the command
line, fix it to show that, still in debug mode, when we have an event
qualifier list, i.e. when we actually are doing subset syscall tracing.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Milian Wolff <mail@milianw.de>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Stephane Eranian <eranian@google.com>
Fixes: 19867b6186 ("perf trace: Use event filters for the event qualifier list")
Link: http://lkml.kernel.org/n/tip-7980ym6vujgh3yiai0cqzc88@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-08-05 10:52:19 -03:00
Arnaldo Carvalho de Melo 959c2199d4 perf python: Remove dependency on 'machine' methods
The python binding still doesn't provide symbol resolving facilities,
but the recent addition of the trace_event__register_resolver() function
made it add as a dependency the machine__resolve_kernel_addr() method,
that in turn drags all the symbol resolving code.

The problem:

  [root@zoo ~]# perf test -v python
  17: Try 'import perf' in python, checking link problems      :
  --- start ---
  test child forked, pid 6853
  Traceback (most recent call last):
    File "<stdin>", line 1, in <module>
  ImportError: /tmp/build/perf/python/perf.so: undefined symbol: machine__resolve_kernel_addr
  test child finished with -1
  ---- end ----
  Try 'import perf' in python, checking link problems: FAILED!
  [root@zoo ~]#

Fix it by requiring this function to receive the resolver as a
parameter, just like pevent_register_function_resolver(), i.e. do
not explicitely refer to an object file not included in
tools/perf/util/python-ext-sources.

  [root@zoo ~]# perf test python
  17: Try 'import perf' in python, checking link problems      : Ok
  [root@zoo ~]#

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Stephane Eranian <eranian@google.com>
Fixes: c3168b0db9 ("perf symbols: Provide libtraceevent callback to resolve kernel symbols")
Link: http://lkml.kernel.org/n/tip-vxlhh95v2em9zdbgj3jm7xi5@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-07-29 10:51:44 -03:00
Arnaldo Carvalho de Melo 706c3da409 perf trace: Provide libtracevent with a kernel symbol resolver
So that beautifiers wanting to resolve kernel function addresses to
names can do its work, now, for instance, the 'timer' tracepoints
beautifiers works with 'perf trace', see the "function=tick..." part:

 # perf trace --event timer:hrtimer_start
<SNIP>
  0.000 timer:hrtimer_start:hrtimer=0xffff88026f3101c0 function=tick_sched_timer/0x0 expires=52098339000000 softexpires=52098339000000)
  0.003 timer:hrtimer_start:hrtimer=0xffff88026f3101c0 function=tick_sched_timer/0x0 expires=52098339000000 softexpires=52098339000000)
<SNIP>

Reported-by: Thomas Gleixner <tglx@linutronix.de>
Acked-by: David Ahern <dsahern@gmail.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Stephane Eranian <eranian@google.com>
Cc: Steven Rostedt <rostedt@goodmis.org>
Link: http://lkml.kernel.org/n/tip-n4i0hxpbl1tnleiqkok47fw2@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-07-23 22:01:38 -03:00
Arnaldo Carvalho de Melo 005438a8ee perf trace: Support 'strace' syscall event groups
I.e.:

  $ cat ~/share/perf-core/strace/groups/file
  access
  chmod
  creat
  execve
  faccessat
  getcwd
  lstat
  mkdir
  open
  openat
  quotactl
  readlink
  rename
  rmdir
  stat
  statfs
  symlink
  unlink
  $

Then, on a quiet desktop, try running this and then moving your mouse to
see the deluge of mouse related activity:

  # perf probe 'vfs_getname=getname_flags:72 pathname=filename:string'
  Added new event:
    probe:vfs_getname    (on getname_flags:72 with pathname=filename:string)

  You can now use it in all perf tools, such as:

	perf record -e probe:vfs_getname -aR sleep 1
  #
  # trace --ev probe:vfs_getname --filter-pids 2232 -e file
   0.042 (0.042 ms): mousetweaks/2235 open(filename: 0x14e3910, mode: 438                                   ) ...
   0.042 (        ): probe:vfs_getname:(ffffffff812230bc) pathname="/home/acme/.icons/Adwaita/cursors/xterm")
   0.100 (0.100 ms): mousetweaks/2235  ... [continued]: open()) = -1 ENOENT No such file or directory
   0.142 (0.018 ms): mousetweaks/2235 open(filename: 0x14c3c10, mode: 438                                   ) ...
   0.142 (        ): probe:vfs_getname:(ffffffff812230bc) pathname="/home/acme/.icons/Adwaita/index.theme")
   0.192 (0.069 ms): mousetweaks/2235  ... [continued]: open()) = -1 ENOENT No such file or directory
   0.230 (0.017 ms): mousetweaks/2235 open(filename: 0x14c3c10, mode: 438                                   ) ...
   0.230 (        ): probe:vfs_getname:(ffffffff812230bc) pathname="/usr/share/icons/Adwaita/cursors/xterm")
   0.253 (0.041 ms): mousetweaks/2235  ... [continued]: open()) = 14
   0.459 (0.008 ms): mousetweaks/2235 open(filename: 0x14e3910, mode: 438                                   ) ...
   0.459 (        ): probe:vfs_getname:(ffffffff812230bc) pathname="/home/acme/.icons/Adwaita/cursors/left_side")
   0.468 (0.017 ms): mousetweaks/2235  ... [continued]: open()) = -1 ENOENT No such file or directory

Need to combine that raw_syscalls:sys_enter(open) + probe:vfs_getname +
raw_syscalls:sys_exit(open) sequence...

Now, if you're bored, please write some more syscall groups, like the ones
in 'strace' and send it our way :-)

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Milian Wolff <mail@milianw.de>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-a42xklu59lcbxp7bbnic74a8@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-07-20 15:16:32 -03:00
Arnaldo Carvalho de Melo 4a77e2183f perf strlist: Make dupstr be the default and part of an extensible config parm
So that we can pass more info to strlist__new() without having to change
its function signature, just adding entries to the strlist_config struct
with sensible defaults for when those fields are not specified.

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: David Ahern <dsahern@gmail.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-5uaaler4931i0s9sedxjquhq@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-07-20 12:13:34 -03:00
Arnaldo Carvalho de Melo 19867b6186 perf trace: Use event filters for the event qualifier list
We use raw_syscalls:sys_{enter,exit} events to show the syscalls, but were
using a rather lazy/inneficient way to implement our 'strace -e' equivalent:
filter out after reading the events in the ring buffer.

Deflect more work to the kernel by appending a filter expression for that,
that, together with the pid list, that is always present, if only to filter the
tracer itself, reduces pressure on the ring buffer and otherwise use
infrastructure already in place in the kernel to do early filtering.

If we use it with -v we can see the filter passed to the kernel,
for instance, for this contrieved case:

  # trace -v -e \!open,close,write,poll,recvfrom,select,recvmsg,writev,sendmsg,read,futex,epoll_wait,ioctl,eventfd --filter-pids 2189,2566,1398,2692,4475,4532
<SNIP>
  (common_pid != 2514 && common_pid != 1398 && common_pid != 2189 && common_pid != 2566 && common_pid != 2692 && common_pid != 4475 && common_pid != 4532) && (id != 3 && id != 232 && id != 284 && id != 202 && id != 16 && id != 2 && id != 7 && id != 0 && id != 45 && id != 47 && id != 23 && id != 46 && id != 1 && id != 20)
     0.011 (0.011 ms): caribou/2295 eventfd2(flags: CLOEXEC|NONBLOCK) = 18
    16.946 (0.019 ms): caribou/2295 eventfd2(flags: CLOEXEC|NONBLOCK) = 18
    38.598 (0.167 ms): chronyd/794 socket(family: INET, type: DGRAM ) = 4
    38.603 (0.002 ms): chronyd/794 fcntl(fd: 4<socket:[239307]>, cmd: GETFD) = 0
    38.605 (0.001 ms): chronyd/794 fcntl(fd: 4<socket:[239307]>, cmd: SETFD, arg: 1) = 0
^C
 #

Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
Cc: David Ahern <dsahern@gmail.com>
Cc: Don Zickus <dzickus@redhat.com>
Cc: Frederic Weisbecker <fweisbec@gmail.com>
Cc: Jiri Olsa <jolsa@redhat.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-ti2tg18atproqpguc2moinp6@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
2015-07-06 08:58:35 -03:00