AOP – Method execution time watcher with PostSharp

I found a nice usage of AOP the other day, using AOP to keep track of how long your method takes to execute and log a warning message if it takes longer than a threshold you supply. You can configure it to log execution times or only flag warning entries when threshold’s been exceeded.

[Serializable]
[DebuggerStepThrough]
[AttributeUsage(AttributeTargets.Method)]
public sealed class LogExecutionTimeAttribute : OnMethodInvocationAspect
{
    private static readonly ILog Log = LogManager.GetLogger(typeof(LogExecutionTimeAttribute));

    // If no threshold is provided, then just log the execution time as debug
    public LogExecutionTimeAttribute() : this (int.MaxValue, true)
    {
    }
    // If a threshold is provided, then just flag warnning when threshold's exceeded
    public LogExecutionTimeAttribute(int threshold) : this (threshold, false)
    {
    }
    // Greediest constructor
    public LogExecutionTimeAttribute(int threshold, bool logDebug)
    {
        Threshold = threshold;
        LogDebug = logDebug;
    }

    public int Threshold { get; set; }
    public bool LogDebug { get; set; }

    // Record time spent executing the method
    public override void OnInvocation(MethodInvocationEventArgs eventArgs)
    {
        var start = DateTime.Now;
        eventArgs.Proceed();
        var timeSpent = (DateTime.Now - start).TotalMilliseconds;

        if (LogDebug)
        {
            Log.DebugFormat(
                "Method [{0}{1}] took [{2}] milliseconds to execute",
                eventArgs.Method.DeclaringType.Name,
                eventArgs.Method.Name,
                timeSpent);
        }

        if (timeSpent > Threshold)
        {
            Log.WarnFormat(
                "Method [{0}{1}] was expected to finish within [{2}] milliseconds, but took [{3}] instead!",
                eventArgs.Method.DeclaringType.Name,
                eventArgs.Method.Name,
                Threshold,
                timeSpent);
       }
}

11 Comments

  1. Pingback: WCF — Improve performance with greater concurrency | theburningmonk.com

  2. Pingback: WCF — Improve performance with greater concurrency | chainding

  3. Pingback: Pseudo RealTime performance monitoring with AOP and AWS CloudWatch | theburningmonk.com

  4. Pingback: Tracing methods execution time - DexPage

  5. Pingback: c# - Tracing methods execution time - c++

  6. Deni35   •  

    What is OnMethodInvocationAspect? Visual Studio can’t find this class.

  7. Deni35   •  

    I have installed PostSharp. What is namespace of OnMethodInvocationAspect? And what is license I need to use it?

  8. Yan Cui   •  

    You should use the free license. This post is out-of-date as the aspect class name is different now, try MethodInvocationAspect instead.
    http://doc.postsharp.net/t_postsharp_aspects_methodinterceptionaspect

    Also, you don’t have to roll your own aspect for doing this either, I have rolled the time tracking aspect we used into a library called Metricano https://github.com/theburningmonk/metricano which you can download via Nuget.
    If you’re interested, this is how I ended up re-implementing the above aspect
    this: https://github.com/theburningmonk/Metricano/blob/master/src/Metricano.PostSharpAspects/LogExecutionTimeAttribute.cs

Leave a Reply

Your email address will not be published.