2021-02-11 13:05:24

by Martin Liška

[permalink] [raw]
Subject: [PATCH] Fix jump parsing for C++ code.

Considering the following testcase:

int
foo(int a, int b)
{
for (unsigned i = 0; i < 1000000000; i++)
a += b;
return a;
}

int main()
{
foo (3, 4);
return 0;
}

perf annotate displays:
86.52 │40055e: → ja 40056c <foo(int, int)+0x26>
13.37 │400560: mov -0x18(%rbp),%eax
│400563: add %eax,-0x14(%rbp)
│400566: addl $0x1,-0x4(%rbp)
0.11 │40056a: → jmp 400557 <foo(int, int)+0x11>
│40056c: mov -0x14(%rbp),%eax
│40056f: pop %rbp

and the 'ja 40056c' does not link to the location in the function.
It's caused by fact that comma is wrongly parsed, it's part
of function signature.

With my patch I see:

86.52 │ ┌──ja 26
13.37 │ │ mov -0x18(%rbp),%eax
│ │ add %eax,-0x14(%rbp)
│ │ addl $0x1,-0x4(%rbp)
0.11 │ │↑ jmp 11
│26:└─→mov -0x14(%rbp),%eax

and 'o' output prints:
86.52 │4005┌── ↓ ja 40056c <foo(int, int)+0x26>
13.37 │4005│0: mov -0x18(%rbp),%eax
│4005│3: add %eax,-0x14(%rbp)
│4005│6: addl $0x1,-0x4(%rbp)
0.11 │4005│a: ↑ jmp 400557 <foo(int, int)+0x11>
│4005└─→ mov -0x14(%rbp),%eax

On the contrary, compiling the very same file with gcc -x c, the parsing
is fine because function arguments are not displyed:

jmp 400543 <foo+0x1d>

Signed-off-by: Martin Liška <[email protected]>
---
tools/perf/util/annotate.c | 6 ++++++
tools/perf/util/annotate.h | 1 +
2 files changed, 7 insertions(+)

diff --git a/tools/perf/util/annotate.c b/tools/perf/util/annotate.c
index ce8c07bc8c56..e3eae646be3e 100644
--- a/tools/perf/util/annotate.c
+++ b/tools/perf/util/annotate.c
@@ -321,11 +321,16 @@ bool ins__is_call(const struct ins *ins)
/*
* Prevents from matching commas in the comment section, e.g.:
* ffff200008446e70: b.cs ffff2000084470f4 <generic_exec_single+0x314> // b.hs, b.nlast
+ *
+ * and skip comma as part of function arguments, e.g.:
+ * 1d8b4ac <linemap_lookup(line_maps const*, unsigned int)+0xcc>
*/
static inline const char *validate_comma(const char *c, struct ins_operands *ops)
{
if (ops->raw_comment && c > ops->raw_comment)
return NULL;
+ else if (ops->raw_func_start && c > ops->raw_func_start)
+ return NULL;

return c;
}
@@ -341,6 +346,7 @@ static int jump__parse(struct arch *arch, struct ins_operands *ops, struct map_s
u64 start, end;

ops->raw_comment = strchr(ops->raw, arch->objdump.comment_char);
+ ops->raw_func_start = strchr(ops->raw, '<');
c = validate_comma(c, ops);

/*
diff --git a/tools/perf/util/annotate.h b/tools/perf/util/annotate.h
index 0a0cd4f32175..096cdaf21b01 100644
--- a/tools/perf/util/annotate.h
+++ b/tools/perf/util/annotate.h
@@ -32,6 +32,7 @@ struct ins {
struct ins_operands {
char *raw;
char *raw_comment;
+ char *raw_func_start;
struct {
char *raw;
char *name;
--
2.30.0


2021-02-11 13:22:24

by Arnaldo Carvalho de Melo

[permalink] [raw]
Subject: Re: [PATCH] Fix jump parsing for C++ code.

Em Thu, Feb 11, 2021 at 01:37:55PM +0100, Martin Liška escreveu:
> Considering the following testcase:

Cool, applied, next time please use a Summary like:

Subject: Re: [PATCH] perf annotate: Fix jump parsing for C++ code.

So that it stands out more clearly in my inbox, this time I saw your
name as a previous perf contributor and figured it should be for perf
:-)

Thanks!

- Arnaldo

> int
> foo(int a, int b)
> {
> for (unsigned i = 0; i < 1000000000; i++)
> a += b;
> return a;
> }
>
> int main()
> {
> foo (3, 4);
> return 0;
> }
>
> perf annotate displays:
> 86.52 │40055e: → ja 40056c <foo(int, int)+0x26>
> 13.37 │400560: mov -0x18(%rbp),%eax
> │400563: add %eax,-0x14(%rbp)
> │400566: addl $0x1,-0x4(%rbp)
> 0.11 │40056a: → jmp 400557 <foo(int, int)+0x11>
> │40056c: mov -0x14(%rbp),%eax
> │40056f: pop %rbp
>
> and the 'ja 40056c' does not link to the location in the function.
> It's caused by fact that comma is wrongly parsed, it's part
> of function signature.
>
> With my patch I see:
>
> 86.52 │ ┌──ja 26
> 13.37 │ │ mov -0x18(%rbp),%eax
> │ │ add %eax,-0x14(%rbp)
> │ │ addl $0x1,-0x4(%rbp)
> 0.11 │ │↑ jmp 11
> │26:└─→mov -0x14(%rbp),%eax
>
> and 'o' output prints:
> 86.52 │4005┌── ↓ ja 40056c <foo(int, int)+0x26>
> 13.37 │4005│0: mov -0x18(%rbp),%eax
> │4005│3: add %eax,-0x14(%rbp)
> │4005│6: addl $0x1,-0x4(%rbp)
> 0.11 │4005│a: ↑ jmp 400557 <foo(int, int)+0x11>
> │4005└─→ mov -0x14(%rbp),%eax
>
> On the contrary, compiling the very same file with gcc -x c, the parsing
> is fine because function arguments are not displyed:
>
> jmp 400543 <foo+0x1d>
>
> Signed-off-by: Martin Liška <[email protected]>
> ---
> tools/perf/util/annotate.c | 6 ++++++
> tools/perf/util/annotate.h | 1 +
> 2 files changed, 7 insertions(+)
>
> diff --git a/tools/perf/util/annotate.c b/tools/perf/util/annotate.c
> index ce8c07bc8c56..e3eae646be3e 100644
> --- a/tools/perf/util/annotate.c
> +++ b/tools/perf/util/annotate.c
> @@ -321,11 +321,16 @@ bool ins__is_call(const struct ins *ins)
> /*
> * Prevents from matching commas in the comment section, e.g.:
> * ffff200008446e70: b.cs ffff2000084470f4 <generic_exec_single+0x314> // b.hs, b.nlast
> + *
> + * and skip comma as part of function arguments, e.g.:
> + * 1d8b4ac <linemap_lookup(line_maps const*, unsigned int)+0xcc>
> */
> static inline const char *validate_comma(const char *c, struct ins_operands *ops)
> {
> if (ops->raw_comment && c > ops->raw_comment)
> return NULL;
> + else if (ops->raw_func_start && c > ops->raw_func_start)
> + return NULL;
> return c;
> }
> @@ -341,6 +346,7 @@ static int jump__parse(struct arch *arch, struct ins_operands *ops, struct map_s
> u64 start, end;
> ops->raw_comment = strchr(ops->raw, arch->objdump.comment_char);
> + ops->raw_func_start = strchr(ops->raw, '<');
> c = validate_comma(c, ops);
> /*
> diff --git a/tools/perf/util/annotate.h b/tools/perf/util/annotate.h
> index 0a0cd4f32175..096cdaf21b01 100644
> --- a/tools/perf/util/annotate.h
> +++ b/tools/perf/util/annotate.h
> @@ -32,6 +32,7 @@ struct ins {
> struct ins_operands {
> char *raw;
> char *raw_comment;
> + char *raw_func_start;
> struct {
> char *raw;
> char *name;
> --
> 2.30.0
>

--

- Arnaldo

2021-02-11 17:55:47

by Arnaldo Carvalho de Melo

[permalink] [raw]
Subject: Re: [PATCH] Fix jump parsing for C++ code.

Em Thu, Feb 11, 2021 at 01:37:55PM +0100, Martin Liška escreveu:
> Considering the following testcase:
>
> int
> foo(int a, int b)
> {
> for (unsigned i = 0; i < 1000000000; i++)
> a += b;
> return a;
> }
>
> int main()
> {
> foo (3, 4);
> return 0;
> }
>
> perf annotate displays:
> 86.52 │40055e: → ja 40056c <foo(int, int)+0x26>
> 13.37 │400560: mov -0x18(%rbp),%eax
> │400563: add %eax,-0x14(%rbp)
> │400566: addl $0x1,-0x4(%rbp)
> 0.11 │40056a: → jmp 400557 <foo(int, int)+0x11>
> │40056c: mov -0x14(%rbp),%eax
> │40056f: pop %rbp
>
> and the 'ja 40056c' does not link to the location in the function.
> It's caused by fact that comma is wrongly parsed, it's part
> of function signature.
>
> With my patch I see:
>
> 86.52 │ ┌──ja 26
> 13.37 │ │ mov -0x18(%rbp),%eax
> │ │ add %eax,-0x14(%rbp)
> │ │ addl $0x1,-0x4(%rbp)
> 0.11 │ │↑ jmp 11
> │26:└─→mov -0x14(%rbp),%eax
>
> and 'o' output prints:
> 86.52 │4005┌── ↓ ja 40056c <foo(int, int)+0x26>
> 13.37 │4005│0: mov -0x18(%rbp),%eax
> │4005│3: add %eax,-0x14(%rbp)
> │4005│6: addl $0x1,-0x4(%rbp)
> 0.11 │4005│a: ↑ jmp 400557 <foo(int, int)+0x11>
> │4005└─→ mov -0x14(%rbp),%eax

So, before your patch, this is what I am seeing:

[acme@five c]$ cat cpp_args_annotate.c
int
foo(int a, int b)
{
for (unsigned i = 0; i < 1000000000; i++)
a += b;
return a;
}

int main()
{
foo (3, 4);
return 0;
}
[acme@five c]$ gcc --version |& head -1
gcc (GCC) 10.2.1 20201125 (Red Hat 10.2.1-9)
[acme@five c]$ gcc -g cpp_args_annotate.c -o cpp_args_annotate
[acme@five c]$ perf record ./cpp_args_annotate
[ perf record: Woken up 2 times to write data ]
[ perf record: Captured and wrote 0.275 MB perf.data (7188 samples) ]
[acme@five c]$ perf annotate --stdio2 foo
Samples: 7K of event 'cycles:u', 4000 Hz, Event count (approx.): 7468429289, [percent: local period]
foo() /home/acme/c/cpp_args_annotate
Percent
0000000000401106 <foo>:
foo():
int
foo(int a, int b)
{
push %rbp
mov %rsp,%rbp
mov %edi,-0x14(%rbp)
mov %esi,-0x18(%rbp)
for (unsigned i = 0; i < 1000000000; i++)
movl $0x0,-0x4(%rbp)
↓ jmp 1d
a += b;
13.45 13: mov -0x18(%rbp),%eax
add %eax,-0x14(%rbp)
for (unsigned i = 0; i < 1000000000; i++)
addl $0x1,-0x4(%rbp)
0.09 1d: cmpl $0x3b9ac9ff,-0x4(%rbp)
86.46 ↑ jbe 13
return a;
mov -0x14(%rbp),%eax
}
pop %rbp
← retq
[acme@five c]$


Ok, now I see:

[acme@five c]$ g++ -g cpp_args_annotate.c -o cpp_args_annotate
[acme@five c]$ perf record ./cpp_args_annotate
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.268 MB perf.data (6976 samples) ]
[acme@five c]$ perf annotate --stdio2 foo
Samples: 6K of event 'cycles:u', 4000 Hz, Event count (approx.): 7380681761, [percent: local period]
foo() /home/acme/c/cpp_args_annotate
Percent
0000000000401106 <foo(int, int)>:
foo(int, int):
int
foo(int a, int b)
{
push %rbp
mov %rsp,%rbp
mov %edi,-0x14(%rbp)
mov %esi,-0x18(%rbp)
for (unsigned i = 0; i < 1000000000; i++)
movl $0x0,-0x4(%rbp)
cmpl $0x3b9ac9ff,-0x4(%rbp)
86.53 → ja 40112c <foo(int, int)+0x26>
a += b;
13.32 mov -0x18(%rbp),%eax
0.00 add %eax,-0x14(%rbp)
for (unsigned i = 0; i < 1000000000; i++)
addl $0x1,-0x4(%rbp)
0.15 → jmp 401117 <foo(int, int)+0x11>
return a;
mov -0x14(%rbp),%eax
}
pop %rbp
← retq
[acme@five c]$

Ok, continuing the test...

- Arnaldo