1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
|
=head1 NAME
traceview - a graphical viewer for execution logs saved by Android application.
=head1 SYNOPSIS
traceview [-r] trace
=head1 DESCRIPTION
Traceview is a graphical viewer for execution logs that you create by using the
Debug class to log tracing information in your code. Traceview can help you
debug your application and profile its performance.
=head1 OPTIONS
=over 4
=item B<-r>
regression only
=back
=head1 TRACEVIEW LAYOUT
When you have a trace log file (generated by adding tracing code to your
application or by DDMS), you can have Traceview load the log files and display
their data in a window visualizes your application in two panels:
=over 4
A timeline panel - describes when each thread and method started and stopped.
A profile panel - provides a summary of what happened inside a method.
=back
The sections below provide addition information about the traceview output
panes.
=head2 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.
=head2 Profile Panel
This view 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.
=head1 TRACEVIEW FILE FORMAT
Tracing creates two distinct pieces of output: a data file, which holds the
trace data, and a key file, which provides a mapping from binary identifiers to
thread and method names. The files are concatenated when tracing completes, into
a single .trace file.
B<Note:> 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 cat mytrace.key mytrace.data > mytrace.trace.
=head2 Data File Format
The data file is binary, structured as follows (all values are stored in little
endian order):
* 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
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.
u8 start date/time in usec is the output from gettimeofday(). It's mainly there
so that you can tell if the output was generated yesterday or three months ago.
method action sits in the two least-significant bits of the method word. The
currently defined meanings are:
0 - method entry
1 - method exit
2 - method "exited" when unrolled by exception handling
3 - (reserved)
An unsigned 32-bit integer can hold about 70 minutes of time in microseconds.
=head2 Key File Format
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.
An example file might look like this:
*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
The following list describes the major sections of a key file:
=over 4
=item version section
The first line is the file version number, currently 1. The second line,
clock=global, 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.
=item threads section
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.
=item methods section
One line per method entry or exit. A line consists of four pieces, separated by
tab marks: method-ID [TAB] class-name [TAB] method-name [TAB] signature. 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.
=back
Neither the threads nor methods sections are sorted.
=head1 CREATING TRACE FILES
To use Traceview, you need to generate log files containing the trace
information you want to analyze.
There are two ways to generate trace logs:
=over 4
Include the Debug class in your code and call its methods to start and stop
logging of trace information to disk. This method is very precise because you
can specify in your code exactly where to start and stop logging trace data.
Use the method profiling feature of DDMS to generate trace logs. This method is
less precise since you do not modify code, but rather specify when to start and
stop logging with a DDMS. Although you have less control on exactly where the
data is logged, this method is useful if you don't have access to the
application's code, or if you do not need the precision of the first method.
=back
Before you start generating trace logs, be aware of the following restrictions:
=over 4
If you are using the Debug class, your device or emulator must have an SD card
and your application must have permission to write to the SD card.
If you are using DDMS, Android 1.5 devices are not supported.
If you are using DDMS, Android 2.1 and earlier devices must have an SD card
present and your application must have permission to write to the SD card.
If you are using DDMS, Android 2.2 and later devices do not need an SD card.
The trace log files are streamed directly to your development machine.
=back
To create the trace files, include the Debug class and call one of the
startMethodTracing() methods. In the call, you specify a base name for the
trace files that the system generates. To stop tracing, call
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.
// start tracing to "/sdcard/calc.trace"
Debug.startMethodTracing("calc");
// ...
// stop tracing
Debug.stopMethodTracing();
When your application calls startMethodTracing(), the system creates a file
called <trace-base-name>.trace. This contains the binary method trace data and
a mapping table with thread and method names.
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.
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.
When using the Android emulator, you must specify an SD card when you create
your AVD because the trace files are written to the SD card. Your application
must have permission to write to the SD card as well.
=head1 COPYING TRACE FILES TO A HOST MACHINE
After your application has run and the system has created your trace files
<trace-base-name>.trace on a device or emulator, you must copy those files to
your development computer. You can use adb pull 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:
adb pull /sdcard/calc.trace /tmp
=head1 COPYRIGHT
This manual page is licensed under the Apache License, Version 2.0.
Copyright (C) 2013 Android Open Source Project
Copyright (C) 2013 Jakub Adam <jakub.adam@ktknet.cz>
|
