gprof.texi

基于4个mips核的noc设计

following syntax:

@example
  filename_containing_a_dot
| funcname_not_containing_a_dot
| linenumber
| ( [ any_filename ] `:' ( any_funcname | linenumber ) )
@end example

Here are some sample symspecs:

@table @samp
@item main.c
Selects everything in file @file{main.c}---the
dot in the string tells @code{gprof} to interpret
the string as a filename, rather than as
a function name.  To select a file whose
name does not contain a dot, a trailing colon
should be specified.  For example, @samp{odd:} is
interpreted as the file named @file{odd}.

@item main
Selects all functions named @samp{main}.

Note that there may be multiple instances of the same function name
because some of the definitions may be local (i.e., static).  Unless a
function name is unique in a program, you must use the colon notation
explained below to specify a function from a specific source file.

Sometimes, function names contain dots.  In such cases, it is necessary
to add a leading colon to the name.  For example, @samp{:.mul} selects
function @samp{.mul}.

In some object file formats, symbols have a leading underscore.
@code{gprof} will normally not print these underscores.  When you name a
symbol in a symspec, you should type it exactly as @code{gprof} prints
it in its output.  For example, if the compiler produces a symbol
@samp{_main} from your @code{main} function, @code{gprof} still prints
it as @samp{main} in its output, so you should use @samp{main} in
symspecs.

@item main.c:main
Selects function @samp{main} in file @file{main.c}.

@item main.c:134
Selects line 134 in file @file{main.c}.
@end table

@node Output
@chapter Interpreting @code{gprof}'s Output

@code{gprof} can produce several different output styles, the
most important of which are described below.  The simplest output
styles (file information, execution count, and function and file ordering)
are not described here, but are documented with the respective options
that trigger them.
@xref{Output Options}.

@menu
* Flat Profile::        The flat profile shows how much time was spent
                            executing directly in each function.
* Call Graph::          The call graph shows which functions called which
                            others, and how much time each function used
                            when its subroutine calls are included.
* Line-by-line::        @code{gprof} can analyze individual source code lines
* Annotated Source::    The annotated source listing displays source code
                            labeled with execution counts
@end menu


@node Flat Profile,Call Graph,,Output
@section The Flat Profile
@cindex flat profile

The @dfn{flat profile} shows the total amount of time your program
spent executing each function.  Unless the @samp{-z} option is given,
functions with no apparent time spent in them, and no apparent calls
to them, are not mentioned.  Note that if a function was not compiled
for profiling, and didn't run long enough to show up on the program
counter histogram, it will be indistinguishable from a function that
was never called.

This is part of a flat profile for a small program:

@smallexample
@group
Flat profile:

Each sample counts as 0.01 seconds.
  %   cumulative   self              self     total           
 time   seconds   seconds    calls  ms/call  ms/call  name    
 33.34      0.02     0.02     7208     0.00     0.00  open
 16.67      0.03     0.01      244     0.04     0.12  offtime
 16.67      0.04     0.01        8     1.25     1.25  memccpy
 16.67      0.05     0.01        7     1.43     1.43  write
 16.67      0.06     0.01                             mcount
  0.00      0.06     0.00      236     0.00     0.00  tzset
  0.00      0.06     0.00      192     0.00     0.00  tolower
  0.00      0.06     0.00       47     0.00     0.00  strlen
  0.00      0.06     0.00       45     0.00     0.00  strchr
  0.00      0.06     0.00        1     0.00    50.00  main
  0.00      0.06     0.00        1     0.00     0.00  memcpy
  0.00      0.06     0.00        1     0.00    10.11  print
  0.00      0.06     0.00        1     0.00     0.00  profil
  0.00      0.06     0.00        1     0.00    50.00  report
@dots{}
@end group
@end smallexample

@noindent
The functions are sorted by first by decreasing run-time spent in them,
then by decreasing number of calls, then alphabetically by name.  The
functions @samp{mcount} and @samp{profil} are part of the profiling
apparatus and appear in every flat profile; their time gives a measure of
the amount of overhead due to profiling.

Just before the column headers, a statement appears indicating
how much time each sample counted as.
This @dfn{sampling period} estimates the margin of error in each of the time
figures.  A time figure that is not much larger than this is not
reliable.  In this example, each sample counted as 0.01 seconds,
suggesting a 100 Hz sampling rate.
The program's total execution time was 0.06
seconds, as indicated by the @samp{cumulative seconds} field.  Since
each sample counted for 0.01 seconds, this means only six samples
were taken during the run.  Two of the samples occurred while the
program was in the @samp{open} function, as indicated by the
@samp{self seconds} field.  Each of the other four samples
occurred one each in @samp{offtime}, @samp{memccpy}, @samp{write},
and @samp{mcount}.
Since only six samples were taken, none of these values can
be regarded as particularly reliable.
In another run,
the @samp{self seconds} field for
@samp{mcount} might well be @samp{0.00} or @samp{0.02}.
@xref{Sampling Error}, for a complete discussion.

The remaining functions in the listing (those whose
@samp{self seconds} field is @samp{0.00}) didn't appear
in the histogram samples at all.  However, the call graph
indicated that they were called, so therefore they are listed,
sorted in decreasing order by the @samp{calls} field.
Clearly some time was spent executing these functions,
but the paucity of histogram samples prevents any
determination of how much time each took.

Here is what the fields in each line mean:

@table @code
@item % time
This is the percentage of the total execution time your program spent
in this function.  These should all add up to 100%.

@item cumulative seconds
This is the cumulative total number of seconds the computer spent
executing this functions, plus the time spent in all the functions
above this one in this table.

@item self seconds
This is the number of seconds accounted for by this function alone.
The flat profile listing is sorted first by this number.

@item calls
This is the total number of times the function was called.  If the
function was never called, or the number of times it was called cannot
be determined (probably because the function was not compiled with
profiling enabled), the @dfn{calls} field is blank.

@item self ms/call
This represents the average number of milliseconds spent in this
function per call, if this function is profiled.  Otherwise, this field
is blank for this function.

@item total ms/call
This represents the average number of milliseconds spent in this
function and its descendants per call, if this function is profiled.
Otherwise, this field is blank for this function.
This is the only field in the flat profile that uses call graph analysis.

@item name
This is the name of the function.   The flat profile is sorted by this
field alphabetically after the @dfn{self seconds} and @dfn{calls}
fields are sorted.
@end table

@node Call Graph,Line-by-line,Flat Profile,Output
@section The Call Graph
@cindex call graph

The @dfn{call graph} shows how much time was spent in each function
and its children.  From this information, you can find functions that,
while they themselves may not have used much time, called other
functions that did use unusual amounts of time.

Here is a sample call from a small program.  This call came from the
same @code{gprof} run as the flat profile example in the previous
chapter.

@smallexample
@group
granularity: each sample hit covers 2 byte(s) for 20.00% of 0.05 seconds

index % time    self  children    called     name
                                                 <spontaneous>
[1]    100.0    0.00    0.05                 start [1]
                0.00    0.05       1/1           main [2]
                0.00    0.00       1/2           on_exit [28]
                0.00    0.00       1/1           exit [59]
-----------------------------------------------
                0.00    0.05       1/1           start [1]
[2]    100.0    0.00    0.05       1         main [2]
                0.00    0.05       1/1           report [3]
-----------------------------------------------
                0.00    0.05       1/1           main [2]
[3]    100.0    0.00    0.05       1         report [3]
                0.00    0.03       8/8           timelocal [6]
                0.00    0.01       1/1           print [9]
                0.00    0.01       9/9           fgets [12]
                0.00    0.00      12/34          strncmp <cycle 1> [40]
                0.00    0.00       8/8           lookup [20]
                0.00    0.00       1/1           fopen [21]
                0.00    0.00       8/8           chewtime [24]
                0.00    0.00       8/16          skipspace [44]
-----------------------------------------------
[4]     59.8    0.01        0.02       8+472     <cycle 2 as a whole>	[4]
                0.01        0.02     244+260         offtime <cycle 2> [7]
                0.00        0.00     236+1           tzset <cycle 2> [26]
-----------------------------------------------
@end group
@end smallexample

The lines full of dashes divide this table into @dfn{entries}, one for each
function.  Each entry has one or more lines.

In each entry, the primary line is the one that starts with an index number
in square brackets.  The end of this line says which function the entry is
for.  The preceding lines in the entry describe the callers of this
function and the following lines describe its subroutines (also called
@dfn{children} when we speak of the call graph).

The entries are sorted by time spent in the function and its subroutines.

The internal profiling function @code{mcount} (@pxref{Flat Profile})
is never mentioned in the call graph.

@menu
* Primary::       Details of the primary line's contents.
* Callers::       Details of caller-lines' contents.
* Subroutines::   Details of subroutine-lines' contents.
* Cycles::        When there are cycles of recursion,
                   such as @code{a} calls @code{b} calls @code{a}@dots{}
@end menu

@node Primary
@subsection The Primary Line

The @dfn{primary line} in a call graph entry is the line that
describes the function which the entry is about and gives the overall
statistics for this function.

For reference, we repeat the primary line from the entry for function
@code{report} in our main example, together with the heading line that
shows the names of the fields:

@smallexample
@group
index  % time    self  children called     name
@dots{}
[3]    100.0    0.00    0.05       1         report [3]
@end group
@end smallexample

Here is what the fields in the primary line mean:

@table @code
@item index
Entries are numbered with consecutive integers.  Each function
therefore has an index number, which appears at the beginning of its
primary line.

Each cross-reference to a function, as a caller or subroutine of
another, gives its index number as well as its name.  The index number
guides you if you wish to look for the entry for that function.

@item % time
This is the percentage of the total time that was spent in this
function, including time spent in subroutines called from this
function.

The time spent in this function is counted again for the callers of
this function.  Therefore, adding up these percentages is meaningless.

@item self
This is the total amount of time spent in this function.  This
should be identical to the number printed in the @code{seconds} field
for this function in the flat profile.

@item children
This is the total amount of time spent in the subroutine calls made by
this function.  This should be equal to the sum of all the @code{self}
and @code{children} entries of the children listed directly below this
function.

@item called
This is the number of times the function was called.

If the function called itself recursively, there are two numbers,
separated by a @samp{+}.  The first number counts non-recursive calls,
and the second counts recursive calls.

In the example above, the function @code{report} was called once from
@code{main}.

@item name
This is the name of the current function.  The index number is
repeated after it.

If the function is part of a cycle of recursion, the cycle number is
printed between the function's name and the index number
(@pxref{Cycles}).  For example, if function @code{gnurr} is part of
cycle number one, and has index number twelve, its primary line would
be end like this:

@example
gnurr <cycle 1> [12]
@end example
@end table