Automatically instrumenting an ASP.NET MVC3 app

10 months ago

Update: There is now a nuget package that will take care of wiring this up automatically see: http://nuget.org/List/Packages/MiniProfiler.MVC3


MiniProfiler seems to have upset quite a few people. One major complain we got when Scott Hanselman blogged about it, goes:

Why do you expect me to sprinkle all these ugly using (MiniProfiler.Current.Step("stuff")) throughout my code. This is ugly and wrong, profilers should never require you to alter your code base. FAIL."

Our usual retort is that you are able to properly control the granularity of your profiling this way. Sure you can introduce aspects using PostSharp or your favorite IOC container, however this method may also force you to refactor your code to accommodate profiling.

That said, I agree that sometimes it may seem tedious and unnecessary to chuck using statements where the framework can do that for us.

Here is a quick document on how you can get far more granular timings out-of-the-box without altering any of your controllers or actions.


Profiling Controllers

Automatically wrapping your controllers with MVC3 is actually quite trivial, it can be done with a GlobalActionFilter

For example:

public class ProfilingActionFilter : ActionFilterAttribute
{

    const string stackKey = "ProfilingActionFilterStack";

    public override void OnActionExecuting(ActionExecutingContext filterContext)
    {
        var mp = MiniProfiler.Current;
        if (mp != null)
        {
            var stack = HttpContext.Current.Items[stackKey] as Stack<IDisposable>;
            if (stack == null)
            {
                stack = new Stack<IDisposable>();
                HttpContext.Current.Items[stackKey] = stack;
            }

            var prof = MiniProfiler.Current.Step("Controller: " + filterContext.Controller.ToString() + "." + filterContext.ActionDescriptor.ActionName);
            stack.Push(prof);

        }
        base.OnActionExecuting(filterContext);
    }

    public override void OnActionExecuted(ActionExecutedContext filterContext)
    {
        base.OnActionExecuted(filterContext);
        var stack = HttpContext.Current.Items[stackKey] as Stack<IDisposable>;
        if (stack != null && stack.Count > 0)
        {
            stack.Pop().Dispose();
        }
    }
}

You wire this up in Global.asax.cs

protected void Application_Start()
{
   // other stuff ...

   GlobalFilters.Filters.Add(new ProfilingActionFilter());
   RegisterGlobalFilters(GlobalFilters.Filters);

   /// more stuff 
}

Profiling Views

Views on the other hand a bit more tricky, what you can do is register a special “profiling” view engine that takes care of instrumentation:

public class ProfilingViewEngine : IViewEngine
{
   class WrappedView : IView
    {
        IView wrapped;
        string name;
        bool isPartial;

        public WrappedView(IView wrapped, string name, bool isPartial)
        {
            this.wrapped = wrapped;
            this.name = name;
            this.isPartial = isPartial;
        }

        public void Render(ViewContext viewContext, System.IO.TextWriter writer)
        {
            using (MiniProfiler.Current.Step("Render "  + (isPartial?"partial":"")  + ": " + name))
            {
                wrapped.Render(viewContext, writer);
            }
        }
    }

    IViewEngine wrapped;

    public ProfilingViewEngine(IViewEngine wrapped)
    {
        this.wrapped = wrapped;
    }

    public ViewEngineResult FindPartialView(ControllerContext controllerContext, string partialViewName, bool useCache)
    {
        var found = wrapped.FindPartialView(controllerContext, partialViewName, useCache);
        if (found != null && found.View != null)
        {
            found = new ViewEngineResult(new WrappedView(found.View, partialViewName, isPartial: true), this);
        }
        return found;
    }

    public ViewEngineResult FindView(ControllerContext controllerContext, string viewName, string masterName, bool useCache)
    {
        var found = wrapped.FindView(controllerContext, viewName, masterName, useCache);
        if (found != null && found.View != null)
        {
            found = new ViewEngineResult(new WrappedView(found.View, viewName, isPartial: false), this);
        }
        return found;
    }

    public void ReleaseView(ControllerContext controllerContext, IView view)
    {
        wrapped.ReleaseView(controllerContext, view);
    }
}

You wire this up in Global.asax.cs:

protected void Application_Start()
{
   // stuff 

   var copy = ViewEngines.Engines.ToList();
   ViewEngines.Engines.Clear();
   foreach (var item in copy)
   {
       ViewEngines.Engines.Add(new ProfilingViewEngine(item));
   }

   // more stuff
}

The trick here is that we return a special view engine that simply wraps the parent and intercepts calls to Render.

The results speak for themselves:

Before

before

After

after


There you go, with minimal changes to your app you are now able to get a fair amount of instrumentation. My controller in the above sample had a System.Threading.Thread.Sleep(50); call which is really easy to spot now. My slow view had a System.Threading.Thread.Sleep(20); which is also easy to spot.

The caveat of this approach is that we now have another layer of indirection which has a minimal effect on performance. We will look at porting in these helpers to MiniProfiler in the near future.

Happy profiling, Sam

Comments

Dhananjay Goyani 10 months ago

Awesome!

Scott Hanselman 10 months ago

Lovely. Throw these in version 1.7 so they are ubiquitous, and lets you and I talk about the magic of AppStart and make a NuGet package that’s MiniProfiler.MVC3 that hooks all this up automatically.

awesome — Sam

Marius Schulz 10 months ago

Really nice! Please build the NuGet package Scott mentioned — looking forward to it …

Finlay 10 months ago

Small thing, in WrappedView.Render it writes out “parital” instead of partial.

using (MiniProfiler.Current.Step(“ Render ” + (isPartial? “ parital ”: “”) (fixed quotes so it is rendered properly)

Other than that it looks excellent!

:) thanks, fixed — Sam

Usman Masood 10 months ago

Nicely done… great job!!

Augi 10 months ago

I’m afraid that the code doesn’t work if there is more requests in parallel.

The problem is that you store request-state in private field of action-filter (prof in ProfilingActionFilter class). And there is just one instance of the ProfilingActionFilter class.

So you should store the reference to MiniProfiler i.e. into HttpContext.Current.Items.

After this change, I will say: good work, guy! :–)

Great catch … fixed! — Sam

Zote 10 months ago

Great project, thank you!

Is that possible to redirect results to some place like App_Data? That way when a customer says that site is slow, I can enable profiler for him (based on authentication) and see results, without any modifications to him.

Thank you.

we have a demo sql data store, grap the code and have a look at the demo app — Sam

Alexandre Jobin 10 months ago

Really good! thank you for the code!

Bryan Migliorisi 10 months ago

FYI, IF you wanted to use PostSharp to enable instrumentation of more than just your MVC actions, I wrote a short blog post with the code for a PostSharp aspect Attribute to do just this..

Use PostSharp to easily allow MiniProfiler to profile your ASP.NET application

Nice one! — Sam

Hendry Ten 10 months ago

Great one. It’ll be wonderful if the FindPartialView and FindView methods of the ProfilingViewEngine are virtual.

Vijayant 9 months ago

Thank u..

Anton Vishnyak 8 months ago

I added a bit more automatic instrumentation. If your site does any amount of real work in custom ActionFilterAttributes, check out my code to instrument them automatically.

Expanding the Mvc-Mini-Profiler to measure and report performance of ActionFilters