NHibernate and log4net

Here’s a quick trick for people using NHibernate and log4net within their .NET applications. (…and if you’re not using NHibernate or log4net, you should seriously think about it!)

Add the following to your log4net configuration to find out what’s going on inside NHibernate:

  <logger name="NHibernate">
    <level value="DEBUG" />
  </logger>
  <logger name="NHibernate.SQL">
    <level value="DEBUG" />
  </logger>

As those kind folks at NHibernate have already set up the loggers behind the scenes, everything just works. The SQL logger is especially useful as it’ll show you explicitly which SQL statements are being generated by NHibernate. You can adjust the levels of NHibernate logging independently of your normal application logging, which is useful as the NHibernate logs tend to be pretty verbose.

The full configuration will look something like this:

<log4net>
  <appender name="TraceAppender" type="log4net.Appender.TraceAppender" >
    <layout type="log4net.Layout.PatternLayout">
      <param name="ConversionPattern" value="%d %-5p- %m%n" />
    </layout>
  </appender>
  <appender name="RollingFileAppender" type="log4net.Appender.RollingFileAppender">
    <file value="Application.log"/>
    <appendToFile value="true"/>
    <rollingStyle value="Date"/>
    <datePattern value="yyyy-MM-dd'.log'"/>
    <layout type="log4net.Layout.PatternLayout">
      <conversionPattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline"/>
    </layout>
  </appender>
  <root>
    <level value="DEBUG"/>
    <appender-ref ref="TraceAppender"/>
    <appender-ref ref="RollingFileAppender"/>
  </root>
  <logger name="NHibernate">
    <level value="ERROR" />
  </logger>
  <logger name="NHibernate.SQL">
    <level value="ERROR" />
  </logger>
</log4net>