C# ASP.NET MVC: Show Page Render Time

Question

I'd like to add an output to all my ASP.NET MVC pages via the master page which shows the render time of the current page. How could I do this?

Answer 1

If you want to time the Action, you can create an IActionFilter, which has start and stop events OnActionExecuting, OnActionExecuted. But that is only the controller time.

To grab the full time, you need to also know the IResultFilter start and stop times, which has events OnResultExecuting, OnResultExecuted.

This is an example that actually writes to the Response in OnResultExecuted, so it suggests such may still be possible at that time. It does a filterContext.HttpContext.Response.Write call in the OnResultExecuted method.

For my personal use, I just want to know who's doing what, what pages are getting hit, and performance wise, what's taking too much time. I log this to a database, but don't put it on every page. (I also store the User, if authenticated, which isn't shown below.)

Particularly, it was for a DevExpress Large Data Grid, which caused me to need to not just time the Action, but start also timing the Result as well.

 public class Log : FilterAttribute, IActionFilter, IResultFilter
{
    public void OnActionExecuting(ActionExecutingContext filterContext)
    {
        try
        {
            var db = new SomeExampleEntities();
            WebLog webLog = new WebLog();

            webLog.LogDate = DateTime.Now;

            // Whatever you want to log
            webLog.Path = filterContext.HttpContext.Request.Path;
            webLog.IPAddress = filterContext.HttpContext.Request.UserHostAddress;
            webLog.SessionId = filterContext.HttpContext.Session.SessionID;

            db.WebLogs.Add(webLog);
            db.SaveChanges();

            filterContext.HttpContext.Items["WebLog"] = webLog;
            filterContext.HttpContext.Items["WebLog_db"] = db;
        }
        catch
        {

        }
    }

    // This is fired when leaving the controller action, before running the View/Result
    public void OnActionExecuted(ActionExecutedContext filterContext)
    {
            WebLog webLog = (WebLog)filterContext.HttpContext.Items["WebLog"];
            webLog.ActionElapsed = (decimal)(((TimeSpan)(DateTime.Now - webLog.LogDate)).TotalMilliseconds / 1000.0000);
    }

    public void OnResultExecuting(ResultExecutingContext filterContext)
    {
        //Do Nothing
    }

    //This is fired after the result is actually executed, not just after the Action returns a View or Result
    public void OnResultExecuted(ResultExecutedContext filterContext)
    {
        try
        {
            UsisWebEntities db = (UsisWebEntities)filterContext.HttpContext.Items["WebLog_db"];
            WebLog webLog = (WebLog)filterContext.HttpContext.Items["WebLog"];

            webLog.Elapsed = (decimal)(((TimeSpan)(DateTime.Now - webLog.LogDate)).TotalMilliseconds / 1000.0000);
            webLog.ResultElapsed = webLog.Elapsed - webLog.ActionElapsed;

            db.SaveChanges();
        }
        catch 
        {

        }
    }

}

Answer 2

This is tricky, because before you can render the page you have to have all your ViewData added to it.

You can get the total time it took to execute the controller action by writing a custom ActionFilterAttribute and overriding OnActionExecuting to start a timer, and OnActionExecuted to get the elapsed time and store it to ViewData. When the ActionResult is executed, it can take that time and render it into your View.

That may be close enough for your needs? Unfortunately, to get the grand total time of both the Action and the Result being executed, you would need to override OnActionExecuting and OnResultExecuted in your Controller, but at that point it's too late to add information to the View, as it's already been rendered. You could log it to a file however, see this link for an example.

---

Okay, here's an example timer action filter. Add this as a class into your project, and then you can tag any controller method with [ActionTimer], and it will add the elapsed time into a ViewData bucket called "_ElapsedTime", which you can print out on your views.

using System.Web.Mvc; 
using System.Diagnostics;

namespace MvcApplication1  {
    public class ActionTimerAttribute : ActionFilterAttribute
        {
            public ActionTimerAttribute()
            {
                // Make sure this attribute executes after every other one!
                this.Order = int.MaxValue;
            }

            public override void OnActionExecuting(ActionExecutingContext filterContext)
            {
                var controller = filterContext.Controller;
                if (controller != null)
                {
                    var timer = new Stopwatch();
                    controller.ViewData["_ActionTimer"] = timer;
                    timer.Start();
                }
                base.OnActionExecuting(filterContext);
            }

            public override void OnActionExecuted(ActionExecutedContext filterContext)
            {
                var controller = filterContext.Controller;
                if (controller != null)
                {
                    var timer = (Stopwatch)controller.ViewData["_ActionTimer"];
                    if (timer != null)
                    {
                        timer.Stop();
                        controller.ViewData["_ElapsedTime"] = timer.ElapsedMilliseconds;
                    }
                }
            }
        } }

As I mentioned earlier, this won't include the time it took to actually render the ActionResult. If you take a look at the example I linked though, it shows you how you could do this to a log file, and also gives you an idea of how the four action filter events can be used.

Answer 3

I would suggest using JavaScript.

Have two times one at the start of the load of the page and one at then end of the page and then you can do a difference for the total time.

By doing it from client side script you can get the entire time it take the page to load versus how long the server takes.