Logging NHibernate SQL commands to debug window

I know there are advanced tools like SQL Server Profiler and NHibernate Profiler but often I want to see NHibernate queries just in debug window to have overview of what’s going on. It’s specially important when improving some legacy application where previous developers had not much idea how NHibernate works. Here’s the simple solution I’m using to get SQL generated by NHibernate to Visual Studio debug window.

Using SQL logging interceptor

NHibernate supports interceptor classes to tweak some internals of mapper. There’s IInterceptor interface available and dummy EmptyInterceptor class we can use as a base class for our own interceptors if we don’t want to implement the whole interface. There’s one interesting method – OnPrepareStatement() that has argument for SQL string.

Based on this I wrote the following interceptor class.

public class SqlDebugOutputInterceptor : EmptyInterceptor
{
    public override SqlString OnPrepareStatement(SqlString sql)
    {
        Debug.Write("NHibernate: ");
        Debug.WriteLine(sql);
 
        return base.OnPrepareStatement(sql);
    }
}

SqlString contains also information about parameters but this far I have had no need to print parameters out.

Adding SQL logging interceptor to ISession

This is how I wire interceptor to ISession in my code (more tips and tricks for NHibernate with ASP.NET Core are available in my blog post NHibernate on ASP.NET Core).

var sessionFactory = configuration.BuildSessionFactory();
 
services.AddSingleton(sessionFactory);       
services.AddScoped(factory => {
 
#if(DEBUG)
    var interceptor = new SqlDebugOutputInterceptor();
    var session = sessionFactory.WithOptions()
                                .Interceptor(interceptor)
                                .OpenSession();
#else
    return sessionFactory.OpenSession();
#endif
    return session;
 
});

When running application in debug mode I can see queries in Debug window like shown on the following screenshot.

Warning! This solution doesn’t work with stateless sessions because interceptors are not supported with stateless sessions. Usually I make queries run using ISession and then switch to  IStatelessSession if needed.

Wrapping up

Although my interceptor is cheap and dirty piece of code, it works like charm and sings me all lines of SQL that NHibernate is going to run. What’s best – I don’t have to include log4net to my projects to see SQL commands and all SQL is written out without any additional efforts. Those who need to do advanced or more professional debugging or profiling should still use normal tools for this.