With SharePoint 2010, Microsoft gave us a better framework for logging that SharePoint 2007, which relied on writing most of your own. Sadly, though, the SPDiagnosticsServiceBase does lack in a couple of areas. Consequently, I’ve ended up writing my own Diagnostics service to try and address those issues. I am far from the only one (See the references below), but I’d like to present what I’ve written, not least ‘cos I’ve been meaning to blog about it for about 8 months.

First, though, let’s look at the limitations of the SPDiagnosticsServiceBase.

The first limitation is that although you can log with a call to SPDiagnosticsService.Local.WriteTrace(), you kind of run into an immediate problem – what’s the bloody SPDiagnosticsCategory that you want to use?

Well, like most people, I guess I tried creating a new SPDiagnosticsCategory object, and handing that into the function. Sadly, though, the logs come through empty, as Jurgen Baurle mentions.

The problem is that the logging categories are used to control the levels of logging you set in the Central Administration > Monitoring pages. In fact, there are two bits to this – a diagnostics service offers a number of SPDiagnosticsAreas, and those areas have a number of SPDiagnosticsCategories.

Worse, compared to 2007, at least, is that you can no longer ‘register’ and ‘unregister’ diagnostics categories from this central administration section. Essentially, your categories are build in – they’re either there … or they aren’t. This is an annoyance, as it means that I can’t write a single Logging class and use it in all my projects. Instead, you have to create an entire diagnostics service, based on the SPDiagnosticsServiceBase class.

Whatever solution I produced, I wanted it to be easy to modify and reuse for other projects that might demand a different diagnostics area or classes. You might notice, I used the singular – “area” there. That was deliberate. I figure, if I need more that one area, it should be simple to provide another entire diagnostics service.

Now, quite a lot of people have produced examples (see below), with discussion of their code, so I won’t go into that so much. What I’ve not seem much of, though, it the use of an enumeration for the call to the logging class. Often, people seem to pass strings to define the logging category. What if it’s invalid? What if there is a typo? Basically, I hate magic strings, so I used an enumeration to define my logging categories for my service:

public enum MyLoggerCategory
 {
 TimerJob = 1,
 FeatureReceiver = 10,
 EventHandler = 20,
 Webpart = 30,
 General = 40
 }

And the method that returns my Diagnostics Area and Categories uses this enumeration to define the categories:

protected override IEnumerable<SPDiagnosticsArea> ProvideAreas()
 {
 List<SPDiagnosticsArea> areas = new List<SPDiagnosticsArea>();
 List<SPDiagnosticsCategory> categories = new List<SPDiagnosticsCategory>();

 foreach (string catName in Enum.GetNames(typeof(MyLoggerCategory)))
 {
 uint catId = (uint)(int)Enum.Parse(typeof(MyLoggerCategory), catName);
 categories.Add(new SPDiagnosticsCategory(catName, TraceSeverity.Medium, EventSeverity.Error, 0, catId));
 }

areas.Add(new SPDiagnosticsArea(DiagnosticsAreaName, 0, 0, false, categories));
 return areas;
 }

Cool.

The next quirk was that there are two methods one might want to use for logging. There is WriteTrace(), which writes to the trace logs, and WriteEvent(), which writes to the Windows event log, and the trace log. Yup, if you used both, you can end up writing to the ULS logs twice. I also don’t want to have to think about making two calls. I just want one call – “Make a record of this” – and have SharePoint sort out where it is written to.

A third point in this aspect of my design was that I don’t like making method calls with parameters to define the importance. Maybe it’s my Java heritage from a long time ago, but I prefer calls like Logger.Warning() to record a message at a ‘Warning’ level of importance. It’s simpler, and easier to read.

Thus, I decided my service would have calls like Error(), Warning(), High() and Medium(). These would call an internal private method, specifying the appropriate EventSeverity and TraceSeverity settings. Methods like Error() would call my internal method with a TraceSeverity of ‘None’, and the call to WriteEvent() will also, as mentioned, write to the tracelogs anyway. Lower importance calls, like Medium() wouldn’t write to the Windows Event Log, so they have an EventSeverity of ‘none’, but an appropriate Traceseverity, so we log things correctly.

Great – but there is another problem. Writing to the Windows Event Log relies on there being an Event Source to write to. If there isn’t, WriteEvent() will try to create it. However, in some configuartion of SharePoint, the account making the logging call won’t have the privileges needed to create this Event Source.

The Event Source itself is really just a key in the Registry of the, so one could try to make sure that a highly privileged account is used to create it. However, you’ve then got the question – which server? Answer – all of them. Fun and games.

Jurgen Baurle’s example shows how, when the Feature for registering the diagnostics service is run, he also tries to create the Registry key for each server in the farm. Kudos, that’s quite neat, but I’m still not sure I like it. What if someone adds a new server? Well, it wouldn’t get that key – and you’re back to square one.

Alternatively, one could use a Timer Job configured to run on each server in the farm. That’s a pretty good approach – but heavyweight. A Timer Service, that’s going to run from time to time forever, just to set that registry key IF a new server is added? (Chris Keyser’s job runs once – but then you’ve got the same problem of adding new servers again).

So, for my little logger, I took the easy option. If there is a problem writing to the Windows Event log, make a note of it in the Trace log, and then output the original message to the Trace log too. It ain’t pretty, but it is simple.

And my final little bonus – I like to know the class and method that output my messages to my logs. It’s useful for debugging. So, the private method WriteLog uses reflection to walk back up the StackFrame to the method that called it, and then uses reflection to get the class and method information, and those get put into the message too. It’s much simpler than, as I’ve seen done (heck, done myself), passing the method name as a parameter to each logging call.

And there you have it. You’ve now got something that you can make a call like:

MyLogger.Error( MyLoggerCategory.General, "My Message" );

… and the rest is dealt with.

You can download MyLogger.cs here. And to register or unregister it, you’ll need a Feature Receiver, something like MyLoggerFeatureReceiver.cs.

References:

• Debugging and Logging Capabilities in SharePoint 2010 on MSDN
• How To Implement A Custom SharePoint 2010 Logging Service For ULS And Windows Event Log by Jurgen Baurle
• Tips for ULS Logging Part 1 & Part 2 by Steve Peschka
• YuleTide ULS by Todd Carter
• Logging to ULS in SharePoint 2010 by Waldek Mastykarz
• Using a SharePoint Timer Job to deploy settings in a farm for registering event sources by Chris Keyser
• Using a Timer Job to ensure diagnostic areas of SPGuidance by Patrick Boom