Click here to Skip to main content
Click here to Skip to main content

A Debug Stopwatch

, 15 Dec 2007 CPOL
Rate this:
Please Sign up or sign in to vote.
A debug build stopwatch useful for diagnostic timing.

Screenshot -

The Problem

On occasions, one needs to take time samples of an operation but only as a diagnostic during development and/or testing in a debug build. And, while there is an excellent Stopwatch class in .NET 2.0, this class is inappropriate for non-diagnostic time sampling because it:

  1. is not a static class, and
  2. therefore does not support conditional debug builds.

The Solution

The solution is to wrap the Stopwatch class in a static class (called DebugStopwatch) that exposes the Stopwatch methods as wrapped in methods decorated with the ConditionalAttribute attribute. Also, because one would probably want to measure several intervals simultaneously, the DebugStopwatch class, being static (and therefore cannot be created as an instance) has to provide functionality to manage multiple instances of the .NET Stopwatch class. As an added feature, the DebugStopwatch class also allows one to accumulate multiple time samples. This might be useful to measure variances in a repetitive task.

The Implementation

The Sample Wrapper Class

This class is a simple wrapper for taking a time sample. We'll see how this class is used later. The sample name can be used to provide application specific information about the sample.

/// <span class="code-SummaryComment"><summary></span>
/// A wrapper for a sample in time.
/// <span class="code-SummaryComment"></summary></span>
public class Sample
{
  protected string sampleName;
  protected long milliseconds;

  /// <span class="code-SummaryComment"><summary></span>
  /// Gets/sets milliseconds
  /// <span class="code-SummaryComment"></summary></span>
  public long Milliseconds
  {
    get { return milliseconds; }
  }

  /// <span class="code-SummaryComment"><summary></span>
  /// Returns sampleName
  /// <span class="code-SummaryComment"></summary></span>
  public string SampleName
  {
    get { return sampleName; }
  }

  public Sample(string sampleName, long milliseconds)
  {
    this.sampleName = sampleName;
    this.milliseconds = milliseconds;
  }
}

The SampleDelta Wrapper Class

This class is a wrapper for the difference s[1]-s[0] and the total elapsed time s[1]. We'll see how this class is used later. The sample name can be used to provide application specific information about the sample.

/// <span class="code-SummaryComment"><summary></span>
/// A wrapper for elapsed time between samples
/// and the total time from the first sample 
/// to the current sample.
/// <span class="code-SummaryComment"></summary></span>
public class SampleDelta
{
  protected string sampleName;
  protected long milliseconds;
  protected long totalMilliseconds;

  /// <span class="code-SummaryComment"><summary></span>
  /// Returns totalMilliseconds
  /// <span class="code-SummaryComment"></summary></span>
  public long TotalMilliseconds
  {
    get { return totalMilliseconds; }
  }

  /// <span class="code-SummaryComment"><summary></span>
  /// Returns milliseconds
  /// <span class="code-SummaryComment"></summary></span>
  public long DeltaMilliseconds
  {
    get { return milliseconds; }
  }

  /// <span class="code-SummaryComment"><summary></span>
  /// Returns sampleName
  /// <span class="code-SummaryComment"></summary></span>
  public string SampleName
  {
    get { return sampleName; }
  }

  public SampleDelta(string sampleName, long milliseconds, long totalMilliseconds)
  {
    this.sampleName = sampleName;
    this.milliseconds = milliseconds;
    this.totalMilliseconds = totalMilliseconds;
  }
}

The DebugStopwatch Class

The Internal Collections

/// <span class="code-SummaryComment"><summary></span>
/// Encapsulates methods that are executed only in Debug mode for measuring
/// timespans.
/// <span class="code-SummaryComment"></summary></span>
public static class DebugStopwatch
{
  internal static Dictionary<Enum, Stopwatch> stopwatchMap = 
       new Dictionary<Enum, Stopwatch>();
  internal static Dictionary<Enum, List<Sample>> stopwatchSampleMap = 
       new Dictionary<Enum, List<Sample>>();

A dictionary is used to map between a stopwatch "descriptor" and the actual Stopwatch instance. A dictionary is also used to manage the samples for a particular stopwatch "descriptor". Note that the key in both dictionaries is an Enum, allowing you to "describe" your stopwatches using an enumeration rather than an integer ID or a string. Note that there are no conflicts between these two enumerations:

enum Modem
{
  Send=1,
  Receive=2,
}

enum DSL
{
  Send=1,
  Receive=2,
}

because the Enum types are different even if the enumeration value is the same. In other words, there will be two different entries in the dictionaries for Modem.Send and DSL.Send, even though the value for both of these enumerations is 1.

Regarding the internal keyword, I'm not exactly thrilled with the fact that C# does not allow protected members in a static class. The internal keyword prevents access to the members from a different assembly, but what I really want to do is to prevent access even from the same assembly. By marking the class as static, which is useful because it prevents someone from accidentally instantiating it, I lose what I consider to be important control over the visibility of my static class' members--they have to be public or internal.

Creating Entries in the Maps

An internal method creates an entry in both dictionaries if the stopwatch descriptor does not currently exist in the dictionaries. Note that the "value" member of the dictionary is initialized when the key is added to the dictionary.

/// <span class="code-SummaryComment"><summary></span>
/// Creates, if new, the list entries for the stopwatch.
/// <span class="code-SummaryComment"></summary></span>
/// <span class="code-SummaryComment"><param name="t"></param></span>
internal static void CreateIfNotInMap(Enum t)
{
  if (!stopwatchMap.ContainsKey(t))
  {
    lock(stopwatchMap)
    {
      stopwatchMap[t] = new Stopwatch();
      stopwatchSampleMap[t] = new List<Sample>();
    }
  }
}

Why the lock? Because of the potential for different threads to be simultaneously adding to the dictionaries, and also because there might be a reader operation that is taking place while another thread is adding a stopwatch.

Basic Stopwatch Control

The basic stopwatch control consists of methods to start and stop the stopwatch and to start a new sample collection:

/// <span class="code-SummaryComment"><summary></span>
/// Starts the specified stopwatch.
/// <span class="code-SummaryComment"></summary></span>
[Conditional("DEBUG")]
public static void Start(Enum t)
{
  CreateIfNotInMap(t);
  stopwatchMap[t].Start();
}

/// <span class="code-SummaryComment"><summary></span>
/// Resets the specified stopwatch, clears the samples,
/// and starts the stopwatch.
/// <span class="code-SummaryComment"></summary></span>
/// <span class="code-SummaryComment"><param name="t"></param></span>
[Conditional("DEBUG")]
public static void StartNew(Enum t)
{
  CreateIfNotInMap(t);
  stopwatchMap[t].Reset();
  stopwatchSampleMap[t].Clear();
  stopwatchMap[t].Start();
}

/// <span class="code-SummaryComment"><summary></span>
/// Stops the specified stopwatch.
/// <span class="code-SummaryComment"></summary></span>
[Conditional("DEBUG")]
public static void Stop(Enum t)
{
  stopwatchMap[t].Stop();
}

/// <span class="code-SummaryComment"><summary></span>
/// Resets the specified stopwatch and clears the samples.
/// <span class="code-SummaryComment"></summary></span>
[Conditional("DEBUG")]
public static void Reset(Enum t)
{
    stopwatchMap[t].Reset();
    stopwatchSampleMap[t].Clear();
}

The salient difference between StartNew and Reset is that Reset simply clears the sample collection and resets the stopwatch, whereas StartNew is a simpler way of calling Reset and Start in succession.

Why aren't there locks around the Clear calls above, in the StartNew and Reset methods? Because, these are methods that I consider to be "master control" methods. All threads that are doing sampling or reporting on samples should be suspended or terminated when these calls are made. Any other scenario doesn't make sense.

Taking a Time Sample

To take a time sample, call the Sample method for the desired stopwatch. The sampleName parameter is useful in providing some additional information about the time sample--the iteration count, for example.

/// <span class="code-SummaryComment"><summary></span>
/// Saves the current elapsed time for the specified
/// stopwatch in the sample buffer.
/// <span class="code-SummaryComment"></summary></span>
[Conditional("DEBUG")]
public static void Sample(Enum t, string sampleName)
{
  lock (stopwatchMap)
  {
    stopwatchSampleMap[t].Add(new Sample(sampleName, 
                   stopwatchMap[t].ElapsedMilliseconds));
  }
}

Why the lock? Because, these routines need to be thread safe, and it is possible that one thread might be adding to the stopwatch collection while another thread is getting the sample collection (see below).

Getting the Elapsed Time

At any time, whether the stopwatch is running or not, you can get the elapsed time by calling the ElapsedMilliseconds method.

/// <span class="code-SummaryComment"><summary></span>
/// Gets the elapsed time in milliseconds for the specified stopwatch.
/// <span class="code-SummaryComment"></summary></span>
/// <span class="code-SummaryComment"><param name="t"></param></span>
[Conditional("DEBUG")]
public static void ElapsedMilliseconds(Enum t, ref long ret)
{
  ret = stopwatchMap[t].ElapsedMilliseconds;
}

And why, you ask, do I get the elapsed milliseconds using a ref parameter and not simply returning it? Because, conditional compilation requires that the method return type be void--in other words, it can't return anything. This is an inconvenience that sort of makes sense. If I could return the list, I would be able to write:

long ms=DebugStopwatch.ElapsedMilliseconds(Stopwatches.SW1);

And what would the compiler do if I compiled this in Release mode? By the way, the out keyword doesn't work either, because out initializes the variable, and if compiled in Release mode, the variable wouldn't be initialized, again giving the compiler fits, as it wouldn't be able to put out that useful error that a variable hasn't been initialized.

Get the Samples

At any time, the current collection of samples can be returned.

/// <span class="code-SummaryComment"><summary></span>
/// Returns the sample buffer for the specified stopwatch.
/// The input list is replaced with a copy of the sample list at
/// the current moment in time.
/// <span class="code-SummaryComment"></summary></span>
[Conditional("DEBUG")]
public static void GetSamples(Enum t, ref List<Sample> ret)
{
  lock (stopwatchMap)
  {
    ret = new List<Sample>(stopwatchSampleMap[t]);
  }
}

As stated above, conditional compilation methods cannot return anything, so the return must be handled by a ref. The lock prevents the sample list from being updated while we copy it, and we copy it so that the caller gets a copy, not the original. This keeps us safe from the caller tampering with our list, and the caller doesn't have to worry about threading--the copy is the caller's own to do with as it pleases.

Get the Sample Deltas

At any time, you can get the list of samples as time deltas.

/// <span class="code-SummaryComment"><summary></span>
/// Returns the buffer of sample deltas, S(n) - S(n-1) for the specified stopwatch.
/// The input list is replaced with the sample delta list.
/// <span class="code-SummaryComment"></summary></span>
[Conditional("DEBUG")]
public static void GetSampleDeltas(Enum t, ref List<SampleDelta> ret)
{
  List<Sample> samples = null;
  GetSamples(t, ref samples);
  ret = new List<SampleDelta>();

  if (samples.Count > 0)
  {
    Sample s0=samples[0];
    ret.Add(new SampleDelta(s0.SampleName, s0.Milliseconds, s0.Milliseconds));
    long ms=s0.Milliseconds;

    for (int i=1; i<samples.Count; i++)
    {
      Sample sn=samples[i];
      long delta = sn.Milliseconds - ms;
      ret.Add(new SampleDelta(sn.SampleName, delta, sn.Milliseconds));
      ms=sn.Milliseconds;
    }
  }
}

This is a nice helper method to get the time between each sample, rather than having to write this method yourself. A running total is also kept.

Doing a Sample Dump

A helper method called DumpSamples does a debug output of all the samples currently in the collection for the specified stopwatch. If you are using Traceract, the output would look similar to this (taken from the unit tests):

A Note About Exceptions

This class does not explicitly test whether the stopwatch descriptor exists in the dictionary. The dictionary is already doing this test, and if the descriptor doesn't exist in the dictionary, you will get an exception from the dictionary rather than the stopwatch class.

Unit Tests

There are three unit tests that validate the basic functionality of the DebugStopwatch class and verify that enumerations of different types are truly different even if their values are the same. These tests rely on the sequencing capability of my unit test application.

Given:

public class DebugStopwatchTests
{
  protected enum Items1
  {
    Avi,
    Mpg,
  }

  protected enum Items2
  {
    Dvd,
  }

  protected int[] delays = new int[] { 100, 200, 300 };
  protected string[] sampleNames1 = new string[] { "A1", "A2", "A3" };
  protected string[] sampleNames2 = new string[] { "D1", "D2", "D3" };
  protected string[] sampleNames3 = new string[] { "M1", "M2", "M3" };

The first unit test verifies the samples and their deltas:

/// <span class="code-SummaryComment"><summary></span>
/// Tests managing samples for a single enum type.
/// <span class="code-SummaryComment"></summary></span>
[Test, Sequence(0)]
public void SampleTest1()
{
  DebugStopwatch.Start(Items1.Avi);

  for (int i = 0; i < 3; i++)
  {
    Thread.Sleep(delays[i]);
    DebugStopwatch.Sample(Items1.Avi, sampleNames1[i]);
  }

  List<SampleDelta> samples = null;
  DebugStopwatch.GetSampleDeltas(Items1.Avi, ref samples);
  Assertion.Assert(samples.Count == 3, "Expected 3 samples.");

  for (int i = 0; i < 3; i++)
  {
    Assertion.Assert(InRange(samples[i].DeltaMilliseconds, delays[i]), 
      "Sample not within expected range.");
    Assertion.Assert(samples[i].SampleName == sampleNames1[i], 
      "Sample name does not match.");
  }
}

The second unit test verifies that samples taken for Items2.Dvd (value 0) are different from the samples taken for Items1.Avi (also value 0):

/// <span class="code-SummaryComment"><summary></span>
/// Tests that there is not conflict between
/// the previous sample enum and a different one,
/// even though the enumerations begin at the same values.
/// <span class="code-SummaryComment"></summary></span>
[Test, Sequence(1)]
public void SampleTest2()
{
  DebugStopwatch.Start(Items2.Dvd);

  for (int i = 0; i < 3; i++)
  {
    Thread.Sleep(delays[i]);
    DebugStopwatch.Sample(Items2.Dvd, sampleNames2[i]);
  }

  List<SampleDelta> samples = null;
  DebugStopwatch.GetSampleDeltas(Items2.Dvd, ref samples);
  Assertion.Assert(samples.Count == 3, "Expected 3 samples.");

  for (int i = 0; i < 3; i++)
  {
    Assertion.Assert(InRange(samples[i].DeltaMilliseconds, delays[i]), 
       "Sample not within expected range.");
    Assertion.Assert(samples[i].SampleName == sampleNames2[i], 
       "Sample name does not match.");
  }
}

And, the last unit test verifies that Items1.Mpg (value 1) creates a different sample list from Items.Avi (value 0):

/// <span class="code-SummaryComment"><summary></span>
/// Tests that there is not conflict between
/// the first sample enum and a second enumeration value.
/// <span class="code-SummaryComment"></summary></span>
[Test, Sequence(3)]
public void SampleTest3()
{
  DebugStopwatch.Start(Items1.Mpg);

  for (int i = 0; i < 3; i++)
  {
    Thread.Sleep(delays[i]);
    DebugStopwatch.Sample(Items1.Mpg, sampleNames3[i]);
  }

  List<SampleDelta> samples = null;
  DebugStopwatch.GetSampleDeltas(Items1.Mpg, ref samples);
  Assertion.Assert(samples.Count == 3, "Expected 3 samples.");

  for (int i = 0; i < 3; i++)
  {
    Assertion.Assert(InRange(samples[i].DeltaMilliseconds, delays[i]), 
       "Sample not within expected range.");
    Assertion.Assert(samples[i].SampleName == sampleNames3[i], 
       "Sample name does not match.");
  }

  DebugStopwatch.DumpSamples(Items1.Mpg);
}

Conclusion

Hopefully, you will find this class useful for adding debug build time sampling, and you won't find it too annoying that you have to use a ref variable to return the elapsed time and time samples.

License

This article, along with any associated source code and files, is licensed under The Code Project Open License (CPOL)

Share

About the Author

Marc Clifton

United States United States
Marc is the creator of two open source projects, MyXaml, a declarative (XML) instantiation engine and the Advanced Unit Testing framework, and Interacx, a commercial n-tier RAD application suite.  Visit his website, www.marcclifton.com, where you will find many of his articles and his blog.
 
Marc lives in Philmont, NY.

Comments and Discussions

 
Generalprotected in static class PinmemberMarqs28-Aug-08 21:45 
GeneralRe: protected in static class PinprotectorMarc Clifton27-Aug-09 5:11 
GeneralRe: protected in static class PinmemberMarqs27-Aug-09 10:01 
GeneralRe: protected in static class PinprotectorMarc Clifton28-Aug-09 4:06 

General General    News News    Suggestion Suggestion    Question Question    Bug Bug    Answer Answer    Joke Joke    Rant Rant    Admin Admin   

Use Ctrl+Left/Right to switch messages, Ctrl+Up/Down to switch threads, Ctrl+Shift+Left/Right to switch pages.

| Advertise | Privacy | Terms of Use | Mobile
Web01 | 2.8.141223.1 | Last Updated 15 Dec 2007
Article Copyright 2007 by Marc Clifton
Everything else Copyright © CodeProject, 1999-2014
Layout: fixed | fluid