mirror of
https://github.com/gperftools/gperftools
synced 2024-12-24 16:22:06 +00:00
66737d1c25
git-svn-id: http://gperftools.googlecode.com/svn/trunk@3 6b5cf1ce-ec42-a296-1ba9-69fdba395a50
410 lines
15 KiB
HTML
410 lines
15 KiB
HTML
<html><head><title>Google CPU Profiler</title></head><body>
|
||
|
||
This is the CPU profiler we use at Google. There are three parts to
|
||
using it: linking the library into an application, running the code,
|
||
and analyzing the output.
|
||
|
||
|
||
<h1>Linking in the Library</h1>
|
||
|
||
<p>To install the CPU profiler into your executable, add -lprofiler to
|
||
the link-time step for your executable. (It's also probably possible
|
||
to add in the profiler at run-time using LD_PRELOAD, but this isn't
|
||
necessarily recommended.)</p>
|
||
|
||
<p>This does <i>not</i> turn on CPU profiling; it just inserts the code.
|
||
For that reason, it's practical to just always link -lprofiler into a
|
||
binary while developing; that's what we do at Google. (However, since
|
||
any user can turn on the profiler by setting an environment variable,
|
||
it's not necessarily recommended to install profiler-linked binaries
|
||
into a production, running system.)</p>
|
||
|
||
|
||
<h1>Running the Code</h1>
|
||
|
||
<p>There are two alternatives to actually turn on CPU profiling for a
|
||
given run of an executable:</p>
|
||
|
||
<ol>
|
||
<li> Define the environment variable CPUPROFILE to the filename to dump the
|
||
profile to. For instance, to profile /usr/local/netscape:
|
||
<pre> $ CPUPROFILE=/tmp/profile /usr/local/netscape # sh
|
||
% setenv CPUPROFILE /tmp/profile; /usr/local/netscape # csh
|
||
</pre>
|
||
OR
|
||
|
||
</li><li> In your code, bracket the code you want profiled in calls to
|
||
ProfilerStart() and ProfilerStop(). ProfilerStart() will take the
|
||
profile-filename as an argument.
|
||
</li></ol>
|
||
|
||
<p>In Linux 2.6 and above, profiling works correctly with threads,
|
||
automatically profiling all threads. In Linux 2.4, profiling only
|
||
profiles the main thread (due to a kernel bug involving itimers and
|
||
threads). Profiling works correctly with sub-processes: each child
|
||
process gets its own profile with its own name (generated by combining
|
||
CPUPROFILE with the child's process id).</p>
|
||
|
||
<p>For security reasons, CPU profiling will not write to a file -- and
|
||
is thus not usable -- for setuid programs.</p>
|
||
|
||
<h2>Controlling Behavior via the Environment</h2>
|
||
|
||
<p>In addition to the environment variable <code>CPUPROFILE</code>,
|
||
which determines where profiles are written, there are several
|
||
environment variables which control the performance of the CPU
|
||
profile.</p>
|
||
|
||
<table cellpadding="5" frame="box" rules="sides" width="100%">
|
||
<tbody><tr>
|
||
<td><code>PROFILEFREQUENCY=<i>x</i></code></td>
|
||
<td>How many interrupts/second the cpu-profiler samples.
|
||
</td>
|
||
</tr>
|
||
</tbody></table>
|
||
|
||
<h1>Analyzing the Output</h1>
|
||
|
||
<p>pprof is the script used to analyze a profile. It has many output
|
||
modes, both textual and graphical. Some give just raw numbers, much
|
||
like the -pg output of gcc, and others show the data in the form of a
|
||
dependency graph.</p>
|
||
|
||
<p>pprof <b>requires</b> perl5 to be installed to run. It also
|
||
requires dot to be installed for any of the graphical output routines,
|
||
and gv to be installed for --gv mode (described below).</p>
|
||
|
||
<p>Here are some ways to call pprof. These are described in more
|
||
detail below.</p>
|
||
|
||
<pre>% pprof "program" "profile"
|
||
Generates one line per procedure
|
||
|
||
% pprof --gv "program" "profile"
|
||
Generates annotated call-graph and displays via "gv"
|
||
|
||
% pprof --gv --focus=Mutex "program" "profile"
|
||
Restrict to code paths that involve an entry that matches "Mutex"
|
||
|
||
% pprof --gv --focus=Mutex --ignore=string "program" "profile"
|
||
Restrict to code paths that involve an entry that matches "Mutex"
|
||
and does not match "string"
|
||
|
||
% pprof --list=IBF_CheckDocid "program" "profile"
|
||
Generates disassembly listing of all routines with at least one
|
||
sample that match the --list=<regexp> pattern. The listing is
|
||
annotated with the flat and cumulative sample counts at each line.
|
||
|
||
% pprof --disasm=IBF_CheckDocid "program" "profile"
|
||
Generates disassembly listing of all routines with at least one
|
||
sample that match the --disasm=<regexp> pattern. The listing is
|
||
annotated with the flat and cumulative sample counts at each PC value.
|
||
</regexp></regexp></pre>
|
||
|
||
<h3>Node Information</h3>
|
||
|
||
<p>In the various graphical modes of pprof, the output is a call graph
|
||
annotated with timing information, like so:</p>
|
||
|
||
<a href="http://goog-perftools.sourceforge.net/doc/pprof-test-big.gif">
|
||
<center><table><tbody><tr><td>
|
||
<img src="../images/pprof-test.gif">
|
||
</td></tr></tbody></table></center>
|
||
</a>
|
||
|
||
<p>Each node represents a procedure.
|
||
The directed edges indicate caller to callee relations. Each node is
|
||
formatted as follows:</p>
|
||
|
||
<center><pre>Class Name
|
||
Method Name
|
||
local (percentage)
|
||
<b>of</b> cumulative (percentage)
|
||
</pre></center>
|
||
|
||
<p>The last one or two lines contains the timing information. (The
|
||
profiling is done via a sampling method, where by default we take 100
|
||
samples a second. Therefor one unit of time in the output corresponds
|
||
to about 10 milliseconds of execution time.) The "local" time is the
|
||
time spent executing the instructions directly contained in the
|
||
procedure (and in any other procedures that were inlined into the
|
||
procedure). The "cumulative" time is the sum of the "local" time and
|
||
the time spent in any callees. If the cumulative time is the same as
|
||
the local time, it is not printed.
|
||
|
||
</p><p>For instance, the timing information for test_main_thread()
|
||
indicates that 155 units (about 1.55 seconds) were spent executing the
|
||
code in test_main_thread() and 200 units were spent while executing
|
||
test_main_thread() and its callees such as snprintf().</p>
|
||
|
||
<p>The size of the node is proportional to the local count. The
|
||
percentage displayed in the node corresponds to the count divided by
|
||
the total run time of the program (that is, the cumulative count for
|
||
main()).</p>
|
||
|
||
<h3>Edge Information</h3>
|
||
|
||
<p>An edge from one node to another indicates a caller to callee
|
||
relationship. Each edge is labelled with the time spent by the callee
|
||
on behalf of the caller. E.g, the edge from test_main_thread() to
|
||
snprintf() indicates that of the 200 samples in
|
||
test_main_thread(), 37 are because of calls to snprintf().</p>
|
||
|
||
<p>Note that test_main_thread() has an edge to vsnprintf(), even
|
||
though test_main_thread() doesn't call that function directly. This
|
||
is because the code was compiled with -O2; the profile reflects the
|
||
optimized control flow.</p>
|
||
|
||
<h3>Meta Information</h3>
|
||
|
||
The top of the display should contain some meta information like:
|
||
<pre> /tmp/profiler2_unittest
|
||
Total samples: 202
|
||
Focusing on: 202
|
||
Dropped nodes with <= 1 abs(samples)
|
||
Dropped edges with <= 0 samples
|
||
</pre>
|
||
|
||
This section contains the name of the program, and the total samples
|
||
collected during the profiling run. If the --focus option is on (see
|
||
the <a href="#focus">Focus</a> section below), the legend also
|
||
contains the number of samples being shown in the focused display.
|
||
Furthermore, some unimportant nodes and edges are dropped to reduce
|
||
clutter. The characteristics of the dropped nodes and edges are also
|
||
displayed in the legend.
|
||
|
||
<h3><a name="focus">Focus and Ignore</a></h3>
|
||
|
||
<p>You can ask pprof to generate a display focused on a particular
|
||
piece of the program. You specify a regular expression. Any portion
|
||
of the call-graph that is on a path which contains at least one node
|
||
matching the regular expression is preserved. The rest of the
|
||
call-graph is dropped on the floor. For example, you can focus on the
|
||
vsnprintf() libc call in profiler2_unittest as follows:</p>
|
||
|
||
<pre>% pprof --gv --focus=vsnprintf /tmp/profiler2_unittest test.prof
|
||
</pre>
|
||
<a href="http://goog-perftools.sourceforge.net/doc/pprof-vsnprintf-big.gif">
|
||
<center><table><tbody><tr><td>
|
||
<img src="../images/pprof-vsnprintf.gif">
|
||
</td></tr></tbody></table></center>
|
||
</a>
|
||
|
||
<p>
|
||
Similarly, you can supply the --ignore option to ignore
|
||
samples that match a specified regular expression. E.g.,
|
||
if you are interested in everything except calls to snprintf(),
|
||
you can say:
|
||
</p><pre>% pprof --gv --ignore=snprintf /tmp/profiler2_unittest test.prof
|
||
</pre>
|
||
|
||
<h3><a name="options">pprof Options</a></h3>
|
||
|
||
<h4>Output Type</h4>
|
||
|
||
<p>
|
||
</p><center>
|
||
<table cellpadding="5" frame="box" rules="sides" width="100%">
|
||
<tbody><tr valign="top">
|
||
<td><code>--text</code></td>
|
||
<td>
|
||
Produces a textual listing. This is currently the default
|
||
since it does not need to access to an X display, or
|
||
dot or gv. However if you
|
||
have these programs installed, you will probably be
|
||
happier with the --gv output.
|
||
</td>
|
||
</tr>
|
||
<tr valign="top">
|
||
<td><code>--gv</code></td>
|
||
<td>
|
||
Generates annotated call-graph, converts to postscript, and
|
||
displays via gv.
|
||
</td>
|
||
</tr>
|
||
<tr valign="top">
|
||
<td><code>--dot</code></td>
|
||
<td>
|
||
Generates the annotated call-graph in dot format and
|
||
emits to stdout.
|
||
</td>
|
||
</tr>
|
||
<tr valign="top">
|
||
<td><code>--ps</code></td>
|
||
<td>
|
||
Generates the annotated call-graph in Postscript format and
|
||
emits to stdout.
|
||
</td>
|
||
</tr>
|
||
<tr valign="top">
|
||
<td><code>--gif</code></td>
|
||
<td>
|
||
Generates the annotated call-graph in GIF format and
|
||
emits to stdout.
|
||
</td>
|
||
</tr>
|
||
<tr valign="top">
|
||
<td><code>--list=<<i>regexp</i>></code></td>
|
||
<td>
|
||
<p>Outputs source-code listing of routines whose
|
||
name matches <regexp>. Each line
|
||
in the listing is annotated with flat and cumulative
|
||
sample counts.</p>
|
||
|
||
<p>In the presence of inlined calls, the samples
|
||
associated with inlined code tend to get assigned
|
||
to a line that follows the location of the
|
||
inlined call. A more precise accounting can be
|
||
obtained by disassembling the routine using the
|
||
--disasm flag.</p>
|
||
</td>
|
||
</tr>
|
||
<tr valign="top">
|
||
<td><code>--disasm=<<i>regexp</i>></code></td>
|
||
<td>
|
||
Generates disassembly of routines that match
|
||
<regexp>, annotated with flat and
|
||
cumulative sample counts and emits to stdout.
|
||
</td>
|
||
</tr>
|
||
</tbody></table>
|
||
</center>
|
||
|
||
<h4>Reporting Granularity</h4>
|
||
|
||
<p>By default, pprof produces one entry per procedure. However you can
|
||
use one of the following options to change the granularity of the
|
||
output. The --files option seems to be particularly useless, and may
|
||
be removed eventually.</p>
|
||
|
||
<center>
|
||
<table cellpadding="5" frame="box" rules="sides" width="100%">
|
||
<tbody><tr valign="top">
|
||
<td><code>--addresses</code></td>
|
||
<td>
|
||
Produce one node per program address.
|
||
</td>
|
||
</tr>
|
||
<tr><td><code>--lines</code></td>
|
||
<td>
|
||
Produce one node per source line.
|
||
</td>
|
||
</tr>
|
||
<tr><td><code>--functions</code></td>
|
||
<td>
|
||
Produce one node per function (this is the default).
|
||
</td>
|
||
</tr>
|
||
<tr><td><code>--files</code></td>
|
||
<td>
|
||
Produce one node per source file.
|
||
</td>
|
||
</tr>
|
||
</tbody></table>
|
||
</center>
|
||
|
||
<h4>Controlling the Call Graph Display</h4>
|
||
|
||
<p>Some nodes and edges are dropped to reduce clutter in the output
|
||
display. The following options control this effect:</p>
|
||
|
||
<center>
|
||
<table cellpadding="5" frame="box" rules="sides" width="100%">
|
||
<tbody><tr valign="top">
|
||
<td><code>--nodecount=<n></code></td>
|
||
<td>
|
||
This option controls the number of displayed nodes. The nodes
|
||
are first sorted by decreasing cumulative count, and then only
|
||
the top N nodes are kept. The default value is 80.
|
||
</td>
|
||
</tr>
|
||
<tr valign="top">
|
||
<td><code>--nodefraction=<f></code></td>
|
||
<td>
|
||
This option provides another mechanism for discarding nodes
|
||
from the display. If the cumulative count for a node is
|
||
less than this option's value multiplied by the total count
|
||
for the profile, the node is dropped. The default value
|
||
is 0.005; i.e. nodes that account for less than
|
||
half a percent of the total time are dropped. A node
|
||
is dropped if either this condition is satisfied, or the
|
||
--nodecount condition is satisfied.
|
||
</td>
|
||
</tr>
|
||
<tr valign="top">
|
||
<td><code>--edgefraction=<f></code></td>
|
||
<td>
|
||
This option controls the number of displayed edges. First of all,
|
||
an edge is dropped if either its source or destination node is
|
||
dropped. Otherwise, the edge is dropped if the sample
|
||
count along the edge is less than this option's value multiplied
|
||
by the total count for the profile. The default value is
|
||
0.001; i.e., edges that account for less than
|
||
0.1% of the total time are dropped.
|
||
</td>
|
||
</tr>
|
||
<tr valign="top">
|
||
<td><code>--focus=<re></code></td>
|
||
<td>
|
||
This option controls what region of the graph is displayed
|
||
based on the regular expression supplied with the option.
|
||
For any path in the callgraph, we check all nodes in the path
|
||
against the supplied regular expression. If none of the nodes
|
||
match, the path is dropped from the output.
|
||
</td>
|
||
</tr>
|
||
<tr valign="top">
|
||
<td><code>--ignore=<re></code></td>
|
||
<td>
|
||
This option controls what region of the graph is displayed
|
||
based on the regular expression supplied with the option.
|
||
For any path in the callgraph, we check all nodes in the path
|
||
against the supplied regular expression. If any of the nodes
|
||
match, the path is dropped from the output.
|
||
</td>
|
||
</tr>
|
||
</tbody></table>
|
||
</center>
|
||
|
||
<p>The dropped edges and nodes account for some count mismatches in
|
||
the display. For example, the cumulative count for
|
||
snprintf() in the first diagram above was 41. However the local
|
||
count (1) and the count along the outgoing edges (12+1+20+6) add up to
|
||
only 40.</p>
|
||
|
||
|
||
<h1>Caveats</h1>
|
||
|
||
<ul>
|
||
<li> If the program exits because of a signal, the generated profile
|
||
will be <font color="red">incomplete, and may perhaps be
|
||
completely empty.</font>
|
||
</li><li> The displayed graph may have disconnected regions because
|
||
of the edge-dropping heuristics described above.
|
||
</li><li> If the program linked in a library that was not compiled
|
||
with enough symbolic information, all samples associated
|
||
with the library may be charged to the last symbol found
|
||
in the program before the libary. This will artificially
|
||
inflate the count for that symbol.
|
||
</li><li> If you run the program on one machine, and profile it on another,
|
||
and the shared libraries are different on the two machines, the
|
||
profiling output may be confusing: samples that fall within
|
||
the shared libaries may be assigned to arbitrary procedures.
|
||
</li><li> If your program forks, the children will also be profiled (since
|
||
they inherit the same CPUPROFILE setting). Each process is
|
||
profiled separately; to distinguish the child profiles from the
|
||
parent profile and from each other, all children will have their
|
||
process-id appended to the CPUPROFILE name.
|
||
</li><li> Due to a hack we make to work around a possible gcc bug, your
|
||
profiles may end up named strangely if the first character of
|
||
your CPUPROFILE variable has ascii value greater than 127. This
|
||
should be exceedingly rare, but if you need to use such a name,
|
||
just set prepend <code>./</code> to your filename:
|
||
<code>CPUPROFILE=./<2F>gypten</code>.
|
||
</li></ul>
|
||
|
||
<hr>
|
||
Last modified: Wed Apr 20 04:54:23 PDT 2005
|
||
|
||
</body></html>
|