diff options
author | Marc Espie <espie@cvs.openbsd.org> | 2001-06-09 22:09:27 +0000 |
---|---|---|
committer | Marc Espie <espie@cvs.openbsd.org> | 2001-06-09 22:09:27 +0000 |
commit | fcab77976ead6644881c2eb7bb3499cdfabed685 (patch) | |
tree | 5c38e8edfe20b4c5500799952322c67ea05b7dfe /gnu/usr.bin/binutils/gprof | |
parent | 657824d46ccc89de1e2c290ff6e78da7efd14d13 (diff) |
Long delayed import of binutils-2.10.1. Turns out art@ needs some alpha
bug-fixes...
Diffstat (limited to 'gnu/usr.bin/binutils/gprof')
-rw-r--r-- | gnu/usr.bin/binutils/gprof/gprof.info-1 | 1121 | ||||
-rw-r--r-- | gnu/usr.bin/binutils/gprof/gprof.info-2 | 760 |
2 files changed, 1881 insertions, 0 deletions
diff --git a/gnu/usr.bin/binutils/gprof/gprof.info-1 b/gnu/usr.bin/binutils/gprof/gprof.info-1 new file mode 100644 index 00000000000..b631818c52d --- /dev/null +++ b/gnu/usr.bin/binutils/gprof/gprof.info-1 @@ -0,0 +1,1121 @@ +This is gprof.info, produced by makeinfo version 4.0 from gprof.texi. + +START-INFO-DIR-ENTRY +* gprof: (gprof). Profiling your program's execution +END-INFO-DIR-ENTRY + + This file documents the gprof profiler of the GNU system. + + Copyright (C) 1988, 92, 97, 98, 99, 2000 Free Software Foundation, +Inc. + + Permission is granted to make and distribute verbatim copies of this +manual provided the copyright notice and this permission notice are +preserved on all copies. + + Permission is granted to copy and distribute modified versions of +this manual under the conditions for verbatim copying, provided that +the entire resulting derived work is distributed under the terms of a +permission notice identical to this one. + + Permission is granted to copy and distribute translations of this +manual into another language, under the above conditions for modified +versions. + + +File: gprof.info, Node: Top, Next: Introduction, Up: (dir) + +Profiling a Program: Where Does It Spend Its Time? +************************************************** + + This manual describes the GNU profiler, `gprof', and how you can use +it to determine which parts of a program are taking most of the +execution time. We assume that you know how to write, compile, and +execute programs. GNU `gprof' was written by Jay Fenlason. + +* Menu: + +* Introduction:: What profiling means, and why it is useful. + +* Compiling:: How to compile your program for profiling. +* Executing:: Executing your program to generate profile data +* Invoking:: How to run `gprof', and its options + +* Output:: Interpreting `gprof''s output + +* Inaccuracy:: Potential problems you should be aware of +* How do I?:: Answers to common questions +* Incompatibilities:: (between GNU `gprof' and Unix `gprof'.) +* Details:: Details of how profiling is done + + +File: gprof.info, Node: Introduction, Next: Compiling, Prev: Top, Up: Top + +Introduction to Profiling +************************* + + Profiling allows you to learn where your program spent its time and +which functions called which other functions while it was executing. +This information can show you which pieces of your program are slower +than you expected, and might be candidates for rewriting to make your +program execute faster. It can also tell you which functions are being +called more or less often than you expected. This may help you spot +bugs that had otherwise been unnoticed. + + Since the profiler uses information collected during the actual +execution of your program, it can be used on programs that are too +large or too complex to analyze by reading the source. However, how +your program is run will affect the information that shows up in the +profile data. If you don't use some feature of your program while it +is being profiled, no profile information will be generated for that +feature. + + Profiling has several steps: + + * You must compile and link your program with profiling enabled. + *Note Compiling::. + + * You must execute your program to generate a profile data file. + *Note Executing::. + + * You must run `gprof' to analyze the profile data. *Note + Invoking::. + + The next three chapters explain these steps in greater detail. + + Several forms of output are available from the analysis. + + The "flat profile" shows how much time your program spent in each +function, and how many times that function was called. If you simply +want to know which functions burn most of the cycles, it is stated +concisely here. *Note Flat Profile::. + + The "call graph" shows, for each function, which functions called +it, which other functions it called, and how many times. There is also +an estimate of how much time was spent in the subroutines of each +function. This can suggest places where you might try to eliminate +function calls that use a lot of time. *Note Call Graph::. + + The "annotated source" listing is a copy of the program's source +code, labeled with the number of times each line of the program was +executed. *Note Annotated Source::. + + To better understand how profiling works, you may wish to read a +description of its implementation. *Note Implementation::. + + +File: gprof.info, Node: Compiling, Next: Executing, Prev: Introduction, Up: Top + +Compiling a Program for Profiling +********************************* + + The first step in generating profile information for your program is +to compile and link it with profiling enabled. + + To compile a source file for profiling, specify the `-pg' option when +you run the compiler. (This is in addition to the options you normally +use.) + + To link the program for profiling, if you use a compiler such as `cc' +to do the linking, simply specify `-pg' in addition to your usual +options. The same option, `-pg', alters either compilation or linking +to do what is necessary for profiling. Here are examples: + + cc -g -c myprog.c utils.c -pg + cc -o myprog myprog.o utils.o -pg + + The `-pg' option also works with a command that both compiles and +links: + + cc -o myprog myprog.c utils.c -g -pg + + If you run the linker `ld' directly instead of through a compiler +such as `cc', you may have to specify a profiling startup file +`gcrt0.o' as the first input file instead of the usual startup file +`crt0.o'. In addition, you would probably want to specify the +profiling C library, `libc_p.a', by writing `-lc_p' instead of the +usual `-lc'. This is not absolutely necessary, but doing this gives +you number-of-calls information for standard library functions such as +`read' and `open'. For example: + + ld -o myprog /lib/gcrt0.o myprog.o utils.o -lc_p + + If you compile only some of the modules of the program with `-pg', +you can still profile the program, but you won't get complete +information about the modules that were compiled without `-pg'. The +only information you get for the functions in those modules is the +total time spent in them; there is no record of how many times they +were called, or from where. This will not affect the flat profile +(except that the `calls' field for the functions will be blank), but +will greatly reduce the usefulness of the call graph. + + If you wish to perform line-by-line profiling, you will also need to +specify the `-g' option, instructing the compiler to insert debugging +symbols into the program that match program addresses to source code +lines. *Note Line-by-line::. + + In addition to the `-pg' and `-g' options, you may also wish to +specify the `-a' option when compiling. This will instrument the +program to perform basic-block counting. As the program runs, it will +count how many times it executed each branch of each `if' statement, +each iteration of each `do' loop, etc. This will enable `gprof' to +construct an annotated source code listing showing how many times each +line of code was executed. + + +File: gprof.info, Node: Executing, Next: Invoking, Prev: Compiling, Up: Top + +Executing the Program +********************* + + Once the program is compiled for profiling, you must run it in order +to generate the information that `gprof' needs. Simply run the program +as usual, using the normal arguments, file names, etc. The program +should run normally, producing the same output as usual. It will, +however, run somewhat slower than normal because of the time spent +collecting and the writing the profile data. + + The way you run the program--the arguments and input that you give +it--may have a dramatic effect on what the profile information shows. +The profile data will describe the parts of the program that were +activated for the particular input you use. For example, if the first +command you give to your program is to quit, the profile data will show +the time used in initialization and in cleanup, but not much else. + + Your program will write the profile data into a file called +`gmon.out' just before exiting. If there is already a file called +`gmon.out', its contents are overwritten. There is currently no way to +tell the program to write the profile data under a different name, but +you can rename the file afterward if you are concerned that it may be +overwritten. + + In order to write the `gmon.out' file properly, your program must +exit normally: by returning from `main' or by calling `exit'. Calling +the low-level function `_exit' does not write the profile data, and +neither does abnormal termination due to an unhandled signal. + + The `gmon.out' file is written in the program's _current working +directory_ at the time it exits. This means that if your program calls +`chdir', the `gmon.out' file will be left in the last directory your +program `chdir''d to. If you don't have permission to write in this +directory, the file is not written, and you will get an error message. + + Older versions of the GNU profiling library may also write a file +called `bb.out'. This file, if present, contains an human-readable +listing of the basic-block execution counts. Unfortunately, the +appearance of a human-readable `bb.out' means the basic-block counts +didn't get written into `gmon.out'. The Perl script `bbconv.pl', +included with the `gprof' source distribution, will convert a `bb.out' +file into a format readable by `gprof'. + + +File: gprof.info, Node: Invoking, Next: Output, Prev: Executing, Up: Top + +`gprof' Command Summary +*********************** + + After you have a profile data file `gmon.out', you can run `gprof' +to interpret the information in it. The `gprof' program prints a flat +profile and a call graph on standard output. Typically you would +redirect the output of `gprof' into a file with `>'. + + You run `gprof' like this: + + gprof OPTIONS [EXECUTABLE-FILE [PROFILE-DATA-FILES...]] [> OUTFILE] + +Here square-brackets indicate optional arguments. + + If you omit the executable file name, the file `a.out' is used. If +you give no profile data file name, the file `gmon.out' is used. If +any file is not in the proper format, or if the profile data file does +not appear to belong to the executable file, an error message is +printed. + + You can give more than one profile data file by entering all their +names after the executable file name; then the statistics in all the +data files are summed together. + + The order of these options does not matter. + +* Menu: + +* Output Options:: Controlling `gprof''s output style +* Analysis Options:: Controlling how `gprof' analyses its data +* Miscellaneous Options:: +* Deprecated Options:: Options you no longer need to use, but which + have been retained for compatibility +* Symspecs:: Specifying functions to include or exclude + + +File: gprof.info, Node: Output Options, Next: Analysis Options, Up: Invoking + +Output Options +============== + + These options specify which of several output formats `gprof' should +produce. + + Many of these options take an optional "symspec" to specify +functions to be included or excluded. These options can be specified +multiple times, with different symspecs, to include or exclude sets of +symbols. *Note Symspecs::. + + Specifying any of these options overrides the default (`-p -q'), +which prints a flat profile and call graph analysis for all functions. + +`-A[SYMSPEC]' +`--annotated-source[=SYMSPEC]' + The `-A' option causes `gprof' to print annotated source code. If + SYMSPEC is specified, print output only for matching symbols. + *Note Annotated Source::. + +`-b' +`--brief' + If the `-b' option is given, `gprof' doesn't print the verbose + blurbs that try to explain the meaning of all of the fields in the + tables. This is useful if you intend to print out the output, or + are tired of seeing the blurbs. + +`-C[SYMSPEC]' +`--exec-counts[=SYMSPEC]' + The `-C' option causes `gprof' to print a tally of functions and + the number of times each was called. If SYMSPEC is specified, + print tally only for matching symbols. + + If the profile data file contains basic-block count records, + specifying the `-l' option, along with `-C', will cause basic-block + execution counts to be tallied and displayed. + +`-i' +`--file-info' + The `-i' option causes `gprof' to display summary information + about the profile data file(s) and then exit. The number of + histogram, call graph, and basic-block count records is displayed. + +`-I DIRS' +`--directory-path=DIRS' + The `-I' option specifies a list of search directories in which to + find source files. Environment variable GPROF_PATH can also be + used to convey this information. Used mostly for annotated source + output. + +`-J[SYMSPEC]' +`--no-annotated-source[=SYMSPEC]' + The `-J' option causes `gprof' not to print annotated source code. + If SYMSPEC is specified, `gprof' prints annotated source, but + excludes matching symbols. + +`-L' +`--print-path' + Normally, source filenames are printed with the path component + suppressed. The `-L' option causes `gprof' to print the full + pathname of source filenames, which is determined from symbolic + debugging information in the image file and is relative to the + directory in which the compiler was invoked. + +`-p[SYMSPEC]' +`--flat-profile[=SYMSPEC]' + The `-p' option causes `gprof' to print a flat profile. If + SYMSPEC is specified, print flat profile only for matching symbols. + *Note Flat Profile::. + +`-P[SYMSPEC]' +`--no-flat-profile[=SYMSPEC]' + The `-P' option causes `gprof' to suppress printing a flat profile. + If SYMSPEC is specified, `gprof' prints a flat profile, but + excludes matching symbols. + +`-q[SYMSPEC]' +`--graph[=SYMSPEC]' + The `-q' option causes `gprof' to print the call graph analysis. + If SYMSPEC is specified, print call graph only for matching symbols + and their children. *Note Call Graph::. + +`-Q[SYMSPEC]' +`--no-graph[=SYMSPEC]' + The `-Q' option causes `gprof' to suppress printing the call graph. + If SYMSPEC is specified, `gprof' prints a call graph, but excludes + matching symbols. + +`-y' +`--separate-files' + This option affects annotated source output only. Normally, + `gprof' prints annotated source files to standard-output. If this + option is specified, annotated source for a file named + `path/FILENAME' is generated in the file `FILENAME-ann'. If the + underlying filesystem would truncate `FILENAME-ann' so that it + overwrites the original `FILENAME', `gprof' generates annotated + source in the file `FILENAME.ann' instead (if the original file + name has an extension, that extension is _replaced_ with `.ann'). + +`-Z[SYMSPEC]' +`--no-exec-counts[=SYMSPEC]' + The `-Z' option causes `gprof' not to print a tally of functions + and the number of times each was called. If SYMSPEC is specified, + print tally, but exclude matching symbols. + +`--function-ordering' + The `--function-ordering' option causes `gprof' to print a + suggested function ordering for the program based on profiling + data. This option suggests an ordering which may improve paging, + tlb and cache behavior for the program on systems which support + arbitrary ordering of functions in an executable. + + The exact details of how to force the linker to place functions in + a particular order is system dependent and out of the scope of this + manual. + +`--file-ordering MAP_FILE' + The `--file-ordering' option causes `gprof' to print a suggested + .o link line ordering for the program based on profiling data. + This option suggests an ordering which may improve paging, tlb and + cache behavior for the program on systems which do not support + arbitrary ordering of functions in an executable. + + Use of the `-a' argument is highly recommended with this option. + + The MAP_FILE argument is a pathname to a file which provides + function name to object file mappings. The format of the file is + similar to the output of the program `nm'. + + c-parse.o:00000000 T yyparse + c-parse.o:00000004 C yyerrflag + c-lang.o:00000000 T maybe_objc_method_name + c-lang.o:00000000 T print_lang_statistics + c-lang.o:00000000 T recognize_objc_keyword + c-decl.o:00000000 T print_lang_identifier + c-decl.o:00000000 T print_lang_type + ... + + To create a MAP_FILE with GNU `nm', type a command like `nm + --extern-only --defined-only -v --print-file-name program-name'. + +`-T' +`--traditional' + The `-T' option causes `gprof' to print its output in + "traditional" BSD style. + +`-w WIDTH' +`--width=WIDTH' + Sets width of output lines to WIDTH. Currently only used when + printing the function index at the bottom of the call graph. + +`-x' +`--all-lines' + This option affects annotated source output only. By default, + only the lines at the beginning of a basic-block are annotated. + If this option is specified, every line in a basic-block is + annotated by repeating the annotation for the first line. This + behavior is similar to `tcov''s `-a'. + +`--demangle' +`--no-demangle' + These options control whether C++ symbol names should be demangled + when printing output. The default is to demangle symbols. The + `--no-demangle' option may be used to turn off demangling. + + +File: gprof.info, Node: Analysis Options, Next: Miscellaneous Options, Prev: Output Options, Up: Invoking + +Analysis Options +================ + +`-a' +`--no-static' + The `-a' option causes `gprof' to suppress the printing of + statically declared (private) functions. (These are functions + whose names are not listed as global, and which are not visible + outside the file/function/block where they were defined.) Time + spent in these functions, calls to/from them, etc, will all be + attributed to the function that was loaded directly before it in + the executable file. This option affects both the flat profile + and the call graph. + +`-c' +`--static-call-graph' + The `-c' option causes the call graph of the program to be + augmented by a heuristic which examines the text space of the + object file and identifies function calls in the binary machine + code. Since normal call graph records are only generated when + functions are entered, this option identifies children that could + have been called, but never were. Calls to functions that were + not compiled with profiling enabled are also identified, but only + if symbol table entries are present for them. Calls to dynamic + library routines are typically _not_ found by this option. + Parents or children identified via this heuristic are indicated in + the call graph with call counts of `0'. + +`-D' +`--ignore-non-functions' + The `-D' option causes `gprof' to ignore symbols which are not + known to be functions. This option will give more accurate + profile data on systems where it is supported (Solaris and HPUX for + example). + +`-k FROM/TO' + The `-k' option allows you to delete from the call graph any arcs + from symbols matching symspec FROM to those matching symspec TO. + +`-l' +`--line' + The `-l' option enables line-by-line profiling, which causes + histogram hits to be charged to individual source code lines, + instead of functions. If the program was compiled with + basic-block counting enabled, this option will also identify how + many times each line of code was executed. While line-by-line + profiling can help isolate where in a large function a program is + spending its time, it also significantly increases the running + time of `gprof', and magnifies statistical inaccuracies. *Note + Sampling Error::. + +`-m NUM' +`--min-count=NUM' + This option affects execution count output only. Symbols that are + executed less than NUM times are suppressed. + +`-n[SYMSPEC]' +`--time[=SYMSPEC]' + The `-n' option causes `gprof', in its call graph analysis, to + only propagate times for symbols matching SYMSPEC. + +`-N[SYMSPEC]' +`--no-time[=SYMSPEC]' + The `-n' option causes `gprof', in its call graph analysis, not to + propagate times for symbols matching SYMSPEC. + +`-z' +`--display-unused-functions' + If you give the `-z' option, `gprof' will mention all functions in + the flat profile, even those that were never called, and that had + no time spent in them. This is useful in conjunction with the + `-c' option for discovering which routines were never called. + + +File: gprof.info, Node: Miscellaneous Options, Next: Deprecated Options, Prev: Analysis Options, Up: Invoking + +Miscellaneous Options +===================== + +`-d[NUM]' +`--debug[=NUM]' + The `-d NUM' option specifies debugging options. If NUM is not + specified, enable all debugging. *Note Debugging::. + +`-ONAME' +`--file-format=NAME' + Selects the format of the profile data files. Recognized formats + are `auto' (the default), `bsd', `4.4bsd', `magic', and `prof' + (not yet supported). + +`-s' +`--sum' + The `-s' option causes `gprof' to summarize the information in the + profile data files it read in, and write out a profile data file + called `gmon.sum', which contains all the information from the + profile data files that `gprof' read in. The file `gmon.sum' may + be one of the specified input files; the effect of this is to + merge the data in the other input files into `gmon.sum'. + + Eventually you can run `gprof' again without `-s' to analyze the + cumulative data in the file `gmon.sum'. + +`-v' +`--version' + The `-v' flag causes `gprof' to print the current version number, + and then exit. + + +File: gprof.info, Node: Deprecated Options, Next: Symspecs, Prev: Miscellaneous Options, Up: Invoking + +Deprecated Options +================== + + These options have been replaced with newer versions that use + symspecs. + +`-e FUNCTION_NAME' + The `-e FUNCTION' option tells `gprof' to not print information + about the function FUNCTION_NAME (and its children...) in the call + graph. The function will still be listed as a child of any + functions that call it, but its index number will be shown as + `[not printed]'. More than one `-e' option may be given; only one + FUNCTION_NAME may be indicated with each `-e' option. + +`-E FUNCTION_NAME' + The `-E FUNCTION' option works like the `-e' option, but time + spent in the function (and children who were not called from + anywhere else), will not be used to compute the + percentages-of-time for the call graph. More than one `-E' option + may be given; only one FUNCTION_NAME may be indicated with each + `-E' option. + +`-f FUNCTION_NAME' + The `-f FUNCTION' option causes `gprof' to limit the call graph to + the function FUNCTION_NAME and its children (and their + children...). More than one `-f' option may be given; only one + FUNCTION_NAME may be indicated with each `-f' option. + +`-F FUNCTION_NAME' + The `-F FUNCTION' option works like the `-f' option, but only time + spent in the function and its children (and their children...) + will be used to determine total-time and percentages-of-time for + the call graph. More than one `-F' option may be given; only one + FUNCTION_NAME may be indicated with each `-F' option. The `-F' + option overrides the `-E' option. + + Note that only one function can be specified with each `-e', `-E', +`-f' or `-F' option. To specify more than one function, use multiple +options. For example, this command: + + gprof -e boring -f foo -f bar myprogram > gprof.output + +lists in the call graph all functions that were reached from either +`foo' or `bar' and were not reachable from `boring'. + + +File: gprof.info, Node: Symspecs, Prev: Deprecated Options, Up: Invoking + +Symspecs +======== + + Many of the output options allow functions to be included or excluded +using "symspecs" (symbol specifications), which observe the following +syntax: + + filename_containing_a_dot + | funcname_not_containing_a_dot + | linenumber + | ( [ any_filename ] `:' ( any_funcname | linenumber ) ) + + Here are some sample symspecs: + +`main.c' + Selects everything in file `main.c'--the dot in the string tells + `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, `odd:' is + interpreted as the file named `odd'. + +`main' + Selects all functions named `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, + `:.mul' selects function `.mul'. + + In some object file formats, symbols have a leading underscore. + `gprof' will normally not print these underscores. When you name a + symbol in a symspec, you should type it exactly as `gprof' prints + it in its output. For example, if the compiler produces a symbol + `_main' from your `main' function, `gprof' still prints it as + `main' in its output, so you should use `main' in symspecs. + +`main.c:main' + Selects function `main' in file `main.c'. + +`main.c:134' + Selects line 134 in file `main.c'. + + +File: gprof.info, Node: Output, Next: Inaccuracy, Prev: Invoking, Up: Top + +Interpreting `gprof''s Output +***************************** + + `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. *Note 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:: `gprof' can analyze individual source code lines +* Annotated Source:: The annotated source listing displays source code + labeled with execution counts + + +File: gprof.info, Node: Flat Profile, Next: Call Graph, Up: Output + +The Flat Profile +================ + + The "flat profile" shows the total amount of time your program spent +executing each function. Unless the `-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: + + 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 + ... + +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 `mcount' and `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 "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 +`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 `open' function, as +indicated by the `self seconds' field. Each of the other four samples +occurred one each in `offtime', `memccpy', `write', and `mcount'. +Since only six samples were taken, none of these values can be regarded +as particularly reliable. In another run, the `self seconds' field for +`mcount' might well be `0.00' or `0.02'. *Note Sampling Error::, for a +complete discussion. + + The remaining functions in the listing (those whose `self seconds' +field is `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 `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: + +`% time' + This is the percentage of the total execution time your program + spent in this function. These should all add up to 100%. + +`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. + +`self seconds' + This is the number of seconds accounted for by this function alone. + The flat profile listing is sorted first by this number. + +`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 "calls" field is blank. + +`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. + +`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. + +`name' + This is the name of the function. The flat profile is sorted by + this field alphabetically after the "self seconds" and "calls" + fields are sorted. + + +File: gprof.info, Node: Call Graph, Next: Line-by-line, Prev: Flat Profile, Up: Output + +The Call Graph +============== + + The "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 `gprof' run as the flat profile example in the previous chapter. + + 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] + ----------------------------------------------- + + The lines full of dashes divide this table into "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 "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 `mcount' (*note 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 `a' calls `b' calls `a'... + + +File: gprof.info, Node: Primary, Next: Callers, Up: Call Graph + +The Primary Line +---------------- + + The "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 +`report' in our main example, together with the heading line that shows +the names of the fields: + + index % time self children called name + ... + [3] 100.0 0.00 0.05 1 report [3] + + Here is what the fields in the primary line mean: + +`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. + +`% 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. + +`self' + This is the total amount of time spent in this function. This + should be identical to the number printed in the `seconds' field + for this function in the flat profile. + +`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 + `self' and `children' entries of the children listed directly + below this function. + +`called' + This is the number of times the function was called. + + If the function called itself recursively, there are two numbers, + separated by a `+'. The first number counts non-recursive calls, + and the second counts recursive calls. + + In the example above, the function `report' was called once from + `main'. + +`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 (*note + Cycles::). For example, if function `gnurr' is part of cycle + number one, and has index number twelve, its primary line would be + end like this: + + gnurr <cycle 1> [12] + + +File: gprof.info, Node: Callers, Next: Subroutines, Prev: Primary, Up: Call Graph + +Lines for a Function's Callers +------------------------------ + + A function's entry has a line for each function it was called by. +These lines' fields correspond to the fields of the primary line, but +their meanings are different because of the difference in context. + + For reference, we repeat two lines from the entry for the function +`report', the primary line and one caller-line preceding it, together +with the heading line that shows the names of the fields: + + index % time self children called name + ... + 0.00 0.05 1/1 main [2] + [3] 100.0 0.00 0.05 1 report [3] + + Here are the meanings of the fields in the caller-line for `report' +called from `main': + +`self' + An estimate of the amount of time spent in `report' itself when it + was called from `main'. + +`children' + An estimate of the amount of time spent in subroutines of `report' + when `report' was called from `main'. + + The sum of the `self' and `children' fields is an estimate of the + amount of time spent within calls to `report' from `main'. + +`called' + Two numbers: the number of times `report' was called from `main', + followed by the total number of non-recursive calls to `report' + from all its callers. + +`name and index number' + The name of the caller of `report' to which this line applies, + followed by the caller's index number. + + Not all functions have entries in the call graph; some options to + `gprof' request the omission of certain functions. When a caller + has no entry of its own, it still has caller-lines in the entries + of the functions it calls. + + If the caller is part of a recursion cycle, the cycle number is + printed between the name and the index number. + + If the identity of the callers of a function cannot be determined, a +dummy caller-line is printed which has `<spontaneous>' as the "caller's +name" and all other fields blank. This can happen for signal handlers. + + +File: gprof.info, Node: Subroutines, Next: Cycles, Prev: Callers, Up: Call Graph + +Lines for a Function's Subroutines +---------------------------------- + + A function's entry has a line for each of its subroutines--in other +words, a line for each other function that it called. These lines' +fields correspond to the fields of the primary line, but their meanings +are different because of the difference in context. + + For reference, we repeat two lines from the entry for the function +`main', the primary line and a line for a subroutine, together with the +heading line that shows the names of the fields: + + index % time self children called name + ... + [2] 100.0 0.00 0.05 1 main [2] + 0.00 0.05 1/1 report [3] + + Here are the meanings of the fields in the subroutine-line for `main' +calling `report': + +`self' + An estimate of the amount of time spent directly within `report' + when `report' was called from `main'. + +`children' + An estimate of the amount of time spent in subroutines of `report' + when `report' was called from `main'. + + The sum of the `self' and `children' fields is an estimate of the + total time spent in calls to `report' from `main'. + +`called' + Two numbers, the number of calls to `report' from `main' followed + by the total number of non-recursive calls to `report'. This + ratio is used to determine how much of `report''s `self' and + `children' time gets credited to `main'. *Note Assumptions::. + +`name' + The name of the subroutine of `main' to which this line applies, + followed by the subroutine's index number. + + If the caller is part of a recursion cycle, the cycle number is + printed between the name and the index number. + + +File: gprof.info, Node: Cycles, Prev: Subroutines, Up: Call Graph + +How Mutually Recursive Functions Are Described +---------------------------------------------- + + The graph may be complicated by the presence of "cycles of +recursion" in the call graph. A cycle exists if a function calls +another function that (directly or indirectly) calls (or appears to +call) the original function. For example: if `a' calls `b', and `b' +calls `a', then `a' and `b' form a cycle. + + Whenever there are call paths both ways between a pair of functions, +they belong to the same cycle. If `a' and `b' call each other and `b' +and `c' call each other, all three make one cycle. Note that even if +`b' only calls `a' if it was not called from `a', `gprof' cannot +determine this, so `a' and `b' are still considered a cycle. + + The cycles are numbered with consecutive integers. When a function +belongs to a cycle, each time the function name appears in the call +graph it is followed by `<cycle NUMBER>'. + + The reason cycles matter is that they make the time values in the +call graph paradoxical. The "time spent in children" of `a' should +include the time spent in its subroutine `b' and in `b''s +subroutines--but one of `b''s subroutines is `a'! How much of `a''s +time should be included in the children of `a', when `a' is indirectly +recursive? + + The way `gprof' resolves this paradox is by creating a single entry +for the cycle as a whole. The primary line of this entry describes the +total time spent directly in the functions of the cycle. The +"subroutines" of the cycle are the individual functions of the cycle, +and all other functions that were called directly by them. The +"callers" of the cycle are the functions, outside the cycle, that +called functions in the cycle. + + Here is an example portion of a call graph which shows a cycle +containing functions `a' and `b'. The cycle was entered by a call to +`a' from `main'; both `a' and `b' called `c'. + + index % time self children called name + ---------------------------------------- + 1.77 0 1/1 main [2] + [3] 91.71 1.77 0 1+5 <cycle 1 as a whole> [3] + 1.02 0 3 b <cycle 1> [4] + 0.75 0 2 a <cycle 1> [5] + ---------------------------------------- + 3 a <cycle 1> [5] + [4] 52.85 1.02 0 0 b <cycle 1> [4] + 2 a <cycle 1> [5] + 0 0 3/6 c [6] + ---------------------------------------- + 1.77 0 1/1 main [2] + 2 b <cycle 1> [4] + [5] 38.86 0.75 0 1 a <cycle 1> [5] + 3 b <cycle 1> [4] + 0 0 3/6 c [6] + ---------------------------------------- + +(The entire call graph for this program contains in addition an entry +for `main', which calls `a', and an entry for `c', with callers `a' and +`b'.) + + index % time self children called name + <spontaneous> + [1] 100.00 0 1.93 0 start [1] + 0.16 1.77 1/1 main [2] + ---------------------------------------- + 0.16 1.77 1/1 start [1] + [2] 100.00 0.16 1.77 1 main [2] + 1.77 0 1/1 a <cycle 1> [5] + ---------------------------------------- + 1.77 0 1/1 main [2] + [3] 91.71 1.77 0 1+5 <cycle 1 as a whole> [3] + 1.02 0 3 b <cycle 1> [4] + 0.75 0 2 a <cycle 1> [5] + 0 0 6/6 c [6] + ---------------------------------------- + 3 a <cycle 1> [5] + [4] 52.85 1.02 0 0 b <cycle 1> [4] + 2 a <cycle 1> [5] + 0 0 3/6 c [6] + ---------------------------------------- + 1.77 0 1/1 main [2] + 2 b <cycle 1> [4] + [5] 38.86 0.75 0 1 a <cycle 1> [5] + 3 b <cycle 1> [4] + 0 0 3/6 c [6] + ---------------------------------------- + 0 0 3/6 b <cycle 1> [4] + 0 0 3/6 a <cycle 1> [5] + [6] 0.00 0 0 6 c [6] + ---------------------------------------- + + The `self' field of the cycle's primary line is the total time spent +in all the functions of the cycle. It equals the sum of the `self' +fields for the individual functions in the cycle, found in the entry in +the subroutine lines for these functions. + + The `children' fields of the cycle's primary line and subroutine +lines count only subroutines outside the cycle. Even though `a' calls +`b', the time spent in those calls to `b' is not counted in `a''s +`children' time. Thus, we do not encounter the problem of what to do +when the time in those calls to `b' includes indirect recursive calls +back to `a'. + + The `children' field of a caller-line in the cycle's entry estimates +the amount of time spent _in the whole cycle_, and its other +subroutines, on the times when that caller called a function in the +cycle. + + The `calls' field in the primary line for the cycle has two numbers: +first, the number of times functions in the cycle were called by +functions outside the cycle; second, the number of times they were +called by functions in the cycle (including times when a function in +the cycle calls itself). This is a generalization of the usual split +into non-recursive and recursive calls. + + The `calls' field of a subroutine-line for a cycle member in the +cycle's entry says how many time that function was called from +functions in the cycle. The total of all these is the second number in +the primary line's `calls' field. + + In the individual entry for a function in a cycle, the other +functions in the same cycle can appear as subroutines and as callers. +These lines show how many times each function in the cycle called or +was called from each other function in the cycle. The `self' and +`children' fields in these lines are blank because of the difficulty of +defining meanings for them when recursion is going on. + diff --git a/gnu/usr.bin/binutils/gprof/gprof.info-2 b/gnu/usr.bin/binutils/gprof/gprof.info-2 new file mode 100644 index 00000000000..6cdfda58698 --- /dev/null +++ b/gnu/usr.bin/binutils/gprof/gprof.info-2 @@ -0,0 +1,760 @@ +This is gprof.info, produced by makeinfo version 4.0 from gprof.texi. + +START-INFO-DIR-ENTRY +* gprof: (gprof). Profiling your program's execution +END-INFO-DIR-ENTRY + + This file documents the gprof profiler of the GNU system. + + Copyright (C) 1988, 92, 97, 98, 99, 2000 Free Software Foundation, +Inc. + + Permission is granted to make and distribute verbatim copies of this +manual provided the copyright notice and this permission notice are +preserved on all copies. + + Permission is granted to copy and distribute modified versions of +this manual under the conditions for verbatim copying, provided that +the entire resulting derived work is distributed under the terms of a +permission notice identical to this one. + + Permission is granted to copy and distribute translations of this +manual into another language, under the above conditions for modified +versions. + + +File: gprof.info, Node: Line-by-line, Next: Annotated Source, Prev: Call Graph, Up: Output + +Line-by-line Profiling +====================== + + `gprof''s `-l' option causes the program to perform "line-by-line" +profiling. In this mode, histogram samples are assigned not to +functions, but to individual lines of source code. The program usually +must be compiled with a `-g' option, in addition to `-pg', in order to +generate debugging symbols for tracking source code lines. + + The flat profile is the most useful output table in line-by-line +mode. The call graph isn't as useful as normal, since the current +version of `gprof' does not propagate call graph arcs from source code +lines to the enclosing function. The call graph does, however, show +each line of code that called each function, along with a count. + + Here is a section of `gprof''s output, without line-by-line +profiling. Note that `ct_init' accounted for four histogram hits, and +13327 calls to `init_block'. + + Flat profile: + + Each sample counts as 0.01 seconds. + % cumulative self self total + time seconds seconds calls us/call us/call name + 30.77 0.13 0.04 6335 6.31 6.31 ct_init + + + Call graph (explanation follows) + + + granularity: each sample hit covers 4 byte(s) for 7.69% of 0.13 seconds + + index % time self children called name + + 0.00 0.00 1/13496 name_too_long + 0.00 0.00 40/13496 deflate + 0.00 0.00 128/13496 deflate_fast + 0.00 0.00 13327/13496 ct_init + [7] 0.0 0.00 0.00 13496 init_block + + Now let's look at some of `gprof''s output from the same program run, +this time with line-by-line profiling enabled. Note that `ct_init''s +four histogram hits are broken down into four lines of source code - +one hit occurred on each of lines 349, 351, 382 and 385. In the call +graph, note how `ct_init''s 13327 calls to `init_block' are broken down +into one call from line 396, 3071 calls from line 384, 3730 calls from +line 385, and 6525 calls from 387. + + Flat profile: + + Each sample counts as 0.01 seconds. + % cumulative self + time seconds seconds calls name + 7.69 0.10 0.01 ct_init (trees.c:349) + 7.69 0.11 0.01 ct_init (trees.c:351) + 7.69 0.12 0.01 ct_init (trees.c:382) + 7.69 0.13 0.01 ct_init (trees.c:385) + + + Call graph (explanation follows) + + + granularity: each sample hit covers 4 byte(s) for 7.69% of 0.13 seconds + + % time self children called name + + 0.00 0.00 1/13496 name_too_long (gzip.c:1440) + 0.00 0.00 1/13496 deflate (deflate.c:763) + 0.00 0.00 1/13496 ct_init (trees.c:396) + 0.00 0.00 2/13496 deflate (deflate.c:727) + 0.00 0.00 4/13496 deflate (deflate.c:686) + 0.00 0.00 5/13496 deflate (deflate.c:675) + 0.00 0.00 12/13496 deflate (deflate.c:679) + 0.00 0.00 16/13496 deflate (deflate.c:730) + 0.00 0.00 128/13496 deflate_fast (deflate.c:654) + 0.00 0.00 3071/13496 ct_init (trees.c:384) + 0.00 0.00 3730/13496 ct_init (trees.c:385) + 0.00 0.00 6525/13496 ct_init (trees.c:387) + [6] 0.0 0.00 0.00 13496 init_block (trees.c:408) + + +File: gprof.info, Node: Annotated Source, Prev: Line-by-line, Up: Output + +The Annotated Source Listing +============================ + + `gprof''s `-A' option triggers an annotated source listing, which +lists the program's source code, each function labeled with the number +of times it was called. You may also need to specify the `-I' option, +if `gprof' can't find the source code files. + + Compiling with `gcc ... -g -pg -a' augments your program with +basic-block counting code, in addition to function counting code. This +enables `gprof' to determine how many times each line of code was +executed. For example, consider the following function, taken from +gzip, with line numbers added: + + 1 ulg updcrc(s, n) + 2 uch *s; + 3 unsigned n; + 4 { + 5 register ulg c; + 6 + 7 static ulg crc = (ulg)0xffffffffL; + 8 + 9 if (s == NULL) { + 10 c = 0xffffffffL; + 11 } else { + 12 c = crc; + 13 if (n) do { + 14 c = crc_32_tab[...]; + 15 } while (--n); + 16 } + 17 crc = c; + 18 return c ^ 0xffffffffL; + 19 } + + `updcrc' has at least five basic-blocks. One is the function +itself. The `if' statement on line 9 generates two more basic-blocks, +one for each branch of the `if'. A fourth basic-block results from the +`if' on line 13, and the contents of the `do' loop form the fifth +basic-block. The compiler may also generate additional basic-blocks to +handle various special cases. + + A program augmented for basic-block counting can be analyzed with +`gprof -l -A'. I also suggest use of the `-x' option, which ensures +that each line of code is labeled at least once. Here is `updcrc''s +annotated source listing for a sample `gzip' run: + + ulg updcrc(s, n) + uch *s; + unsigned n; + 2 ->{ + register ulg c; + + static ulg crc = (ulg)0xffffffffL; + + 2 -> if (s == NULL) { + 1 -> c = 0xffffffffL; + 1 -> } else { + 1 -> c = crc; + 1 -> if (n) do { + 26312 -> c = crc_32_tab[...]; + 26312,1,26311 -> } while (--n); + } + 2 -> crc = c; + 2 -> return c ^ 0xffffffffL; + 2 ->} + + In this example, the function was called twice, passing once through +each branch of the `if' statement. The body of the `do' loop was +executed a total of 26312 times. Note how the `while' statement is +annotated. It began execution 26312 times, once for each iteration +through the loop. One of those times (the last time) it exited, while +it branched back to the beginning of the loop 26311 times. + + +File: gprof.info, Node: Inaccuracy, Next: How do I?, Prev: Output, Up: Top + +Inaccuracy of `gprof' Output +**************************** + +* Menu: + +* Sampling Error:: Statistical margins of error +* Assumptions:: Estimating children times + + +File: gprof.info, Node: Sampling Error, Next: Assumptions, Up: Inaccuracy + +Statistical Sampling Error +========================== + + The run-time figures that `gprof' gives you are based on a sampling +process, so they are subject to statistical inaccuracy. If a function +runs only a small amount of time, so that on the average the sampling +process ought to catch that function in the act only once, there is a +pretty good chance it will actually find that function zero times, or +twice. + + By contrast, the number-of-calls and basic-block figures are derived +by counting, not sampling. They are completely accurate and will not +vary from run to run if your program is deterministic. + + The "sampling period" that is printed at the beginning of the flat +profile says how often samples are taken. The rule of thumb is that a +run-time figure is accurate if it is considerably bigger than the +sampling period. + + The actual amount of error can be predicted. For N samples, the +_expected_ error is the square-root of N. For example, if the sampling +period is 0.01 seconds and `foo''s run-time is 1 second, N is 100 +samples (1 second/0.01 seconds), sqrt(N) is 10 samples, so the expected +error in `foo''s run-time is 0.1 seconds (10*0.01 seconds), or ten +percent of the observed value. Again, if the sampling period is 0.01 +seconds and `bar''s run-time is 100 seconds, N is 10000 samples, +sqrt(N) is 100 samples, so the expected error in `bar''s run-time is 1 +second, or one percent of the observed value. It is likely to vary +this much _on the average_ from one profiling run to the next. +(_Sometimes_ it will vary more.) + + This does not mean that a small run-time figure is devoid of +information. If the program's _total_ run-time is large, a small +run-time for one function does tell you that that function used an +insignificant fraction of the whole program's time. Usually this means +it is not worth optimizing. + + One way to get more accuracy is to give your program more (but +similar) input data so it will take longer. Another way is to combine +the data from several runs, using the `-s' option of `gprof'. Here is +how: + + 1. Run your program once. + + 2. Issue the command `mv gmon.out gmon.sum'. + + 3. Run your program again, the same as before. + + 4. Merge the new data in `gmon.out' into `gmon.sum' with this command: + + gprof -s EXECUTABLE-FILE gmon.out gmon.sum + + 5. Repeat the last two steps as often as you wish. + + 6. Analyze the cumulative data using this command: + + gprof EXECUTABLE-FILE gmon.sum > OUTPUT-FILE + + +File: gprof.info, Node: Assumptions, Prev: Sampling Error, Up: Inaccuracy + +Estimating `children' Times +=========================== + + Some of the figures in the call graph are estimates--for example, the +`children' time values and all the the time figures in caller and +subroutine lines. + + There is no direct information about these measurements in the +profile data itself. Instead, `gprof' estimates them by making an +assumption about your program that might or might not be true. + + The assumption made is that the average time spent in each call to +any function `foo' is not correlated with who called `foo'. If `foo' +used 5 seconds in all, and 2/5 of the calls to `foo' came from `a', +then `foo' contributes 2 seconds to `a''s `children' time, by +assumption. + + This assumption is usually true enough, but for some programs it is +far from true. Suppose that `foo' returns very quickly when its +argument is zero; suppose that `a' always passes zero as an argument, +while other callers of `foo' pass other arguments. In this program, +all the time spent in `foo' is in the calls from callers other than `a'. +But `gprof' has no way of knowing this; it will blindly and incorrectly +charge 2 seconds of time in `foo' to the children of `a'. + + We hope some day to put more complete data into `gmon.out', so that +this assumption is no longer needed, if we can figure out how. For the +nonce, the estimated figures are usually more useful than misleading. + + +File: gprof.info, Node: How do I?, Next: Incompatibilities, Prev: Inaccuracy, Up: Top + +Answers to Common Questions +*************************** + +How do I find which lines in my program were executed the most times? + Compile your program with basic-block counting enabled, run it, + then use the following pipeline: + + gprof -l -C OBJFILE | sort -k 3 -n -r + + This listing will show you the lines in your code executed most + often, but not necessarily those that consumed the most time. + +How do I find which lines in my program called a particular function? + Use `gprof -l' and lookup the function in the call graph. The + callers will be broken down by function and line number. + +How do I analyze a program that runs for less than a second? + Try using a shell script like this one: + + for i in `seq 1 100`; do + fastprog + mv gmon.out gmon.out.$i + done + + gprof -s fastprog gmon.out.* + + gprof fastprog gmon.sum + + If your program is completely deterministic, all the call counts + will be simple multiples of 100 (i.e. a function called once in + each run will appear with a call count of 100). + + +File: gprof.info, Node: Incompatibilities, Next: Details, Prev: How do I?, Up: Top + +Incompatibilities with Unix `gprof' +*********************************** + + GNU `gprof' and Berkeley Unix `gprof' use the same data file +`gmon.out', and provide essentially the same information. But there +are a few differences. + + * GNU `gprof' uses a new, generalized file format with support for + basic-block execution counts and non-realtime histograms. A magic + cookie and version number allows `gprof' to easily identify new + style files. Old BSD-style files can still be read. *Note File + Format::. + + * For a recursive function, Unix `gprof' lists the function as a + parent and as a child, with a `calls' field that lists the number + of recursive calls. GNU `gprof' omits these lines and puts the + number of recursive calls in the primary line. + + * When a function is suppressed from the call graph with `-e', GNU + `gprof' still lists it as a subroutine of functions that call it. + + * GNU `gprof' accepts the `-k' with its argument in the form + `from/to', instead of `from to'. + + * In the annotated source listing, if there are multiple basic + blocks on the same line, GNU `gprof' prints all of their counts, + separated by commas. + + * The blurbs, field widths, and output formats are different. GNU + `gprof' prints blurbs after the tables, so that you can see the + tables without skipping the blurbs. + + +File: gprof.info, Node: Details, Prev: Incompatibilities, Up: Top + +Details of Profiling +******************** + +* Menu: + +* Implementation:: How a program collects profiling information +* File Format:: Format of `gmon.out' files +* Internals:: `gprof''s internal operation +* Debugging:: Using `gprof''s `-d' option + + +File: gprof.info, Node: Implementation, Next: File Format, Up: Details + +Implementation of Profiling +=========================== + + Profiling works by changing how every function in your program is +compiled so that when it is called, it will stash away some information +about where it was called from. From this, the profiler can figure out +what function called it, and can count how many times it was called. +This change is made by the compiler when your program is compiled with +the `-pg' option, which causes every function to call `mcount' (or +`_mcount', or `__mcount', depending on the OS and compiler) as one of +its first operations. + + The `mcount' routine, included in the profiling library, is +responsible for recording in an in-memory call graph table both its +parent routine (the child) and its parent's parent. This is typically +done by examining the stack frame to find both the address of the +child, and the return address in the original parent. Since this is a +very machine-dependent operation, `mcount' itself is typically a short +assembly-language stub routine that extracts the required information, +and then calls `__mcount_internal' (a normal C function) with two +arguments - `frompc' and `selfpc'. `__mcount_internal' is responsible +for maintaining the in-memory call graph, which records `frompc', +`selfpc', and the number of times each of these call arcs was traversed. + + GCC Version 2 provides a magical function +(`__builtin_return_address'), which allows a generic `mcount' function +to extract the required information from the stack frame. However, on +some architectures, most notably the SPARC, using this builtin can be +very computationally expensive, and an assembly language version of +`mcount' is used for performance reasons. + + Number-of-calls information for library routines is collected by +using a special version of the C library. The programs in it are the +same as in the usual C library, but they were compiled with `-pg'. If +you link your program with `gcc ... -pg', it automatically uses the +profiling version of the library. + + Profiling also involves watching your program as it runs, and +keeping a histogram of where the program counter happens to be every +now and then. Typically the program counter is looked at around 100 +times per second of run time, but the exact frequency may vary from +system to system. + + This is done is one of two ways. Most UNIX-like operating systems +provide a `profil()' system call, which registers a memory array with +the kernel, along with a scale factor that determines how the program's +address space maps into the array. Typical scaling values cause every +2 to 8 bytes of address space to map into a single array slot. On +every tick of the system clock (assuming the profiled program is +running), the value of the program counter is examined and the +corresponding slot in the memory array is incremented. Since this is +done in the kernel, which had to interrupt the process anyway to handle +the clock interrupt, very little additional system overhead is required. + + However, some operating systems, most notably Linux 2.0 (and +earlier), do not provide a `profil()' system call. On such a system, +arrangements are made for the kernel to periodically deliver a signal +to the process (typically via `setitimer()'), which then performs the +same operation of examining the program counter and incrementing a slot +in the memory array. Since this method requires a signal to be +delivered to user space every time a sample is taken, it uses +considerably more overhead than kernel-based profiling. Also, due to +the added delay required to deliver the signal, this method is less +accurate as well. + + A special startup routine allocates memory for the histogram and +either calls `profil()' or sets up a clock signal handler. This +routine (`monstartup') can be invoked in several ways. On Linux +systems, a special profiling startup file `gcrt0.o', which invokes +`monstartup' before `main', is used instead of the default `crt0.o'. +Use of this special startup file is one of the effects of using `gcc +... -pg' to link. On SPARC systems, no special startup files are used. +Rather, the `mcount' routine, when it is invoked for the first time +(typically when `main' is called), calls `monstartup'. + + If the compiler's `-a' option was used, basic-block counting is also +enabled. Each object file is then compiled with a static array of +counts, initially zero. In the executable code, every time a new +basic-block begins (i.e. when an `if' statement appears), an extra +instruction is inserted to increment the corresponding count in the +array. At compile time, a paired array was constructed that recorded +the starting address of each basic-block. Taken together, the two +arrays record the starting address of every basic-block, along with the +number of times it was executed. + + The profiling library also includes a function (`mcleanup') which is +typically registered using `atexit()' to be called as the program +exits, and is responsible for writing the file `gmon.out'. Profiling +is turned off, various headers are output, and the histogram is +written, followed by the call-graph arcs and the basic-block counts. + + The output from `gprof' gives no indication of parts of your program +that are limited by I/O or swapping bandwidth. This is because samples +of the program counter are taken at fixed intervals of the program's +run time. Therefore, the time measurements in `gprof' output say +nothing about time that your program was not running. For example, a +part of the program that creates so much data that it cannot all fit in +physical memory at once may run very slowly due to thrashing, but +`gprof' will say it uses little time. On the other hand, sampling by +run time has the advantage that the amount of load due to other users +won't directly affect the output you get. + + +File: gprof.info, Node: File Format, Next: Internals, Prev: Implementation, Up: Details + +Profiling Data File Format +========================== + + The old BSD-derived file format used for profile data does not +contain a magic cookie that allows to check whether a data file really +is a `gprof' file. Furthermore, it does not provide a version number, +thus rendering changes to the file format almost impossible. GNU +`gprof' uses a new file format that provides these features. For +backward compatibility, GNU `gprof' continues to support the old +BSD-derived format, but not all features are supported with it. For +example, basic-block execution counts cannot be accommodated by the old +file format. + + The new file format is defined in header file `gmon_out.h'. It +consists of a header containing the magic cookie and a version number, +as well as some spare bytes available for future extensions. All data +in a profile data file is in the native format of the host on which the +profile was collected. GNU `gprof' adapts automatically to the +byte-order in use. + + In the new file format, the header is followed by a sequence of +records. Currently, there are three different record types: histogram +records, call-graph arc records, and basic-block execution count +records. Each file can contain any number of each record type. When +reading a file, GNU `gprof' will ensure records of the same type are +compatible with each other and compute the union of all records. For +example, for basic-block execution counts, the union is simply the sum +of all execution counts for each basic-block. + +Histogram Records +----------------- + + Histogram records consist of a header that is followed by an array of +bins. The header contains the text-segment range that the histogram +spans, the size of the histogram in bytes (unlike in the old BSD +format, this does not include the size of the header), the rate of the +profiling clock, and the physical dimension that the bin counts +represent after being scaled by the profiling clock rate. The physical +dimension is specified in two parts: a long name of up to 15 characters +and a single character abbreviation. For example, a histogram +representing real-time would specify the long name as "seconds" and the +abbreviation as "s". This feature is useful for architectures that +support performance monitor hardware (which, fortunately, is becoming +increasingly common). For example, under DEC OSF/1, the "uprofile" +command can be used to produce a histogram of, say, instruction cache +misses. In this case, the dimension in the histogram header could be +set to "i-cache misses" and the abbreviation could be set to "1" +(because it is simply a count, not a physical dimension). Also, the +profiling rate would have to be set to 1 in this case. + + Histogram bins are 16-bit numbers and each bin represent an equal +amount of text-space. For example, if the text-segment is one thousand +bytes long and if there are ten bins in the histogram, each bin +represents one hundred bytes. + +Call-Graph Records +------------------ + + Call-graph records have a format that is identical to the one used in +the BSD-derived file format. It consists of an arc in the call graph +and a count indicating the number of times the arc was traversed during +program execution. Arcs are specified by a pair of addresses: the +first must be within caller's function and the second must be within +the callee's function. When performing profiling at the function +level, these addresses can point anywhere within the respective +function. However, when profiling at the line-level, it is better if +the addresses are as close to the call-site/entry-point as possible. +This will ensure that the line-level call-graph is able to identify +exactly which line of source code performed calls to a function. + +Basic-Block Execution Count Records +----------------------------------- + + Basic-block execution count records consist of a header followed by a +sequence of address/count pairs. The header simply specifies the +length of the sequence. In an address/count pair, the address +identifies a basic-block and the count specifies the number of times +that basic-block was executed. Any address within the basic-address can +be used. + + +File: gprof.info, Node: Internals, Next: Debugging, Prev: File Format, Up: Details + +`gprof''s Internal Operation +============================ + + Like most programs, `gprof' begins by processing its options. +During this stage, it may building its symspec list +(`sym_ids.c:sym_id_add'), if options are specified which use symspecs. +`gprof' maintains a single linked list of symspecs, which will +eventually get turned into 12 symbol tables, organized into six +include/exclude pairs - one pair each for the flat profile +(INCL_FLAT/EXCL_FLAT), the call graph arcs (INCL_ARCS/EXCL_ARCS), +printing in the call graph (INCL_GRAPH/EXCL_GRAPH), timing propagation +in the call graph (INCL_TIME/EXCL_TIME), the annotated source listing +(INCL_ANNO/EXCL_ANNO), and the execution count listing +(INCL_EXEC/EXCL_EXEC). + + After option processing, `gprof' finishes building the symspec list +by adding all the symspecs in `default_excluded_list' to the exclude +lists EXCL_TIME and EXCL_GRAPH, and if line-by-line profiling is +specified, EXCL_FLAT as well. These default excludes are not added to +EXCL_ANNO, EXCL_ARCS, and EXCL_EXEC. + + Next, the BFD library is called to open the object file, verify that +it is an object file, and read its symbol table (`core.c:core_init'), +using `bfd_canonicalize_symtab' after mallocing an appropriately sized +array of symbols. At this point, function mappings are read (if the +`--file-ordering' option has been specified), and the core text space +is read into memory (if the `-c' option was given). + + `gprof''s own symbol table, an array of Sym structures, is now built. +This is done in one of two ways, by one of two routines, depending on +whether line-by-line profiling (`-l' option) has been enabled. For +normal profiling, the BFD canonical symbol table is scanned. For +line-by-line profiling, every text space address is examined, and a new +symbol table entry gets created every time the line number changes. In +either case, two passes are made through the symbol table - one to +count the size of the symbol table required, and the other to actually +read the symbols. In between the two passes, a single array of type +`Sym' is created of the appropriate length. Finally, +`symtab.c:symtab_finalize' is called to sort the symbol table and +remove duplicate entries (entries with the same memory address). + + The symbol table must be a contiguous array for two reasons. First, +the `qsort' library function (which sorts an array) will be used to +sort the symbol table. Also, the symbol lookup routine +(`symtab.c:sym_lookup'), which finds symbols based on memory address, +uses a binary search algorithm which requires the symbol table to be a +sorted array. Function symbols are indicated with an `is_func' flag. +Line number symbols have no special flags set. Additionally, a symbol +can have an `is_static' flag to indicate that it is a local symbol. + + With the symbol table read, the symspecs can now be translated into +Syms (`sym_ids.c:sym_id_parse'). Remember that a single symspec can +match multiple symbols. An array of symbol tables (`syms') is created, +each entry of which is a symbol table of Syms to be included or +excluded from a particular listing. The master symbol table and the +symspecs are examined by nested loops, and every symbol that matches a +symspec is inserted into the appropriate syms table. This is done +twice, once to count the size of each required symbol table, and again +to build the tables, which have been malloced between passes. From now +on, to determine whether a symbol is on an include or exclude symspec +list, `gprof' simply uses its standard symbol lookup routine on the +appropriate table in the `syms' array. + + Now the profile data file(s) themselves are read +(`gmon_io.c:gmon_out_read'), first by checking for a new-style +`gmon.out' header, then assuming this is an old-style BSD `gmon.out' if +the magic number test failed. + + New-style histogram records are read by `hist.c:hist_read_rec'. For +the first histogram record, allocate a memory array to hold all the +bins, and read them in. When multiple profile data files (or files +with multiple histogram records) are read, the starting address, ending +address, number of bins and sampling rate must match between the +various histograms, or a fatal error will result. If everything +matches, just sum the additional histograms into the existing in-memory +array. + + As each call graph record is read (`call_graph.c:cg_read_rec'), the +parent and child addresses are matched to symbol table entries, and a +call graph arc is created by `cg_arcs.c:arc_add', unless the arc fails +a symspec check against INCL_ARCS/EXCL_ARCS. As each arc is added, a +linked list is maintained of the parent's child arcs, and of the child's +parent arcs. Both the child's call count and the arc's call count are +incremented by the record's call count. + + Basic-block records are read (`basic_blocks.c:bb_read_rec'), but +only if line-by-line profiling has been selected. Each basic-block +address is matched to a corresponding line symbol in the symbol table, +and an entry made in the symbol's bb_addr and bb_calls arrays. Again, +if multiple basic-block records are present for the same address, the +call counts are cumulative. + + A gmon.sum file is dumped, if requested (`gmon_io.c:gmon_out_write'). + + If histograms were present in the data files, assign them to symbols +(`hist.c:hist_assign_samples') by iterating over all the sample bins +and assigning them to symbols. Since the symbol table is sorted in +order of ascending memory addresses, we can simple follow along in the +symbol table as we make our pass over the sample bins. This step +includes a symspec check against INCL_FLAT/EXCL_FLAT. Depending on the +histogram scale factor, a sample bin may span multiple symbols, in +which case a fraction of the sample count is allocated to each symbol, +proportional to the degree of overlap. This effect is rare for normal +profiling, but overlaps are more common during line-by-line profiling, +and can cause each of two adjacent lines to be credited with half a +hit, for example. + + If call graph data is present, `cg_arcs.c:cg_assemble' is called. +First, if `-c' was specified, a machine-dependent routine (`find_call') +scans through each symbol's machine code, looking for subroutine call +instructions, and adding them to the call graph with a zero call count. +A topological sort is performed by depth-first numbering all the +symbols (`cg_dfn.c:cg_dfn'), so that children are always numbered less +than their parents, then making a array of pointers into the symbol +table and sorting it into numerical order, which is reverse topological +order (children appear before parents). Cycles are also detected at +this point, all members of which are assigned the same topological +number. Two passes are now made through this sorted array of symbol +pointers. The first pass, from end to beginning (parents to children), +computes the fraction of child time to propagate to each parent and a +print flag. The print flag reflects symspec handling of +INCL_GRAPH/EXCL_GRAPH, with a parent's include or exclude (print or no +print) property being propagated to its children, unless they +themselves explicitly appear in INCL_GRAPH or EXCL_GRAPH. A second +pass, from beginning to end (children to parents) actually propagates +the timings along the call graph, subject to a check against +INCL_TIME/EXCL_TIME. With the print flag, fractions, and timings now +stored in the symbol structures, the topological sort array is now +discarded, and a new array of pointers is assembled, this time sorted +by propagated time. + + Finally, print the various outputs the user requested, which is now +fairly straightforward. The call graph (`cg_print.c:cg_print') and +flat profile (`hist.c:hist_print') are regurgitations of values already +computed. The annotated source listing +(`basic_blocks.c:print_annotated_source') uses basic-block information, +if present, to label each line of code with call counts, otherwise only +the function call counts are presented. + + The function ordering code is marginally well documented in the +source code itself (`cg_print.c'). Basically, the functions with the +most use and the most parents are placed first, followed by other +functions with the most use, followed by lower use functions, followed +by unused functions at the end. + + +File: gprof.info, Node: Debugging, Prev: Internals, Up: Details + +Debugging `gprof' +----------------- + + If `gprof' was compiled with debugging enabled, the `-d' option +triggers debugging output (to stdout) which can be helpful in +understanding its operation. The debugging number specified is +interpreted as a sum of the following options: + +2 - Topological sort + Monitor depth-first numbering of symbols during call graph analysis + +4 - Cycles + Shows symbols as they are identified as cycle heads + +16 - Tallying + As the call graph arcs are read, show each arc and how the total + calls to each function are tallied + +32 - Call graph arc sorting + Details sorting individual parents/children within each call graph + entry + +64 - Reading histogram and call graph records + Shows address ranges of histograms as they are read, and each call + graph arc + +128 - Symbol table + Reading, classifying, and sorting the symbol table from the object + file. For line-by-line profiling (`-l' option), also shows line + numbers being assigned to memory addresses. + +256 - Static call graph + Trace operation of `-c' option + +512 - Symbol table and arc table lookups + Detail operation of lookup routines + +1024 - Call graph propagation + Shows how function times are propagated along the call graph + +2048 - Basic-blocks + Shows basic-block records as they are read from profile data (only + meaningful with `-l' option) + +4096 - Symspecs + Shows symspec-to-symbol pattern matching operation + +8192 - Annotate source + Tracks operation of `-A' option + + |