2020-01-20 13:38:26

by Thomas Richter

[permalink] [raw]
Subject: [PATCH v2] perf test: Fix test case Merge cpu map

V2: Added Reviewed-by statement

Commit a2408a70368a ("perf evlist: Maintain evlist->all_cpus")
introduces a test case for cpumap merge operation, see functions
perf_cpu_map__merge() and test__cpu_map_merge().

The test case fails on s390 with this error message:
[root@m35lp76 perf]# ./perf test -Fvvvvv 52
52: Merge cpu map :
--- start ---
cpumask list: 1-2,4-5,7
perf: /root/linux/tools/include/linux/refcount.h:131:\
refcount_sub_and_test: Assertion `!(new > val)' failed.
Aborted (core dumped)
[root@m35lp76 perf]#

The root cause is in the function test__cpu_map_merge():
It creates two cpu_maps named 'a' and 'b':

struct perf_cpu_map *a = perf_cpu_map__new("4,2,1");
struct perf_cpu_map *b = perf_cpu_map__new("4,5,7");

and creates a third map named 'c' which is the result of
the merge of maps a and b:

struct perf_cpu_map *c = perf_cpu_map__merge(a, b);

After some verifaction of the merged cpu_map all three
of them are have their reference count reduced and are
freed:

perf_cpu_map__put(a); (1)
perf_cpu_map__put(b);
perf_cpu_map__put(c);

The release of perf_cpu_map__put(a) is wrong. The map
is already released and free'ed as part of the function

perf_cpu_map__merge(struct perf_cpu_map *orig,
| struct perf_cpu_map *other)
+--> perf_cpu_map__put(orig);
|
+--> cpu_map__delete(orig)

At the end perf_cpu_map_put() is called for map 'orig'
alias 'a' and since the reference count is 1, the map
is deleted, as can be seen by the following gdb trace:

(gdb) where
#0 tcache_put (tc_idx=0, chunk=0x156cc30) at malloc.c:2940
#1 _int_free (av=0x3fffd49ee80 <main_arena>, p=0x156cc30,
have_lock=<optimized out>) at malloc.c:4222
#2 0x00000000012d5e78 in cpu_map__delete (map=0x156cc40) at cpumap.c:31
#3 0x00000000012d5f7a in perf_cpu_map__put (map=0x156cc40) at cpumap.c:45
#4 0x00000000012d723a in perf_cpu_map__merge (orig=0x156cc40,
other=0x156cc60) at cpumap.c:343
#5 0x000000000110cdd0 in test__cpu_map_merge (
test=0x14ea6c8 <generic_tests+2856>, subtest=-1) at tests/cpumap.c:128

Thus the perf_cpu_map__put(a) (see (1) above) frees map 'a'
a second time and causes the failure. Fix this be removing that
function call.

Output after:
[root@m35lp76 perf]# ./perf test -Fvvvvv 52
52: Merge cpu map :
--- start ---
cpumask list: 1-2,4-5,7
---- end ----
Merge cpu map: Ok
[root@m35lp76 perf]#

Signed-off-by: Thomas Richter <[email protected]>
Reviewed-by: Andi Kleen <[email protected]>
---
tools/perf/tests/cpumap.c | 1 -
1 file changed, 1 deletion(-)

diff --git a/tools/perf/tests/cpumap.c b/tools/perf/tests/cpumap.c
index 4ac56741ac5f..29c793ac7d10 100644
--- a/tools/perf/tests/cpumap.c
+++ b/tools/perf/tests/cpumap.c
@@ -131,7 +131,6 @@ int test__cpu_map_merge(struct test *test __maybe_unused, int subtest __maybe_un
TEST_ASSERT_VAL("failed to merge map: bad nr", c->nr == 5);
cpu_map__snprint(c, buf, sizeof(buf));
TEST_ASSERT_VAL("failed to merge map: bad result", !strcmp(buf, "1-2,4-5,7"));
- perf_cpu_map__put(a);
perf_cpu_map__put(b);
perf_cpu_map__put(c);
return 0;
--
2.21.0


2020-01-20 13:50:29

by Thomas Richter

[permalink] [raw]
Subject: [PATCH v2] perf test: Fix test trace+probe_vfs_getname.sh

This test places a kprobe to function getname_flags() in the kernel
which has the following prototype:

struct filename *
getname_flags(const char __user *filename, int flags, int *empty)

Variable filename points to a filename located in user space memory.
Looking at
commit 88903c464321c ("tracing/probe: Add ustring type for user-space string")
the kprobe should indicate that user space memory is accessed.

Fix this with a patch to specify user space memory access to
parameter 'filename' and 'string' is replaced by 'ustring'.

Signed-off-by: Thomas Richter <[email protected]>
---
tools/perf/tests/shell/lib/probe_vfs_getname.sh | 4 ++--
1 file changed, 2 insertions(+), 2 deletions(-)

diff --git a/tools/perf/tests/shell/lib/probe_vfs_getname.sh b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
index 7cb99b433888..7ecf117651dd 100644
--- a/tools/perf/tests/shell/lib/probe_vfs_getname.sh
+++ b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
@@ -13,8 +13,8 @@ add_probe_vfs_getname() {
local verbose=$1
if [ $had_vfs_getname -eq 1 ] ; then
line=$(perf probe -L getname_flags 2>&1 | egrep 'result.*=.*filename;' | sed -r 's/[[:space:]]+([[:digit:]]+)[[:space:]]+result->uptr.*/\1/')
- perf probe -q "vfs_getname=getname_flags:${line} pathname=result->name:string" || \
- perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:string"
+ perf probe -q "vfs_getname=getname_flags:${line} pathname=result->uptr:ustring" || \
+ perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:ustring"
fi
}

--
2.21.0

2020-01-20 13:57:49

by Thomas Richter

[permalink] [raw]
Subject: [PATCH v2] perf probe: Add ustring support for perf probe command

Kernel commit 88903c464321 ("tracing/probe: Add ustring type for user-space string")
adds support for user-space strings when type 'ustring' is specified.

Here is an example using sysfs command line interface
for kprobes:

Function to probe:
struct filename *
getname_flags(const char __user *filename, int flags, int *empty)

Setup:
# cd /sys/kernel/debug/tracing/
# echo 'p:tmr1 getname_flags +0(%r2):ustring' > kprobe_events
# cat events/kprobes/tmr1/format | fgrep print
print fmt: "(%lx) arg1=\"%s\"", REC->__probe_ip, REC->arg1
# echo 1 > events/kprobes/tmr1/enable
# touch /tmp/111
# echo 0 > events/kprobes/tmr1/enable
# cat trace|fgrep /tmp/111
touch-5846 [005] d..2 255520.717960: tmr1:\
(getname_flags+0x0/0x400) arg1="/tmp/111"

Doing the same with the perf tool fails.
Using type 'string' succeeds:
# perf probe "vfs_getname=getname_flags:72 pathname=filename:string"
Added new event:
probe:vfs_getname (on getname_flags:72 with pathname=filename:string)
....
# perf probe -d probe:vfs_getname
Removed event: probe:vfs_getname

However using type 'ustring' fails (output before):
# perf probe "vfs_getname=getname_flags:72 pathname=filename:ustring"
Failed to write event: Invalid argument
Error: Failed to add events.
#

Fix this by adding type 'ustring' in function
convert_variable_type().

Using ustring succeeds (output after):
# ./perf probe "vfs_getname=getname_flags:72 pathname=filename:ustring"
Added new event:
probe:vfs_getname (on getname_flags:72 with pathname=filename:ustring)

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

perf record -e probe:vfs_getname -aR sleep 1

#

Note: This issue also exists on x86, it is not s390 specific.

Signed-off-by: Thomas Richter <[email protected]>
---
tools/perf/util/probe-finder.c | 3 ++-
1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/tools/perf/util/probe-finder.c b/tools/perf/util/probe-finder.c
index c470c49a804f..1c817add6ca4 100644
--- a/tools/perf/util/probe-finder.c
+++ b/tools/perf/util/probe-finder.c
@@ -303,7 +303,8 @@ static int convert_variable_type(Dwarf_Die *vr_die,
char prefix;

/* TODO: check all types */
- if (cast && strcmp(cast, "string") != 0 && strcmp(cast, "x") != 0 &&
+ if (cast && strcmp(cast, "string") != 0 && strcmp(cast, "ustring") &&
+ strcmp(cast, "x") != 0 &&
strcmp(cast, "s") != 0 && strcmp(cast, "u") != 0) {
/* Non string type is OK */
/* and respect signedness/hexadecimal cast */
--
2.21.0

2020-01-31 08:37:29

by Arnaldo Carvalho de Melo

[permalink] [raw]
Subject: Re: [PATCH v2] perf test: Fix test trace+probe_vfs_getname.sh

Em Mon, Jan 20, 2020 at 02:20:11PM +0100, Thomas Richter escreveu:
> This test places a kprobe to function getname_flags() in the kernel
> which has the following prototype:
>
> struct filename *
> getname_flags(const char __user *filename, int flags, int *empty)
>
> Variable filename points to a filename located in user space memory.
> Looking at
> commit 88903c464321c ("tracing/probe: Add ustring type for user-space string")
> the kprobe should indicate that user space memory is accessed.

We can't just replace it, right? I.e. this should continue to work with
older kernels, i.e. the latest userspace tooling version should work
when installed in an older kernel, i.e. please just add more fallbacks
to cover the new cases.

- Arnaldo

> Fix this with a patch to specify user space memory access to
> parameter 'filename' and 'string' is replaced by 'ustring'.
>
> Signed-off-by: Thomas Richter <[email protected]>
> ---
> tools/perf/tests/shell/lib/probe_vfs_getname.sh | 4 ++--
> 1 file changed, 2 insertions(+), 2 deletions(-)
>
> diff --git a/tools/perf/tests/shell/lib/probe_vfs_getname.sh b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
> index 7cb99b433888..7ecf117651dd 100644
> --- a/tools/perf/tests/shell/lib/probe_vfs_getname.sh
> +++ b/tools/perf/tests/shell/lib/probe_vfs_getname.sh
> @@ -13,8 +13,8 @@ add_probe_vfs_getname() {
> local verbose=$1
> if [ $had_vfs_getname -eq 1 ] ; then
> line=$(perf probe -L getname_flags 2>&1 | egrep 'result.*=.*filename;' | sed -r 's/[[:space:]]+([[:digit:]]+)[[:space:]]+result->uptr.*/\1/')
> - perf probe -q "vfs_getname=getname_flags:${line} pathname=result->name:string" || \
> - perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:string"
> + perf probe -q "vfs_getname=getname_flags:${line} pathname=result->uptr:ustring" || \
> + perf probe $verbose "vfs_getname=getname_flags:${line} pathname=filename:ustring"
> fi
> }
>
> --
> 2.21.0
>

--

- Arnaldo

Subject: [tip: perf/urgent] perf probe: Add ustring support for perf probe command

The following commit has been merged into the perf/urgent branch of tip:

Commit-ID: 1873f1547dde65c687de143938581347a9312207
Gitweb: https://git.kernel.org/tip/1873f1547dde65c687de143938581347a9312207
Author: Thomas Richter <[email protected]>
AuthorDate: Mon, 20 Jan 2020 14:20:10 +01:00
Committer: Arnaldo Carvalho de Melo <[email protected]>
CommitterDate: Fri, 31 Jan 2020 09:33:58 +01:00

perf probe: Add ustring support for perf probe command

Kernel commit 88903c464321 ("tracing/probe: Add ustring type for user-space string")
adds support for user-space strings when type 'ustring' is specified.

Here is an example using sysfs command line interface
for kprobes:

Function to probe:
struct filename *
getname_flags(const char __user *filename, int flags, int *empty)

Setup:
# cd /sys/kernel/debug/tracing/
# echo 'p:tmr1 getname_flags +0(%r2):ustring' > kprobe_events
# cat events/kprobes/tmr1/format | fgrep print
print fmt: "(%lx) arg1=\"%s\"", REC->__probe_ip, REC->arg1
# echo 1 > events/kprobes/tmr1/enable
# touch /tmp/111
# echo 0 > events/kprobes/tmr1/enable
# cat trace|fgrep /tmp/111
touch-5846 [005] d..2 255520.717960: tmr1:\
(getname_flags+0x0/0x400) arg1="/tmp/111"

Doing the same with the perf tool fails.
Using type 'string' succeeds:
# perf probe "vfs_getname=getname_flags:72 pathname=filename:string"
Added new event:
probe:vfs_getname (on getname_flags:72 with pathname=filename:string)
....
# perf probe -d probe:vfs_getname
Removed event: probe:vfs_getname

However using type 'ustring' fails (output before):
# perf probe "vfs_getname=getname_flags:72 pathname=filename:ustring"
Failed to write event: Invalid argument
Error: Failed to add events.
#

Fix this by adding type 'ustring' in function
convert_variable_type().

Using ustring succeeds (output after):
# ./perf probe "vfs_getname=getname_flags:72 pathname=filename:ustring"
Added new event:
probe:vfs_getname (on getname_flags:72 with pathname=filename:ustring)

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

perf record -e probe:vfs_getname -aR sleep 1

#

Note: This issue also exists on x86, it is not s390 specific.

Signed-off-by: Thomas Richter <[email protected]>
Cc: Heiko Carstens <[email protected]>
Cc: Vasily Gorbik <[email protected]>
Cc: [email protected]
Link: http://lore.kernel.org/lkml/[email protected]
Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
---
tools/perf/util/probe-finder.c | 3 ++-
1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/tools/perf/util/probe-finder.c b/tools/perf/util/probe-finder.c
index c470c49..1c817ad 100644
--- a/tools/perf/util/probe-finder.c
+++ b/tools/perf/util/probe-finder.c
@@ -303,7 +303,8 @@ static int convert_variable_type(Dwarf_Die *vr_die,
char prefix;

/* TODO: check all types */
- if (cast && strcmp(cast, "string") != 0 && strcmp(cast, "x") != 0 &&
+ if (cast && strcmp(cast, "string") != 0 && strcmp(cast, "ustring") &&
+ strcmp(cast, "x") != 0 &&
strcmp(cast, "s") != 0 && strcmp(cast, "u") != 0) {
/* Non string type is OK */
/* and respect signedness/hexadecimal cast */

Subject: [tip: perf/urgent] perf test: Fix test case Merge cpu map

The following commit has been merged into the perf/urgent branch of tip:

Commit-ID: 0dd1979f7f9981dcc5c497e68390f208580032ae
Gitweb: https://git.kernel.org/tip/0dd1979f7f9981dcc5c497e68390f208580032ae
Author: Thomas Richter <[email protected]>
AuthorDate: Mon, 20 Jan 2020 14:20:09 +01:00
Committer: Arnaldo Carvalho de Melo <[email protected]>
CommitterDate: Thu, 30 Jan 2020 11:55:02 +01:00

perf test: Fix test case Merge cpu map

Commit a2408a70368a ("perf evlist: Maintain evlist->all_cpus")
introduces a test case for cpumap merge operation, see functions
perf_cpu_map__merge() and test__cpu_map_merge().

The test case fails on s390 with this error message:

[root@m35lp76 perf]# ./perf test -Fvvvvv 52
52: Merge cpu map :
--- start ---
cpumask list: 1-2,4-5,7
perf: /root/linux/tools/include/linux/refcount.h:131:\
refcount_sub_and_test: Assertion `!(new > val)' failed.
Aborted (core dumped)
[root@m35lp76 perf]#

The root cause is in the function test__cpu_map_merge():
It creates two cpu_maps named 'a' and 'b':

struct perf_cpu_map *a = perf_cpu_map__new("4,2,1");
struct perf_cpu_map *b = perf_cpu_map__new("4,5,7");

and creates a third map named 'c' which is the result of
the merge of maps a and b:

struct perf_cpu_map *c = perf_cpu_map__merge(a, b);

After some verifaction of the merged cpu_map all three
of them are have their reference count reduced and are
freed:

perf_cpu_map__put(a); (1)
perf_cpu_map__put(b);
perf_cpu_map__put(c);

The release of perf_cpu_map__put(a) is wrong. The map
is already released and free'ed as part of the function

perf_cpu_map__merge(struct perf_cpu_map *orig,
| struct perf_cpu_map *other)
+--> perf_cpu_map__put(orig);
|
+--> cpu_map__delete(orig)

At the end perf_cpu_map_put() is called for map 'orig'
alias 'a' and since the reference count is 1, the map
is deleted, as can be seen by the following gdb trace:

(gdb) where
#0 tcache_put (tc_idx=0, chunk=0x156cc30) at malloc.c:2940
#1 _int_free (av=0x3fffd49ee80 <main_arena>, p=0x156cc30,
have_lock=<optimized out>) at malloc.c:4222
#2 0x00000000012d5e78 in cpu_map__delete (map=0x156cc40) at cpumap.c:31
#3 0x00000000012d5f7a in perf_cpu_map__put (map=0x156cc40) at cpumap.c:45
#4 0x00000000012d723a in perf_cpu_map__merge (orig=0x156cc40,
other=0x156cc60) at cpumap.c:343
#5 0x000000000110cdd0 in test__cpu_map_merge (
test=0x14ea6c8 <generic_tests+2856>, subtest=-1) at tests/cpumap.c:128

Thus the perf_cpu_map__put(a) (see (1) above) frees map 'a'
a second time and causes the failure. Fix this be removing that
function call.

Output after:
[root@m35lp76 perf]# ./perf test -Fvvvvv 52
52: Merge cpu map :
--- start ---
cpumask list: 1-2,4-5,7
---- end ----
Merge cpu map: Ok
[root@m35lp76 perf]#

Signed-off-by: Thomas Richter <[email protected]>
Reviewed-by: Andi Kleen <[email protected]>
Cc: Heiko Carstens <[email protected]>
Cc: Vasily Gorbik <[email protected]>
Cc: [email protected]
Link: http://lore.kernel.org/lkml/[email protected]
Signed-off-by: Arnaldo Carvalho de Melo <[email protected]>
---
tools/perf/tests/cpumap.c | 1 -
1 file changed, 1 deletion(-)

diff --git a/tools/perf/tests/cpumap.c b/tools/perf/tests/cpumap.c
index 4ac5674..29c793a 100644
--- a/tools/perf/tests/cpumap.c
+++ b/tools/perf/tests/cpumap.c
@@ -131,7 +131,6 @@ int test__cpu_map_merge(struct test *test __maybe_unused, int subtest __maybe_un
TEST_ASSERT_VAL("failed to merge map: bad nr", c->nr == 5);
cpu_map__snprint(c, buf, sizeof(buf));
TEST_ASSERT_VAL("failed to merge map: bad result", !strcmp(buf, "1-2,4-5,7"));
- perf_cpu_map__put(a);
perf_cpu_map__put(b);
perf_cpu_map__put(c);
return 0;