Get Logging with the Enterprise Library

• LoggingBlockInvestigator demo project - 9.92 Kb

Note: You will need to follow the steps in Setting Up Your Development Environment before the project will build.

Contents

• Introduction
• Background
• The Basics
• Linking the Basics Together
• Setting Up Your Development Environment
• Instrumenting an Application
• Where to go from Here
• Conclusion

Introduction

Note: This article is a major re-working of my earlier Getting started with the Logging Application Block article. Whereas that article used Microsoft's Enterprise Instrumentation Framework and the stand-alone Logging Application Block, this article deals with the Logging and Instrumentation Application Block supplied as part of the Enterprise Library.

Have you ever encountered a system where the logging is a twisted pile of spaghetti? One where it seems to save trace messages to five different files? Or it requires seven different flags in the registry to control its output?

All too often, logging is added to a system in an ad-hoc, as the need arises, manner. When this approach is applied to a large system, with many sub-systems and layers, it can lead to numerous “home grown” logging mechanisms being implemented; each implementation having its own configuration peculiarities and probably logging in different ways (e.g., one subsystem to the Windows Event Log, one to a file in the root directory, one to a database etc.). This article will introduce you to the Logging and Instrumentation Application Block (a part of the Microsoft / Avanade Enterprise Library) and show how it could bring some consistency to an application’s logging.

This article is for those who have never encountered the Logging and Instrumentation Application Block, those who are looking to evaluate it, and those who have looked at it and thought it seemed like too much trouble. I will provide an overview of what features the Logging and Instrumentation Application Block provides, followed by a description of how to get the basics working in your environment.

The article will not explore too deeply the additional features the new Logging Application and Instrumentation Block provides over the Microsoft Enterprise Instrumentation Framework (EIF) and the original stand-alone Logging Application Block. Nor will it explore the other application blocks provided with the Enterprise Library.

Background

Many applications, and especially large-scale systems, could benefit from a consistent approach to logging. To help, there are a number of logging libraries available to the .NET developer, such as Log4Net and NSpring. In April 2003, Microsoft released the EIF. As part of Microsoft’s Patterns & Practices initiative, the EIF was extended by the original, stand-alone, Logging Application Block.

In January 2005, a new set of application blocks were released together as the Enterprise Library. This library combines many of the preceding stand-alone application blocks (and some new ones) providing a consistent, integrated suite of “best practice” software. The Logging and Instrumentation Application Block is part of that library.

The Logging and Instrumentation Application Block provides a simple way for your code to log information in a consistent manner across your managed application. Powerful configuration files allow the filtering, routing and formatting of those “Log Entries” to be determined at run time (rather than at compile time). Log Entries can be generated as discrete events or as part of a traced process.

Some of the major improvements over the original stand-alone Logging Application Block are:

• Automated installation and compilation of the library on the developer's machine;
• The configuration file can be edited through a simple user interface (the Enterprise Library Configuration Console);
• No dependency on the EIF;
• The format of the data saved to a sink can be configured through the Enterprise Library Configuration Console rather than by providing XSLT files;
• The Database Sink is no longer SQL Server specific;
• New sinks such as the Email Sink and Flat File Sink.

When I first looked at the original Logging Application Block, I nearly dismissed it as too much effort. I’m glad I persisted. Due to its automated setup and simplified configuration, the Logging and Instrumentation Application Block is far simpler to start working with and use in a real life project.

The Basics

The Logging and Instrumentation Application Block makes use of four basic concepts to provide a logging framework: Log Entries, Tracers, Sinks and Formatters.

Log Entries

A LogEntry is the object that you “write” when your application needs to log some information. For instance, adding the following to your application would write a Log Entry containing the message “Hello World”:

   Logger.Write("Hello World");

It is as simple as that. OK, you do have to put in some using statements and your project must reference the Enterprise Library... but the code can be as basic as that!

The above code implicitly creates a LogEntry object with its Message field set to “Hello World”. Overrides of the Logger.Write method allow you to provide more information, such as:

• Category - used to determine the routing of the LogEntry;
• Priority - used to filter Log Entries, only those above the “Minimum Priority” are processed (defaults to -1 which indicates that the Minimum Priority should be used);
• EventId - a value you can use to further categorise Log Entries (defaults to 0 for a LogEntry and to 1 for a LogEntry implicitly created by Logger.Write);
• Severity - indicates the severity of the Log Entry, e.g., Information, Warning, Error etc.
• Title - a summary of the LogEntry.Message.

Another overload takes a LogEntry object, allowing you to set all these fields explicitly. A LogEntry also has a number of additional fields that are automatically populated with details of the system's state at the time it was instantiated (e.g., machine name, timestamp, application domain name, process ID etc.).

Additional, context specific information can be added to a LogEntry through its ExtendedProperties field. This takes a reference to an IDictionary object containing any additional name / value pairs you want to log. Included with the Logging and Instrumentation Application Block are a number of “Extra Information Providers”. These can be used to populate an IDictionary object with some basic information. For example, the ComPlusInformationProvider will populate an IDictionary object with details of the current COM+ context.

Tracers

Whereas a LogEntry allows you to log a discrete event, a Tracer object can be used to indicate that a LogEntry is being written as part of a particular process (or execution path through the application). For instance, you might use it to indicate that a LogEntry has been written as part of a “Create New Customer” process:

   using (new Tracer("Create New Customer"))
   {
      Logger.Write("Hello World again");
   }

When a Tracer is instantiated, you can either supply an activityId (as the second parameter to the constructor) or allow a GUID to be generated for you. A “Start Trace” Log Entry will then be written containing this Activity ID. When the Tracer object is disposed of, an “End Trace” Log Entry containing the elapsed time is written. The using statement in the above code ensures the Tracer object is disposed of correctly.

All Log Entries written between the using statement’s opening and closing brackets will automatically have a TracerActivityId entry added to their ExtendedProperties (populated with the Tracer object's Activity ID). This includes Log Entries written from other methods, classes, or even assemblies.

Tracer objects can be nested. Unless explicitly supplied with an activityId, an inner Tracer object will have the same Activity ID as its parent. Any Log Entries will be written with their TracerActivityId extended property set to the inner most Tracer object's Activity ID. In the following code, the first LogEntry is written with a TracerActivityId set to “Outer”, the second with the value set to “Inner”:

   using (new Tracer("Outer most trace", "Outer"))
   {
      using (new Tracer("A nested trace"))
      {
         Logger.Write("Hello World inside");
      }
      
      using (new Tracer("Another nested trace", "Inner"))
      {
         Logger.Write("Hello World inside again");
      }
   }

A number of static methods on the Tracer class allow you to discover information about the current and outermost (or “Root”) Tracer objects.

Log Sinks

When a LogEntry is “written”, the Logging and Instrumentation Application Block routes it to one or more Log Sinks. A Log Sink receives Log Entries and is responsible for persisting them. The Logging and Instrumentation Application Block provides six Log Sinks:

• Event Log – writes to a Windows Event Log;
• Flat File – writes to a text file;
• Microsoft Message Queuing – writes to a message queue;
• E-mail – sends Log Entries via an SMTP server;
• Database – executes a stored procedure for each LogEntry;
• WMI Log – fires WMI events.

You can always write your own Custom Log Sink as well.

Formatters

To persist a LogEntry, the Log Sink uses a Formatter to convert the Log Entry's information into a string. The Logging and Instrumentation Application Block provides a single formatter, the TextFormatter.

The TextFormatter is initialised with a template that dictates which properties of the LogEntry are added to the output string. For instance, a template like this:

   The message {message} was logged at {timestamp}

would result in an entry in the Log Sink such as:

   The message Hello World was logged at 08/02/2005 18:08:56

This templated approach means Log Entries can be made user friendly and allows sensitive information to be hidden. The template is read from the configuration files, so can easily be changed.

Linking the Basics Together

Hopefully, the section above gives you an insight into the features provided by the Logging and Instrumentation Application Block. What that section doesn’t describe is how LogEntry, Tracer, LogSink and Formatter objects are made to interact with each other. That “plumbing” is provided by the Logging and Instrumentation Application Block based on settings in your configuration files.

There are two more concepts to understand: Categories and Destinations. These are not defined at compile time, but at run time, when the Logging and Instrumentation Application Block reads the configuration files. Therefore, if you need to change how a LogEntry is distributed, you can simply change a configuration file. It is this flexibility that makes the Logging and Instrumentation Application Block so powerful.

Categories

Log Entries can be grouped together into Categories. Each Category can be independently configured to route and format Log Entries in a particular way. Categories can also be used to filter Log Entries, allowing certain Categories to be ignored.

A LogEntry is assigned to a particular Category by either providing the Category name to the Logger.Write method or by explicitly setting its Category property:

   Logger.Write("Hello World once more", "My Category");

   LogEntry logEntry = new LogEntry();
   logEntry.Category = "My Other Category";
   logEntry.Message  = "Hello World once more again";
   Logger.Write(logEntry);

When a Tracer object is constructed, it writes a “Start Trace” LogEntry. When it is disposed of, it writes an “End Trace” LogEntry. The easiest way to assign these Log Entries to a Category is via the Tracer's constructor:

   using (new Tracer("My Trace Category"))
   {
      Logger.Write("Hello World another time");
   }

If a LogEntry is not explicitly assigned to a Category, or the configuration files don't contain a definition for its Category, it is assigned to the “Default Category”. The name of the Default Category is set in the configuration files.

Destinations

A Destination is used to determine to which Log Sink a LogEntry is routed. It also configures the Formatter that the Log Sink will use to transform the information held in the LogEntry.

Like Categories, Destinations are defined in your application's configuration files. For each Category, you can specify zero or more Destinations. This means all the Log Entries in a particular Category can be sent to no Log Sinks, one Log Sink or simultaneously to several Log Sinks.

Setting Up Your Development Environment

First off, your system must at least meet the following requirements:

• Windows 2000, Windows Server 2003 or Windows XP;
• .NET Framework 1.1;
• Visual Studio .NET 2003 Enterprise Architect, Enterprise Developer or .NET Professional edition.

Here are the steps I followed to create a development environment:

• Download the Enterprise Library from here (N.B.: this currently requires registration);
• Run the install, ensuring you tick the “Compile Enterprise Library” check box. The installation will copy the source files to your machine and compile everything for you. If the installation appears to freeze on the "Removing backup files..." stage, be patient, it will be starting up the build process;
• Manually install the performance counters - on the Start menu, you should find Program Files > Microsoft patterns & practices > Enterprise Library > Install Services.

All in all, this is a far simpler setup than the previous, stand-alone, Logging Application Block!

Instrumenting an Application

Perhaps the best way to get to grips with the Logging and Instrumentation Application Block is to try it. The download for this article contains the code for a sample Windows Forms application (LoggingBlockInvestigator.exe) that should allow you to experiment. You may need to delete and re-add its reference to the various Microsoft.Practices.EnterpriseLibrary assemblies.

Writing Log Entries

The LoggingBlockInvestigator.exe application writes two Log Entries in the Main method, one on start up and one on shutdown:

LogEntry logEntry    = new LogEntry();
logEntry.Message    = "Starting up the application";
Logger.Write(logEntry);

Application.Run(new MainForm());

Logger.Write("Shutting down the application");

This code shows two techniques for writing Log Entries with the Default Category. The first technique explicitly creates a LogEntry object and initializes it with a message. The second, more compact technique creates the LogEntry implicitly.

If you build and run the LoggingBlockInvestigator.exe application, then close it down, you will find two new entries in your Windows Event Log, in the Application section. If you look at the details, you will see a list of each of the Log Entries' properties.

Specifying a Category

By default, all Log Entries are marked with the Default Category. For instance, the Windows Event Log details for the two Log Entries created above indicate their Category is “General.” The code in the sample application for the “Log From My Category” button handler uses an explicit Category instead:

private void LogFromMyCategory_Click(object sender, System.EventArgs e)
{
   Logger.Write("Written using My Category", "My Category");
}

Run the sample application and press the “Log From My Category” button, then look in the Windows Event Log. Under the System Log, you will find an entry with a source of "Logging Investigator". Looking at the details will show that the Category is set to "My Category". This Category has a second Destination configured which specifies that Log Entries are also written to a flat file C:\Trace.Log. If you open that file, you will find it contains the same Log Entry except formatted differently, as the second Destination is set to use a different Formatter.

The code above uses a LogEntry. The code behind the “Log With Tracer” button uses two nested Tracer objects:

private void LogWithTracer_Click(object sender, System.EventArgs e)
{
   using (new Tracer("My Trace Category", "My Outer Trace"))
   {
      Logger.Write("My first entry");

      using (new Tracer("My Trace Category", "My Nested Trace"))
      {
         Logger.Write("My second entry [Root = " + Tracer.RootActivityId + "]");
      }
   }
}

If you press the “Log With Tracer” button, the following Log Entries are saved into the Application area of the Windows Event Log:

• Starting up the application;
• Start Trace: Activity 'My Outer Trace' - the outer most trace has started;
• My first entry - if you look at its details, you will see this Log Entry has an extended property “TracerActivityId” set to “My Outer Trace”;
• Start Trace: Activity 'My Nested Trace' - the inner most trace has started;
• My second entry [Root = My Outer Trace] - has an extended property “TracerActivityId” set to “My Nested Trace”;
• End Trace: Activity 'My Nested Trace' - the inner most trace has ended;
• End Trace: Activity 'My Outer Trace' - the outer most trace has ended;
• Shutting down the application.

Specifying a Priority

When a LogEntry is written, it can be given a priority. If not specified, this defaults to the currently configured Minimum Priority. In the case of the “Start Trace” and “End Trace” Log Entries created by a Tracer, the priority is hard coded to 5.

If you press the Log At Priority 10 button, the following code is executed:

private void LogAtPriority10_Click(object sender, System.EventArgs e)
{
   Logger.Write("Written at priority 2",  "General", 2);
   Logger.Write("Written at priority 10", "General", 10);
}

This code actually tries to write two Log Entries. However, if you look in the Windows Event Log, you will find the first one has been filtered out. This is because the configuration files for the LoggingBlockInvestigator.exe application set a Minimum Priority of 5.

Creating a Custom Log Sink

As well as using the provided Log Sinks, you can create your own. For instance, you may wish to send Log Entries by SMS or some proprietary protocol. CustomLogSink.cs in the sample application shows how simple this is. The class is derived from Microsoft.Practices.EnterpriseLibrary.Logging.Sinks.LogSink and overrides the Initialize and SendMessageCore methods. As well as writing a Log Event, the example shows how to read the configuration information for the Log Sink. If you put a break point in the SendMessageCore method, then press the “Log To My Sink” button, your break point should be hit.

Note: The help supplied with the Enterprise library contains a “Walkthrough: Creating a Custom Sink” section. As of 9 February 2005, this is incorrect.

Adding Context Specific Information

You can add additional information to a LogEntry and have it persisted to a Log Sink. The example shows how to add information directly and how to use one of the IExtraInformationProvider objects:

private void LogWithContextInformation_Click(object sender, System.EventArgs e)
{
   IDictionary contextInfo = new Hashtable();

   contextInfo.Add("Additional Info", "Some information I wanted logged");

   DebugInformationProvider provider = new DebugInformationProvider();
   provider.PopulateDictionary(contextInfo);

   LogEntry logEntry           = new LogEntry();
   logEntry.Message            = "Logged with context specific information";
   logEntry.ExtendedProperties = contextInfo;

   Logger.Write(logEntry);
}

If you press the “Log With Context Information” button, a new entry is added to the Windows Event Log. If you look in its details, you will see the Extended Properties contain both the “Additional Info” property and a “Stack Trace” property.

Configuration

The last few sections have introduced the code that you can add to your application to start logging through the Logging and Instrumentation Application Block. There is one more very important task... configuration. Without configuration, your Log Entries will never reach a Log Sink!

One of the major enhancements that comes with the Enterprise Library is the Enterprise Library Configuration Console. This can be found on your Start menu under Program Files > Microsoft patterns & practices > Enterprise Library.

With the console, you can use a fairly user friendly GUI to edit the various configuration files. To open the configuration files for the LoggingBlockInvestigator.exe application:

• Start the Enterprise Library Configuration Console;
• Select File > Open Application;
• Navigate to the LoggingBlockInvestigator project directory;
• Open the App.Config file;

This should populate the console as below:

In the tree control on the left hand side, you will see all the configuration settings required to get the LoggingBlockInvestigator.exe application working correctly. Here is a quick run down of the highlights (click on each node to see its properties):

• Client Settings:
  • CategoryFilterSettings allows you to specify which Categories are to be published and which are to be ignored;
  • MinimumPriority sets the filter level, setting this to 2 will mean the Log Entry filtered out above will be logged;
  • TracingEnabled turns on or off the “Start Trace” and “End Trace” Log Entries (N.B.: if you create a new set of configuration data from scratch, this is turned off by default).
• Distributor Settings:
  • DefaultCategory allows you to specify the Category to be used if a Log Entry is written without one being explicitly set;
  • DefaultFormatter sets the formatter to be used for Destinations that don't have a Formatter explicitly set.
• Categories - lists the Categories that have been configured for the application. A new Category can be added using the Action menu or by right clicking on the Categories node. Under each Category is one or more Destinations;
• Event Log Destination:
  • Formatter: the Formatter to be used by the Log Sink when persisting a LogEntry;
  • Sink: the Log Sink to which Log Entries will be sent.
• Formatters - lists the Formatters that have been configured for the application. A new Formatter can be added using the Action menu or by right clicking on the Formatters node;
• Text Formatter - the Template property allows you to define the text that will be persisted for each Log Entry that is processed by this Formatter;
• Sinks - lists the Sinks that have been configured for the application. A new Log Sink can be added using the Action menu or by right clicking on the Sinks node;
• Custom Sink:
  • Attributes: a list of name value pairs that can be used to pass configuration data to a Custom Log Sink (the CustomLogSink.cs file gives an example of reading this data);
  • TypeName: the type of the Custom Log Sink (see Note 1).
• Event Log Sink:
  • EventLogName: name of the Event Log to write to (normally Application, System or one you create yourself);
  • EventSourceName: the name used to populate the source field of the Event Log (see Note 2).
• Flat File Sink - allows you to specify the file to be written to and the separators used between each Log Entry.

Note 1: The console allows you to search for a Custom Log Sink type by loading an assembly. However, it appears that it doesn't use a separate AppDomain to do this, therefore, once your assembly is loaded, it is never unloaded until the console is shut down. This prevents you searching for a type in an assembly, adding a new type to that assembly, and then looking for this new type. Obscure I know, but it caught me out!

Note 2: Once an EventSourceName has been used to write to a particular EventLogName, it cannot be used to write to another without first being removed from the original EventSourceName. If you try, an error is logged.

Adding Logging To Your Application

In order to start using the Logging and Instrumentation Application Block in your own application, there are a few simple steps to follow:

Create the configuration files

In the Enterprise Library Configuration Console, do the following:

• Select File > New Application;
• Highlight the new application and select Action > New > Logging and Instrumentation Application Block;
• Highlight the new application, then select File > Save Application;
• Navigate to your project's directory;
• Select the App.Config file (or Web.config file for a web application) and press Save;

Your project directory will now contain two new files: loggingConfiguration.config and loggingDistributorConfiguration.config. These should be put under source control.

Note: Tracing is disabled by default. To enable tracing, highlight Client Settings and change TracingEnabled to true and save.

Set your project to copy the new configuration files

Add the loggingConfiguration.config and loggingDistributorConfiguration.config files to your project. For a Windows application, you can ensure these files are always copied to your project's output directory, by adding the following to its “Post-build Event Command Line” (to do this, edit your project's settings and navigate to Common Properties > Build Events):

copy "$(ProjectDir)loggingConfiguration.config" "$(TargetDir)"
copy "$(ProjectDir)loggingDistributorConfiguration.config" "$(TargetDir)"

Add a reference to the Logging and Instrumentation Application Block

In Visual Studio, highlight your project and select Project > Add Reference. On the .NET tab, use “Browse...” to locate the Microsoft.Practices.EnterpriseLibrary.Logging.dll.

Where to go from Here

By no means have I covered all the features of the Logging and Instrumentation Application Block. So there is plenty more for you to find for yourself. A good place to start is from GotDotNet. By participating in this workspace, you could influence the future direction of the block. You may also find patches, news about future updates, and contributions from other developers... you might even contribute yourself!

Conclusion

Hopefully, this article provides a good introduction to the benefits and features of the Logging and Instrumentation Application Block. If implemented consistently throughout a system, it should provide a robust and powerful tool for both debugging and monitoring. The information given in this article should allow you to start incorporating the block into your code.

At the very least, I hope the article has highlighted the benefits of thinking about logging early in a project, and choosing a consistent approach (whether that is with Log4Net, NSpring, the EIF, the Logging and Instrumentation Application Block, System.Diagnostics.Trace, or a home grown framework).

Revision History

25 Feb 2005:

• The copying of .config files in a post build step is not necessary for an ASP.NET application.

28 Sep 2005:

• Updated the URL of the link to the GotDotNet site.