Copied to clipboard

Flag this post as spam?

This post will be reported to the moderators as potential spam to be looked at


  • Simon Dingley 1470 posts 3427 karma points c-trib
    Jan 07, 2014 @ 13:42
    Simon Dingley
    0

    v4.11.10 Razor Script Performance Issues

    I have a large multi-lingual site that I developed and maintain for a client and performance issues have been the bain of my life with the site for quite some time. After installing MiniProfiler I've discovered the fact that there are a huge number of unnecessary calls (150+) to the database being performed when accessing properties in the Razor scripts like this:

    Model.PropertyName
    

    Yet if this is changed to access properties like this...

    var model = new DynamicNode(Model.Id);
    var propertyName = model.GetPropertyValue("propertyName");
    

    ...there are no calls to the database (there shouldn't be since that's why we have the XML cache). There are a large number of Macroscripts in the site and so before I embark on refactoring them all I want to understand why this is - is it a v4 vs v6 API thing? I've done a lot of reading on this and some of what I read indicated it was fixed in v4.11.10 so I upgraded but the problem remained unless all properties were accessed as per my second example above.

    The problem is obviously not as apparent once caching is enabled however the client is adamant they don't want their visitors to ever take the current hit when the cache refreshes so I am doing all I can to optimise them further.

    Thanks, Simon

  • Jeavon Leopold 3072 posts 13628 karma points MVP 10x admin c-trib
    Jan 07, 2014 @ 13:52
    Jeavon Leopold
    2

    Hi Simon,

    I would say there are many many performance issues with DynamicNode (especially usages of Descendants and other collections) and if you are about to refactor all your Razor, I would urge you to consider upgrading to Umbraco v6 and converting to Macro Partial Views which use the new MVC engine with Webforms templates, the engine is vastly superior in terms of performance.

    With your two examples above, the first one is using dynamics and the second one is not, that would account for some difference in speed and possibly also the additional db calls, although I am not sure on that.

    You could simplify you typed code further to:

    var propertyName = CurrentModel.GetPropertyValue("propertyName");
    

    Jeavon

  • Simon Dingley 1470 posts 3427 karma points c-trib
    Jan 07, 2014 @ 14:06
    Simon Dingley
    0

    Thanks Jeavon. A v6 upgrade is on the horizon however the need to quash the performance issues is now before the launch of the Uk and Global sites in the installation.

    Thanks for the pointer on simplifying the code to access the current Model, that at least saves me some work.

    Every day is a school day in the world of Umbraco :)

  • Jeroen Breuer 4908 posts 12265 karma points MVP 4x admin c-trib
    Jan 07, 2014 @ 14:09
    Jeroen Breuer
    1

    I've also had a lot of performance problems with DynamicNode in the past. Even Gareth (who wrote most of the DynamicNode stuff) admitted it. There is a big topic about it here: http://our.umbraco.org/forum/developers/razor/28479-Razor-menu-performance-(v4)?p=3#comment108221

    In v4.11.10 you can also use the new IPublishedContent stuff so you should definitely do that if you can.

    Jeroen

  • Jeavon Leopold 3072 posts 13628 karma points MVP 10x admin c-trib
    Jan 07, 2014 @ 14:11
    Jeavon Leopold
    0

    Good point Jeroen, you can use Macro Partial Views in v4.10+, there is just no UI for them in the backoffice but you can create them on the file system an hook them up to the macro.

  • Simon Dingley 1470 posts 3427 karma points c-trib
    Jan 09, 2014 @ 18:34
    Simon Dingley
    0

    Thanks guys for you input. I've removed all but 2 of the 150+ SQL queries that were being fired but I am still left with a 4+ second page load most of which appears to be down to Umbraco and mostly to do with querying the domains table - is this avoidable? 

    T+352.1 ms
    Reader
    13.2 ms
    ExecuteReader ExecuteReader <GetDomains>b__0 <GetCacheItem>b__0 GetCacheItem GetCacheItem GetDomains LookupDomain ProcessRequest
    select id, domainName from umbracoDomains   
    T+352.7 ms
    Reader
    8.4 ms
    ExecuteReader ExecuteReader initDomain <GetDomains>b__0 <GetCacheItem>b__0 GetCacheItem GetCacheItem GetDomains LookupDomain
    DECLARE@ID int =10

    select domainDefaultLanguage, domainRootStructureID, domainName from umbracoDomains where id =@ID  
    T+355.8 ms
    Reader
    5.0 ms
    ExecuteReader ExecuteReader <GetAllAsList>b__5 GetCacheItem GetAllAsList initDomain <GetDomains>b__0 <GetCacheItem>b__0 GetCacheItem
    select*from umbracoLanguage   
    T+361.6 ms
    DUPLICATE Reader
    0.2 ms
    ExecuteReader ExecuteReader initDomain <GetDomains>b__0 <GetCacheItem>b__0 GetCacheItem GetCacheItem GetDomains LookupDomain
    DECLARE@ID int =11

    select domainDefaultLanguage, domainRootStructureID, domainName from umbracoDomains where id =@ID  
    T+362.0 ms
    DUPLICATE Reader
    0.1 ms
    ExecuteReader ExecuteReader initDomain <GetDomains>b__0 <GetCacheItem>b__0 GetCacheItem GetCacheItem GetDomains LookupDomain
    DECLARE@ID int =17

    select domainDefaultLanguage, domainRootStructureID, domainName from umbracoDomains where id =@ID  
    T+362.3 ms
    DUPLICATE Reader
    0.1 ms
    ExecuteReader ExecuteReader initDomain <GetDomains>b__0 <GetCacheItem>b__0 GetCacheItem GetCacheItem GetDomains LookupDomain
    DECLARE@ID int =21

    select domainDefaultLanguage, domainRootStructureID, domainName from umbracoDomains where id =@ID  
    T+362.5 ms
    DUPLICATE Reader
    0.1 ms
    ExecuteReader ExecuteReader initDomain <GetDomains>b__0 <GetCacheItem>b__0 GetCacheItem GetCacheItem GetDomains LookupDomain
    DECLARE@ID int =22

    select domainDefaultLanguage, domainRootStructureID, domainName from umbracoDomains where id =@ID  
    T+362.7 ms
    DUPLICATE Reader
    0.1 ms
    ExecuteReader ExecuteReader initDomain <GetDomains>b__0 <GetCacheItem>b__0 GetCacheItem GetCacheItem GetDomains LookupDomain
    DECLARE@ID int =23

    select domainDefaultLanguage, domainRootStructureID, domainName from umbracoDomains where id =@ID  
    T+363.0 ms
    DUPLICATE Reader
    0.1 ms
    ExecuteReader ExecuteReader initDomain <GetDomains>b__0 <GetCacheItem>b__0 GetCacheItem GetCacheItem GetDomains LookupDomain
    DECLARE@ID int =24

    select domainDefaultLanguage, domainRootStructureID, domainName from umbracoDomains where id =@ID  
    T+363.2 ms
    DUPLICATE Reader
    0.1 ms
    ExecuteReader ExecuteReader initDomain <GetDomains>b__0 <GetCacheItem>b__0 GetCacheItem GetCacheItem GetDomains LookupDomain
    DECLARE@ID int =28

    select domainDefaultLanguage, domainRootStructureID, domainName from umbracoDomains where id =@ID  
    T+363.4 ms
    DUPLICATE Reader
    0.1 ms
    ExecuteReader ExecuteReader initDomain <GetDomains>b__0 <GetCacheItem>b__0 GetCacheItem GetCacheItem GetDomains LookupDomain
    DECLARE@ID int =29

    select domainDefaultLanguage, domainRootStructureID, domainName from umbracoDomains where id =@ID  
    T+363.7 ms
    DUPLICATE Reader
    0.2 ms
    ExecuteReader ExecuteReader initDomain <GetDomains>b__0 <GetCacheItem>b__0 GetCacheItem GetCacheItem GetDomains LookupDomain
    DECLARE@ID int =34

    select domainDefaultLanguage, domainRootStructureID, domainName from umbracoDomains where id =@ID  
  • Simon Dingley 1470 posts 3427 karma points c-trib
    Jan 10, 2014 @ 12:22
    Simon Dingley
    0

    On a related note, I have another post on a closely related topic for this site:

    http://our.umbraco.org/forum/core/general/47391-Umbraco-v41110-Caching-Problems

  • Jeavon Leopold 3072 posts 13628 karma points MVP 10x admin c-trib
    Jan 10, 2014 @ 12:57
    Jeavon Leopold
    0

    Hey Simon,

    How many domains do you have in this Umbraco installation?

    Stephen completely overhauled how domains are managed in v6 so it would be interesting to see the number of queries in v6 compared to this.

    Jeavon

  • Simon Dingley 1470 posts 3427 karma points c-trib
    Jan 10, 2014 @ 13:29
    Simon Dingley
    0

    Hi Jeavon,

    11 domains in the umbrcoDomains table at present.

    Thanks, Simon

  • Stephen 767 posts 2273 karma points c-trib
    Jan 11, 2014 @ 10:39
    Stephen
    1

    Looking into it. What you see (all those SQL queries) is a (rather unefficient) way of loading all domains in memory. We're still doing it that way in v6 and v7 because the Domains API has not been ported to PetaPoco (new ORM) yet. It could be optimized... well, it should, and I'll try to do it asap.

    That being said... the result of that load, ie the list of all domains, is supposed to be cached for 30 minutes. That is, you should see all those queries only once every 30 minutes, and certainly not on every request. Can you check whether you see them on every request?

    What worries me is that you say that using the Model.propertyName syntax also triggers a bunch of queries... any chance you can track and report those queries? The DynamicNode is not über-performant, and Gareth never denied it, but I fail to see why it would issue that many queries, on each request. As far as I can tell, database access is not an issue with DynamicNode.

    So... assuming you see these queries on every request... the first thing that pops to my mind would be that some caching is not taking place. As if, your AppDomain keeps restarting, or something. I know it does not make much sense...

    So... could you check whether you get the domain queries on every request? Could you try to dump the DynamicNode queries?

    Stephan

  • Simon Dingley 1470 posts 3427 karma points c-trib
    Jan 13, 2014 @ 17:59
    Simon Dingley
    0

    Hi Stephan,

    > you should see all those queries only once every 30 minutes, and certainly not on every request. Can you check whether you see them on every request?

    No I don't see them for every request however the client wants an uncached page load time improvement and this is one significant factor. Is there an open issue on the tracker for the Domain API refactoring? Wondering if it is something I might be able to assist with (with some guidance).

    > What worries me is that you say that using the Model.propertyName syntax also triggers a bunch of queries... any chance you can track and report those queries? The DynamicNode is not über-performant, and Gareth never denied it, but I fail to see why it would issue that many queries, on each request. As far as I can tell, database access is not an issue with DynamicNode.

    Here is an example of what happens when using the .Property notation in a navigation script e.g. node.MenuText: 

    T+2093.5 ms
    Reader
    173.2 ms
    ExecuteReader ExecuteReader <GetDataType>b__a GetOrAdd GetDataType <.cctor>b__10d GetDataType TryGetPropertyData TryGetMember
    DECLARE@contentTypeAlias nvarchar(16)= N'StandardTextPage',
           
    @propertyAlias nvarchar(8)= N'menuText'

    select  cmsDataType.controlId, masterContentType.alias as masterAlias  from  cmsContentType  leftjoin cmsPropertyType on(cmsContentType.nodeId = cmsPropertyType.contentTypeId and cmsPropertyType.Alias =@propertyAlias)  leftjoin cmsDataType on(cmsPropertyType.dataTypeId = cmsDataType.nodeId)leftjoin cmsContentType masterContentType on masterContentType.nodeid = cmsContentType.masterContentType  where  cmsContentType.alias =@contentTypeAlias  
    T+2219.9 ms
    DUPLICATE Reader
    46.8 ms
    ExecuteReader ExecuteReader <GetDataType>b__a GetOrAdd GetDataType <GetDataType>b__a GetOrAdd GetDataType <.cctor>b__10d
    DECLARE@contentTypeAlias nvarchar(8)= N'BaseMeta',
           
    @propertyAlias nvarchar(8)= N'menuText'

    select  cmsDataType.controlId, masterContentType.alias as masterAlias  from  cmsContentType  leftjoin cmsPropertyType on(cmsContentType.nodeId = cmsPropertyType.contentTypeId and cmsPropertyType.Alias =@propertyAlias)  leftjoin cmsDataType on(cmsPropertyType.dataTypeId = cmsDataType.nodeId)leftjoin cmsContentType masterContentType on masterContentType.nodeid = cmsContentType.masterContentType  where  cmsContentType.alias =@contentTypeAlias  
    56.20 ms
    T+2322.9 ms
    DUPLICATE Reader
    25.3 ms
    ExecuteReader ExecuteReader <GetDataType>b__a GetOrAdd GetDataType <.cctor>b__10d GetDataType TryGetPropertyData TryGetMember
    DECLARE@contentTypeAlias nvarchar(7)= N'SiteMap',
           
    @propertyAlias nvarchar(8)= N'menuText'

    select  cmsDataType.controlId, masterContentType.alias as masterAlias  from  cmsContentType  leftjoin cmsPropertyType on(cmsContentType.nodeId = cmsPropertyType.contentTypeId and cmsPropertyType.Alias =@propertyAlias)  leftjoin cmsDataType on(cmsPropertyType.dataTypeId = cmsDataType.nodeId)leftjoin cmsContentType masterContentType on masterContentType.nodeid = cmsContentType.masterContentType  where  cmsContentType.alias =@contentTypeAlias  
    T+2349.3 ms
    DUPLICATE Reader
    31.4 ms
    ExecuteReader ExecuteReader <GetDataType>b__a GetOrAdd GetDataType <.cctor>b__10d GetDataType TryGetPropertyData TryGetMember
    DECLARE@contentTypeAlias nvarchar(11)= N'ContactPage',
           
    @propertyAlias nvarchar(8)= N'menuText'

    select  cmsDataType.controlId, masterContentType.alias as masterAlias  from  cmsContentType  leftjoin cmsPropertyType on(cmsContentType.nodeId = cmsPropertyType.contentTypeId and cmsPropertyType.Alias =@propertyAlias)  leftjoin cmsDataType on(cmsPropertyType.dataTypeId = cmsDataType.nodeId)leftjoin cmsContentType masterContentType on masterContentType.nodeid = cmsContentType.masterContentType  where  cmsContentType.alias =@contentTypeAlias  

    Again this is not for every page request only uncached requests but if I change it to use node.GetPropertyValue("menuText") there are no calls to the database which is what I'd expect.

    In case its relevant, historically this install has been plagued with caching problems for some time, see http://our.umbraco.org/forum/core/general/39961-Cache-Problems-in-4114-Wont-Rebuild
    Let me know if you want any further information.
    Thanks, Simon
  • Stephen 767 posts 2273 karma points c-trib
    Jan 13, 2014 @ 18:08
    Stephen
    0

    Thanks for replying.

    Just to make sure... by "uncached request" do you mean requests that do not use content cache, or cold-start requests -- ie the first request after the application pool has (re)started?

    The Domain API refactoring has no entry in the bug tracker yet -- I still need to create it. Also, it's on my TODO list for this week.

    I will read the other thread.

    Stephan

  • Simon Dingley 1470 posts 3427 karma points c-trib
    Jan 14, 2014 @ 14:01
    Simon Dingley
    0

    Just to make sure... by "uncached request" do you mean requests that do not use content cache, or cold-start requests -- ie the first request after the application pool has (re)started?

    I've just checked and it appears to be on cold-start requests only.

    Thanks, Simon

  • Stephen 767 posts 2273 karma points c-trib
    Jan 14, 2014 @ 14:26
    Stephen
    0

    Well then... it's pretty normal that you see these requests. Granted, the domains stuff could be optimized (created http://issues.umbraco.org/issue/U4-4043) but it does not explain bad perfs issues such as a 4secs page load that you mention earlier. Are these 4secs on cold-start page, or also once the site is up and running?

  • Simon Dingley 1470 posts 3427 karma points c-trib
    Feb 28, 2014 @ 09:31
    Simon Dingley
    0

    The plot thickens on this situation which has cost so much time it's driving everyone crazy, every time we seem to be making progress we find something else. The latest contributor to slow load times was the CropUpUrls module, a separate thread on this can be found here. Disabling the module and losing the clean urls gave us a nice little extra performance boost but we still keep hitting randomly slow load times.

    Can someone provide some clarification on how macro caching works please? The homepage of the site in question has a number of macros with long cache time of mostly 604800s (1 week). The reason they are so long is because we found the cache seems to be cleared on every publish action so it will always be flushed when something new is published, this is a problem but one we are using to our advantage right now. When the cache is working we get really good page load times < 1sec however the site goes through periods of ignoring the macro cache entirely and reloading the macros and adding the content to cache on every page load and we can't work out why? Is the macro cache an in-memory cache?

    Example which is often repeated for every page load:

    enter image description here

    The site is a multi-language site (multiple root nodes), mostly only one of the languages is currently updated regularly but switching between languages (probably related to the above) often results in all macro content being loaded again and not coming from the cache.

    Once again I'm looking to the community for some help in trying to resolve this once and for all.

    Cheers, Simon

  • Stephen 767 posts 2273 karma points c-trib
    Mar 03, 2014 @ 09:10
    Stephen
    0

    The macro cache is an in-memory cache that is cleared when a document is published as it is assumed that because content has changed, you want the front-end to be updated. Otherwise that can be quite confusing to editors, especially with very long cache durations, ie they publish something but don't see any changes for ages.

    There might be other events that clear that cache but I can't remember them all at the moment.

    Making sense?

  • Simon Dingley 1470 posts 3427 karma points c-trib
    Mar 03, 2014 @ 09:15
    Simon Dingley
    0

    Thanks Stephen, that confirms one suspicion I had. Clearing the cache on every publish on a regularly updated site is a problem however my immediate concern is currently why on our staging server where no content is being edited, the site keeps losing the macro cache randomly. The machine has plenty of RAM so I don't think its a case of it being flushed due to a shortage of available memory.

    Guessing this is going to require some digging into the core to try and work out how to trace when the macro cache gets dropped and why?

    Thanks, Simon

  • Simon Dingley 1470 posts 3427 karma points c-trib
    Mar 07, 2014 @ 09:48
    Simon Dingley
    0

    Is there anything I can do to monitor the Macro cache activity? Primarily I would like to log cache item insertion and expiry or clearing to try and better understand what is triggering the loss of macro cache.

Please Sign in or register to post replies

Write your reply to:

Draft