Sunday, May 08, 2011

Generate better NHibernate logs

I will show you in this post two tricks you can do to enhance and add value to your nhibernate logs.
Format Sql
This is widely know trick, you can add a configuration setting to your hibernate.cfg.xml, app.config or web.config as follow:

<property name="hibernate.format_sql" value="true" />

or you can simply do it in code:

config.DataBaseIntegration(db => db.LogFormatedSql = true)
with this trick you will get nicely formated sql in your logs files.

Logging the session identifier
All nice, we have a bunch of sql logs, but we don’t know which queries belongs to which sessions. This might be useful when you are debugging an application with multiples threads or requests.
I found this trick inside NHibernate, the easy way I found so far is to add a log4net appender like this one:

<appender name="NHibernateAppender" type="log4net.Appender.RollingFileAppender">
  <appendToFile value="true"/>
  <datePattern value="yyyyMMdd"/>
  <file value="./logs/NHibernate.log"/>
  <layout type="log4net.Layout.PatternLayout">
    <conversionPattern value="%date Session id: %property{sessionId} - %message%newline"/>
  </layout>
  <rollingStyle value="Date"/>
</appender>

See the %property{sessionId} in the conversion pattern?
Well, in order to log something there you need to do two steps.
Add a class like this one:

public class SessionIdCapturer
{
    public override string ToString()
    {
        return SessionIdLoggingContext.SessionId.ToString();
    }
}

Read more: NHibernate forge