perf probe currently errors out if there are any tail calls to probed
functions:
[root@rhel71be]# perf probe do_fork
Failed to find probe point in any functions.
Error: Failed to add events.
Fix this by teaching perf to ignore tail calls.
Without patch:
[root@rhel71be perf]# ./perf probe -v do_fork
probe-definition(0): do_fork symbol:do_fork file:(null) line:0 offset:0
return:0 lazy:(null)
0 arguments
Looking at the vmlinux_path (7 entries long)
symsrc__init: build id mismatch for /boot/vmlinux.
Using /usr/lib/debug/lib/modules/3.10.0-201.el7.ppc64/vmlinux for symbols
Open Debuginfo file:
/usr/lib/debug/lib/modules/3.10.0-201.el7.ppc64/vmlinux
Try to find probe point from debuginfo.
found inline addr: 0xc0000000000bb9b0
Probe point found: do_fork+0
found inline addr: 0xc0000000000bbe20
Probe point found: kernel_thread+48
found inline addr: 0xc0000000000bbe5c
Probe point found: sys_fork+28
found inline addr: 0xc0000000000bbfac
Probe point found: sys_vfork+44
found inline addr: 0xc0000000000bc27c
Failed to find probe point in any functions.
An error occurred in debuginfo analysis (-2).
Error: Failed to add events. Reason: No such file or directory (Code: -2)
With patch:
[root@rhel71be perf]# ./perf probe -v do_fork
probe-definition(0): do_fork symbol:do_fork file:(null) line:0 offset:0
return:0 lazy:(null)
0 arguments
Looking at the vmlinux_path (7 entries long)
symsrc__init: build id mismatch for /boot/vmlinux.
Using /usr/lib/debug/lib/modules/3.10.0-201.el7.ppc64/vmlinux for symbols
Open Debuginfo file:
/usr/lib/debug/lib/modules/3.10.0-201.el7.ppc64/vmlinux
Try to find probe point from debuginfo.
found inline addr: 0xc0000000000bb9b0
Probe point found: do_fork+0
found inline addr: 0xc0000000000bbe20
Probe point found: kernel_thread+48
found inline addr: 0xc0000000000bbe5c
Probe point found: sys_fork+28
found inline addr: 0xc0000000000bbfac
Probe point found: sys_vfork+44
found inline addr: 0xc0000000000bc27c
Ignoring tail call from SyS_clone
Found 4 probe_trace_events.
Opening /sys/kernel/debug/tracing/kprobe_events write=1
No kprobe blacklist support, ignored
Added new events:
Writing event: p:probe/do_fork _text+768432
Failed to write event: Invalid argument
Error: Failed to add events. Reason: Invalid argument (Code: -22)
[Ignore the error about failure to write event - this kernel is missing
a patch to resolve _text properly]
The reason to ignore tail calls is that the address does not belong to
any function frame. In the example above, the address in SyS_clone is
0xc0000000000bc27c, but looking at the debug-info:
<1><830081>: Abbrev Number: 133 (DW_TAG_subprogram)
<830083> DW_AT_external : 1
<830083> DW_AT_name : (indirect string, offset: 0x3cea3): SyS_clone
<830087> DW_AT_decl_file : 7
<830088> DW_AT_decl_line : 1689
<83008a> DW_AT_prototyped : 1
<83008a> DW_AT_type : <0x8110eb>
<83008e> DW_AT_low_pc : 0xc0000000000bc270
<830096> DW_AT_high_pc : 0xc
<83009e> DW_AT_frame_base : 1 byte block: 9c (DW_OP_call_frame_cfa)
<8300a0> DW_AT_GNU_all_call_sites: 1
<8300a0> DW_AT_sibling : <0x830178>
<snip>
<3><830147>: Abbrev Number: 125 (DW_TAG_GNU_call_site)
<830148> DW_AT_low_pc : 0xc0000000000bc27c
<830150> DW_AT_GNU_tail_call: 1
<830150> DW_AT_abstract_origin: <0x82e7e1>
The frame ends at 0xc0000000000bc27c. I suppose this is why this
particular call is a "tail" call. FWIW, systemtap seems to ignore these
as well and requires users to explicitly place probes at these call
sites if necessary. I print out the caller so that users know.
Signed-off-by: Naveen N. Rao <naveen.n.rao@linux.vnet.ibm.com>
Acked-by: Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>
Link: http://lkml.kernel.org/r/1430394151-15928-1-git-send-email-naveen.n.rao@linux.vnet.ibm.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
When introducing reference counting for struct thread instances I forgot
to remove the synthetic threads from the machine's rbtree so that it
then the threads would have just one reference and thus the
thread__put() replacing the thread__delete() really turns into a
thread__delete() (thread->refcnt == 1 at thread__put() time) and thus
drop the thread->mg refcount, as expected by the this test.
Fix it by calling machine__remove_thread() (the counterpart of
machine__findnew_thread()) on all the synthetic threads after the
checks that involves the rbtree were done.
Before:
# perf test -v mg
30: Test thread mg sharing :
--- start ---
test child forked, pid 26995
FAILED tests/thread-mg-share.c:68 wrong refcnt (4 != 3)
test child finished with -1
---- end ----
Test thread mg sharing: FAILED!
#
After:
# perf test mg
30: Test thread mg sharing: Ok
#
Fixes: b91fc39f4a ("perf machine: Protect the machine->threads with a rwlock")
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-uoqq0fjei90ohhhcboz6ay33@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
To help understand the failure.
[acme@zoo linux]$ perf test -v 30
30: Test thread mg sharing :
--- start ---
test child forked, pid 12275
FAILED tests/thread-mg-share.c:68 wrong refcnt (4 != 3)
test child finished with -1
---- end ----
Test thread mg sharing: FAILED!
[acme@zoo linux]$
This is under investigation, the thread__delete() calls were replaced
with thread__put(), and those cause mismatches because now we need to be
more judicious with the thread lifetime management.
I.e. previously the thread__delete() would drop the map_group refcount,
but now since thread__put doesn't call thread__delete() necessarily.
because we have other refcount holders, the map_group refcount will not
be as we expected when this test was implemented.
Will be fixed soon...
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-9y8e3f7ukzco5loxvnlitpfq@git.kernel.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
WEXITSTATUS consists of the least significant 8 bits of the status
argument, so we should convert the value to signed char if we have valid
negative exit codes. And the return value of test->func() contains
negative values:
enum {
TEST_OK = 0,
TEST_FAIL = -1,
TEST_SKIP = -2,
};
Before this patch:
$ perf test -v 1
...
test child finished with 254
---- end ----
vmlinux symtab matches kallsyms: FAILED!
After this patch:
$ perf test -v 1
...
test child finished with -2
---- end ----
vmlinux symtab matches kallsyms: Skip
Signed-off-by: He Kuang <hekuang@huawei.com>
Acked-by: 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-1-git-send-email-hekuang@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Indicate to check variable location range in error message when we got
failed to find the variable.
Before this patch:
$ perf probe --add 'generic_perform_write+118 bytes'
Failed to find the location of bytes at this address.
Perhaps, it has been optimized out.
Error: Failed to add events.
After this patch:
$ perf probe --add 'generic_perform_write+118 bytes'
Failed to find the location of the 'bytes' variable at this address.
Perhaps it has been optimized out.
Use -V with the --range option to show 'bytes' location range.
Error: Failed to add events.
Signed-off-by: He Kuang <hekuang@huawei.com>
Acked-by: Masami Hiramatsu <masami.hiramatsu.pt@hitachi.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/1431336304-16863-3-git-send-email-hekuang@huawei.com
[ Improve the error message based on lkml thread ]
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
It is not easy for users to get the accurate byte offset or the line
number where a local variable can be probed.
With '--range' option, local variables in the scope of the probe point
are showed with a byte offset range, and can be added according to this
range information.
For example, there are some variables in the function
generic_perform_write():
<generic_perform_write@mm/filemap.c:0>
0 ssize_t generic_perform_write(struct file *file,
1 struct iov_iter *i, loff_t pos)
2 {
3 struct address_space *mapping = file->f_mapping;
4 const struct address_space_operations *a_ops = mapping->a_ops;
...
42 status = a_ops->write_begin(file, mapping, pos, bytes, flags,
&page, &fsdata);
44 if (unlikely(status < 0))
But we fail when we try to probe the variable 'a_ops' at line 42 or 44.
$ perf probe --add 'generic_perform_write:42 a_ops'
Failed to find the location of a_ops at this address.
Perhaps, it has been optimized out.
This is because the source code do not match the assembly, so a variable
may not be available in the source code line where it appears.
After this patch, we can lookup the accurate byte offset range of a
variable, 'INV' indicates that this variable is not valid at the given
point, but available in the scope:
$ perf probe --vars 'generic_perform_write:42' --range
Available variables at generic_perform_write:42
@<generic_perform_write+141>
[INV] ssize_t written @<generic_perform_write+[324-331]>
[INV] struct address_space_operations* a_ops @<generic_perform_write+[55-61,170-176,223-246]>
[VAL] (unknown_type) fsdata @<generic_perform_write+[70-307,346-411]>
[VAL] loff_t pos @<generic_perform_write+[0-286,286-336,346-411]>
[VAL] long int status @<generic_perform_write+[83-342,346-411]>
[VAL] long unsigned int bytes @<generic_perform_write+[122-311,320-338,346-403,403-411]>
[VAL] struct address_space* mapping @<generic_perform_write+[35-344,346-411]>
[VAL] struct iov_iter* i @<generic_perform_write+[0-340,346-411]>
[VAL] struct page* page @<generic_perform_write+[70-307,346-411]>
Then it is more clear for us to add a probe with this variable:
$ perf probe --add 'generic_perform_write+170 a_ops'
Added new event:
probe:generic_perform_write (on generic_perform_write+170 with a_ops)
Signed-off-by: He Kuang <hekuang@huawei.com>
Acked-by: Masami Hiramatsu <masami.hiramatsu.pt@hitachi.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/1431336304-16863-2-git-send-email-hekuang@huawei.com
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Pull perf/core improvements and fixes from Arnaldo Carvalho de Melo:
User visible changes:
- 'perf probe' improvements: (Masami Hiramatsu)
- Support glob wildcards for function name
- Support $params special probe argument: Collect all function arguments
- Make --line checks validate C-style function name.
- Add --no-inlines option to avoid searching inline functions
- Introduce new 'perf bench futex' benchmark: 'wake-parallel', to
measure parallel waker threads generating contention for kernel
locks (hb->lock). (Davidlohr Bueso)
Bug fixes:
- Improve 'perf top' to survive much longer on high core count machines,
more work needed to refcount more data structures besides 'struct thread'
and fix more races. (Arnaldo Carvalho de Melo)
Infrastructure changes:
- Move barrier.h mb/rmb/wmb API from tools/perf/ to kernel like tools/arch/
hierarchy. (Arnaldo Carvalho de Melo)
- Borrow atomic.h from the kernel, initially the x86 implementations
with a fallback to gcc intrinsics for the other arches, all the kernel
like framework in place for doing arch specific implementations,
preferrably cloning what is in the kernel to the greater extent
possible. (Arnaldo Carvalho de Melo)
- Protect the 'struct thread' lifetime with a reference counter,
and protect data structures that contains its instances with
a mutex. (Arnaldo Carvalho de Melo
- Disable libdw DWARF unwind when built with NO_DWARF (Naveen N. Rao)
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Signed-off-by: Ingo Molnar <mingo@kernel.org>
Support glob wildcards for function name when adding new probes. This
will allow us to build caches of function-entry level information with
$params.
e.g.
----
# perf probe --no-inlines --add 'kmalloc* $params'
Added new events:
probe:kmalloc_slab (on kmalloc* with $params)
probe:kmalloc_large_node (on kmalloc* with $params)
probe:kmalloc_order_trace (on kmalloc* with $params)
You can now use it in all perf tools, such as:
perf record -e probe:kmalloc_order_trace -aR sleep 1
# perf probe --list
probe:kmalloc_large_node (on kmalloc_large_node@mm/slub.c with size flags node)
probe:kmalloc_order_trace (on kmalloc_order_trace@mm/slub.c with size flags order)
probe:kmalloc_slab (on kmalloc_slab@mm/slab_common.c with size flags)
----
Signed-off-by: Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Ananth N Mavinakayanahalli <ananth@in.ibm.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Hemant Kumar <hemant@linux.vnet.ibm.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/20150508010335.24812.19972.stgit@localhost.localdomain
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
The futex-wake benchmark only measures wakeups done within a single
process. While this has value in its own, it does not really generate
any hb->lock contention.
A new benchmark 'wake-parallel' is added, by extending the futex-wake
code such that we can measure parallel waker threads. The program output
shows the avg per-thread latency in order to complete its share of
wakeups:
Run summary [PID 13474]: blocking on 512 threads (at [private] futex 0xa88668), 8 threads waking up 64 at a time.
[Run 1]: Avg per-thread latency (waking 64/512 threads) in 0.6230 ms (+-15.31%)
[Run 2]: Avg per-thread latency (waking 64/512 threads) in 0.5175 ms (+-29.95%)
[Run 3]: Avg per-thread latency (waking 64/512 threads) in 0.7578 ms (+-18.03%)
[Run 4]: Avg per-thread latency (waking 64/512 threads) in 0.8944 ms (+-12.54%)
[Run 5]: Avg per-thread latency (waking 64/512 threads) in 1.1204 ms (+-23.85%)
Avg per-thread latency (waking 64/512 threads) in 0.7826 ms (+-9.91%)
Naturally, different combinations of numbers of blocking and waker
threads will exhibit different information.
Signed-off-by: Davidlohr Bueso <dbueso@suse.de>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Davidlohr Bueso <dbueso@suse.de>
Link: http://lkml.kernel.org/r/1431110280-20231-1-git-send-email-dave@stgolabs.net
Signed-off-by: Arnaldo 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: David 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.org
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Fix to return 0 when positive value returned from probe command.
At least --vars can returns a positive value if it found a point.
----
# perf probe --vars vfs_read && echo succeeded! || echo failed!
Available variables at vfs_read
@<vfs_read+0>
char* buf
loff_t* pos
size_t count
struct file* file
failed!
----
This fixes above problem.
----
# perf probe --vars vfs_read && echo succeeded! || echo failed!
Available variables at vfs_read
@<vfs_read+0>
char* buf
loff_t* pos
size_t count
struct file* file
succeeded!
----
Signed-off-by: Masami Hiramatsu <masami.hiramatsu.pt@hitachi.com>
Tested-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Cc: Ananth N Mavinakayanahalli <ananth@in.ibm.com>
Cc: David Ahern <dsahern@gmail.com>
Cc: Hemant Kumar <hemant@linux.vnet.ibm.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/20150506124645.4961.56973.stgit@localhost.localdomain
Signed-off-by: Arnaldo Carvalho de Melo <acme@redhat.com>
Stephane asked about PERF_COUNT_SW_CPU_MIGRATIONS and I realized it
was borken:
> The problem is that the task isn't actually scheduled while its being
> migrated (obviously), and if its not scheduled, the counters aren't
> scheduled either, so there's no observing of the fact.
>
> A further problem with migrations is that many migrations happen from
> softirq context, which is nested inside the 'random' task context of
> whoemever happens to run at that time, similarly for the wakeup
> migrations triggered from (soft)irq context. All those end up being
> accounted in the task that's currently running, eg. your 'ls'.
The below cures this by marking a task as migrated and accounting it
on the subsequent sched_in().
Signed-off-by: Peter Zijlstra (Intel) <peterz@infradead.org>
Cc: Andrew Morton <akpm@linux-foundation.org>
Cc: Borislav Petkov <bp@alien8.de>
Cc: H. Peter Anvin <hpa@zytor.com>
Cc: Linus Torvalds <torvalds@linux-foundation.org>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Stephane Eranian <eranian@google.com>
Cc: Thomas Gleixner <tglx@linutronix.de>
Signed-off-by: Ingo Molnar <mingo@kernel.org>
iTLB-load-misses and LLC-load-misses count incorrectly on SLM.
There is no ITLB.MISSES support on SLM. Event PAGE_WALKS.I_SIDE_WALK
should be used to count iTLB-load-misses. This event counts when an
instruction (I) page walk is completed or started. Since a page walk
implies a TLB miss, the number of TLB misses can be counted by counting
the number of pagewalks.
DMND_DATA_RD counts both demand and DCU prefetch data reads. However,
LLC-load-misses should only count demand reads. There is no way to not
include prefetches with a single counter on SLM. So the LLC-load-misses
support should be removed on SLM.
Signed-off-by: Kan Liang <kan.liang@intel.com>
Signed-off-by: Peter Zijlstra (Intel) <peterz@infradead.org>
Cc: Borislav Petkov <bp@alien8.de>
Cc: H. Peter Anvin <hpa@zytor.com>
Cc: Thomas Gleixner <tglx@linutronix.de>
Link: http://lkml.kernel.org/r/1429608881-5055-1-git-send-email-kan.liang@intel.com
Signed-off-by: Ingo Molnar <mingo@kernel.org>
