Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1667437 > unrolled thread

Re: perf report: fix off-by-one for non-activation frames

Started byJan Kratochvil <jan.kratochvil@redhat.com>
First post2017-06-16 08:20 +0200
Last post2017-06-19 21:10 +0200
Articles 8 — 4 participants

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.

Contents

  Re: perf report: fix off-by-one for non-activation frames Jan Kratochvil <jan.kratochvil@redhat.com> - 2017-06-16 08:20 +0200
    Re: perf report: fix off-by-one for non-activation frames Milian Wolff <milian.wolff@kdab.com> - 2017-06-16 14:00 +0200
      Re: perf report: fix off-by-one for non-activation frames Jan Kratochvil <jan.kratochvil@redhat.com> - 2017-06-16 14:00 +0200
        Re: perf report: fix off-by-one for non-activation frames Milian Wolff <milian.wolff@kdab.com> - 2017-06-16 22:00 +0200
          Re: perf report: fix off-by-one for non-activation frames Namhyung Kim <namhyung@kernel.org> - 2017-06-17 10:00 +0200
            Re: perf report: fix off-by-one for non-activation frames Jan Kratochvil <jan.kratochvil@redhat.com> - 2017-06-17 10:10 +0200
              Re: perf report: fix off-by-one for non-activation frames Milian Wolff <milian.wolff@kdab.com> - 2017-06-17 13:20 +0200
                Re: perf report: fix off-by-one for non-activation frames Arnaldo Carvalho de Melo <acme@redhat.com> - 2017-06-19 21:10 +0200

#1667437 — Re: perf report: fix off-by-one for non-activation frames

FromJan Kratochvil <jan.kratochvil@redhat.com>
Date2017-06-16 08:20 +0200
SubjectRe: perf report: fix off-by-one for non-activation frames
Message-ID<tSSLT-4KG-1@gated-at.bofh.it>
On Mon, 15 May 2017 17:04:44 +0200, Milian Wolff wrote:

commit 1982ad48fc82c284a5cc55697a012d3357e84d01
Author: Milian Wolff <milian.wolff@kdab.com>
Date:   Wed May 24 15:21:25 2017 +0900

> --- a/tools/perf/util/unwind-libdw.c
> +++ b/tools/perf/util/unwind-libdw.c
> @@ -168,12 +168,16 @@ frame_callback(Dwfl_Frame *state, void *arg)
...
> +	if (!isactivation)
> +		--pc;
> +

FYI I find it as a regression a bit:

perf-4.11.4-200.fc25.x86_64
                  30c563 gdb_main (/usr/libexec/gdb)
                   fae48 main (/usr/libexec/gdb)
   0x000055555564ee43 <+51>:    callq  0x55555585f340 <gdb_main(captured_main_args*)>
   0x000055555564ee48 <+56>:    mov    0x18(%rsp),%rcx

perf-4.12.0-0.rc5.git0.1.fc27.x86_64
                  39e32e gdb_main (/usr/libexec/gdb)
                  10b6fa main (/usr/libexec/gdb)
   0x000055555565f6f6 <+54>:    callq  0x5555558f17a0 <gdb_main(captured_main_args*)>
   0x000055555565f6fb <+59>:    mov    0x18(%rsp),%rcx

In backtraces it is correct to show the source line of the calling line - as
perf does now after your fix - but one still should report PC address of the
start of the next instruction.  At least this is what debuggers are used to
do:

#9  gdb_main (args=0x7fffffffe2e0) at ../../gdb/main.c:1257
#10 0x000055555565f6fb in main (argc=<optimized out>, argv=<optimized out>) at ../../gdb/gdb.c:40
   0x000055555565f6f6 <+54>:	callq  0x5555558f17a0 <gdb_main(captured_main_args*)>
=> 0x000055555565f6fb <+59>:	mov    0x18(%rsp),%rcx
Line 40 of "../../gdb/gdb.c" starts at address 0x55555565f6f6 <main(int, char**)+54> and ends at 0x55555565f6fb <main(int, char**)+59>.
Line 41 of "../../gdb/gdb.c" starts at address 0x55555565f6fb <main(int, char**)+59> and ends at 0x55555565f715.

You see "gdb.c:40" and 0x000055555565f6fb in the backtrace despite
0x55555565f6fb is already line 41.

This is also why elfutils reports separately PC and 'isactivation' flag.
Instead of just reporting decreased PC.


Jan

[toc] | [next] | [standalone]

#1667667

FromMilian Wolff <milian.wolff@kdab.com>
Date2017-06-16 14:00 +0200
Message-ID<tSY4W-7Xg-15@gated-at.bofh.it>
In reply to#1667437
On Freitag, 16. Juni 2017 08:14:56 CEST Jan Kratochvil wrote:
> On Mon, 15 May 2017 17:04:44 +0200, Milian Wolff wrote:
> 
> commit 1982ad48fc82c284a5cc55697a012d3357e84d01
> Author: Milian Wolff <milian.wolff@kdab.com>
> Date:   Wed May 24 15:21:25 2017 +0900
> 
> > --- a/tools/perf/util/unwind-libdw.c
> > +++ b/tools/perf/util/unwind-libdw.c
> > @@ -168,12 +168,16 @@ frame_callback(Dwfl_Frame *state, void *arg)
> 
> ...
> 
> > +	if (!isactivation)
> > +		--pc;
> > +
> 
> FYI I find it as a regression a bit:
> 
> perf-4.11.4-200.fc25.x86_64
>                   30c563 gdb_main (/usr/libexec/gdb)
>                    fae48 main (/usr/libexec/gdb)
>    0x000055555564ee43 <+51>:    callq  0x55555585f340
> <gdb_main(captured_main_args*)> 0x000055555564ee48 <+56>:    mov   
> 0x18(%rsp),%rcx
> 
> perf-4.12.0-0.rc5.git0.1.fc27.x86_64
>                   39e32e gdb_main (/usr/libexec/gdb)
>                   10b6fa main (/usr/libexec/gdb)
>    0x000055555565f6f6 <+54>:    callq  0x5555558f17a0
> <gdb_main(captured_main_args*)> 0x000055555565f6fb <+59>:    mov   
> 0x18(%rsp),%rcx
> 
> In backtraces it is correct to show the source line of the calling line - as
> perf does now after your fix - but one still should report PC address of
> the start of the next instruction.  At least this is what debuggers are
> used to do:
> 
> #9  gdb_main (args=0x7fffffffe2e0) at ../../gdb/main.c:1257
> #10 0x000055555565f6fb in main (argc=<optimized out>, argv=<optimized out>)
> at ../../gdb/gdb.c:40 0x000055555565f6f6 <+54>:	callq  0x5555558f17a0
> <gdb_main(captured_main_args*)> => 0x000055555565f6fb <+59>:	mov   
> 0x18(%rsp),%rcx
> Line 40 of "../../gdb/gdb.c" starts at address 0x55555565f6f6 <main(int,
> char**)+54> and ends at 0x55555565f6fb <main(int, char**)+59>. Line 41 of
> "../../gdb/gdb.c" starts at address 0x55555565f6fb <main(int, char**)+59>
> and ends at 0x55555565f715.
> 
> You see "gdb.c:40" and 0x000055555565f6fb in the backtrace despite
> 0x55555565f6fb is already line 41.
> 
> This is also why elfutils reports separately PC and 'isactivation' flag.
> Instead of just reporting decreased PC.

Excuse me, but I'm having trouble following you. The non-GDB backtraces you 
are pasting do not show srcline information. So what exactly is broken? Can 
you show me the differences a bit more clearly? Maybe paste the perf output 
you get now and highlight what you'd expect instead? Best would be an 
accompanying test case that I can use to improve the situation, if possible?

Thanks

-- 
Milian Wolff | milian.wolff@kdab.com | Senior Software Engineer
KDAB (Deutschland) GmbH&Co KG, a KDAB Group company
Tel: +49-30-521325470
KDAB - The Qt Experts

[toc] | [prev] | [next] | [standalone]

#1667679

FromJan Kratochvil <jan.kratochvil@redhat.com>
Date2017-06-16 14:00 +0200
Message-ID<tSY4X-7Xg-39@gated-at.bofh.it>
In reply to#1667667
On Fri, 16 Jun 2017 13:51:37 +0200, Milian Wolff wrote:
> > perf-4.12.0-0.rc5.git0.1.fc27.x86_64
> >                   39e32e gdb_main (/usr/libexec/gdb)
> >                   10b6fa main (/usr/libexec/gdb)
> >    0x000055555565f6f6 <+54>:    callq  0x5555558f17a0 <gdb_main(captured_main_args*)
> >    0x000055555565f6fb <+59>:    mov    0x18(%rsp),%rcx
[...]
> Excuse me, but I'm having trouble following you. The non-GDB backtraces you 
> are pasting do not show srcline information. So what exactly is broken?

There is broken that perf now reports address 10b6fa (corresponding to
relocated address 0x000055555565f6fa) but there is no instruction on address
0x000055555565f6fa.  If you 'objdump -d' it you cannot find any instruction on
adress 0x000055555565f6fa (or on address 0x10b6fa).  There is instruction on
address 0x000055555565f6fb.


> Maybe paste the perf output you get now and highlight what you'd expect
> instead?

Actual:
                  39e32e gdb_main (/usr/libexec/gdb)
                  10b6fa main (/usr/libexec/gdb)
Expected:
                  39e32f gdb_main (/usr/libexec/gdb)
                  10b6fb main (/usr/libexec/gdb)

I agree perf needs to calculate with 39e32e and 10b6fa.  But it should display
to user 39e32f and 10b6fb.


Jan

[toc] | [prev] | [next] | [standalone]

#1668039

FromMilian Wolff <milian.wolff@kdab.com>
Date2017-06-16 22:00 +0200
Message-ID<tT5zr-4Er-1@gated-at.bofh.it>
In reply to#1667679
On Freitag, 16. Juni 2017 13:57:44 CEST Jan Kratochvil wrote:
> On Fri, 16 Jun 2017 13:51:37 +0200, Milian Wolff wrote:
> > > perf-4.12.0-0.rc5.git0.1.fc27.x86_64
> > > 
> > >                   39e32e gdb_main (/usr/libexec/gdb)
> > >                   10b6fa main (/usr/libexec/gdb)
> > >    
> > >    0x000055555565f6f6 <+54>:    callq  0x5555558f17a0
> > >    <gdb_main(captured_main_args*) 0x000055555565f6fb <+59>:    mov   
> > >    0x18(%rsp),%rcx
> 
> [...]
> 
> > Excuse me, but I'm having trouble following you. The non-GDB backtraces
> > you
> > are pasting do not show srcline information. So what exactly is broken?
> 
> There is broken that perf now reports address 10b6fa (corresponding to
> relocated address 0x000055555565f6fa) but there is no instruction on address
> 0x000055555565f6fa.  If you 'objdump -d' it you cannot find any instruction
> on adress 0x000055555565f6fa (or on address 0x10b6fa).  There is
> instruction on address 0x000055555565f6fb.
> 
> > Maybe paste the perf output you get now and highlight what you'd expect
> > instead?
> 
> Actual:
>                   39e32e gdb_main (/usr/libexec/gdb)
>                   10b6fa main (/usr/libexec/gdb)
> Expected:
>                   39e32f gdb_main (/usr/libexec/gdb)
>                   10b6fb main (/usr/libexec/gdb)
> 
> I agree perf needs to calculate with 39e32e and 10b6fa.  But it should
> display to user 39e32f and 10b6fb.

Hmmm this will require some more changes throughout the stack then. I.e. we'll 
have to remember the "isactivation" flag along with the original IP, and only 
apply the offset then when we query for inliners or srcline information. Maybe 
I can pull that off somehow in the patch series I'm working on currently, 
which refactors the whole inline/srcline/callchain logic anyways.

I don't see an easy way to fix the behavior. Does anyone else? So how do we 
deal with this situation in the interim? I'd prefer we keep the current 
"broken" state, as I consider it less broken than what we had before... I 
guess some of the core perf developers should decide how to handle this.

Thanks

-- 
Milian Wolff | milian.wolff@kdab.com | Senior Software Engineer
KDAB (Deutschland) GmbH&Co KG, a KDAB Group company
Tel: +49-30-521325470
KDAB - The Qt Experts

[toc] | [prev] | [next] | [standalone]

#1668195

FromNamhyung Kim <namhyung@kernel.org>
Date2017-06-17 10:00 +0200
Message-ID<tTgOe-3X6-3@gated-at.bofh.it>
In reply to#1668039
On Sat, Jun 17, 2017 at 4:54 AM, Milian Wolff <milian.wolff@kdab.com> wrote:
> On Freitag, 16. Juni 2017 13:57:44 CEST Jan Kratochvil wrote:
>> On Fri, 16 Jun 2017 13:51:37 +0200, Milian Wolff wrote:
>> > > perf-4.12.0-0.rc5.git0.1.fc27.x86_64
>> > >
>> > >                   39e32e gdb_main (/usr/libexec/gdb)
>> > >                   10b6fa main (/usr/libexec/gdb)
>> > >
>> > >    0x000055555565f6f6 <+54>:    callq  0x5555558f17a0
>> > >    <gdb_main(captured_main_args*) 0x000055555565f6fb <+59>:    mov
>> > >    0x18(%rsp),%rcx
>>
>> [...]
>>
>> > Excuse me, but I'm having trouble following you. The non-GDB backtraces
>> > you
>> > are pasting do not show srcline information. So what exactly is broken?
>>
>> There is broken that perf now reports address 10b6fa (corresponding to
>> relocated address 0x000055555565f6fa) but there is no instruction on address
>> 0x000055555565f6fa.  If you 'objdump -d' it you cannot find any instruction
>> on adress 0x000055555565f6fa (or on address 0x10b6fa).  There is
>> instruction on address 0x000055555565f6fb.
>>
>> > Maybe paste the perf output you get now and highlight what you'd expect
>> > instead?
>>
>> Actual:
>>                   39e32e gdb_main (/usr/libexec/gdb)
>>                   10b6fa main (/usr/libexec/gdb)
>> Expected:
>>                   39e32f gdb_main (/usr/libexec/gdb)
>>                   10b6fb main (/usr/libexec/gdb)
>>
>> I agree perf needs to calculate with 39e32e and 10b6fa.  But it should
>> display to user 39e32f and 10b6fb.
>
> Hmmm this will require some more changes throughout the stack then. I.e. we'll
> have to remember the "isactivation" flag along with the original IP, and only
> apply the offset then when we query for inliners or srcline information. Maybe
> I can pull that off somehow in the patch series I'm working on currently,
> which refactors the whole inline/srcline/callchain logic anyways.
>
> I don't see an easy way to fix the behavior. Does anyone else? So how do we
> deal with this situation in the interim? I'd prefer we keep the current
> "broken" state, as I consider it less broken than what we had before... I
> guess some of the core perf developers should decide how to handle this.

Not sure whether it needs be fixed or not.  If we fix it, srcline and
address would not match so it can give its own confusion to users.
Ideally it should display an addressof the instruction before the
address IMHO.

Thanks,
Namhyung

[toc] | [prev] | [next] | [standalone]

#1668196

FromJan Kratochvil <jan.kratochvil@redhat.com>
Date2017-06-17 10:10 +0200
Message-ID<tTgXT-4gp-1@gated-at.bofh.it>
In reply to#1668195
On Sat, 17 Jun 2017 09:56:57 +0200, Namhyung Kim wrote:
> Not sure whether it needs be fixed or not.  If we fix it, srcline and
> address would not match so it can give its own confusion to users.
> Ideally it should display an addressof the instruction before the
> address IMHO.

One can figure million ways how it can behave and each one has its pros and
cons.  I was just describing the current behavior of GDB and LLDB which people
are used to already.


Jan

[toc] | [prev] | [next] | [standalone]

#1668225

FromMilian Wolff <milian.wolff@kdab.com>
Date2017-06-17 13:20 +0200
Message-ID<tTjVL-6mI-1@gated-at.bofh.it>
In reply to#1668196
On Samstag, 17. Juni 2017 10:04:02 CEST Jan Kratochvil wrote:
> On Sat, 17 Jun 2017 09:56:57 +0200, Namhyung Kim wrote:
> > Not sure whether it needs be fixed or not.  If we fix it, srcline and
> > address would not match so it can give its own confusion to users.
> > Ideally it should display an addressof the instruction before the
> > address IMHO.
> 
> One can figure million ways how it can behave and each one has its pros and
> cons.  I was just describing the current behavior of GDB and LLDB which
> people are used to already.

Personally, I agree with Jan that we should mimick existing tool's behavior. I 
just fear that it's not trivial to do it with the current code base...

-- 
Milian Wolff | milian.wolff@kdab.com | Senior Software Engineer
KDAB (Deutschland) GmbH&Co KG, a KDAB Group company
Tel: +49-30-521325470
KDAB - The Qt Experts

[toc] | [prev] | [next] | [standalone]

#1669719

FromArnaldo Carvalho de Melo <acme@redhat.com>
Date2017-06-19 21:10 +0200
Message-ID<tUadI-6Iy-13@gated-at.bofh.it>
In reply to#1668225
Em Sat, Jun 17, 2017 at 01:13:11PM +0200, Milian Wolff escreveu:
> On Samstag, 17. Juni 2017 10:04:02 CEST Jan Kratochvil wrote:
> > On Sat, 17 Jun 2017 09:56:57 +0200, Namhyung Kim wrote:
> > > Not sure whether it needs be fixed or not.  If we fix it, srcline and
> > > address would not match so it can give its own confusion to users.
> > > Ideally it should display an addressof the instruction before the
> > > address IMHO.
> > 
> > One can figure million ways how it can behave and each one has its pros and
> > cons.  I was just describing the current behavior of GDB and LLDB which
> > people are used to already.
> 
> Personally, I agree with Jan that we should mimick existing tool's behavior. I 
> just fear that it's not trivial to do it with the current code base...

But we agree it is a worthwhile change (have backtraces in perf match
what gdb, etc show), right?

If you can, please try to do this, your attempt will help us understand
more the extent of the changes needed and perhaps someonw can come up
with simplifications...

- Arnaldo

[toc] | [prev] | [standalone]

Back to top | Article view | linux.kernel

csiph-web