Using Log4net in C# - Quick start guide (and reminder to myself!)

I use logging in virtually every app I write. Even if it is just a simple proof of concept, or even if I'm tweaking someone else's code, the first thing I do is hook in log4net. This is a mature, lightweight logging framework which is easy to configure and easy to turn on and off.

And yet - I still do not remember all the steps needed to get it up and running, and hence this blog - a place for me and hopefully others to go to get log4net up and running so we can get onto more important tasks.

Installation and Setup

These days I usually use nuget to install log4net. You can also get it from Apache. It consists of one dll of 292kB.
The minimum steps needed to get it working are:

• Reference the log4net.dll 
• Add a line to AssemblyInfo.cs 
• Declare a logger in each class 
• Add logging statements 
• Modify the .config file as needed - this is where the magic happens! 

You can also consult this very good setup summary by Justin Rhinesmith here

AssemblyInfo.cs

In AssemblyInfo.cs, add the line:

[assembly: log4net.Config.XmlConfigurator(ConfigFile="log4net.config", Watch = true)]

This tells your program to call the default configurator for log4net, use the file "log4net.config", and watch the file for changes. You could leave out the ConfigFile, in which case it would use the application's app.config file. I long ago decided that I would just use the same filename "log4net.config", for all my applications. Then I can simply copy over this file anytime I needed it. So far, this has worked out well and I tend to re-use the same settings 90% of the time.


Note that if you want to use the app.config file you still need to update AssemblyInfo.cs with:

[assembly: log4net.Config.XmlConfigurator(Watch = true)]

Also note that you can call the configurator explicitly in your code. I have found that this just does not work as well as declaring it in the assembly. In particular, declaring in the assembly means that you put that exact same line in assembly.cs for console, windows, ASP.NET and Service applications.

Using it in your code

Next, let's add logging to the code. Here is the basic code:

public class MyClass {

  static log4net.ILog log = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType); 

  public void Foo () {

    log.Warn("This is a Warning message");

    log.Info("This is an Info message");

    log.Debug("This is Debug message");

  }

}

GetLogger takes either a Type or a String. In this case, I am using reflection to get the type of "this" class.
I really like this way of doing it, since, it means that this same line can be cut and pasted into any class,
and will not need to be edited.

The log is also static, since I don't want to waste time and resources instantiating one in each instance of my class.

Next, I make calls to the logger, as in:

    log.Info("This is an Info message");

There you go. Now the code will send log information to log4net. So what happens to the information? Where does it go?  The very nice thing at this point is that where the log info goes is no longer in the application's hands. You don't  have to change any code to set or change where it goes.

Configuring log output

Log4net can be configured in the app.config file, within the code itself, or from any xml-formatted file. I like to just call my file log4net.config and be done with it.

My favorite log4net.config file can be found here.  I'm not including the text directly in the interest of saving space.  Feel free to copy it from GitHub!

This looks like any other config file for .Net. First a configuration handler is defined. Then comes the actual log4net configuration.  We add an appender, which can be defined as "a thing which takes log messages and puts them somewhere".  I will list my 3 essential appenders:  Trace, Console and RollingLog

TraceAppender

I work in Visual Studio, and so want  to see my log output in the Debug Output window.  The Trace Apender does that:

    <appender name="TraceAppender" type="log4net.Appender.TraceAppender" >
      <threshold value="DEBUG"/>
      <layout type="log4net.Layout.PatternLayout">
        <param name="ConversionPattern" value="%-5p %m%n" />
      </layout>
    </appender>

I generally want to see everything in this trace.


ConsoleAppender

The ConsoleAppender simply outputs messages to the console.  Many of my apps are console apps or have some form of console mode.   There is even a color-coded console appender if you want to get fancy.

 <appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender" >

      <threshold value="INFO"/>

      <layout type="log4net.Layout.PatternLayout">

        <param name="ConversionPattern" value="%-5p %m%n" />

      </layout>

 </appender>

I generally put the threshold to Info here, so that it does not show the verbose Debug messages.

RollingFile Appender

For persistent diagnostics, you want to log to a file. But what file? What happens when the file gets large? Log4net's file naming options take care of the first question, and the RollingFileAppender takes care of the second.

<appender name="RollingFileAppender" type="log4net.Appender.RollingFileAppender">

  <threshold value="DEBUG"/>

  <file type="log4net.Util.PatternString"

        value="%appdomain_%property{log4net:HostName}.log"/>

  <lockingModel type="log4net.Appender.FileAppender+MinimalLock" />

  <layout type="log4net.Layout.PatternLayout">

    <conversionPattern value="%date %-5level: %message%newline" />

  </layout>

  <rollingStyle value="Composite"/>

  <datePattern value="yyyyMMdd"/>

  <maxSizeRollBackups value="100"/>

  <maximumFileSize value="15MB"/>

</appender>

The file name is set in the <file> tag.  It basically gets the name of the executable itself and  the machine name.  So if my program is called foo.exe, running on Bombur, the file will be named "foo.exe_Bombur.log"  The file also rolls, meaning that if it exceeds a certain size, then it will rename the current log file and start a new one.  You can tell it how far to back up before deleting old log files, as well as how large to let those files get.  With the settings above, I generally have enough history to find recent issues, and the files are small enough to be read easily.

Log4net Debugging

But what if you don't see any messages? This is a concern about using a 3rd party logging system. If it does not work, how will you know?  The answer is that you can turn on log4net's own built-in debugging by putting the following into app.config:

<appSettings>
  <add key="log4net.Internal.Debug" value="false"/>
</appSettings>
<system.diagnostics>
  <trace autoflush="true">
    <listeners>
    <add name="textWriterTraceListener"
    type="System.Diagnostics.TextWriterTraceListener"
    initializeData="C:\log4net_internal.log"/>
    </listeners>
  </trace>
</system.diagnostics>
In the appsettings you tell log4net to run its internal debugging. If you run from the console you'll see many messages as log4net created repositories, adds appenders, and sets various properties. However, if you are debugging an ASP.NET application, you won't have a console. But the good news is that log4net's messages are emitted as trace calls. So you can add a tracelistener, such as a simple TextWriter in the example above. Now you'll see the messages in your log file.

This should be sufficient to find out what is going wrong.

However, if you still are getting no logs, then you can also just run from the debugger and step into the log4net code itself. It is all available in the download, and if you want to, you can even modify it yourself!

Summary

This was  intended to be a simple introduction to log4net, and a reminder to myself of the basocs.  I hope it helps to show how simple it is to use, and how easy it is to add the benefit of logging to your development experience.