Intro and Configuration
Log4net is a sophisticated logging library for .NET
applications (web or otherwise). It’s not however cumbersome to use, neither
it’s intrusive I believe. I will try in this post to illustrate what I think is
good configuration for this library. A configuration that lets a .NET
application uses but not have a hard dependency on it.
Now there are a number of ways you can configure the
library, what to log (date & time stamp, thread #, custom message,
exceptions etc) and where to log (a database, a file or the standard output
{console}). A good way to configure the library is tell your application and
the assembly level where the configuration file for log4net (typically an XML
file) lives. You do so by adding the below line to your AssemblyInfo.vb or
(AsssemblyInfo.cs) class
<Assembly:
log4net.Config.XmlConfigurator(ConfigFile:="MyAppLog4net.config",
Watch:=True)>
The configFile can a full-path to your log4net configuration
file. The watch flag if set true tells log4net to reload the configuration at
runtime if the configuration file was changed.
Now technically you can start logging. Given the simple
config file below
<?xml version="1.0" encoding="utf-8" ?>
<log4net>
<appender name="RollingFile" type="log4net.Appender.RollingFileAppender">
<file value="myLog.log" />
<appendToFile value="true" />
<maximumFileSize value="100KB" />
<maxSizeRollBackups value="2" />
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date
%level %thread %logger - %message%newline" />
</layout>
</appender>
<root>
<!--<level
value="DEBUG" />-->
<appender-ref ref="RollingFile" />
</root>
</log4net>
With this log file we can log a visit to web page
Protected Sub Page_Load(ByVal
sender As Object,
ByVal e As
System.EventArgs) Handles Me.Load
log4net.LogManager.GetLogger(Me.GetType().Name).Info(Me.Request.Path
+ " visited.")
End Sub
A sample output: 2012-04-21 09:21:33,970 INFO 21
default_aspx - /Default.aspx visited.
A better
approach (create your own wrapper):
Instead of invoking log4net directly from your business logic
layer, data layer, etc. a better approach is to create wrapper logging layer.
The benefit is that you decouple your application from a specific logging
implementation.
One way to do this is to create an interface that defines
your logging operations. A simple interface can look like the below.
Public Interface ICustomLog
Sub Debug(ByVal source As Type,
ByVal message As
String, ByVal
exception As Exception, ByVal customObject As
CustomLogProperties)
Sub Info(ByVal source As Type,
ByVal message As
String, ByVal
exception As Exception, ByVal customObject As
CustomLogProperties)
Sub Warn(ByVal source As Type,
ByVal message As
String, ByVal
exception As Exception, ByVal customObject As
CustomLogProperties)
Sub
[Error](ByVal source As
Type, ByVal message As
String, ByVal
exception As Exception, ByVal customObject As
CustomLogProperties)
Sub Fatal(ByVal source As Type,
ByVal message As
String, ByVal
exception As Exception, ByVal customObject As
CustomLogProperties)
End Interface
Any type of logging implementation will then have to adhere
to the defined interface. The parameters passed to various logging methods will
apparent later, hopefully.
Here is an implementation that will rely fundamentally on
log4net. But before showing the concrete implementation, let’s talk about
custom properties that you can tell log4net to log for you.
Logging Custom Properties using log4net [.Core.LoggingEvent]
By default log4net will log a number of properties (thread
number, date of event, custom message etc.). If you wish to add properties that
are specific to your application, log4net will let you do that through a number
of ways. One of the ways that you can load a log4net logger object with custom
properties is through using the LoggingEvent class. The sample code will
illustrate how. One of the common issues one runs to when using custom
properties is that even it appears the code is using them correctly, they don’t
show in the log file/ log table etc. This is almost always due to the fact that
configuration file is not written correctly to tell log4net how to render or
from where to get the custom properties; so special care needs to be given to
how the configuration is written.
For example, let’s assume that one of the requirements of
your is logging three custom properties: the SessionID {asp.net SessionID}, the
raw request’s URL, and an application name. Putting these three variables in a
custom object is a good idea (CustomLogProperties in sample). Every time we
need to log an event with then create an instance of CustomLogProperites and
pass to our logger who takes care of creating a LoggingEvent populated with the
custom properties.
Private Sub SetCustomLogProperties(ByVal
loggingEvent As log4net.Core.LoggingEvent, ByVal customLogObject As
CustomLogProperties)
If
customLogObject Is Nothing
OrElse loggingEvent Is
Nothing Then
Return
End If
loggingEvent.Properties(CustomFileLogger.ApplicationNameKey) =
customLogObject.ApplicationName
loggingEvent.Properties(CustomFileLogger.RequestKey) =
customLogObject.RequestPath
loggingEvent.Properties(CustomFileLogger.ASPSesssionIDKey) =
customLogObject.SessionID
End Sub
Private Function GetLoggingEvent(ByVal
source As Type, ByVal
logger As log4net.ILog, ByVal message As String, ByVal
exception As Exception _
, ByVal level As
log4net.Core.Level, ByVal customLogObject As Object) As log4net.Core.LoggingEvent
If
source Is Nothing
OrElse logger Is
Nothing Then
Return
Nothing
End If
Dim
loggingEvent As New
log4net.Core.LoggingEvent(source, logger.Logger.Repository, logger.Logger.Name,
level, message, exception)
SetCustomLogProperties(loggingEvent,
customLogObject)
Return
loggingEvent
End Function
Public Sub Debug(ByVal
source As Type, ByVal
message As String,
ByVal exception As
Exception, _
ByVal
customLogObject As CustomLogProperties) Implements ICustomLog.Debug
Dim
logger As log4net.ILog = GetLogger(source)
Dim
loggingEvent = GetLoggingEvent(source, logger, message, exception,
log4net.Core.Level.Debug, customLogObject)
If
loggingEvent IsNot Nothing
Then
logger.Debug(message)
End If
End Sub
Here is the relevant portion of the log configuration file
which will instruct the log4net library on how to write the custom properties
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date %level %thread %logger - %message %exception
[%property{ApplicationName}]
[%property{RequestPath}]
[%property{SessionID}] %newline" />
</layout>
Notice the use of %property{property_name} syntax.
Code Listings
Configuration
<?xml version="1.0" encoding="utf-8" ?>
<log4net>
<appender name="RollingFile" type="log4net.Appender.RollingFileAppender">
<file value="myLog.log" />
<appendToFile value="true" />
<maximumFileSize value="100KB" />
<maxSizeRollBackups value="2" />
<layout type="log4net.Layout.PatternLayout">
<conversionPattern value="%date %level %thread %logger - %message %exception [%property{ApplicationName}]
[%property{RequestPath}] [%property{SessionID}] %newline" />
</layout>
</appender>
<root>
<!--<level value="DEBUG" />-->
<appender-ref ref="RollingFile" />
</root>
</log4net>
Sample Code
Partial Public Class _Default
Inherits System.Web.UI.Page
Private logger As ICustomLog = CustomFileLogger.GetInstance()
Protected Sub Page_Load(ByVal sender As Object, ByVal e As System.EventArgs) Handles Me.Load
'log4net.LogManager.GetLogger(Me.GetType().Name).Info(Me.Request.Path + " visited.")
logger.Info(Me.GetType(), "Page visitied", Nothing, New CustomLogProperties() With {.ApplicationName = "MyApp", .RequestPath = Request.RawUrl, .SessionID = Me.Session.SessionID})
CauseAndLogException()
End Sub
Private Sub CauseAndLogException()
Dim str = "4/31/2012"
Try
DateTime.Parse(str)
Catch ex As Exception
logger.Error(Me.GetType(), "An error occurred in " + System.Reflection.MethodBase.GetCurrentMethod().Name, ex, New CustomLogProperties With _
{.ApplicationName = "MyApp", .RequestPath = Request.RawUrl, .SessionID = Me.Session.SessionID})
End Try
End Sub
End Class
Public Interface ICustomLog
Sub Debug(ByVal source As Type, ByVal message As String, ByVal exception As Exception, ByVal customObject As CustomLogProperties)
Sub Info(ByVal source As Type, ByVal message As String, ByVal exception As Exception, ByVal customObject As CustomLogProperties)
Sub Warn(ByVal source As Type, ByVal message As String, ByVal exception As Exception, ByVal customObject As CustomLogProperties)
Sub [Error](ByVal source As Type, ByVal message As String, ByVal exception As Exception, ByVal customObject As CustomLogProperties)
Sub Fatal(ByVal source As Type, ByVal message As String, ByVal exception As Exception, ByVal customObject As CustomLogProperties)
End Interface
Public Class CustomFileLogger
Implements ICustomLog
Private Shared _loggers As Dictionary(Of Type, log4net.ILog) = New Dictionary(Of Type, log4net.ILog)
Private Shared _lock = New Object()
Private Shared _instance As ICustomLog = Nothing
Private Sub New()
End Sub
Public Shared Function GetInstance() As ICustomLog
If _instance Is Nothing Then
_instance = New CustomFileLogger()
End If
Return _instance
End Function
Private Function GetLogger(ByVal source As Type) As log4net.ILog
SyncLock _lock
If CustomFileLogger._loggers.ContainsKey(source) Then
Return CustomFileLogger._loggers(source)
Else
Dim logger As log4net.ILog = log4net.LogManager.GetLogger(source)
CustomFileLogger._loggers.Add(source, logger)
Return logger
End If
End SyncLock
End Function
Private Sub SetCustomLogProperties(ByVal loggingEvent As log4net.Core.LoggingEvent, ByVal customLogObject As CustomLogProperties)
If customLogObject Is Nothing OrElse loggingEvent Is Nothing Then
Return
End If
loggingEvent.Properties(CustomFileLogger.ApplicationNameKey) = customLogObject.ApplicationName
loggingEvent.Properties(CustomFileLogger.RequestKey) = customLogObject.RequestPath
loggingEvent.Properties(CustomFileLogger.ASPSesssionIDKey) = customLogObject.SessionID
End Sub
Private Function GetLoggingEvent(ByVal source As Type, ByVal logger As log4net.ILog, ByVal message As String, ByVal exception As Exception _
, ByVal level As log4net.Core.Level, ByVal customLogObject As Object) As log4net.Core.LoggingEvent
If source Is Nothing OrElse logger Is Nothing Then
Return Nothing
End If
Dim loggingEvent As New log4net.Core.LoggingEvent(source, logger.Logger.Repository, logger.Logger.Name, level, message, exception)
SetCustomLogProperties(loggingEvent, customLogObject)
Return loggingEvent
End Function
Public Sub Debug(ByVal source As Type, ByVal message As String, ByVal exception As Exception, _
ByVal customLogObject As CustomLogProperties) Implements ICustomLog.Debug
Dim logger As log4net.ILog = GetLogger(source)
Dim loggingEvent = GetLoggingEvent(source, logger, message, exception, log4net.Core.Level.Debug, customLogObject)
If loggingEvent IsNot Nothing Then
logger.Debug(message)
End If
End Sub
Public Sub Info(ByVal source As Type, ByVal message As String, ByVal exception As Exception, ByVal customLogObject As CustomLogProperties) Implements ICustomLog.Info
Dim logger As log4net.ILog = GetLogger(source)
Dim loggingEvent = GetLoggingEvent(source, logger, message, exception, log4net.Core.Level.Info, customLogObject)
If loggingEvent IsNot Nothing Then
logger.Logger.Log(loggingEvent)
End If
End Sub
Public Sub Warn(ByVal source As Type, ByVal message As String, ByVal exception As Exception, ByVal customLogObject As CustomLogProperties) Implements ICustomLog.Warn
Dim logger As log4net.ILog = GetLogger(source)
Dim loggingEvent = GetLoggingEvent(source, logger, message, exception, log4net.Core.Level.Warn, customLogObject)
If loggingEvent IsNot Nothing Then
logger.Logger.Log(loggingEvent)
End If
End Sub
Public Sub [Error](ByVal source As Type, ByVal message As String, ByVal exception As Exception, ByVal customLogObject As CustomLogProperties) Implements ICustomLog.Error
Dim logger As log4net.ILog = GetLogger(source)
Dim loggingEvent = GetLoggingEvent(source, logger, message, exception, log4net.Core.Level.Error, customLogObject)
If loggingEvent IsNot Nothing Then
logger.Logger.Log(loggingEvent)
End If
End Sub
Public Sub Fatal(ByVal source As Type, ByVal message As String, ByVal exception As Exception, ByVal customLogObject As CustomLogProperties) Implements ICustomLog.Fatal
Dim logger As log4net.ILog = GetLogger(source)
Dim loggingEvent = GetLoggingEvent(source, logger, message, exception, log4net.Core.Level.Fatal, customLogObject)
If loggingEvent IsNot Nothing Then
logger.Logger.Log(loggingEvent)
End If
End Sub
Private Shared Sub FlushLog()
For Each log In _loggers
Dim rep As log4net.Repository.ILoggerRepository
rep = log.Value
For Each appender As log4net.Appender.BufferingAppenderSkeleton In rep.GetAppenders()
appender.Flush()
Next
Next
End Sub
Private Shared ReadOnly ApplicationNameKey As String = "ApplicationName"
Private Shared ReadOnly RequestKey As String = "RequestPath"
Private Shared ReadOnly ASPSesssionIDKey As String = "SessionID"
End Class
Public Class CustomLogProperties
Public ApplicationName As String
Public RequestPath As String
Public SessionID As String
End Class
Useful Links:
http://logging.apache.org/log4net/
http://haacked.com/archive/2006/09/27/Log4Net_Troubleshooting.aspx
