How to measure the execution time using PostSharp

You might need to know how much time a method in your application takes to execute. This information would help you analyze the slow running methods in the application.

There are various ways to achieve this — you can use profilers or write custom code to get this information. Some of the popular performance profilers that you can use to profile your .Net applications are: RedGate ANTS Performance Profiler, JetBrains dotTrace, and Telerik Just Trace. You can also measure the execution time programmatically with a popular AOP library called PostSharp.

Measuring the execution time programmatically

If you would like to measure the execution time of a method, i.e., the time a method takes to execute programmatically, you can use the Stopwatch class in the System.Diagnostics namespace, which can measure the elapsed time for one interval or to measure the total elapsed time for multiple intervals. The following code snippet illustrates how you can leverage the Stopwatch class to measure execution time:

var timer = System.Diagnostics.Stopwatch.StartNew();

// Write your code here

timer.Stop();

var elapsedMilliseconds = timer.ElapsedMilliseconds;

Note that there is a very useful boolean property in the Stopwatch class called Stopwatch.IsHighResolution that you can use. This lets you know the Stopwatch capabilities based on the system’s hardware and host OS.

Measuring the execution time using PostSharp

You can use PostSharp’s compile-time weaving features to reduce code clutter and write much less boilerplate code while you try to profile methods. PostSharp is one of the most popular tools available that can be used to implement AOP in applications. You can learn more on PostSharp from my article here.

First off, you should include the necessary PostSharp library from NuGet. Assuming that PostSharp is successfully installed, create the following class that extends the OnMethodBoundaryAspect class. This aspect would be used to log the execution time of a method.

[Serializable]

 [AttributeUsage(AttributeTargets.Method)]

    public sealed class LogExecutionTimeAttribute : OnMethodBoundaryAspect

    {

        public override void OnEntry(MethodExecutionEventArgs eventArgs)

            {

                //Some code

            }

           public override void OnExit(MethodExecutionEventArgs eventArgs)

            {

              // Some code

            }

    }

Note that this attribute class is marked with the [Serializable] attribute and we have specified AttributeTargets.Method in AttributeUsage. This implies that this attribute can be applied to all methods. There are many other values available in this enumeration as well for you to choose from. As an example, you can specify AttributeTargets.Class to apply this attribute on a class, AttributeTargets.Interface to apply it on an interface, and so on.

You should override the OnEntry and the OnExit methods of this class. In the OnEntry method you can start a Stopwatch and in the OnExit method you can retrieve the elapsed time and then stop the watch.

 public override void OnEntry(MethodExecutionArgs args)

        {

            timer.Start();

        }

 public override void OnExit(MethodExecutionArgs args)

        {          

            var elapsedMilliseconds = timer.ElapsedMilliseconds;

            timer.Stop();

            //Write code here to store the elapsed time in a data store

        }

Here’s the complete source code for your reference.

using PostSharp.Aspects;

using System;

using System.Diagnostics;

namespace ExecutionTimer

{

    [Serializable]

    [AttributeUsage(AttributeTargets.Method)]

    public sealed class LogExecutionTimeAttribute : OnMethodBoundaryAspect

    {

        private static readonly Stopwatch timer = new Stopwatch();      

        public override void OnEntry(MethodExecutionArgs args)

        {

            timer.Start();

        }

        public override void OnExit(MethodExecutionArgs args)

        {           

            var elapsedMilliseconds = timer.ElapsedMilliseconds;

            timer.Stop();

            //Write code here to store the elapsed time in a data store

        }

    }

}

And that’s all you need to do. You can now apply this custom aspect on any method as shown in the code snippet given below.

  static void Main(string[] args)

        {

            TestMethod();

        }

        [LogExecutionTimeAttribute]

        static void TestMethod()

        {

            for (int i = 0; i < 100000; i++) ;

        }

I’ve not provided the code for logging the information in a log file — you can refer to my article on Log4Net and create one for you.

You can extend this class to incorporate more functionality, and you can even add a threshold and flag warning if the execution time of method exceeds the threshold.