Getting more "granularity" from the MVC Mini Profiler

Should this turn out to be useful for anyone, I'll gladly turn it into a community wiki thing.

I have some slow pages in an MVC3 app, and since little of the execution time seemed to happen in my code, I wanted to see if I could find out more about what took so long. Not that I succeeded, but I gained a little more wisdom along the way.

There is nothing here that isn't obvious to anyone with some MVC experience. Basically, I created my own ActionFilterAttribute that looks like this:

public class ProfilerAttribute : ActionFilterAttribute
{
    IDisposable actionStep = null;
    IDisposable resultStep = null;

    public override void OnActionExecuting(ActionExecutingContext filterContext)
    {
        actionStep = MiniProfiler.Current.Step("OnActionExecuting " + ResultDescriptor(filterContext));
        base.OnActionExecuting(filterContext);
    }

    public override void OnActionExecuted(ActionExecutedContext filterContext)
    {
        if (actionStep != null)
        {
            actionStep.Dispose();
            actionStep = null;
        }
        base.OnActionExecuted(filterContext);
    }

    public override void OnResultExecuting(ResultExecutingContext filterContext)
    {
        resultStep = MiniProfiler.Current.Step("OnResultExecuting " + ResultDescriptor(filterContext));
        base.OnResultExecuting(filterContext);
    }

    public override void OnResultExecuted(ResultExecutedContext filterContext)
    {
        if (resultStep != null)
        {
            resultStep.Dispose();
            resultStep = null;
        }
        base.OnResultExecuted(filterContext);
    }

    private string ResultDescriptor(ActionExecutingContext filterContext)
    {
        return filterContext.ActionDescriptor.ControllerDescriptor.ControllerName + "." + filterContext.ActionDescriptor.ActionName;
    }

    private string ResultDescriptor(ResultExecutingContext filterContext)
    {
        var values = filterContext.RouteData.Values;

        return String.Format("{0}.{1}", values["controller"], values["action"]);
    }

This seems to work well, and in my case I have learned that most of the time is actually spent in the ResultExecuting part of life, not inside my actions.

However, I have some questions about this approach.

1) Is this a request-safe way of doing things? I am guessing no, since the actionfilter is created only once, in the RegisterGlobalFilters() method in Global.asax.cs. If two requests appear at once, actionStep and resultStep will be worthless. Is this true? If so, can someone who knows more than me contribute a clever way to handle this? Works for me during local machine profiling, but probably not so much deployed on a server with multiple people making requests at the same time.

2) Is there any way to get more insight into the result-executing process? Or should I just accept that rendering the view etc. takes the time it takes? In my o开发者_运维百科wn app I ensure that all database access is finished before my action method is over (using NHibernate Profiler in my case), and I like to keep my views slim and simple; Any kind of insight into what slows the rendering down could still be useful, though. I guess using the Mini Profiler in my model objects would show up here, if any slow code on my part was executed here.

3) The ResultDescriptor methods are probably evil and poisonous. They've worked for me in my tests, but would probably need to be replaced by something more robust. I just went with the first versions that gave me something halfway useful.

Any other comments to this would also be very welcome, even if they are "This is a bad idea, go die alone".

This looks like a cool idea. I believe that it's NOT a request safe way of doing things.

You could link it to HttpContext.Items like this

HttpContext.Items.Add("actionstep", actionStep);
HttpContext.Items.Add("resultstep", resultStep);

And then retrieve it in similar fashion

actionStep = HttpContext.Items["actionstep"];
resultStep = HttpContext.Items["resultstep"];

Obviously putting in your own checks for nulls and so forth.

The HttpContext is different for each user/request.

The thing to remember about HttpContext.Current.Session.SessionID which I sometimes forget it that it is the SessionId of the current HTTP request (i.e. it changes each time you hit F5 or otherwise make a new request). The other important thing to remember is that, whilst at any on time, all HttpContext.Current.Session.SessionID values are necessarily unique (i.e. one for each user, or request), they can be reused, so dno't think of them as GUIDs which are only used once each.

There is already an action filter attribute in the MiniProfiler assembly that does the profiling for the actions. It is in the StackExchange.Profiling.MVCHelpers namespace and it's called ProfilingActionFilter. You can extend it to also profile your views.

It uses the same approach as described by @Dommer but instead of storing the IDisposable directly, it stores a Stack in the HttpContext.Current.Items. You can do the same for the views.

Here is the code for the action profiling:

/// <summary>
/// This filter can be applied globally to hook up automatic action profiling
/// 
/// </summary>
public class ProfilingActionFilter : ActionFilterAttribute
{
    private const string stackKey = "ProfilingActionFilterStack";

    /// <summary>
    /// Happens before the action starts running
    /// 
    /// </summary>
    public override void OnActionExecuting(ActionExecutingContext filterContext)
    {
        if (MiniProfiler.Current != null)
        {
            Stack<IDisposable> stack = HttpContext.Current.Items[(object) "ProfilingActionFilterStack"] as Stack<IDisposable>;
            if (stack == null)
            {
                stack = new Stack<IDisposable>();
                HttpContext.Current.Items[(object) "ProfilingActionFilterStack"] = (object) stack;
            }
            MiniProfiler current = MiniProfiler.Current;
            if (current != null)
            {
                RouteValueDictionary dataTokens = filterContext.RouteData.DataTokens;
                string str1 = !dataTokens.ContainsKey("area") || string.IsNullOrEmpty(dataTokens["area"].ToString()) ? "" : (string) dataTokens["area"] + (object) ".";
                string str2 = Enumerable.Last<string>((IEnumerable<string>) filterContext.Controller.ToString().Split(new char[1] { '.' })) + ".";
                string actionName = filterContext.ActionDescriptor.ActionName;
                stack.Push(MiniProfilerExtensions.Step(current, "Controller: " + str1 + str2 + actionName, ProfileLevel.Info));
            }
        }
        base.OnActionExecuting(filterContext);
    }

    /// <summary>
    /// Happens after the action executes
    /// 
    /// </summary>
    public override void OnActionExecuted(ActionExecutedContext filterContext)
    {
        base.OnActionExecuted(filterContext);
        Stack<IDisposable> stack = HttpContext.Current.Items[(object) "ProfilingActionFilterStack"] as Stack<IDisposable>;
        if (stack == null || stack.Count <= 0) return;
        stack.Pop().Dispose();
    }
}

Hope this help.

You can just wrap ExecuteCore method on Controller. :)