Friday, July 12, 2013

Using StopWatch to calibrate code performance


When we have to calibrate the performance of a loop, method or block of code we quickly tend to throw in few datetime.now and calculate the time difference. This approach has some flaws and does not provide accurate results. One major reason is datetime.now has a very low resolution depending on the computer, a typical computer has a resolution of somewhere around 100 ticks per second.

Microsoft introduced the Stopwatch class to help developers get more accurate time stamp. Stopwatch is generally more precise then datetime.now and secondly it’s more lightweight, also it support object oriented design. So what does the stopwatch class do, It just stores the current time-stamp (via QueryPerformanceCounter) when you start it, and compare it to the time-stamp when you stop it, so between start and stop it does not use cpu cycles and so it does not effect the performance of your code. Stopwatch was designed specifically for accurate time measurements, so you can be sure it is optimized. Though it would be a good idea to remove any performance counters in a release build. It is also much more accurate than comparing successive values of datetime.now.

For everyday debugging use case we need a easy and clean code to calculate execution time, so lets create a re-usable class that can be easily used to measure performance of our code.


   1: using System;
   2: using System.Diagnostics;
   3:  
   4: namespace Common.Helper
   5: {
   6:     public class StopWatchHelper
   7:     {
   8:         public static void CalculateTime(string stopWatchLabel, Action action)
   9:         {
  10:             var internalStopWatch = new InternalStopWatch();
  11:             action();
  12:             PrintToConsole(internalStopWatch.TimeDifference(), null, stopWatchLabel);
  13:         }
  14:  
  15:         public static void CalculateTime(Action action)
  16:         {
  17:             var internalStopWatch = new InternalStopWatch();
  18:             action();
  19:             PrintToConsole(internalStopWatch.TimeDifference(), action.Method.Name, null,
  20:                            new StackTrace(new StackFrame(1, true)));
  21:         }
  22:  
  23:         private static void PrintToConsole(TimeSpan timeDifference, string methodName = null,
  24:                                            string stopWatchLabel = null, StackTrace st = null)
  25:         {
  26:             if (string.IsNullOrEmpty(stopWatchLabel))
  27:             {
  28:                 PrintDottedLine();
  29:                 Console.WriteLine(" Method : {0} ", methodName);
  30:                 Console.WriteLine(" Time : {0} ", timeDifference);
  31:                 Console.WriteLine(" Location: {0}", st);
  32:                 PrintDottedLine();
  33:             }
  34:             else
  35:             {
  36:                 PrintDottedLine();
  37:                 Console.WriteLine(" Label : {0} ", stopWatchLabel);
  38:                 Console.WriteLine(" Time : {0} ", timeDifference);
  39:                 PrintDottedLine();
  40:             }
  41:         }
  42:  
  43:         private static void PrintDottedLine()
  44:         {
  45:             Console.WriteLine("-------------------------------------------------\n");
  46:         }
  47:  
  48:     }
  49:  
  50:     internal class InternalStopWatch
  51:     {
  52:         private readonly Stopwatch stopwatch;
  53:  
  54:         public InternalStopWatch()
  55:         {
  56:             stopwatch = new Stopwatch();
  57:             stopwatch.Start();
  58:         }
  59:  
  60:         public TimeSpan TimeDifference()
  61:         {
  62:             stopwatch.Stop();
  63:             return stopwatch.Elapsed;
  64:         }
  65:  
  66:     }
  67:  
  68: }



Code for the main console application

   1: using System;
   2: using System.Collections.Generic;
   3: using Common.Helper;
   4:  
   5: namespace StopWatchHelperConsole
   6: {
   7:     internal class Program
   8:     {
   9:         private static void Main(string[] args)
  10:         {
  11:             //If not release mode then exit the application
  12:             if (!CheckIfReleaseMode()) return;
  13:  
  14:             //Single line statment
  15:             var list = CreateNewList();
  16:             StopWatchHelper.CalculateTime(list.Sort);
  17:  
  18:             //Use Lambda
  19:             list = CreateNewList();
  20:             StopWatchHelper.CalculateTime(() => { list.Sort(); });
  21:  
  22:             //User a label to indicate the location
  23:             list = CreateNewList();
  24:             StopWatchHelper.CalculateTime("StopWatch for List", () =>
  25:                 {
  26:                     list.Sort();
  27:                     list.Sort();
  28:                 });
  29:  
  30:             Console.Read();
  31:         }
  32:  
  33:         private static List CreateNewList()
  34:         {
  35:             var list = new List();
  36:             const int size = 10000;
  37:             var random = new Random();
  38:             for (int i = 0; i < size; ++i)
  39:                 list.Add(random.Next());
  40:             return list;
  41:         }
  42:  
  43:         private static bool CheckIfReleaseMode()
  44:         {
  45: #if DEBUG
  46:             Console.WriteLine("Performance test should be done in Relase Mode");
  47:             Console.Read();
  48:             return false;
  49: #else
  50:             return true;
  51: #endif
  52:         }
  53:     
  54:     }



Output on the console screen

Console Output






















No comments:

Post a Comment