diff options
Diffstat (limited to 'docs/html/guide/developing/traceview.jd')
| -rw-r--r-- | docs/html/guide/developing/traceview.jd | 310 |
1 files changed, 310 insertions, 0 deletions
diff --git a/docs/html/guide/developing/traceview.jd b/docs/html/guide/developing/traceview.jd new file mode 100644 index 000000000000..8c87eed6db5f --- /dev/null +++ b/docs/html/guide/developing/traceview.jd @@ -0,0 +1,310 @@ +page.title=Traceview: A Graphical Log Viewer +@jd:body + +<p>Traceview is a graphical viewer for execution logs +saved by your application. The sections below describe how to use the program. </p> + +<h2>Contents</h2> + +<dl> + <dt><a href="#creatingtracefiles">Creating Trace Files</a></dt> + <dt><a href="#copyingfiles">Copying Trace Files to a Host Machine</a></dt> + <dt><a href="#runningtraceview">Viewing Trace Files in Traceview</a></dt> + <dd><a href="#timelinepanel">Timeline Panel</a></dd> + <dd><a href="#profilepanel">Profile Panel</a></dd> + <dt><a href="#format">Traceview File Format</a></dd> + <dd><a href="#datafileformat">Data File Format</a><dd> + <dd><a href="#keyfileformat">Key File Format</a></dd> + <dt><a href="#knownissues">Traceview Known Issues</a></dd> + <dt><a href="#dmtracedump">Using dmtracedump</a></dt> +</dl> + +<a name="creatingtracefiles"></a> + +<h2>Creating Trace Files</h2> + +<p>To use Traceview, you need to generate log files containing the trace information you want to analyze. To do that, you include the {@link android.os.Debug} + class in your code and call its methods to start and stop logging of trace information + to disk. When your application quits, you can then use Traceview to examine the log files + for useful run-time information such + as method calls and run times. </p> +<p>To create the trace files, include the {@link android.os.Debug} class and call one + of the {@link android.os.Debug#startMethodTracing() startMethodTracing()} methods. + In the call, you specify a base name for the trace files that the system generates. + To stop tracing, call {@link android.os.Debug#stopMethodTracing() stopMethodTracing()}. + These methods start and stop method tracing across the entire virtual machine. For + example, you could call startMethodTracing() in your activity's onCreate() + method, and call stopMethodTracing() in that activity's onDestroy() method.</p> + +<pre> + // start tracing to "/sdcard/calc.trace" + Debug.startMethodTracing("calc"); + // ... + // stop tracing + Debug.stopMethodTracing(); +</pre> + +<p>When your application calls startMethodTracing(), the system creates a +file called <code><trace-base-name>.trace</code>. This contains the +binary method trace data and a mapping table with thread and method names.</p> + +<p>The system then begins buffering the generated trace data, until your application calls + stopMethodTracing(), at which time it writes the buffered data to the + output file. + If the system reaches the maximum buffer size before stopMethodTracing() + is called, the system stops tracing and sends a notification + to the console. </p> + +<p>Interpreted code will run more slowly when profiling is enabled. Don't +try to generate absolute timings from the profiler results (i.e. "function +X takes 2.5 seconds to run"). The times are only +useful in relation to other profile output, so you can see if changes +have made the code faster or slower. </p> + +<p>When using the Android emulator, you must create an SD card image upon which +the trace files will be written. For example, from the <code>/tools</code> directory, you +can create an SD card image and mount it when launching the emulator like so:</p> +<pre> +<b>$</b> mksdcard 1024M ./imgcd +<b>$</b> emulator -sdcard ./img +</pre> +<p>For more information, read about the +<a href="{@docRoot}reference/othertools.html#mksdcard">mksdcard tool</a>.</p> + +<p>The format of the trace files is described <a href="#format">later + in this document</a>. </p> + +<a name="copyingfiles"></a> + +<h2>Copying Trace Files to a Host Machine</h2> +<p>After your application has run and the system has created your trace files <code><trace-base-name>.trace</code> + on a device or emulator, you must copy those files to your development computer. You can use <code>adb pull</code> to copy + the files. Here's an example that shows how to copy an example file, + calc.trace, from the default location on the emulator to the /tmp directory on +the emulator host machine:</p> +<pre>adb pull /sdcard/calc.trace /tmp</pre> + + +<a name="runningtraceview"></a> + +<h2>Viewing Trace Files in Traceview</h2> +<p>To run traceview and view the trace files, enter <code>traceview <trace-base-name></code>. + For example, to run Traceview on the example files copied in the previous section, + you would use: </p> + <pre>traceview /tmp/calc</pre> + + <p>Traceview loads the log files and displays their data in a window that has two panels:</p> + <ul> + <li>A <a href="#timelinepanel">timeline panel</a> -- describes when each thread + and method started and stopped</li> + <li>A <a href="#timelinepanel">profile panel</a> -- provides a summary of what happened inside a method</li> + </ul> + <p>The sections below provide addition information about the traceview output panes. </p> + +<a name="timelinepanel"></a> + +<h3>Timeline Panel </h3> +<p>The image below shows a close up of the timeline panel. Each thread’s + execution is shown in its own row, with time increasing to the right. Each method + is shown in another color (colors are reused in a round-robin fashion starting + with the methods that have the most inclusive time). The thin lines underneath + the first row show the extent (entry to exit) of all the calls to the selected + method. The method in this case is LoadListener.nativeFinished() and it was + selected in the profile view. </p> +<p><img src="../images/traceview_timeline.png" alt="Traceview timeline panel" width="893" height="284"></p> +<a name="profilepanel"></a> +<h3>Profile Panel</h3> +<p>The image below shows the profile pane. The profile pane shows a + summary of all the time spent in a method. The table shows + both the inclusive and exclusive times (as well as the percentage of the total + time). Exclusive time is the time spent in the method. Inclusive time is the + time spent in the method plus the time spent in any called functions. We refer + to calling methods as "parents" and called methods as "children." + When a method is selected (by clicking on it), it expands to show the parents + and children. Parents are shown with a purple background and children + with a yellow background. The last column in the table shows the number of calls + to this method plus the number of recursive calls. The last column shows the + number of calls out of the total number of calls made to that method. In this + view, we can see that there were 14 calls to LoadListener.nativeFinished(); looking + at the timeline panel shows that one of those calls took an unusually + long time.</p> +<p><img src="../images/traceview_profile.png" alt="Traceview profile panel." width="892" height="630"></p> + +<a name="format"></a> +<h2>Traceview File Format</h2> +<p>Tracing creates two distinct pieces of output: a <em>data</em> file, + which holds the trace data, and a <em>key</em> file, which + provides a mapping from binary identifiers to thread and method names. + The files are concatenated when tracing completes, into a + single <em>.trace</em> file. </p> + +<p class="note"><strong>Note:</strong> The previous version of Traceview did not concatenate +these files for you. If you have old key and data files that you'd still like to trace, you +can concatenate them yourself with <code>cat mytrace.key mytrace.data > mytrace.trace</code>.</p> + +<a name="datafileformat"></a> + +<h3>Data File Format</h3> +<p>The data file is binary, structured as + follows (all values are stored in little-endian order):</p> +<pre>* File format: +* header +* record 0 +* record 1 +* ... +* +* Header format: +* u4 magic 0x574f4c53 ('SLOW') +* u2 version +* u2 offset to data +* u8 start date/time in usec +* +* Record format: +* u1 thread ID +* u4 method ID | method action +* u4 time delta since start, in usec +</pre> +<p>The application is expected to parse all of the header fields, then seek + to "offset to data" from the start of the file. From there it just + reads + 9-byte records until EOF is reached.</p> +<p><em>u8 start date/time in usec</em> is the output from gettimeofday(). + It's mainly there so that you can tell if the output was generated yesterday + or three months ago.</p> +<p><em>method action</em> sits in the two least-significant bits of the + <em>method</em> word. The currently defined meanings are: </p> +<ul> + <li>0 - method entry </li> + <li>1 - method exit </li> + <li>2 - method "exited" when unrolled by exception handling </li> + <li>3 - (reserved)</li> +</ul> +<p>An unsigned 32-bit integer can hold about 70 minutes of time in microseconds. +</p> + +<a name="keyfileformat"></a> + +<h3>Key File Format</h3> +<p>The key file is a plain text file divided into three sections. Each + section starts with a keyword that begins with '*'. If you see a '*' at the start + of a line, you have found the start of a new section.</p> +<p>An example file might look like this:</p> +<pre>*version +1 +clock=global +*threads +1 main +6 JDWP Handler +5 Async GC +4 Reference Handler +3 Finalizer +2 Signal Handler +*methods +0x080f23f8 java/io/PrintStream write ([BII)V +0x080f25d4 java/io/PrintStream print (Ljava/lang/String;)V +0x080f27f4 java/io/PrintStream println (Ljava/lang/String;)V +0x080da620 java/lang/RuntimeException <init> ()V +[...] +0x080f630c android/os/Debug startMethodTracing ()V +0x080f6350 android/os/Debug startMethodTracing (Ljava/lang/String;Ljava/lang/String;I)V +*end</pre> +<dl> + <dt><em>version section</em></dt> + <dd>The first line is the file version number, currently + 1. + The second line, <code>clock=global</code>, indicates that we use a common + clock across all threads. A future version may use per-thread CPU time counters + that are independent for every thread.</dd> + <dt><em>threads section</em></dt> + <dd>One line per thread. Each line consists of two parts: the thread ID, followed + by a tab, followed by the thread name. There are few restrictions on what + a valid thread name is, so include everything to the end of the line.</dd> + <dt><em>methods section </em></dt> + <dd>One line per method entry or exit. A line consists of four pieces, + separated by tab marks: <em>method-ID</em> [TAB] <em>class-name</em> [TAB] + <em>method-name</em> [TAB] + <em>signature</em> . Only + the methods that were actually entered or exited are included in the list. + Note that all three identifiers are required to uniquely identify a + method.</dd> +</dl> +<p>Neither the threads nor methods sections are sorted.</p> + +<a name="knownissues"></a> +<h2>Traceview Known Issues</h2> +<dl> + <dt>Threads</dt> + <dd>Traceview logging does not handle threads well, resulting in these two problems: +<ol> + <li> If a thread exits during profiling, the thread name is not emitted; </li> + <li>The VM reuses thread IDs. If a thread stops and another starts, they + may get the same ID. </li> +</ol> +</dd> + +<a name="dmtracedump"></a> + +<h2>Using dmtracedump</h2> + +<p>The Android SDK includes dmtracedump, a tool that gives you an alternate way + of generating graphical call-stack diagrams from trace log files. The tool + uses the Graphviz Dot utility to create the graphical output, so you need to + install Graphviz before running dmtracedump.</p> + +<p>The dmtracedump tool generates the call stack data as a tree diagram, with each call + represented as a node. It shows call flow (from parent node to child nodes) using + arrows. The diagram below shows an example of dmtracedump output.</p> + +<img src="{@docRoot}images/tracedump.png" width="485" height="401" style="margin-top:1em;"/> + +<p style="margin-top:1em;">For each node, dmtracedump shows <code><ref> <em>callname</em> (<inc-ms>, + <exc-ms>,<numcalls>)</code>, where</p> + +<ul> + <li><code><ref></code> -- Call reference number, as used in trace logs</li> + <li><code><inc-ms></code> -- Inclusive elapsed time (milliseconds spent in method, including all child methods)</li> + <li><code><exc-ms></code> -- Exclusive elapsed time (milliseconds spent in method, not including any child methods)</li> + <li><code><numcalls></code> -- Number of calls</li> +</ul> + +<p>The usage for dmtracedump is: </p> + +<pre>dmtracedump [-ho] [-s sortable] [-d trace-base-name] [-g outfile] <trace-base-name></pre> + +<p>The tool then loads trace log data from <trace-base-name>.data and <trace-base-name>.key. + The table below lists the options for dmtracedump.</p> + +<table> +<tr> + <th>Option</td> + <th>Description</th> +</tr> + + <tr> + <td><code>-d <trace-base-name> </code></td> + <td>Diff with this trace name</td> + </tr> + <tr> + <td><code>-g <outfile> </code></td> + <td>Generate output to <outfile></td> + </tr> + <tr> + <td><code>-h </code></td> + <td>Turn on HTML output</td> + </tr> + <tr> + <td><code>-o </code></td> + <td>Dump the trace file instead of profiling</td> + </tr> + <tr> + <td><code>-d <trace-base-name> </code></td> + <td>URL base to the location of the sortable javascript file</td> + </tr> + <tr> + <td><code>-t <percent> </code></td> + <td>Minimum threshold for including child nodes in the graph (child's inclusive + time as a percentage of parent inclusive time). If this option is not used, + the default threshold is 20%. </td> + </tr> + +</table> |