Recently at work, I came across a situation where someone described a log as a "nice to have". No, it's not nice to have - its essential to have it. As I was working in .Net (c# to be exact, hence the title), I decided to take a look at log4net. This is a logging framework maintained by the Apache project and is a port of the popular log4j to .Net, I am not going to bore people with an explanation of it here, all I will say about it is that it is a very powerful and flexible logging service. You can check out the official site here: http://logging.apache.org/log4net/index.html.
I spent a few weeks working with log4net (as it apparently wasnt essential to have a log, it was a low priority task). Creating a logfile with it is incredibly easiy, as is logging to the console. There are wide range of methods for creating a log, called appenders, however the most useful for me was appending the log to a database. Whilst log4net is popular, powerful and active, there isnt that much in the way of documentation or howto's, which could put some people off using it, this is especially apparent when logging to a database. The examples that already exist on the interweb, while useful, are sometimes out of date using deprecated syntax.
For my logging scenario, I needed to maintain a log in a MySql table, this compounded my explotation of log4net, as it isnt readily obvious how this can be done. My aim is to use log4net for all of my logging needs, so I want to create an assembly that can be referenced etc wherever I need it. Due to the extremely felxible nature of log4net, this is achievable - the majority of the configuration for it lives within the app.config (or web.config if you are that way inclined). It is possible to programatically configure log4net from within your code - but what would be the point? If you do that, then you loose all of the flexibility offered. One way to highlight this feature - right now I need to log to a MySql table, but what about in future if we decide to migrate to another DB? If I configured my logger programtically, I would then need to rewrite code. Whereas if I configured it via a .config file, all I need to do is deploy that file wherever it needs to go...
Anyway, enough waffle - you are all grownups and have myriad needs. Lets take a look at how I got log4net logging to my MySql table.
Setting up log4net to log to the console or to a file is dead simple, there is very little taking place in the code, most of it is done in the config file. The same can go for logging to a db, but with one small difference - if you rely on the config file to control your logging when using a database you have to be comfortable with the fact that your connection string will be visible. I am not sure how much of a security risk that is for everyone else, but for me it wasnt something I was willing to do at all. Even if you use a seperate database for logging, you are still exposing a lot of information about your infrastructure here. So, instead of placing the connection string in the log4net config, I am going to place it in the connectionStrings section and encrypt it. Once this is done, I need to set the connection programatically. This isnt as easy as you would first imagine (well, at least I didnt find it that easy), whilst there is a lot of documentation on what log4net can do, I found it quite tricky to figure out how to make it work with MySql - and even when I had I still had one small issue... Anyway, on to getting this setup.
All of my config for my logger is going to live in my app.config - inlcuded my encrypted db connection string. I need to get this string and then provide it to log4net, this bit is done in the code. It sounds simple but there are a number of steps I need to take first. To start with I need to get the default repository that my logger is going to use with log4net:
private Hierarchy hierachy()
{
Hierarchy h = (Hierarchy)log4net.LogManager.GetRepository();
return h;
}
It is possible to use different configuration repositories with log4net - but I dont need to so I havent had to worry about this. To be honest, I am not sure that a lot of people will need to either. Once this has been done, we need to create an ADOAppeneder - it should also be pointed out by now that I am using the MySql .Net connector to work with my db.
private AdoNetAppender adoAppender()
{
Hierarchy myHierarchy = hierachy();
if (myHierarchy != null)
{
AdoNetAppender adoApp = (AdoNetAppender)myHierarchy.Root.GetAppender("ADONetAppender");
return adoApp;
}
return null;
}
With this code, I am able to get the section of my .config file that holds all of the config for logging to a db through log4net, log4net relies on one or more 'appenders' being configured for use - my db appender is simply called 'ADONetAppender', so I have specified this in the above method. With this done, I am now ready to configure my appender programtically:
private void createAdoSettings(string dbConn)
{
AdoNetAppender myAppender = adoAppender();
if (myAppender != null)
{
myAppender.ConnectionString = dbConn;
myAppender.UseTransactions = true;
myAppender.ActivateOptions();
}
}
After all of this, we are done. All I need to do is tell my logging class what my connection string is. This isnt so difficult (thankfully, is very easy):
string connstring = ConfigurationManager.ConnectionStrings["SQLLogDB"].ConnectionString.ToString();
SetUpLog _setup = new SetUpLog(connstring);
Cant get any simpler really :). All I need to do is drop this into any class I want to log from and I am set. There is only one other addition I need to make, and that is to implement the ILog interface. This is the most important bit, regardless of any db logging, without it you cant log anything at all! I got a nice little gem from here: http://www.ondotnet.com/pub/a/dotnet/2003/06/16/log4net.html that give a good tip on implementing the interface. Basically, popping this line in at the start of your class ensures that log4net reports the name of the class duing the logging process:
protected static readonly log4net.ILog log = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);
This is so useful and provides a very concise log. With all this in place, we are now able to use log4net to log our application. The following code is the test app I wrote when to prove that it works:
using Logger.Setup;
using System;
using System.Configuration;
using System.Collections.Generic;
using System.Linq;
using System.Text;
namespace TestClient
{
class Program
{
protected static readonly log4net.ILog log = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);
static void Main(string[] args)
{
Program test = new Program();
test.logtest();
}
private void logtest()
{
string connstring = ConfigurationManager.ConnectionStrings["LogDB"].ConnectionString.ToString();
SetUpLog _setup = new SetUpLog(connstring);
log.Info("Hello there");
}
}
}
On execution, it provides the following on the command line:
2009-05-23 23:21:37,536 [12260] INFO Hello there 23 TestClient.Program
You can also see how I am specifying the connection string, which is also held in the .config file. This is driven by my .config file, it is just a console appender and lives inside the log4net section:
<appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date [%thread] %-5level %message%newline %L %C" />
</layout>
</appender>
Now I know it works, I can get down to logging the same information to my db, first I create my schema:
CREATE TABLE logdb.mylog(
`DateTime` DATETIME DEFAULT NULL,
Thread VARCHAR (20) DEFAULT NULL,
Level VARCHAR (20) DEFAULT NULL,
Message VARCHAR (20) DEFAULT NULL,
Exception VARCHAR (20) DEFAULT NULL,
line VARCHAR (20) DEFAULT NULL,
object_ref VARCHAR (20) DEFAULT NULL,
taskID VARCHAR (20) DEFAULT NULL
)
ENGINE = INNODB
CHARACTER SET latin1
COLLATE latin1_swedish_ci;
The object_ref and taskID columns are things I want to capture as part of my wider logging process - they dont really have anything to do with log4net or its configuration. With my schema in place all I need to do now is configure log4net to log my messages to my new table. This can be a bit frustrating when working with MySql - if you get something wrong in the config you will get an error message, but they dont always seem to be that helpful to me. For instance, log4net requires you to define a connection type in order to log to a db. When I first started working with log4net, my connection type was incorrect which resulted in an error. However, the error I got complained about connection strings being null - not that there was an error with the connection type I had configured. Granted, they are closely related, but it would have just been nice if I get an error back telling me that my connection type was wrong... Anyway, I got passed it. When configuring log4net there are a couple sections that you need to work with. I am going to assume that if you are reading this then you have already looked at the log4net site and looked at how it is configured. I am not going to explain how to configure log4net here in general, if you want to see how this works then there are a lot of other articles out there that do this well, one good place to start on the topic of configuration is the log4net site - even though it is very general it will give you an idea of how all the appenders look: http://logging.apache.org/log4net/release/manual/configuration.html
Now that my schema is in place and my logic is complete, all I need to do now is configure a log4net appender. Appenders in log4net control how information is formatted as it is logged, I am going to use an ADO appender and it looks like this:<appender name="ADONetAppender" type="log4net.Appender.ADONetAppender">
<connectionType value="MySql.Data.MySqlClient.MySqlConnection, MySql.Data, Version=6.0.3.0, Culture=neutral, PublicKeyToken=c5687fc88969c44d" />
<commandText value="insert into mylog (thread,line,object_ref,taskID,message,level,datetime)
values(?thread,?line,?objectref,?taskid,?message,?level,?log_date)" />
<parameter>
<parameterName value="?thread"/>
<dbType value="String"/>
<size value="20"/>
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%thread"/>
</layout>
</parameter>
<parameter>
<parameterName value="?line"/>
<dbType value="String"/>
<size value="20"/>
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%L"/>
</layout>
</parameter>
<parameter>
<parameterName value="?objectref"/>
<dbType value="String"/>
<size value="20"/>
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%C"/>
</layout>
</parameter>
<parameter>
<parameterName value="?taskid"/>
<dbType value="String"/>
<size value="20"/>
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%property{taskid}"/>
</layout>
</parameter>
<parameter>
<parameterName value="?message"/>
<dbType value="String"/>
<size value="20"/>
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%message"/>
</layout>
</parameter>
<parameter>
<parameterName value="?level"/>
<dbType value="String"/>
<size value="20"/>
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%level"/>
</layout>
</parameter>
<parameter>
<parameterName value="?log_date" />
<dbType value="DateTime" />
<layout type="log4net.Layout.RawTimeStampLayout"/>
</parameter>
</appender>
The most notable thing about my config here is the use of a property. This lets me capture custom information for my log and place this in my db. This is really useful, I am sure you can all understand why and goes to show the power of log4net. With all of this in place, I am now able to log to my db - but with one small caveat, I think I have found a problem with log4net when using an ADO appender with MySql. For some reason, log4net generates an error telling me that there is a null system exception, but carries on and logs the data to the db anyway. I spent a long time trying to figure out what the problem was, but couldnt spot it. So, after some advice, I started working with the log4net source to spot where the error was being generated. Stepping through the code, I found that log4net (when used with the MySql .Net connector) seems to loose the connection string, but logs data anyway. I couldnt replicate this with SQL Server and have still been unable to resolve the error. I dont like errors hanging around like this, the data is logged, but I get this nasty message.... I have posted my findings to the log4net support group, but have not had anything back about it really - which is a shame. However, in saying that, log4net is still a truly useful tool to use in any project that requires any form of logging.
What an awesome post! Thank you
ReplyDelete