"New gprof" for gcc V2.95.2+
Yannick PERRET
yperret@bat710.univ-lyon1.fr
Thu Jan 11 06:53:00 GMT 2001
Hello,
I've developed a profiler for C/C++ programs, based on the '-finstrument-functions'
feature
of gcc V2.95.2+.
My motivation is that gprof cant take in count time spend in not-profiled
functions.
For example, the function:
f(int n)
{
ÃÂ sleep(1);
ÃÂ if (n <=0)
ÃÂ ÃÂ ÃÂ return;
ÃÂ f(n-1);
}
profiled with gprof gives a 0 time...
It is a problem for me as I want to profile programs that use _many_
calls to libs
that are not profiled (and not profilable). When profiling with gprof,
it gives me
invalid times, because all functions using non-profiling calls have
short execution
time, which is not real at all.
With my approach, treatments are adding for each enter/exit of functions,
and
an internal call-stack allows to know the local time spend in functions,
EVEN
if they call non-profiled function.
See http://www710.univ-lyon1.fr/~yperret/profiler.html (devel version
will soon
be the V1.1.5 pre-V1.2).
ÃÂ
I think that this tool can be usefull for other people, and I think
that:
1. people from binutils can help me to improve it
2. it can become a part (I hope) of binutils if you think it can help
people
ÃÂ
Thank you in advance for your answer.
I'm open to discution, you can email me to obtain more details...
ÃÂ
ÃÂ
Example of profile output of my library on a small program (including
functions
calling functions that are not profiled, recursive function, and cross-recursive
functions):
[it is supposed to be displayed with fixed font]
> bin/fncdump bin/essai
FunctionChecker for gcc (by Hexasoft)
Profile for 'bin/essai'
Total execution time: 16.456096
Times computed using real clock time.
Number of realloc performed: 0
|ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ localÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
|ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ totalÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
|ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ |ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
|
|ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ sec. |ÃÂ ÃÂ
%ÃÂ |ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ sec. |ÃÂ ÃÂ
%ÃÂ |ÃÂ ÃÂ callsÃÂ ÃÂ ÃÂ |tot. sec/call| name
|-------------|------|-------------|------|------------|-------------|--------
|ÃÂ ÃÂ ÃÂ ÃÂ 0.001403|ÃÂ 0.01|ÃÂ ÃÂ ÃÂ
16.456096|100.00|ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
1|ÃÂ ÃÂ ÃÂ 16.456096| main
|ÃÂ ÃÂ ÃÂ ÃÂ 4.031660| 24.50|ÃÂ ÃÂ ÃÂ ÃÂ
8.071628| 49.05|ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
4|ÃÂ ÃÂ ÃÂ ÃÂ 2.017907| recurs_1s
|ÃÂ ÃÂ ÃÂ ÃÂ 2.737634| 16.64|ÃÂ ÃÂ ÃÂ ÃÂ
5.482986| 33.32|ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
4|ÃÂ ÃÂ ÃÂ ÃÂ 1.370747| recurs_a
|ÃÂ ÃÂ ÃÂ ÃÂ 2.745352| 16.68|ÃÂ ÃÂ ÃÂ ÃÂ
4.814751| 29.26|ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
4|ÃÂ ÃÂ ÃÂ ÃÂ 1.203688| recurs_b
|ÃÂ ÃÂ ÃÂ ÃÂ 4.039960| 24.55|ÃÂ ÃÂ ÃÂ ÃÂ
4.039960| 24.55|ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
4|ÃÂ ÃÂ ÃÂ ÃÂ 1.009990| s1
|ÃÂ ÃÂ ÃÂ ÃÂ 2.899960| 17.62|ÃÂ ÃÂ ÃÂ ÃÂ
2.899960| 17.62|ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
1|ÃÂ ÃÂ ÃÂ ÃÂ 2.899960| test
|ÃÂ ÃÂ ÃÂ ÃÂ 0.000056|ÃÂ 0.00|ÃÂ ÃÂ ÃÂ ÃÂ
0.000103|ÃÂ 0.00|ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
32|ÃÂ ÃÂ ÃÂ ÃÂ 0.000003| recurs
|ÃÂ ÃÂ ÃÂ ÃÂ 0.000008|ÃÂ 0.00|ÃÂ ÃÂ ÃÂ ÃÂ
0.000014|ÃÂ 0.00|ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
1|ÃÂ ÃÂ ÃÂ ÃÂ 0.000014| f3
|ÃÂ ÃÂ ÃÂ ÃÂ 0.000006|ÃÂ 0.00|ÃÂ ÃÂ ÃÂ ÃÂ
0.000006|ÃÂ 0.00|ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
3|ÃÂ ÃÂ ÃÂ ÃÂ 0.000002| f1
|ÃÂ ÃÂ ÃÂ ÃÂ 0.000002|ÃÂ 0.00|ÃÂ ÃÂ ÃÂ ÃÂ
0.000002|ÃÂ 0.00|ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
1|ÃÂ ÃÂ ÃÂ ÃÂ 0.000002| small
Unresolved functions not shownÃÂ ÃÂ ÃÂ : 0
Spontaneous functions not shownÃÂ ÃÂ : 0
Hidden functions due to -not/-only: 0
Final stack size used: 33
Number of function(s): 10
|indx|ÃÂ ÃÂ ÃÂ ÃÂ MINÃÂ ÃÂ ÃÂ ÃÂ |ÃÂ ÃÂ ÃÂ ÃÂ
MAXÃÂ ÃÂ ÃÂ ÃÂ |name
|----|-------------|-------------|-----
|ÃÂ ÃÂ 0|ÃÂ ÃÂ ÃÂ 16.456096|ÃÂ ÃÂ ÃÂ
16.456096| main
|ÃÂ ÃÂ 1|ÃÂ ÃÂ ÃÂ ÃÂ 2.020003|ÃÂ ÃÂ ÃÂ ÃÂ
8.071628| recurs_1s
|ÃÂ ÃÂ 2|ÃÂ ÃÂ ÃÂ ÃÂ 1.401139|ÃÂ ÃÂ ÃÂ ÃÂ
5.482986| recurs_a
|ÃÂ ÃÂ 3|ÃÂ ÃÂ ÃÂ ÃÂ 0.714880|ÃÂ ÃÂ ÃÂ ÃÂ
4.814751| recurs_b
|ÃÂ ÃÂ 4|ÃÂ ÃÂ ÃÂ ÃÂ 1.009984|ÃÂ ÃÂ ÃÂ ÃÂ
1.009993| s1
|ÃÂ ÃÂ 5|ÃÂ ÃÂ ÃÂ ÃÂ 2.899960|ÃÂ ÃÂ ÃÂ ÃÂ
2.899960| test
|ÃÂ ÃÂ 6|ÃÂ ÃÂ ÃÂ ÃÂ 0.000002|ÃÂ ÃÂ ÃÂ ÃÂ
0.000103| recurs
|ÃÂ ÃÂ 7|ÃÂ ÃÂ ÃÂ ÃÂ 0.000014|ÃÂ ÃÂ ÃÂ ÃÂ
0.000014| f3
|ÃÂ ÃÂ 8|ÃÂ ÃÂ ÃÂ ÃÂ 0.000002|ÃÂ ÃÂ ÃÂ ÃÂ
0.000002| f1
|ÃÂ ÃÂ 9|ÃÂ ÃÂ ÃÂ ÃÂ 0.000002|ÃÂ ÃÂ ÃÂ ÃÂ
0.000002| small
'main' [0] spontaneously called.
'recurs_1s' [1] called by:
ÃÂ ÃÂ [0],
ÃÂ ÃÂ [1],
'recurs_a' [2] called by:
ÃÂ ÃÂ [0],
ÃÂ ÃÂ [3],
'recurs_b' [3] called by:
ÃÂ ÃÂ [2],
's1' [4] called by:
ÃÂ ÃÂ [1],
'test' [5] called by:
ÃÂ ÃÂ [0],
'recurs' [6] called by:
ÃÂ ÃÂ [0],
ÃÂ ÃÂ [6],
'f3' [7] called by:
ÃÂ ÃÂ [0],
'f1' [8] called by:
ÃÂ ÃÂ [7],
'small' [9] called by:
ÃÂ ÃÂ [0],
ÃÂ
ÃÂ
Here is the '--help' of the 'fncdump' program:
ÃÂ > bin/fncdump --help
fncdump by Hexasoft (Y.Perret, December 2000)
Usage: bin/fncdump exec [opts]
ÃÂ ÃÂ or: bin/fncdump -avg
Opts:ÃÂ -sfile fÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
: use 'f' as stat file instead of 'fnccheck.out'
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ -sort nÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
: sort mode. See at the end for details
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ +sort nÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
: sort mode (reverse). See at the end for details
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ -no-spontaneous : dont print
spontaneous called functions (dont apply to main)
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ -no-unresolvedÃÂ : dont
print unresolved symbols
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ -callsÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
: show 'called' functions instead of 'called by'
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ +callsÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
: show 'called' functions AND 'called by'
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ -no-minmaxÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
: dont display MIN/MAX time for functions
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ -nmÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
: use 'nm' instead of 'libbfd'(1) to extract names
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ -addr2lineÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
: use 'addr2line' instead of 'libbfd'(1) to extract names
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ -func-detailsÃÂ ÃÂ
: add file/line for functions (not with '-nm')
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ -call-detailsÃÂ ÃÂ
: add file/line for function calls (not with '-nm')
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ -fullnameÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
: use full pathname for file/line info
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ -only <lst>ÃÂ ÃÂ ÃÂ ÃÂ
: just use functions that are in the comma separated list
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ -not <lst>ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
: dont use functions that are in the comma separated list
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ -propagateÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
: -only/-not is applied to childs
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ -rpropagateÃÂ ÃÂ ÃÂ ÃÂ
: -only/-not is applied to callers
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ -real-maxtimeÃÂ ÃÂ
: use total execution time of displayed functions rather
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
than total exec. time of all functions.
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ --helpÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
: this message
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ --versionÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
: fnccheck/bin/fncdump version
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ --miscÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
: author/contact/bugs
ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ --detailsÃÂ ÃÂ ÃÂ ÃÂ ÃÂ ÃÂ
: explanations about displayed informations
(1): if 'fncdump' is compiled using 'libbfd' (standard behavior).
ÃÂ ÃÂ ÃÂ ÃÂ Else (make fncdump_nobfd), -addr2line
is the default approach.
Sort types:
ÃÂ ÃÂ ÃÂ 1:ÃÂ sorted by 'Local time'
ÃÂ ÃÂ ÃÂ 2:ÃÂ sorted by 'Total time'
ÃÂ ÃÂ ÃÂ 3:ÃÂ sorted by 'Call number'
ÃÂ ÃÂ ÃÂ 4:ÃÂ sorted by 'Function name'
ÃÂ ÃÂ ÃÂ 5:ÃÂ sorted by 'No sort'
The -avg usage gives you the average time spend
ÃÂ in FncCheck treatments per each of your function.
ÃÂ
More information about the Binutils
mailing list