Security Briefs

Improve Manageability through Event Logging

Keith Brown

Contents

The IT Pro Is a User Too
A Closer Look at the Event Log
Using the Event Log from the .NET Framework
Working with Message Files
Creating a Custom Log
Logging Events at Run Time
Conclusion

The three traditional pillars of computing security are confidentiality, integrity, and availability. Often when I speak of availability, I talk about obvious threats such as denial of service attacks, but there's more to it than that. An application that requires high availability must be resilient to abnormal situations. If something goes wrong, an administrator must be able to sort out a solution quickly. Applications designed with management in mind tend to be more highly available, partly because administrators are constantly made aware of the application's health. When something does go wrong, a manageable application will tell the administrator how to fix the problem instead of simply dumping out a stack trace that requires a developer to analyze.

You may have heard about the Dynamic Systems Initiative (DSI) led by Microsoft. This long-term vision would have us model applications using tools and languages such as the System Definition Model (SDM) and the Service Modeling Language (SML) to build more easily deployable and manageable applications. The Visual Studio® Team System Distributed System Designer, formerly code-named "Whitehorse" (msdn2.microsoft.com/ms181778.aspx), is a great example of where this initiative is going, but this is just an early glimpse. Developers need practical guidance they can use today to build manageable systems.

The IT Pro Is a User Too

I recently spent some time speaking with David Aiken, a Microsoft developer/evangelist whose passion is building manageable software. He said something that really hit home: "Developers should think of the IT professional as a user of their software." He pointed out how much painstaking effort we undertake when designing the layout of a Windows form or Web page, and posed the question, "Why we don't make the same effort when we're designing an error message to be posted to the event log?"

David has a good point. Not only is the IT professional a user of your software, she's the one who will be operating and managing it for its entire lifetime. Making her job easier is not only important from an availability standpoint, but having the system administrator as an ally will very likely help you sell the next version of your product. Applications that are designed for operations are few and far between today, and this is one area where you can seek a competitive edge.

Over the past several years, I've seen tremendous advances from Microsoft in terms of building more secure software, including tools and blueprints for building threat models. Now, with a tighter leash on security, the focus seems to be shifting towards manageability. With any luck, by the time this article is printed, you'll be hearing about health modeling tools from Microsoft.

In the meantime, I'm going to address some of the lowest-hanging fruit on the management tree: event logging. I'll focus on how you can do a better job of using the event log from the Microsoft® .NET Framework on Windows Server® 2003.

A Closer Look at the Event Log

The Windows® event log was designed with localization and efficiency in mind. For example, a well-designed event found in the Application log should contain just enough prose to explain a problem to the administrator and provide a suggested course of action. The vast majority of this prose should be localized for the reader, who may very well be on a remote machine in a different country. To support reading the log in your own native language, the localizable prose in the message is not actually stored in the log; rather, it is merged with the log locally as you read it. The actual prose is stored in a localized resource DLL on the reader's machine. This also has the effect of keeping the log files smaller and reducing the amount of network traffic required to read them.

Before the .NET Framework came along, this was all very clear to developers because you had to create and register these resource DLLs yourself. A typical message in a resource DLL might look like this: "Failed to connect to database %1 using connection string %2. Check to see that the database is available."

In this example, the only data about the event that would be stored in the event log would be the event ID, source, category, and a few other bits of metadata, along with the arguments supplied when the event was logged: the database name (%1) and the connection string (%2). When you use a tool such as Event Viewer to read an event like this, Windows will load the message resource DLL installed on your machine, look up the localized message based on the event ID, then merge the arguments from the log in order to display the message to you.

The way Windows figures out which resource DLL to use is by looking at the name of the event source in the log and mapping it to a registry key. This registry key contains the path to the resource DLL that should be used to display the message. Figure 1 shows an example of an event source registry key. In the early days, a Win32® programmer would create this key manually, but when the .NET Framework came along, it included an EventLog class to hide details like this.

Figure 1 Event Source Registration

Figure 1** Event Source Registration **(Click the image for a larger view)

Using the Event Log from the .NET Framework

In version 1.x of the .NET Framework, the EventLog class provided very rudimentary access to the event log. The strategy seemed to be to simplify access to the event log to perhaps convince people to actually use it. At install time, when your code is running with high privilege, you can create an event source with a single line of code:

EventLog.CreateEventSource("MyApp",
    "Application")

Then at run time, when your code is running with lower privilege, you can log events without ever having to create a resource DLL:

EventLog.WriteEntry("MyApp", "Testing 123")

It's important to note that there are two steps involved here. Remember that when you create an event source, you're actually creating a registry key. This is a privileged operation, and if you neglect this step, EventLog.WriteEntry will attempt to do it for you. While this may work when you're running a demo as an administrator, it's not going to work in production code when you're running under a normal user account. So be sure to create your event sources during installation when you have permissions to do so!

Normally, if you were to write a message to the event log without having a corresponding resource DLL, you'd get a rather nasty note in the event log, complaining that no description for the event could be found (see Figure 2). The Framework has a unique way of getting around this. The simple call to CreateEventSource wires your event source up with a default message file. This file is called EventLogMessages.dll, and it contains 65,536 event descriptions, each of which consists of the string "%1", a placeholder for whatever string you want to write. While this may have encouraged a few more people to use the event log, it defeated the purpose of having message files in the first place: to allow localized viewing of messages in the reader's language, and to keep the size of the event logs in check.

Figure 2 An Event with No Message File

Figure 2** An Event with No Message File **(Click the image for a larger view)

Fortunately, version 2.0 of the .NET Framework remedies this and allows you to gain the full power of the event log by registering a message file when you create your event source. This lets you support localized categories and messages, and it reduces the size of your messages in the log.

Here's the modern way to register an event source using the .NET Framework 2.0:

EventSourceCreationData source =
    new EventSourceCreationData("MyApp", "Application");
source.CategoryCount = 2;
source.CategoryResourceFile  = "path to dll";
source.MessageResourceFile   = "path to dll";
source.ParameterResourceFile = "path to dll";

EventLog.CreateEventSource(source);

Note that while technically you are allowed to have three resource DLLs, most applications roll all three resource types-categories, messages, and parameters-into a single DLL.

Working with Message Files

In order to create a resource DLL for the event log, you'll need to start by creating one or more message files. I'll keep things simple by using a single message file, which is a text file that traditionally carries a .mc file extension. You use a tool called mc.exe, the message compiler, to process these files.

The message compiler keeps track of several variables that you can set at any time in your message file. MessageId is one variable that you'll want to update for each message, while you might set the Severity variable once for an entire section of your message file. If you don't explicitly set a MessageId, the assigned MessageId will be one greater than the previous one. Variable definitions are separated by white space (including line break):

    MessageId=1001 SymbolicName=AppStarted
    Severity=Informational

Message prose itself must be started on a new line and can cover as many lines as you need. It is terminated by a new line with a period, as shown below:

MessageId=1003 SymbolicName=DatabaseConnectionFailed 
Language=English
Could not connect to SQL Server database %1. Reason: %2
.
Language=Spanish
No podía conectar con SQL Server database %1. Razón: %2
.

Here I've defined a single message with two localized bits of prose. Before I can compile this message file, I need to define the languages I'm using. So at the top of the message file, I've added a header section with language definitions:

LanguageNames=(English=0x409:MSG00409)
LanguageNames=(Spanish=0xC0A:MSG00C0A)

This defines the symbolic name I'll be using to represent each language along with its locale ID. Since the message compiler produces a separate output file for each language, I've supplied the name it should use for each file. Here's what I get when I run the message compiler from the command line:

$ mc messages.mc
MC: Compiling messages.mc
$ dir
12/16/2006  05:18 AM             1,970 messages.h
12/16/2006  05:13 AM             1,199 Messages.mc
12/16/2006  05:18 AM                74 messages.rc
12/16/2006  05:18 AM               356 MSG00409.bin
12/16/2006  05:18 AM               352 MSG00C0A.bin

As you can see, the message compiler produces a .bin file for each language along with a resource file (messages.rc) that refers to the .bin files. The messages.rc file looks like this:

LANGUAGE 0xa,0x3
1 11 MSG00C0A.bin
LANGUAGE 0x9,0x1
1 11 MSG00409.bin

You can now build a resource DLL with two more steps: running the resource compiler to create a .res file, then using the linker to link that file into a DLL:

$ rc messages.rc
$ link /DLL /SUBSYSTEM:WINDOWS /NOENTRY /MACHINE:x86 messages.res
Microsoft (R) Incremental Linker Version 8.00.50727.42
Copyright (C) Microsoft Corporation.  All rights reserved.

At this point you should have a file called messages.dll that you can use when you create your event source.

There's a lot of nitty-gritty detail you can learn about message files by looking up mc.exe in the MSDN documentation, but there are a few items of particular interest that I'll point out.

First, you should include the localized names of your event categories in your message file. These look like normal messages, except that they are short names and must use consecutive MessageIds that start with the number 1. When you create your event source, you should specify the CategoryCount as the highest category message number. Here are the two category definitions in my sample application (you will likely have more interesting and varied categories for your own application):

;// Categories
MessageId=1 SymbolicName=Administrative
Language=English
Administrative
.
Language=Spanish
Administrativo
.

MessageId=2 SymbolicName=Operational
Language=English
Operational
.
Language=Spanish
Operacional
.

Keep in mind that the message compiler was originally written for use by C programmers writing native Win32 applications. Did you notice the messages.h file that was produced? This file contains a set of constants that C/C++ programmers can use to refer to categories and messages. This is the reason for the SymbolicName variable you see in all of my message and category definitions. You may also have noticed the strange-looking comment above my category list:

;// Categories

Technically, the message compiler only needs the semicolon to delimit a comment, but traditionally you'll see a C style comment following that. The reason for this is because the compiler emits all of these comments into the messages.h file as well.

So what good is the SymbolicName variable to a programmer who uses .NET if it is only used to create a C header file? Frankly, it's not much use as things stand today, but imagine writing a parser that would take a message file as input and produce a class definition in your managed language of choice.

There are many other variables that are typically defined in the header of the message file, but I'm relying on the default definitions. Here are the default message severities that you'll get, and you can use these values in your message definitions:

SeverityNames=(Success=0
               Informational=1
               Warning=2
               Error=3
              )

One other thing about message files that may be confusing at first is the concept of parameters. There are two types of parameters. The most common type are those that you fill with data collected at run time: %1, %2, and so on. The other type is simply a way of factoring out common strings from your message files. For example, early in development, you might not want to hardcode the name of your application in lots of individual messages, so you can factor that name out as a parameter, then use a special syntax, %%N where N is the MessageId of the replacement string from the parameter resource DLL.

Creating a Custom Log

If there's one thing an IT pro really hates, it's an application that makes a lot of noise in the application event log, drowning out the really important messages that well-behaved applications produce from time to time. You shouldn't be writing operational, analytical, or trace/debug messages to the application log! These are more appropriate for a custom application log, and you can easily create one of these in your application's installer by specifying the name of the custom log you wish to create (the code below creates a new log called MyApp) if it doesn't already exist. Note that you'll need a distinct event source name for each log file you create:

EventSourceCreationData source =
    new EventSourceCreationData("MyApp Operational", "MyApp");
source.CategoryCount = 2;
source.CategoryResourceFile  = "path to dll";
source.MessageResourceFile   = "path to dll";
source.ParameterResourceFile = "path to dll";

EventLog.CreateEventSource(source);

Logging Events at Run Time

Just as you may be accustomed to creating a data layer for your application, complete with strongly typed arguments that simplify database access, you should consider creating classes to help you log events. In my sample application, I've created two classes for event logging. The first is for administrative events that will be written to the Application log, and the second is for operational events that will be written to my application's custom log. These classes each expose a method per event, with strongly typed parameters representing the data that each event needs for its parameters. For example, here is the code for an event that records a failure to connect to a database in my custom operational log:

public void DatabaseConnectionFailed(
    string dbName, string connectionString) {
    operationalLog.WriteEvent(
        new EventInstance(1003, 2, EventLogEntryType.Error),
        dbName, connectionString, new StackTrace(1));
}

The WriteEvent method is new for the .NET Framework 2.0. This method allows you to pass arguments that will fill in the parameters in your message file such as %1. Figure 3 shows an example of this event in the log.

Note that this particular method provides a lot of detail, including the database name, the connection string, and a stack trace. That is why this message is destined for my custom operational log. I also send a simpler, more actionable message to the Application log.

Figure 3 A Parameterized Event

Figure 3** A Parameterized Event **(Click the image for a larger view)

Conclusion

Applications that are designed for operations are carefully instrumented using technologies such as the event log. By treating the IT pro as a first-class user of your application, you're helping to ensure smooth operation and less downtime. By creating your own custom event log and sequestering your noisier events there, you make room in the Application log for the actionable events that quickly explain to the IT pro how to restore your application to health.

A lot about the existing eventing system, including the .mc message file format, is a bit arcane. Fortunately, there is a completely redesigned eventing system built into Windows Vista™ that will also be part of the upcoming Windows Server code-named "Longhorn." While many of the basic concepts stay the same, there are a lot of cool new features that will allow you to log richer events in a more granular way. Plus, the new files that replace message files contain significantly more metadata for events and are stored as XML, which will make parsing much easier. I'll be covering the new system in an upcoming column, so stay tuned!

Send your questions or comments for Keith to  briefs@microsoft.com.

Keith Brown is a co-founder of Pluralsight, a premier Microsoft .NET training provider. Keith is the author of Pluralsight's Applied .NET Security course, as well as several books, including The .NET Developer's Guide to Windows Security, which is available both in print and on the web.