7 Comments

image_thumb[4]By following this tutorial you can enable your ASP.NET MVC application to output the NHibernate’s SQL-queries into the web browser, in real-time. If you have an existing application, no coding is required, this is all about configuration.

Background

When developing any application which uses NHibernate, at some point you will probably want to see the SQL-queries executed by the ORM. When that need arises, you have multiple options. You can:

  1. trace at the database level,
  2. use NHProf or
  3. use log4net to output the queries into a text file.

To just name a few options. Or, as this tutorial shows, it is possible to see the executed SQL-queries with a web browser, in real-time, by just using your ASP.NET MVC application. This can be done by combining NHibernate with log4net and Glimpse.

Glimpse

Glimpse can be described as the “Firebug for the server-side”. It’s an application which shows interesting details about your ASP.NET MVC applications, like the routes, executed methods and requested views. After configuration, there’s nothing else to do: Just use your website and watch the Glimpse’s UI to see how your application behaves. The Glimpse’s UI is divided between different tabs so it is easy to use and navigate.image_thumb[5]

One of the tabs inside the Glimpse is called Trace. This contains all the trace outputs which were written by your application when a page was requested. If you call Trace.WriteLine (“Hello”) in your controller, it will be shown on this tab. This tab is one of the easiest extension points of the Glimpse.

For more information on Glimpse check out the links in the end of this article.

Implementation

Getting NHibernate’s SQL-queries into the Glimpse is done by configuring the log4net to write all the NHibernate’s logs using the TraceAppender.Nothing else is required. If something is written to the Trace, Glimpse will show it.

If you have an existing ASP.NET MVC 3 application which already uses NHibernate and log4net, configuring the Glimpse to show the SQL-queries is just a matter of couple copy-pastes.

1. Installing Glimpse

You need to have Glimpse installed and configured. Installation is easily done with Nuget: Install_package Glimpse

2. Configuring log4net

The web.config’s log4net-section must be changed so that NHibernate’s logs are written with a TraceAppender:

    <appender name="TraceAppender" type="log4net.Appender.TraceAppender">
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%thread] %-5level %logger [%property{NDC}] - %message%newline" />
      </layout>
    </appender>

    <logger name="NHibernate.Loader">
      <level value="ALL" />
      <appender-ref ref="TraceAppender" />
    </logger>

3. Enabling the Glimpse

Point your browser to http://yourapp:port/Glimpse/Config and click the “Turn Glimpse On”. Now when you browse back into the homepage, you should see the Glimpse’s icon on the bottom right corner and clicking it will expand the UI.

And you’re all set.

It’s now just matter of using your application and watching the Trace-tab to see all the SQL-queries executed by the NHibernate.

If you don’t have an existing ASP.NET MVC 3 application, you can test this out by downloading a sample project from the GitHub https://github.com/mikoskinen/blog. The test project has log4net, (Fluent) NHibernate and Glimpse all configured and ready and it doesn’t require a database to run. All you have to do is to visit the http://site:port/glimpse/config to enable the Glimpse.

Tweaking the output

In my example I’m using NHibernate.Loader-logger. This results in a quite verbose output:

image_thumb[6]

I like it because it provides me information on the performance of the SQL queries. If you want to include just the executed SQL-queries, you can make this happen by changing the NHibernate.Loader to NHibernate.SQL in your web.config:

    <logger name="NHibernate.SQL">
      <level value="ALL" />
      <appender-ref ref="TraceAppender" />
    </logger>

image_thumb[8]

Or, if you want more information, changing the NHibernate.SQL to NHibernate will log everything:

image_thumb[9]

Links

The original idea was provided by Sam Saffron’s blog post “A day in the life of a slow page at Stack Overflow”.