Software Development Blog

Time is of the utmost importance to almost any performance test, but, in .net, it can require a bit of scaffolding code. A triplet of C# classes can make short work of measuring performance, and of collating and persisting the results, in a handy XML format.

In the wild, this is often done with code similar to the following:

   Stopwatch sw = new Stopwatch();

   sw.Start();
   // Do some work here
   sw.Stop();

   Debug.WriteLine(sw.Elapsed.TotalMilliseconds.ToString();

This is hardly the end of the world, but it’s a bit cumbersome, especially over the course of many tests.  Perhaps a more natural construction would be:

   using (DebugStopwatch countIndexOf = new DebugStopwatch("IndexOf")) {
      // Do some work here
   }

… with the results being harvested later.  The literal text “IndexOf” can be replaced with any label that will be meaningful when you analyze the timing data.  Persistence of test results is accomplished through the magic of static classes.

While run time is almost always the most important performance metric at the end of the day, it’s often more useful to know the start and end time-stamps.  In situations when other running code can affect your results, knowing when, and not just how long, your test ran can help you make better sense of the results.  You can correlate tests to best and worst case scenarios, if you know when other, impactful things happened.

A final note:  this library commits a cardinal sin, and builds XML with a StringBuilder.  There are a few reasons for this ( performance and simplicity of the code ), and this is a very particular situation;  only numbers will ever be output, so no entities could possibly corrupt a document.

namespace ForrestCroce.Logic {
      public class BenchmarkState {
            DateTime started, ended;
            long startingWorkingSet, endingWorkingSet;
            DebugStopwatch sw;

            internal BenchmarkState(DebugStopwatch creator) {
                  startingWorkingSet = Environment.WorkingSet;
                  sw = creator;
                  started = DateTime.Now;
            }

            internal void Conclude() {
                  ended = DateTime.Now;
                  endingWorkingSet = Environment.WorkingSet;
            }

            public string XmlFragment {
                  get {
                        StringBuilder sb = new StringBuilder();
                        sb.AppendLine("\t");
                        sb.AppendLine("\t\t");
                        sb.AppendLine("\t\t\t" + started.ToString() + "");
                        sb.AppendLine("\t\t\t" + ended.ToString() + "");
                        sb.AppendLine("\t\t\t" + sw.Elapsed.TotalMilliseconds.ToString() + "");
                        sb.AppendLine("\t\t");
                        sb.AppendLine("\t\t");
                        sb.AppendLine("\t\t\t" + startingWorkingSet.ToString() + "");
                        sb.AppendLine("\t\t\t" + endingWorkingSet.ToString() + "");
                        sb.AppendLine("\t\t");
                        sb.AppendLine("\t");
                        return sb.ToString();
                  }
            }
      }

      public class DebugStopwatch : Stopwatch, IDisposable {
            BenchmarkState status;
            string label;

            public DebugStopwatch() {
                  status = new BenchmarkState(this);
                  StopwatchManager.Add(this);
                  Start();
            }

            public DebugStopwatch(string debugLabel) {
                  label = debugLabel;
                  status = new BenchmarkState(this);
                  StopwatchManager.Add(this);
                  Start();
            }

            public void Dispose() {
                  Stop();
            }

            public new void Stop() {
                  base.Stop();
                  status.Conclude();

                  string text = string.IsNullOrEmpty(label) ? DateTime.Now.ToString() : label + ": ";
                  text += (Elapsed.TotalSeconds + Elapsed.TotalMilliseconds).ToString("#,##0.000") + " ms";
                  System.Diagnostics.Debug.WriteLine(text);
            }

            public BenchmarkState State { get { return status; } }

            public string Label { get { return label; } set { label = value; } }
      }

      public static class StopwatchManager {
            static Dictionary byInstanceID = new Dictionary();

            public static DebugStopwatch Create(string label) {
                  DebugStopwatch sw = new DebugStopwatch(label);
                  return sw;
            }

            public static void Add(DebugStopwatch sw) {
                  int id = byInstanceID.Count;
                  byInstanceID.Add(id, sw.State);
            }

            public static string Xml {
                  get {
                        StringBuilder sb = new StringBuilder();
                        sb.AppendLine("");

                        foreach (KeyValuePair item in byInstanceID)
                              sb.Append(item.Value.XmlFragment);

                        sb.AppendLine("");
                        return sb.ToString();
                  }
            }
      }

}