Download source files - 18.6 Kb
Introduction
Most coders do some kind of rudimentary performance testing from time to time. The most common of which is probably comparing the execution times of two or more methods to see which one is most efficient.
While it is not difficult to implement these sorts of comparative tests (they are sometimes no more than 5-6 lines of code, including writing the results out to the console), I thought it would be a good idea to write a little library to not only make it quicker and easier to duplicate what many already do, but to enable a few slightly more involved scenarios.
Classes in this library
ExectuionTimer - This is the main class. It contains functions to time the execution of methods and display the results.
ExecutionTimerCollection - This is, well, a collection of ExecutionTimer objects.
ExecutionTimerManager - This class is used to manage a group of ExecutionTimers.
BlockTimer - This class implements the IDisposable interface and exists to be used with the C# 'using' statement.
TimedMethod - This class holds references to one or more delegates, whose target methods will be timed.
TimedMethodCollection - A collection of TimedMethod objects.
NameExistsExcpetion - Occurs when an ExecutionTimer is added to an ExecutionTimerManager that already contains a timer with the same name.
SeriesAbortedException - Occurs when a TimerManagerException could not run a series.
I won't cover everything in this article; I'll try to just hit the high points.
The BlockTimer Class
The most direct way of measuring the execution time of a method is to simply record the system's tick count immediately before and after the method being timed is executed:
Collapse
// This is the method we'll be timing throughout the article
void TakeOneSecond()
{
System.Threading.Thread.Sleep(1000);
}
long start = DateTime.Now.Ticks;
MethodToTime();
long end = DateTime.Now.Ticks;
long executionTime = end - start;
Console.WriteLine("MethodToTime took {0} ticks to execute.",
executionTime);
Now, that certainly wasn't difficult, but it can be even easier. The ExecutionTimer's (introduced shortly) static TimeBlock returns a BlockTimer object which implements IDisposable. Here is the BlockTimer class, in its entirety:
Collapse
public class BlockTimer : IDisposable
{
private string _description;
private long _start;
public BlockTimer(string description)
{
_description = description;
_start = DateTime.Now.Ticks;
}
public void Dispose()
{
long totalTime = DateTime.Now.Ticks - _start;
Console.WriteLine(_description);
Console.Write(" - Total Execution Time: ");
Console.Write(new TimeSpan(totalTime).TotalMilliseconds.ToString());
Console.WriteLine(" ms.");
}
}
That tiny class allows the last example to be rewritten like this:
Collapse
using(ExecutionTimer.TimeBlock("MethodToTime"))
{
TakeOneSecond();
}
// Output:
// Timer for TakeOneSecond
// - Total Execution Time: 1000 ms.
Note: The output from BlockTimer is in milliseconds because I thought that would be more useful than ticks.
If all you need is to replace the 3-4 lines of code with one line and a couple of curly braces, you're good to go. However, if you'd like more control over the output and/or how something gets timed, there's much more in store.
The ExecutionTimer Class
The main class in this library is the ExecutionTimer class. The simplest use of this class is as follows (this code doesn't really gain you anything over using the BlockTimer):
Collapse
ExecutionTimer timer = new ExecutionTimer("TakeOneSecond");
timer.Start();
// run the method being timed
TakeOneSecond();
timer.Stop();
// Write the results
// Note: Setting ExecutionTimer.AutoTrace to true
// would cause this to be called automatically when
// the timer is stopped.
Timer.Write();
// Output:
// ***********************
// Execution time for "TakeOneSecond" (Run 1): 1000 ms.
One way to ensure more accurate results when running any performance test is to run it multiple times. The ExecutionTimer class supports that by adding previous runs to a series when Start and Stop are called multiple times. Here's an example of running a series:
Collapse
// We'll pass true as the second parameter so each run will
// be written to the Console automatically
ExecutionTimer timer = new ExecutionTimer("TakeOneSecond", true);
// We'll do three runs
for(int i = 0; i < 3; i++)
{
timer.Start();
TakeOneSecond();
timer.Stop();
}
// Write the statistics for the series
timer.WriteSeries();
// Output:
// ***********************
// Execution time for "TakeOneSecond" (Run 1): 1000 ms.
//
// ***********************
// Execution time for "TakeOneSecond" (Run 2): 1000 ms.
//
// ***********************
// Execution time for "TakeOneSecond" (Run 3): 1000 ms.
//
// ***********************
// Stats for "TakeOneSecond":
// - Number of runs completed: 3
// - Average execution time per run: 1000 ms.
// - Shortest run: 1000 ms.
// - Longest run: 1000 ms.
Now, you not only get the results for each individual run (if AutoTrace is set to true), but you also get the total number of runs, average execution time, and shortest and longest runs.
There are a couple of different ways to alter the way results are output. The ExecutionTimer class has BeginDelim and EndDelim properties which you can use to specify what gets printed before and after the results for each run, as well as SeriesBeginDelim and SeriesEndDelim, which do the same for series results. As you can see from the previous example, the default string for BeginDelim and SeriesBeginDelim is "***********************", and an empty string for EndDelim and SeriesEndDelim.
Each of the properties just mentioned also has a "companion" property that is a delegate of type PrintString that will be used in place of the delimiting strings, if defined. The names of the companion properties are (not surprisingly) BeginPrintString, EndPrintString, SeriesBeginPrintString, and SeriesEndPrintString. Here is the definition of the PrintString delegate:
Collapse
public delegate string PrintString(string timerName);
The parameter passed to the PrintString delegate is the name of the timer in question. Here's an example of how to use the *Delim and *PrintString properties:
Collapse
private string GetExecutionDate(string timerName)
{
string header = timerName + " is being timed on ";
header += DateTime.Now.ToShortDateString();
header += " at ";
header += DateTime.Now.ToLongTimeString();
return header;
}
ExecutionTimer timer = new ExecutionTimer("Example", true);
// Set the method to be called before each run is printed
timer.BeginPrintString = new PrintString(GetExecutionDate);
// Set the string to be written before the series results are written
timer.SeriesBeginDelim = "Running series with blah, blah set to something";
timer.Start();
TakeOneSecond();
timer.Stop();
timer.WriteSeries();
In order to talk about some of the other features of the ExecutionTimer class, I need to introduce another class first. Namely, the TimedMethod class.
The TimedMethod Class
The TimedMethod class exists to facilitate the use of delegates to represent the methods to time. The Method property of TimedMethod represents the main method being timed by the ExecutionTimer. Just to clarify what I mean, here's a small example showing a use of ExecutionTimer I've already shown, as well as the equivalent use of TimedMethod:
Collapse
ExecutionTimer timer = new ExecutionTimer("TakeOneSecond", true);
for(int i = 0; i < 3; i++)
{
timer.Start();
TakeOneSecond();
timer.Stop();
}
timer.WriteSeries();
// Now do the same thing with delegates
ExecutionTimer timerWithDelegates = new ExecutionTimer("With Delegates", true");
// We'll pass the
timerWithDelegates.Method = new TimedMethod(new MethodInvoker(TakeOneSecond), 3);
timerWithDelegates.RunTimedMethod();
As you can probably deduce from the above example, the RunTimedMethod method of ExecutionTimer runs the method targeted by the specified delegate for the specified number of iterations, calling Start and Stop before and after each run.
I've used the MethodInvoker delegate here, which is defined in the System.Windows.Forms namespace, but the Method property of TimedMethod is of the base type Delegate so you can use whatever delegate is appropriate. If your delegate requires arguments, you can pass them via the Args property of TimedMethod.
The method we've been timing up till now (TakeOneSecond) does not change the state of any object, and can be called multiple times back-to-back and produce the same results. However, this is not the case if the method being timed alters something which needs to be reset before the method can be run again. To this end, the TimedMethod class defines two more delegate properties: SetUp and TearDown, which are called before and after the method being timed, respectively. Both properties also have companion properties (SetUpArgs and TearDownArgs) representing the arguments to be passed to those methods, if any.
Back to the ExecutionTimer Class
Up until now, all results have been written to the Console. However, the ExecutionTimer class has an Out property, which is of type TextWriter. This can be used to redirect the output to where ever is most appropriate, such as to a string for presentation in a message box, or to a text file, or to be parsed and entered into a database.
Collapse
ExecutionTimer timer = new ExecutionTimer("Example", true);
// Instead of writing to the console, we'll write to a file
StreamWriter writer = new StreamWriter("Execution Results.log");
timer.Out = writer;
timer.TimedMethod = new TimedMethod("Method 1",
new MethodInvoker(TakeOnSecond), 100));
timer.RunTimedMethod();
writer.Close();
Events of the ExecutionTimer Class
The ExecutionTimer class defines six events, which are TimerStarting, TimerStopped (there are no corresponding TimerStarted and TimerStopping events because they would alter the recorded execution time), ResultsPrinting, ResultsPrinted, SeriesResultsPrinting, and SeriesResultsPrinted.
They can be used to alter the properties of the ExecutionTimer, such as where the results will be printed, delimiter strings, etc., based on what is about to be printed, or the execution time of the most recent run, or whatever else you deem appropriate.
The ExecutionTimerManager Class
The ExecutionTimerManager class exists mostly for convenience. It allows you to control a group of ExecutionTimer objects with fewer lines of code. It can be useful for setting up tests to be run automatically. I can imagine a configuration file being used to specify what tests to run and the options used to run them, but I haven't implemented anything like that yet.
Here is an example of using the ExecutionTimerManager class:
Collapse
void RunManager()
{
TimedMethodCollection methods = new TimedMethodCollection();
methods.Add(new TimedMethod("No args",
new MethodInvoker(MethodToTime), 100));
methods.Add(new TimedMethod("Int arg",
new VoidIntArg(MethodToTime), new object[]{10}, 100));
methods.Add(new TimedMethod("String arg",
new VoidStringArg(MethodToTime), new object[]{" "}, 100));
ExecutionTimerManager manager = new ExecutionTimerManager();
StreamWriter writer = new StreamWriter("Managed Timers.log");
manager.Out = writer;
manager.ExecuteTimers(methods,false);
manager.WriteAll();
writer.Close();
}
delegate void VoidIntArg(int iterations);
delegate void VoidStringArg(string arg);
private string GetResultsHeader(string timerName)
{
string result = "Execution time for ";
result += timerName;
result += ":";
return result;
}
private void MethodToTime()
{
string res = "";
for(int i = 0; i < 10000; i++)
{
res += " ";
}
}
private void MethodToTime(int iterations)
{
string res = "";
for(int i = 0; i < iterations; i++)
{
res += " ";
}
}
private void MethodToTime(string str)
{
for(int i = 0; i < 10000; i++)
{
str += " ";
}
}
Conclusion
I'd like to be perfectly clear when I say this is not attempting to be a commercial-grade performance testing tool, or anything of the sort. There are a lot of variances to consider when testing for performance, and I have taken into account... well, none of them. Also, the first run of whatever method you're calling will often be the longest, as it won't get JIT'd until you call it for the first time.
These classes will do a good job, overall, of telling you which of your routines is quickest, but it obviously will not suggest any improvements as it is not a code analysis tool. If you take it for what it is, you may find it to be helpful.
I'd also like to add that the source code for this library is thoroughly commented. Some of the code samples from this article were lifted directly from the code comments. I used the XML commenting feature of the C# compiler. If you have NDoc, you can use it to build MSDN look-alike web pages for the documentation. If you don't have NDoc, I highly recommend it. The quality of my commenting improved dramatically once I started thinking about how it was going to look once I built the final documentation in NDoc. You can find it here.
License
This article has no explicit license attached to it but may contain usage terms in the article text or the download files themselves. If in doubt please contact the author via the discussion board below.
