One of the goals that I set for myself with the NHibernate Profiler is to be able to run on unmodified NHibernate 2.0. The way that I do that is by intercepting and parsing the log stream from NHibernate.

NHibernate logging is extremely rich and detailed, so anything I wanted to do so far was possible. I am pretty sure that there would come a time when a feature would require more invasive approaches, running profiler code in the client application to gather more information, but for now this is enough.

I did run into several problems with logging interception. Ideally, I want this to happen on the fly, as we go. So I really want to get the real time logging stream. The problem is how to do so. I started with the UdpAppender, but that doesn't work on Vista in the released version. Remoting Appender is what I am using now, but it has one critical issue, it is an async appender, so message can (and do) appear out of order.

The message order is pretty important to the profiler. It can deal with that, but it would lead to surprising results. So that one is out as well.

The only other appender that comes out of the box with log4net and can be used remotedly is the telnet appender, which is next on the list for exploring. It does mean that the profiler has to connect to the application, rather than the other way around, which can be a problem.

I built an appender that fit my needs, and I am using it now to test how the profiler works, but before starting to deal with the telnet appender, I thought it would be a good time to ask.

How important is "running on unmodified NHibernate" is?

I am not talking about having a profiler build of NHibernate, I am talking about doing things like using the profiler appender, or registering an HttpModule.

It is by no means the final UI, it  was just thrown together by me in about half an hour, just to show how things are working.

I am also using it now to track what is going on in an application that I am working on.

I just finished writing the final test for the basic functionality that I want for NHibernate Profiler:

        [Test]
        public void SelectBlogById()
        {
            ExecuteScenarioInDifferentProcess<SelectBlogByIdUsingCriteria>();
            StatementModel selectBlogById = observer.Model.Sessions.First()
                .Statements.First();
            const string expected = @"SELECT this_.Id             as Id3_0_,
       this_.Title          as Title3_0_,
       this_.Subtitle       as Subtitle3_0_,
       this_.AllowsComments as AllowsCo4_3_0_,
       this_.CreatedAt      as CreatedAt3_0_
FROM   Blogs this_
WHERE  this_.Id = @p0

";
            Assert.AreEqual(expected, selectBlogById.Text);
        }

I actually had to invest some thought about the architecture of testing this. This little test has a whole set of ideas behind it, about which I'll talk about at a later date. Suffice to say that this test creates a new process, start to listen to interesting things that are going on there (populating the observer model with data).

Another interesting tidbit is that the output is formatted for readability. By default, NHiberante's SQL output looks something like this:

SELECT this_.Id as Id3_0_, this_.Title as Title3_0_, this_.Subtitle as Subtitle3_0_, this_.AllowsComments as AllowsCo4_3_0_, this_.CreatedAt as CreatedAt3_0_ FROM Blogs this_ WHERE this_.Id = @p0

This is pretty hard to read the moment that you have any sort of complex conditions.

This is speculative at the moment, just to be clear.

I am thinking about creating a profiler for NHibernate. This came out of the common need to actually get a good view about what is going on with NHibernate.

This is intended to be a commercial project.

I have a feature set in mind, but I would rather hear from you if you think that it is a tool that you would use (and buy) and what kind of features do you expect such a tool to have?

And, to forestall the nitpickers, I am well aware of SQL Profiler.