Hi Arnaldo,
Here is the v3 series of bugfix patches for perf-probe.
I've rewriten the patch description of 2/3 (no code changed)
and added a comment on the 3/3 for reproductivity.
This series fixes below bugs;
- --list shows the list of probes in stderr.
(It is refined from https://lkml.org/lkml/2015/5/30/34)
- return success even if no probe is added.
- usage message is not shown if the last event is skipped.
BTW, this series still include 1/3, since I couldn't find it
in the latest(published) perf/core. If you've already merged
it on your local tree, please skip it.
Thank you,
---
Masami Hiramatsu (3):
[BUGFIX] perf probe: List probes in stdout
[BUGFIX] perf probe: Fix to return error if no-probe is added
[BUGFIX] perf probe: Show usage even if the last event is skipped
tools/perf/util/probe-event.c | 187 ++++++++++++++++++++++++++---------------
1 file changed, 118 insertions(+), 69 deletions(-)
--
Masami HIRAMATSU
Linux Technology Research Center, System Productivity Research Dept.
Center for Technology Innovation - Systems Engineering
Hitachi, Ltd., Research & Development Group
E-mail: [email protected]
Since commit 5e17b28f1e24 ("perf probe: Add --quiet option to
suppress output result message") have replaced printf with pr_info,
perf probe -l outputs its result in stderr. However, that is not
what the commit expected.
e.g.
-----
# perf probe -l > /dev/null
probe:vfs_read (on vfs_read@ksrc/linux-3/fs/read_write.c)
-----
With this fix,
-----
# perf probe -l > list
# cat list
probe:vfs_read (on vfs_read@ksrc/linux-3/fs/read_write.c)
-----
Of course, --quiet(-q) still works on --add/--del.
-----
# perf probe -q vfs_write
# perf probe -l
probe:vfs_read (on vfs_read@ksrc/linux-3/fs/read_write.c)
probe:vfs_write (on vfs_write@ksrc/linux-3/fs/read_write.c)
-----
Signed-off-by: Masami Hiramatsu <[email protected]>
Reported-by: Naohiro Aota <[email protected]>
---
Changes in v2:
- Fix to reverse the use_stdio flag at each caller.
---
tools/perf/util/probe-event.c | 49 +++++++++++++++++++++++++++++------------
1 file changed, 35 insertions(+), 14 deletions(-)
diff --git a/tools/perf/util/probe-event.c b/tools/perf/util/probe-event.c
index daa24a2..c4ab588 100644
--- a/tools/perf/util/probe-event.c
+++ b/tools/perf/util/probe-event.c
@@ -2126,9 +2126,9 @@ kprobe_blacklist__find_by_address(struct list_head *blacklist,
return NULL;
}
-/* Show an event */
-static int show_perf_probe_event(struct perf_probe_event *pev,
- const char *module)
+static int perf_probe_event__sprintf(struct perf_probe_event *pev,
+ const char *module,
+ struct strbuf *result)
{
int i, ret;
char buf[128];
@@ -2141,27 +2141,47 @@ static int show_perf_probe_event(struct perf_probe_event *pev,
ret = e_snprintf(buf, 128, "%s:%s", pev->group, pev->event);
if (ret < 0)
- return ret;
+ goto out;
- pr_info(" %-20s (on %s", buf, place);
+ strbuf_addf(result, " %-20s (on %s", buf, place);
if (module)
- pr_info(" in %s", module);
+ strbuf_addf(result, " in %s", module);
if (pev->nargs > 0) {
- pr_info(" with");
+ strbuf_addstr(result, " with");
for (i = 0; i < pev->nargs; i++) {
ret = synthesize_perf_probe_arg(&pev->args[i],
buf, 128);
if (ret < 0)
- break;
- pr_info(" %s", buf);
+ goto out;
+ strbuf_addf(result, " %s", buf);
}
}
- pr_info(")\n");
+ strbuf_addch(result, ')');
+out:
free(place);
return ret;
}
+/* Show an event */
+static int show_perf_probe_event(struct perf_probe_event *pev,
+ const char *module, bool use_stdout)
+{
+ struct strbuf buf = STRBUF_INIT;
+ int ret;
+
+ ret = perf_probe_event__sprintf(pev, module, &buf);
+ if (ret >= 0) {
+ if (use_stdout)
+ printf("%s\n", buf.buf);
+ else
+ pr_info("%s\n", buf.buf);
+ }
+ strbuf_release(&buf);
+
+ return ret;
+}
+
static bool filter_probe_trace_event(struct probe_trace_event *tev,
struct strfilter *filter)
{
@@ -2200,9 +2220,10 @@ static int __show_perf_probe_events(int fd, bool is_kprobe,
goto next;
ret = convert_to_perf_probe_event(&tev, &pev,
is_kprobe);
- if (ret >= 0)
- ret = show_perf_probe_event(&pev,
- tev.point.module);
+ if (ret < 0)
+ goto next;
+ ret = show_perf_probe_event(&pev, tev.point.module,
+ true);
}
next:
clear_perf_probe_event(&pev);
@@ -2468,7 +2489,7 @@ static int __add_probe_trace_events(struct perf_probe_event *pev,
group = pev->group;
pev->event = tev->event;
pev->group = tev->group;
- show_perf_probe_event(pev, tev->point.module);
+ show_perf_probe_event(pev, tev->point.module, false);
/* Trick here - restore current event/group */
pev->event = (char *)event;
pev->group = (char *)group;
Fix perf probe to return an error if no-probe is added since
the given probe point is on the blacklist.
To fix this problem, this moves blacklist checking right
after finding symbols/probe-points and marks it as skipped.
If all the symbols are skipped, perf-probe returns error as
it fails to find corresponding probe address.
e.g. currently if we give a blacklisted probe is given,
----
# perf probe do_trap && echo 'succeed'
Added new event:
Warning: Skipped probing on blacklisted function: sync_regs
succeed
----
No! it must be failed. With this patch, it correctly failed.
----
# perf probe do_trap && echo 'succeed'
do_trap is blacklisted function, skip it.
Probe point 'do_trap' not found.
Error: Failed to add events.
----
Signed-off-by: Masami Hiramatsu <[email protected]>
---
Changes in v3:
- Rewrite the comment and ensure what was fixed.
---
tools/perf/util/probe-event.c | 113 ++++++++++++++++++++++++++---------------
1 file changed, 71 insertions(+), 42 deletions(-)
diff --git a/tools/perf/util/probe-event.c b/tools/perf/util/probe-event.c
index c4ab588..85c8207 100644
--- a/tools/perf/util/probe-event.c
+++ b/tools/perf/util/probe-event.c
@@ -246,6 +246,20 @@ static void clear_probe_trace_events(struct probe_trace_event *tevs, int ntevs)
clear_probe_trace_event(tevs + i);
}
+static bool kprobe_blacklist__listed(unsigned long address);
+static bool kprobe_warn_out_range(const char *symbol, unsigned long address)
+{
+ /* Get the address of _etext for checking non-probable text symbol */
+ if (kernel_get_symbol_address_by_name("_etext", false) < address)
+ pr_warning("%s is out of .text, skip it.\n", symbol);
+ else if (kprobe_blacklist__listed(address))
+ pr_warning("%s is blacklisted function, skip it.\n", symbol);
+ else
+ return false;
+
+ return true;
+}
+
#ifdef HAVE_DWARF_SUPPORT
static int kernel_get_module_dso(const char *module, struct dso **pdso)
@@ -559,7 +573,6 @@ static int post_process_probe_trace_events(struct probe_trace_event *tevs,
bool uprobe)
{
struct ref_reloc_sym *reloc_sym;
- u64 etext_addr;
char *tmp;
int i, skipped = 0;
@@ -575,31 +588,28 @@ static int post_process_probe_trace_events(struct probe_trace_event *tevs,
pr_warning("Relocated base symbol is not found!\n");
return -EINVAL;
}
- /* Get the address of _etext for checking non-probable text symbol */
- etext_addr = kernel_get_symbol_address_by_name("_etext", false);
for (i = 0; i < ntevs; i++) {
- if (tevs[i].point.address && !tevs[i].point.retprobe) {
- /* If we found a wrong one, mark it by NULL symbol */
- if (etext_addr < tevs[i].point.address) {
- pr_warning("%s+%lu is out of .text, skip it.\n",
- tevs[i].point.symbol, tevs[i].point.offset);
- tmp = NULL;
- skipped++;
- } else {
- tmp = strdup(reloc_sym->name);
- if (!tmp)
- return -ENOMEM;
- }
- /* If we have no realname, use symbol for it */
- if (!tevs[i].point.realname)
- tevs[i].point.realname = tevs[i].point.symbol;
- else
- free(tevs[i].point.symbol);
- tevs[i].point.symbol = tmp;
- tevs[i].point.offset = tevs[i].point.address -
- reloc_sym->unrelocated_addr;
+ if (!tevs[i].point.address || tevs[i].point.retprobe)
+ continue;
+ /* If we found a wrong one, mark it by NULL symbol */
+ if (kprobe_warn_out_range(tevs[i].point.symbol,
+ tevs[i].point.address)) {
+ tmp = NULL;
+ skipped++;
+ } else {
+ tmp = strdup(reloc_sym->name);
+ if (!tmp)
+ return -ENOMEM;
}
+ /* If we have no realname, use symbol for it */
+ if (!tevs[i].point.realname)
+ tevs[i].point.realname = tevs[i].point.symbol;
+ else
+ free(tevs[i].point.symbol);
+ tevs[i].point.symbol = tmp;
+ tevs[i].point.offset = tevs[i].point.address -
+ reloc_sym->unrelocated_addr;
}
return skipped;
}
@@ -2126,6 +2136,27 @@ kprobe_blacklist__find_by_address(struct list_head *blacklist,
return NULL;
}
+static LIST_HEAD(kprobe_blacklist);
+
+static void kprobe_blacklist__init(void)
+{
+ if (!list_empty(&kprobe_blacklist))
+ return;
+
+ if (kprobe_blacklist__load(&kprobe_blacklist) < 0)
+ pr_debug("No kprobe blacklist support, ignored\n");
+}
+
+static void kprobe_blacklist__release(void)
+{
+ kprobe_blacklist__delete(&kprobe_blacklist);
+}
+
+static bool kprobe_blacklist__listed(unsigned long address)
+{
+ return !!kprobe_blacklist__find_by_address(&kprobe_blacklist, address);
+}
+
static int perf_probe_event__sprintf(struct perf_probe_event *pev,
const char *module,
struct strbuf *result)
@@ -2409,8 +2440,6 @@ static int __add_probe_trace_events(struct perf_probe_event *pev,
char buf[64];
const char *event, *group;
struct strlist *namelist;
- LIST_HEAD(blacklist);
- struct kprobe_blacklist_node *node;
bool safename;
if (pev->uprobes)
@@ -2430,28 +2459,15 @@ static int __add_probe_trace_events(struct perf_probe_event *pev,
ret = -ENOMEM;
goto close_out;
}
- /* Get kprobe blacklist if exists */
- if (!pev->uprobes) {
- ret = kprobe_blacklist__load(&blacklist);
- if (ret < 0)
- pr_debug("No kprobe blacklist support, ignored\n");
- }
safename = (pev->point.function && !strisglob(pev->point.function));
ret = 0;
pr_info("Added new event%s\n", (ntevs > 1) ? "s:" : ":");
for (i = 0; i < ntevs; i++) {
tev = &tevs[i];
- /* Skip if the symbol is out of .text (marked previously) */
+ /* Skip if the symbol is out of .text or blacklisted */
if (!tev->point.symbol)
continue;
- /* Ensure that the address is NOT blacklisted */
- node = kprobe_blacklist__find_by_address(&blacklist,
- tev->point.address);
- if (node) {
- pr_warning("Warning: Skipped probing on blacklisted function: %s\n", node->symbol);
- continue;
- }
if (pev->event)
event = pev->event;
@@ -2513,7 +2529,6 @@ static int __add_probe_trace_events(struct perf_probe_event *pev,
tev->event);
}
- kprobe_blacklist__delete(&blacklist);
strlist__delete(namelist);
close_out:
close(fd);
@@ -2563,7 +2578,7 @@ static int find_probe_trace_events_from_map(struct perf_probe_event *pev,
struct perf_probe_point *pp = &pev->point;
struct probe_trace_point *tp;
int num_matched_functions;
- int ret, i, j;
+ int ret, i, j, skipped = 0;
map = get_target_map(pev->target, pev->uprobes);
if (!map) {
@@ -2631,7 +2646,12 @@ static int find_probe_trace_events_from_map(struct perf_probe_event *pev,
}
/* Add one probe point */
tp->address = map->unmap_ip(map, sym->start) + pp->offset;
- if (reloc_sym) {
+ /* If we found a wrong one, mark it by NULL symbol */
+ if (!pev->uprobes &&
+ kprobe_warn_out_range(sym->name, tp->address)) {
+ tp->symbol = NULL; /* Skip it */
+ skipped++;
+ } else if (reloc_sym) {
tp->symbol = strdup_or_goto(reloc_sym->name, nomem_out);
tp->offset = tp->address - reloc_sym->addr;
} else {
@@ -2667,6 +2687,10 @@ static int find_probe_trace_events_from_map(struct perf_probe_event *pev,
}
arch__fix_tev_from_maps(pev, tev, map);
}
+ if (ret == skipped) {
+ ret = -ENOENT;
+ goto err_out;
+ }
out:
put_target_map(map, pev->uprobes);
@@ -2737,6 +2761,9 @@ int add_perf_probe_events(struct perf_probe_event *pevs, int npevs)
/* Loop 1: convert all events */
for (i = 0; i < npevs; i++) {
pkgs[i].pev = &pevs[i];
+ /* Init kprobe blacklist if needed */
+ if (!pkgs[i].pev->uprobes)
+ kprobe_blacklist__init();
/* Convert with or without debuginfo */
ret = convert_to_probe_trace_events(pkgs[i].pev,
&pkgs[i].tevs);
@@ -2744,6 +2771,8 @@ int add_perf_probe_events(struct perf_probe_event *pevs, int npevs)
goto end;
pkgs[i].ntevs = ret;
}
+ /* This just release blacklist only if allocated */
+ kprobe_blacklist__release();
/* Loop 2: add all events */
for (i = 0; i < npevs; i++) {
When the last part of converted events are blacklisted or out-of-text,
those are skipped and perf probe doesn't show usage examples.
This fixes it to show the example even if the last part of event list
is skipped.
E.g. without this patch, events are added, but suddenly end;
----
# perf probe vfs_*
vfs_caches_init_early is out of .text, skip it.
vfs_caches_init is out of .text, skip it.
Added new events:
probe:vfs_fallocate (on vfs_*)
probe:vfs_open (on vfs_*)
...
probe:vfs_dentry_acceptable (on vfs_*)
probe:vfs_load_quota_inode (on vfs_*)
#
----
With this fix;
----
# perf probe vfs_*
vfs_caches_init_early is out of .text, skip it.
vfs_caches_init is out of .text, skip it.
Added new events:
probe:vfs_fallocate (on vfs_*)
...
probe:vfs_load_quota_inode (on vfs_*)
You can now use it in all perf tools, such as:
perf record -e probe:vfs_load_quota_inode -aR sleep 1
#
----
Note that this can be reproduced ONLY IF the vfs_caches_init*
is the last part of matched symbol list. I've checked this happens
on "3.19.0-generic #18-Ubuntu" kernel binary.
Signed-off-by: Masami Hiramatsu <[email protected]>
---
tools/perf/util/probe-event.c | 35 +++++++++++++++++------------------
1 file changed, 17 insertions(+), 18 deletions(-)
diff --git a/tools/perf/util/probe-event.c b/tools/perf/util/probe-event.c
index 85c8207..65a1c82 100644
--- a/tools/perf/util/probe-event.c
+++ b/tools/perf/util/probe-event.c
@@ -2157,7 +2157,8 @@ static bool kprobe_blacklist__listed(unsigned long address)
return !!kprobe_blacklist__find_by_address(&kprobe_blacklist, address);
}
-static int perf_probe_event__sprintf(struct perf_probe_event *pev,
+static int perf_probe_event__sprintf(const char *group, const char *event,
+ struct perf_probe_event *pev,
const char *module,
struct strbuf *result)
{
@@ -2170,7 +2171,7 @@ static int perf_probe_event__sprintf(struct perf_probe_event *pev,
if (!place)
return -EINVAL;
- ret = e_snprintf(buf, 128, "%s:%s", pev->group, pev->event);
+ ret = e_snprintf(buf, 128, "%s:%s", group, event);
if (ret < 0)
goto out;
@@ -2195,13 +2196,14 @@ out:
}
/* Show an event */
-static int show_perf_probe_event(struct perf_probe_event *pev,
+static int show_perf_probe_event(const char *group, const char *event,
+ struct perf_probe_event *pev,
const char *module, bool use_stdout)
{
struct strbuf buf = STRBUF_INIT;
int ret;
- ret = perf_probe_event__sprintf(pev, module, &buf);
+ ret = perf_probe_event__sprintf(group, event, pev, module, &buf);
if (ret >= 0) {
if (use_stdout)
printf("%s\n", buf.buf);
@@ -2253,7 +2255,8 @@ static int __show_perf_probe_events(int fd, bool is_kprobe,
is_kprobe);
if (ret < 0)
goto next;
- ret = show_perf_probe_event(&pev, tev.point.module,
+ ret = show_perf_probe_event(pev.group, pev.event,
+ &pev, tev.point.module,
true);
}
next:
@@ -2438,7 +2441,7 @@ static int __add_probe_trace_events(struct perf_probe_event *pev,
int i, fd, ret;
struct probe_trace_event *tev = NULL;
char buf[64];
- const char *event, *group;
+ const char *event = NULL, *group = NULL;
struct strlist *namelist;
bool safename;
@@ -2500,15 +2503,12 @@ static int __add_probe_trace_events(struct perf_probe_event *pev,
/* Add added event name to namelist */
strlist__add(namelist, event);
- /* Trick here - save current event/group */
- event = pev->event;
- group = pev->group;
- pev->event = tev->event;
- pev->group = tev->group;
- show_perf_probe_event(pev, tev->point.module, false);
- /* Trick here - restore current event/group */
- pev->event = (char *)event;
- pev->group = (char *)group;
+ /* We use tev's name for showing new events */
+ show_perf_probe_event(tev->group, tev->event, pev,
+ tev->point.module, false);
+ /* Save the last valid name */
+ event = tev->event;
+ group = tev->group;
/*
* Probes after the first probe which comes from same
@@ -2522,11 +2522,10 @@ static int __add_probe_trace_events(struct perf_probe_event *pev,
warn_uprobe_event_compat(tev);
/* Note that it is possible to skip all events because of blacklist */
- if (ret >= 0 && tev->event) {
+ if (ret >= 0 && event) {
/* Show how to use the event. */
pr_info("\nYou can now use it in all perf tools, such as:\n\n");
- pr_info("\tperf record -e %s:%s -aR sleep 1\n\n", tev->group,
- tev->event);
+ pr_info("\tperf record -e %s:%s -aR sleep 1\n\n", group, event);
}
strlist__delete(namelist);
Em Tue, Jun 16, 2015 at 08:50:50PM +0900, Masami Hiramatsu escreveu:
> Hi Arnaldo,
>
> Here is the v3 series of bugfix patches for perf-probe.
> I've rewriten the patch description of 2/3 (no code changed)
> and added a comment on the 3/3 for reproductivity.
> This series fixes below bugs;
>
> - --list shows the list of probes in stderr.
> (It is refined from https://lkml.org/lkml/2015/5/30/34)
> - return success even if no probe is added.
> - usage message is not shown if the last event is skipped.
>
> BTW, this series still include 1/3, since I couldn't find it
> in the latest(published) perf/core. If you've already merged
> it on your local tree, please skip it.
Right, I forgot to push my perf/core branch yesterday, thanks for the
corrections, trying to apply the series now.
- Arnaldo
> Thank you,
>
> ---
>
> Masami Hiramatsu (3):
> [BUGFIX] perf probe: List probes in stdout
> [BUGFIX] perf probe: Fix to return error if no-probe is added
> [BUGFIX] perf probe: Show usage even if the last event is skipped
>
>
> tools/perf/util/probe-event.c | 187 ++++++++++++++++++++++++++---------------
> 1 file changed, 118 insertions(+), 69 deletions(-)
>
>
> --
> Masami HIRAMATSU
> Linux Technology Research Center, System Productivity Research Dept.
> Center for Technology Innovation - Systems Engineering
> Hitachi, Ltd., Research & Development Group
> E-mail: [email protected]
Em Tue, Jun 16, 2015 at 08:50:57PM +0900, Masami Hiramatsu escreveu:
> When the last part of converted events are blacklisted or out-of-text,
> those are skipped and perf probe doesn't show usage examples.
> This fixes it to show the example even if the last part of event list
> is skipped.
>
> E.g. without this patch, events are added, but suddenly end;
End what? Stop being added? I.e. not all eligible events are added? From
your description the problem seems to be that that last message: "You
can now use it..." is not presented, but here, without this patch, it
is:
[root@zoo ~]# perf probe vfs_*
vfs_caches_init_early is out of .text, skip it.
vfs_caches_init is out of .text, skip it.
Added new events:
probe:vfs_open (on vfs_*)
probe:vfs_open_1 (on vfs_*)
probe:vfs_fallocate (on vfs_*)
probe:vfs_open_2 (on vfs_*)
probe:vfs_truncate (on vfs_*)
probe:vfs_setpos (on vfs_*)
probe:vfs_setpos_1 (on vfs_*)
probe:vfs_setpos_2 (on vfs_*)
<SNIP>
probe:vfs_test_lock (on vfs_*)
probe:vfs_lock_file_3 (on vfs_*)
probe:vfs_setlease (on vfs_*)
probe:vfs_pressure_ratio_1 (on vfs_*)
probe:vfs_dentry_acceptable (on vfs_*)
probe:vfs_pressure_ratio_2 (on vfs_*)
probe:vfs_load_quota_inode (on vfs_*)
You can now use it in all perf tools, such as:
perf record -e probe:vfs_load_quota_inode -aR sleep 1
[root@zoo ~]# echo $?
0
[root@zoo ~]#
But here I stumbled into a problem, 'perf probe -l' gets into a long loop
calling brk(), i.e. allocating memory:
[root@zoo ~]# time perf trace -o /tmp/bla -S perf probe -l
probe:vfs_cancel_lock (on vfs_cancel_lock@/home/git/linux/fs/locks.c)
probe:vfs_create (on vfs_create@/home/git/linux/fs/namei.c)
probe:vfs_create_1 (on lookup_open:55@/home/git/linux/fs/namei.c)
probe:vfs_create_2 (on SyS_mknodat+504@/home/git/linux/fs/namei.c)
probe:vfs_create_3 (on SyS_mknod+521@/home/git/linux/fs/namei.c)
probe:vfs_create_4 (on vfs_create@/home/git/linux/fs/namei.c)
<SNIP>
probe:vfs_lock_file_1 (on locks_remove_posix:25@/home/git/linux/fs/locks.c)
probe:vfs_lock_file_2 (on do_lock_file_wait:11@/home/git/linux/fs/locks.c)
probe:vfs_lock_file_3 (on vfs_lock_file@/home/git/linux/fs/locks.c)
probe:vfs_lstat (on vfs_lstat@/home/git/linux/fs/stat.c)
probe:vfs_lstat_1 (on SYSC_lstat:6@/home/git/linux/fs/stat.c)
probe:vfs_lstat_2 (on SYSC_newlstat:6@/home/git/linux/fs/stat.c)
probe:vfs_lstat_3 (on vfs_lstat@/home/git/linux/fs/stat.c)
^C
[root@zoo ~]# grep -w brk /tmp/bla | wc -l
6083
[root@zoo ~]#
[root@zoo ~]# perf probe -F vfs_* | wc -l
45
And there were ~100 probes added, probably due to those _N aliases.
I.e.:
[root@zoo ~]# perf probe -F vfs_* | tail
vfs_statfs
vfs_symlink
vfs_test_lock
vfs_truncate
vfs_unlink
vfs_ustat
vfs_whiteout
vfs_write
vfs_writev
vfs_xattr_cmp
[root@zoo ~]# pref probe -l | tail
bash: pref: command not found...
[root@zoo ~]# perf probe -l | tail
probe:vfs_symlink_3 (on vfs_symlink@/home/git/linux/fs/namei.c)
probe:vfs_test_lock (on vfs_test_lock@/home/git/linux/fs/locks.c)
probe:vfs_truncate (on vfs_truncate@/home/git/linux/fs/open.c)
probe:vfs_unlink (on vfs_unlink@/home/git/linux/fs/namei.c)
probe:vfs_ustat (on vfs_ustat@/home/git/linux/fs/statfs.c)
probe:vfs_whiteout (on vfs_whiteout@/home/git/linux/fs/namei.c)
probe:vfs_whiteout_1 (on vfs_whiteout@/home/git/linux/fs/namei.c)
probe:vfs_write (on vfs_write@git/linux/fs/read_write.c)
probe:vfs_writev (on vfs_writev@git/linux/fs/read_write.c)
probe:vfs_xattr_cmp (on vfs_xattr_cmp@/home/git/linux/fs/xattr.c)
[root@zoo ~]#
I am pushing my perf/core branch now, and I see no need to apply your patch as
I am not reproducing the problem described in the changeset log, not the output
copy'n'pasted in it.
I.e. the only problem I found was this:
[root@zoo ~]# time perf probe -l > /dev/null
real 0m15.408s
user 0m14.892s
sys 0m0.534s
[root@zoo ~]#
[root@zoo ~]# perf stat perf probe -l > /dev/null
Performance counter stats for 'perf probe -l':
15256.588897 task-clock (msec) # 1.001 CPUs utilized
116 context-switches # 0.008 K/sec
4 cpu-migrations # 0.000 K/sec
230,720 page-faults # 0.015 M/sec
47,830,405,530 cycles # 3.135 GHz
43,974,134,505 stalled-cycles-frontend # 91.94% frontend cycles idle
<not supported> stalled-cycles-backend
11,540,587,038 instructions # 0.24 insns per cycle
# 3.81 stalled cycles per insn
2,807,769,592 branches # 184.037 M/sec
20,087,075 branch-misses # 0.72% of all branches
15.240796324 seconds time elapsed
[root@zoo ~]#
Can you check why it takes so long and check the need for this patch?
- Arnaldo
> ----
> # perf probe vfs_*
> vfs_caches_init_early is out of .text, skip it.
> vfs_caches_init is out of .text, skip it.
> Added new events:
> probe:vfs_fallocate (on vfs_*)
> probe:vfs_open (on vfs_*)
> ...
> probe:vfs_dentry_acceptable (on vfs_*)
> probe:vfs_load_quota_inode (on vfs_*)
> #
> ----
> With this fix;
> ----
> # perf probe vfs_*
> vfs_caches_init_early is out of .text, skip it.
> vfs_caches_init is out of .text, skip it.
> Added new events:
> probe:vfs_fallocate (on vfs_*)
> ...
> probe:vfs_load_quota_inode (on vfs_*)
>
> You can now use it in all perf tools, such as:
>
> perf record -e probe:vfs_load_quota_inode -aR sleep 1
>
> #
> ----
>
> Note that this can be reproduced ONLY IF the vfs_caches_init*
> is the last part of matched symbol list. I've checked this happens
> on "3.19.0-generic #18-Ubuntu" kernel binary.
>
> Signed-off-by: Masami Hiramatsu <[email protected]>
> ---
> tools/perf/util/probe-event.c | 35 +++++++++++++++++------------------
> 1 file changed, 17 insertions(+), 18 deletions(-)
>
> diff --git a/tools/perf/util/probe-event.c b/tools/perf/util/probe-event.c
> index 85c8207..65a1c82 100644
> --- a/tools/perf/util/probe-event.c
> +++ b/tools/perf/util/probe-event.c
> @@ -2157,7 +2157,8 @@ static bool kprobe_blacklist__listed(unsigned long address)
> return !!kprobe_blacklist__find_by_address(&kprobe_blacklist, address);
> }
>
> -static int perf_probe_event__sprintf(struct perf_probe_event *pev,
> +static int perf_probe_event__sprintf(const char *group, const char *event,
> + struct perf_probe_event *pev,
> const char *module,
> struct strbuf *result)
> {
> @@ -2170,7 +2171,7 @@ static int perf_probe_event__sprintf(struct perf_probe_event *pev,
> if (!place)
> return -EINVAL;
>
> - ret = e_snprintf(buf, 128, "%s:%s", pev->group, pev->event);
> + ret = e_snprintf(buf, 128, "%s:%s", group, event);
> if (ret < 0)
> goto out;
>
> @@ -2195,13 +2196,14 @@ out:
> }
>
> /* Show an event */
> -static int show_perf_probe_event(struct perf_probe_event *pev,
> +static int show_perf_probe_event(const char *group, const char *event,
> + struct perf_probe_event *pev,
> const char *module, bool use_stdout)
> {
> struct strbuf buf = STRBUF_INIT;
> int ret;
>
> - ret = perf_probe_event__sprintf(pev, module, &buf);
> + ret = perf_probe_event__sprintf(group, event, pev, module, &buf);
> if (ret >= 0) {
> if (use_stdout)
> printf("%s\n", buf.buf);
> @@ -2253,7 +2255,8 @@ static int __show_perf_probe_events(int fd, bool is_kprobe,
> is_kprobe);
> if (ret < 0)
> goto next;
> - ret = show_perf_probe_event(&pev, tev.point.module,
> + ret = show_perf_probe_event(pev.group, pev.event,
> + &pev, tev.point.module,
> true);
> }
> next:
> @@ -2438,7 +2441,7 @@ static int __add_probe_trace_events(struct perf_probe_event *pev,
> int i, fd, ret;
> struct probe_trace_event *tev = NULL;
> char buf[64];
> - const char *event, *group;
> + const char *event = NULL, *group = NULL;
> struct strlist *namelist;
> bool safename;
>
> @@ -2500,15 +2503,12 @@ static int __add_probe_trace_events(struct perf_probe_event *pev,
> /* Add added event name to namelist */
> strlist__add(namelist, event);
>
> - /* Trick here - save current event/group */
> - event = pev->event;
> - group = pev->group;
> - pev->event = tev->event;
> - pev->group = tev->group;
> - show_perf_probe_event(pev, tev->point.module, false);
> - /* Trick here - restore current event/group */
> - pev->event = (char *)event;
> - pev->group = (char *)group;
> + /* We use tev's name for showing new events */
> + show_perf_probe_event(tev->group, tev->event, pev,
> + tev->point.module, false);
> + /* Save the last valid name */
> + event = tev->event;
> + group = tev->group;
>
> /*
> * Probes after the first probe which comes from same
> @@ -2522,11 +2522,10 @@ static int __add_probe_trace_events(struct perf_probe_event *pev,
> warn_uprobe_event_compat(tev);
>
> /* Note that it is possible to skip all events because of blacklist */
> - if (ret >= 0 && tev->event) {
> + if (ret >= 0 && event) {
> /* Show how to use the event. */
> pr_info("\nYou can now use it in all perf tools, such as:\n\n");
> - pr_info("\tperf record -e %s:%s -aR sleep 1\n\n", tev->group,
> - tev->event);
> + pr_info("\tperf record -e %s:%s -aR sleep 1\n\n", group, event);
> }
>
> strlist__delete(namelist);
On 2015/06/16 23:46, Arnaldo Carvalho de Melo wrote:
> Em Tue, Jun 16, 2015 at 08:50:57PM +0900, Masami Hiramatsu escreveu:
>> When the last part of converted events are blacklisted or out-of-text,
>> those are skipped and perf probe doesn't show usage examples.
>> This fixes it to show the example even if the last part of event list
>> is skipped.
>>
>> E.g. without this patch, events are added, but suddenly end;
>
> End what? Stop being added?
"End without the last message", I meant.
> I.e. not all eligible events are added? From
> your description the problem seems to be that that last message: "You
> can now use it..." is not presented, but here, without this patch, it
> is:
I see, actually, this happens only if the skipped symbols (
vfs_caches_init_early or vfs_caches_init) are placed at the end of the
matched symbol list. On Ubuntu 15.04 kernel, it doesn't have
vfs_load_quota_inode etc. and the vfs_caches_init is the last part of
the matched list. Since it is hard to reproduce, I've added a Note on
the end of description :)
----
>>
>> Note that this can be reproduced ONLY IF the vfs_caches_init*
>> is the last part of matched symbol list. I've checked this happens
>> on "3.19.0-generic #18-Ubuntu" kernel binary.
>>
----
To reproduce this bug, you need to find a good symbol matching pattern
which (1) matches both of valid function in .text and invalid function
in .inittext (2) invalid one must be on the end of matched function list.
I fortunately hit such pattern and found this bug, but it depends on
the kernel binary.
[...]
> I.e. the only problem I found was this:
>
> [root@zoo ~]# time perf probe -l > /dev/null
>
> real 0m15.408s
> user 0m14.892s
> sys 0m0.534s
> [root@zoo ~]#
> [root@zoo ~]# perf stat perf probe -l > /dev/null
>
> Performance counter stats for 'perf probe -l':
>
> 15256.588897 task-clock (msec) # 1.001 CPUs utilized
> 116 context-switches # 0.008 K/sec
> 4 cpu-migrations # 0.000 K/sec
> 230,720 page-faults # 0.015 M/sec
> 47,830,405,530 cycles # 3.135 GHz
> 43,974,134,505 stalled-cycles-frontend # 91.94% frontend cycles idle
> <not supported> stalled-cycles-backend
> 11,540,587,038 instructions # 0.24 insns per cycle
> # 3.81 stalled cycles per insn
> 2,807,769,592 branches # 184.037 M/sec
> 20,087,075 branch-misses # 0.72% of all branches
>
> 15.240796324 seconds time elapsed
>
> [root@zoo ~]#
>
> Can you check why it takes so long and check the need for this patch?
It is because perf probe -l is not optimized to show a lot of probes yet.
It initializes and loads debuginfo for each probe. I guess we can reuse
debuginfo among them. let me try...
Thank you,
--
Masami HIRAMATSU
Linux Technology Research Center, System Productivity Research Dept.
Center for Technology Innovation - Systems Engineering
Hitachi, Ltd., Research & Development Group
E-mail: [email protected]
On 2015/06/17 14:31, Masami Hiramatsu wrote:
>> > I.e. the only problem I found was this:
>> >
>> > [root@zoo ~]# time perf probe -l > /dev/null
>> >
>> > real 0m15.408s
>> > user 0m14.892s
>> > sys 0m0.534s
>> > [root@zoo ~]#
>> > [root@zoo ~]# perf stat perf probe -l > /dev/null
>> >
>> > Performance counter stats for 'perf probe -l':
>> >
>> > 15256.588897 task-clock (msec) # 1.001 CPUs utilized
>> > 116 context-switches # 0.008 K/sec
>> > 4 cpu-migrations # 0.000 K/sec
>> > 230,720 page-faults # 0.015 M/sec
>> > 47,830,405,530 cycles # 3.135 GHz
>> > 43,974,134,505 stalled-cycles-frontend # 91.94% frontend cycles idle
>> > <not supported> stalled-cycles-backend
>> > 11,540,587,038 instructions # 0.24 insns per cycle
>> > # 3.81 stalled cycles per insn
>> > 2,807,769,592 branches # 184.037 M/sec
>> > 20,087,075 branch-misses # 0.72% of all branches
>> >
>> > 15.240796324 seconds time elapsed
>> >
>> > [root@zoo ~]#
>> >
>> > Can you check why it takes so long and check the need for this patch?
> It is because perf probe -l is not optimized to show a lot of probes yet.
> It initializes and loads debuginfo for each probe. I guess we can reuse
> debuginfo among them. let me try...
>
OK, I've ensured that's true,
[root@localhost perf]# time ./perf probe -l &> /dev/null
real 0m25.376s
user 0m24.381s
sys 0m1.012s
[root@localhost perf]# time ./perf probe --no-dwarf -l &> /dev/null
real 0m0.059s
user 0m0.039s
sys 0m0.020s
(Note that --no-dwarf is my local patch for debugging, not sending yet)
So, the problem is on the debuginfo processing. I've also fixed that
by caching the last used debuginfo. :)
[root@localhost perf]# time ./perf probe -l &> /dev/null
real 0m0.161s
user 0m0.136s
sys 0m0.025s
I'll send the patch asap.
Thank you!
--
Masami HIRAMATSU
Linux Technology Research Center, System Productivity Research Dept.
Center for Technology Innovation - Systems Engineering
Hitachi, Ltd., Research & Development Group
E-mail: [email protected]
Speed up the "perf probe --list" by caching the last used
debuginfo. perf probe --list always open and load debuginfo
for each entry of probe list. This takes very a long time.
E.g. with vfs_* events (total 96 probes)
----
[root@localhost perf]# time ./perf probe -l &> /dev/null
real 0m25.376s
user 0m24.381s
sys 0m1.012s
----
To solve this issue, this adds debuginfo_cache to cache the
last used debuginfo on memory.
With this fix, the perf-probe --list significantly improves
its speed.
----
[root@localhost perf]# time ./perf probe -l &> /dev/null
real 0m0.161s
user 0m0.136s
sys 0m0.025s
----
Signed-off-by: Masami Hiramatsu <[email protected]>
---
tools/perf/util/probe-event.c | 48 ++++++++++++++++++++++++++++++++++++++---
1 file changed, 44 insertions(+), 4 deletions(-)
diff --git a/tools/perf/util/probe-event.c b/tools/perf/util/probe-event.c
index 65a1c82..076527b 100644
--- a/tools/perf/util/probe-event.c
+++ b/tools/perf/util/probe-event.c
@@ -429,6 +429,41 @@ static struct debuginfo *open_debuginfo(const char *module, bool silent)
return ret;
}
+/* For caching the last debuginfo */
+static struct debuginfo *debuginfo_cache;
+static char *debuginfo_cache_path;
+
+static struct debuginfo *debuginfo_cache__open(const char *module, bool silent)
+{
+ if ((debuginfo_cache_path && !strcmp(debuginfo_cache_path, module)) ||
+ (!debuginfo_cache_path && !module && debuginfo_cache))
+ goto out;
+
+ /* Copy module path */
+ free(debuginfo_cache_path);
+ if (module) {
+ debuginfo_cache_path = strdup(module);
+ if (!debuginfo_cache_path) {
+ debuginfo__delete(debuginfo_cache);
+ debuginfo_cache = NULL;
+ goto out;
+ }
+ }
+
+ debuginfo_cache = open_debuginfo(module, silent);
+ if (!debuginfo_cache)
+ zfree(&debuginfo_cache_path);
+out:
+ return debuginfo_cache;
+}
+
+static void debuginfo_cache__exit(void)
+{
+ debuginfo__delete(debuginfo_cache);
+ debuginfo_cache = NULL;
+ zfree(&debuginfo_cache_path);
+}
+
static int get_text_start_address(const char *exec, unsigned long *address)
{
@@ -490,12 +525,11 @@ static int find_perf_probe_point_from_dwarf(struct probe_trace_point *tp,
pr_debug("try to find information at %" PRIx64 " in %s\n", addr,
tp->module ? : "kernel");
- dinfo = open_debuginfo(tp->module, verbose == 0);
- if (dinfo) {
+ dinfo = debuginfo_cache__open(tp->module, verbose == 0);
+ if (dinfo)
ret = debuginfo__find_probe_point(dinfo,
(unsigned long)addr, pp);
- debuginfo__delete(dinfo);
- } else
+ else
ret = -ENOENT;
if (ret > 0) {
@@ -930,6 +964,10 @@ out:
#else /* !HAVE_DWARF_SUPPORT */
+static void debuginfo_cache__exit(void)
+{
+}
+
static int
find_perf_probe_point_from_dwarf(struct probe_trace_point *tp __maybe_unused,
struct perf_probe_point *pp __maybe_unused,
@@ -2266,6 +2304,8 @@ next:
break;
}
strlist__delete(rawlist);
+ /* Cleanup cached debuginfo if needed */
+ debuginfo_cache__exit();
return ret;
}
Em Wed, Jun 17, 2015 at 11:58:18PM +0900, Masami Hiramatsu escreveu:
> On 2015/06/17 14:31, Masami Hiramatsu wrote:
> >> > I.e. the only problem I found was this:
> >> >
> >> > [root@zoo ~]# time perf probe -l > /dev/null
> >> >
> >> > real 0m15.408s
> >> > user 0m14.892s
> >> > sys 0m0.534s
> >> > [root@zoo ~]#
> >> > [root@zoo ~]# perf stat perf probe -l > /dev/null
> >> >
> >> > Performance counter stats for 'perf probe -l':
> >> >
> >> > 15256.588897 task-clock (msec) # 1.001 CPUs utilized
> >> > 116 context-switches # 0.008 K/sec
> >> > 4 cpu-migrations # 0.000 K/sec
> >> > 230,720 page-faults # 0.015 M/sec
> >> > 47,830,405,530 cycles # 3.135 GHz
> >> > 43,974,134,505 stalled-cycles-frontend # 91.94% frontend cycles idle
> >> > <not supported> stalled-cycles-backend
> >> > 11,540,587,038 instructions # 0.24 insns per cycle
> >> > # 3.81 stalled cycles per insn
> >> > 2,807,769,592 branches # 184.037 M/sec
> >> > 20,087,075 branch-misses # 0.72% of all branches
> >> >
> >> > 15.240796324 seconds time elapsed
> >> >
> >> > [root@zoo ~]#
> >> >
> >> > Can you check why it takes so long and check the need for this patch?
> > It is because perf probe -l is not optimized to show a lot of probes yet.
> > It initializes and loads debuginfo for each probe. I guess we can reuse
> > debuginfo among them. let me try...
> >
>
> OK, I've ensured that's true,
>
> [root@localhost perf]# time ./perf probe -l &> /dev/null
>
> real 0m25.376s
> user 0m24.381s
> sys 0m1.012s
>
> [root@localhost perf]# time ./perf probe --no-dwarf -l &> /dev/null
>
> real 0m0.059s
> user 0m0.039s
> sys 0m0.020s
>
> (Note that --no-dwarf is my local patch for debugging, not sending yet)
>
> So, the problem is on the debuginfo processing. I've also fixed that
> by caching the last used debuginfo. :)
>
> [root@localhost perf]# time ./perf probe -l &> /dev/null
>
> real 0m0.161s
> user 0m0.136s
> sys 0m0.025s
>
> I'll send the patch asap.
Thanks! I really need to go thru builtin-probe.c looking at how it uses
the symbol functions, to see what I can change in symbol*.[ch] to help
it with its needs.
Till then tho, please send the patch, that is a really great speedup! :-)
- Arnaldo
Commit-ID: b031220d520238075bd99513a420e65cf37866ad
Gitweb: http://git.kernel.org/tip/b031220d520238075bd99513a420e65cf37866ad
Author: Masami Hiramatsu <[email protected]>
AuthorDate: Tue, 16 Jun 2015 20:50:55 +0900
Committer: Arnaldo Carvalho de Melo <[email protected]>
CommitDate: Tue, 16 Jun 2015 11:39:51 -0300
perf probe: Fix to return error if no probe is added
Fix perf probe to return an error if no probe is added due to the given
probe point being on the blacklist.
To fix this problem, this moves the blacklist checking to right after
finding symbols/probe-points and marks them as skipped.
If all the symbols are skipped, "perf probe" returns an error as it
fails to find the corresponding probe address.
E.g. currently if a blacklisted probe is given:
# perf probe do_trap && echo 'succeed'
Added new event:
Warning: Skipped probing on blacklisted function: sync_regs
succeed
No! It must fail! With this patch, it correctly fails:
# perf probe do_trap && echo 'succeed'
do_trap is blacklisted function, skip it.
Probe point 'do_trap' not found.
Error: Failed to add events.
Signed-off-by: Masami Hiramatsu <[email protected]>
Tested-by: Arnaldo Carvalho de Melo <[email protected]>
Cc: David Ahern <[email protected]>
Cc: Jiri Olsa <[email protected]>
Cc: Namhyung Kim <[email protected]>
Cc: Naohiro Aota <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Link: http://lkml.kernel.org/r/[email protected]
Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
---
tools/perf/util/probe-event.c | 113 ++++++++++++++++++++++++++----------------
1 file changed, 71 insertions(+), 42 deletions(-)
diff --git a/tools/perf/util/probe-event.c b/tools/perf/util/probe-event.c
index c4ab588..85c8207 100644
--- a/tools/perf/util/probe-event.c
+++ b/tools/perf/util/probe-event.c
@@ -246,6 +246,20 @@ static void clear_probe_trace_events(struct probe_trace_event *tevs, int ntevs)
clear_probe_trace_event(tevs + i);
}
+static bool kprobe_blacklist__listed(unsigned long address);
+static bool kprobe_warn_out_range(const char *symbol, unsigned long address)
+{
+ /* Get the address of _etext for checking non-probable text symbol */
+ if (kernel_get_symbol_address_by_name("_etext", false) < address)
+ pr_warning("%s is out of .text, skip it.\n", symbol);
+ else if (kprobe_blacklist__listed(address))
+ pr_warning("%s is blacklisted function, skip it.\n", symbol);
+ else
+ return false;
+
+ return true;
+}
+
#ifdef HAVE_DWARF_SUPPORT
static int kernel_get_module_dso(const char *module, struct dso **pdso)
@@ -559,7 +573,6 @@ static int post_process_probe_trace_events(struct probe_trace_event *tevs,
bool uprobe)
{
struct ref_reloc_sym *reloc_sym;
- u64 etext_addr;
char *tmp;
int i, skipped = 0;
@@ -575,31 +588,28 @@ static int post_process_probe_trace_events(struct probe_trace_event *tevs,
pr_warning("Relocated base symbol is not found!\n");
return -EINVAL;
}
- /* Get the address of _etext for checking non-probable text symbol */
- etext_addr = kernel_get_symbol_address_by_name("_etext", false);
for (i = 0; i < ntevs; i++) {
- if (tevs[i].point.address && !tevs[i].point.retprobe) {
- /* If we found a wrong one, mark it by NULL symbol */
- if (etext_addr < tevs[i].point.address) {
- pr_warning("%s+%lu is out of .text, skip it.\n",
- tevs[i].point.symbol, tevs[i].point.offset);
- tmp = NULL;
- skipped++;
- } else {
- tmp = strdup(reloc_sym->name);
- if (!tmp)
- return -ENOMEM;
- }
- /* If we have no realname, use symbol for it */
- if (!tevs[i].point.realname)
- tevs[i].point.realname = tevs[i].point.symbol;
- else
- free(tevs[i].point.symbol);
- tevs[i].point.symbol = tmp;
- tevs[i].point.offset = tevs[i].point.address -
- reloc_sym->unrelocated_addr;
+ if (!tevs[i].point.address || tevs[i].point.retprobe)
+ continue;
+ /* If we found a wrong one, mark it by NULL symbol */
+ if (kprobe_warn_out_range(tevs[i].point.symbol,
+ tevs[i].point.address)) {
+ tmp = NULL;
+ skipped++;
+ } else {
+ tmp = strdup(reloc_sym->name);
+ if (!tmp)
+ return -ENOMEM;
}
+ /* If we have no realname, use symbol for it */
+ if (!tevs[i].point.realname)
+ tevs[i].point.realname = tevs[i].point.symbol;
+ else
+ free(tevs[i].point.symbol);
+ tevs[i].point.symbol = tmp;
+ tevs[i].point.offset = tevs[i].point.address -
+ reloc_sym->unrelocated_addr;
}
return skipped;
}
@@ -2126,6 +2136,27 @@ kprobe_blacklist__find_by_address(struct list_head *blacklist,
return NULL;
}
+static LIST_HEAD(kprobe_blacklist);
+
+static void kprobe_blacklist__init(void)
+{
+ if (!list_empty(&kprobe_blacklist))
+ return;
+
+ if (kprobe_blacklist__load(&kprobe_blacklist) < 0)
+ pr_debug("No kprobe blacklist support, ignored\n");
+}
+
+static void kprobe_blacklist__release(void)
+{
+ kprobe_blacklist__delete(&kprobe_blacklist);
+}
+
+static bool kprobe_blacklist__listed(unsigned long address)
+{
+ return !!kprobe_blacklist__find_by_address(&kprobe_blacklist, address);
+}
+
static int perf_probe_event__sprintf(struct perf_probe_event *pev,
const char *module,
struct strbuf *result)
@@ -2409,8 +2440,6 @@ static int __add_probe_trace_events(struct perf_probe_event *pev,
char buf[64];
const char *event, *group;
struct strlist *namelist;
- LIST_HEAD(blacklist);
- struct kprobe_blacklist_node *node;
bool safename;
if (pev->uprobes)
@@ -2430,28 +2459,15 @@ static int __add_probe_trace_events(struct perf_probe_event *pev,
ret = -ENOMEM;
goto close_out;
}
- /* Get kprobe blacklist if exists */
- if (!pev->uprobes) {
- ret = kprobe_blacklist__load(&blacklist);
- if (ret < 0)
- pr_debug("No kprobe blacklist support, ignored\n");
- }
safename = (pev->point.function && !strisglob(pev->point.function));
ret = 0;
pr_info("Added new event%s\n", (ntevs > 1) ? "s:" : ":");
for (i = 0; i < ntevs; i++) {
tev = &tevs[i];
- /* Skip if the symbol is out of .text (marked previously) */
+ /* Skip if the symbol is out of .text or blacklisted */
if (!tev->point.symbol)
continue;
- /* Ensure that the address is NOT blacklisted */
- node = kprobe_blacklist__find_by_address(&blacklist,
- tev->point.address);
- if (node) {
- pr_warning("Warning: Skipped probing on blacklisted function: %s\n", node->symbol);
- continue;
- }
if (pev->event)
event = pev->event;
@@ -2513,7 +2529,6 @@ static int __add_probe_trace_events(struct perf_probe_event *pev,
tev->event);
}
- kprobe_blacklist__delete(&blacklist);
strlist__delete(namelist);
close_out:
close(fd);
@@ -2563,7 +2578,7 @@ static int find_probe_trace_events_from_map(struct perf_probe_event *pev,
struct perf_probe_point *pp = &pev->point;
struct probe_trace_point *tp;
int num_matched_functions;
- int ret, i, j;
+ int ret, i, j, skipped = 0;
map = get_target_map(pev->target, pev->uprobes);
if (!map) {
@@ -2631,7 +2646,12 @@ static int find_probe_trace_events_from_map(struct perf_probe_event *pev,
}
/* Add one probe point */
tp->address = map->unmap_ip(map, sym->start) + pp->offset;
- if (reloc_sym) {
+ /* If we found a wrong one, mark it by NULL symbol */
+ if (!pev->uprobes &&
+ kprobe_warn_out_range(sym->name, tp->address)) {
+ tp->symbol = NULL; /* Skip it */
+ skipped++;
+ } else if (reloc_sym) {
tp->symbol = strdup_or_goto(reloc_sym->name, nomem_out);
tp->offset = tp->address - reloc_sym->addr;
} else {
@@ -2667,6 +2687,10 @@ static int find_probe_trace_events_from_map(struct perf_probe_event *pev,
}
arch__fix_tev_from_maps(pev, tev, map);
}
+ if (ret == skipped) {
+ ret = -ENOENT;
+ goto err_out;
+ }
out:
put_target_map(map, pev->uprobes);
@@ -2737,6 +2761,9 @@ int add_perf_probe_events(struct perf_probe_event *pevs, int npevs)
/* Loop 1: convert all events */
for (i = 0; i < npevs; i++) {
pkgs[i].pev = &pevs[i];
+ /* Init kprobe blacklist if needed */
+ if (!pkgs[i].pev->uprobes)
+ kprobe_blacklist__init();
/* Convert with or without debuginfo */
ret = convert_to_probe_trace_events(pkgs[i].pev,
&pkgs[i].tevs);
@@ -2744,6 +2771,8 @@ int add_perf_probe_events(struct perf_probe_event *pevs, int npevs)
goto end;
pkgs[i].ntevs = ret;
}
+ /* This just release blacklist only if allocated */
+ kprobe_blacklist__release();
/* Loop 2: add all events */
for (i = 0; i < npevs; i++) {
Commit-ID: d350bd571ffa89fc3bd07cfa9685d5210f459be8
Gitweb: http://git.kernel.org/tip/d350bd571ffa89fc3bd07cfa9685d5210f459be8
Author: Masami Hiramatsu <[email protected]>
AuthorDate: Tue, 16 Jun 2015 20:50:57 +0900
Committer: Arnaldo Carvalho de Melo <[email protected]>
CommitDate: Wed, 17 Jun 2015 16:31:42 -0300
perf probe: Show usage even if the last event is skipped
When the last part of converted events are blacklisted or out-of-text,
those are skipped and perf probe doesn't show usage examples. This
fixes it to show the example even if the last part of event list is
skipped.
E.g. without this patch, events are added, but suddenly end:
# perf probe vfs_*
vfs_caches_init_early is out of .text, skip it.
vfs_caches_init is out of .text, skip it.
Added new events:
probe:vfs_fallocate (on vfs_*)
probe:vfs_open (on vfs_*)
...
probe:vfs_dentry_acceptable (on vfs_*)
probe:vfs_load_quota_inode (on vfs_*)
#
With this fix:
# perf probe vfs_*
vfs_caches_init_early is out of .text, skip it.
vfs_caches_init is out of .text, skip it.
Added new events:
probe:vfs_fallocate (on vfs_*)
...
probe:vfs_load_quota_inode (on vfs_*)
You can now use it in all perf tools, such as:
perf record -e probe:vfs_load_quota_inode -aR sleep 1
Note that this can be reproduced ONLY IF the vfs_caches_init* is the
last part of matched symbol list. I've checked this happens on
"3.19.0-generic #18-Ubuntu" kernel binary.
Signed-off-by: Masami Hiramatsu <[email protected]>
Cc: David Ahern <[email protected]>
Cc: Jiri Olsa <[email protected]>
Cc: Namhyung Kim <[email protected]>
Cc: Naohiro Aota <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Link: http://lkml.kernel.org/r/[email protected]
Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
---
tools/perf/util/probe-event.c | 35 +++++++++++++++++------------------
1 file changed, 17 insertions(+), 18 deletions(-)
diff --git a/tools/perf/util/probe-event.c b/tools/perf/util/probe-event.c
index 85c8207..65a1c82 100644
--- a/tools/perf/util/probe-event.c
+++ b/tools/perf/util/probe-event.c
@@ -2157,7 +2157,8 @@ static bool kprobe_blacklist__listed(unsigned long address)
return !!kprobe_blacklist__find_by_address(&kprobe_blacklist, address);
}
-static int perf_probe_event__sprintf(struct perf_probe_event *pev,
+static int perf_probe_event__sprintf(const char *group, const char *event,
+ struct perf_probe_event *pev,
const char *module,
struct strbuf *result)
{
@@ -2170,7 +2171,7 @@ static int perf_probe_event__sprintf(struct perf_probe_event *pev,
if (!place)
return -EINVAL;
- ret = e_snprintf(buf, 128, "%s:%s", pev->group, pev->event);
+ ret = e_snprintf(buf, 128, "%s:%s", group, event);
if (ret < 0)
goto out;
@@ -2195,13 +2196,14 @@ out:
}
/* Show an event */
-static int show_perf_probe_event(struct perf_probe_event *pev,
+static int show_perf_probe_event(const char *group, const char *event,
+ struct perf_probe_event *pev,
const char *module, bool use_stdout)
{
struct strbuf buf = STRBUF_INIT;
int ret;
- ret = perf_probe_event__sprintf(pev, module, &buf);
+ ret = perf_probe_event__sprintf(group, event, pev, module, &buf);
if (ret >= 0) {
if (use_stdout)
printf("%s\n", buf.buf);
@@ -2253,7 +2255,8 @@ static int __show_perf_probe_events(int fd, bool is_kprobe,
is_kprobe);
if (ret < 0)
goto next;
- ret = show_perf_probe_event(&pev, tev.point.module,
+ ret = show_perf_probe_event(pev.group, pev.event,
+ &pev, tev.point.module,
true);
}
next:
@@ -2438,7 +2441,7 @@ static int __add_probe_trace_events(struct perf_probe_event *pev,
int i, fd, ret;
struct probe_trace_event *tev = NULL;
char buf[64];
- const char *event, *group;
+ const char *event = NULL, *group = NULL;
struct strlist *namelist;
bool safename;
@@ -2500,15 +2503,12 @@ static int __add_probe_trace_events(struct perf_probe_event *pev,
/* Add added event name to namelist */
strlist__add(namelist, event);
- /* Trick here - save current event/group */
- event = pev->event;
- group = pev->group;
- pev->event = tev->event;
- pev->group = tev->group;
- show_perf_probe_event(pev, tev->point.module, false);
- /* Trick here - restore current event/group */
- pev->event = (char *)event;
- pev->group = (char *)group;
+ /* We use tev's name for showing new events */
+ show_perf_probe_event(tev->group, tev->event, pev,
+ tev->point.module, false);
+ /* Save the last valid name */
+ event = tev->event;
+ group = tev->group;
/*
* Probes after the first probe which comes from same
@@ -2522,11 +2522,10 @@ static int __add_probe_trace_events(struct perf_probe_event *pev,
warn_uprobe_event_compat(tev);
/* Note that it is possible to skip all events because of blacklist */
- if (ret >= 0 && tev->event) {
+ if (ret >= 0 && event) {
/* Show how to use the event. */
pr_info("\nYou can now use it in all perf tools, such as:\n\n");
- pr_info("\tperf record -e %s:%s -aR sleep 1\n\n", tev->group,
- tev->event);
+ pr_info("\tperf record -e %s:%s -aR sleep 1\n\n", group, event);
}
strlist__delete(namelist);
Commit-ID: 7737af010b097f3c1e2aeded21774d58b4aa2698
Gitweb: http://git.kernel.org/tip/7737af010b097f3c1e2aeded21774d58b4aa2698
Author: Masami Hiramatsu <[email protected]>
AuthorDate: Wed, 17 Jun 2015 23:58:54 +0900
Committer: Arnaldo Carvalho de Melo <[email protected]>
CommitDate: Wed, 17 Jun 2015 16:37:53 -0300
perf probe: Speed up perf probe --list by caching debuginfo
Speed up the "perf probe --list" by caching the last used debuginfo.
perf probe --list always open and load debuginfo for each entry of probe
list. This takes very a long time.
E.g. with vfs_* events (total 96 probes)
[root@localhost perf]# time ./perf probe -l &> /dev/null
real 0m25.376s
user 0m24.381s
sys 0m1.012s
To solve this issue, this adds debuginfo_cache to cache the
last used debuginfo on memory.
With this fix, the perf-probe --list significantly improves
its speed.
[root@localhost perf]# time ./perf probe -l &> /dev/null
real 0m0.161s
user 0m0.136s
sys 0m0.025s
Signed-off-by: Masami Hiramatsu <[email protected]>
Tested-by: Arnaldo Carvalho de Melo <[email protected]>
Cc: David Ahern <[email protected]>
Cc: Jiri Olsa <[email protected]>
Cc: Namhyung Kim <[email protected]>
Cc: Naohiro Aota <[email protected]>
Cc: Peter Zijlstra <[email protected]>
Link: http://lkml.kernel.org/r/[email protected]
Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
---
tools/perf/util/probe-event.c | 48 +++++++++++++++++++++++++++++++++++++++----
1 file changed, 44 insertions(+), 4 deletions(-)
diff --git a/tools/perf/util/probe-event.c b/tools/perf/util/probe-event.c
index 65a1c82..076527b 100644
--- a/tools/perf/util/probe-event.c
+++ b/tools/perf/util/probe-event.c
@@ -429,6 +429,41 @@ static struct debuginfo *open_debuginfo(const char *module, bool silent)
return ret;
}
+/* For caching the last debuginfo */
+static struct debuginfo *debuginfo_cache;
+static char *debuginfo_cache_path;
+
+static struct debuginfo *debuginfo_cache__open(const char *module, bool silent)
+{
+ if ((debuginfo_cache_path && !strcmp(debuginfo_cache_path, module)) ||
+ (!debuginfo_cache_path && !module && debuginfo_cache))
+ goto out;
+
+ /* Copy module path */
+ free(debuginfo_cache_path);
+ if (module) {
+ debuginfo_cache_path = strdup(module);
+ if (!debuginfo_cache_path) {
+ debuginfo__delete(debuginfo_cache);
+ debuginfo_cache = NULL;
+ goto out;
+ }
+ }
+
+ debuginfo_cache = open_debuginfo(module, silent);
+ if (!debuginfo_cache)
+ zfree(&debuginfo_cache_path);
+out:
+ return debuginfo_cache;
+}
+
+static void debuginfo_cache__exit(void)
+{
+ debuginfo__delete(debuginfo_cache);
+ debuginfo_cache = NULL;
+ zfree(&debuginfo_cache_path);
+}
+
static int get_text_start_address(const char *exec, unsigned long *address)
{
@@ -490,12 +525,11 @@ static int find_perf_probe_point_from_dwarf(struct probe_trace_point *tp,
pr_debug("try to find information at %" PRIx64 " in %s\n", addr,
tp->module ? : "kernel");
- dinfo = open_debuginfo(tp->module, verbose == 0);
- if (dinfo) {
+ dinfo = debuginfo_cache__open(tp->module, verbose == 0);
+ if (dinfo)
ret = debuginfo__find_probe_point(dinfo,
(unsigned long)addr, pp);
- debuginfo__delete(dinfo);
- } else
+ else
ret = -ENOENT;
if (ret > 0) {
@@ -930,6 +964,10 @@ out:
#else /* !HAVE_DWARF_SUPPORT */
+static void debuginfo_cache__exit(void)
+{
+}
+
static int
find_perf_probe_point_from_dwarf(struct probe_trace_point *tp __maybe_unused,
struct perf_probe_point *pp __maybe_unused,
@@ -2266,6 +2304,8 @@ next:
break;
}
strlist__delete(rawlist);
+ /* Cleanup cached debuginfo if needed */
+ debuginfo_cache__exit();
return ret;
}