I'm way below my depth here, but I'd like to use the perf tool to see where a program is spending its time. Unfortunately, the recipe here http://hackage.haskell.org/trac/ghc/wiki/Debugging/LowLevelProfiling/Perf isn't working for me. I get output like this instead 90.20% drbg_test drbg_test [.] 0x2515ef 5.71% drbg_test [kernel.kallsyms] [k] 0xffffffff8103e0ca 1.53% drbg_test libc-2.15.so [.] bsearch 1.02% drbg_test libc-2.15.so [.] 0x9194c 0.43% drbg_test libgmp.so.10.0.2 [.] __gmpz_mul_2exp 0.27% drbg_test libgmp.so.10.0.2 [.] __gmpz_add 0.16% drbg_test [vdso] [.] 0x7fffd3d25983 0.16% drbg_test libgmp.so.10.0.2 [.] __gmpn_lshift 0.10% drbg_test libgmp.so.10.0.2 [.] 0x13565 0.05% drbg_test libgmp.so.10.0.2 [.] __gmpz_init 0.05% drbg_test libc-2.15.so [.] __select 0.05% drbg_test libgmp.so.10.0.2 [.] __gmpn_modexact_1_odd 0.05% drbg_test libgmp.so.10.0.2 [.] __gmpz_realloc 0.05% drbg_test libc-2.15.so [.] __errno_location 0.05% drbg_test drbg_test [.] __gmpz_init@plt 0.05% drbg_test librt-2.15.so [.] clock_gettime 0.05% drbg_test libgmp.so.10.0.2 [.] __gmpn_add_n Again --- below my depth here --- but I don't know how to investigate what 0x2515ef indicates. Does anyone have any pointers? I was hoping that the address would be a nice RTS-ish symbol, like in the Wiki's examples. Thanks for your time.
On Fri, Feb 15, 2013 at 10:05 AM, Nicolas Frisby <nicolas.frisby@gmail.com>wrote:
I'm way below my depth here, but I'd like to use the perf tool to see where a program is spending its time.
Unfortunately, the recipe here
http://hackage.haskell.org/trac/ghc/wiki/Debugging/LowLevelProfiling/Perf
isn't working for me. I get output like this instead
90.20% drbg_test drbg_test [.] 0x2515ef 5.71% drbg_test [kernel.kallsyms] [k] 0xffffffff8103e0ca 1.53% drbg_test libc-2.15.so [.] bsearch 1.02% drbg_test libc-2.15.so [.] 0x9194c 0.43% drbg_test libgmp.so.10.0.2 [.] __gmpz_mul_2exp 0.27% drbg_test libgmp.so.10.0.2 [.] __gmpz_add 0.16% drbg_test [vdso] [.] 0x7fffd3d25983 0.16% drbg_test libgmp.so.10.0.2 [.] __gmpn_lshift 0.10% drbg_test libgmp.so.10.0.2 [.] 0x13565 0.05% drbg_test libgmp.so.10.0.2 [.] __gmpz_init 0.05% drbg_test libc-2.15.so [.] __select 0.05% drbg_test libgmp.so.10.0.2 [.] __gmpn_modexact_1_odd 0.05% drbg_test libgmp.so.10.0.2 [.] __gmpz_realloc 0.05% drbg_test libc-2.15.so [.] __errno_location 0.05% drbg_test drbg_test [.] __gmpz_init@plt 0.05% drbg_test librt-2.15.so [.] clock_gettime 0.05% drbg_test libgmp.so.10.0.2 [.] __gmpn_add_n
Again --- below my depth here --- but I don't know how to investigate what 0x2515ef indicates. Does anyone have any pointers?
I was hoping that the address would be a nice RTS-ish symbol, like in the Wiki's examples.
I thought I fixed this issue (at least in the native backend). What was missing before was .size assembler directives that would let tools like perf know where a function started and ended. See this commit https://github.com/ghc/ghc/commit/32f24ddfd9549010dd345733c6f46f67196cacf6 Perhaps it broke at some point? Are you using the x86 backend?
I'm not passing any flags related to code generation, I don't think. $HC -H64m -O -Rghc-timing -package array -H32m -hisuf hi -O1 -rtsopts -c Main.hs -o Main.o So that'd just be the native code generator, right?. $ uname -a Linux cam-05-unx 3.2.0-35-generic #55-Ubuntu SMP Wed Dec 5 17:42:16 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux Is there a objdump-ish way to directly look for these .size directives? Thanks Johan. On Fri, Feb 15, 2013 at 6:18 PM, Johan Tibell <johan.tibell@gmail.com>wrote:
On Fri, Feb 15, 2013 at 10:05 AM, Nicolas Frisby <nicolas.frisby@gmail.com
wrote:
I'm way below my depth here, but I'd like to use the perf tool to see where a program is spending its time.
Unfortunately, the recipe here
http://hackage.haskell.org/trac/ghc/wiki/Debugging/LowLevelProfiling/Perf
isn't working for me. I get output like this instead
90.20% drbg_test drbg_test [.] 0x2515ef 5.71% drbg_test [kernel.kallsyms] [k] 0xffffffff8103e0ca 1.53% drbg_test libc-2.15.so [.] bsearch 1.02% drbg_test libc-2.15.so [.] 0x9194c 0.43% drbg_test libgmp.so.10.0.2 [.] __gmpz_mul_2exp 0.27% drbg_test libgmp.so.10.0.2 [.] __gmpz_add 0.16% drbg_test [vdso] [.] 0x7fffd3d25983 0.16% drbg_test libgmp.so.10.0.2 [.] __gmpn_lshift 0.10% drbg_test libgmp.so.10.0.2 [.] 0x13565 0.05% drbg_test libgmp.so.10.0.2 [.] __gmpz_init 0.05% drbg_test libc-2.15.so [.] __select 0.05% drbg_test libgmp.so.10.0.2 [.] __gmpn_modexact_1_odd 0.05% drbg_test libgmp.so.10.0.2 [.] __gmpz_realloc 0.05% drbg_test libc-2.15.so [.] __errno_location 0.05% drbg_test drbg_test [.] __gmpz_init@plt 0.05% drbg_test librt-2.15.so [.] clock_gettime 0.05% drbg_test libgmp.so.10.0.2 [.] __gmpn_add_n
Again --- below my depth here --- but I don't know how to investigate what 0x2515ef indicates. Does anyone have any pointers?
I was hoping that the address would be a nice RTS-ish symbol, like in the Wiki's examples.
I thought I fixed this issue (at least in the native backend). What was missing before was .size assembler directives that would let tools like perf know where a function started and ended. See this commit https://github.com/ghc/ghc/commit/32f24ddfd9549010dd345733c6f46f67196cacf6
Perhaps it broke at some point? Are you using the x86 backend?
On Fri, Feb 15, 2013 at 10:24 AM, Nicolas Frisby <nicolas.frisby@gmail.com>wrote:
I'm not passing any flags related to code generation, I don't think.
$HC -H64m -O -Rghc-timing -package array -H32m -hisuf hi -O1 -rtsopts -c Main.hs -o Main.o
So that'd just be the native code generator, right?.
$ uname -a Linux cam-05-unx 3.2.0-35-generic #55-Ubuntu SMP Wed Dec 5 17:42:16 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux
Is there a objdump-ish way to directly look for these .size directives?
Thanks Johan.
If you tell GHC to keep all temporary file you could look in the .S files for the .size directive. It could be that I missed some place where we ought to put a .size directive. Are you doing dynamic linking?
No, nothing fancy. It's just a nofib program. I am seeing the .size directives in the .s files. And objdump -S gives output like this: 0000000000000368 <c2hw_info>: 368: 48 83 e3 07 and $0x7,%rbx 36c: 48 83 fb 02 cmp $0x2,%rbx 370: 0f 83 96 00 00 00 jae 40c <c2hA_info+0x5c> 376: 48 8b 45 08 mov 0x8(%rbp),%rax ... so it's just perf that's going awry? ... investigating perf ... This might be my issue: http://us.generation-nt.com/answer/tip-perf-urgent-perf-symbols-handle-proc-... Now I just have to decode all of that! On Fri, Feb 15, 2013 at 6:48 PM, Johan Tibell <johan.tibell@gmail.com>wrote:
On Fri, Feb 15, 2013 at 10:24 AM, Nicolas Frisby <nicolas.frisby@gmail.com
wrote:
I'm not passing any flags related to code generation, I don't think.
$HC -H64m -O -Rghc-timing -package array -H32m -hisuf hi -O1 -rtsopts -c Main.hs -o Main.o
So that'd just be the native code generator, right?.
$ uname -a Linux cam-05-unx 3.2.0-35-generic #55-Ubuntu SMP Wed Dec 5 17:42:16 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux
Is there a objdump-ish way to directly look for these .size directives?
Thanks Johan.
If you tell GHC to keep all temporary file you could look in the .S files for the .size directive. It could be that I missed some place where we ought to put a .size directive. Are you doing dynamic linking?
Ah, looks like the symbol information exists in the .o files, but not in my actual executable. Could I invoke ld manually with some incantation to preserve the function symbols? On Fri, Feb 15, 2013 at 7:18 PM, Nicolas Frisby <nicolas.frisby@gmail.com>wrote:
No, nothing fancy. It's just a nofib program.
I am seeing the .size directives in the .s files. And objdump -S gives output like this:
0000000000000368 <c2hw_info>: 368: 48 83 e3 07 and $0x7,%rbx 36c: 48 83 fb 02 cmp $0x2,%rbx 370: 0f 83 96 00 00 00 jae 40c <c2hA_info+0x5c> 376: 48 8b 45 08 mov 0x8(%rbp),%rax ...
so it's just perf that's going awry?
... investigating perf ...
This might be my issue:
http://us.generation-nt.com/answer/tip-perf-urgent-perf-symbols-handle-proc-...
Now I just have to decode all of that!
On Fri, Feb 15, 2013 at 6:48 PM, Johan Tibell <johan.tibell@gmail.com>wrote:
On Fri, Feb 15, 2013 at 10:24 AM, Nicolas Frisby < nicolas.frisby@gmail.com> wrote:
I'm not passing any flags related to code generation, I don't think.
$HC -H64m -O -Rghc-timing -package array -H32m -hisuf hi -O1 -rtsopts -c Main.hs -o Main.o
So that'd just be the native code generator, right?.
$ uname -a Linux cam-05-unx 3.2.0-35-generic #55-Ubuntu SMP Wed Dec 5 17:42:16 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux
Is there a objdump-ish way to directly look for these .size directives?
Thanks Johan.
If you tell GHC to keep all temporary file you could look in the .S files for the .size directive. It could be that I missed some place where we ought to put a .size directive. Are you doing dynamic linking?
Try invoking ghc with -optl-g? Geoff From: ghc-devs-bounces@haskell.org [mailto:ghc-devs-bounces@haskell.org] On Behalf Of Nicolas Frisby Sent: Friday, February 15, 2013 7:41 PM To: Johan Tibell Cc: ghc-devs@haskell.org Subject: Re: low-level profiling Ah, looks like the symbol information exists in the .o files, but not in my actual executable. Could I invoke ld manually with some incantation to preserve the function symbols? On Fri, Feb 15, 2013 at 7:18 PM, Nicolas Frisby <nicolas.frisby@gmail.com<mailto:nicolas.frisby@gmail.com>> wrote: No, nothing fancy. It's just a nofib program. I am seeing the .size directives in the .s files. And objdump -S gives output like this: 0000000000000368 <c2hw_info>: 368: 48 83 e3 07 and $0x7,%rbx 36c: 48 83 fb 02 cmp $0x2,%rbx 370: 0f 83 96 00 00 00 jae 40c <c2hA_info+0x5c> 376: 48 8b 45 08 mov 0x8(%rbp),%rax ... so it's just perf that's going awry? ... investigating perf ... This might be my issue: http://us.generation-nt.com/answer/tip-perf-urgent-perf-symbols-handle-proc-... Now I just have to decode all of that! On Fri, Feb 15, 2013 at 6:48 PM, Johan Tibell <johan.tibell@gmail.com<mailto:johan.tibell@gmail.com>> wrote: On Fri, Feb 15, 2013 at 10:24 AM, Nicolas Frisby <nicolas.frisby@gmail.com<mailto:nicolas.frisby@gmail.com>> wrote: I'm not passing any flags related to code generation, I don't think. $HC -H64m -O -Rghc-timing -package array -H32m -hisuf hi -O1 -rtsopts -c Main.hs -o Main.o So that'd just be the native code generator, right?. $ uname -a Linux cam-05-unx 3.2.0-35-generic #55-Ubuntu SMP Wed Dec 5 17:42:16 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux Is there a objdump-ish way to directly look for these .size directives? Thanks Johan. If you tell GHC to keep all temporary file you could look in the .S files for the .size directive. It could be that I missed some place where we ought to put a .size directive. Are you doing dynamic linking?
Thanks for rallying everyone! I made a bit of a breakthrough while trying to pinpoint where the linker is invoked. Here's the situation: * If I use nofib's "make" command to build the text, the executable does not have the function symbols in its .text section. The .o files do have them. * If I use ghc --make instead, the symbols survive in the executable. I'm not up to sleuthing out the details at the moment. Should I open a Trac ticket? On Fri, Feb 15, 2013 at 7:55 PM, Geoffrey Mainland <gmainlan@microsoft.com>wrote:
Try invoking ghc with -optl-g?****
** **
Geoff****
** **
*From:* ghc-devs-bounces@haskell.org [mailto:ghc-devs-bounces@haskell.org] *On Behalf Of *Nicolas Frisby *Sent:* Friday, February 15, 2013 7:41 PM *To:* Johan Tibell *Cc:* ghc-devs@haskell.org *Subject:* Re: low-level profiling****
** **
Ah, looks like the symbol information exists in the .o files, but not in my actual executable. Could I invoke ld manually with some incantation to preserve the function symbols?****
****
****
** **
On Fri, Feb 15, 2013 at 7:18 PM, Nicolas Frisby <nicolas.frisby@gmail.com> wrote:****
No, nothing fancy. It's just a nofib program.****
****
I am seeing the .size directives in the .s files. And objdump -S gives output like this:****
****
0000000000000368 <c2hw_info>: 368: 48 83 e3 07 and $0x7,%rbx 36c: 48 83 fb 02 cmp $0x2,%rbx 370: 0f 83 96 00 00 00 jae 40c <c2hA_info+0x5c> 376: 48 8b 45 08 mov 0x8(%rbp),%rax****
...****
****
so it's just perf that's going awry? ****
****
... investigating perf ...****
****
This might be my issue:****
****
http://us.generation-nt.com/answer/tip-perf-urgent-perf-symbols-handle-proc-... ****
****
Now I just have to decode all of that!****
** **
On Fri, Feb 15, 2013 at 6:48 PM, Johan Tibell <johan.tibell@gmail.com> wrote:****
On Fri, Feb 15, 2013 at 10:24 AM, Nicolas Frisby <nicolas.frisby@gmail.com> wrote:****
I'm not passing any flags related to code generation, I don't think.****
****
$HC -H64m -O -Rghc-timing -package array -H32m -hisuf hi -O1 -rtsopts -c Main.hs -o Main.o****
****
So that'd just be the native code generator, right?.****
****
$ uname -a Linux cam-05-unx 3.2.0-35-generic #55-Ubuntu SMP Wed Dec 5 17:42:16 UTC 2012 x86_64 x86_64 x86_64 GNU/Linux****
****
Is there a objdump-ish way to directly look for these .size directives?*** *
****
Thanks Johan.****
** **
If you tell GHC to keep all temporary file you could look in the .S files for the .size directive. It could be that I missed some place where we ought to put a .size directive. Are you doing dynamic linking? ****
** **
** **
On Fri, Feb 15, 2013 at 12:02 PM, Nicolas Frisby <nicolas.frisby@gmail.com>wrote:
Thanks for rallying everyone! I made a bit of a breakthrough while trying to pinpoint where the linker is invoked.
Here's the situation:
* If I use nofib's "make" command to build the text, the executable does not have the function symbols in its .text section. The .o files do have them.
* If I use ghc --make instead, the symbols survive in the executable.
I'm not up to sleuthing out the details at the moment. Should I open a Trac ticket?
Sounds like make for nofib strips the executables after they are created. That probably makes sense if nofib also measures executable sizes, but it might screw you up here. Using ghc --make (command copied form whatever nofib uses) is probably the right thing to do while you're debugging any performance issues.
OK. I added a blurb on the wiki page. On Fri, Feb 15, 2013 at 8:31 PM, Johan Tibell <johan.tibell@gmail.com>wrote:
On Fri, Feb 15, 2013 at 12:02 PM, Nicolas Frisby <nicolas.frisby@gmail.com
wrote:
Thanks for rallying everyone! I made a bit of a breakthrough while trying to pinpoint where the linker is invoked.
Here's the situation:
* If I use nofib's "make" command to build the text, the executable does not have the function symbols in its .text section. The .o files do have them.
* If I use ghc --make instead, the symbols survive in the executable.
I'm not up to sleuthing out the details at the moment. Should I open a Trac ticket?
Sounds like make for nofib strips the executables after they are created. That probably makes sense if nofib also measures executable sizes, but it might screw you up here. Using ghc --make (command copied form whatever nofib uses) is probably the right thing to do while you're debugging any performance issues.
On 15/02/13 20:31, Johan Tibell wrote:
On Fri, Feb 15, 2013 at 12:02 PM, Nicolas Frisby <nicolas.frisby@gmail.com <mailto:nicolas.frisby@gmail.com>> wrote:
Thanks for rallying everyone! I made a bit of a breakthrough while trying to pinpoint where the linker is invoked. Here's the situation: * If I use nofib's "make" command to build the text, the executable does not have the function symbols in its .text section. The .o files do have them. * If I use ghc --make instead, the symbols survive in the executable. I'm not up to sleuthing out the details at the moment. Should I open a Trac ticket?
Sounds like make for nofib strips the executables after they are created. That probably makes sense if nofib also measures executable sizes, but it might screw you up here. Using ghc --make (command copied form whatever nofib uses) is probably the right thing to do while you're debugging any performance issues.
Ah yes, I usually have STRIP=: in my mk/build.mk Probably a good idea to get rid of the stripping completely, it doesn't affect the size measurements anyway which use the 'size' command. Cheers, Simon
Hmm. build.mk.sample includes STRIP_CMD = : (so do the build.mk files I'm using) Is that symbol for something else or is there a typo somewhere? On Mon, Feb 18, 2013 at 2:12 PM, Simon Marlow <marlowsd@gmail.com> wrote:
On 15/02/13 20:31, Johan Tibell wrote:
On Fri, Feb 15, 2013 at 12:02 PM, Nicolas Frisby <nicolas.frisby@gmail.com <mailto:nicolas.frisby@gmail.**com<nicolas.frisby@gmail.com>>> wrote:
Thanks for rallying everyone! I made a bit of a breakthrough while trying to pinpoint where the linker is invoked. Here's the situation: * If I use nofib's "make" command to build the text, the executable does not have the function symbols in its .text section. The .o files do have them. * If I use ghc --make instead, the symbols survive in the executable. I'm not up to sleuthing out the details at the moment. Should I open a Trac ticket?
Sounds like make for nofib strips the executables after they are created. That probably makes sense if nofib also measures executable sizes, but it might screw you up here. Using ghc --make (command copied form whatever nofib uses) is probably the right thing to do while you're debugging any performance issues.
Ah yes, I usually have
STRIP=:
in my mk/build.mk
Probably a good idea to get rid of the stripping completely, it doesn't affect the size measurements anyway which use the 'size' command.
Cheers, Simon
On 18/02/13 17:37, Nicolas Frisby wrote:
Hmm. build.mk.sample includes STRIP_CMD = : (so do the build.mk <http://build.mk> files I'm using) Is that symbol for something else or is there a typo somewhere?
It looks like the GHC build system uses STRIP_CMD, but the nofib build system uses STRIP. We like to keep you on your toes! (Actually this is probably because the nofib build system is a snapshot of an old GHC build system, and at some point we consistently renamed lots of make variables to be FOO_CMD in GHC). Cheers, Simon
On Mon, Feb 18, 2013 at 2:12 PM, Simon Marlow <marlowsd@gmail.com <mailto:marlowsd@gmail.com>> wrote:
On 15/02/13 20:31, Johan Tibell wrote:
On Fri, Feb 15, 2013 at 12:02 PM, Nicolas Frisby <nicolas.frisby@gmail.com <mailto:nicolas.frisby@gmail.com> <mailto:nicolas.frisby@gmail.__com <mailto:nicolas.frisby@gmail.com>>> wrote:
Thanks for rallying everyone! I made a bit of a breakthrough while trying to pinpoint where the linker is invoked. Here's the situation: * If I use nofib's "make" command to build the text, the executable does not have the function symbols in its .text section. The .o files do have them. * If I use ghc --make instead, the symbols survive in the executable. I'm not up to sleuthing out the details at the moment. Should I open a Trac ticket?
Sounds like make for nofib strips the executables after they are created. That probably makes sense if nofib also measures executable sizes, but it might screw you up here. Using ghc --make (command copied form whatever nofib uses) is probably the right thing to do while you're debugging any performance issues.
Ah yes, I usually have
STRIP=:
in my mk/build.mk <http://build.mk>
Probably a good idea to get rid of the stripping completely, it doesn't affect the size measurements anyway which use the 'size' command.
Cheers, Simon
participants (4)
-
Geoffrey Mainland -
Johan Tibell -
Nicolas Frisby -
Simon Marlow