Take the community feedback survey now.

Anders Hattestad
Apr 12, 2016
  2126
(0 votes)

Light logging of time used in Controller and View

There are great tool available for logging user actions on your site like google analytic, but sometimes you want to know more about how much time a controller used, and how much time the view rendering took. If one creates a ActionFilterAttribute and tag your controller with it it’s possible to get that kind of information easy.

You tag your controller like this

    [TrackTimeActionFilter]
    public class SearchPageController : PageController<SearchPage>
    {

The you create a TrackTimeActionFilter

    public class TrackTimeActionFilter : ActionFilterAttribute
    {
        Stopwatch stopWatch0;
        Stopwatch stopWatch1;
        Stopwatch stopWatch2;
        public override void OnActionExecuting(ActionExecutingContext filterContext)
        {
            stopWatch0 = new Stopwatch();
            stopWatch1 = new Stopwatch();
            stopWatch0.Start();
            stopWatch1.Start();
        }
        public override void OnActionExecuted(ActionExecutedContext filterContext)
        {
            stopWatch1.Stop();
           
           // Log("OnActionExecuted", filterContext.RouteData);
        }
        public override void OnResultExecuting(ResultExecutingContext filterContext)
        {
            stopWatch2 = new Stopwatch();
            stopWatch2.Start();
        }
        public override void OnResultExecuted(ResultExecutedContext filterContext)
        {
            stopWatch0.Stop();
            stopWatch2.Stop();
            Log(filterContext.RouteData, stopWatch0.ElapsedMilliseconds, stopWatch1.ElapsedMilliseconds, stopWatch2.ElapsedMilliseconds, filterContext.HttpContext);

        }
      
        private void Log(RouteData routeData, long timeTotal, long timeController, long timeRenderView, HttpContextBase context)
        {
            var service = ServiceLocator.Current.GetInstance<ContentActionStoreService>();
            if (service.IsEnabled && !EPiServer.Editor.PageEditing.PageIsInEditMode)
            {
                try {

                    var add = CreateEntity(routeData);
                    if (add != null)
                    {
                        var userNameOrSessionId = context.Session.SessionID;
                        if (!string.IsNullOrEmpty(context.User.Identity.Name))
                            userNameOrSessionId = context.User.Identity.Name;
                        var ip = GetUsersIp(context.Request);
                        IGeolocationResult geo = null;
                        if (ip != IPAddress.None)
                            geo = GetCurrentUsersLocation(ip);
                        add.SiteReference = ContentReference.StartPage.ToReferenceWithoutVersion().ToString();
                        add.MachineName = System.Environment.MachineName;
                        add.TotalMilliSeconds = timeTotal;
                        add.ControllerMilliSeconds = timeController;
                        add.ViewMilliSeconds = timeRenderView;
                        add.Viewed = DateTime.Now;
                        add.IpAdress = "" + ip;
                        add.RawUrl = context.Request.RawUrl;
                        if (context.Request.UrlReferrer!=null)
                        {
                            add.UrlReferrer = "" + context.Request.UrlReferrer;
                            var url = new EPiServer.UrlBuilder(context.Request.UrlReferrer);
                            var fromContent = UrlResolver.Current.Route(new EPiServer.UrlBuilder(context.Request.UrlReferrer));
                            if (fromContent==null)
                                fromContent = UrlResolver.Current.Route(new EPiServer.UrlBuilder(context.Request.UrlReferrer.PathAndQuery));
                          
                            if (fromContent!=null)
                            {
                                add.ReferrerReferenceWithoutVersion = fromContent.ContentLink.ToReferenceWithoutVersion().ToString();
                                if (fromContent is ILocale && (fromContent as ILocale).Language!=null)
                                    add.ReferrerLanguageID = (fromContent as ILocale).Language.Name.ToLower();
                            }
                          
                        }
                           
                        add.QueryString = context.Request.Url.Query;
                        add.IsEditMode = EPiServer.Editor.PageEditing.PageIsInEditMode;
                        add.UserNameOrSessionId = userNameOrSessionId;

                        if (geo != null)
                        {
                            add.Region = geo.Region;
                            add.ContinentCode = geo.ContinentCode;
                            add.CountryCode = geo.CountryCode;
                            if (geo.Location != null)
                            {
                                add.Latitude = geo.Location.Latitude;
                                add.Longitude = geo.Location.Longitude;
                                add.HorizontalAccuracy = geo.Location.HorizontalAccuracy;
                            }
                        }

                        service.AddAndLazySave(add);

                    }
                }
                catch (System.Exception error)
                {
                    service.AddError(error);
                }

            }
        }
        protected static ContentActionEntity CreateEntity(RouteData routeData)
        {

            var nodeRef = "" + routeData.DataTokens["node"];
            ContentReference parsed;
            if (!ContentReference.TryParse(nodeRef, out parsed))
            {
                return null;
            }
            var result = new ContentActionEntity();
            result.ReferenceWithoutVersion = parsed.ToReferenceWithoutVersion().ToString();
            result.WorkdId = parsed.WorkID;
            result.ControllerName = "" + routeData.Values["controller"];
            result.ActionName = "" + routeData.Values["action"];

            result.LanguageID = "" + (routeData.Values["language"] ?? routeData.DataTokens["defaultLanguage"]);
            if (string.IsNullOrEmpty(result.LanguageID))
                result.LanguageID = ContentLanguage.PreferredCulture.Name;
            var currentNode = routeData.Values["currentContent"];
            if (currentNode is IContent)
            {
                result.ReferenceWithoutVersion += (currentNode as IContent).ContentLink.ToReferenceWithoutVersion().ToString();
                result.WorkdId += (currentNode as IContent).ContentLink.WorkID;
            }
            if (currentNode is ILocale)
            {
                result.LanguageID = (currentNode as ILocale).Language.Name;
            }

            return result;

        }
        protected IGeolocationResult GetCurrentUsersLocation(IPAddress ipAddress)
        {
            var geoLocationProvider = Geolocation.Provider as GeolocationProvider;

            return geoLocationProvider.Lookup(ipAddress);
        }
        protected IPAddress GetUsersIp(HttpRequestBase request)
        {


            if (request.ServerVariables["HTTP_X_FORWARDED_FOR"] != null)
                return IPAddress.Parse(request.ServerVariables["HTTP_X_FORWARDED_FOR"].ToString());

            if (request.UserHostAddress.Length != 0)
                return IPAddress.Parse(request.UserHostAddress);

            return IPAddress.None;
        }
    }

This code will create an object of type ContentActionEntity and save it to a store if we are not in edit modus. The object have different kind of attributes specified bellow.

[EPiServerDataStore(AutomaticallyRemapStore = true, AutomaticallyCreateStore = true)]
    public class ContentActionEntity : IDynamicData
    {
        public EPiServer.Data.Identity Id { get; set; }
        [EPiServerIgnoreDataMember]
        public bool IsSaved { get
            {
                if (Id == null)
                    return false;
                return true;
            }
        }
        [EPiServerDataIndex]
        public string SiteReference { get; set; }

        [EPiServerDataIndex]
        public string MachineName { get; set; }

        [EPiServerDataIndex]
        public string ReferenceWithoutVersion { get; set; }

        public int WorkdId { get; set; }
        [EPiServerDataIndex]
        public string LanguageID { get; set; }

        [EPiServerDataIndex]
        public bool IsEditMode { get; set; }

        [EPiServerDataIndex]
        public DateTime Viewed { get; set; }

        public long TotalMilliSeconds { get; set; }
        public long ControllerMilliSeconds { get; set; }
        public long ViewMilliSeconds { get; set; }

        public string UserNameOrSessionId { get; set; }

        public string QueryString { get; set; }

        public string ControllerName { get; set; }
        public string ActionName { get; set; }
   


        public string ContinentCode { get; set; }

        public string CountryCode { get; set; }
        public string Region { get; set; }

        public string IpAdress { get; set; }

        public double HorizontalAccuracy { get; set; }

        public double Latitude { get; set; }

        public double Longitude { get; set; }

        public string RawUrl { get; set; }
        public string UrlReferrer { get; set; }

        [EPiServerDataIndex]
        public string ReferrerReferenceWithoutVersion { get; set; }

        [EPiServerDataIndex]
        public string ReferrerLanguageID { get; set; }

        public GeoCoordinate GetLocation()
        {
            return new GeoCoordinate(Latitude, Longitude);
        }
        public string GetContinentName()
        {
            if (string.IsNullOrEmpty(ContinentCode))
                return "";
            var localizationService = ServiceLocator.Current.GetInstance<LocalizationService>();
            return localizationService.GetString("/shell/cms/visitorgroups/criteria/geographiclocation/continents/" + ContinentCode);
        }
        public string GetCountryName()
        {
            if (string.IsNullOrEmpty(CountryCode))
                return "";
            var localizationService = ServiceLocator.Current.GetInstance<LocalizationService>();
            return localizationService.GetString("/shell/cms/visitorgroups/criteria/geographiclocation/countries/" + CountryCode);
        }
        public IContent GetContent()
        {
            try {
                var pageRef = ContentReference.Parse(ReferenceWithoutVersion);
                var lang = new LanguageSelector(this.LanguageID);
                return EPiServer.DataFactory.Instance.Get<IContent>(pageRef, lang);
            }
            catch
            {
                return null;
            }
        }

        public MvcHtmlString GetPageName(string format)
        {
            try
            {
                var pageRef = ContentReference.Parse(ReferenceWithoutVersion);
                var lang = new LanguageSelector(this.LanguageID);
                var pathList = EPiServer.DataFactory.Instance.GetAncestors(pageRef).Where(p => p is SitePageData).Reverse().Select(p => p.Name);

                var paths =string.Join("/", pathList);
                var name = EPiServer.DataFactory.Instance.Get<IContent>(pageRef, lang).Name;

                return MvcHtmlString.Create(string.Format(format, paths, name));

            }
            catch
            {
                return MvcHtmlString.Create(string.Format(format, "Error " + ReferenceWithoutVersion + " [" + LanguageID + "]", ""));
            }
       
        }
    }

The servcie looks like this

    [ServiceConfiguration(ServiceType = typeof(ContentActionStoreService), Lifecycle = ServiceInstanceScope.Singleton)]
    public class ContentActionStoreService
    {
        public ContentActionStoreService()
        {
            var key = ConfigurationManager.AppSettings["ServereTimeInfo"];
            if (string.IsNullOrEmpty(key) || key.ToLower() == "true")
            {
                IsEnabled = true;
            }
        }
       
        DynamicDataStore ContentActionStore
        {
            get
            {
                return DynamicDataStoreFactory.Instance.GetStore(typeof(ContentActionEntity));
            }
        }
       
        List<ContentActionEntity> spool = new List<ContentActionEntity>();
        object lockObject = new object();
        public void AddAndLazySave(ContentActionEntity add)
        {
            Add(add);
            SaveTempItems(false);
            
        }
        public void SaveTempItems(bool always)
        {
            List<ContentActionEntity> saveItems = null;
            lock (lockObject)
            {
                if (spool.Count > 10 || always)
                {
                    saveItems = spool;
                    spool = new List<ContentActionEntity>();
                }
            }
            if (saveItems != null)
            {
                foreach (var item in saveItems)
                    ContentActionStore.Save(item);
            }
        }
        void Add(ContentActionEntity add)
        {
                      lock (lockObject)
            {
                spool.Add(add);
            }
        }
}

Then you can either create a view based on thees rows, or just to some SQL queries on the view. Either way it’s a easy and simple solution to find what controller actions or views that takes long time to execute.

Apr 12, 2016

Comments

Please login to comment.
Latest blogs
A day in the life of an Optimizely OMVP - Opticon London 2025

This installment of a day in the life of an Optimizely OMVP gives an in-depth coverage of my trip down to London to attend Opticon London 2025 held...

Graham Carr | Oct 2, 2025

Optimizely Web Experimentation Using Real-Time Segments: A Step-by-Step Guide

  Introduction Personalization has become de facto standard for any digital channel to improve the user's engagement KPI’s.  Personalization uses...

Ratish | Oct 1, 2025 |

Trigger DXP Warmup Locally to Catch Bugs & Performance Issues Early

Here’s our documentation on warmup in DXP : 🔗 https://docs.developers.optimizely.com/digital-experience-platform/docs/warming-up-sites What I didn...

dada | Sep 29, 2025

Creating Opal Tools for Stott Robots Handler

This summer, the Netcel Development team and I took part in Optimizely’s Opal Hackathon. The challenge from Optimizely was to extend Opal’s abiliti...

Mark Stott | Sep 28, 2025

Integrating Commerce Search v3 (Vertex AI) with Optimizely Configured Commerce

Introduction This blog provides a technical guide for integrating Commerce Search v3, which leverages Google Cloud's Vertex AI Search, into an...

Vaibhav | Sep 27, 2025

A day in the life of an Optimizely MVP - Opti Graph Extensions add-on v1.0.0 released

I am pleased to announce that the official v1.0.0 of the Opti Graph Extensions add-on has now been released and is generally available. Refer to my...

Graham Carr | Sep 25, 2025