Measuring performance of each action in MVC

When you have a few developers working on your solution, ensuring code quality, performance is very important. One thing I have used frequently is a global action filter. The filter simply clocks each action in every controller and logs the speed. This is accessible to each developer and since it is in the logs, we can measure performance over a period of time.

Here is the code

The action filter:

public class LogActionFilter : ActionFilterAttribute
    {


        public override void OnActionExecuting(ActionExecutingContext filterContext)
        {
            filterContext.HttpContext.Trace.Write(string.Format("Action Executing: {0}", filterContext.ActionDescriptor.ActionName));
#if DEBUG
            ApplicationLog.Debug(filterContext.ActionDescriptor.ActionName, string.Format("Started executing action {0}, from controller {1}, route data {2}", filterContext.ActionDescriptor.ActionName, filterContext.ActionDescriptor.ControllerDescriptor.ControllerName, filterContext.RouteData));

            filterContext.HttpContext
                .Items["Watch for action {0}".FormatWith(filterContext.ActionDescriptor.ActionName)] = Stopwatch.StartNew();
#endif
        }

        public override void OnActionExecuted(ActionExecutedContext filterContext)
        {
            if (filterContext.Exception != null)
            {
                filterContext.HttpContext.Trace.Write("Exception thrown by action");
                ApplicationLog.Error("Exception thrown by action", filterContext.Exception.Message, filterContext.Exception);
            }
#if DEBUG
            var watch = (Stopwatch)filterContext.HttpContext
                .Items["Watch for action {0}".FormatWith(filterContext.ActionDescriptor.ActionName)];
            if (watch != null)
            {
                watch.Stop();
                ApplicationLog.Debug(filterContext.ActionDescriptor.ActionName, string.Format("Execution time for Action {0} is {1} ms", filterContext.ActionDescriptor.ActionName, watch.ElapsedMilliseconds));
            }

            ApplicationLog.Debug(filterContext.ActionDescriptor.ActionName, string.Format("Completed executing action {0}, from controller {1}, route data {2}", filterContext.ActionDescriptor.ActionName, filterContext.ActionDescriptor.ControllerDescriptor.ControllerName, filterContext.RouteData));
#endif
        }

and the update to global.asax:

  protected override void Application_Start()
        {
            GlobalFilters.Filters.Add(new LogActionFilter());
            base.Application_Start();

        }
Measuring performance of each action in MVC

Leave a Reply

Your email address will not be published. Required fields are marked *