The Problem...
For a (personal) project I'm currently working on, I decided to use the Logging and Instrumentation application block from the Enterprise Library to handle logging. The problem I ran into was that I wanted my log destination to be an XML file. Why is that a problem? Well, there's a couple of reasons: 1) The logging application block doesn't provide an option for an XML file as one of the default trace listener options, and 2) working with large sets of XML, such as one that might be generated as a log file, can lead to some performance problems fairly quickly, which is certainly not something you want for such a common operation as logging. Loading up an XML document just to do an AppendChild() on the root node to add a log entry would become an extremely slow operation after about a week's worth of use at the most. So, I had to try to figure out a way to just append an XML node to an existing document without actually loading up the entire document. Here's what I ended up doing...
The Solution...
Configuring the Logging Application Block
Run the Enterprise Library Configuration tool, and open your application's app.config file, and add a new Logging Application Block.
The new logging application block adds a default event log trace listener and text formatter. You can do what you want with those, I didn't need them, so I deleted them.
The next step is to add our XML file trace listener and formatter. So add a new Flat File Trace Listener, and Text Formatter. I called mine Xml TraceListener and Xml Formatter respectively.
Next, we need to edit the template of our new Xml Formatter. To do this, highlight the Xml Formatter node, and highlight the Template property on the right, then click the elipsis button on the far right to open up the Template Editor window. For each piece of information that you wish to record in your log entry, wrap the value in XML tags in the editor, as shown below. Optionally, you can add a {tab} token before each node, so that the children of the log entry node will be indented for easier reading.
Once the formatter template is setup, we need to set the properties of the Xml TraceListener. The first thing we should do is set the Formatter property to our Xml Formatter (select it from the dropdown list of available formatters). Then we need to set the Header and Footer properties such that they wrap the log entry in XML tags to encapsulate the log entry as a proper XML node in the document. I set the Header to <LogEntry> and the Footer to </LogEntry>. Set the Filename property to whatever makes the most sense to you, I set mine to XmlLogFile.log.
Finally, we need to add Trace Listener references to each of our Category Sources and Special Sources. For each Category Source and Special Source that you have, right-click on it, and select New Trace Listener Reference, and then select the Xml TraceListener in the list of available Trace Listeners for the ReferencedTraceListener property.
Once that's done, the configuration is complete. Seems like a lot to do, but once you've done it, you'll realize its really not that big of a deal. Pretty simple. Now that you've finished configuring the application block, click the Save icon on the toolbar to validate and save the changes you've made to your app.config file.
Writing Log Entries
In order to simplify the process of writing log entries to my log file, I just created a single file I call Logging.cs, and wrap everything in it in a namespace I called MyApp.Logging. Within that namespace, I created all of the classes that I needed as static classes, and all of the methods within them as static methods. Having done this, anywhere in my application that I want to be able to write log entries to my log file, I just import that namespace, and I have access to all of my logging functionality. For example, I've created structs with string and integer constants for my Priorities, my EventIDs, Categories, etc. I've also created static methods for writing different types of log entries, such as LogError, LogInformation, LogWarning, etc. LogError accepts a .NET Exception object as an argument and allows me to include the full call stack in the ExtendedProperties of the LogEntry to assist in debugging errors. NOTE: This has the potential of introducing a security risk into your application, so use that functionality at your own risk, or remove it if that is an issue for you. Here's what my Logging.cs file looks like, to give you an idea.
using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Text;
using Microsoft.Practices.EnterpriseLibrary.Logging;
namespace MyApp.Logging
{
/// <summary>
/// Contains methods for adding LogEntries to the log file
/// </summary>
public static class Log
{
/// <summary>
/// Adds an informational LogEntry with the given properties to the log file
/// </summary>
/// <param name="message">The message to write in the log entry</param>
/// <param name="priority">The Priority of the log entry</param>
/// <param name="severity">The Severity of the log entry</param>
/// <param name="category">The Category of the log entry</param>
/// <param name="eventID">The EventID for the log entry</param>
public static void AddInformation( string message, int priority, TraceEventType severity, string category, int eventID )
{
LogEntry le = new LogEntry();
le.Message = message;
le.Priority = priority;
le.Severity = severity;
le.Categories.Add( category );
le.EventId = eventID;
Logger.Write( le );
}
/// <summary>
/// Adds an error LogEntry with the given properties to the log file
/// </summary>
/// <param name="message">The message to write to the log entry</param>
/// <param name="priority">The Priority of the log entry</param>
/// <param name="severity">The Severity of the log entry</param>
/// <param name="category">The Category of the log entry</param>
/// <param name="eventID">The EventID of the log entry</param>
/// <param name="ex">The exception information to add to the log entry</param>
public static void AddError( string message, int priority, TraceEventType severity, string category, int eventID, Exception ex )
{
LogEntry le = new LogEntry();
le.Message = message;
le.Priority = priority;
le.Severity = severity;
le.Categories.Add( category );
le.EventId = eventID;
le.ExtendedProperties.Add( "ErrorStack", ex.ToString() );
Logger.Write( le );
}
}
/// <summary>
/// Struct containing integer constants used to identify the Priority level for log messages
/// </summary>
public struct Priority
{
/// <summary>
/// Low Priority
/// </summary>
public const int Low = 1;
/// <summary>
/// Medium Priority
/// </summary>
public const int Medium = 2;
/// <summary>
/// High Priority
/// </summary>
public const int High = 3;
/// <summary>
/// Urgent Priority
/// </summary>
public const int Urgent = 4;
}
/// <summary>
/// Struct containing string constants used to identify Categories for log messages
/// </summary>
public struct Category
{
/// <summary>
/// Used for Informational log messages
/// </summary>
public const string Information = "Information";
/// <summary>
/// Used for Warning messages, informing the user of a potentially negative conditions or events
/// </summary>
public const string Warning = "Warning";
/// <summary>
/// Used for Error messages, informing the user of Error conditions of events
/// </summary>
public const string Error = "Error";
}
/// <summary>
/// Struct containing integer constants used to identify events for log messages
/// </summary>
public struct EventID
{
/// <summary>
/// Identifies the service starting event
/// </summary>
public const int ServiceStart = 1;
/// <summary>
/// Identifies the service stopping event
/// </summary>
public const int ServiceStop = 2;
/// <summary>
/// Identifies the Blah event
/// </summary>
public const int Blah = 3;
/// <summary>
/// Identifies the configuration update event
/// </summary>
public const int ConfigurationUpdate = 4;
/// <summary>
/// Identifies AnotherBlah event
/// </summary>
public const int AnotherBlah = 5;
}
}
So, with a reference to the MyApp.Logging namespace, writing an entry to our log file in XML format becomes as simple as this:
Log.AddError( "Error performing operation", Priority.High, TraceEventType.Error, Category.Error, EventID.MyOperation, ex );
The Result
So, once you start writing log entries, the resulting XmlLogFile.log ends up looking something like this:
<LogEntry>
<Timestamp>9/14/2006 2:19:15 AM</Timestamp>
<Message>Operation completed successfully</Message>
<Category>Information</Category>
<Priority>1</Priority>
<EventID>3</EventID>
<Severity>Information</Severity>
<Title></Title>
<MachineName>MyMachineName</MachineName>
<AppDomain>MyApp.Service.vshost.exe</AppDomain>
<ProcessID>3100</ProcessID>
<ProcessName>C:\MyDirectory\MyApp.Service.vshost.exe</ProcessName>
<Win32ThreadID>4092</Win32ThreadID>
<ThreadName></ThreadName>
<ExtendedProperties></ExtendedProperties>
</LogEntry>
<LogEntry>
<Timestamp>9/14/2006 2:21:47 AM</Timestamp>
<Message>Error performing operation</Message>
<Category>Error</Category>
<Priority>3</Priority>
<EventID>3</EventID>
<Severity>Error</Severity>
<Title></Title>
<MachineName>MyMachineName</MachineName>
<AppDomain>MyApp.Service.vshost.exe</AppDomain>
<ProcessID>3844</ProcessID>
<ProcessName>C:\MyDirectory\MyApp.Service.vshost.exe</ProcessName>
<Win32ThreadID>3944</Win32ThreadID>
<ThreadName></ThreadName>
<ExtendedProperties>
ErrorStack - System.InvalidOperationException: Cross-thread operation not valid: Control 'Toast' accessed from a thread other than the thread it was created on.
at System.Windows.Forms.Control.get_Handle()
at System.Windows.Forms.Control.get_InternalHandle()
at System.Windows.Forms.Control.get_CreateParams()
at System.Windows.Forms.Label.get_CreateParams()
at System.Windows.Forms.Control.UpdateBounds(Int32 x, Int32 y, Int32 width, Int32 height)
at System.Windows.Forms.Control.SetBoundsCore(Int32 x, Int32 y, Int32 width, Int32 height, BoundsSpecified specified)
at System.Windows.Forms.Label.SetBoundsCore(Int32 x, Int32 y, Int32 width, Int32 height, BoundsSpecified specified)
at System.Windows.Forms.Control.SetBounds(Int32 x, Int32 y, Int32 width, Int32 height, BoundsSpecified specified)
at System.Windows.Forms.Control.set_Size(Size value)
at System.Windows.Forms.Label.AdjustSize()
at System.Windows.Forms.Label.OnTextChanged(EventArgs e)
at System.Windows.Forms.Control.set_Text(String value)
at System.Windows.Forms.Label.set_Text(String value)
at BackBurner.Service.BackupServiceController.SetServiceMessageText(String message) in C:\MyDirectory\MyApp.Service\MyAppServiceController.cs:line 189
at MyApp.Service.MyAppServiceController.MyOperation(Object sender, MyEventArgs e) in C:\MyDirectory\MyApp.Service\MyAppServiceController.cs:line 175
at MyApp.Service.MyOtherOperation(Blah archive, String folder) in C:\MyDirectory\MyApp.Service\MyClass.cs:line 194
at MyApp.Service.YetAnotherOperation(AnotherBlah archive, String folder) in C:\MyDirectory\MyApp.Service\AnotherClass.cs:line 159
at MyApp.Service.WowAnotherOperation(BlahBlahBlah archive, String folder) in C:\MyDirectory\MyApp.Service\AnotherClass.cs:line 163
at MyApp.Service.WowAnotherOperation(BlahBlahBlah archive, String folder) in C:\MyDirectory\MyApp.Service\AnotherClass.cs:line:line 163
at MyApp.Service.WowAnotherOperation(BlahBlahBlah archive, String folder) in C:\MyDirectory\MyApp.Service\AnotherClass.cs:line:line 163
at MyApp.Service.WowAnotherOperation(BlahBlahBlah archive, String folder) in C:\MyDirectory\MyApp.Service\AnotherClass.cs:line:line 163
at MyApp.Service.WowAnotherOperation(BlahBlahBlah archive, String folder) in C:\MyDirectory\MyApp.Service\AnotherClass.cs:line:line 163
at MyApp.Service.WowAnotherOperation(BlahBlahBlah archive, String folder) in C:\MyDirectory\MyApp.Service\AnotherClass.cs:line:line 127
</ExtendedProperties>
</LogEntry>
More problems
Anybody notice the problem here? This is not a well-formed XML document. We can't really do anything useful with this can we? Most XML parsers out there will only work with well-formed XML, and until we have that, this is pretty much useless to us. We need to somehow wrap it all up in a root node, and maybe even an XML document declaration too (not completely necessary for well-formed XML, but nice-to-have for clarity nonetheless).
Getting around the problem
In searching for a way to deal with this issue, I found a great article in the MSDN Developer Center by Dare Obasanjo on efficient techniques for modifying large XML files, and specifically uses log files as an example for using this technique. In the article, he offers two different techniques. The one I chose to use involves the use of XML external entities to "include" a fragment of XML inside a well-formed XML document. See the article for more specifics if you're interested, but for now, I'll just discuss the implementation that I used that has worked very well for me so far.
In my solution, recall that the log file I specified in the Logging application block configuration is called XmlLogFile.log. The contents of this file is the XML fragment that will be included in the actual XML document that ultimately ends up being the well-formed XML document that is our XML log file. This file, I'll call it LogFile.xml, is very simple, and includes nothing more than the following code:
<?xml version="1.0" encoding="utf-8" ?>
<?xml-stylesheet type="text/xsl" href="MyLogTransform.xslt"?>
<!DOCTYPE MyLog [ <!ENTITY LogEntries SYSTEM "XmlLogFile.log"> ]>
<MyLog>
&LogEntries;
</MyLog>
When this document is actually parsed by an XML parser (or perhaps even XSLT), it will include all of the LogEntry nodes that were written to the XmlLogFile.log file, as if they were actually part of the that physical document. This technique has worked very well for me so far, without any problems at all. I get all the benefits of structure and flexibility of XML as a log source, and the performance capabilities of appending data to a flat file. Nice.
Viewing the log file
Obviously, since we're using XML, we can view/display our log entries just about any possible way we wish. But I thought I'd provide a quick sample of the method I used for displaying the contents of my log file to users.
The application I'm using this technique on is a Windows Service, and it uses a Windows form as the UI for it's configuration. So, I decided to display my log file to users using XSLT to transform the XML into HTML with some embedded JavaScript and CSS to display the results in a Web Browser control on the configuration screen. Noitice in the above code sample how I specified the XSLT file used for transformation of the log file. Here's my XSLT file:
<?xml version="1.0" encoding="UTF-8" ?>
<xsl:stylesheet version="1.0" xmlns:xsl="http://www.w3.org/1999/XSL/Transform">
<xsl:template match="/">
<html>
<head>
<Title>My Log File</Title>
<script language="JavaScript" type="text/javascript">
// Shows/Hides the element with the given ID
function ShowHide(panelID)
{
var panel = document.getElementById(panelID);
if (panel != null)
{
if (panel.style.visibility == "hidden")
{
panel.style.display = "block";
panel.style.visibility = "visible";
}
else
{
panel.style.display = "none";
panel.style.visibility = "hidden";
}
}
}
</script>
<style>
body
{
font-family: Tahoma, Arial, Verdana, Helvetica, Sans-Serif;
font-size: 8pt;
color: #000;
margin: 0px 6px;
padding: 0px;
cursor: default;
}
.LineItem
{
cursor: pointer;
}
.LineItem:hover
{
color: #339;
}
.EntryDetails
{
margin: 3px 20px 10px 20px;
}
.EntryDetailsLabel
{
color: #777;
}
.ErrorStackHeader
{
cursor: pointer;
}
.ErrorStack
{
font-family: Lucida Console;
font-size: 8pt;
color: #f00;
margin: 5px -9px 5px 20px;
}
</style>
</head>
<body>
<xsl:for-each select="MyLog/LogEntry">
<xsl:sort select="Timestamp" order="descending" />
<div class="LineItem" onclick="ShowHide('{generate-id(Message)}')"><span class="EntryDetailsLabel"><xsl:value-of select="Timestamp"/>: </span><xsl:value-of select="Message" /></div>
<div class="EntryDetails" style="visibility: hidden; display: none;" id="{generate-id(Message)}">
<div><span class="EntryDetailsLabel">Category: </span><xsl:value-of select="Category" /></div>
<div><span class="EntryDetailsLabel">Priority: </span>
<xsl:choose>
<xsl:when test="Priority = 1">Low</xsl:when>
<xsl:when test="Priority = 2">Medium</xsl:when>
<xsl:when test="Priority = 3">High</xsl:when>
<xsl:when test="Priority = 4">Urgent</xsl:when>
</xsl:choose></div>
<div><span class="EntryDetailsLabel">Event: </span>
<xsl:choose>
<xsl:when test="EventID = 1">Service Start</xsl:when>
<xsl:when test="EventID = 2">Service Stop</xsl:when>
<xsl:when test="EventID = 3">My Operation</xsl:when>
<xsl:when test="EventID = 4">Configuration Update</xsl:when>
</xsl:choose></div>
<div><span class="EntryDetailsLabel">Severity: </span><xsl:value-of select="Severity" /></div>
<div><span class="EntryDetailsLabel">Machine name: </span><xsl:value-of select="MachineName" /></div>
<div><span class="EntryDetailsLabel">AppDomain: </span><xsl:value-of select="AppDomain" /></div>
<div><span class="EntryDetailsLabel">Process ID: </span><xsl:value-of select="ProcessID" /></div>
<div><span class="EntryDetailsLabel">Process name: </span><xsl:value-of select="ProcessName" /></div>
<div><span class="EntryDetailsLabel">Win32 Thread ID: </span><xsl:value-of select="Win32ThreadID" /></div>
<xsl:if test="ExtendedProperties != ''">
<div class="ErrorStackHeader" onclick="ShowHide('{generate-id(Message)}-ErrorStack')">Error Stack (click to show):</div>
<div class="ErrorStack" style="visibility: hidden; display: none;" id="{generate-id(Message)}-ErrorStack"><xsl:value-of select="ExtendedProperties" /></div>
</xsl:if>
</div>
</xsl:for-each>
</body>
</html>
</xsl:template>
</xsl:stylesheet>
And here's a few screenshots of the UI displaying the log entries:
Conclusion
I know what you're thinking...FINALLY!! Please forgive me for my lack of brevity. I tend to be a bit long-winded at times. However, this has proven to be a pretty successful method for generating and viewing flexible log files for me. Hopefully it can be of use to someone else as well. As always, feedback, thoughts or ideas for improvement are always welcome.
Cross-posted from my personal weblog at Bob.Yexley.Net.
Posted
10-06-2006 10:59 AM
by
Bob Yexley