blob: 829c82a19fc7f08feb3716e6e76146aef9c25dcd [file] [log] [blame]
Scott Main50e990c2012-06-21 17:14:39 -07001page.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
Scott Main50e990c2012-06-21 17:14:39 -070021 <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),
Scott Mainc4682402013-06-13 12:38:55 -070041 you can load the log files in Traceview, which displays the log data in two panels:</p>
Scott Main50e990c2012-06-21 17:14:39 -070042
43 <ul>
44 <li>A <a href="#timelinepanel">timeline panel</a> -- describes when each thread and method
45 started and stopped</li>
46
47 <li>A <a href="#timelinepanel">profile panel</a> -- provides a summary of what happened inside
48 a method</li>
49 </ul>
50
51 <p>The sections below provide addition information about the traceview output panes.</p>
52
53 <h3 id="timelinepanel">Timeline Panel</h3>
54
Scott Mainc4682402013-06-13 12:38:55 -070055 <p>Figure 1 shows a close up of the timeline panel. Each thread&rsquo;s execution is shown
Scott Main50e990c2012-06-21 17:14:39 -070056 in its own row, with time increasing to the right. Each method is shown in another color (colors
57 are reused in a round-robin fashion starting with the methods that have the most inclusive time).
58 The thin lines underneath the first row show the extent (entry to exit) of all the calls to the
Scott Mainc4682402013-06-13 12:38:55 -070059 selected method.</p>
Scott Main50e990c2012-06-21 17:14:39 -070060
61 <img src="{@docRoot}images/traceview_timeline.png"
62 alt="Traceview timeline panel"
63 width="893"
64 height="284" />
65 <p class="img-caption"><strong>Figure 1.</strong> The Traceview Timeline Panel</p>
66
67 <h3 id="profilepanel">Profile Panel</h3>
68
69 <p>Figure 2 shows the profile pane, a summary of all the time spent
70 in a method. The table shows both the inclusive and exclusive times (as well as the percentage of
71 the total time). Exclusive time is the time spent in the method. Inclusive time is the time spent
72 in the method plus the time spent in any called functions. We refer to calling methods as
73 "parents" and called methods as "children." When a method is selected (by clicking on it), it
74 expands to show the parents and children. Parents are shown with a purple background and children
75 with a yellow background. The last column in the table shows the number of calls to this method
76 plus the number of recursive calls. The last column shows the number of calls out of the total
77 number of calls made to that method. In this view, we can see that there were 14 calls to
78 <code>LoadListener.nativeFinished();</code> looking at the timeline panel shows that one of those calls took
79 an unusually long time.</p>
80
81 <img src="{@docRoot}images/traceview_profile.png"
82 alt="Traceview profile panel."
83 width="892"
84 height="630" />
85 <p class="img-caption"><strong>Figure 2.</strong> The Traceview Profile Panel</p>
86
Scott Main50e990c2012-06-21 17:14:39 -070087 <h2 id="creatingtracefiles">Creating Trace Files</h2>
88
89 <p>To use Traceview, you need to generate log files containing the trace information you want to
90 analyze.</p>
91
92 <p>There are two ways to generate trace logs:</p>
93 <ul>
94 <li>Include the {@link android.os.Debug} class in your code and call its
Scott Mainc4682402013-06-13 12:38:55 -070095 methods such as {@link android.os.Debug#startMethodTracing()} and {@link
96 android.os.Debug#stopMethodTracing()}, to start and stop logging of trace information to disk.
97 This option is very precise because
98 you can specify exactly where to start and stop logging trace data in your code.</li>
99 <li>Use the method profiling feature of DDMS to generate trace logs. This option is less
100 precise because you do not modify code, but rather specify when to start and stop logging with
101 DDMS. Although you have less control on exactly where logging starts and stops,
102 this option is useful if you don't have access to the application's code, or if you do
103 not need precise log timing.
Scott Main50e990c2012-06-21 17:14:39 -0700104 </li>
105 </ul>
106
107 <p>Before you start generating trace logs, be aware of the following restrictions:</p>
108 <ul>
Scott Mainc4682402013-06-13 12:38:55 -0700109 <li>If you are using the {@link android.os.Debug} class,
110 your application must have permission to write to external storage
111 ({@link android.Manifest.permission#READ_EXTERNAL_STORAGE}). </li>
112 <li>If you are using DDMS:
113 <ul>
114 <li>Android 2.1 and earlier devices must
Scott Main50e990c2012-06-21 17:14:39 -0700115 have an SD card present and your application must have permission to write to the SD card.
Scott Mainc4682402013-06-13 12:38:55 -0700116 <li>Android 2.2 and later devices do not need an SD card. The trace log files are
Scott Main50e990c2012-06-21 17:14:39 -0700117 streamed directly to your development machine.</li>
Scott Mainc4682402013-06-13 12:38:55 -0700118 </ul>
119 </li>
Scott Main50e990c2012-06-21 17:14:39 -0700120 </ul>
121
122 <p>This document focuses on using the {@link android.os.Debug} class to generate trace data. For more information on using DDMS
123 to generate trace data, see <a href="ddms.html#profiling">Using the Dalvik Debug Monitor Server.</a>
124 </p>
125
126 <p>To create the trace files, include the {@link android.os.Debug} class and call one of the
127 {@link android.os.Debug#startMethodTracing() startMethodTracing()} methods. In the call, you
128 specify a base name for the trace files that the system generates. To stop tracing, call {@link
129 android.os.Debug#stopMethodTracing() stopMethodTracing()}. These methods start and stop method
Jeff Haocf6a3b92015-05-05 18:36:42 -0700130 tracing across the entire virtual machine. For example, you could call
Scott Main50e990c2012-06-21 17:14:39 -0700131 {@link android.os.Debug#startMethodTracing() startMethodTracing()} in
132 your activity's {@link android.app.Activity#onCreate onCreate()} method, and call
133 {@link android.os.Debug#stopMethodTracing() stopMethodTracing()} in that activity's
134 {@link android.app.Activity#onDestroy()} method.</p>
135 <pre>
136 // start tracing to "/sdcard/calc.trace"
137 Debug.startMethodTracing("calc");
138 // ...
139 // stop tracing
140 Debug.stopMethodTracing();
141</pre>
142
Scott Mainc4682402013-06-13 12:38:55 -0700143 <p>When your application calls {@link android.os.Debug#startMethodTracing() startMethodTracing()},
144 the system creates a file called
Scott Main50e990c2012-06-21 17:14:39 -0700145 <code>&lt;trace-base-name&gt;.trace</code>. This contains the binary method trace data and a
146 mapping table with thread and method names.</p>
147
148 <p>The system then begins buffering the generated trace data, until your application calls
Scott Mainc4682402013-06-13 12:38:55 -0700149 {@link android.os.Debug#stopMethodTracing() stopMethodTracing()}, at which time it writes
150 the buffered data to the output file. If the system
151 reaches the maximum buffer size before you call {@link android.os.Debug#stopMethodTracing()
152 stopMethodTracing()}, the system stops tracing
Scott Main50e990c2012-06-21 17:14:39 -0700153 and sends a notification to the console.</p>
154
Scott Mainc4682402013-06-13 12:38:55 -0700155 <p>Interpreted code runs more slowly when profiling is enabled. Don't try to generate
156 absolute timings from the profiler results (such as, "function X takes 2.5 seconds to run"). The
Scott Main50e990c2012-06-21 17:14:39 -0700157 times are only useful in relation to other profile output, so you can see if changes have made
Scott Mainc4682402013-06-13 12:38:55 -0700158 the code faster or slower relative to a previous profiling run.</p>
Scott Main50e990c2012-06-21 17:14:39 -0700159
Jeff Haocf6a3b92015-05-05 18:36:42 -0700160 <p>In Android 4.4 and later, you can use sample-based profiling to profile with less runtime
161 performance impact. To enable sample profiling, call {@link
Jeff Haoc5ced5d2015-05-11 17:33:49 -0700162 android.os.Debug#startMethodTracingSampling(java.lang.String, int, int)
163 startMethodTracingSampling()} with a specified sampling interval. The system will then gather
164 samples periodically until tracing is stopped via {@link android.os.Debug#stopMethodTracing()
165 stopMethodTracing()}.</p>
Jeff Haocf6a3b92015-05-05 18:36:42 -0700166
Scott Main50e990c2012-06-21 17:14:39 -0700167 <h2 id="copyingfiles">Copying Trace Files to a Host Machine</h2>
168
169 <p>After your application has run and the system has created your trace files
170 <code>&lt;trace-base-name&gt;.trace</code> on a device or emulator, you must copy those files to
171 your development computer. You can use <code>adb pull</code> to copy the files. Here's an example
172 that shows how to copy an example file, calc.trace, from the default location on the emulator to
173 the /tmp directory on the emulator host machine:</p>
174 <pre>
175adb pull /sdcard/calc.trace /tmp
176</pre>
177
178 <h2 id="runningtraceview">Viewing Trace Files in Traceview</h2>
179
Rich Slogar2c35e922015-03-31 16:30:02 -0700180 <p>To run Traceview and view the trace files:</p>
181 <ul>
182 <li>start the
183 <a href="{@docRoot}tools/help/monitor.html">Android Device Monitor</a>. </li>
184 <li>In the Android Device Monitor tool bar, click <strong>DDMS</strong> and select a process. </li>
185 <li>Click the <strong>Start Method Profiling</strong> icon to start method profiling. </li>
186 <li>After the profiling is complete, click the <strong>Stop Method Profiling</strong> icon to
187 display the traceview. </li>
188 </ul>
Scott Main50e990c2012-06-21 17:14:39 -0700189
190 <p class="note"><strong>Note:</strong> If you are trying to view the trace logs of an application
191 that is built with ProGuard enabled (release mode build), some method and member names might be obfuscated.
192 You can use the Proguard <code>mapping.txt</code> file to figure out the original unobfuscated names. For more information
193 on this file, see the <a href="{@docRoot}tools/help/proguard.html">Proguard</a> documentation.</p>
194
Elliott Hughesdbc3c402013-02-22 21:21:03 -0800195 <h2 id="dmtracedump">Using dmtracedump</h2>
Scott Main50e990c2012-06-21 17:14:39 -0700196
197 <p><code>dmtracedump</code> is a tool that gives you an alternate way of generating
198 graphical call-stack diagrams from trace log files. The tool uses the Graphviz Dot utility to
199 create the graphical output, so you need to install Graphviz before running dmtracedump.</p>
200
201 <p>The dmtracedump tool generates the call stack data as a tree diagram, with each call
202 represented as a node. It shows call flow (from parent node to child nodes) using arrows. The
203 diagram below shows an example of dmtracedump output.</p>
204 <img src=
205 "{@docRoot}images/tracedump.png"
206 width="485"
207 height="401" />
Scott Mainc4682402013-06-13 12:38:55 -0700208 <p class="img-caption"><strong>Figure 3.</strong> Screenshot of dmtracedump</p>
Scott Main50e990c2012-06-21 17:14:39 -0700209
210 <p>For each node, dmtracedump shows <code>&lt;ref&gt;
211 <em>callname</em> (&lt;inc-ms&gt;, &lt;exc-ms&gt;,&lt;numcalls&gt;)</code>, where</p>
212
213 <ul>
214 <li><code>&lt;ref&gt;</code> -- Call reference number, as used in trace logs</li>
215
216 <li><code>&lt;inc-ms&gt;</code> -- Inclusive elapsed time (milliseconds spent in method,
217 including all child methods)</li>
218
219 <li><code>&lt;exc-ms&gt;</code> -- Exclusive elapsed time (milliseconds spent in method,
220 not including any child methods)</li>
221
222 <li><code>&lt;numcalls&gt;</code> -- Number of calls</li>
223 </ul>
224
225 <p>The usage for dmtracedump is:</p>
226 <pre>
227dmtracedump [-ho] [-s sortable] [-d trace-base-name] [-g outfile] &lt;trace-base-name&gt;
228</pre>
229
230 <p>The tool then loads trace log data from <code>&lt;trace-base-name&gt;.data</code> and
231 <code>&lt;trace-base-name&gt;.key</code>. The table below lists the options for dmtracedump.</p>
232
233 <table>
234 <tr>
235 <th>Option</th>
236
237 <th>Description</th>
238 </tr>
239
240 <tr>
241 <td><code>-d&nbsp;&lt;trace-base-name&gt;</code></td>
242
243 <td>Diff with this trace name</td>
244 </tr>
245
246 <tr>
247 <td><code>-g&nbsp;&lt;outfile&gt;</code></td>
248
249 <td>Generate output to &lt;outfile&gt;</td>
250 </tr>
251
252 <tr>
253 <td><code>-h</code></td>
254
255 <td>Turn on HTML output</td>
256 </tr>
257
258 <tr>
259 <td><code>-o</code></td>
260
261 <td>Dump the trace file instead of profiling</td>
262 </tr>
263
264 <tr>
265 <td><code>-d&nbsp;&lt;trace-base-name&gt;</code></td>
266
267 <td>URL base to the location of the sortable javascript file</td>
268 </tr>
269
270 <tr>
271 <td><code>-t&nbsp;&lt;percent&gt;</code></td>
272
273 <td>Minimum threshold for including child nodes in the graph (child's inclusive time as a
274 percentage of parent inclusive time). If this option is not used, the default threshold
275 is 20%.</td>
276 </tr>
277 </table>
278
279
280
281 <h2 id="knownissues">Traceview Known Issues</h2>
282
283 <dl>
284 <dt>Threads</dt>
285
286 <dd>
287 Traceview logging does not handle threads well, resulting in these two problems:
288
289 <ol>
Jeff Haocf6a3b92015-05-05 18:36:42 -0700290 <li>If a thread exits during profiling, the thread name is not emitted (fixed in Android 5.1
291 and later);</li>
Scott Main50e990c2012-06-21 17:14:39 -0700292
293 <li>The VM reuses thread IDs. If a thread stops and another starts, they may get the same
294 ID.</li>
295 </ol>
296 </dd>
297
Elliott Hughesdbc3c402013-02-22 21:21:03 -0800298 </dl>