Troubleshooting NHibernate

There are many different ways to troubleshoot NHibernate. I mainly use show_sql, log4net and SQL Server Profile.

show_sql

In the configuration of NHibernate, there is a property called show_sql. If you set this to true, NHibernate will output all generated sql to the console.

You enable show_sql by adding the following piece of code to the configuration file.

<property name=”show_sql”>true</property>

To view the output from a unit test, you must select the unit test in the Test Result window and use View Test Result Details.

The unit test’s result window displays the output.

log4Net

If you need more detailed debug information you can use log4net. Log4Net is an open source library that NHibernate uses to log all interesting events. You can use it to log information to a file, the console or both. To use it, you have to add some information to the configuration file. First declare the log4net section.

<configSections>
<section name=”hibernate-configuration” type=”NHibernate.Cfg.ConfigurationSectionHandler, NHibernate” />
<section name=”log4net” type=”log4net.Config.Log4NetConfigurationSectionHandler, log4net”/>
</configSections>

Here is an example how you can configure log4net to write events from NHibernate both to a file and the console. Read more about log4net on the homepage.

<log4net>
<appender name=”NHibernateFileLog” type=”log4net.Appender.RollingFileAppender”>
<file value=”c:\nhibernate2.txt” />
<appendToFile value=”true” />
<rollingStyle value=”Size” />
<maxSizeRollBackups value=”10″ />
<maximumFileSize value=”100KB” />
<staticLogFileName value=”true” />
<layout type=”log4net.Layout.PatternLayout”>
<conversionPattern value=”%d{HH:mm:ss.fff} [%-5p] %c – %m%n” />
</layout>
</appender>
<appender name=”Console” type=”log4net.Appender.ConsoleAppender, log4net”>
<layout type=”log4net.Layout.PatternLayout,log4net”>
<param name=”ConversionPattern” value=”%d{ABSOLUTE} %-5p %c{1}:%L – %m%n” />
</layout>
</appender>
<root>
<level value=”DEBUG”/>
<appender-ref ref=”Console” />
</root>
<logger name=”NHibernate” additivity=”false”>
<level value=”DEBUG”/>
<appender-ref ref=”NHibernateFileLog”/>
<appender-ref ref=”Console” />
</logger>
</log4net>

You also have to initialize log4net from the application

//Start Log4Net
log4net.Config.XmlConfigurator.Configure();

The output now contains much more information about the internal works of NHibernate:

SQL Server Profiler

SQL Server Profiler can be very useful when you line step an application and want to view each database call NHiberante makes. In this way you can follow how NHibernate flushes changes to the database and manages caching. SQL Server Profiler can be started from SQL Server Management Studio.

To use it your user must be a member of sysadmin.

When the Profiler is started, you can create a new trace and view each database call NHibernate makes.

Peter

Leave a Reply

Your email address will not be published. Required fields are marked *

This site uses Akismet to reduce spam. Learn how your comment data is processed.