5
\$\begingroup\$

I want to easily measure method's execution time. Of course instead of doing something like this:

var timer = Stopwatch.StartNew();
DoSomething();
timer.Stop();
Console.WriteLine(timer.ElapsedMilliseconds)

I want to make it more elegant. What I've managed is something like this:

static class MethodMeasurer
{
    public static T Invoke<T>(Func<T> action, out Stopwatch stopwatch)
    {
        var timer = Stopwatch.StartNew();
        var res = action.Invoke();
        timer.Stop();
        stopwatch = timer;
        return res;
    }

    public static void Invoke(Action action, out Stopwatch stopwatch)
    {
        var timer = Stopwatch.StartNew();
        action.Invoke();
        timer.Stop();
        stopwatch = timer;
    }
}

And here is the usage:

class Program
{
    static void Main(string[] args)
    {
        MethodMeasurer.Invoke(DoSomething1, out var s1);
        Console.WriteLine("s1 executed time: " + s1.ElapsedMilliseconds);

        var doSomething2Measured = MethodMeasurer.Invoke(DoSomething2, out var s2);
        Console.WriteLine("s2 executed time: " + s2.ElapsedMilliseconds);
        Console.WriteLine("s2 returned: " + doSomething2Measured);

        var doSomething3Measured = MethodMeasurer.Invoke(() => DoSomething3(5), out var s3);
        Console.WriteLine("s3 executed time: " + s3.ElapsedMilliseconds);
        Console.WriteLine("s3 returned: " + doSomething3Measured);
    }

    static void DoSomething1()
    {
        Thread.Sleep(100);
    }

    static int DoSomething2()
    {
        Thread.Sleep(300);
        return 1;
    }

    static int DoSomething3(int i)
    {
        Thread.Sleep(300);
        return i;
    }
}

So what do you think about that? Would you suggest I use a different solution, or is mine okay?

\$\endgroup\$
  • 2
    \$\begingroup\$ As far as I can tell, you don't really need the local timer variables. Just assign directly as stopwatch = Stopwatch.StartNew();. Might also want to wrap the call to action.Invoke() with a try..finally to make sure the stopwatch is stopped even in exceptional conditions. \$\endgroup\$ – Jesse C. Slicer Jun 4 '18 at 17:50
3
\$\begingroup\$

Because you are interested in the time it took and not the stopwatch, you should return a TimeSpan. And since we no longer need stopwatch as a parameter, we can rename timer to stopwatch (as "timer" makes me think of the Timer class).

public static void Invoke(Action action, out TimeSpan timeSpan)
{
    var stopwatch = Stopwatch.StartNew();
    action.Invoke();
    stopwatch.Stop();
    timeSpan = stopwatch.Elapsed;
}
\$\endgroup\$
2
\$\begingroup\$

Why not just return the result instead of having it as a parameter?:

public static TimeSpan Invoke(Action action)
{
  var stopWatch = Stopwatch.StartNew();
  action();
  stopWatch.Stop();
  return stopWath.Ellapsed;
}

What is often tedious is to write the result every time you measure something. I use a simple solution with an IDisposable implementation allowing me to wrap the code I want to measure in a using statement. The result is then automatically printed when the object is disposed by leaving the using statement:

  public class StopClock : IDisposable
  {
    Stopwatch m_watch;
    string m_title;

    public StopClock(string title = "Test 1")
    {
      m_watch = Stopwatch.StartNew();
      m_title = title;
    }

    public Stopwatch Stop()
    {
      if (m_watch != null)
      {
        m_watch.Stop();
      }

      return m_watch;
    }

    public void Print()
    {
      if (m_watch != null)
      {
        Console.WriteLine($"{m_title}: Duration: {m_watch.ElapsedMilliseconds} ({m_watch.ElapsedTicks})");
      }
    }

    public void Dispose()
    {
      Stop();
      Print();
    }
  }

Usage:

using (StopClock sc = new StopClock("First Test"))
{
  // Execute the code to be measured
  Thread.Sleep(1000);
} // At this point, the result is automatically written to the console.

Or:

StopClock sc = new StopClock("First Test");

// Execute the code to be measured
Thread.Sleep(1000);

sc.Stop();

// Do some more code.
// ...

sc.Print();

It can easily be refined with the possibility to inject another output mechanism than Console.WriteLine() for instance Debug.WriteLine() or to an output file.

\$\endgroup\$
  • 1
    \$\begingroup\$ I can see why you'd use the IDisposable implementation just for the syntactical sugar you get from the using syntax; but this seems to make it harder to do anything with the result unless it is either hardcoded in the class (which limits your options) or the handling action is as a parameter (which detracts from the nice syntax you'd be using it for). I assume you mainly use it as a debug feature (where it's easy to hardcode the handling), as opposed to an application feature? \$\endgroup\$ – Flater Jun 5 '18 at 5:52
  • 2
    \$\begingroup\$ @Flater: I can't hardly follow your argumentation. It is just a debug tool, which I find very useful in the way I'm debugging. So I just posted it as an inspiration for the OP to use as is or to extent as needed. No big deal :-) \$\endgroup\$ – Henrik Hansen Jun 5 '18 at 7:17
2
\$\begingroup\$

Here are a couple of suggestions:

  • You don't have to repeat yourself in each Invoke method. Reuse the implementation of the largest one by calling it from other overloads.
  • You can greatly simplify it by using try/finally and provide the Elapsed value in any case. With your solution you'll loose it if the measured method throws.
  • I find it's more useful to provide the Elapsed value as TimeSpan via Action<> so that you can use it instantly inside the call as this is what you're be doing most often. Writing to the Console or to a log.
  • Make these methods extension for the Stopwatch.

Example:

public static class StopwatchExtensions
{
    public static T Measure<T>(this Stopwatch stopwatch, Func<T> action, Action<TimeSpan> elapsed)
    {
        try
        {
            return action();
        }
        finally
        {
            elapsed(stopwatch.Elapsed);
        }
    }

    public static void Measure(this Stopwatch stopwatch, Action action, Action<TimeSpan> elapsed)
    {
        stopwatch.Measure<object>(() => { action(); return default; }, elapsed);
    }
}

Usage:

Stopwatch
    .StartNew()
    .Measure(DoSomething, elapsed => Console.WriteLine(elapsed));

If you want it even shorter then create a helper for that:

static class ConsoleHelper
{
    // TODO for you: format the message whatever you like.
    public static void WriteElapsed(TimeSpan elapsed) => Console.WriteLine(elapsed);
}

and plug it in without the lambda:

Stopwatch
    .StartNew()
    .Measure(DoSomething, ConsoleHelper.WriteElapsed);

You can create more of them. E.g. if you want to include the method name in the message then create an overload that returns an Action<TimeSpan> so that you can use this one without the lambda too:

public static Action<TimeSpan> WriteElapsed(string memberName)
{
    return elapsed => Console.WriteLine($"'{memberName}' executed in {elapsed}");
}

and you call it like this:

Stopwatch
    .StartNew()
    .Measure(DoSomething, ConsoleHelper.WriteElapsed(nameof(DoSomething)));
\$\endgroup\$

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.