Revisiting ANTS Performance Profiler 7.4

Posted by James Michael Hare on Geeks with Blogs See other posts from Geeks with Blogs or by James Michael Hare
Published on Thu, 18 Oct 2012 17:30:29 GMT Indexed on 2012/10/22 11:02 UTC
Read the original article Hit count: 735

Filed under:

Last year, I did a small review on the ANTS Performance Profiler 6.3, now that it’s a year later and a major version number higher, I thought I’d revisit the review and revise my last post. This post will take the same examples as the original post and update them to show what’s new in version 7.4 of the profiler.

Background

A performance profiler’s main job is to keep track of how much time is typically spent in each unit of code. This helps when we have a program that is not running at the performance we expect, and we want to know where the program is experiencing issues.

There are many profilers out there of varying capabilities. Red Gate’s typically seem to be the very easy to “jump in” and get started with very little training required.

So let’s dig into the Performance Profiler. I’ve constructed a very crude program with some obvious inefficiencies. It’s a simple program that generates random order numbers (or really could be any unique identifier), adds it to a list, sorts the list, then finds the max and min number in the list.

Ignore the fact it’s very contrived and obviously inefficient, we just want to use it as an example to show off the tool:

   1: // our test program
   2: public static class Program
   3: {
   4:     // the number of iterations to perform
   5:     private static int _iterations = 1000000;
   6:  
   7:     // The main method that controls it all
   8:     public static void Main()
   9:     {
  10:         var list = new List<string>();
  11:  
  12:         for (int i = 0; i < _iterations; i++)
  13:         {
  14:             var x = GetNextId();
  15:  
  16:             AddToList(list, x);
  17:  
  18:             var highLow = GetHighLow(list);
  19:  
  20:             if ((i % 1000) == 0)
  21:             {
  22:                 Console.WriteLine("{0} - High: {1}, Low: {2}", i, highLow.Item1, highLow.Item2);
  23:                 Console.Out.Flush();
  24:             }
  25:         }
  26:     }
  27:  
  28:     // gets the next order id to process (random for us)
  29:     public static string GetNextId()
  30:     {
  31:         var random = new Random();
  32:         var num = random.Next(1000000, 9999999);
  33:         return num.ToString();
  34:     }
  35:  
  36:     // add it to our list - very inefficiently!
  37:     public static void AddToList(List<string> list, string item)
  38:     {
  39:         list.Add(item);
  40:         list.Sort();
  41:     }
  42:  
  43:     // get high and low of order id range - very inefficiently!
  44:     public static Tuple<int,int> GetHighLow(List<string> list)
  45:     {
  46:         return Tuple.Create(list.Max(s => Convert.ToInt32(s)), list.Min(s => Convert.ToInt32(s)));
  47:     }
  48: }

So let’s run it through the profiler and see what happens!

Visual Studio Integration

First, let’s look at how the ANTS profilers integrate with Visual Studio’s menu system. Once you install the ANTS profilers, you will get an ANTS menu item with several options:

Integration

Notice that you can either Profile Performance or Launch ANTS Performance Profiler. These sound similar but achieve two slightly different actions:

  • Profile Performance: this immediately launches the profiler with all defaults selected to profile the active project in Visual Studio.
  • Launch ANTS Performance Profiler: this launches the profiler much the same way as starting it from the Start Menu. The profiler will pre-populate the application and path information, but allow you to change the settings before beginning the profile run.

So really, the main difference is that Profile Performance immediately begins profiling with the default selections, where Launch ANTS Performance Profiler allows you to change the defaults and attach to an already-running application.

Let’s Fire it Up!

So when you fire up ANTS either via Start Menu or Launch ANTS Performance Profiler menu in Visual Studio, you are presented with a very simple dialog to get you started:

image_thumb1_thumb

Notice you can choose from many different options for application type. You can profile executables, services, web applications, or just attach to a running process.

In fact, in version 7.4 we see two new options added:

  • ASP.NET Web Application (IIS Express)
  • SharePoint web application (IIS)

So this gives us an additional way to profile ASP.NET applications and the ability to profile SharePoint applications as well.

You can also choose your level of detail in the Profiling Mode drop down. If you choose Line-Level and method-level timings detail, you will get a lot more detail on the method durations, but this will also slow down profiling somewhat. If you really need the profiler to be as unintrusive as possible, you can change it to Sample method-level timings. This is performing very light profiling, where basically the profiler collects timings of a method by examining the call-stack at given intervals.

Which method you choose depends a lot on how much detail you need to find the issue and how sensitive your program issues are to timing. So for our example, let’s just go with the line and method timing detail.

So, we check that all the options are correct (if you launch from VS2010, the executable and path are filled in already), and fire it up by clicking the [Start Profiling] button.

Profiling the Application

Once you start profiling the application, you will see a real-time graph of CPU usage that will indicate how much your application is using the CPU(s) on your system.

image_thumb4_thumb

During this time, you can select segments of the graph and bookmark them, giving them mnemonic names. This can be useful if you want to compare performance in one part of the run to another part of the run.

image_thumb8_thumb

Notice that once you select a block, it will give you the call tree breakdown for that selection only, and the relative performance of those calls. Once you feel you have collected enough information, you can click [Stop Profiling] to stop the application run and information collection and begin a more thorough analysis.

Analyzing Method Timings

So now that we’ve halted the run, we can look around the GUI and see what we can see.

image_thumb11_thumb

By default, the times are shown in terms of percentage of time of the total run of the application, though you can change it in the View menu item to milliseconds, ticks, or seconds as well. This won’t affect the percentages of methods, it only affects what units the times are shown.

Notice also that the major hotspot seems to be in a method without source, ANTS Profiler will filter these out by default, but you can right-click on the line and remove the filter to see more detail. This proves especially handy when a bottleneck is due to a method in the BCL.

image_thumb13_thumb

So now that we’ve removed the filter, we see a bit more detail:

image_thumb16_thumb

In addition, ANTS Performance Profiler gives you the ability to decompile the methods without source so that you can dive even deeper, though typically this isn’t necessary for our purposes.

When looking at timings, there are generally two types of timings for each method call:

  • Time: This is the time spent ONLY in this method, not including calls this method makes to other methods.
  • Time With Children: This is the total of time spent in both this method AND including calls this method makes to other methods.

In other words, the Time tells you how much work is being done exclusively in this method, and the Time With Children tells you how much work is being done inclusively in this method and everything it calls.

You can also choose to display the methods in a tree or in a grid. The tree view is the default and it shows the method calls arranged in terms of the tree representing all method calls and the parent method that called them, etc. This is useful for when you find a hot-spot method, you can see who is calling it to determine if the problem is the method itself, or if it is being called too many times.

image_thumb18_thumb

The grid method represents each method only once with its totals and is useful for quickly seeing what method is the trouble spot. In addition, you can choose to display Methods with source which are generally the methods you wrote (as opposed to native or BCL code), or Any Method which shows not only your methods, but also native calls, JIT overhead, synchronization waits, etc.

image_thumb20_thumb

So these are just two ways of viewing the same data, and you’re free to choose the organization that best suits what information you are after.

Analyzing Method Source

If we look at the timings above, we see that our AddToList() method (and in particular, it’s call to the List<T>.Sort() method in the BCL) is the hot-spot in this analysis. If ANTS sees a method that is consuming the most time, it will flag it as a hot-spot to help call out potential areas of concern. This doesn’t mean the other statistics aren’t meaningful, but that the hot-spot is most likely going to be your biggest bang-for-the-buck to concentrate on.

So let’s select the AddToList() method, and see what it shows in the source window below:

image_thumb22_thumb

Notice the source breakout in the bottom pane when you select a method (from either tree or grid view). This shows you the timings in this method per line of code. This gives you a major indicator of where the trouble-spot in this method is.

So in this case, we see that performing a Sort() on the List<T> after every Add() is killing our performance! Of course, this was a very contrived, duh moment, but you’d be surprised how many performance issues become duh moments.

Note that this one line is taking up 86% of the execution time of this application! If we eliminate this bottleneck, we should see drastic improvement in the performance.

So to fix this, if we still wanted to maintain the List<T> we’d have many options, including: delay Sort() until after all Add() methods, using a SortedSet, SortedList, or SortedDictionary depending on which is most appropriate, or forgoing the sorting all together and using a Dictionary.

Rinse, Repeat!

So let’s just change all instances of List<string> to SortedSet<string> and run this again through the profiler:

image_thumb25_thumb

Now we see the AddToList() method is no longer our hot-spot, but now the Max() and Min() calls are! This is good because we’ve eliminated one hot-spot and now we can try to correct this one as well.

As before, we can then optimize this part of the code (possibly by taking advantage of the fact the list is now sorted and returning the first and last elements). We can then rinse and repeat this process until we have eliminated as many bottlenecks as possible.

Calls by Web Request

Another feature that was added recently is the ability to view .NET methods grouped by the HTTP requests that caused them to run. This can be helpful in determining which pages, web services, etc. are causing hot spots in your web applications.

image_thumb2_thumb

Summary

If you like the other ANTS tools, you’ll like the ANTS Performance Profiler as well. It is extremely easy to use with very little product knowledge required to get up and running.

There are profilers built into the higher product lines of Visual Studio, of course, which are also powerful and easy to use. But for quickly jumping in and finding hot spots rapidly, Red Gate’s Performance Profiler 7.4 is an excellent choice.

Technorati Tags: ,,,

© Geeks with Blogs or respective owner