Instrumentation & Logging for SharePoint (Part 1)

Recently I have been defining how the development team will implement Instrumentation and Logging for SharePoint.  I looked at a lot of different options and settled on the built-in .Net Framework diagnostic routines.

Logging

For logging I decided to use the System.Diagnostics.TraceSource class.  This class was introduced with .Net Framework 2 and is a marked improvement over the original System.Diagnostics.Trace (my opinion). 

Out-of-Box System.Diagnostics has trace listeners for Event Log, Console and File System.  For grins I wrote a listener that will write to the SharePoint log system.  It was very easy since the WSS SDK contains an example.

Three really nice features I like about the improved Diagnostics tracing classes are: Trace Options, Source Levels and Trace Filters

Trace Options provide a nice flexible way of indicating what data should be written along with the log message.  Some examples include: Call Stack, Date & Time stamps, Thread ID, Process ID and Logical Call Stack.  These options can be configured in the configuration file so the application does not need to even know about them.

Source Levels provide a nice alternative to the old Trace Switch class.  A source level determines what type of messages should be logged (i.e. Critical, Error, All, ...).

Trace Filters provide a way to tell the Listener what types of errors it should log.  This is really nice because it means that I can create File System listener that will write out every messages passed on by the Trace Source.  At the same time my Trace Source could have an Event Log listener that still only writes critical messages to the Event Log.

The really great thing is all of these classes can be configured in a configuration file.

Below is a sample configuration I used while working with the Trace classes.

<system.diagnostics>
    <trace autoflush="true" />
    <sources>
        <source name="MyLogSource" switchValue="All">
            <listeners>
                <add name="consoleListener" />
                <add name="fileListener" />
                <add name="eventLogListener" />
                <add name="sharepointLogListener" />
            </listeners>
        </source>
    </sources>        
    <sharedListeners>
        <add name="consoleListener" type="System.Diagnostics.ConsoleTraceListener" />
        <add name="fileListener" initializeData="c:\temp\VolvoCWP.txt" type="System.Diagnostics.TextWriterTraceListener" traceOutputOptions="DateTime,ProcessId,LogicalOperationStack">
            <filter type="System.Diagnostics.EventTypeFilter" initializeData="All"/>
        </add>
        <add name="eventLogListener" type="System.Diagnostics.EventLogTraceListener" traceOutputOptions="DateTime,ProcessId,LogicalOperationStack" initializeData="JD Application">
            <filter type="System.Diagnostics.EventTypeFilter" initializeData="Critical"/>
        </add>
        <add name="sharepointLogListener" type="MyLogListener.SharePointTraceListener, MyLogListener, Version=1.0.0.0, Culture=neutral, PublicKeyToken=6bb1c46a01dcf0a2" ApplicationName="JeffD" ProductName="JeffD" CategoryName="Runtime">                
        </add>
    </sharedListeners>        
</system.diagnostics>

This configuration contains one Trace Source (MyLogSource).  It is configured to log all messages that are logged with it (switchValue="All").  It has four listeners it will use to log the message (yes the message can get logged into four places... not very practical in the real world). The consoleListener, fileListener and sharepointLogListener are configured with filters that tell them to log every message.  The eventLogListener is configured to only log messages marked as Critical.

The SharePointTraceListner was actually very simple to write.  I was able to find a really great example of writing to the SharePoint log inside the WSS SDK.  All I did was take that example and plug it into a standard Trace Listener. 

Technorati Tags: SharePoint,Logging,Development,.Net Framework

Test Driven Development with SharePoint

Lately I have been doing quite a bit of development inside of SharePoint.  I am a big fan of Test Driven Development so naturally I wanted to carry over one of my favorite development techniques to SharePoint.

I wanted to share some of the obstacles I ran into along the way and techniques I used to overcome them.

Before I go on I want to point out that I am using Visual Studio 2008 for my development environment. 

Missing Method Exception 

One of the first problems I encountered was a Missing Method Exception when I would run the unit tests.  I never did really find out what was happening.  I did find a nice technique for working around it. 

I modified the PostBuild routine of my Unit Tests to install my target DLL in the GAC.  I also executed my tests in Debug mode.  Doing both things overcame the issues.  You can read the details here.

Testing Routines that require HTTPRuntime context

The next big challenge for me was to find a way to test routines that needed the HTTPRuntime, HTTPContext or SPContext objects.

I'm not a big fan of using mock objects when unit testing.  And the thought of mocking any of those classes (or any of the SharePoint classes) turns my stomach. 

For the most part my routines are built so they do not require runtime context.  If I had to guess I would say < 5% of my tests are setup this way.  Even though it is such a small part of my test footprint it is still a very important part. 

Since I am using Visual Studio 2008 (this was available in VS.Net 2005 too) I am able to decorate those tests that require context with the HostType and UrlToTest attributes.  Using these attributes will tell MSUnit to run my tests within the context of the IIS runtime.

[TestMethod()]
[HostType("ASP.Net")]
[UrlToTest("Url to SharePoint Page"]
public void FooBarTest
{
    string expected = "raBooF";
    string actual = MySharePointRoutine.RoutineThatUsesSPContext();
    Assert.AreEqual(expected, actual);
}

This works great, but there are some drawbacks.

1. Requires SharePoint site to be configured with Full trust

For MSUnit to hook into the IIS runtime context it has to do some tricky stuff.  Unfortunately it doesn't work unless you configure the SharePoint site Full Trust. 

One could argue that this invalidates my Unit Tests since it is quite possible that I will have some code that executes one way under Full Trust and another under WSS_Minimal Trust.  While this is true I believe the chance of this happening is small. 

2. Does not work with Publishing Pages

If you try to use a publishing page in the UrlToTest attribute the test will fail.  Below is the error message.

The Web request 'SharePoint URL' completed successfully without running the test. This can occur when configuring the Web application for testing fails (an ASP.NET server error occurs when processing the request), or when no ASP.NET page is executed (the URL may point to an HTML page, a Web service, or a directory listing). Running tests in ASP.NET requires the URL to resolve to an ASP.NET page and for the page to execute properly up to the Load event. The response from the request is stored in the file 'WebRequestResponse_RelatedLinkPathTest_.html' with the test results; typically this file can be opened with a Web browser to view its contents.

I do not know exactly what this means, but I believe the problem may be caused by the fact that Publishing pages are virtual pages that map directly to a list item (i.e. they are not actually an ASPX page).

This kind of stinks because some of the tests may expect the SPContext.Current.ListItem property to be loaded with a valid list item.  As a work around I discovered that I could could use the URL that will display list properties for a publishing page (Pages/Forms/DispForm.aspx?ID={List ID}). 

To find create the DispForm Url I will first open a browser and point to /pages/forms/allitems.aspx (where pages represents the Publishing pages list).  This will provide a list of all of the pages.  I then choose the item I want and select View Properties.

Then I copy the URL from the web browser and I have what I need.

3. Difficult for Team Environments

Another problem is the fact that it is not possible (or I could never find a way) to parameterize the UrlToTest attribute.  This means that the URL must be generalized so it works on all of the developer and build machines. 

Microsoft has a great article that discusses issues teams will encounter when testing web pages (here).  The article discuss's using the AspNetDeveloperServerHost attribute in the MSUnit.  This attribute supports context parameters so tests can be made to work across teams.  Unfortunately I was not able to AspNetDevelpoerServerHost to work with SharePoint Url's.  When you think about all of the infrastructure needed to make WSS work it is not surprising that this does not work.

Conclusions

Test Driven Development with SharePoint is doable.  The difficulties of setting up Unit Tests will vary depending on what your tests need to do.  

Technorati Tags: SharePoint,Test Driven Development,Development,Visual Studio 2008

Creating a Rendering Template that supports Edit and Display modes

I have been working on a Field Control rendering template that works for both Edit and Display modes.  Along the way I learned quite a few things.

First I am not covering the steps to create a SharePoint field control.  You can find a walk-through for creating a custom field control here.

DefaultTemplateName is not used in Display mode.

The first problem I ran into was the rendering of my control in Display mode.  I had put in an override for the DefaultTemplateName property in my control.  The documentation was vague but seemed to imply that the Display rendering template would be pulled from this value.

Well that is not the case.  To get my custom rendering template loaded in Display mode I had to override the DisplayTemplateName property. 

Once I had both DefaultTemplateName and DisplayTemplateName overridden I was in full control of the display.

Mixing the TemplateContainer and EditModePanel objects

With my rendering template I thought it would be best to just create one rendering template for both Edit and Display modes.  The main reason I did this was so I could encapsulate all of the markup for a control in one rendering template. 

My rendering template was nothing more than a ASP.Net User Control (ASCX file).  By using a user control I had a nice container to edit the HTML mark-up for my control.

To give myself different looks for Edit and Display modes I decided to use the Publishing EditModePanel control.  EditModePanels are a nice way of isolating a set of mark-up based on the page mode. 

I put my EditModePanel controls inside my RenderingTemplate control.  This is very important because it caused me grief later on.

<SharePoint:RenderingTemplate ID="VolvoCWPRelatedLinkControl" runat="server">
    <Template>    
        <SharePointPublishing:EditModePanel ID="RelatedLinkEditPanel" runat="server" PageDisplayMode="Edit" SuppressTag="true">

In the CreateChildControls routine of my control I needed to instantiate classes that were mapped to the controls in my ASCX file.  According to the walk-through sample I should use the TemplateContainer.FindControl routine.  Well this did not work because my controls were sitting inside an Edit Mode Panel.

To make this work I had to first find the Edit Mode Panel and then use the FindControl routine in its class.

this.empPanel = (EditModePanel)Utility.FindAndValidateControl(TemplateContainer, "RelatedLinkDisplayPanel");
this.empPanel.PreRender += new EventHandler(RelatedLinkDisplayPanel_PreRender);

this.lblTitle = (Label)Utility.FindAndValidateControl(this.empPanel, "tbRelatedLinkTitle");

this.repLinks = (Repeater)Utility.FindAndValidateControl(this.empPanel, "repRelatedLinkItems");

The FindAndValidateControl is a routine I wrote to do call the FindControl routine and make sure that the value passed back is not null. 

public static object FindAndValidateControl(System.Web.UI.Control controlContainer, string controlName)
{            
    object returnValue = controlContainer.FindControl(controlName);
    if (returnValue == null)
        throw new ConfigurationErrorsException(string.Format("{0} not found. Corrupt control template.", controlName));

    return returnValue;
}

Once I figured out that the parent container mattered I was on my way.  But it took me a few times staring at the "Control not found error" before I figured out what was going on.  Just in case you are wondering I have not done a lot of ASP.Net control development so I realize I may have made a rookie mistake.

ItemFieldValue vs. Value

The next problem I ran into was a difference in the way the BaseFieldControl Value and ItemFieldValue properties work. 

In my control I had put an override in for the Value property (per the Custom Control Walk-through).  This works great when you are in Edit mode (I assume it also works when in New mode).  But when in Display mode I discovered that the Value property was not being set.  The documentation clearly states that when the control is loaded the Value is supposed to be given the same value as the ItemFieldValue property.  Well this did not happen in my control.

To get around the issue I created a special handler for my Display Mode panel pre-render event.

public void RelatedLinkDisplayPanel_PreRender(object item, EventArgs e)
{
    EnsureChildControls();

    RelatedLinkValue fieldValue = new RelatedLinkValue(ItemFieldValue.ToString());
    QueryService queryService = new QueryService();
    DataTable queryResults = queryService.GetCategoryItems(fieldValue.Category, PropertyService.RelatedLinkPath, "PublishingPageContent");
    
    this.lblTitle.Text = fieldValue.Title;
    this.repLinks.DataSource =  queryResults;
    this.repLinks.DataBind();

}

In the PreRender event I call the EnsureChildControls (for the same reason why it should be called in the Value override) and I use the ItemFieldValue property.

Conclusion

I was able to consolidate my Edit and Display mode rendering templates into one control without too much effort.  I did run into some gotchas, but nothing that made me think I had made a big mistake.

 

Technorati Tags: SharePoint,Development,Rendering Template,Field Control

Publishing Pages List Template ID

The Publishing Pages List BaseTemplate ID is 850. 

It is not listed in the SPListTemplateType enumeration.

SharePoint Community Kit Wiki (or Lipstick on a Pig)

Recently the development team at work started using a Wiki to keep track of information that is important to the team.  Since our company has standardized on using SharePoint for Collaboration solutions we used the Wiki featured delivered from Microsoft (via the Community Kit for SharePoint).

I must say I am very unimpressed by the SharePoint Wiki.  I don't want to take anything away from the community effort that developed the Wiki template for SharePoint.  I'm sure the community has done the best they can to develop a Wiki application on top of SharePoint (although it does appear to be missing some basic functionality one would expect from a Wiki.. Categories, Page Discussions).  Perhaps SharePoint is not the best platform to host a Wiki.

Here is a short list of my main concerns with using the SharePoint Wiki.

1. Content is stored in a single list

As most know SharePoint starts to perform badly whenever a list contains more than 1000 items (this number is debated, what is not debated is that SharePoint performance degrades as list size grows).

The Wiki appears to be storing all pages directly in the root of a Document list.  So after my Wiki has 1000 pages I will start to see a major slowdown.  I am really surprised that categories (acting as Folders) were not implemented.  To me this would have been a natural way to help reduce the impact of having a large list of Wiki pages.

2. Poor Search

This is my #1 complaint with our new Wiki.  In my opinion a Wiki is only as good as its search engine.  And unfortunately SharePoint search is still not as good as it can be. 

Conclusion

When I compare the SharePoint Wiki features and functionality to something like ScrewTurn I am left with one thought..  the SharePoint Wiki sucks.

Technorati Tags: ShrarePoint,Community Kit for SharePoint,Wiki,ScrewTurn

FieldID class

I came across a very useful class in the Publishing library.

Microsoft.SharePoint.Publishing.FieldId

The FieldId class contains a list of commonly used field ids.  I like it because it gives me an easy way to reference fields without having to worry about Internal Name vs. Display Name.

Since this is in the Publishing library you will have to have SharePoint 2007 to take advantage.

Technorati Tags: SharePoint,Field,Publishing

Missing Method Exception (or why my Unit Tests would not work with my SharePoint project)

I'm using some test driven development concepts on a little SharePoint development project.

I noticed that I kept running into a really strange error every time I added a new Method to my SharePoint project.

Whenever I would run my new Unit Test I would get a System.MissingMethodException error saying that the method in my SharePoint project could not be found.

Turns out that the problem was caused by the fact that the Unit Test project was loading my SharePoint assembly from the GAC.  So for me to get the tests to work I had to install the latest version of my SharePoint assembly into the GAC and then close/open Visual Studio.

I like to take very small steps when I develop (add some functionality, test it, add some functionality, test it).  So the idea of constantly updating the GAC and closing Visual Studio was not appealing.

I considered removing my SharePoint assembly from the GAC, but I put it in there for some legitimate reasons.

After much trial and error I found a solution that works okay (but is not ideal).  I configured my Unit Test project to install the SharePoint dll in the GAC whenever the project is compiled.  And I run the Unit Tests in Debug mode.  With this setup I am able to get instant feedback from my changes.

As I said it is not ideal, but works.

To install my SharePoint dll in the GAC I added a Post Build event to my Unit Test project.  It just runs the gacutil command.

To run my Unit Tests in debug mode I launch my tests using the Visual Studio Debug option rather than Run option.

I am using Visual Studio 2008 Test project for my Unit Tests.

Technorati Tags: SharePoint,Development,TDD,UnitTests,Visual Studio 2008

Six hours later...

I finally figured out why my Feature would not create my Site Columns and Content Types.

I mistyped the ElementManifests statement in the Feature definition.

Instead of using the ElementManifest tag I used the ElementFile tag. Uggg...

<Feature xmlns="http://schemas.microsoft.com/sharepoint/" ...>
    <ElementManifests>
        <ElementManifest Location="SiteColumns.xml"/> <!-- Right -->
        <ElementFile Location="SiteColumns.xml"/> <!-- Wrong -->
    </ElementManifests>
</Feature>

Rookie mistake. I didn't look closely at my Feature file because I was sure I had screwed up something in the element file that contained by Field definitions.

Technorati Tags: SharePoint,Features,Mistakes

Load Testing SharePoint (Lessons Learned) (Part 2)

In part 1 I discussed the setup of my load testing environment and tests.  In part 2 I want to focus on the tests runs and what configuration I had to make to get them to work.

Bottlenecks oh Bottlenecks, wherefore art thou Bottlenecks

Right out of the gate I ran into trouble.  My tests showed a bottleneck at 4 requests per second.  The CPU was running @ 25 - 35% no matter what user load VSTS used (remember I was using goal based testing that would keep loading users until the goal was met).  I tried several different tests and they all had the same result.  So I knew there was a bottleneck somewhere.

I started by looking at the network.  Specifically I focused on the virtual's network adaptor.  I was worried that there was some sort of VMWare configuration problem.  To test the network I used a file copy test (I uploaded and downloaded a large file to the web server).  The test showed that the network was working just fine.

Then it hit me, the web server was configured to only support Integrated Windows authentication (NTLM).  So I configured SharePoint (and IIS) to support Anonymous authentication.  Bam, the bottleneck was gone.

Size Matters

So I ran my first set of tests.  Unfortunately I noted a fairly significant difference between the out of the box Article page and our custom page.

Next I used the SharePoint Test Data Population Tool to create a site collection that contained 22,000 sites and about 50,000 pages.

Then I ran the tests again with some very surprising results.  The out of the box Article page when from 114 requests per second to 56 requests per second.  That's right we recorded an almost 100% decrease in performance just due to the size of the site collection. 

Our custom page's did not experience the same percentage of slow down (actually their performance improved, but that was due to improvements we made to the code).

Summing Up

Performance testing SharePoint is a tedious but necessary task.  Here are my lessons learned from the exercise.

1. Plan, Plan, Plan

Establish the test goals

Determine which tests you need to run

Determine which tools you will use

Determine the setup/configuration of your SharePoint and Load test environments.

2. Dry run the tests (leave plenty of time to work through issues)

3. Don't test with an empty site collection

Technorati Tags: SharePoint,Performance,visual Studio Team System,Load Testing

Musing on CrossListQueryCache class

Summary

The SharePoint CrossListQueryCache class provides a highly scalable way to run site wide queries.  It provides all the power of SPSiteDataQuery without the performance implications.  However it has some major gotchas that you should be aware of before using.

I'm always looking for ways to improve application performance (and with SharePoint I have more opportunities than time). I was focused on some code we use to pull list items.  This code is in the critical path for our runtime performance and scalability.  It is the perfect place for cached data query.  So I started looking at different ways to do data querying in SharePoint. 

My first stop was on Google where I found some information about the SharePoint SPSiteDataQuery object. According to Eric Shupps (The SharePoint Cowboy :D) SPSiteDataQuery is great for small data sets and small to medium traffic environments. Eric actually recommends using the good ole GetListItems method.  Well we are using GetListItems today, so I was not encouraged.  Waldek Mastykarz put together a really nice posting that compares several different approaches for querying lists (just what I needed).

Even though I had read the warnings about SPSiteDataQuery I decided to check it out (for some reason I really like to repeat the mistakes of others ;-).  I really like the functionality provided by the class. I used Reflector to look under the covers.  I didn't seen anything crazy going on (makes a call to COM method called CrossListQuery... I didn't bother chasing it to the SQL layer).  I ran some performance tests with it, but didn't see a compelling reason to dump GetListItems for this routine.

Next I jumped into the CrossListQueryInfo/CrossListQueryCache routines. It is worth mentioning that these are in the Microsoft.SharePoint.Publishing library which means you have to have SharePoint 2007 (WSS v3 does not include this library). What I found shocked and delighted me (hmm, doesn't sound quite right).

First the shock...

According to the documentation CrossListQueryCache was built specifically for what I needed to do. Query one or more lists and store the results in cache so subsequent calls are at near lightening speed.

But when I ran my tests I was seeing no better performance than SPSiteDataQuery (all you haters saying CrossListQueryInfo.UseCache must be set to true, bite your tongue and keep reading). I assumed I was doing something wrong, so I cracked open the worlds best documents (the source code).

I used Reflector (one of the best dam tools ever developed) to look at the routine I was using, CrossListQueryCache.GetSiteData(SPWeb).  Well according to the code there is no caching going on, infact this routine is nothing more than a wrapper for SPSiteDataQuery.  So a little more checking and I discovered that something strange was afoot in the CrossListQueryCache library. 

There are 4 overloads for CrossListQueryCache.GetSiteData.  Two of the overloads cache the results and two do not.

CrossListQueryCache Routine	Uses Cache
GetSiteData (SPSite)	Yes
GetSiteData (SPWeb)	No
GetSiteData (SPSite, String)	Yes
GetSiteData (SPWeb, SPSiteDataQuery)	No

So unless you are using one of the overloads that supports caching (and have the CrossListQueryInfo.UseCache property set to true) you might as well use SPSiteDataQuery. 

There is one other gotcha with the overloads that support cache.  Your query cannot contain "<UserId/>" tag.  If it does then cache is not used.

Next the delight...

When you use the GetSiteData routines that support caching you see major performance improvements.  In fact my testing showed that the performance of CrossListQueryCache was as good as the Content By Query Control (not surprising since they are both caching their results).

Code Snippet

CrossListQueryInfo clqi = new CrossListQueryInfo();
clqi.Query = "<OrderBy><FieldRef Ascending=\"FALSE\" Name=\"Title\" /></OrderBy><Where><BeginsWith><FieldRef Name=\"Title\" /><Value Type=\"Text\">Test</Value></BeginsWith></Where>";
clqi.ViewFields = "<FieldRef Name=\"Title\" /><FieldRef Name=\"ContentType\" />";
clqi.Lists = "<Lists BaseType=\"1\" />";
clqi.Webs = "<Webs Scope=\"SiteCollection\" />";
clqi.UseCache = true;

CrossListQueryCache clqc = new CrossListQueryCache(clqi);
DataTable tbl = clqc.GetSiteData(SPContext.Current.Web);

 

The code above (which does not use caching since it passes in the Web) averaged 0.0500 seconds.

That same code slightly modified (see below) averaged 0.0008 seconds. 

Code Snippet

CrossListQueryInfo clqi = new CrossListQueryInfo();
clqi.Query = "<OrderBy><FieldRef Ascending=\"FALSE\" Name=\"Title\" /></OrderBy><Where><BeginsWith><FieldRef Name=\"Title\" /><Value Type=\"Text\">Test</Value></BeginsWith></Where>";
clqi.ViewFields = "<FieldRef Name=\"Title\" /><FieldRef Name=\"ContentType\" />";
clqi.Lists = "<Lists BaseType=\"1\" />";
clqi.Webs = "<Webs Scope=\"SiteCollection\" />";
clqi.UseCache = true;

CrossListQueryCache clqc = new CrossListQueryCache(clqi);
DataTable tbl = clqc.GetSiteData(SPContext.Current.Site, CrossListQueryCache.ContextUrl());

 

Slightly Different Results

As I said the performance is great, but one thing really bothered me. The DataTable results did not match.  Everything about the code is identical (same query, same CrossListQueryInfo configuration), but different results. 

I discovered that the routines that actually use cache contain some extra code that does a check to see if the item is checked-in.  If it is then it shows it, if not then it does not.  While the code that does not use cache returns all items that match the query (even those that are not checked-in).

I was worried that the routines were not using the same technique to query across the site lists, so I did some digging with Reflector.  What I found is that they both use the SPWeb.GetSiteData to execute the query.  The routines that cache the results do a little extra work to trim the results.  Just take a look at CachedArea.GetCrossListQuery if you want to see what is happening.

Anyway the end result was that I found that if used correctly the CrossListQueryCache object operates with the same efficiency of the Content Query Control. It provides an out of the box way to have your GetSiteData results cached. I highly recommended it if you are using SharePoint 2007 and not WSS 3.

Technorati Tags: SharePoint,Performance,Development