Sunday, October 28, 2012

Simple log4net configuration in C# applications

Log4net is the .Net cousin of the very popular Java based log4j logging package.  The simple to use package logs information to a variety of data sinks (appenders) with fine grain control over the amount of output generated by each logging source. log4net is available for download from the Apache Software Foundation  and is part of the Apache Logging Project which includes logging libraries for several languages.

Log messages are generated by calls through named instances of the ILog interface. Each class that wants to log creates an instance of the ILog interface based on the class's fully qualified class name, including namespace.  This means each class has its own entry point into the logging system. In some sense each namespace has it's own common entry point by virtue of the fact that the ILog instances for that namespace all share the same base name/category-name. Callers pass a logging level and message along with an optional Exception objects for certain logging levels.  The system then filters the log messages passing the unfiltered messages to the message sinks, called Appenders.

Logging Levels

log4net supports five (5) logging levels.  Teams create their own policies around when the different levels should be used but the general approach is:
Fatal: This is the highest level severity.  Some type of system error or some type of non-recoverable user error.  I've used this when a user is disconnected from the system because of a user error.  These usually include an enclosed exception or stack trace.
Error: Some type of error that the system recognizes.  The system usually can roll back or somehow salvage some of the work. This might also be used when a database lookup fails but there is some type of fallback action that can be taken.  These usually include an enclosed stack trace or exception.
Info: This is the minimum level enabled in most systems. These are usually used for checkpoint messages or other information that should be retained in log files, event logs, or other external data stores.
Debug: Developer output that helps debug a system. This level is only enabled when troubleshooting. Messages at this level are often wrapped in a debug-enabled check to save the system from creating logging messages that will never appear in production.
Trace: Verbose debugging output. Probably a major performance hog.
Messages at this level are often wrapped in a debug-enabled check to save the system from creating logging messages that will never appear in production.  I've used this in unit tests where we log at at a trace level with a Trace level enabled appender.  This lets us track tests through the code without having to modify the code for tests and production.

Filtering messages based on category and logging level. 

Filters set the pass-through level for logging names/categories based on full or partial category names. Classes set up their loggers using the class names using typeof. The following creates two loggers with category names BuildWatcher.BuildWatchDriver and BuildWatcher.TfsBuildAdapter

    namespace BuildWatcher
    private static ILog log = 
    private static ILog log = 
The following configuration sets the default logging level to DEBUG except for BuildWatcher namespace related loggers that log at WARN and above.  Note that BuildWatcher WARN level messages are actually routed to a special Appender.  log4net supports multiple appenders.


Routing messages to sinks using Appenders

Log4net output is routed, formatted and delivered through the Appenders.  Applications can any number of Appenders to route information to different places.  The two most common are ConsoleAppender and Rolling FileAppender.  Others exist for message buses , event logs and data stores. Here is a simple Console appender configuration.


Configuring log4net using App.config or Web.config

You can configure log4net using an external config file, through code using the API or through your already existing config file.  The following shows an log4net configured as part of app.config.  This sample comes from my TFS build monitoring program on github  

This configuration supports logging of all messages to the console and to a file that is rolled over on regular intervals. The default logging level for this configuration is DEBUG which means DEBUG and above all appear in both logging locations.

Thanks for reading...

1 comment:

  1. This comment has been removed by a blog administrator.