Profiling .NET Applications I

If you are a serious developer, you are certain to have either come across or used tools to profile your application. This will let you know a couple of things about your code:

  1. How fast it (the program) executes
  2. How fast each method executes
  3. Bottlenecks within the code
  4. Number of times loops execute
  5. Memory usage
  6. Number of objects created

These are pretty useful metrics that can help you identify notoriously difficult to identify bugs, such as memory leaks. They also show you where you can concentrate on optimizing your code.

For this example I will use a very trivial console application that does nothing more than concatenate a large number of strings. This is in a static function imaginatively called ConcatenateWithPlus()

   1: class Program
   2:     {
   3:         static void Main(string[] args)
   4:         {
   5:             ConcatWithPlus();         
   6:         }
   7:         static void ConcatWithPlus()
   8:         {
   9:             Random r = new Random(0);
  10:             string s = “”;
  11:             for(int i =0;i <5000;i++)
  12:             {
  13:                 s += r.NextDouble().ToString();
  14:             }
  15:         }        
  16:     }

 

A couple of interesting things to note:

  1. It is entirely possible that if we used the same string repeatedly to concatenate, the compiler or the runtime might make some optimizations to improve the performance. To avoid this I use the random class to generate 5000 (pseudo) random strings
  2. Yes yes, pseudo random. This is because I want to generate the exact same sequence of strings. You’ll see why shortly

So, the next thing to do is run the application through a profiler. The better known ones are Red Gate Software’s ANTS Profiler and JetBrains’ dotTrace. Today I will use ANTS. (Both have evaluation versions you can download to check out)

First, open ANTS

ants1

This is the screen you should get

ants 2

We want the detailed mode. Click next

ants 3

As you can see, quite a number of applications can be profiled. A console application is a .NET desktop application so we select that an move on to the next screen.

ants 4

Here select the executable that you want to run. In our case, the console app.

ants 5

The final screen gives you control over what to profile. We can if we want also profile the .NET classes, or choose exactly what we want to profile. For simplicity, let’s take the first choice. Then click Finish and we’re off.

ants 6

Yes I do!

ants 8

You should get something like you see above

The points of interest are the following:

  1. The summary pane gives you an overview of the profile that has just been run and two reports:
    • Slowest Lines Of Code
    • Slowest Methods
  2. The all methods pane gives you a grid with all the profiled methods and some metrics, such as time (for the method itself) and time with children (for the method and any other methods it calls)
  3. The source code pane gives you the actual source code and time taken for each line of code. This is very valuable information because you can identify any slow algorithms and method calls.

ants 9

The all methods pane tell us that the ConcatWithPlus() call is the slowest, at 0.482 seconds. Can we improve this? Methinks so.

String concatenation is a very slow process. Due to the fact that they are immutable (cannot be changed once created), any method that purports to manipulate a string actucally creates a new string with the manipulations. So stuff like ToUpper(), ToLower(), etc actually creates a new string and returns the new instance.

Naturally, concatenation also has the same side effect. So in effect our code creates 5,000 string objects.

Hmm.

Can we avoid 5,000 string objects being created? Turns out that we can.

Enter the StringBuilder.

This is an object designed for precisely this sort of thing. So let’s create a second method that uses a StringBuilder.

Modify your code as follows:

   1: class Program
   2:     {
   3:         static void Main(string[] args)
   4:         {
   5:             ConcatWithPlus();
   6:             ConcatWithStringBuilder();
   7:         }
   8:         static void ConcatWithPlus()
   9:         {
  10:             Random r = new Random(0);
  11:             string s = “”;
  12:             for (int i = 0; i < 5000; i++)
  13:             {
  14:                 s += r.NextDouble().ToString();
  15:             }
  16:         }
  17:         static void ConcatWithStringBuilder()
  18:         {
  19:             Random r = new Random(0);
  20:             System.Text.StringBuilder sb = new System.Text.StringBuilder();
  21:             for (int i = 0; i < 5000; i++)
  22:             {
  23:                 sb.Append(r.NextDouble().ToString());
  24:             }
  25:         }
  26:     }

Now, we run the profiler again, by clicking the green Go button or Control + G

Then click the All Methods pane. The results should be interesting

ants 11

The method with the StringBuilder is several orders of magnitude faster than the concatenation!

The source code view reveals the same information slightly differently

ants 12

You can see the line with

   1: s += r.NextDouble();

Has a little red bar after the time (0.427). This is a contribution of that line of code to the total time taken. Notice the corresponding line for the StringBuilder

   1: sb.Append(r.NextDouble().ToString());

Does not have the bar. This is because graphing 0.0099 next to 0.430 is a bit of a stretch.

Thus we see the profiler has helped us identify a bottleneck and we have investigated how to correct it. Version 2 of our do nothing application will be MUCH faster.

AOB

Now, back to that Random business.

The System.Random class does not actually generate truly random numbers. In fact it is fairly predictable because given the same seed it generates the same sequence of numbers. I used this to generate a large set of randomish yet predictable strings for the test.

kick it on DotNetKicks.com

Share and Enjoy:These icons link to social bookmarking sites where readers can share and discover new web pages.
  • blogmarks
  • co.mments
  • del.icio.us
  • digg
  • Fark
  • feedmelinks
  • Furl
  • LinkaGoGo
  • Ma.gnolia
  • NewsVine
  • Reddit
  • TailRank
  • YahooMyWeb
 

One trackback

Leave a Reply