Peterson's Ponderings

Log4Net versus Enterprise Library 2.0 Logging Application Block (Part II - Database Logging)

In my last blog I performed some head-to-head benchmarks of the new Microsoft Enterprise Library 2.0 Logging Application Block versus the free SourceForge Log4Net assembly when logging to a text file.  In this post I will finish the comparison with the results of using the loggers to log to a SQL Server 2000 database.

Part II - Database Logging

The basis of my test remains the same as outline in Part I - File Logging, including logging the same data with each entry, except now the log entries will be written to a SQL Server 2000 database running on the same machine as the WinForm test application.  To perform this test I first had to set up a new database containing a single table to hold the log entries.  I also created a stored procedure which will be called from the loggers to insert the entries.  Since both loggers can be configured to indicate what stored procedure to execute they will both call into the same procedure when they are run.  To setup for the test I needed to adjust settings in the app.config file for both loggers and make a small code change to the Logging.Database project of the Enterprise Library (more on that later).

To get Log4Net to log to the database I only needed to make several app.config changes.  First, I removed the appender for the text file format and added the ADONetAppender configuration to match my stored procedure:

<appender name="AllTypesADONetAppender_SqlServer" type="log4net.Appender.ADONetAppender">

<param name="ConnectionType" value="System.Data.SqlClient.SqlConnection, System.Data, Version=1.0.3300.0, Culture=neutral, PublicKeyToken=b77a5c561934e089"/>

<param name="ConnectionString" value="Server=(local);Database=CompareLog;user=sa;pwd=--removed--"/>

<param name="CommandType" value="StoredProcedure"/>

<param name="CommandText" value="LogInsert"/>

<param name="BufferSize" value="1"/>

<param name="Parameter">

<param name="ParameterName" value="@CREATEDATE"/>

<param name="DbType" value="DateTime"/>

<param name="Layout" type="log4net.Layout.PatternLayout">

<param name="ConversionPattern" value="%d{yyyy'-'MM'-'dd HH':'mm':'ss'.'fff}"/>

</param>

</param>

<param name="Parameter">

<param name="ParameterName" value="@TICKCOUNT"/>

<param name="DbType" value="Int32"/>

<param name="Layout" type="log4net.Layout.PatternLayout">

<param name="ConversionPattern" value="%P{tick_count}"/>

</param>

</param>

<param name="Parameter">

<param name="ParameterName" value="@LOGLEVEL"/>

<param name="DbType" value="String"/>

<param name="Size" value="10"/>

<param name="Layout" type="log4net.Layout.PatternLayout">

<param name="ConversionPattern" value="%p"/>

</param>

</param>

<param name="Parameter">

<param name="ParameterName" value="@MACHINENAME"/>

<param name="DbType" value="String"/>

<param name="Size" value="255"/>

<param name="Layout" type="log4net.Layout.PatternLayout">

<param name="ConversionPattern" value="%X{machine}"/>

</param>

</param>

<param name="Parameter">

<param name="ParameterName" value="@THREADID"/>

<param name="DbType" value="String"/>

<param name="Size" value="25"/>

<param name="Layout" type="log4net.Layout.PatternLayout">

<param name="ConversionPattern" value="%t"/>

</param>

</param>

<param name="Parameter">

<param name="ParameterName" value="@SOURCE"/>

<param name="DbType" value="String"/>

<param name="Size" value="255"/>

<param name="Layout" type="log4net.Layout.PatternLayout">

<param name="ConversionPattern" value="%c"/>

</param>

</param>

<param name="Parameter">

<param name="ParameterName" value="@METHOD"/>

<param name="DbType" value="String"/>

<param name="Size" value="50"/>

<param name="Layout" type="log4net.Layout.PatternLayout">

<param name="ConversionPattern" value="%M"/>

</param>

</param>

<param name="Parameter">

<param name="ParameterName" value="@CONTEXT"/>

<param name="DbType" value="String"/>

<param name="Size" value="255"/>

<param name="Layout" type="log4net.Layout.PatternLayout">

<param name="ConversionPattern" value="%x"/>

</param>

</param>

<param name="Parameter">

<param name="ParameterName" value="@MESSAGE"/>

<param name="DbType" value="String"/>

<param name="Layout" type="log4net.Layout.PatternLayout">

<param name="ConversionPattern" value="%m"/>

</param>

</param>

</appender>

<!-- Rolling Log File appender configuration that all loggers can use -->

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

<param name="File" value="teststub.log"/>

<param name="AppendToFile" value="true"/>

<param name="MaxSizeRollBackups" value="30"/>

<!-- Default is 10MB anyway...

-->

<param name="RollingStyle" value="Date"/>

<param name="StaticLogFileName" value="false"/>

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

<!-- <param name="Header" value="#TIME TICK_COUNT THREAD_ID LOG_LEVEL MACHINE_NAME SOURCE METHOD CONTEXT MESSAGE\r\n" /> -->

<param name="ConversionPattern" value="%d{yyyy'-'MM'-'dd HH':'mm':'ss'.'fff}|*|%P{tick_count}|*|%-5p|*|%X{machine}|*|%t|*|%c|*|%M|*|%x|*|%m|*|%n"/>

</layout>

</appender>

I also needed to enter a listener for the Logging Application Block.  The listener entry was:

<add databaseInstanceName="Server=(local);Database=CompareLog;user=sa;pwd=--removed--"

writeLogStoredProcName="LogInsert" addCategoryStoredProcName="AddCategory"

formatter="Text Formatter" listenerDataType="Microsoft.Practices.EnterpriseLibrary.Logging.Database.Configuration.FormattedDatabaseTraceListenerData, Microsoft.Practices.EnterpriseLibrary.Logging.Database, Version=2.0.0.0, Culture=neutral, PublicKeyToken=null"

traceOutputOptions="None" type="Microsoft.Practices.EnterpriseLibrary.Logging.Database.FormattedDatabaseTraceListener, Microsoft.Practices.EnterpriseLibrary.Logging.Database, Version=2.0.0.0, Culture=neutral, PublicKeyToken=null"

name="SimpleTextFormat" />

The Logging Application Block comes with a table format and stored procedure that matches the FormattedDatabaseTraceListener class in the Logging.Database project.  Unfortunately, the table format and data it stores doesn't match what I want to log so I would need to customize the existing FormattedDatabaseTraceListener code or make my own listener - either way pointed to a code change which wasn't as nice as just changing configuration.  First off I had to find this trace listener which seemed to be hidden in a separate project in a sub-directory beneath the main Logging Application Block project, this isn't very obvious as all the other formatters are in the Logging Application Block project except this one.  Once I found the class I decided to change some lines of the existing code to match the stored procedure parameters of my procedure.  To do this I found the ExecuteWriteLogStoredProcedure overloaded methods and changed the parameters to be added as:

db.AddInParameter(cmd, "CreateDate", DbType.DateTime, DateTime.Now);

db.AddInParameter(cmd, "TickCount", DbType.Int32, 1);

db.AddInParameter(cmd, "LogLevel", DbType.String, "Verbose");

db.AddInParameter(cmd, "MachineName", DbType.String, logEntry.MachineName);

db.AddInParameter(cmd, "ThreadID", DbType.String, logEntry.Win32ThreadId);

db.AddInParameter(cmd, "Source", DbType.String, logEntry.ExtendedProperties["Source"].ToString());

db.AddInParameter(cmd, "Method", DbType.String, logEntry.ExtendedProperties["Method"].ToString());

db.AddInParameter(cmd, "Context", DbType.String, "");

db.AddInParameter(cmd, "Message", DbType.String, logEntry.Message);

I also had to comment out a line of code that was doing a second insert of some category data which I had no need for with my log output.  This extra call was in the ExecuteStoredProcedure method where the code calls ExecuteAddCategoryStoredProcedure.  When I was in this code I noticed it was using a database transaction since it was originally performing multiple execute calls to the database and I could have removed it since I only needed a single call per log entry, but I decided to leave it so that I could run with the code as close to the original as possible.

The (Unofficial) Results

Now it was time to run the tests.  Using the same WinForm application and format described in Part I - File Logging three independent test runs were performed.

Test Run 1

Test Run 2

Test Run 3

It looks like the Logging Application Block wins again.  It's still important to note that this version of Log4Net was written for the 1.1 version of the .NET Framework so there maybe a performance change when a newer version becomes available that is made for the .NET 2.0 Framework.  The one thing I didn't like about the new Enterprise Library was that I had to change code to support my database stored procedure, it would have been nice if it all could have been configured in the app.config like Log4Net does.  I may look into making my own formatter for the database that is purely configurable before I integrate this into any applications.