[Bug binutils/747] Profiling of nested functions

2005-03-15 Thread nickc at redhat dot com

--- Additional Comments From nickc at redhat dot com  2005-03-15 16:34 
---
Hi Laurent,

  This is not a bug but rather a feature of gprof.  It considers nested
functions to be part of their parent function and by default it will include
their timing in their parent's total.  You can get to see the time spent in the
nested function if you really want to however - by using the "-l" switch to
gprof.  For example with the test program you supplied I get the following
results from "gprof -l -b ./a.out":

  %   cumulative   self  self total   
 time   seconds   secondscalls  ms/call  ms/call  name
 38.25  0.70 0.70 p3 (profile.c:34 @8048537)
 36.61  1.37 0.67 p2 (profile.c:25 @80484d1)
 13.11  1.61 0.24 p1 (profile.c:10 @8048488)
  7.10  1.74 0.13 f2 (profile.c:19 @8048518)
  1.09  1.76 0.02120.0020.00  p3 (profile.c:30 @8048523)
  1.09  1.78 0.02 f2 (profile.c:20 @8048521)
  0.82  1.79 0.01 p3 (profile.c:33 @804855c)
  0.82  1.81 0.01 p3 (profile.c:35 @804856a)
  0.55  1.82 0.01 p1 (profile.c:9 @80484ad)
  0.55  1.83 0.01 p2 (profile.c:24 @8048500)
  0.00  1.83 0.00 2001 0.00 0.00  p2 (profile.c:15 @80484bd)
  0.00  1.83 0.001 0.00 0.00  p1 (profile.c:7 @8048474)

[...]
 
Index by function name

   [4] f2 (profile.c:19 @ 8048518) [10] p1 (profile.c:9 @ 80484ad) [5] p3
(prole.c:30 @ 8048523)
   [6] f2 (profile.c:20 @ 8048521) [12] p2 (profile.c:15 @ 80484bd) [1] p3
(profile.c:34 @ 8048537)
  [13] p1 (profile.c:7 @ 8048474) [2] p2 (profile.c:25 @ 80484d1) [8] p3
(profile.c:33 @ 804855c)
   [3] p1 (profile.c:10 @ 8048488) [11] p2 (profile.c:24 @ 8048500) [9] p3
(profile.c:35 @ 804856a)

Cheers
  Nick


-- 
   What|Removed |Added

 Status|NEW |WAITING


http://sources.redhat.com/bugzilla/show_bug.cgi?id=747

--- You are receiving this mail because: ---
You are on the CC list for the bug, or are watching someone who is.


___
bug-binutils mailing list
bug-binutils@gnu.org
http://lists.gnu.org/mailman/listinfo/bug-binutils


[Bug binutils/747] Profiling of nested functions

2005-03-15 Thread laurent at guerby dot net

--- Additional Comments From laurent at guerby dot net  2005-03-15 20:20 
---
Thanks Nick for your answer. I missed the -l flag in the documentation, very
useful indeed!

The per "line" profile looks indeed correct, but
the call graph suffers from this nested=parent assimilation and shows p2 as a
recursive function (if I understand correctly):

index % timeself  childrencalled name
0.120.00   1/1   main (cn.c:21 @ 80485dc) [6]
[5]  0.70.120.00   1 p3 (cn.c:14 @ 804856d) [5]
---
0.000.00   1/2001 main (cn.c:21 @ 80485dc) [6]
0.000.00 2000/2001 p2 (cn.c:12 @ 8048518) [2]
[11] 0.00.000.00 2001 p2 (cn.c:7 @ 804850d) [11]
---
0.000.00   1/1   main (cn.c:20 @ 80485d7) [38]
[12] 0.00.000.00   1 p1 (cn.c:3 @ 80484c4) [12]
---

I feel that treating nested functions as normal functions would be more helpful
for GNU Ada and Pascal for example, but this is a new feature request no longer
a bug. I don't know if it's easy to do in gprof, GCC 4.0 transforms all nested
functions to top level functions (with arguments) during code generation, it
wasn't doing so before so may be it helps.

I will try "-l" on the larger original Ada software and report back in a few 
days.

Thanks again for your time.

Laurent

-- 


http://sources.redhat.com/bugzilla/show_bug.cgi?id=747

--- You are receiving this mail because: ---
You are on the CC list for the bug, or are watching someone who is.


___
bug-binutils mailing list
bug-binutils@gnu.org
http://lists.gnu.org/mailman/listinfo/bug-binutils