VSTS (Orcas March CTP) Profiler - Comparing Performance Reports
I recently came across this blog by Ianhu and was interested to explore the comparsion of performance reports.
Being able to compare reports from two performance runs is very important since without it, it becomes very difficult to figure out if one has been able to make improvements or not post the code changes. Hence I created a dummy application that created an array of 200000 strings and then wrote it on the Console. I wanted to see the impact of using an object based ArrayList or a generics based List<T>.
Post the capturing of execution data, I started to look at the report generated. The UI for this has been changed a bit and considering this is March CTP, this may change further. I will hence not get too much into the UI apart from a few quick observations
- There is new query option with which you can search for specific items of interest in the report
- The various tabs for Summary, Functions, Call Tree, etc have now become drop down items
- The earlier Functions view is now same as Modules view. However Functions view is still there, but it no longer shows the parent modules. That is shown in the new Modules tab.
- There is a new view for displaying Marks. These can be useful to take a snapshot during the execution for some interesting events. By default it captures the start and end of the performance test session.
- There are new views for Process data and for showing the Event tracing for Windows (ETW). See more information on ETW on MSDN and Matt Pietrek's blog. The ETW view doesn't seem to work in March CTP so I couldn't really see what all values it will display.
An interesting addition to the Call Tree view is the support for finding and highlighting hot paths. This is very handy to quickly find out key areas that are most time consuming and can help shortlist areas to explore for performance tuning. The following figure shows how "hot path" look like (with highlighting enabled).
To view hot paths, in the Call Tree view, collapse all the nodes below, keep focus on the top node and hit the "Expand Hot Path" icon in the toolbar.
Coming back to the comparison report. This shows how the time spent in the functions has changed between the two reports and there is visual indication of an increase in time or decrease in time, as seen in the following figure.
There are however few issues that I have with this comparison report and maybe things will change by the time RTM is available.
1. A function taking more time has a positive delta and appears with green upward arrow (as seen in the figure above). This seems to be wrong since when I do performance tuning, I would expect time taken the function to come down.
2. Individual Function time comparison doesn't makes much sense. The comparison should really happen on the overall time basis. Consider a case where a function though is taking more time, but has impacted another function to take far less time and thus giving an overall improvement in the application's performance. This isn't easily understood in the comparison report.
3. In the Functions view, the "Elapsed Inclusive time" shows time spent in that function and all its children. If we look at the application's entry point function, we will get an idea of overall time it has taken for the code to execute. If this time decreases in the second run, it would mean an improvement in the performance. However the comparison report still shows this with negative delta (orange down arrow). There should probably be a mechanism to show overall time comparison for the entry point method separately.
4. In the current version there seems to be some problem in displaying the "Elapsed Inclusive time" comparisons. The values shown in old and new value columns didn't match up with the ones in the baseline and new report. Not only they didn't match, they seemed to be too high.
As I explore this further, I will post more entries here. If you have any comments/observations to share, do post your comments here.