Demystifying The Performance Analysis Session File
You have just installed DevPartner Studio, instrumented your application, and launched Performance Analysis. You are fired up and ready to go. Then it hits you, you have no idea what you are looking at, or any idea what this stuff means.
What are all of these numbers and columns?
How am I supposed to interpret this data?
How in the heck is any of this information useful to me?
Trust me, I've been there too!
At first glance, the Performance Analysis session file can appear a little daunting, however, the presentation of information makes more sense then you may realize.
What is Performance Analysis?
Let’s quickly cover what the component does. In a nutshell, Performance Analysis profiles distributed, and component-based applications. It collects performance data, COM method calls, etc, of which the server data is transmitted back to the client and automatically correlated into a single session file.
Moreover, the Performance Analyzer is used to collect the performance metrics of DLLs, source code files, assemblies, methods, functions, and line-level code. The session data made available to you, assists in highlighting performance issues, anywhere in your code, from third-party APIs, and or the operating system.
Session File Breakdown
The completion of a successful performance profiling session results in a session file with the extension of *.*.dpprf. By default, the session file has the naming convention of the profiled executable's name, appended with a numerical representation of subsequent runs.
When first displayed, the session file will be presented as a two-paned window. A tree list will display filtered data and the tabulated pane will display session data. (See Fig. 1)
The tree list to the left is the filtered pane, listing the performance data from your profiled application (.exe, dll, .ocx, managed-assemblies, etc). Expanding the view of these components will display the timing metrics for each source file (.cpp, .vb, .cs, etc). *Note: The percentage in parentheses represents the total execution time. (See Fig. 2)
Fig. 2 shows us that animationinstance.cpp, spent 0.3% of the session time in that section of the code. Whereas, dxut.cpp spent on 0.2%.
*Note: During the execution of MutliAnimation.exe, used for this demonstration, only certain parts of the application was executed, therefore, 0.0% metrics in certain areas.
If you look further down the tree in Fig. 2, you will notice that there is a high percentage listed for System. Usually, you will find that System produces the highest percentage of time.
By expanding the System node, you can research how your application uses system resources. However, keep in mind that it is your source code that controls the system, and it is up to you to determine where the actual performance losses may be coming from.
Next to the tree list is the data pane. The session data pane provides method level metrics. You have a total of three tabs available to you across the top: Method List, Source, and Session Summary. (See Fig. 3)
Not really. So what is the information actually telling us?
Let’s take a look at the method DXUTRender3DEnviornment(void). (See Fig. 3)
We can see that the time spent in the method is 0.0%, in actuality this is probably closer to 0.1%. But lets take a look at the time spent “with Children” which is 9.4%, and how many times our method was called - 2,984 times. This could be a possible candidate for further investigation.
First let’s discuss what some of these columns mean.
% in Method - indicates how much time was spent during the session percentage wise.
% with Children - indicates how much time was spent in the method, and any child methods.
Called - represents the number of times a particular method was called.
Average - the average execution time of the method.
Real - the average execution time of the method, and its child methods, including the time spent in threads of other processes. *Note: Real is the value also known as wall-clock-time.
Viewing the Source Code
The first item in this section that you may want to investigate are the lines with the highest amount of time associated with them. These lines of code represent the slowest executed lines.
Here is a quick rundown of the columns:
Count - indicates the number of times that a particular line of code was executed.
% of Method - indicates how much time was spent on a particular line of code, and the methods it calls as a percentage of the time spent in the entire method.
% with Children - indicates how much time is spent on a particular line of code, and the methods it calls as a percentage of the time spent during the session.
Time - the total time spent executing a particular line of code and the methods it calls during the session. (See Fig. 7)
Well there you have it, a 50,000ft view of the Performance Analysis session file. Although we only touched on the high level details. You should now have a better understanding of Performance analysis, how to use it, and how to interpret the data.
For a more in-depth look at Performance Analysis, its available features, options, and configurations - please consult the DevPartner User Guide (Micro Focus, 2013, p. 207).
Micro Focus (2013). Understanding DevPartner -Chapter 7 “In-Depth Performance Analysis”(207).