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: 19867b61 ("perf trace: Use event filters for the event qualifier list")
Link: http://lkml.kernel.org/n/tip-7980ym6vujgh3yiai0cqzc88@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

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: c3168b0d ("perf symbols: Provide libtraceevent callback to resolve kernel symbols")
Link: http://lkml.kernel.org/n/tip-vxlhh95v2em9zdbgj3jm7xi5@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

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: NThomas Gleixner <tglx@linutronix.de>
Acked-by: NDavid 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.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

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.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

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.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

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.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

Instead of calling perf_evsel__apply_filter straight away, so that
we can, in the next patches, expand the filter with more conditions
before actually calling the ioctl to pass the end result filter to
the kernel.

Now we need to call perf_evlist__apply_filters() after the filter
is completely setup, i.e. do the ioctl calls.

The perf_evlist__apply_filters() method was already in place, because
that is the model for the other tools that receives filters in the
command line: go on setting then in the evsel->filter and only at
the end, after parsing the whole command line, apply them.

We get, as a bonus, a more expressive message that states which
event, if any, failed to have the filter applied to, with an
error message stating what happened.

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-f429pgz75ryz7tpe6v74etre@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

That we will use to set a filter on raw_syscalls:sys_{enter,exit}
events.

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-2acxrcxyu7tlolrfilpty38y@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

We will need to set filters on then.

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-u8hpgjpf3w8o1prnnjnwegwf@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

The 'trace' tool was accepting any names passed and just looking if
syscalls returned via the raw_syscalls:* tracepoints were in that list,
leading to it accepting perf events and then never finding any, as those
are not valid syscall names, confusing users.

Fix it by checking each entry in the list using audit_name_to_syscall,
telling the user which entries are invalid and suggesting where to look
for valid syscall names.

E.g:

  [root@zoo ~]# trace -e open,foo,bar,close,baz
  Error: Invalid syscall bar, baz, foo
  Hint:	 try 'perf list syscalls:sys_enter_*'
  Hint:	 and: 'man syscalls'
  [root@zoo ~]#
Reported-by: NFlavio Leitner <fbl@redhat.com>
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>
Link: http://lkml.kernel.org/n/tip-4g1i3m1z6fzsrznn2umi02wa@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

Instead provide a method to set the array entries, and another to access
the contents.
Signed-off-by: NJiri Olsa <jolsa@kernel.org>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Andi Kleen <ak@linux.intel.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/r/1435012588-9007-2-git-send-email-jolsa@kernel.org
[ Split providing the set/get accessors from transforming the entries structs ]
Signed-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

The time out to limit the individual proc map processing was hard code
to 500ms. This patch introduce a new option --proc-map-timeout to make
the time limit configurable.
Signed-off-by: NKan Liang <kan.liang@intel.com>
Cc: Andi Kleen <andi@firstfloor.org>
Cc: David Ahern <dsahern@gmail.com>
Cc: Ying Huang <ying.huang@intel.com>
Link: http://lkml.kernel.org/r/1434549071-25611-2-git-send-email-kan.liang@intel.comSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

Syswide tracing and then running 'stat' and 'trace':

 $ perf trace -e perf_event_open
 1034.649 (0.019 ms): perf/6133 perf_event_open(attr_uptr: 0x36f0360, pid: 16134, cpu: -1, group_fd: -1, flags: FD_CLOEXEC) = -1 EINVAL Invalid argument
 1034.670 (0.008 ms): perf/6133 perf_event_open(attr_uptr: 0x36f0360, pid: 16134, cpu: -1, group_fd: -1) = -1 EINVAL Invalid argument
 1034.681 (0.007 ms): perf/6133 perf_event_open(attr_uptr: 0x36f0360, pid: 16134, cpu: -1, group_fd: -1) = -1 EINVAL Invalid argument
 1034.692 (0.007 ms): perf/6133 perf_event_open(attr_uptr: 0x36f0360, pid: 16134, cpu: -1, group_fd: -1) = -1 EINVAL Invalid argument
 9986.983 (0.014 ms): trace/6139 perf_event_open(attr_uptr: 0x7ffd9c629320, pid: -1, group_fd: -1, flags: FD_CLOEXEC) = 3
 9987.026 (0.016 ms): trace/6139 perf_event_open(attr_uptr: 0x37c7e70, pid: -1, group_fd: -1, flags: FD_CLOEXEC) = 3
 9987.041 (0.008 ms): trace/6139 perf_event_open(attr_uptr: 0x37c7e70, pid: -1, group_fd: -1, flags: FD_CLOEXEC) = 3
 9987.489 (0.092 ms): trace/6139 perf_event_open(attr_uptr: 0x3795ee0, pid: 16140, group_fd: -1, flags: FD_CLOEXEC) = 3
 9987.536 (0.044 ms): trace/6139 perf_event_open(attr_uptr: 0x3795ee0, pid: 16140, cpu: 1, group_fd: -1, flags: FD_CLOEXEC) = 4
 9987.580 (0.041 ms): trace/6139 perf_event_open(attr_uptr: 0x3795ee0, pid: 16140, cpu: 2, group_fd: -1, flags: FD_CLOEXEC) = 5
 9987.620 (0.037 ms): trace/6139 perf_event_open(attr_uptr: 0x3795ee0, pid: 16140, cpu: 3, group_fd: -1, flags: FD_CLOEXEC) = 7
 9987.659 (0.035 ms): trace/6139 perf_event_open(attr_uptr: 0x37975d0, pid: 16140, group_fd: -1, flags: FD_CLOEXEC) = 8
 9987.692 (0.031 ms): trace/6139 perf_event_open(attr_uptr: 0x37975d0, pid: 16140, cpu: 1, group_fd: -1, flags: FD_CLOEXEC) = 9
 9987.727 (0.032 ms): trace/6139 perf_event_open(attr_uptr: 0x37975d0, pid: 16140, cpu: 2, group_fd: -1, flags: FD_CLOEXEC) = 10
 9987.761 (0.031 ms): trace/6139 perf_event_open(attr_uptr: 0x37975d0, pid: 16140, cpu: 3, group_fd: -1, flags: FD_CLOEXEC) = 11

Need to intercept perf_copy_attr() with a kprobe or with eBPF...

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>
Link: http://lkml.kernel.org/n/tip-njb105hab2i3t5dexym9lskl@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

Such as RHEL5, where CLOEXEC, NONBLOCK flags are not present, use a
ifdef+define approach instead to make it build on all distros.

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>
Cc: Vinson Lee <vlee@twitter.com>
Link: http://lkml.kernel.org/n/tip-pioazikk9d9oz5qdeor3eldu@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

No need to test trace.evlist against NULL twice.
Signed-off-by: NHe Kuang <hekuang@huawei.com>
Cc: Jiri Olsa <jolsa@kernel.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/r/1431347316-30401-2-git-send-email-hekuang@huawei.comSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

In addition to using refcounts for the struct thread lifetime
management, we need to protect access to machine->threads from
concurrent access.

That happens in 'perf top', where a thread processes events, inserting
and deleting entries from that rb_tree while another thread decays
hist_entries, that end up dropping references and ultimately deleting
threads from the rb_tree and releasing its resources when no further
hist_entry (or other data structures, like in 'perf sched') references
it.

So the rule is the same for refcounts + protected trees in the kernel,
get the tree lock, find object, bump the refcount, drop the tree lock,
return, use object, drop the refcount if no more use of it is needed,
keep it if storing it in some other data structure, drop when releasing
that data structure.

I.e. pair "t = machine__find(new)_thread()" with a "thread__put(t)", and
"perf_event__preprocess_sample(&al)" with "addr_location__put(&al)".

The addr_location__put() one is because as we return references to
several data structures, we may end up adding more reference counting
for the other data structures and then we'll drop it at
addr_location__put() time.
Acked-by: NDavid Ahern <dsahern@gmail.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
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-bs9rt4n0jw3hi9f3zxyy3xln@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

This comes from the desire of having -e/--expr to have the same meaning
as for 'strace', while other perf tools use it for --event, which
'trace' honours, i.e. all perf tools have --event in common, but trace
uses -e for strace's --expr.

Clarify it in the --help output.
Reported-by: NDavid Ahern <dsahern@gmail.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
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-5j94bcsdmcbeu2xthnzsj60d@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

Cut't'paste error, fix it.
Reported-by: NDavid Ahern <dsahern@gmail.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
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-26abqh0wg9dci3fqcppyrpxy@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

We were not checking in the inner event processing loop if the forked workload
had finished, which, on a busy system, may make it take a long time trying to
drain events, entering a seemingly neverending loop, waiting for the system to
get idle enough to make it drain the buffers.

Fix it by disabling the events when 'done' is true, in the inner loop, to start
draining what is in the buffers.

Now:

[root@ssdandy ~]# time trace --filter-pids 14003 -a sleep 1 | tail
  996.748 ( 0.002 ms): sh/30296 rt_sigprocmask(how: SETMASK, nset: 0x7ffc83418160, sigsetsize: 8) = 0
  996.751 ( 0.002 ms): sh/30296 rt_sigprocmask(how: BLOCK, nset: 0x7ffc834181f0, oset: 0x7ffc83418270, sigsetsize: 8) = 0
  996.755 ( 0.002 ms): sh/30296 rt_sigaction(sig: INT, act: 0x7ffc83417f50, oact: 0x7ffc83417ff0, sigsetsize: 8) = 0
 1004.543 ( 0.362 ms): tail/30198  ... [continued]: read()) = 4096
 1004.548 ( 7.791 ms): sh/30296 wait4(upid: -1, stat_addr: 0x7ffc834181a0) ...
 1004.975 ( 0.427 ms): tail/30198 read(buf: 0x7633f0, count: 8192) = 4096
 1005.390 ( 0.410 ms): tail/30198 read(buf: 0x765410, count: 8192) = 4096
 1005.743 ( 0.348 ms): tail/30198 read(buf: 0x7633f0, count: 8192) = 4096
 1006.197 ( 0.449 ms): tail/30198 read(buf: 0x765410, count: 8192) = 4096
 1006.492 ( 0.290 ms): tail/30198 read(buf: 0x7633f0, count: 8192) = 4096

real	0m1.219s
user	0m0.704s
sys	0m0.331s
[root@ssdandy ~]#
Reported-by: NMichael Petlan <mpetlan@redhat.com>
Suggested-by: NJiri Olsa <jolsa@redhat.com>
Acked-by: NJiri Olsa <jolsa@redhat.com>
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: Namhyung Kim <namhyung@kernel.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-p6kpn1b26qcbe47pufpw0tex@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

 commit f7aa222f
 Author: Arnaldo Carvalho de Melo <acme@redhat.com>
 Date:   Tue Feb 3 13:25:39 2015 -0300

    perf trace: No need to enable evsels for workload started from perf

The assumption was that whenever a workload is specified, the
attr.enable_on_exec evsel flag would be set, but that is not happening
when perf_record_opts.system_wide is set, for instance

That resulted in both perf_evlist__enable() and attr.enable_on_exec
being not called/set, which made the events to remain disabled while the
workload runs, producing no output.

Fix it,  by calling perf_evlist__enable() in the 'trace' tool
when forking and not targetting a workload started from trace

v2: Test against !target__none(), as suggested by Namhyung Kim, that is
what is used in perf_evsel__config() when deciding if the
attr.enable_on_exec flag to be set. More work is needed to cover other
cases such as opts->initial_delay.
Acked-by: NJiri Olsa <jolsa@redhat.com>
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: Namhyung Kim <namhyung@kernel.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-27z7169pvfxgj8upic636syv@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

Enable perf trace to use perf.data when it is not owned by current user
or root.

Example:

 # perf trace record ls
 # chown Yunlong.Song:Yunlong.Song perf.data
 # ls -al perf.data
 -rw------- 1 Yunlong.Song Yunlong.Song 4153101 Apr  2 15:28 perf.data
 # id
 uid=0(root) gid=0(root) groups=0(root),64(pkcs11)

Before this patch:

 # perf trace -i perf.data
 File perf.data not owned by current user or root (use -f to override)
 # perf trace -i perf.data -f
   Error: unknown switch `f'

  usage: perf trace [<options>] [<command>]
     or: perf trace [<options>] -- <command> [<options>]
     or: perf trace record [<options>] [<command>]
     or: perf trace record [<options>] -- <command> [<options>]

         --event <event>   event selector. use 'perf list' to list
 						  available events
         --comm            show the thread COMM next to its id
         --tool_stats      show tool stats
     -e, --expr <expr>     list of events to trace
     -o, --output <file>   output file name
     -i, --input <file>    Analyze events in file
     -p, --pid <pid>       trace events on existing process id
     -t, --tid <tid>       trace events on existing thread id
         --filter-pids <float>
  ...

As shown above, the -f option does not work at all.

After this patch:

 # perf trace -i perf.data
 File perf.data not owned by current user or root (use -f to override)
 # perf trace -i perf.data -f
 0.056 ( 0.002 ms): ls/47325 brk(                                 ...
 0.108 ( 0.018 ms): ls/47325 mmap(len: 4096, prot: READ|WRITE,    ...
 0.145 ( 0.013 ms): ls/47325 access(filename: 0x7f31259a0eb0,     ...
 0.172 ( 0.008 ms): ls/47325 open(filename: 0x7fffeb9a0d00,       ...
 0.180 ( 0.004 ms): ls/47325 stat(filename: 0x7fffeb9a0d00,       ...
 0.185 ( 0.004 ms): ls/47325 open(filename: 0x7fffeb9a0d00,       ...
 0.189 ( 0.003 ms): ls/47325 stat(filename: 0x7fffeb9a0d00,       ...
 0.195 ( 0.004 ms): ls/47325 open(filename: 0x7fffeb9a0d00,       ...
 0.199 ( 0.002 ms): ls/47325 stat(filename: 0x7fffeb9a0d00,       ...
 0.205 ( 0.004 ms): ls/47325 open(filename: 0x7fffeb9a0d00,       ...
 0.211 ( 0.004 ms): ls/47325 stat(filename: 0x7fffeb9a0d00,       ...
 0.220 ( 0.007 ms): ls/47325 open(filename: 0x7f312599e8ff,       ...
 ...
 ...

As shown above, the -f option really works now.
Signed-off-by: NYunlong Song <yunlong.song@huawei.com>
Tested-by: NArnaldo Carvalho de Melo <acme@redhat.com>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/r/1427982439-27388-10-git-send-email-yunlong.song@huawei.comSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

 commit e596663e
 Author: Arnaldo Carvalho de Melo <acme@redhat.com>
 Date:   Fri Feb 13 13:22:21 2015 -0300

    perf trace: Handle multiple threads better wrt syscalls being intermixed

Introduced a bug where it considered the number of bytes output directly
to the output file when formatting the syscall entry buffer that is
stored to be finally printed at syscall exit, ending up leaving garbage
at the start of syscalls that appeared while another syscall was being
processed, in another thread. Fix it.

Example of garbage in the output before this patch:

 4280.102 (  0.000 ms): lsmd/763  ... [continued]: select()) = 0 Timeout
 4280.107 (275.250 ms): tuned/852 select(tvp: 0x7f41f7ffde50        ) ...
 4280.109 (  0.002 ms): lsmd/763 Xl��                                ) = -10
 4639.197 (  0.000 ms): systemd-journa/542  ... [continued]: epoll_wait()) = 1
 4639.202 (359.088 ms): lsmd/763 select(n: 6, inp: 0x7ffff21daad0, tvp: 0x7ffff21daac0) ...
 4639.207 (  0.005 ms): systemd-journa/542 Hn��                      ) = 106
 4639.221 (  0.002 ms): systemd-journa/542 uname(name: 0x7ffdbaed8e00) = 0
 4639.271 (  0.008 ms): systemd-journa/542 ftruncate(fd: 11</run/log/journal/60cd52417cf440a4a80107518bbd3c20/system.journal>, length: 50331648) = 0

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-9ckfe8mvsedgkg6y80gz1ul8@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

Currently the code skips the first field with the expectation that it is 'nr'.
But older kernels do not have the 'nr' field:

    field:int nr;   offset:8;   size:4; signed:1;

Change perf-trace to drop the field if it exists after parsing the format file.

This fixes the off-by-one problem with older kernels (e.g., RHEL6). e.g,
perf-trace shows this for write:

  1.515 ( 0.006 ms): dd/4245 write(buf: 2</dev/pts/0>, count: 140733837536224       ) = 26

where 2 is really the fd, the huge number is really the buf address, etc.  With
this patch you get the more appropriate:

  1.813 ( 0.003 ms): dd/6330 write(fd: 2</dev/pts/0>, buf: 0x7fff22fc81f0, count: 25) = 25
Based-on-a-patch-by: NDavid Ahern <dsahern@gmail.com>
Acked-by: NDavid Ahern <dsahern@gmail.com>
Cc: Adrian Hunter <adrian.hunter@intel.com>
Cc: Borislav Petkov <bp@suse.de>
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-gvpdave4u2yq2jnzbcdznpvf@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

The intent of the -s/--summary-only option is to just show a summary of
the system calls and statistics without any of the individual events.
Commit e596663e broke that by showing the interrupted lines:

perf trace -i perf.data -s
...
     0.741 ( 0.000 ms): sleep/31316 fstat(fd: 4, statbuf: 0x7ffc75ceb830                                  ) ...
     0.744 ( 0.000 ms): sleep/31316 mmap(len: 100244, prot: READ, flags: PRIVATE, fd: 4                   ) ...
     0.747 ( 0.000 ms): perf/31315 write(fd: 3, buf: 0x7d4bb0, count: 8                                  ) ...
...

Fix by checking for the summary only option.
Signed-off-by: NDavid Ahern <dsahern@gmail.com>
Link: http://lkml.kernel.org/r/1426789383-19023-1-git-send-email-dsahern@gmail.comSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

The bash completion does not support listing subsubcommands for 'perf
trace <TAB>', so fix it.

Example:

Before this patch:

 $ perf trace <TAB>
 $

As shown above, the subsubcommands of perf trace does not come out.

After this patch:

 $ perf trace <TAB>
 record

As shown above, the subsubcommands of perf trace can come out now.
Signed-off-by: NYunlong Song <yunlong.song@huawei.com>
Tested-by: NArnaldo Carvalho de Melo <acme@redhat.com>
Cc: Paul Mackerras <paulus@samba.org>
Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Wang Nan <wangnan0@huawei.com>
Link: http://lkml.kernel.org/r/1426685758-25488-13-git-send-email-yunlong.song@huawei.comSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

By keeping pointers to machines, evlist and tool in ordered_events.

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-0c6huyaf59mqtm2ek9pmposl@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

We need to do that to stop accumulating entries in the dead_threads
linked list, i.e. we were keeping references to threads in struct hists
that continue to exist even after a thread exited and was removed from
the machine threads rbtree.

We still keep the dead_threads list, but just for debugging, allowing us
to iterate at any given point over the threads that still are referenced
by things like struct hist_entry.

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-3ejvfyed0r7ue61dkurzjux4@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

On Sparc64 perf-trace is failing in many spots due to extended load
instructions being used on misaligned accesses.

(gdb) run trace ls
Starting program: /tmp/perf/perf trace ls
[Thread debugging using libthread_db enabled]
Detaching after fork from child process 169460.

<ls output removed>

Program received signal SIGBUS, Bus error.
0x000000000014f4dc in tp_field__u64 (field=0x4cc700, sample=0x7feffffa098) at builtin-trace.c:61
warning: Source file is more recent than executable.
61      TP_UINT_FIELD(64);

(gdb) bt
 0  0x000000000014f4dc in tp_field__u64 (field=0x4cc700, sample=0x7feffffa098) at builtin-trace.c:61
 1  0x0000000000156ad4 in trace__sys_exit (trace=0x7feffffc268, evsel=0x4cc580, event=0xfffffc0104912000,
    sample=0x7feffffa098) at builtin-trace.c:1701
 2  0x0000000000158c14 in trace__run (trace=0x7feffffc268, argc=1, argv=0x7fefffff360) at builtin-trace.c:2160
 3  0x000000000015b78c in cmd_trace (argc=1, argv=0x7fefffff360, prefix=0x0) at builtin-trace.c:2609
 4  0x0000000000107d94 in run_builtin (p=0x4549c8, argc=2, argv=0x7fefffff360) at perf.c:341
 5  0x0000000000108140 in handle_internal_command (argc=2, argv=0x7fefffff360) at perf.c:400
 6  0x0000000000108308 in run_argv (argcp=0x7feffffef2c, argv=0x7feffffef20) at perf.c:444
 7  0x0000000000108728 in main (argc=2, argv=0x7fefffff360) at perf.c:559

(gdb) p *sample
$1 = {ip = 4391276, pid = 169472, tid = 169472, time = 6303014583281250, addr = 0, id = 72082,
  stream_id = 18446744073709551615, period = 1, weight = 0, transaction = 0, cpu = 73, raw_size = 36,
  data_src = 84410401, flags = 0, insn_len = 0, raw_data = 0xfffffc010491203c, callchain = 0x0,
  branch_stack = 0x0, user_regs = {abi = 0, mask = 0, regs = 0x0, cache_regs = 0x7feffffa098, cache_mask = 0},
  intr_regs = {abi = 0, mask = 0, regs = 0x0, cache_regs = 0x7feffffa098, cache_mask = 0}, user_stack = {
    offset = 0, size = 0, data = 0x0}, read = {time_enabled = 0, time_running = 0, {group = {nr = 0,
        values = 0x0}, one = {value = 0, id = 0}}}}
(gdb) p *field
$2 = {offset = 16, {integer = 0x14f4a8 <tp_field__u64>, pointer = 0x14f4a8 <tp_field__u64>}}

sample->raw_data is guaranteed to not be 8-byte aligned because it is preceded
by the size as a u3. So accessing raw data with an extended load instruction causes
the SIGBUS. Resolve by using memcpy to a temporary variable of appropriate size.
Signed-off-by: NDavid Ahern <david.ahern@oracle.com>
Cc: Peter Zijlstra <peterz@infradead.org>
Link: http://lkml.kernel.org/r/1424376022-140608-1-git-send-email-david.ahern@oracle.comSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

  [root@ssdandy ~]# perf trace --filter-pids 16348
     0.000 ( 0.000 ms): tuned/1027  ... [continued]: select()) = 0 Timeout
   793.770 ( 0.000 ms): lsmd/895  ... [continued]: select()) = 0 Timeout
   793.775 (793.724 ms): tuned/1027 select(tvp: 0x7f7655556e50) ...
  perf: Segmentation fault
  Obtained 15 stack frames.
  perf(dump_stack+0x2e) [0x4ed330]
  perf(sighandler_dump_stack+0x2e) [0x4ed40f]
  /lib64/libc.so.6(+0x35640) [0x7fa2d5b69640]
  perf() [0x4c2d35]
  perf(machine__findnew_thread+0x39) [0x4c2ed6]
  perf() [0x454a4d]
  perf() [0x455f87]
  perf() [0x456556]
  perf(cmd_trace+0xa7e) [0x4580af]
  perf() [0x4867bd]
  perf() [0x486a1c]
  perf() [0x486b68]
  perf(main+0x23b) [0x486ec9]
  /lib64/libc.so.6(__libc_start_main+0xf5) [0x7fa2d5b55af5]
  perf() [0x41bd91]
[  root@ssdandy ~]#

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-v38cbxcnm2yf5qn9u4y4n9ab@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

Because we need to use ordered_events in some cases, so we will need to
first have them in a queue, order that queue, and then process the
event.

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: Mike Galbraith <efault@gmx.de>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-cmkw9zgoh0z4r218957ftp1a@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

When tracing in X we get event loops due to the tracing activity, i.e.
updates to a gnome-terminal that generate syscalls for X.org, etc.

To get a more useful view of what is happening, syscall wise, system
wide, we need to filter those, like in:

 # ps ax|egrep '981|2296|1519' | grep -v egrep
   981 tty1 Ss+ 5:40 /usr/bin/Xorg :0 -background none ...
  1519 ?    Sl  2:22 /usr/bin/gnome-shell
  2296 ?    Sl  4:16 /usr/libexec/gnome-terminal-server
 #

 # trace -e write --filter-pids 981,2296,1519
    0.385 ( 0.021 ms): goa-daemon/2061 write(fd: 1</dev/null>, buf: 0x7fbeb017b000, count: 136) = 136
    0.922 ( 0.014 ms): goa-daemon/2061 write(fd: 1</dev/null>, buf: 0x7fbeb017b000, count: 140) = 140
 5006.525 ( 0.029 ms): goa-daemon/2061 write(fd: 1</dev/null>, buf: 0x7fbeb017b000, count: 136) = 136
 5007.235 ( 0.023 ms): goa-daemon/2061 write(fd: 1</dev/null>, buf: 0x7fbeb017b000, count: 140) = 140
 5177.646 ( 0.018 ms): rtkit-daemon/782 write(fd: 5<anon_inode:[eventfd]>, buf: 0x7f7eea70be88, count: 8) = 8
 8314.497 ( 0.004 ms): gsd-locate-poi/2084 write(fd: 5<anon_inode:[eventfd]>, buf: 0x7fffe96af7b0, count: 8) = 8
 8314.518 ( 0.002 ms): gsd-locate-poi/2084 write(fd: 5<anon_inode:[eventfd]>, buf: 0x7fffe96af0e0, count: 8) = 8
 ^C#

When this option is used the tracer pid is also filtered.

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: Mike Galbraith <efault@gmx.de>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-f5qmiyy7c0uxdm21ncatpeek@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

To avoid tracing the tracer.

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: Mike Galbraith <efault@gmx.de>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-shmwd1khzpaobr3i0j1ygapg@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

When printing just events, i.e. '--no-sys --ev some:events' it makes no
sense to waste screen space.

Before:

 # trace --no-sys --ev probe:*
 84481.704 (         ): probe:vfs_getname:(ffffffff811ed023) pathname="/etc/services")
 84481.892 (         ): probe:vfs_getname:(ffffffff811ed023) pathname="/etc/services")
 84482.230 (         ): probe:vfs_getname:(ffffffff811ed023) pathname="/etc/resolv.conf")
 84482.481 (         ): probe:vfs_getname:(ffffffff811ed023) pathname="/etc/hosts")
 85097.725 (         ): probe:vfs_getname:(ffffffff811ed023) pathname="/root"
 #

After:

 # trace --no-sys --ev probe:*
 0.000 probe:vfs_getname:(ffffffff811ed023) pathname="/root")
 1.711 probe:vfs_getname:(ffffffff811ed023) pathname="/etc/localtime")
 2.103 probe:vfs_getname:(ffffffff811ed023) pathname="/etc/localtime")
^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: Mike Galbraith <efault@gmx.de>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-jhryxgnam8zecq0q0wsy6pyb@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

I.e. support tracing just tracepoints, without strace like
raw_syscalls:*.

[acme@ssdandy linux]$ trace --no-sys --ev sched:*exec,sched:*switch,sched:*exit usleep 1
  0.048 (     ): sched:sched_process_exec:filename=/usr/bin/usleep pid=27298 old_pid=27298)
  0.369 (     ): sched:sched_switch:usleep:27298 [120] S ==> swapper/5:0 [120])
  0.452 (     ): sched:sched_process_exit:comm=usleep pid=27298 prio=120)
[acme@ssdandy linux]$

TODO: remove that (...) thing when --no-syscalls is specified.

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: Mike Galbraith <efault@gmx.de>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-vn0hsixsbhm31b2rpj97r96k@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

Basically adopting 'perf record' --event command line argument syntax:

 # trace -e \!mprotect,mmap,munmap,open,close,read,fstat,access,arch_prctl --event sched:*switch,sched:*exec,sched:*exit usleep 1
  0.048 (        ): sched:sched_process_exec:filename=/bin/usleep pid=24732 old_pid=24732)
  0.078 (0.002 ms): usleep/24732 brk(                          ) = 0x78f000
  0.430 (0.002 ms): usleep/24732 brk(                          ) = 0x78f000
  0.434 (0.003 ms): usleep/24732 brk(brk: 0x7b0000             ) = 0x7b0000
  0.438 (0.001 ms): usleep/24732 brk(                          ) = 0x7b0000
  0.460 (0.004 ms): usleep/24732 nanosleep(rqtp: 0x7ffff3696a40) ...
  0.460 (        ): sched:sched_switch:prev_comm=usleep prev_pid=24732 prev_prio=120 prev_state=S ==> next_comm=swapper/1 next_pid=0 next_prio=120)
  0.515 (0.058 ms): usleep/24732  ... [continued]: nanosleep()) = 0
  0.520 (0.000 ms): usleep/24732 exit_group(
  0.550 (        ): sched:sched_process_exit:comm=usleep pid=24732 prio=120)
 #

Next steps, probably in this order:

1) Use ordered_events code, the logic in trace needs the events to be
   time ordered when needed, i.e. when multiple CPUs are involved.

2) Callchains!

3) Automatically account for interruptions when saying how long things
   took.

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: Mike Galbraith <efault@gmx.de>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-gpst8mph575yb4wgf91qibyb@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

 $ trace time taskset -c 0 usleep 1
   0.845 ( 0.021 ms): time/16722 wait4(upid: 4294967295, stat_addr: 0x7fff17f443d4, ru: 0x7fff17f44438 ) ...
   0.865 ( 0.008 ms): time/16723 execve(arg0: 140733595272004, arg1: 140733595272720, arg2: 140733595272768, arg3: 139755107218496, arg4: 7307199665339051828, arg5: 3) = -2
   2.395 ( 1.523 ms): taskset/16723 execve(arg0: 140733595272013, arg1: 140733595272720, arg2: 140733595272768, arg3: 139755107218496, arg4: 7307199665339051828, arg5: 3) = 0
   2.411 ( 0.002 ms): taskset/16723 brk(                                                                  ) = 0x1915000
   3.300 ( 0.058 ms): usleep/16723 nanosleep(rqtp: 0x7ffff4ada190                                        ) = 0
 <SNIP>
   3.305 ( 0.000 ms): usleep/16723 exit_group(
   3.363 ( 2.539 ms): time/16722  ... [continued]: wait4()) = 16723
   3.366 ( 0.001 ms): time/16722 rt_sigaction(sig: INT, act: 0x7fff17f44160, oact: 0x7fff17f44200, sigsetsize: 8) = 0

We we're not seeing this line:

  0.845 ( 0.021 ms): time/16722 wait4(upid: 4294967295, stat_addr: 0x7fff17f443d4, ru: 0x7fff17f44438 ) ...

just the one when it finishes:

  3.363 ( 2.539 ms): time/16722  ... [continued]: wait4()) = 16723

Still some issues left till we move to ordered_samples when multiple
CPUs/threads are involved...

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-zq9x30a1ky3djqewqn2v3ja3@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

The default for 'trace workload' is to set perf_event_attr.inherit to 1,
i.e. to make it equivalent to 'strace -f workload', so we were ending
with syscalls for multiple processes mixed up, fix it:

Before:

  [root@ssdandy ~]# trace -e brk time usleep 1
     0.071 ( 0.002 ms): brk(              ) = 0x100e000
     0.802 ( 0.001 ms): brk(              ) = 0x1d99000
     1.132 ( 0.003 ms): brk(              ) = 0x1d99000
     1.136 ( 0.003 ms): brk(brk: 0x1dba000) = 0x1dba000
     1.140 ( 0.001 ms): brk(              ) = 0x1dba000
  0.00user 0.00system 0:00.00elapsed 63%CPU (0avgtext+0avgdata 528maxresident)k
  0inputs+0outputs (0major+181minor)pagefaults 0swaps
  [root@ssdandy ~]#

After:

  [root@ssdandy ~]# trace -f -e brk time usleep 1
     0.072 ( 0.002 ms): time/26308 brk(               ) = 0x1e6e000
     0.860 ( 0.001 ms): usleep/26309 brk(             ) = 0xb91000
     1.193 ( 0.003 ms): usleep/26309 brk(             ) = 0xb91000
     1.197 ( 0.003 ms): usleep/26309 brk(brk: 0xbb2000) = 0xbb2000
     1.201 ( 0.001 ms): usleep/26309 brk(             ) = 0xbb2000
  0.00user 0.00system 0:00.00elapsed 0%CPU (0avgtext+0avgdata 524maxresident)k
  0inputs+0outputs (0major+180minor)pagefaults 0swaps
  [root@ssdandy ~]#

BTW: to achieve the 'strace workload' behaviour, i.e. without a explicit
'-f', one has to use --no-inherit.

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>
echo Link: http://lkml.kernel.org/n/tip-`ranpwd -l 24`@git.kernel.org
Link: http://lkml.kernel.org/n/tip-2wu2d5n65msxoq1i7vtcaft2@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

As they will have perf_event_attr.enable_on_exec set, starting as soon
as we exec() the workload.

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: Mike Galbraith <efault@gmx.de>
Cc: Namhyung Kim <namhyung@kernel.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Link: http://lkml.kernel.org/n/tip-vmj3f6o3vxrg7mrdipts09li@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

There will be other cases where not just a tracepoint event is being
opened below the debugfs mountpoint, but it is rather common, so provide
one helper for that.

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-q6e6zct49ql6nbcw8kkg0lbj@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>

In that case the only failure possible is not to have enough memory, as
we are just creating the evsels, not trying to access any system
facility such as debugfs files or syscalls.

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-7k6asvfhiwiu2zs6o2oknchk@git.kernel.orgSigned-off-by: NArnaldo Carvalho de Melo <acme@redhat.com>