Originally posted at 12/3/2010

One of the things that are coming to NH Prof is more smarts at the analysis part. We now intend to create a lot more alerts and guidance. One of the new features that is already there as part of this strategy is detecting bad ‘like’ queries.

For example, let us take a look at this

This is generally not a good idea, because that sort of query cannot use an index, and requires the database to generate a table scan, which can be pretty slow.

Here is how it looks like from the query perspective:

And NH Prof (and all the other profilers) will now detect this and warn about this.

In fact, it will even detect queries like this:

One of the most annoying things about doing the TekPub episodes is finding the right session, because NH Prof will detect any session opening. This means that it usually looks like this:

Which also means that it is pretty hard to figure out. I got annoyed enough with that to add a specific filter to filter all of those in one shot (you could already do it, but it meant creating several filters):

Which results in a much better experience:

I mentioned before that exporting reports (so you can mail them around) is something that I would really like to do. In fact, I decided to put it out as a challenge, and I got some really great responses.

Josh Perry has been able to flat out amaze me with a solution that was at once simple, elegant and beautiful. It is an HTML report that contains all the styling inline (so it supports emailing it around, for example, to the DBA) but it also has some java script smarts around it that make it behave like the real application.

As a matter of fact, I have added the exported version as a “live demo” for NH Prof.

I am quite happy with this. You can export your NH Prof load using File > Export, giving you a single HTML that is easily achievable, mailable, etc.

 Check it out.

Well, I was demoing how easy it is to add new features to NH Prof in a user group in JAOO today, and tomorrow I am doing my OR/M += 2 talk. Part of the things that I want to show is NHibernate Search, but the demo doesn’t really work unless I can point to NH Prof and show what is going on there.

I now consider output results to the console to be so 2005.

Here is the code that I am using for this post:

using (var s = factory.OpenSession())
{
    var posts = NHibernate.Search.Search.CreateFullTextSession(s)
        .CreateFullTextQuery<Post>("Title:NHibernate User.Name:ayende")
        .List<Post>();

    NHibernate.Search.Search.CreateFullTextSession(s)
        .CreateFullTextQuery<Post>("Title:NHibernate User.Name:ayende")
        .SetMaxResults(10)
        .List<Post>();

    foreach (var post in posts)
    {
        Console.WriteLine(post.Title);
    }
}

I had to make a small modification to NHibernate Search, to output the right information (which means that you can make this work with r1044 or up), but here is the result:

Notice that you can get not only the actual Lucene query text, but you also get the query duration and the number of returned results. The next query is NHibernate Search actually hitting the database to load the managed entities, after hitting the Lucene index to perform the actual search.

We can also generate some warnings on top of Lucene! As you can see here, we detect unbounded queries:

If you do specify a maximum number of entities to return, we are going to reflect that in the query directly:

We can also tell you if your Lucene index is out of date with respect to the database:

Sweet, and is currently warming up in the oven, build 488 should have it.

One common request for NH Prof is that we will support multiple session factories. This turn out to be a bit more problematic than it would seems, mostly because NHibernate doesn’t currently output this relation in any way that NH Prof can access.

But here is the first step along the way, NH Prof can now report statistics from multiple session factories.

It is very common to use NH Prof as.. well, a profiler :-) That is, we execute a piece of code, look at the profiler output, and try to improve it.

The problem is that when you are working on big applications, a single request may perform quite a bit of work. That can make it harder to figure out the changes between the first session and the optimized session.

In order to make this easier, I added a feature that allows you to compare two sessions, see what statements were added, what were removed and what matches.

The UI to show it is only temporary, as you can probably guess, I am still considering some variation of that vs. a flat list with color codes or icons to mark matching, added and removed.

This came up as a request yesterday, and I spent a few minutes making it happen today.

NH Prof can now capture the output of Schema Export and Schema Update:

NHibernate sessions are not thread safe, and attempting to use them in multiple threads requires careful synchronization. It is generally better to consider a session only useful within the thread that created it.

There are valid scenarios for cross thread session usage (background loading with careful sync, multi request spanning session), but the invalid scenarios are far more common.

Let us take a look at the following code:

public class CrossThreadSession : IScenario
{
	public void Execute(ISessionFactory factory)
	{
		using(var session = factory.OpenSession())
		{
			var @event = new ManualResetEvent(false);

			ThreadPool.QueueUserWorkItem(state =>
			{
				using(var tx = session.BeginTransaction())
				{
					session.Get<Blog>(1);

					tx.Commit();
				}

				@event.Set();
			});

			@event.WaitOne();
		}
	}
}

If you’ll try to execute it with NH Prof listening, you are going to see this:

NH Prof is properly detecting and warning that we are using a single session in multiple threads.

I did mention that there are valid scenarios for that, so you can either just tell NHibernate to ignore this specific alert by clicking the link, or disable this alert completely if you are doing cross thread session usage extensively and you know it to be safe:

Nice enough feature, for about 30 minutes of work. I love working on NH Prof code base.

And just for fun, here is the test for this:

public class DetectCrossThreadSessionUsage : IntegrationTestBase
{
	[Fact]
	public void CanDetectCrossThreadSessionUsage()
	{
		ExecuteScenarioInDifferentAppDomain<CrossThreadSession>();

		var first = model.Sessions.First();

		Assert.Equal(1, first.Statistics.NumberOfStatements);
		Assert.Equal(2, first.Statistics.NumberOfTransactionsStatements);
		foreach (var statement in first.StatementsModel.Statements)
		{
			Assert.True(
				statement.Alerts.Any(alert => alert.HelpTopic == "CrossThreadSessionUsage"));
		}
	}
}

And for additional fun, here is the code to implement the feature:

public class CrossThreadSessionUsage : AbstractStatementProcessor
{
	public override void AfterAttachingToSession(SessionInformation session, TransactionStatement transaction)
	{
		AfterAttachingToSession(session, (SqlStatement)transaction);
	}

	public override void AfterAttachingToSession(SessionInformation sessionInformation, SqlStatement statement)
	{
		if (sessionInformation.SessionId.IdentifierId.ThreadId ==
			statement.SessionId.IdentifierId.ThreadId)
			return;
		statement.AcceptAlert(AlertInformation.CrossThreadSessionUsage());
	}
}

I did have to change some of the innards so NH Prof will track both the session id and the thread id, but that was quite easy to do and the only thing that actually took any time at all.

I noticed the lack when I was teaching the Core NHibernate course. While NH Prof was able to detect loading of an entity from the second level cache and the loading of query from the query cache, it wouldn’t show when we were loading a collection from the collection cache.

That was actually quite easy to fix :-)

Take a look:

This feature is now available on Build 277 and up.

Have fun, and happy cache tracing :-)

The feature for the day is detecting & notifying the user about NHibernate errors, warning messages and other things that require human attention. As a simple example, let us take this common error:

public class ErrorSavingToDatabase : IScenario
{
    public void Execute(ISessionFactory factory)
    {
        using(var s = factory.OpenSession())
        using(var tx = s.BeginTransaction())
        {
            s.Save(new Blog
            {
                Title = "Will error",
                CreatedAt = DateTime.MinValue// cause error
            });

            tx.Commit();
        }
    }
}

Which will give us:

There are quire a few things going on in here.

First, we can see that NH Prof correctly detected the statement that caused an error and marked it as failed. We can also see the next statement, which give us the actual error details about the actual issue. This means that we have direct access to everything, and can usually understand what is going on very easily, by seeing both the error and the statement that caused it.

This isn’t actually limited to issues that are being raised from exceptions executing SQL queries, there are several cases where NHibernate itself needs to let you know about an issue. In those cases, the profiler will detect and display the message and expose it to you in a visible manner.