I was recently involved in a discussion around logging and the best way of implementing it in an application.  I was once again reminded of how many applications choose to implement their own logging solutions rather than use a logging framework.  It’s the most common occurrence of ‘not-invented-here’ syndrome that I’ve come across.

You shouldn’t implement your own logging solution.

Phew, now that we’ve got that out of the way, let’s spend some time looking at one of the most popular logging frameworks for the .Net framework – log4net.

Log4net

Log4net is a port of the excellent (so I’ve heard – never used it) log4j framework to the .Net runtime.  It’s easy to use, easy to configure and very flexible.  I’m a fan.

I particularly like log4net because it allows you to log to multiple sources at once with very little effort.  For example, I often choose to run a Windows Service as a Console application during development.  Log4net allows me to log to this console application during development and then switch to logging to a file or database for production – it’s a very simple config change.

Example – Logging from an MVC website

As an example I’m going to show how to configure logging in an MVC 2 website.  To get started I create the application and referenced the log4net dll.  Now add the following to the web.config file.  (You can either add the log4net configuration to the web.config file, or put the configuration into a separate file.  The advantage of putting it into a separate file is that you can change the configuration at runtime.  Phil Haack has a nice example of how to do that)

<configSections>
  <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" requirePermission="false" />
</configSections>

Obviously if there is already a configSections element you should simply add your section to that.  Now you can go ahead and add a log4net section, I added mine right before the closing configuration tag.

<log4net>
  <appender name="FileAppender" type="log4net.Appender.FileAppender">
    <threshold value="DEBUG"/>
    <file value="E:\\Projects\\LoggingExample\\Logs\\log.txt" />
    <appendToFile value="true" />
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%date [%thread] %-5level %logger - %message %newline" />
    </layout>
  </appender>
  <root>
    <level value="ALL" />
    <appender-ref ref="FileAppender" />
  </root>
</log4net>

Log4net uses the concept of an appender – an appender is basically a destination for logging – this can be a file, database, e-mail, console, etc.

Let’s quickly run through some of the different options I’ve configured here. 

• The threshold specifies the level of verbosity for the specific appender – in this case, Debug.  Log4net has 5 levels of logging – Debug, Info, Warn, Error and Fatal.  For example, specifying the threshold as Warn means any messages of level Warn or higher will be logged.  It’s also very useful to be able to specify different threshold levels for different appenders.
• The layout specifies the actual message that will be logged.  Log4net makes several variables available to you (such as the date, thread and context/logger) and then allows you to format the log message any way you want.

If you want to look at some of the other appender configuration options available I suggest you take a look at the example page on the log4net site.

What about monitoring?

I was specifically looking at the different log4net appender options because I was looking for a possible monitoring solution.  While I believe that keeping logs is critical for tracking down problems, it doesn’t really work all that well for monitoring.  Sure you can use the e-mail appender to send e-mails to your support team, but the pure volume can be overwhelming and often gets ignored. 

In my (very limited) experience monitoring works best when you can push events to the monitoring solution rather than relying on the monitoring solution to constantly sift through the masses of data being produced by the application and trying to find critical issues.  In the application I am currently working on the monitoring is implemented by logging to the database and then constantly polling the database.  Any issues are then displayed on a physical monitor where the support team can keep an eye on them – anything in red generally means they need to take action.  I wanted to see if log4net could possibly offer a similar but more elegant solution.  I decided to try the Remoting appender.

The Remoting appender

My basic idea was this – write any messages of Info and above to a file and possibly the database and push any messages of Warn and above to the monitoring application.  Logging to a file or database is straightforward but I haven’t found any solutions that use the Remoting appender.

Firstly, we need to implement the Remoting sink.

public class RemoteSink : MarshalByRefObject, RemotingAppender.IRemoteLoggingSink
{
    public void LogEvents(LoggingEvent[] events)
    {
        foreach (var loggingEvent in events)
        {
            // Do something with the log message here
        }
    }
}

Now we simply need to host this inside some kind of application.  I went for the simple Console application.

static void Main(string[] args)
{
    RemotingConfiguration.Configure("Monitor.exe.config", false);
    RemotingConfiguration.RegisterWellKnownServiceType(new WellKnownServiceTypeEntry(typeof(RemoteSink), "LoggingSink", WellKnownObjectMode.SingleCall));

    Console.WriteLine("Monitor started");
    Console.WriteLine("Press <ENTER> to kill.");
    Console.WriteLine();
    Console.ReadLine();
}

This is what my app.config looks like:

<?xml version="1.0"?>
<configuration>
  <system.runtime.remoting>
    <application>
      <channels>
        <channel ref="tcp" port="8086"/>
      </channels>
    </application>
  </system.runtime.remoting>
</configuration>

Pretty simple stuff.  The only tricky bit was configuring the config on the website.  The Remoting appender has a buffervalue property which I tried to use, but log4net seemed to simply ignore it.  I then used a BufferingForwardingAppender to buffer and push messages to the Remoting appender (another simple config change) – this worked perfectly.  But unfortunately after a while the Remoting appender just stopped working completely – after fiddling around for a while I found that I needed to set the buffervalue on both appenders – an annoyance, but no biggie.

<appender name="RemotingAppender" type="log4net.Appender.RemotingAppender" >
  <bufferSize value="2" />
  <sink value="tcp://localhost:8086/LoggingSink" />
  <lossy value="false" />
  <onlyFixPartialEventData value="true" />
</appender>
<appender name="BufferRemotingAppender" type="log4net.Appender.BufferingForwardingAppender" >
  <bufferSize value="2" />
  <evaluator type="log4net.Core.LevelEvaluator">
    <threshold value="WARN"/>
  </evaluator>
  <appender-ref ref="RemotingAppender" />
</appender>

Now we can easily modify this application into a proper monitoring tool.

Conclusion

Logging is tricky to get right.  But far less tricky than we make it out to be.  In my opinion log4net is sufficient for the majority of applications out there – even adding a monitoring solution is reasonably straightforward.

Happy coding.

Share on: Twitter, Facebook, Google+ or use the Permalink