Yuletide ULS

blog-diagnostics0In this season of giving why not consider adding ULS logging to your customizations for your SharePoint administrators. When troubleshooting a critical issue around the holidays nothing goes better with the old Eggnog and Jack Daniels than some good old fashion, the way your mama did it, diagnostic logging. In this post I will show you a pattern that I use which not only provides an easy way to add that logging to your SharePoint customizations, e.g.. one method call, but also allows the SharePoint Administrator, tat has to keep your code up and running, the ability to customize and manage the Tracing and Event levels from within Central Administrator just like any other logging component within SharePoint Server 2010.

Solution

The full solution is available for download at the end of this post.

For our scenario I am going to build ULS logging into a project named “Level Zero”. The project has several components including Pages, Web Parts, etc and we need to supply an easy to use interface for developers to write trace and event messages to. The entire solution here is only two classes. The first class is the LevelZeroService which derives from SharePoint’s SPDiagnosticsServiceBase class. When logging to the ULS Areas and Categories are used to segment entries between components and sub-components. This is an especially nice feature when using a tool such as ULS Viewer to filter through the logs. My implementation only exposes one Area however more could be added within the appropriately named method ProvideAreas where I return an IEnumerable set of SPDiagnosticsArea instances. For each area there is a set of one or more Categories which are of type SPDiagnosticsCategory. It’s the category were you supply a default Trace and Event level. These default levels are used when no custom logging levels have been configured within Central Administration (more on this later). I used Monitorable and Error as the default Trace and Event levels respectively because this is what the out of the box (OOTB) SharePoint categories use and I didn’t want to be different. When writing trace or event messages you must access the Area’s Categories collection by the category name. Since I did not want to expose an interface that relied on me to remember the various category names or how to case and spell them I created a Category enum which I use to reference the categories in a type safe way. Take note that whatever order the categories are added to the SPDiagnosticsArea is the order in which they are displayed to the administrator within the diagnostics logging page.

public sealed class LevelZeroService : SPDiagnosticsServiceBase 
{ 
  private const string AreaName = "Level Zero";

  public enum Category
  {
      Email,
      General,
      Modules,
      Pages,
      SiteManagement,
      WebParts,
      Workflow
  };
           

  public LevelZeroService() 
      : this("LevelZeroDiagnostics", SPFarm.Local)
  {
  }

  public LevelZeroService(string name, SPFarm farm)
      : base(name, farm)
  {
  }

  internal static LevelZeroService Local 
  { 
      get 
      {
          return SPDiagnosticsServiceBase.GetLocal<LevelZeroService>();
      } 
  } 
     
  protected override IEnumerable<SPDiagnosticsArea> ProvideAreas() 
  { 
      
      List<SPDiagnosticsCategory> categories = new List<SPDiagnosticsCategory>();

      foreach (string categoryName in Enum.GetNames(typeof(Category)))
      {
          uint categoryId = (uint)(int)Enum.Parse(typeof(Category), categoryName);

          categories.Add(new SPDiagnosticsCategory(   categoryName, 
                                                      TraceSeverity.Monitorable, 
                                                      EventSeverity.Error, 
                                                      0, 
                                                      categoryId));
      }

      yield return new SPDiagnosticsArea(AreaName, categories);
  }

  internal SPDiagnosticsCategory this[string categoryName]
  {
      get
      {
          return Areas[AreaName].Categories[categoryName];
      }
  }
}

 

With the service out of the way now I can create the static Diagnostics class which exposes a number of static methods such as Trace, WriteEvent, and WriteException. These public methods simply call into the internal interface on my service class. Below is the Trace method which as you can see gets a reference to the service and calls the WriteTrace method, or in the case of the the Events, calls WriteEvent. The Diagnostics class also has a WriteDebug method which I added as a failsafe for when I need to get logging quickly and just want to use DbgView.

public static void Trace(uint tagId, LevelZeroService.Category category, TraceSeverity severity, string message, params object[] data)
{
  LevelZeroService localService = null;

  try
  {
    localService = LevelZeroService.Local;
  }
  catch (Exception ex)
  {
    Debug.WriteLine(String.Format("ERROR: Failed to log Trace message: {0}", ex.Message));
  }
  
  if (localService != null)
  {
    localService.WriteTrace(tagId, localService[category.ToString()], severity, message, data);
  }

  WriteDebug(category, severity.ToString(), message, data);

}

Those astute developers will notice that I do a try/catch and just swallow any exception which may be thrown. I do this for a couple of reasons, first, the call to the Local property seems to be the only place where I could possibly through and exception in my testing so I needed to log something so as to help figure out why logging may not be occurring, and second I didn’t want to re-throw the exception because its likely that for whatever reason it is that I cannot get a reference to the service its not about to clear up anytime soon and throwing and error here may mean the developer calling this method might catch that exception and attempt to log it too, basically you end up with a Chicken/Egg issue if you don’t just swallow any exceptions here.

Its important to note that almost all customizations you write within SharePoint no matter the process they may run in can leverage the ULS logging mechanism, even console applications running on the server can write events. The exception to this is a custom SharePoint Search connector. This assembly will run within the SharePoint Search daemon process which does not write into the ULS so the failsafe WriteDebug method I mentioned previously will be needed when logging is required in this scenario.

Deployment

Once you download the solution you will find there are two projects, a SharePoint project which includes the source code we have discussed up to this point and a simple console application to test the functionality. Unlike most SharePoint projects this one does not have any Features defined. Its not really necessary since all we are really doing is placing our assembly in the GAC. Oh didn’t I mention that, yea the assembly needs to be strong named and installed into the GAC. So why didn’t I just create a class assembly project in Visual Studio 2010? Good question, for at least 2 reasons: 1) When a SharePoint solution is deployed within Central Administration its deployed across all servers in the farm auto-magically, 2) All of my customizations are going to take a dependency on this project and therefore I can add an activation dependency within my dependent SharePoint projects to ensure the diagnostic package is in place.

Once the solution has been added and deployed within SharePoint we now need to make a simple registry addition on each server within the farm (this does not include SQL Servers) to register our service with SharePoint. In the download I included a setup.cmd file which make the registry change which simply writes the class name and 4 part assembly name of our service into a location where SharePoint can locate it.  

reg Add "hklm\SOFTWARE\Microsoft\Shared Tools\Web Server Extensions\14.0\WSS\Services\[ServiceName]" /v AssemblyQualifiedName /d "[class name + 4 part assembly name]" /f

 

Once the registry change has been made on all servers its now time to run PSConfig to install the service.

PSCONFIG.EXE -cmd services –install


This command should be run this from just one serer in the farm (I like the machine hosting CA myself). It should be noted its always a best practice when you do anything with psconfig that you do this during non peak or off hours.

Now its time to navigate to Central Administration (CA) and take a look at the diagnostic logging. As you can see from the image below our new area and its child categories are nestled all snug in their beds right amongst SharePoint’s out of the box settings just waiting for our administrators to configure further.

blog-diagnostics1

The Test

With deployment complete its time to test the solution. Included in the download is a test project which is just a simple console application which when executed calls into the Diagnostics class’s public methods and logs several Trace and Event messages into the ULS log.

    class Program
    {
        static void Main(string[] args)
        {

            Diagnostics.Trace(  LevelZeroService.Category.General, 
                                TraceSeverity.Unexpected, 
                                "This was unexpected so I added logging");

            Diagnostics.Trace(  LevelZeroService.Category.General, 
                                TraceSeverity.Unexpected, 
                                "This was unexpected too, it happened at {0}", 
                                DateTime.Now);

            Diagnostics.WriteEvent( LevelZeroService.Category.Pages, 
                                    EventSeverity.ErrorCritical, 
                                    "Call the developer at home.");

            Diagnostics.WriteException( LevelZeroService.Category.WebParts, 
                                        new SPException("A better error message than we get most of the time..."));
            
        }
    }

 

So if everything has gone correct at this point we can open up our trusty notepad and point it to our ULS logs directory and see the impact we have made to our administrator’s lives with the small bit of code we have added. As you can see both the Trace and Event calls have made it into our ULS logs.

blog-diagnostics2

Using my favorite ULS looky tool ULSViewer I am able to filter on the events from my test tool. ULS Viewer has a thing against the name “Area” and instead calls it “Product” but it’s the same field so just do the substitution in your head

blog-diagnostics4

Since we also logged a couple of super critical Events these not only where written to the ULS but to the event log as well. So hopefully we have some monitoring happening at the event logs that we can hook up to our new fancy logging mechanism.

blog-diagnostics3

At this point you are ready to wrap up this functionality, put a nice bow on it, and include it in your projects. I am no St. Nick but trust me, your administrators will love you for providing such a wonder gift that keeps on giving.

Microsoft.SP.Diagnostics.zip (45 kb)

Post to Twitter Post to Facebook Post to LinkedIn Post to Delicious Post to Digg

11 thoughts on “Yuletide ULS

  1. Andy Burns

    Funny, I’ve been working on the same thing; our code looks very similar, which is reassuring.

    Regarding registering the service, though, I do things a little differently. I did see the various articles creating registry entries, but that isn’t really suitable for a SharePoint farm. What if I add a new Front-end server? How will that registry change be applied?

    Instead, I’ve been trying the following function; so far it seems to work. You might want to give this approach a try:

    /// <summary>
    /// Registers the class for logging.
    /// Run in a Feature Receiver at the farm level
    /// </summary>
    public static void Register()
    {
    MyLog diagnositicService = new MyLog(String.Empty, SPFarm.Local);
    diagnositicService.Update(true);
    }

    Reply
  2. Todd

    Thanks Andy. So you call Register() from a Farm Level Feature Receiver, however that only gets called once per farm not per server. So is tihs actually making the registry settings for you?

    Reply
  3. Andy Burns

    Hi Todd. Nope, no registry settings seem to be set. I’d read other blog posts that talked about using them, but I simply couldn’t believe that registry settings were part of a SharePoint WSP install!

    I found this blog which talked about just using Update() on the class:
    http://rbosman.blogspot.com/2010/09/sharepoint-2010-logging-to-uls.html

    I’ve also seen SPFarm.Current.Service.Add() being described:
    http://dbremes.wordpress.com/2010/09/02/using-sharepoint-2010s-logging-infrastructure-part-2/

    Not tried that, though.

    So far, it seems to work, though I’m unclear exactly as to why.

    Regarding Registry settings – after the categories are registered and in Central Admin, I still don’t see any new registry keys in Regedit. I am currently wondering if the above code actually end up ‘injecting’ the new categories and areas into the SPDiagnosticsServiceBase – but I’ve not checked that theory out yet. Looking at reflector, I think this might be what SPDiagnosticsServiceBase.UpdateShadowCategories() is doing (called from Update()) but I’m not sure.

    I’ll take a closer look and maybe blog about it over Christmas! Sorry, Yuletide!

    Reply
  4. Raj

    Hi Todd

    Thanks for the article. I followed most part of it except the service registration. Is there any reason why an entry has to be added in registry and the PSConfig command needs to be run? I have tried running the code without running the setup.cmd file and it did write to ULS log file. I could also see the categories in central admin, so a bit confused with this.

    Thanks

    Reply

Leave a Reply

Your email address will not be published. Required fields are marked *

You may use these HTML tags and attributes: <a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <q cite=""> <strike> <strong>