Self-Profiling using Proxy class

Question

Given an interface

public interface IValueProvider
{
  object GetValue(int index);
}

and a tree structure of instances of IValueProvider similar to a math expression tree. I want to measure the time that is spent in the GetValue method of each node at runtime without an external profiler.

GetValue could do anything that i don't know at design time: Collecting values from other IValueProviders, running a IronPython expression or even be an external plugin. I want to present statistics about the node-timings to the user.

For this i can create a proxy class that wraps an IValueProvider:

public class ValueProviderProfiler : IValueProvider
{
  private IValueProvider valueProvider;

  public object GetValue(int index)
  {
    // ... start measuring
    try
    {
      return this.valuepProvider.GetValue(index);
    }
    finally
    {
      // ... stop measuring
    }
  }
}

What is the best way to measure the time that is spend in a node without distortions caused by external processes, with good accuracy and respect to the fact that the nodes are evaluated in parallel?

Just using the Stopwatch class won't work and having a look at the process' processor time doesn't respect the fact that the cpu time could have been consumed on another node.

Answer 1

You don't say how quickly you expect each GetValue call to finish, so it's hard to give any definite advice...

For things that take some number of milliseconds (disk accesses, filling in controls, network transfers, etc.) I've used DateTime.Ticks.Now. It seems to work reasonably well, and the claimed resolution of 10,000,000 ticks per second sounds pretty good. (I doubt it's really that precise though; I don't know what facility it is backed by.)

I'm not aware of any way of avoiding distortions introduced by execution of other processes. I usually just take the mean time spent running each particular section I'm interested in, averaged out over as many runs as possible (to smooth out variations caused by other processes and any timer inaccuracies).

(In native code, for profiling things that don't take long to execute, I use the CPU cycle counter via the RDTSC instruction. So if you're timing stuff that is over too soon for other timers to get a useful reading, but doesn't finish so quickly that call overhead is an issue, and you don't mind getting your readings in CPU cycles rather than any standard time units, it could be worth writing a little native function that returns the cycle counter value in a UInt64. I haven't needed to do this in managed code myself though...)

Answer 2

If you're trying to analyze performance instead of starting with a given method get an actual profile like Ants profiler and see where the real bottlenecks are. Many times when you assume why your application isn't being performant you end up looking and optimizing all of the wrong places and just waste a lot of time.