NHibernate Profiler: Minute 15

I’ve said this before and I’ll say it again: Lord Tunderin’ Jayzus!

The target this time is NHibernate Profiler. As of this moment, I’ve had it "installed" for all of fifteen minutes and I’ve already reduced the query count of one page from 205 to 1. Such is the story you will read about today. I suspect typing it out will take longer than it took me to optimize the page I’m about to describe.

By the way, I put "installed" in quotes because installing the application consists of unzipping it to a folder of your choosing. Means you need to set up shortcuts on your own but I like the minimalist approach myself.

The app I’ve already described. To sum up, Surveyors have many MonumentAssignments. Here is the (original) Fluent NHibernate mapping for review:

public SurveyorMap() {
    WithTable("Surveyor");

    Id(x => x.ID, "SurveyorID")
        .WithUnsavedValue(0)
        .GeneratedBy.Identity();

    // Boring stuff

    HasMany( x => x.Monuments )
        .Cascade.AllDeleteOrphan( )
        .WithKeyColumn( "SurveyorID" );
}

Notice how I put (original) in brackets there. That’s what we in the legitimate journalism field like to call "foreshadowing" (or, more likely, foreboding).

The page in question provides a list of Surveyors. First name, last name, commission number. That’s it. It isn’t displaying anything from the Monuments collection. (See? More foreshadowing.)

So it was much to my surprise when I profiled this application that it outlined a total of 205 SQL statements for 202 Surveyors. "Odd" says I, and I proceeded to work my way through NHibernate Profiler to see what it can tell me.image

Quite a bit as it turns out. The screenshot at right shows a summary of the alerts. The one that jumped out at me was 199 SELECT N+1 alerts.

The ellipsis took me to this page which was pretty helpful. It says if I’m going to iterate over the collection, I should consider eager loading. Well, you won’t accuse me of not being eager so that’s what I did. My GetAll method now looked like this:

public IList GetAll()
{
    var criteria = DetachedCriteria.For( );
    criteria.SetFetchMode( "Monuments", FetchMode.Eager );
    return criteria.GetExecutableCriteria( Session ).List( );
}

That baby reduced my query count from 205 to 3. And my alerts consisted of two "Use of implicit transactions discouraged" and one "Unbounded result set". "Acceptable" says I!

But then something occurred to me. I’m not using the Monuments collection in this page. Why is it even retrieving them? Maybe I *am* being too eager after all…

As it turns out, the HasMany call in my map doesn’t retrieve the Monuments lazily by default as I had expected it would. So with a flourish of my hand, I remedy that:

public SurveyorMap() {
    WithTable("Surveyor");

    Id(x => x.ID, "SurveyorID")
        .WithUnsavedValue(0)
        .GeneratedBy.Identity();

    // Boring stuff

    HasMany( x => x.Monuments )
        .Cascade.AllDeleteOrphan( )
        .WithKeyColumn( "SurveyorID" )
        .LazyLoad();
}

I also reverted my previous eager change because it was no longer necessary and poof! I am now down to a single SQL query for the page, which is as it should be. I still prefers that I limit my result set and put things in an explicit transaction so I’ll be tackling those shortly. But for now, I’m agog, AGOG I TELL YOU!!1!

Granted, exposing my ignorance is not exactly an Olympic event. But just this morning, I made some facetious remark (no, it’s true) that I wanted to make an application that was wildly successful in spite of itself. Several people responded with variations of "is there any other kind?" Given what I know of its creator, I’m hoping this is an exception: an application that is wildly successful because it fills a niche *and* because it is reliable and well-built.

That said, Ayende, if you’re reading, it’d be nice if you could clear individual sessions from the list…

Kyle the Reduced

This entry was posted in NHibernate. Bookmark the permalink. Follow any comments here with the RSS feed for this post.
  • Kyle Baley

    Jeremy,

    I was going to go that route too in my last comment but I don’t know that it works in the large scale. As an individual consultant, yes, I think it’s easy to justify with a simple cost/benefit analysis. But economics is a funny thing. I suspect I’d save more time with VisualSVN, yet that one is $50. If I have only a certain amount of dollars to spend, which would I go for.

    Also, if VisualSVN doubled its price, would they lose less than half their customers? It’s a bit of a guessing game to figure out the optimal price, trying to balance how many customers you’ll gain by dropping it or how many you’ll lose by raising it. The amount of time and effort that are put into it are only a very small fraction, in my opinion.

    And we haven’t covered the topic of *whose* time we’re saving by buying it.

  • Jeremy Gray

    @Kyle – I suppose it is a question of how much time similar optimization would have taken without NHProf at hand, what that time is worth to you, and just how often you run into such situations. I did similar math at one point in the past regarding R# and the ROI was so quick that before long it was almost as if JetBrains was paying ME to buy it! :)

    That said, I am semi-serious. There are tools, like these, that go beyond paying for themselves to the point of actually (if indirectly) making us money when employed correctly. :D

    As soon as my consulting work takes me back towards database land, as it surely will (it still feels weird to have been working on a contract for more than a year that involves nary a database), I’ll be grabbing a license for this for sure.

  • Kyle Baley

    Yeah, I think you’re right. US$210-280 seems steep to me. But then again, if it dropped to $70, would he get 3-4 times more people buying it? That’s not rhetorical because I honestly have no idea either way.

  • http://www.lybecker.com/blog/ Anders Lybecker

    Yikes!
    I didn’t know that the fluent-nhibernate HasMany mapping do not lazy load by default. This is odd. Thanks for pointing it out.

    I have also tried the NHibernate Profiler and found it to be a great tool, especially with the new 2nd level cache feature. I do not like the price tag, though.

  • http://www.davidhayden.com/ David Hayden

    hehe… I was teasing. I know you were just screwing with it.

    It is a good reminder, however, as to how we need to verify the O/R Mapper calls to the database to be sure it is working as expected. The dreaded SELECT N + 1 scenario will get you every time…

  • Kyle Baley

    Oh, come on, David. SQL Profiler is so 2001.

    I jest. You’re right, and yes, I’ve used the SQL Profiler in the past and yes, you should use it to pinpoint performance issues. I didn’t really go looking for optimization points when I fired up NHibernate Profiler. Just wanted to test drive it and was impressed to see it work as advertised, I suppose.

  • http://www.davidhayden.com/ David Hayden

    Dude,

    You are freaking me out :) Assuming you are using SQL Server, there is a SQL Server Profiler you can use as well to pinpoint such a catastrophe of queries as well. Checking rountrips to the database is a must for performance reasons. Although NH Profiler apparently rocks, I hope you have been using something like SQL Server Profiler in the past to optimize calls to the database ;)