View source for Extra Extra!!

''by [[Michelle Harr]] and [[Tina Lemire]]''

Extra is the execution trace analyzer for C Set++. It helps you understand the behavior of your application by performing an execution trace. By collecting execution trace data and presenting it in several graphical diagrams, Extra can provide information on:
* ''Timing and tuning:'' The trace file contains a detailed record of function calls and returns. The events let Extra's utility programs display the trace in a chronologically-scaled format. This helps you find the "hot spots" in the code and the cause of hose hot spots.
* ''Program hangs and deadlocks:'' Extra provides a complete history of the events leading up to the point the program stopped. You can view the function call stack any place in the application.
* ''Multithread interactions:'' You can look at the sequencing of procedures across threads, which can make problems with critical sections visible.

Extra runs your program in near real-time; that is, only a few percent of overhead is added to the program's run time. And, this overhead is removed by the analysis programs. This makes the timings very accurate without specialized timing hardware. Plus, your program's runtime characteristics are virtually unchanged by running it under Extra's control.

==Hint 1: Customize the Execution Monitor==
Direct Extra which specific executables, object files, or functions in an execution trace to include. Or, set ''"trigger procedures"'' to start and stop tracing in the middle of your application. When tracing with a trigger, Extra starts recording events when the trigger is entered and stops recording events when the trigger exits.

Set a timeout control to stop your application if it gets into an infinite loop. And, optionally trace file accesses that your application makes using common DOS file functions. Or, link to Extra's traceable version of DOS, PM GPI, and PM WIN libraries and trace these APIs.

Insert calls to Extra at critical points in your application to add your own user events to a trace file. For C, the prototype for the user event call is <tt>VOID EXTRA(PSZ string);</tt> and a sample user event is <tt>EXTRA( "well, we actually got to this code]" );</tt> For C++, the prototype for the call is <tt>EXTERN "C" { VOID EXTRA(PSZ string); }</tt> and the sample user event is the same as in C. Be sure to use static constant character strings for your user-event strings.

==Hint 2: Use a Combination of Views==
When you have a new application to learn and don't want to wade through code listings to understand how the code works, use a combination of the ''Call Nesting Diagram'' and the ''Dynamic Call Graph'' to get a good understanding of the program's flow. ''Figure 1'' shows a Dynamic Call Graph diagram from our favorite sample, PMLINES. This diagram gives you an overall view of the program's flow. You can see the two threads and tell which functions consume most of the application's execution time.
[[Image:Extra-Fig-1.gif|thumb|''Figure 1. Dynamic Call Graph diagram'']]

==Hint 3:Use Correlation==
One diagram cannot show everything of interest. So, the three time-scaled diagrams (Call Nesting, Time Line, and Execution Density) can be correlated, based on an event time or a time interval.

For example, use the Time Line diagram to get an overall view of the trace. Then, use the Call Nesting diagram to show all of the trace details. You can identify a point of interest in the Time Line diagram and correlate it to the Call Nesting diagram. Press and hold mouse button two in the Time Line diagram, and drag the mouse pointer to the Call Nesting display. When you release mouse button two, Extra scrolls to the trace events whose time stamps most nearly correspond to the specified time interval into the Call Nesting window and highlights the corresponding parts of both diagrams.

Also, use correlation to place a bookmark in one of your time-scaled diagrams. This is called correlating to the desktop. To do this, correlate as above, but drag the mouse pointer to the desktop. Then, release mouse button two. This will highlight the spot in the diagram -- just like when you correlate to another diagram.

==Hint 4:Use Color and Size==
Extra uses the color and size of arcs and nodes in the Dynamic Call Graph to show you the times associated with the calls and functions. The diagram shows both execution time and active time; that is, the, time spent on the active call stack. Each node's height shows its execution time; width shows active time.

A short, wide node, such as a <tt>main</tt> function that doesn't do much processing on its own, has very little execution time, but is on the call stack for a long time. If a function is waiting for a message, that time is logged as part of its active time. The thickness of the arcs represents the number of calls between two functions.

We paint the nodes and arcs in 4 colors and assign the colors based on execution time for nodes and on number of calls. For example, we use red for functions with execution times greater than 1/2 the maximum execution time, yellow for functions with execution times between 1/4 and 1/2 maximum, cyan for functions with execution times between 1/8 and 1/4 maximum, and gray for functions with execution times below 1/8 maximum.

Returning to ''Figure 1'', notice the different shades of gray (representing colors) used for the nodes. The short, wide node at the upper right is the <tt>Drawing Thread</tt> function, which spends a lot of time calling other functions. The three big light gray box es are the functions that consume most of the time: <tt>GpiLine, GpiSetColor,</tt> and <tt>WinPeekMsg</tt>.

==Hint 5:Use the Execution Density==
Execution Density is similar to the Time Line diagram, in that time is proportional along the vertical axis. The delta time can be varied through the Scale pages dialog; the smaller the number of pages, the larger the delta. Extra assigns every function traced a vertical column in the diagram. If a particular function is executed during a time slice, Extra paints a little color in its column. So, the trace time is divided into a series of equal time slices.

Think of these time slices as buckets that will hold a certain capacity of time. Extra walks through the trace file filling up each bucket with time from functions. When a bucket becomes full, Extra examines its contents and calculates the percentage of the time slice that each function accumulated. Then, Extra maps the percentages to a range and a color (this can be varied through the ''Color'' dialog) and paints it to the screen. When you alter the scale of the diagram, you actually change the bucket's capacity. When filling, its contents will differ, and it will result in visually different drawing.

''Figure 2'' shows an Execution Density diagram from PMLINES. On the right side of ''Figure 2'', there are 5 vertical columns of time slices. Solid vertical columns tend to be very active functions. Examining the columns horizontally, it appears that these 5 functions are always called within a single time slice, and the functions are executed one after another in some regular pattern. main resides in the first column of ''Figure 2''. It appears to be an alternating vertical column of the function color and the background color. This appearance tends to show up for irregularly called functions, and especially for main calling functions.
[[Image:Extra-Fig-2.gif|thumb|''Figure 2. Execution Density diagram'']]

When using Execution Density, you might want to see only the functions that take a large percentage of execution time. You can filter out some of the functions by setting their colors equal to the background color. For example, if you don't want to see functions that take 0 to 1% of execution time, set the color for that group to the background color. Those functions will disappear from the diagram.

==Hint 6:Use the Zoom Feature==
To zoom in to a particular point in Execution Density or Time Line, you need to keep the particular slice of time in sight. To do this, bring up another diagram that allows correlation and correlate from what you're interested in to the second diagram. Then, use the Scale option without ever losing your place. When you've set the scale, simply correlate from the second diagram back to the original display. If you don't want to open up another diagram, scale the diagram up in small steps. With each scaling step, you can scroll your correlation bar to the top of the window, where it will remain.

==Hint 7:Use Pattern Recognition==
Pattern recognition is a feature of the Call Nesting diagram that you can use when a single thread appears. It looks at a single thread and finds patterns of calls and returns. When this feature is on, the Call Nesting diagram shows these patterns as a curved arc and number of repetitions to the right of the series of calls and returns. This technique shortens the number of pages for the execution trace. An experienced user seeing large repetitions of patterns could group the functions with <tt>pragma alloc_text</tt> statements to limit the number of page swaps between calls in the pattern for improved performance.

==Hint 8:Place Bookmarks in Your Trace Files==
Annotations are a way to place a bookmark in the trace file. In the Call Nesting diagram, you can note what's being displayed next to the calls and returns. Extra writes these annotation notes in the trace file itself, so you can use them whenever you look at the trace file.

You also can make notes to yourself in the trace file using user events. User events can be placed as bookmarks in the code to locate where a certain structure has been executed or to locate where, in the trace file, you would like to scroll. Consider a user event to be a smart printf statement that can be used for a variety of debugging purposes.

==Hint 9:Understand Exception Exits==
''My program died at 1249B900 - how did it get there?'' Extra tells you where your application was when an exception exits. For example, your application causes an exception in the class libraries and seems to exit cleanly. But, you have no idea where the application exits. Extra's Call Nesting view of your trace shows you exactly where you were on exit and how you got there.

==Summary==
This article has listed some suggestions that will help you to become a whiz at tracing your applications. They will also help you understand why your applications behave the way the do.

==For More Information...==
Extra's online help is a good place get more information about specific features and techniques. The ''"Execution Trace Analyzer Introduction"'' booklet, number S61G-1398, is a printed introduction to Extra and its features. You can reach the IBM C Set++ developers at cset2@vnet.ibm.com on the Internet and CSET2 at VNET on Bitnet.

==About the Authors - Michelle Harr and Tina Lemire==
''Michelle Harr'' is an Advisory Programmer in Software Products in Lexington, Kentucky. Since joining IBM in 1979, Michelle has worked on automated chip design, typewriter development, debuggers, and execution trace analysis.

''Tina Lemire'' is a Senior Associate Programmer in Software Products in Lexington, Kentucky. Since joining IBM in 1990, Tina has worked on OS/2 linkers and execution trace analysis. Her main focus has been in the area of user interface design and implementation.

{{IBM-Reprint}}
[[Category:Developer Connection News]]