* [PATCH] perf annotate: Numeric assembly labels cause incorrect annotation
@ 2012-02-07 3:55 Anton Blanchard
2012-02-07 14:25 ` Eric B Munson
2012-02-07 14:40 ` Arnaldo Carvalho de Melo
0 siblings, 2 replies; 7+ messages in thread
From: Anton Blanchard @ 2012-02-07 3:55 UTC (permalink / raw)
To: Peter Zijlstra, Paul Mackerras, Ingo Molnar,
Arnaldo Carvalho de Melo, Frederic Weisbecker, emunson, imunsie,
eranian
Cc: linux-kernel
A perf annotate of a kernel function written in assembly shows
very strange percentages:
: _GLOBAL(__copy_tofrom_user_base)
...
: addi r3,r3,1
99.67 : c00000000004d78c: addi r3,r3,1
:
0.00 : 1: bf cr7*4+2,2f
0.07 : c00000000004d790: bne- cr7,c00000000004d7a4
: err1; lhz r0,0(r4)
0.00 : c00000000004d794: lhz r0,0(r4)
: addi r4,r4,2
0.00 : c00000000004d798: addi r4,r4,2
: err1; sth r0,0(r3)
0.00 : c00000000004d79c: sth r0,0(r3)
: addi r3,r3,2
99.60 : c00000000004d7a0: addi r3,r3,2
:
0.00 : 2: bf cr7*4+1,3f
0.12 : c00000000004d7a4: ble- cr7,c00000000004d7b8
: err1; lwz r0,0(r4)
0.00 : c00000000004d7a8: lwz r0,0(r4)
: addi r4,r4,4
0.00 : c00000000004d7ac: addi r4,r4,4
: err1; stw r0,0(r3)
0.00 : c00000000004d7b0: stw r0,0(r3)
: addi r3,r3,4
99.48 : c00000000004d7b4: addi r3,r3,4
~300% in one function. Urgh.
This is caused by the way we parse objdump -S output, eg:
addi r3,r3,1
c00000000004d78c: addi r3,r3,1
1: bf cr7*4+2,2f
c00000000004d790: bne- cr7,c00000000004d7a4
We assume the asm label (1:) is an address, compute a bogus offset
into the function and then screw up the matching of samples to lines.
I notice this also fails with c inline assembly in a similar
manner.
We already have a sanity check that the address is not beyond the end
of the function, so add a check against the start too.
Signed-off-by: Anton Blanchard <anton@samba.org>
---
Cc: <stable@kernel.org>
Index: linux-tip/tools/perf/util/annotate.c
===================================================================
--- linux-tip.orig/tools/perf/util/annotate.c 2012-01-09 17:45:09.056373433 +1100
+++ linux-tip/tools/perf/util/annotate.c 2012-02-07 13:53:01.610970209 +1100
@@ -244,7 +244,7 @@ static int symbol__parse_objdump_line(st
end = map__rip_2objdump(map, sym->end);
offset = line_ip - start;
- if (offset < 0 || (u64)line_ip > end)
+ if (offset < 0 || (u64)line_ip < start || (u64)line_ip > end)
offset = -1;
}
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: [PATCH] perf annotate: Numeric assembly labels cause incorrect annotation
2012-02-07 3:55 [PATCH] perf annotate: Numeric assembly labels cause incorrect annotation Anton Blanchard
@ 2012-02-07 14:25 ` Eric B Munson
2012-02-07 14:40 ` Arnaldo Carvalho de Melo
1 sibling, 0 replies; 7+ messages in thread
From: Eric B Munson @ 2012-02-07 14:25 UTC (permalink / raw)
To: Anton Blanchard
Cc: Peter Zijlstra, Paul Mackerras, Ingo Molnar,
Arnaldo Carvalho de Melo, Frederic Weisbecker, imunsie, eranian,
linux-kernel
[-- Attachment #1: Type: text/plain, Size: 2133 bytes --]
On Tue, 07 Feb 2012, Anton Blanchard wrote:
>
> A perf annotate of a kernel function written in assembly shows
> very strange percentages:
>
> : _GLOBAL(__copy_tofrom_user_base)
>
> ...
>
> : addi r3,r3,1
> 99.67 : c00000000004d78c: addi r3,r3,1
> :
> 0.00 : 1: bf cr7*4+2,2f
> 0.07 : c00000000004d790: bne- cr7,c00000000004d7a4
> : err1; lhz r0,0(r4)
> 0.00 : c00000000004d794: lhz r0,0(r4)
> : addi r4,r4,2
> 0.00 : c00000000004d798: addi r4,r4,2
> : err1; sth r0,0(r3)
> 0.00 : c00000000004d79c: sth r0,0(r3)
> : addi r3,r3,2
> 99.60 : c00000000004d7a0: addi r3,r3,2
> :
> 0.00 : 2: bf cr7*4+1,3f
> 0.12 : c00000000004d7a4: ble- cr7,c00000000004d7b8
> : err1; lwz r0,0(r4)
> 0.00 : c00000000004d7a8: lwz r0,0(r4)
> : addi r4,r4,4
> 0.00 : c00000000004d7ac: addi r4,r4,4
> : err1; stw r0,0(r3)
> 0.00 : c00000000004d7b0: stw r0,0(r3)
> : addi r3,r3,4
> 99.48 : c00000000004d7b4: addi r3,r3,4
>
> ~300% in one function. Urgh.
>
> This is caused by the way we parse objdump -S output, eg:
>
> addi r3,r3,1
> c00000000004d78c: addi r3,r3,1
>
> 1: bf cr7*4+2,2f
> c00000000004d790: bne- cr7,c00000000004d7a4
>
> We assume the asm label (1:) is an address, compute a bogus offset
> into the function and then screw up the matching of samples to lines.
> I notice this also fails with c inline assembly in a similar
> manner.
>
> We already have a sanity check that the address is not beyond the end
> of the function, so add a check against the start too.
>
> Signed-off-by: Anton Blanchard <anton@samba.org>
Acked-by: Eric B Munson <emunson@mgebm.net>
[-- Attachment #2: Digital signature --]
[-- Type: application/pgp-signature, Size: 836 bytes --]
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: [PATCH] perf annotate: Numeric assembly labels cause incorrect annotation
2012-02-07 3:55 [PATCH] perf annotate: Numeric assembly labels cause incorrect annotation Anton Blanchard
2012-02-07 14:25 ` Eric B Munson
@ 2012-02-07 14:40 ` Arnaldo Carvalho de Melo
2012-02-09 10:10 ` Mike Galbraith
1 sibling, 1 reply; 7+ messages in thread
From: Arnaldo Carvalho de Melo @ 2012-02-07 14:40 UTC (permalink / raw)
To: Anton Blanchard
Cc: Mike Galbraith, Peter Zijlstra, Paul Mackerras, Ingo Molnar,
Frederic Weisbecker, emunson, imunsie, eranian, linux-kernel
Em Tue, Feb 07, 2012 at 02:55:35PM +1100, Anton Blanchard escreveu:
>
> A perf annotate of a kernel function written in assembly shows
> very strange percentages:
Thanks! I think this is the same problem Mike Galbraith noticed and
reported me (I guess that was in a private message), Mike, can you
please test it so that I can add more Foo-by stamps to this one?
- Arnaldo
> : _GLOBAL(__copy_tofrom_user_base)
>
> ...
>
> : addi r3,r3,1
> 99.67 : c00000000004d78c: addi r3,r3,1
> :
> 0.00 : 1: bf cr7*4+2,2f
> 0.07 : c00000000004d790: bne- cr7,c00000000004d7a4
> : err1; lhz r0,0(r4)
> 0.00 : c00000000004d794: lhz r0,0(r4)
> : addi r4,r4,2
> 0.00 : c00000000004d798: addi r4,r4,2
> : err1; sth r0,0(r3)
> 0.00 : c00000000004d79c: sth r0,0(r3)
> : addi r3,r3,2
> 99.60 : c00000000004d7a0: addi r3,r3,2
> :
> 0.00 : 2: bf cr7*4+1,3f
> 0.12 : c00000000004d7a4: ble- cr7,c00000000004d7b8
> : err1; lwz r0,0(r4)
> 0.00 : c00000000004d7a8: lwz r0,0(r4)
> : addi r4,r4,4
> 0.00 : c00000000004d7ac: addi r4,r4,4
> : err1; stw r0,0(r3)
> 0.00 : c00000000004d7b0: stw r0,0(r3)
> : addi r3,r3,4
> 99.48 : c00000000004d7b4: addi r3,r3,4
>
> ~300% in one function. Urgh.
>
> This is caused by the way we parse objdump -S output, eg:
>
> addi r3,r3,1
> c00000000004d78c: addi r3,r3,1
>
> 1: bf cr7*4+2,2f
> c00000000004d790: bne- cr7,c00000000004d7a4
>
> We assume the asm label (1:) is an address, compute a bogus offset
> into the function and then screw up the matching of samples to lines.
> I notice this also fails with c inline assembly in a similar
> manner.
>
> We already have a sanity check that the address is not beyond the end
> of the function, so add a check against the start too.
>
> Signed-off-by: Anton Blanchard <anton@samba.org>
> ---
> Cc: <stable@kernel.org>
>
> Index: linux-tip/tools/perf/util/annotate.c
> ===================================================================
> --- linux-tip.orig/tools/perf/util/annotate.c 2012-01-09 17:45:09.056373433 +1100
> +++ linux-tip/tools/perf/util/annotate.c 2012-02-07 13:53:01.610970209 +1100
> @@ -244,7 +244,7 @@ static int symbol__parse_objdump_line(st
> end = map__rip_2objdump(map, sym->end);
>
> offset = line_ip - start;
> - if (offset < 0 || (u64)line_ip > end)
> + if (offset < 0 || (u64)line_ip < start || (u64)line_ip > end)
> offset = -1;
> }
>
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: [PATCH] perf annotate: Numeric assembly labels cause incorrect annotation
2012-02-07 14:40 ` Arnaldo Carvalho de Melo
@ 2012-02-09 10:10 ` Mike Galbraith
2012-02-09 13:31 ` Ingo Molnar
0 siblings, 1 reply; 7+ messages in thread
From: Mike Galbraith @ 2012-02-09 10:10 UTC (permalink / raw)
To: Arnaldo Carvalho de Melo
Cc: Anton Blanchard, Peter Zijlstra, Paul Mackerras, Ingo Molnar,
Frederic Weisbecker, emunson, imunsie, eranian, linux-kernel
On Tue, 2012-02-07 at 12:40 -0200, Arnaldo Carvalho de Melo wrote:
> Em Tue, Feb 07, 2012 at 02:55:35PM +1100, Anton Blanchard escreveu:
> >
> > A perf annotate of a kernel function written in assembly shows
> > very strange percentages:
>
> Thanks! I think this is the same problem Mike Galbraith noticed and
> reported me (I guess that was in a private message), Mike, can you
> please test it so that I can add more Foo-by stamps to this one?
Sorry for the slow response (bz bz).
I don't see that problem, but perf top annotation isn't working properly
in tip at least. It seems to have forgotten how to average, seems to be
clearing hit counts at every screen refresh or something.
-Mike
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: [PATCH] perf annotate: Numeric assembly labels cause incorrect annotation
2012-02-09 10:10 ` Mike Galbraith
@ 2012-02-09 13:31 ` Ingo Molnar
2012-02-09 14:50 ` Mike Galbraith
2012-02-09 15:50 ` Mike Galbraith
0 siblings, 2 replies; 7+ messages in thread
From: Ingo Molnar @ 2012-02-09 13:31 UTC (permalink / raw)
To: Mike Galbraith
Cc: Arnaldo Carvalho de Melo, Anton Blanchard, Peter Zijlstra,
Paul Mackerras, Frederic Weisbecker, emunson, imunsie, eranian,
linux-kernel
* Mike Galbraith <efault@gmx.de> wrote:
> On Tue, 2012-02-07 at 12:40 -0200, Arnaldo Carvalho de Melo wrote:
> > Em Tue, Feb 07, 2012 at 02:55:35PM +1100, Anton Blanchard escreveu:
> > >
> > > A perf annotate of a kernel function written in assembly shows
> > > very strange percentages:
> >
> > Thanks! I think this is the same problem Mike Galbraith noticed and
> > reported me (I guess that was in a private message), Mike, can you
> > please test it so that I can add more Foo-by stamps to this one?
>
> Sorry for the slow response (bz bz).
>
> I don't see that problem, but perf top annotation isn't
> working properly in tip at least. It seems to have forgotten
> how to average, seems to be clearing hit counts at every
> screen refresh or something.
hm, seems to work fine here. We used to have such a bug recently
(as of a few weeks [days?] ago), but latest -tip does not show
those symptoms.
Thanks,
Ingo
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: [PATCH] perf annotate: Numeric assembly labels cause incorrect annotation
2012-02-09 13:31 ` Ingo Molnar
@ 2012-02-09 14:50 ` Mike Galbraith
2012-02-09 15:50 ` Mike Galbraith
1 sibling, 0 replies; 7+ messages in thread
From: Mike Galbraith @ 2012-02-09 14:50 UTC (permalink / raw)
To: Ingo Molnar
Cc: Arnaldo Carvalho de Melo, Anton Blanchard, Peter Zijlstra,
Paul Mackerras, Frederic Weisbecker, emunson, imunsie, eranian,
linux-kernel
On Thu, 2012-02-09 at 14:31 +0100, Ingo Molnar wrote:
> * Mike Galbraith <efault@gmx.de> wrote:
> > I don't see that problem, but perf top annotation isn't
> > working properly in tip at least. It seems to have forgotten
> > how to average, seems to be clearing hit counts at every
> > screen refresh or something.
>
> hm, seems to work fine here. We used to have such a bug recently
> (as of a few weeks [days?] ago), but latest -tip does not show
> those symptoms.
Fresh pulled from git server:
marge:/usr/local/src/kernel/git/linux-3.0-tip # git describe
v3.3-rc2-1940-g8819807
marge:/usr/local/src/kernel/git/linux-3.0-tip # perf --version
perf version 3.3.rc2.1940.g881980.dirty
get server:
git@marge:~/linux-2.6> git checkout x86-tip
Switched to branch 'x86-tip'
Your branch is ahead of 'x86-tip/master' by 566 commits
Aha, need to drop/re-checkout again. Have to be careful with tip, it
wiggles around on ya :)
-Mike
^ permalink raw reply [flat|nested] 7+ messages in thread
* Re: [PATCH] perf annotate: Numeric assembly labels cause incorrect annotation
2012-02-09 13:31 ` Ingo Molnar
2012-02-09 14:50 ` Mike Galbraith
@ 2012-02-09 15:50 ` Mike Galbraith
1 sibling, 0 replies; 7+ messages in thread
From: Mike Galbraith @ 2012-02-09 15:50 UTC (permalink / raw)
To: Ingo Molnar
Cc: Arnaldo Carvalho de Melo, Anton Blanchard, Peter Zijlstra,
Paul Mackerras, Frederic Weisbecker, emunson, imunsie, eranian,
linux-kernel
On Thu, 2012-02-09 at 14:31 +0100, Ingo Molnar wrote:
> * Mike Galbraith <efault@gmx.de> wrote:
>
> > On Tue, 2012-02-07 at 12:40 -0200, Arnaldo Carvalho de Melo wrote:
> > > Em Tue, Feb 07, 2012 at 02:55:35PM +1100, Anton Blanchard escreveu:
> > > >
> > > > A perf annotate of a kernel function written in assembly shows
> > > > very strange percentages:
> > >
> > > Thanks! I think this is the same problem Mike Galbraith noticed and
> > > reported me (I guess that was in a private message), Mike, can you
> > > please test it so that I can add more Foo-by stamps to this one?
> >
> > Sorry for the slow response (bz bz).
> >
> > I don't see that problem, but perf top annotation isn't
> > working properly in tip at least. It seems to have forgotten
> > how to average, seems to be clearing hit counts at every
> > screen refresh or something.
>
> hm, seems to work fine here. We used to have such a bug recently
> (as of a few weeks [days?] ago), but latest -tip does not show
> those symptoms.
Build dependency buglet snuck into tip config, but annotating master
v3.3-rc3-0-gd65b4e9 with tips patched perf worked fine.
Tested-by: Mike Galbraith <efault@gmx.de>
marge:/usr/local/src/kernel/linux-3.x-tip # make -j4
scripts/kconfig/conf --silentoldconfig Kconfig
warning: (USB_WHCI_HCD && USB_HWA_HCD) selects USB_WUSB which has unmet direct dependencies (USB_SUPPORT && EXPERIMENTAL && USB && PCI && UWB)
warning: (USB_WHCI_HCD) selects UWB_WHCI which has unmet direct dependencies (UWB && PCI)
warning: (USB_WHCI_HCD && USB_HWA_HCD) selects USB_WUSB which has unmet direct dependencies (USB_SUPPORT && EXPERIMENTAL && USB && PCI && UWB)
warning: (USB_WHCI_HCD) selects UWB_WHCI which has unmet direct dependencies (UWB && PCI)
make[1]: Nothing to be done for `all'.
CHK include/linux/version.h
CHK include/generated/utsrelease.h
CALL scripts/checksyscalls.sh
CHK include/generated/compile.h
GZIP kernel/config_data.gz
CHK kernel/config_data.h
Building modules, stage 2.
Kernel: arch/x86/boot/bzImage is ready (#2077)
MODPOST 611 modules
ERROR: "uwb_rsv_establish" [drivers/usb/wusbcore/wusbcore.ko] undefined!
ERROR: "uwb_pal_register" [drivers/usb/wusbcore/wusbcore.ko] undefined!
ERROR: "uwb_rsv_get_usable_mas" [drivers/usb/wusbcore/wusbcore.ko] undefined!
ERROR: "uwb_rsv_destroy" [drivers/usb/wusbcore/wusbcore.ko] undefined!
ERROR: "uwb_radio_stop" [drivers/usb/wusbcore/wusbcore.ko] undefined!
ERROR: "uwb_rsv_terminate" [drivers/usb/wusbcore/wusbcore.ko] undefined!
ERROR: "uwb_pal_unregister" [drivers/usb/wusbcore/wusbcore.ko] undefined!
ERROR: "uwb_pal_init" [drivers/usb/wusbcore/wusbcore.ko] undefined!
ERROR: "uwb_rc_reset_all" [drivers/usb/wusbcore/wusbcore.ko] undefined!
ERROR: "uwb_radio_start" [drivers/usb/wusbcore/wusbcore.ko] undefined!
ERROR: "uwb_rsv_create" [drivers/usb/wusbcore/wusbcore.ko] undefined!
ERROR: "uwb_rc_put" [drivers/usb/host/whci/whci-hcd.ko] undefined!
ERROR: "uwb_rc_get_by_grandpa" [drivers/usb/host/whci/whci-hcd.ko] undefined!
ERROR: "__umc_driver_register" [drivers/usb/host/whci/whci-hcd.ko] undefined!
ERROR: "umc_driver_unregister" [drivers/usb/host/whci/whci-hcd.ko] undefined!
ERROR: "whci_wait_for" [drivers/usb/host/whci/whci-hcd.ko] undefined!
make[1]: *** [__modpost] Error 1
make: *** [modules] Error 2
marge:/usr/local/src/kernel/linux-3.x-tip # git describe
v3.3-rc2-1377-gf4ab688
^ permalink raw reply [flat|nested] 7+ messages in thread
end of thread, other threads:[~2012-02-09 15:50 UTC | newest]
Thread overview: 7+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2012-02-07 3:55 [PATCH] perf annotate: Numeric assembly labels cause incorrect annotation Anton Blanchard
2012-02-07 14:25 ` Eric B Munson
2012-02-07 14:40 ` Arnaldo Carvalho de Melo
2012-02-09 10:10 ` Mike Galbraith
2012-02-09 13:31 ` Ingo Molnar
2012-02-09 14:50 ` Mike Galbraith
2012-02-09 15:50 ` Mike Galbraith
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).