Logo

NHibernate

The object-relational mapper for .NET

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();
    }
}

Add the following code in some place at the application initialization:

ThreadContext.Properties["sessionId"] = new SessionIdCapturer();

That is all! I found this code inside a nhibernate test.. it is something not very known.

After doing so, your logs will look like:

2011-05-05 18:35:59,899 Session id: 5e172068-5064-44b6-bf96-99362ca05c46 - 
    SELECT
        myFoo0_.AccountId as AccountId3_0_,
        myFoo0_.Name as Name3_0_,
        myFoo0_.Version as Version3_0_ 
    FROM
        MyFoo myFoo0_
    WHERE
        myFoo0_.AccountId=@p0;
    @p0 = 1 [Type: Int32 (0)]

Another way to have this information (and much more) is to use the nhprof tool.


Posted Thu, 05 May 2011 12:57:43 PM by jfromainello
Filed under: logging

comments powered by Disqus
© NHibernate Community 2024