Nice tool: NHibernate Profiler

A few weeks ago, we started to use a new tool by Ayende: The NHibernate Profiler (currently beta). It is a real-time debugger to debug and improve the usage of NHibernate in our modules.

The NHibernate Profiler provides a lot of valuable (technical and statistical) data on the current activity:

  • SQL statements per session with additional information: Details, stack trace, and alerts. Alerts are some warnings which Ayende explains on his website.
  • A session usage report: Number of entities loaded, entities loaded, duration, etc.
  • A session analysis, e.g. View by Method which displays all SQL statements generated by a particular method of a module.
  • Statistics not only on the sessions, but also on the session factory.

We have used it several times to see, what our modules using NHibernate internally do. In particular, the alert information have been extremely valuable for us.

Obviously, there are still some minor bugs in the beta version of the tool. For example, we get a Use of implicit transactions is discouraged alert although we only have explicit transactions.

Usage

In order to debug an application, the client for monitoring the activity has to be started. This client provides all the information explained above.

The best way to make your application communicate with the client is to use log4net, for the application (and the solution/project) does not need to be changed in any way in this case (provided that you already use log4net in your application). Just add an appender in the log4net.config file and make the required loggers use that appender.

Example:

<appender name="NHibernate.Profiler" type="HibernatingRhinos.NHibernate.Profiler.Appender.NHibernateProfilerAppender, HibernatingRhinos.NHibernate.Profiler.Appender" >
  <sink value="tcp://localhost:22897/NHibernateAppenderLoggingSink" />
</appender>
 
<logger name="NHibernate.Transaction.AdoTransaction">
  <level value="DEBUG"/>
  <appender-ref ref="NHibernate.Profiler"/>
</logger>
<logger name="NHibernate.Loader.Loader">
  <level value="DEBUG"/>
  <appender-ref ref="NHibernate.Profiler"/>
</logger>
<logger name="NHibernate.SQL">
  <level value="DEBUG"/>
  <appender-ref ref="NHibernate.Profiler"/>
</logger>
<logger name="NHibernate.Impl.SessionImpl">
  <level value="DEBUG"/>
  <appender-ref ref="NHibernate.Profiler"/>
</logger>
<logger name="NHibernate.Persister.Entity.AbstractEntityPersister">
  <level value="DEBUG"/>
  <appender-ref ref="NHibernate.Profiler"/>
</logger>

As this example shows, the profiler appender class has to be referenced and a TCP sink for the communication with the client has to be declared. The defined loggers redirect the required information to the profiler. Finally, the DLL containing the profiler appender class has to be stored in the application directory. That’s all. When running the application, the NHibernate activities are monitored by the client.

You can (and due to the licence, you probably must) ship your application without the profiler appender class DLL. There is no need to modify the log4net.config file, though. The profiler appender does not have to be removed. log4net just complains (within its log file), that the particular appender could not be instantiated (because it was not found). If you do not want that message in the log file, you have to ship your application with a log4net.config which does not contain the profiler appender.

Another way to use the profiler is to reference the HibernatingRhinos.NHibernate.Profiler.Appender.dll and make the following call within the application startup:

HibernatingRhinos.NHibernate.Profiler.Appender.NHibernateProfiler.Initialize();

But as this means a change of the application code and requires a reference within the project, I do prefer the first kind of usage. Additionally, the application cannot be shipped when modified in this way. (Remember, you may not ship the profiler appender class DLL with your application.)