Monday, October 3, 2011

Using The SharePoint Developer Dashboard and SPMonitoredScope

How often do we have clients come to us and say:

I like SharePoint feature X, but I want to just ‘tweak’ it a little bit.

Often, these ‘little tweaks’ involve displaying more information than the OOTB feature, or just displaying it in a different manner.  To a client, it sometimes looks quite easy – “just change that to grab this extra field I want and these other items I want you’ll be done in no-time flat”.  As we all know, sometimes it’s a bit more complex than that, but that’s not the focus of this post.  The problem is, sometimes this extra data being pulled back has performance implications.  Just because you can access a property/object by just a few object references or a short loop doesn’t mean that it’s free (I’m using the term “free” here to refer to having no or virtually no performance delay associated with it).  Generally, data that has already been fetched into memory is so close to free to use that it’s not worth caring about.  What we have to be careful of is loading data that hits that database – that is definitely not free.

One tool we have to help narrow down performance problems is the SharePoint Developer Dashboard.  It gives us a bunch of useful information about how a page renders, including a tree-based display of where time was spent during the request, and the new SharePoint 2010 class SPMonitoredScope lets us send information to it from our custom components.  See http://blogs.technet.com/b/speschka/archive/2009/10/28/using-the-developer-dashboard-in-sharepoint-2010.aspx for a good writeup of what it is, what it can do, and how to turn it on.  I usually run my development farms with it in “on demand” mode so I don’t have to see it all the time, but can just flip it on when I need it.

Now, on to today’s problem – building a better breadcrumb.  I was asked to enhance the OOTB breadcrumb to not only show this page’s location with the current site (which the OOTB breadcrumb does), but also it’s place within the site collection.  Additionally, we did *not* want to see sites above the root of the current variation.  So I started off with the simplest thing that could possibly work – find the label for the current variation, then walk my way up the tree of SPWeb objects starting with SPContext.Current.Web and using SPWeb.ParentWeb until I got a null, or left the current variation.  My code roughly looked like this:

// build the multi-site breadcrumb

using (new SPMonitoredScope("Build site breadcrumb"))

{

    VariationLabel label;

    using (new SPMonitoredScope("Get current variation label"))

    {

        label = VariationsUtility.GetCurrentVariationLabel();

    }

    // Use label and SPContext.Current.Web to build the tree

}

Which resulted in a trace that looked like this for a site deep in the tree:

image

Wow, 110ms to build the breadcrumb, 93ms of it getting the labels? (this was on my laptop – on my development server with a remote database server, it was around 600ms, 350ms of it fetching the variation labels)  Ouch, that’s expensive…  Can we get this down further?  Is there any way to tell by looking at a web whether it’s in a variation (so we wouldn’t have to fetch the labels)?  Turns out, yes, there is.

Take a look at the property bag on two different webs – first two variations of the same site, then their parent (who is outside of the variation hierarchy):

PS C:\> (get-spweb http://client.local/sites/langtest-custom/en-US).AllProperties["Variation Group Id"] 

1c929197-85bc-4d8b-8388-34112d7da33e 

PS C:\> (get-spweb http://client.local/sites/langtest-custom/es-ES).AllProperties["Variation Group Id"] 

1c929197-85bc-4d8b-8388-34112d7da33e 

PS C:\> (get-spweb http://client.local/sites/langtest-custom).AllProperties["Variation Group Id"] 

PS C:\>

The “Variation Group Id” property appears to be used to tie the variations of a given site together.  I don’t care about doing that for this case, so I can ignore the value – all I need to worry about is whether or not that property exists.  By changing my code to not fetch the list of variation labels (since I already had the SPWeb objects for each node already), I get this trace on my laptop:

image

14ms – not too shabby.  Unfortunately, on the development server it was still about 250ms to fetch the webs.  Is there any way I could eliminate that?  My first thought was PortalSiteMapProvider.WebSiteMapProvider.  PortalSiteMapProviders are pretty heavily-cached, and that one just deals with SPWebs – exactly what I need.  I changed my inner code to something like this (using PortalWebSiteMapNode.TryGetProperty to check for the web property I discovered above):

using (new SPMonitoredScope("Fetch data from PortalSiteMapProvider via HttpContext"))

{

    var node = PortalSiteMapProvider.WebSiteMapProvider.FindSiteMapNode(HttpContext.Current) as PortalWebSiteMapNode;

    // use node and .ParentWebNode to build up the path

}

Which resulted in a trace that looked like this (even for repeated loads):

image

Not good – we went from 14ms to 42ms locally.  However, it looked like a lot of it was loading the node for the page I was one and using that to find the web, and that part didn’t seem to be cached… Hmm…  I wonder what would happen if I gave it the web directly….

using (new SPMonitoredScope("Fetch data from PortalSiteMapProvider via HttpContext"))

{

    var node = PortalSiteMapProvider.WebSiteMapProvider.FindSiteMapNode(SPContext.Current.Web.ServerRelativeUrl, SPContext.Current.Web) as PortalWebSiteMapNode; 

    // use node and .ParentWebNode to build up the path

}

image

Voila!  Just what I was looking for – 0.07ms to load the data about what webs I was displaying.  Now for the real test – what does it look like on the development server (where database accesses are more expensive)?

image

Yes, a little bit slower on the server than my laptop, but now we’re in the acceptable range.  And all thanks to detailed performance monitoring made possible by SPMonitoredScope.  The result?  The possibility for an obnoxiously-long breadcrumb:

image

The lessons from this?

  1. SPMonitoredScope is very helpful when tracking down performance issues in custom code. Use it. Love it.
  2. Just because there's a property on an object you already have, doesn't mean it's free to fetch (ie. SPWeb.ParentWeb in this example).
  3. PortalSiteMapProvider is fast, especially if you use the right overload of FindSiteMapNode for the kind of node you're looking for.
  4. 7-level deep breadcrumbs with really long names look kinda odd.