YapBee

Integrating log4net with Enterprise Library Exception Handling Application Block

info.nospam@nospam.yapbee.com (Hakkı Yılmaz) — Mon, 09 Mar 2009 00:21:52 +0000

Most people may prefer Entlib Logging because Exception Handling Application Block (EHAP) which is another cool Entlib part serve integration with Logging as an inbox solution and another thing Entlib Logging has the ability of consuming WCF traces with a proxy trace listener.

But if you don’t want to use Entlib Logging because of some performance issues and prefer using log4net or another tool there is a chance here provided. In this post I will show you how to integrate EHAP with log4net. Directing WCF traces to log4net is beyond this post I will provide it in the next posts.

Now let’s start. EHAP providing us an interface IExceptionHandler and implementing this interface and declaring it in the configuration file you have your own way of handing exceptions. And Entlib configuration system needs this class decorated with ConfigurationElementType attribute like below.

[ConfigurationElementType(typeof(CustomHandlerData))]

This decoration lets Entlib configuration system pass parameters defined in configuration file to your class constructor as a NameValueCollection. IExceptionHandler interface has a single method HandleException that give you the chance to handle exception. At the end of the method you either return same exception or another one you provided.

Here is my implementation.

using System;

using System.Collections.Generic;

using System.Linq;

using System.Text;

using Microsoft.Practices.EnterpriseLibrary.Common.Configuration;

using Microsoft.Practices.EnterpriseLibrary.ExceptionHandling.Configuration;

using Microsoft.Practices.EnterpriseLibrary.ExceptionHandling;

using System.Collections.Specialized;

using log4net;

using log4net.Core;

namespace YapBee.Samples.log4netExceptionHandler

    [ConfigurationElementType(typeof(CustomHandlerData))]

    public class log4netExceptionHandler : IExceptionHandler

        private static readonly ILog log = LogManager.GetLogger(

            System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);

        public log4netExceptionHandler(NameValueCollection configurationData)

            string categories = configurationData["logCategories"];

            if (string.IsNullOrEmpty(categories))

                m_categories = new string[] { "General" };

            else

                m_categories = categories.Split(',');

            string levelString = configurationData["Level"];

            level = log.Logger.Repository.LevelMap[levelString];

        public Exception HandleException(Exception exception, Guid handlingInstanceId)

            if (log.Logger.IsEnabledFor(level))

                LoggingEvent loggingEvent = new LoggingEvent(ThisDeclaringType,

                    log.Logger.Repository, log.Logger.Name, level, exception.Message, exception);

                loggingEvent.Properties["Categories"] = m_categories;

                log.Logger.Log(loggingEvent);

            return exception;

        private string[] m_categories;

        private Level level;

        private readonly static Type ThisDeclaringType = typeof(log4netExceptionHandler);

And here is the configuration

<exceptionHandling>

    <exceptionPolicies>

      <add name="WCF Exception Shielding">

        <exceptionTypes>

          <add type="YapBee.Samples.WCFService1.MyInternalSampleException, YapBee.Samples.WCFService1"

            postHandlingAction="ThrowNewException" name="MyInternalSampleException">

            <exceptionHandlers>

              <add logCategories="BusinessFault,UnauthorizedUserOperation" Level="Warn"

                type="YapBee.Samples.log4netExceptionHandler.log4netExceptionHandler,

                YapBee.Samples.log4netExceptionHandler" name="Custom Handler" />

              <add exceptionMessage="" faultContractType="YapBee.Samples.WCFService1.ServiceFault,

                   YapBee.Samples.WCFService1"

                  type="Microsoft.Practices.EnterpriseLibrary.ExceptionHandling.WCF.FaultContractExceptionHandler,

                  Microsoft.Practices.EnterpriseLibrary.ExceptionHandling.WCF,

                  Version=4.0.0.0, Culture=neutral, PublicKeyToken=null"

                  name="DefaultFaultContract Handler">

                <mappings>

                  <add source="{Guid}" name="Id" />

                  <add source="{Message}" name="MessageText" />

                </mappings>

              </add>

            </exceptionHandlers>

          </add>

....

In my sample code I make use of WCF Exception Shielding Policy come with the EHAP so there is a section with the name. This means whenever an exception thrown in service its handled by EHAP. And from the configuration part you can see there is declared an Exception which is a custom exception provided by me and there is two handlers for the exception type one is our log4netExceptionHandler and the other FaultContractExceptionHandler which is come with EHAP. These two handler handles exception consequently.

As you can see from the exceptionHandlers section in xml there is a logCategories parameter and a Level parameter. The other name and type parameters are needed by configuration system in order to initiate handler class. logCategories and Level parameters are passed to constructor of custom handler class. And the constructor logic stores the values to the private fields in order to use in HandleException method later. Lastly in the HandleException method simply initiate a LoggingEvent and call Logger to log it.

You can download sample code from here.

In zip two console applications provided one is wcf service with hosting app the other is client simply calling GetIPAddress and ThrowException methods. When ThrowException method called in wcf app debugger hangs it is not a bug don’t panic, simply press F5 to proceed. You will see exception string on client console and exception log on wcf service console.

Users of log4net know that log4net doesn’t let you categorize logs like Entlib Logging. In discussions around on Entlib Logging or log4net which to prefer I see some says there isn’t categorization available in log4net unlike Entlib Logging and this is a significant functionality they want to see in a logging tool I notice. This is quite true but log4net’s categorization is provided with Levels and Named Loggers. I think there must be a fair requirement for this so I extended log4net for categorization support.

I will provide categorized log4net in my next post.

Getting started with log4net

info.nospam@nospam.yapbee.com (Hakkı Yılmaz) — Tue, 24 Feb 2009 21:19:00 +0000

This post is a startup for using log4net in your application and briefly mentions on features, building blocks and extension points of log4net.

For whom doesn’t hear log4net before, log4net is an open source project used by .net community for logging and is a port of log4j that is developed for Java World and can be downloaded hereunder Apache License.

Starting up with log4net is really simple process with provided samples come with the package. Let’s start step by step :

After downloading log4net package and unzipping it open a project in Visual Studio and add reference to log4net.dll.
Add an Application Configuration File and copy paste the xml below.
Go to application’s starting point (in my case Console Application’s Main method) and obtain a reference to an instance of Logger.
Issue configuration request.
End last feel free using your logger.

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
  <configSections>
    <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
  </configSections>
  <log4net>
    <!-- [Appenders]-->
    <appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender" >
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%thread] %-5level %logger - %message%newline" />
      </layout>
      <filter type="log4net.Filter.LevelRangeFilter">
        <levelMin value="DEBUG"/>
        <levelMax value="INFO"/>
      </filter>
    </appender>
    <appender name="RollingFile" type="log4net.Appender.RollingFileAppender">
      <file value="example.log" />
      <appendToFile value="true" />
      <maximumFileSize value="100KB" />
      <maxSizeRollBackups value="2" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%level %thread %logger - %message%newline" />
      </layout>
    </appender>
    <!-- [/Appenders]-->
    
    <!-- [Loggers]-->
    <root>
      <level value="ALL" />
      <appender-ref ref="ConsoleAppender" />
    </root>
    <logger name="YapBee.Common" additivity="false">
      <level value="DEBUG"/>
      <appender-ref ref="RollingFile"/>
    </logger>
    <logger name="YapBee.Security" additivity="false">
      <level value="INFO"/>
      <appender-ref ref="ConsoleAppender"/>
      <appender-ref ref="RollingFile"/>
    </logger>
    <logger name="YapBee.Business.Accounting" additivity="false">
      <level value="ALL"/>
      <appender-ref ref="ConsoleAppender"/>
    </logger>
    <!-- [Loggers]-->
  </log4net>
</configuration>

And here is my code

using System;
using System.Reflection;

using log4net;

namespace YapBee.Poc.Logging
{
    class Program
    {
        private static readonly ILog log = 
            LogManager.GetLogger(MethodBase.GetCurrentMethod().DeclaringType);
        static void Main(string[] args)
        {
            log4net.Config.XmlConfigurator.Configure();

            log.Debug("log message 1");
            ILog log2 = LogManager.GetLogger("YapBee.Business.Accounting");
            log2.Info("log an Info");
            log2.Error("log an error"); // This log will be filtered
            Console.WriteLine("Press Enter to exit");
            Console.ReadLine();
        }
    }
}

After this fast start up I want to step into features and building blocks of log4net.

log4net is fully configurable programaticly and by using configuration files and provides you a simple interface for logging. log4net’s structure consists of four main components which are Logger, Repository, Appender and the Layout.

Logger, is the main component which your application interacts with to generate log messages. There is another class LoggerManager responsible for creation and management of instances of Logger. Logger instances are named entities and served in a hierarchal manner which means if there are Loggers one named a and another a.b (hierarchy supplied with a dot) then all properties of a is inherited by a.b.

From the above config file you can see how named Loggers are configured. There is a root element which is still a Logger with the other logger blocks. All the other named Loggers are inherits their properties from this root logger unless they have an additivity attribute set to false. Additivity prevents the inheritance from the ancestor. You can notice that I gave loggers namespace like names and have %logger parameter at the layout. Similarly you may have each component have its own logger and this help you finding problems and vulnerabilities efficiently.

You initiate Logger instances using LogManager.GetLogger method and supply it the name of the logger like this:

log4net.ILog log = log4net.LogManager.GetLogger("YapBee.Security");

Here in fact LogManager is an extension to LoggerManager class and wraps Logger instances into LogImpl instances which derived from ILog interface and in this way serve us methods which know their levels.

So that we can log messages by using log.Debug or log.Info like methods which are not possible with the Logger.

Logger have a priority level can be configured using Level element and by using this you may filter log events and direct them to different output destinations.

Appender, is define the logging sink (output destination) and there is a number of Appender classes under log4net.Appender namespace that enable you to log to Console, Event Log, Database, Aspnet Trace, mail etc. You either use provided appenders or create custom appenders by extending log4net.Appender.AppenderSkeleton class or implementing IAppender interface.

As you can see from config using appender-ref element you attach Appenders (zero or more) to Logger.

Layout, is the formatter of the message. Like Appender Layout serve you another chance to extend the framework.

There is another thing named Filter. Filter as its name suggest it gives you opportunity to filter out messages. I will not go in deep on these classes, you may find more information about Appender, Layout, Filter at the official documentation.

Possibly most of the users never need Repository. By default all assemblies loaded by single process share same configuration file but repository let them have their own configuration.

Log4net also supports writing plugins.

I tried to make a summary on log4net. But It seems like summary of summary :)

log4net vs Enterprise Library Logging Application Block

info.nospam@nospam.yapbee.com (Hakkı Yılmaz) — Thu, 19 Feb 2009 12:59:00 +0000

In past recent weeks I dealed with log4net and Enterprise Library Logging Application Block in order to compare which one is most appropriate tool for our enterprise application. So I wanted to share my exprerience. This is the first post of a series about the logging and constitutes priliminary for the issue. In this series you will find what features are provided and and how this two meet your auditing concerns of your application.

In the enterprise application's world we have some core concerns (business logic) and some cross cutting concerns like logging, auditing, transaction management, memory allocation, security etc. and from the OO Programmer point of view we separate these concerns in order to serve a loosely coupled architecture. And I will focus on logging which supporting our auditing infrastructure.

In order to select one of this cool tools first you must define your consideration and prioritize your expectations.

Now let's start. We are using WCF for our SOA architecture and other Enterprise Library Application Blocks for exception handling, validation.

And here is the criterias:

- Integration with other program concerns we use (WCF and Entib)

- Outputing to several output media for example flat file, database, windows eventlog etc.

- Configuration richness (configurability of every aspect)

- Configuration simplicity

- Extendability

- Stability

- Performance

- Documentation & Support

I made simple PoC applications for both for examining features and read blog posts, refered to official documentations, downloaded samples and these made me think both have sufficient examples and documentation and configuration richness. Through playing with provided samples I saw both have a sufficient level of extendibility options. But with the in box configuration tool Enterprise Library Logging has a minor advantage of configuration simplicity. There are plenty of written article upon Entlib logging on the web and there is an active community using it and this made me have the idea with the EntLib logging getting help with it will be much more easier. When we come to the stability I didn't see users struggling with the problems they faced around. Its enough for me now about stability of them.

When we come to the performance which too many people discussing on the issue. I tested them with 100.000 records with console output option and log4net was four times faster than Entlib logging and with the database output option log4net faster again. log4net is the winner of the test drive by means of performance. But I think this test drive does not show using that Entlib logging will boast your application performance. I think no one will log 100.000 log entry in a sequential manner.

Last point perhaps one of the most important is the integration. Entlib logging serve us good integration points with other application blocks and WCF.

Much of you will say this all blah blah. Be patient, soon I will come up with sample codes and howtos.