Sunday, November 21, 2010

Using the System.Diagnostics EventLog.WriteEntry

Disclaimer – I’m a part-time developer. Do not assume that any coding advice that you read here is “best practice”.

I’ve been working on a SharePoint timer job in SharePoint 2007. To make it easier to find out what is going on within the job, I want to write to a log. From my perspective, the best log to use is the Windows Application log. This is a location that server administrators are familiar with accessing and there are many monitoring products out there that can keep an eye on it for you.

The Microsoft Dot Net Framework includes a System.Diagnostics namespace to help you interact with the Windows Logs. Initially I thought it would be a straightforward job to just call the Eventlog.WriteEntry() method. That’s when I disappeared down the rabbit hole of MSDN articles and blog posts.

Here’s what I’ve discovered in my journey:

When writing to the event log you need to specify a Source. This identifies the process that generated the error. This column is shown in the Windows Application Log and it can be used for filtering. It may be possible to use pre-existing ones, but I wanted to use my own.

When you use the EventLog.WriteEntry() method with a Source that doesn’t already exist, Windows will try to create the source for you. Behind the scenes, that involves updating the registry at HKEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\Eventlog\Application (assuming you are writing to the Application log). The problem is that your code may not have permissions to update that location, which causes your code to throw an exception. Trust me, it can take a while to realise that your error handling code is the component that is causing the problems.

You’ll find a number of blog posts and forum responses out there about granting ASPNet accounts permissions to registry keys. I really don’t like including steps like that as part of a deployment, so I continued to look for another approach. As an aside, since my code is a timer job, it will be running under the credentials of the account configured for the OWSTimer service. Even when I granted this account permissions to the Application and Security registry keys AND ran the code using the SPSecurity.RunWithElevatedPrivileges, I still couldn’t get it to create the Event Log source for me.

If your read this KB article you might decide to create the source manually by adding a registry key under the KEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\Eventlog\Application key and giving it the same name as the Source parameter in your call to eventLog.WriteEntry(). This will stop your call to EventLog.WriteEntry() crashing, however – you’ll probably start seeing longwinded error messages in your eventlogs such as:

The description for Event ID 0 from source YourSourceName cannot be found. Either the component that raises this event is not installed on your local computer or the installation is corrupted. You can install or repair the component on the local computer.

If the event originated on another computer, the display information had to be saved with the event.

The following information was included with the event:

The actual text from you event will be appended. Not ideal, is it?

It turns out that event log messages are usually generated by passing an ID along with some parameters. This gets cross-referenced with a “message log file” and translated into the text seen in the event log. This makes translating errors into multiple languages easy. So what Windows is trying to tell us in the previous message is that it cannot find this message log file, which isn’t surprising, because I didn’t create one.

Now if I were a real developer, I’d probably go off and create a message log file, bundle it up and register it using all the proper ways and means. But I’m not. I just want to write a message to the Windows Event Logs.

So here’s the approach I worked out. I created a simple Dot Net console app. I included a reference to the System.Diagnostics namespace, and I added one line of code to the main() method -

EventLog.CreateEventSource("MySourceName", "Application");

I then run this application directly on the server (Windows 2008 Standard in this case) while I’m logged on as a local administrator. I checked the registry and confirmed that a new key had been added to the KEY_LOCAL_MACHINE\SYSTEM\CurrentControlSet\Services\Eventlog\Application location. This key includes a value that references EventLogMessages.dll

EventLog

This is a reference to one of those message log files I mentioned earlier. It basically contains a simple mapping rule that outputs whatever text you pass EventLog.WriteEntry(). I rebooted the server at this stage. This may not be necessary, perhaps I could have just restarted the timer job service. I’ll leave that as an exercise for the reader.

Once the machine came back online, my timer job started writing to the event log without all the extra “the description of the event not found”. Now if I’m working on a multi-server SharePoint farm, I’d run my little console app on each of the servers to ensure that they all get the registry settings. I could even get trickier and make the console app use a command line parameter for my Source name, but I don’t want to stretch my luck.

One of Microsoft’s support articles mentions using an EventLogInstaller class to register the source. That worked too, but I found the console app easier to create and easier to implement in a production environment. I’m not sure what the advantages are with the EventLogInstallter, perhaps it makes sense if you are creating more complicated setup applications.

Here’s a link to an MSDN magazine article that explained a lot of the process to me:

http://msdn.microsoft.com/en-us/magazine/cc163446.aspx#S3