[Bug binutils/747] Profiling of nested functions
--- 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
--- 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