724bf5d331b3313cd0e65366e692f3c6ea4fdb14
[charm.git] / doc / projections / tracing.tex
1 \projections{} is a performance analysis/visualization framework that
2 helps you understand and investigate performance-related problems in
3 the (\charmpp{}) applications. It is a framework with an
4 event tracing component which allows to control the
5 amount of information generated. The tracing has low perturbation 
6 on the application. It
7 also has a Java-based visualization and analysis component with
8 various views that help present the performance information in a
9 visually useful manner.
10
11 Performance analysis with \projections{} typically involves two simple
12 steps:
13
14 \begin{enumerate}
15 \item 
16 Prepare your application by linking with the appropriate trace
17 generation modules and execute it to generate trace data.
18 \item
19 Using the Java-based tool to visually study various aspects of the
20 performance and locate the performance issues for that application execution.
21 \end{enumerate}
22
23 The \charmpp{} runtime automatically records pertinent performance
24 data for performance-related events during execution. These
25 events include the start and end of entry method execution, message
26 send from entry methods and scheduler idle time. This means {\em
27 most} users do not need to manually insert code into their
28 applications in order to generate trace data. In scenarios where
29 special performance information not captured by the runtime is
30 required, an API (see section \ref{sec::api}) is available for
31 user-specific events with some support for visualization by the
32 Java-based tool. If greater control over tracing activities
33 (e.g. dynamically turning instrumentation on and off) is desired, the
34 API also allows users to insert code into their applications for such
35 purposes.
36
37 The automatic recording of events by the \projections{} framework
38 introduces the overhead of an if-statement for each runtime event,
39 even if no performance analysis traces are desired. Developers of
40 \charmpp{} applications who consider such an overhead to be
41 unacceptable (e.g. for a production application which requires the
42 absolute best performance) may recompile the \charmpp{} runtime with
43 the {\tt -{}-with-production} flag which removes the instrumentation
44 stubs.
45
46 To enable performance tracing of your application, users simply need
47 to link the appropriate trace data generation module(s) (also referred
48 to as {\em tracemode(s)}). (see section \ref{sec::trace modules})
49
50 \section{Enabling Performance Tracing at Link/Run Time}
51 \label{sec::trace modules}
52
53 \projections{} tracing modules dictate the type of performance data,
54 data detail and data format each processor will record. They are also
55 refereed to as ``tracemodes''. There are currently 2 tracemodes
56 available. Zero or more tracemodes may be specified at link-time. When
57 no tracemodes are specified, no trace data is generated.
58
59 \subsection{Tracemode {\tt projections}}
60
61 Link time option: {\tt -tracemode projections}
62
63 This tracemode generates files that contain
64 information about all \charmpp{} events like entry method calls and
65 message packing during the execution of the program.  The data will be
66 used by \projections{} in visualization and analysis.
67
68 This tracemode creates a single symbol table file and $p$ ASCII
69 log files for $p$ processors. The names of the log files will be
70 NAME.\#.log where NAME is the name of your executable and \# is the
71 processor \#. The name of the symbol table file is NAME.sts where NAME
72 is the name of your executable.
73
74 This is the main source of data needed by the performance
75 visualizer. Certain tools like timeline will not work without the
76 detail data from this tracemode.
77
78 The following is a list of runtime options available under this tracemode:
79
80 \begin{itemize}
81 \item
82 {\tt +logsize NUM}: keep only NUM log entries in the memory of each
83 processor. The logs are emptied and flushed to disk when filled.
84 \item
85 {\tt +binary-trace}:  generate projections log in binary form.
86 \item
87 {\tt +gz-trace}:      generate gzip (if available) compressed log files.
88 \item
89 {\tt +checknested}: a debug option. Checks if events are improperly nested
90 while recorded and issue a warning immediately.
91
92 \item {\tt +trace-subdirs NUM}: divide the generated log files among
93   {\tt NUM} subdirectories of the trace root, each named {\tt
94     PROGNAME.projdir.K}
95 \end{itemize}
96
97 \subsection{Tracemode {\tt summary}}
98
99 Compile option: {\tt -tracemode summary}
100
101 In this tracemode, execution time across all entry points for each
102 processor is partitioned into a fixed number of equally sized
103 time-interval bins. These bins are globally resized whenever they are
104 all filled in order to accommodate longer execution times while keeping
105 the amount of space used constant.
106
107 Additional data like the total number of calls made to each entry
108 point is summarized within each processor.
109
110 This tracemode will generate a single symbol table file and $p$ ASCII
111 summary files for $p$ processors. The names of the summary files will
112 be NAME.\#.sum where NAME is the name of your executable and \# is the
113 processor \#. The name of the symbol table file is NAME.sum.sts where NAME
114 is the name of your executable.
115
116 This tracemode can be used to control the amount of output generated
117 in a run. It is typically used in scenarios where a quick look at the
118 overall utilization graph of the application is desired to identify
119 smaller regions of time for more detailed study. Attempting to
120 generate the same graph using the detailed logs of the prior tracemode
121 may be unnecessarily time consuming or impossible.
122
123 The following is a list of runtime options available under this tracemode:
124
125 \begin{itemize}
126 \item
127 {\tt +bincount NUM}:   use NUM time-interval bins. The bins are resized and compacted when filled.
128 \item
129 {\tt +binsize TIME}:   sets the initial time quantum each bin represents.
130 \item
131 {\tt +version}:        set summary version to generate.
132 %\item
133 %{\tt +epThreshold}: DOESNT DO ANYTHING YET. LEFT COMMENTED FOR DOC PURPOSES
134 %\item
135 %{\tt +epInterval}: DOESNT DO ANYTHING YET. LEFT COMMENTED FOR DOC PURPOSES
136 \item
137 {\tt +sumDetail}: Generates a additional set of files, one per processor,
138 that stores the time spent by each entry method associated with each 
139 time-bin. The names of ``summary detail'' files will be NAME.\#.sumd where
140 NAME is the name of your executable and \# is the processor \#.
141 \item
142 {\tt +sumOnly}: Generates an additional file that stores a single
143 utilization value per time-bin, averaged across all processors. This
144 file bears the name NAME.sum where NAME is the name of your
145 executable. This runtime option currently overrides the {\tt
146 +sumDetail} option.
147 \end{itemize}
148
149 \subsection{General Runtime Options}
150 \label{sec::general options}
151
152 The following is a list of runtime options available with the same
153 semantics for all tracemodes:
154
155 \begin{itemize}
156 \item
157 {\tt +traceroot DIR}: place all generated files in DIR.
158 \item
159 {\tt +traceoff}: trace generation is turned off when the application
160 is started. The user is expected to insert code to turn tracing on at
161 some point in the run.
162 \item
163 {\tt +traceWarn}: By default, warning messages from the framework are
164 not displayed. This option enables warning messages to be printed to
165 screen. However, on large numbers of processors, they can overwhelm
166 the terminal I/O system of the machine and result in unacceptable
167 perturbation of the application.
168 \end{itemize}
169
170 \subsection{End-of-run Analysis for Data Reduction}
171 \label{sec::data reduction}
172
173 As applications are scaled to thousands or hundreds of thousands of
174 processors, the amount of data generated becomes extremely large and
175 potentially unmanageable by the visualization tool. At the time of this
176 documentation, \projections{} is capable of handling data from 8000+
177 processors but with somewhat severe tool responsiveness issues. We
178 have developed an approach to mitigate this data size problem with
179 options to trim-off ``uninteresting'' processors' data by not writing
180 such data at the end of an application's execution.
181
182 This is currently done through heuristics to pick out interesting
183 extremal (i.e. poorly behaved) processors and at the same time using a
184 k-means clustering to pick out exemplar processors from equivalence
185 classes to form a representative subset of processor data. The analyst
186 is advised to also link in the summary module via {\tt +tracemode
187 summary} and enable the {\tt +sumDetail} option in order to retain
188 some profile data for processors whose data were dropped.
189
190 \begin{itemize}
191 \item
192 {\tt +extrema}: enables extremal processor identification analysis at
193 the end of the application's execution.
194 \item
195 {\tt +numClusters}: determines the number of clusters (equivalence
196 classes) to be used by the k-means clustering algorithm for
197 determining exemplar processors. Analysts should take advantage of
198 their knowledge of natural application decomposition to guess at a
199 good value for this.
200 \end{itemize}
201
202 This feature is still being developed and refined as part of our
203 research. It would be appreciated if users of this feature could
204 contact the developers if you have input or suggestions.
205
206
207 \section{Controlling Tracing from Within the Program}
208 \label{sec::api}
209
210 \subsection{Selective Tracing}
211 \label{sec::selective tracing}
212
213 \charmpp{} allows user to start/stop tracing the execution at certain
214 points in time on the local processor. Users are advised to make these
215 calls on all processors and at well-defined points in the application.
216
217 Users may choose to have instrumentation turned off at first (by
218 command line option {\tt +traceoff} - see section \ref{sec::general options}) if some period of time in middle of the
219 application\'s execution is of interest to the user.
220
221 Alternatively, users may start the application with instrumentation
222 turned on (default) and turn off tracing for specific sections of the
223 application.
224
225 Again, users are advised to be consistent as the {\tt +traceoff}
226 runtime option applies to all processors in the application.
227
228 \begin{itemize}
229 \item
230 {\tt void traceBegin()}
231
232 Enables the runtime to trace events (including all user events) on the local processor where {\tt traceBegin} is called.
233
234 \item
235 {\tt void traceEnd()}
236
237 Prevents the runtime from tracing events (including all user events) on the local processor where {\tt traceEnd} is called.
238
239 \end{itemize}
240
241 \subsection{User Events}
242 \label{sec::user events}
243
244 \projections{} has the ability to visualize traceable user
245 specified events. User events are usually displayed in the Timeline view as vertical bars above the entry methods. Alternatively the user event can be displayed as a vertical bar that vertically spans the timelines for all processors. Follow these following basic steps for creating user events in a charm++ program:
246
247 \begin{enumerate}
248 \item
249 Register an event with an identifying string and either specify or acquire
250 a globally unique event identifier. All user events that are not registered will be displayed in white.
251
252 \item
253 Use the event identifier to specify trace points in your code of interest to you.
254 \end{enumerate}
255
256 The functions available are as follows:
257
258 \begin{itemize}
259 \item
260 {\tt int traceRegisterUserEvent(char* EventDesc, int EventNum=-1) }
261
262 This function registers a user event by associating {\tt EventNum} to
263 {\tt EventDesc}. If {\tt EventNum} is not specified, a globally unique
264 event identifier is obtained from the runtime and returned. The string {\tt EventDesc} must either be a constant string, or it can be a dynamically allocated string that is {\bf NOT} freed by the program. If the {\tt EventDesc} contains a substring ``***'' then the Projections Timeline tool will draw the event vertically spanning all PE timelines.
265
266 {\tt EventNum} has to be the same on all processors. Therefore use one of the following methods to ensure the same value for any PEs generating the user events:
267
268 \begin{enumerate}
269 \item
270 Call {\tt traceRegisterUserEvent} on PE 0 in main::main without specifying
271 an event number, and store returned event number into a readonly variable.
272 \item
273 Call {\tt traceRegisterUserEvent} and specify the event number on
274 processor 0. Doing this on other processors would have no
275 effect. Afterwards, the event number can be used in the following user
276 event calls.
277 \end{enumerate}
278
279 Eg. {\tt traceRegisterUserEvent("Time Step Begin", 10);}
280
281 Eg. {\tt eventID = traceRegisterUserEvent(``Time Step Begin'');}
282
283 \end{itemize}
284
285
286
287 There are two main types of user events, bracketed and non bracketed. Non-bracketed user events mark a specific point in time. Bracketed user events span an arbitrary contiguous time range. Additionally, the user can supply a short user supplied text string that is recorded with the event in the log file. These strings should not contain newline characters, but they may contain simple html formatting tags such as \texttt{<br>}, \texttt{<b>}, \texttt{<i>}, \texttt{<font color=\#ff00ff>}, etc.
288
289 The calls for recording user events are the following:
290
291 \begin{itemize}
292
293
294 \item
295 {\tt void traceUserEvent(int EventNum) }
296
297 This function creates a user event that marks a specific point in time.
298
299 Eg. {\tt traceUserEvent(10);}
300
301 \item
302 {\tt void traceUserBracketEvent(int EventNum, double StartTime, double EndTime) }
303
304 This function records a user event spanning a time interval from {\tt StartTime} to {\tt EndTime}. Both {\tt StartTime} and {\tt EndTime} should be obtained from a call to {\tt CmiWallTimer()} at the appropriate point in the program.
305
306 Eg.
307 \begin{verbatim}
308    traceRegisterUserEvent("Critical Code", 20); // on PE 0
309    double critStart = CmiWallTimer();;  // start time
310    // do the critical code
311    traceUserBracketEvent(20, critStart,CmiWallTimer());
312 \end{verbatim}
313
314 \item
315 {\tt void traceUserSuppliedNote(char * note) }
316
317 This function records a user specified text string at the current time.
318
319 \item
320 {\tt void traceUserSuppliedBracketedNote(char *note, int EventNum, double StartTime, double EndTime)}
321
322 This function records a user event spanning a time interval from {\tt StartTime} to {\tt EndTime}. Both {\tt StartTime} and {\tt EndTime} should be obtained from a call to {\tt CmiWallTimer()} at the appropriate point in the program.
323
324 Additionally, a user supplied text string is recorded, and the  {\tt EventNum} is recorded. These events are therefore displayed with colors determined by the {\tt EventNum}, just as those generated with {\tt traceUserBracketEvent} are.
325
326 \end{itemize}
327