Posts tagged ‘log4net’

Audit Trail with NHibernate Using a Custom log4net Appender

I was originally using NHibernate event listeners to do an audit trail, and I might post on that some day. My issue with that was, you get your entities when intercepting. You can save off what’s going with your entites, but I really wanted to save the actual query that NHibernate generates. I wanted to log the same thing that NHProf shows; the actual SQL query.

The way to do this is to create a custom log4net appender that inserts info into your audit table. You need to hook into the NHibernate logs to do this. This is how I did it.

First, create the audit table.

CREATE TABLE [dbo].[Audit]
(
[Id] INT NOT NULL IDENTITY,
[User] NVARCHAR( 100 ) NOT NULL,
[Trail] NVARCHAR( MAX ) NOT NULL,
[Created] DATETIME NOT NULL
)
ALTER TABLE [dbo].[Audit]
ADD CONSTRAINT [PK_Audit_Id]
PRIMARY KEY (Id)
view raw Audit.sql hosted with ❤ by GitHub

Next, create the log4net appender.

public class NHibernateAuditAppender : AppenderSkeleton
{
private static IKernel kernel;
protected override void Append( LoggingEvent loggingEvent )
{
#if !DEBUG
if( loggingEvent.RenderedMessage.StartsWith( "SELECT" ) )
{
return;
}
#endif
var session = kernel.Get<ISession>();
var audit = new Audit
{
Created = DateTime.UtcNow,
Trail = loggingEvent.RenderedMessage,
User = Thread.CurrentPrincipal.Identity.Name
};
session.Save( audit );
}
}
view raw gistfile1.cs hosted with ❤ by GitHub

I am using Ninject to get the current NHibernate session being used. All that you really need to know is, get a session from the session factory. The Append method passes in a LoggingEvent. The data that you need from here is the RenderedMessage. The is the formatted message that is to be logged. Create an audit object and save it off to the database. This assumes that you have a mapping set up for for the Audit object to the Audit table. Next, we need to actually hook into the NHibernate logs.

public class NHibernateAuditAppender : AppenderSkeleton
{
private static IKernel kernel;
protected override void Append( LoggingEvent loggingEvent )
{
#if !DEBUG
if( loggingEvent.RenderedMessage.StartsWith( "SELECT" ) )
{
return;
}
#endif
var session = kernel.Get<ISession>();
var audit = new Audit
{
Created = DateTime.UtcNow,
Trail = loggingEvent.RenderedMessage,
User = Thread.CurrentPrincipal.Identity.Name
};
session.Save( audit );
}
public static void RegisterAppender( IKernel kernel )
{
NHibernateAuditAppender.kernel = kernel;
var repository = (Hierarchy)LogManager.GetRepository();
var appender = new NHibernateAuditAppender { Name = "NHibernateAuditAppender" };
var logger = (Logger)repository.GetLogger( "NHibernate.SQL" );
logger.Level = Level.Debug;
logger.Additivity = false;
logger.AddAppender( appender );
appender.ActivateOptions();
repository.Configured = true;
}
}

The RegisterAppender static method was added. Here we get the NHibernate.SQL logger. This is the logger that outputs the actual query that NHibernate generates. Add our appender to the logger, and it’s basically done. You can lookup the other details if you like. :)