• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
1page.title=Profiling with Traceview and dmtracedump
2parent.title=Debugging
3parent.link=index.html
4@jd:body
5
6 <div id="qv-wrapper">
7    <div id="qv">
8      <h2>In this document</h2>
9
10      <ol>
11        <li>
12          <a href="#traceviewLayout">Traceview Layout</a>
13
14          <ol>
15            <li><a href="#timelinepanel">Timeline Panel</a></li>
16
17            <li><a href="#profilepanel">Profile Panel</a></li>
18          </ol>
19        </li>
20
21        <li><a href="#creatingtracefiles">Creating Trace Files</a></li>
22
23        <li><a href="#copyingfiles">Copying Trace Files to a Host Machine</a></li>
24
25        <li><a href="#runningtraceview">Viewing Trace Files in Traceview</a></li>
26
27        <li><a href="#dmtracedump">Using dmtracedump</a></li>
28
29        <li><a href="#knownissues">Traceview Known Issues</a></li>
30      </ol>
31    </div>
32  </div>
33
34  <p>Traceview is a graphical viewer for execution logs that you create by using the {@link
35  android.os.Debug} class to log tracing information in your code. Traceview can help you debug
36  your application and profile its performance.</p>
37
38  <h2 id="traceviewLayout">Traceview Layout</h2>
39
40  <p>When you have a trace log file (generated by adding tracing code to your application or by DDMS),
41  you can have Traceview load the log files and display their data in a window visualizes your application
42  in two panels:</p>
43
44  <ul>
45    <li>A <a href="#timelinepanel">timeline panel</a> -- describes when each thread and method
46    started and stopped</li>
47
48    <li>A <a href="#timelinepanel">profile panel</a> -- provides a summary of what happened inside
49    a method</li>
50  </ul>
51
52  <p>The sections below provide addition information about the traceview output panes.</p>
53
54  <h3 id="timelinepanel">Timeline Panel</h3>
55
56  <p>The image below shows a close up of the timeline panel. Each thread&rsquo;s execution is shown
57  in its own row, with time increasing to the right. Each method is shown in another color (colors
58  are reused in a round-robin fashion starting with the methods that have the most inclusive time).
59  The thin lines underneath the first row show the extent (entry to exit) of all the calls to the
60  selected method. The method in this case is <code>LoadListener.nativeFinished()</code> and it was selected in
61  the profile view.</p>
62
63  <img src="{@docRoot}images/traceview_timeline.png"
64       alt="Traceview timeline panel"
65       width="893"
66       height="284" />
67       <p class="img-caption"><strong>Figure 1.</strong> The Traceview Timeline Panel</p>
68
69  <h3 id="profilepanel">Profile Panel</h3>
70
71  <p>Figure 2 shows the profile pane, a summary of all the time spent
72  in a method. The table shows both the inclusive and exclusive times (as well as the percentage of
73  the total time). Exclusive time is the time spent in the method. Inclusive time is the time spent
74  in the method plus the time spent in any called functions. We refer to calling methods as
75  "parents" and called methods as "children." When a method is selected (by clicking on it), it
76  expands to show the parents and children. Parents are shown with a purple background and children
77  with a yellow background. The last column in the table shows the number of calls to this method
78  plus the number of recursive calls. The last column shows the number of calls out of the total
79  number of calls made to that method. In this view, we can see that there were 14 calls to
80  <code>LoadListener.nativeFinished();</code> looking at the timeline panel shows that one of those calls took
81  an unusually long time.</p>
82
83  <img src="{@docRoot}images/traceview_profile.png"
84       alt="Traceview profile panel."
85       width="892"
86       height="630" />
87  <p class="img-caption"><strong>Figure 2.</strong> The Traceview Profile Panel</p>
88
89  <h2 id="creatingtracefiles">Creating Trace Files</h2>
90
91  <p>To use Traceview, you need to generate log files containing the trace information you want to
92  analyze.</p>
93
94  <p>There are two ways to generate trace logs:</p>
95  <ul>
96    <li>Include the {@link android.os.Debug} class in your code and call its
97  methods to start and stop logging of trace information to disk. This method is very precise because
98  you can specify in your code exactly where to start and stop logging trace data.</li>
99    <li>Use the method profiling feature of DDMS to generate trace logs. This method is less
100    precise since you do not modify code, but rather specify when to start and stop logging with
101    a DDMS. Although you have less control on exactly where the data is logged, this method is useful
102    if you don't have access to the application's code, or if you do not need the precision of the first method.
103    </li>
104  </ul>
105
106  <p>Before you start generating trace logs, be aware of the following restrictions:</p>
107  <ul>
108    <li>If you are using the {@link android.os.Debug} class, your device or emulator must have an SD card
109     and your application must have permission to write to the SD card. </li>
110    <li>If you are using DDMS, Android 2.1 and earlier devices must
111    have an SD card present and your application must have permission to write to the SD card.
112    <li>If you are using DDMS, Android 2.2 and later devices do not need an SD card. The trace log files are
113    streamed directly to your development machine.</li>
114  </ul>
115
116  <p>This document focuses on using the {@link android.os.Debug} class to generate trace data.  For more information on using DDMS
117  to generate trace data, see <a href="ddms.html#profiling">Using the Dalvik Debug Monitor Server.</a>
118  </p>
119
120  <p>To create the trace files, include the {@link android.os.Debug} class and call one of the
121  {@link android.os.Debug#startMethodTracing() startMethodTracing()} methods. In the call, you
122  specify a base name for the trace files that the system generates. To stop tracing, call {@link
123  android.os.Debug#stopMethodTracing() stopMethodTracing()}. These methods start and stop method
124  tracing across the entire virtual machine. For example, you could call
125  {@link android.os.Debug#startMethodTracing() startMethodTracing()} in
126  your activity's {@link android.app.Activity#onCreate onCreate()} method, and call
127  {@link android.os.Debug#stopMethodTracing() stopMethodTracing()} in that activity's
128  {@link android.app.Activity#onDestroy()} method.</p>
129  <pre>
130    // start tracing to "/sdcard/calc.trace"
131    Debug.startMethodTracing("calc");
132    // ...
133    // stop tracing
134    Debug.stopMethodTracing();
135</pre>
136
137  <p>When your application calls startMethodTracing(), the system creates a file called
138  <code>&lt;trace-base-name&gt;.trace</code>. This contains the binary method trace data and a
139  mapping table with thread and method names.</p>
140
141  <p>The system then begins buffering the generated trace data, until your application calls
142  stopMethodTracing(), at which time it writes the buffered data to the output file. If the system
143  reaches the maximum buffer size before stopMethodTracing() is called, the system stops tracing
144  and sends a notification to the console.</p>
145
146  <p>Interpreted code will run more slowly when profiling is enabled. Don't try to generate
147  absolute timings from the profiler results (i.e. "function X takes 2.5 seconds to run"). The
148  times are only useful in relation to other profile output, so you can see if changes have made
149  the code faster or slower.</p>
150
151  <p>When using the Android emulator, you must specify an SD card when you create your AVD because the trace files
152  are written to the SD card. Your application must have permission to write to the SD card as well.
153
154  <h2 id="copyingfiles">Copying Trace Files to a Host Machine</h2>
155
156  <p>After your application has run and the system has created your trace files
157  <code>&lt;trace-base-name&gt;.trace</code> on a device or emulator, you must copy those files to
158  your development computer. You can use <code>adb pull</code> to copy the files. Here's an example
159  that shows how to copy an example file, calc.trace, from the default location on the emulator to
160  the /tmp directory on the emulator host machine:</p>
161  <pre>
162adb pull /sdcard/calc.trace /tmp
163</pre>
164
165  <h2 id="runningtraceview">Viewing Trace Files in Traceview</h2>
166
167  <p>To run Traceview and view the trace files, enter <code>traceview
168  &lt;trace-base-name&gt;</code>. For example, to run Traceview on the example files copied in the
169  previous section, use:</p>
170  <pre>
171traceview /tmp/calc
172</pre>
173
174  <p class="note"><strong>Note:</strong> If you are trying to view the trace logs of an application
175  that is built with ProGuard enabled (release mode build), some method and member names might be obfuscated.
176  You can use the Proguard <code>mapping.txt</code> file to figure out the original unobfuscated names. For more information
177  on this file, see the <a href="{@docRoot}tools/help/proguard.html">Proguard</a> documentation.</p>
178
179      <h2 id="dmtracedump">Using dmtracedump</h2>
180
181      <p><code>dmtracedump</code> is a tool that gives you an alternate way of generating
182      graphical call-stack diagrams from trace log files. The tool uses the Graphviz Dot utility to
183      create the graphical output, so you need to install Graphviz before running dmtracedump.</p>
184
185      <p>The dmtracedump tool generates the call stack data as a tree diagram, with each call
186      represented as a node. It shows call flow (from parent node to child nodes) using arrows. The
187      diagram below shows an example of dmtracedump output.</p>
188      <img src=
189      "{@docRoot}images/tracedump.png"
190          width="485"
191          height="401" />
192       <p class="image-caption"><strong>Figure 3.</strong> Screenshot of dmtracedump</p>
193
194      <p>For each node, dmtracedump shows <code>&lt;ref&gt;
195      <em>callname</em> (&lt;inc-ms&gt;, &lt;exc-ms&gt;,&lt;numcalls&gt;)</code>, where</p>
196
197      <ul>
198        <li><code>&lt;ref&gt;</code> -- Call reference number, as used in trace logs</li>
199
200        <li><code>&lt;inc-ms&gt;</code> -- Inclusive elapsed time (milliseconds spent in method,
201        including all child methods)</li>
202
203        <li><code>&lt;exc-ms&gt;</code> -- Exclusive elapsed time (milliseconds spent in method,
204        not including any child methods)</li>
205
206        <li><code>&lt;numcalls&gt;</code> -- Number of calls</li>
207      </ul>
208
209      <p>The usage for dmtracedump is:</p>
210      <pre>
211dmtracedump [-ho] [-s sortable] [-d trace-base-name] [-g outfile] &lt;trace-base-name&gt;
212</pre>
213
214      <p>The tool then loads trace log data from <code>&lt;trace-base-name&gt;.data</code> and
215      <code>&lt;trace-base-name&gt;.key</code>. The table below lists the options for dmtracedump.</p>
216
217      <table>
218        <tr>
219          <th>Option</th>
220
221          <th>Description</th>
222        </tr>
223
224        <tr>
225          <td><code>-d&nbsp;&lt;trace-base-name&gt;</code></td>
226
227          <td>Diff with this trace name</td>
228        </tr>
229
230        <tr>
231          <td><code>-g&nbsp;&lt;outfile&gt;</code></td>
232
233          <td>Generate output to &lt;outfile&gt;</td>
234        </tr>
235
236        <tr>
237          <td><code>-h</code></td>
238
239          <td>Turn on HTML output</td>
240        </tr>
241
242        <tr>
243          <td><code>-o</code></td>
244
245          <td>Dump the trace file instead of profiling</td>
246        </tr>
247
248        <tr>
249          <td><code>-d&nbsp;&lt;trace-base-name&gt;</code></td>
250
251          <td>URL base to the location of the sortable javascript file</td>
252        </tr>
253
254        <tr>
255          <td><code>-t&nbsp;&lt;percent&gt;</code></td>
256
257          <td>Minimum threshold for including child nodes in the graph (child's inclusive time as a
258          percentage of parent inclusive time). If this option is not used, the default threshold
259          is 20%.</td>
260        </tr>
261      </table>
262
263
264
265  <h2 id="knownissues">Traceview Known Issues</h2>
266
267  <dl>
268    <dt>Threads</dt>
269
270    <dd>
271      Traceview logging does not handle threads well, resulting in these two problems:
272
273      <ol>
274        <li>If a thread exits during profiling, the thread name is not emitted;</li>
275
276        <li>The VM reuses thread IDs. If a thread stops and another starts, they may get the same
277        ID.</li>
278      </ol>
279    </dd>
280
281    </dl>
282