Enterprise Library Logging

Logging is an essential function of an application to help debug issues that occur on a production system when you don’t have access to a debugger. It is also helpful to keep track of what’s happening as it runs during testing, as a confirmation that the events and actions you expect to happen are happening.

There are a number of popular logging utilities and for the most part each is about as good as any other. They are all very similar. I am partial to the Enterprise Library Logging Application Block which can be downloaded here.

The Enterprise Library Logging Application Block, like other logging frameworks, allow you to create log messages and send those messages to different targets of output. Multiple output targets may be configured. The most typical output targets include a console window, file, database, web services and email though any conceivable target could be configured. Use of the logging infrastructure includes 3 components. 1) configuring each logging component 2) calling the logging infrastructure and 3) listening for log messages and sending them to the output targets.

The implementation below starts off with a wrapper around the actual EntLib logger. The wrapper is intended to limit references to the EntLib assemblies to one project. Going this route would allow for the EntLib logger to be swapped out for another with minimal impact on the application.

I should note that access to most loggers is static. The wrapper implementation below uses the static calls but the object itself is intended to be registered in an IoC container and used as an instance. This way I can add an interface and have better control over the object lifetime and better manage multiple loggers. The application in which this logger is used manages long running background threads. Each thread could be thought of as a sub-application and thus gets its own logger to differentiate the log messages. Though when I say “own logger” it’s really separate instances of the wrapper making static calls to the underlying EntLib logger. This approach also makes testing easier as I can mock out the logger interface and just ignore all logging calls in the unit tests.

public class EntLibLogger : ILogger
{
    public string Name { get; set; }
        
    public void Log(string message)
    {
        Log(message, LogSeverity.Information);
    }

    public void Log(string message, LogSeverity logSeverity)
    {
        LogEntry log = new LogEntry
                           {
                               Message = message,
                               Priority = GetLogSeverity(logSeverity),
                               Title = Name
                           };
        log.Categories.Add(Name);
            
        Logger.Write(log);
    }

    public void Log(Exception exception)
    {
        Log(exception, LogSeverity.Error);
    }

    public void Log(Exception exception, LogSeverity logSeverity)
    {
        Log(string.Empty, exception, logSeverity);
    }

    public void Log(string message, Exception exception)
    {
        Log(message, exception, LogSeverity.Information);
    }

    public void Log(string message, Exception exception, LogSeverity logSeverity)
    {
        const string subjectFormat = "{0}\r\n\r\n{1}";
        LogEntry logEntry = new LogEntry
                                {
                                    Message = string.IsNullOrEmpty(message) ? FormatException(exception) : string.Format(subjectFormat, message, FormatException(exception)),
                                    Priority = GetLogSeverity(logSeverity),
                                    Title = Name
                                };

        logEntry.Categories.Add(Name);
            
        // Set the category to the name of this logger, hopefully we can use this to distinguish log messages.
        // Setting the category causes the message to not be picked up by the console or email listeners, not sure whats up.
        //logEntry.Categories.Add(Name);
        Logger.Write(logEntry);
    }

    private static int GetLogSeverity(LogSeverity severity)
    {
        switch(severity)
        {
            case LogSeverity.Information:
                return 10;
            case LogSeverity.Highlight:
                return 20;
            case LogSeverity.Warning:
                return 30;
            case LogSeverity.Error:
                return 40;
            case LogSeverity.Critical:
                return 50;
            default:
                return 10;
        }
    }

    private static string FormatException(Exception exception)
    {
        StringBuilder formattedException = new StringBuilder();
        formattedException.AppendLine(exception.Source);
        formattedException.AppendLine(exception.Message);
        formattedException.AppendLine(exception.StackTrace);
        formattedException.AppendLine();

        if (exception.InnerException != null)
        {
            formattedException.AppendLine(FormatException(exception.InnerException));
        }

        return formattedException.ToString();
    }
}

There are a number of utility/helper overrides of the Log method to ease logging the desired information at the certain levels. The Name property exists to track in the log output where log messages come from. The Name property is set when the log instance is created and each message that gets log has this Name included in it. The GetLogSeverity method maps EntLib logging priority levels, indicated as integers, and translates those numbers to an enum containing more descriptive levels of logging priority. The FormatException method translates the important information contained in an exception into something readable. The ILogger interface contains all of the public methods in this class.

[ConfigurationElementType(typeof(CustomTraceListenerData))]
public class ConsoleTraceListener : CustomTraceListener
{
    public ConsoleTraceListener()
    {
        Console.BufferHeight = 9999;
    }

    public override void TraceData(TraceEventCache eventCache, string source, TraceEventType eventType, int id, object data)
    {
        LogEntry log = data as LogEntry;
        if (log != null && Formatter != null)
        {
            ConsoleColor color = Console.ForegroundColor;
            SetConsoleColor(log);
            WriteLine(Formatter.Format(data as LogEntry));
            Console.ForegroundColor = color;
        }
        else if (data != null)
        {
            WriteLine(data.ToString());
        }
    }

    public override void Write(string message)
    {
        Console.Write(message);
    }

    public override void WriteLine(string message)
    {
        Console.WriteLine(message);
    }

    private static void SetConsoleColor(LogEntry entry)
    {
        if (entry.Priority <= 10)
        {
            Console.ForegroundColor = Settings.Default.InformationLogColor;
        }
        else if (entry.Priority <= 20)
        {
            Console.ForegroundColor = Settings.Default.HighlightLogColor;
        }
        else if (entry.Priority <= 30)
        {
            Console.ForegroundColor = Settings.Default.WarningLogColor;
        }
        else if (entry.Priority <= 40)
        {
            Console.ForegroundColor = Settings.Default.ErrorLogColor;
        }
        else if (entry.Priority <= 50)
        {
            Console.ForegroundColor = Settings.Default.CriticalLogColor;
        }
    }
}

The above class inherits from the CustomTraceListener and has an attribute ConfigurationElementType. The TraceData method is where the log messages get outputed. It is a good idea to make use of the Write and WriteLine overrides in case the underlying class calls them as well. The constructor sets the buffer of the Console window to be big in order to maintain a longer history of log messages. This is important when you start to see large numbers of log messages.

The final step to logging with EntLib is to configure each of the previous components to work together.

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
  <configSections>
    <section name="loggingConfiguration" type="Microsoft.Practices.EnterpriseLibrary.Logging.Configuration.LoggingSettings, Microsoft.Practices.EnterpriseLibrary.Logging, Version=4.1.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35" />
    <section name="dataConfiguration" type="Microsoft.Practices.EnterpriseLibrary.Data.Configuration.DatabaseSettings, Microsoft.Practices.EnterpriseLibrary.Data, Version=4.1.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35" />
  </configSections>
  <loggingConfiguration name="Logging Application Block" tracingEnabled="true"
    defaultCategory="General" logWarningsWhenNoCategoriesMatch="true">
    <listeners>
      <add formatter="ConsoleFormatter" initializeData="" delimiter="------------------------------------"
        listenerDataType="Microsoft.Practices.EnterpriseLibrary.Logging.Configuration.CustomTraceListenerData, Microsoft.Practices.EnterpriseLibrary.Logging, Version=4.1.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35"
        traceOutputOptions="None" filter="All" type="MyNamespace.ConsoleTraceListener, MyAssembly.Name, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null"
        name="ConsoleTraceListener" />
      <add source="Enterprise Library Logging" formatter="Text Formatter"
        log="Application" machineName="" listenerDataType="Microsoft.Practices.EnterpriseLibrary.Logging.Configuration.FormattedEventLogTraceListenerData, Microsoft.Practices.EnterpriseLibrary.Logging, Version=4.1.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35"
        traceOutputOptions="None" filter="All" type="Microsoft.Practices.EnterpriseLibrary.Logging.TraceListeners.FormattedEventLogTraceListener, Microsoft.Practices.EnterpriseLibrary.Logging, Version=4.1.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35"
        name="Formatted EventLog TraceListener" />
    </listeners>
    <formatters>
      <add template="Timestamp: {timestamp}
Message: {message}
Category: {category}
Priority: {priority}
EventId: {eventid}
Severity: {severity}
Title:{title}
Machine: {machine}
Application Domain: {appDomain}
Process Id: {processId}
Process Name: {processName}
Win32 Thread Id: {win32ThreadId}
Thread Name: {threadName}
Extended Properties: {dictionary({key} - {value}
)}"
        type="Microsoft.Practices.EnterpriseLibrary.Logging.Formatters.TextFormatter, Microsoft.Practices.EnterpriseLibrary.Logging, Version=4.1.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35"
        name="Text Formatter" />
      <add type="Microsoft.Practices.EnterpriseLibrary.Logging.Formatters.TextFormatter, Microsoft.Practices.EnterpriseLibrary.Logging, Version=4.1.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35"
           name="ConsoleFormatter"
           template="{category} {timestamp}:  {message}" />
    </formatters>
    <categorySources>
      <add switchValue="All" name="General">
        <listeners>
          <add name="ConsoleTraceListener" />
        </listeners>
      </add>
    </categorySources>
    <specialSources>
      <allEvents switchValue="All" name="All Events" />
      <notProcessed switchValue="All" name="Unprocessed Category" />
      <errors switchValue="All" name="Logging Errors &amp; Warnings">
        <listeners>
          <add name="Formatted EventLog TraceListener" />
        </listeners>
      </errors>
    </specialSources>
  </loggingConfiguration>
</configuration>

Configuring the logger is a tedious process but does provide a lot of flexibility in terms of formatting output and determining which loggers get which log messages. First, you need to setup the configuration sections of which there is one required for the EntLib logging application block called loggingConfiguration. In the loggingConfiguration section add a listener to point to the ConsoleTraceListener class created ealier. Also in the loggingConfiguration section create a formatter to determine how the output of the log messages in text will appear. After the formatters, create categorySources which determines which targets will receive log messages from each logger.

Once the configuration is completed you’re ready to start logging messages. There are a number of other log targets, mentioned earlier, that can be created to solve unique logging requirements. I’ll include a couple other log listeners below that can be used. The comments are removed for sake of brevity.

[ConfigurationElementType(typeof(CustomTraceListenerData))]
public class EmailTraceListener : CustomTraceListener
{
    private readonly EmailLogService emailService;

    public EmailTraceListener()
    {
        emailService = new EmailLogService();
    }
    public override void TraceData(TraceEventCache eventCache, string source, TraceEventType eventType, int id, object data)
    {
        LogEntry logEntry = data as LogEntry;
        if (logEntry != null && logEntry.Priority >= 50)
        {
            emailService.SendExceptionEmail(logEntry.Title, logEntry.Message);
        }
    }

    public override void Write(string message)
    {
    }

    public override void WriteLine(string message)
    {
    }
}
public class EmailLogService
{
    private readonly SmtpClient mailClient;

    public EmailLogService()
    {
        mailClient = new SmtpClient(Constants.EmailHost, 25);
    }
   
    public void SendExceptionEmail(string subject, string body)
    {
        MailMessage email = new MailMessage
                                {
                                    From = new MailAddress(Constants.DefaultDebugEmailAddress),
                                    Subject = string.IsNullOrEmpty(subject) ? "MAFramework Critical Error" : subject,
                                    Body = body
                                };

        email.To.Add(Settings.Default.DefaultDebugEmailAddresses);

        mailClient.Send(email);
    }
}

The EmailTraceListener sends an email for log messages of the highest priority which are reserved for serious system errors, usually in which the application is crashing or is being prevented from running normally. Note in the TraceData method the send email service is used only when log priority is greater than or equal to 50. Also note the Write and WriteLine methods do nothing.

[ConfigurationElementType(typeof(CustomTraceListenerData))]
public class PublishLogTraceListener : CustomTraceListener
{
    private readonly ILogNotifier logNotifier;

    public PublishLogTraceListener()
    {
        logNotifier = LogNotifierFactory.GetLogNotifier();
    }

    static PublishLogTraceListener()
    {
        Mapper.CreateMap<LogEntry, LogMessage>();
    }

    public override void TraceData(TraceEventCache eventCache, string source, TraceEventType eventType, int id, object data)
    {
        LogEntry logEntry = data as LogEntry;
        if (logEntry == null)
        {
            return;
        }

        logNotifier.FireMessageLogged(Mapper.Map<LogEntry, LogMessage>(logEntry));
    }

    public override void Write(string message)
    {
    }

    public override void WriteLine(string message)
    {
    }
}

The PublishLogTraceListener is used to broadcast log messages using WCF’s duplex services. I have created a Silverlight web app that listens for and displays these log messages essentially creating a Console window in the browser that allows for viewing application log messages without being logged onto the server to see the actual console window. Also since the Silverlight client is dealing with log message objects I can create a UI around sorting and filtering different messages to view only the most significant errors for the application function I’m interested in. A sample implementation of the of the PollingDuplexBinding can be found in an older post here. Note too that I’m using Automapper to map from the EntLib log object to a log object of my own. This is so the client can have access to the log object without needing a reference to EntLib.

Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s