Disclaimer: This is not a stab at the NHibernate team. They are doing an awesome job, it might as well (and for a long time I thought it was) have been in my own code. In addition - the memory leak is already solved on the NHibernate trunk.

Introduction

A few weeks back, an ASP.NET application (using NHibernate 2.0.0.4000) I am running got under heavier load than usual. I had noted that the memory usage was slightly high earlier, but it had never been a real problem - this is all the server is doing. However, under heavier load, memory pressure started approaching 700-800mb and the dreaded OutOfMemoryException started appearing when doing big chunks of work.

To be honest, I have never done much memory debugging - learning opportunity! If you do a sweep of the web these days on .NET and debugging, you will no doubt find the blog of Tess Ferrandez, who is an ASP.NET Escalation Engineer working at Microsoft. She has even done a lab series aptly named buggy bits that ease you through debugging and identifying various kinds of application problems.

After reading through her articles and watching her TechEd presentation on the subject, I downloaded WinDbg, configured it as Tess had described and started experimenting. This blog post will describe my journey and hopefully help other solve similar problems.

The Puzzle

The first thing I did was to grab a memory with adplus, one of the tools included with WinDbg. From my understanding, it stops the application momentarily and just writes the entire contents of memory to disk. This produced a huge .DMP file - a memory dump. My managed heap was at around 800mb at the time, but the dump file was slightly bigger.

Working with WinDbg is not your standard draggy-droppy windows application, it looks sort of like a console and you type bizarre command and it produces even more bizarre output for you to reason about. I started out using the "!eeheap -gc" command, which produces some basic information about your heaps.

As you can see, my heap size was around 814mb. If you dig into the information (not all shown on screenshot), you will find that my garbage collectors generation 2 is much bigger than generation 0 and 1. (You can read more about garbage collection and generational garbage collection here.)

After looking at this, I fired off the "!dumpheap -stat" command to get an overview of the objects in the heap.

The output looked like that, the first column denoting the type of object, second is number of objects, third is the shallow size of the objects, that is, not including whatever it references - the fourth is the type name.

Now, the first time I looked at this, I noted the NHibernate objects but focused more on the 385mb of strings - usually, SELECT isn't broken - I was convinced this was a problem in my code. I dug a bit deeper but didn't really find much, partly because WinDbg isn't super easy. This lead me to find some other places in my code that needed StringBuilders, but this proved not to be the root cause (thanks anyway Søren).

Later, when thinking about the problem, it came to me that that maybe 1.9 million NHibernate SqlStrings was a wee bit too many. I decided to did deeper into this - I found the SqlString in my list and found that the type is denoted with 0eafd714. Now, !dumpheap can do more that just give you statistics, it can give you filtered lists using various arguments. I wanted to sample some instances of these SqlStrings to see where they were bounded, so I used the command "!dumpheap -mt 0eafd714". This makes WinDbg give me a list of all the instances of the NHibernate SqlString - this is a very long list.

Now, the second column denotes the type, the third is the shallow object size and the first is what we are looking for - the instance address. I picked a few of them at random and used the !gcroot command to show where they were rooted. That is, give me the chain of references that lead to this object. An example is "!gcroot 57c2f130", which produces the following output.

You can see the actual instance at the bottom and then follow the chain upwards. It seems this current SqlString is rooted in a QueryPlanCache in the NHibernate SessionFactory.

At this point I actually downloaded the NHibernate source and started looking around. Conceptually, the NHibernate SessionFactory keeps a cache of recent HQL queries, so it doesn't have to rebuild them. According to the source code, it would store the 128 most recently used queries.

Now WinDbg can actually tell you the "deep" size of an object, object size + objects it references. This is done using the !objsize command. Now this literally took several hours of processing, so I don't have a screenshot for the blog post, but executing "!objsize 067016bc" command should give me the memory size of my SessionFactory. According to my log file, it told me:

sizeof(067016bc) =    716798348 (  0x2ab9798c) bytes (NHibernate.Impl.SessionFactoryImpl)

That is one big SessionFactory (~700mb). I dug further down the reference chain to try and figure out what was wrong with the cache. Remember I said that this cache was supposed to hold 128 queries. When I got to the hashtable in the cache and dumped it using the "!do 067030d4" command, it revealed the following:

According to this, my cache contains 92000 queries. After digging around in the code, writing a few unit tests and getting some help from the NHibernate user group, I finally found out that it was a bug in the object indexer in the LRUMap, such that it didn't enforce the 128 limit properly.

It was a small innocent bug, but having a 700mb (and growing) hashtable hanging around in your system forever is not really that pleasant. I ended up writing a hack that used reflection to access the field that contained the cache and clearing it periodically. It is already fixed on the NHibernate trunk, but I haven't gotten around to updating yet.

Since implementing my clear hack, I haven't seen memory usages above 50mb.

Conclusion

I've told my small debugging tale of how I got introduced to WinDbg and how it helped me track down a major issue in my application and reduce memory usage from ~800mb to ~50mb. It's a funky tool and can be quite scary at first, but if it helps me remove memory leaks, I am all for it. The second lesson learned is that sometimes - although I still won't look there first - SELECT is broken.

Introduction

I had a project using an old version of Castle ActiveRecord and NHibernate 1.2. Lately there's been a lot of interesting projects surrounding NHibernate and I've been wanting to make the switch away from the old version of ActiveRecord.

ActiveRecord is a thin layer on top of NHibernate that makes it easier to use and configure, especially through configuration using attributes on classes and properties (hence the ActiveRecord name as seen in Ruby on Rails). However unless you build all the tools yourself, it can be quite the dependency hell to play around with all the new NHibernate toys. So I wanted to eradicate ActiveRecord from my reference list and upgrade NHibernate from 1.2. So I thought I'd share my experiences and some of the useful links I found along the way.

Fluent NHibernate

One of the new things I wanted to try out for NHibernate was Fluent NHibernate, a refreshing new way of doing configuration using a fluent interface in C#. NHibernate is usually configured through XML files that look something like this:

<?xml version="1.0" encoding="utf-16"?>
<hibernate-mapping  auto-import="true" default-lazy="false" xmlns:xsd="http://www.w3.org/2001/XMLSchema" xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance" xmlns="urn:nhibernate-mapping-2.2">
  <class name="Model.Survey, Model" table="Surveys">
    <id name="Id" access="property" column="Id" type="System.Guid" unsaved-value="00000000-0000-0000-0000-000000000000">
      <generator class="assigned">
      </generator>
    </id>
    <property name="Name" access="property" type="String">
      <column name="Name"/>
    </property>
    <property name="Label" access="property" type="String">
      <column name="Label"/>
    </property>
    <property name="HeaderFile" access="property" type="String">
      <column name="HeaderFile"/>
    </property>
    <property name="FooterFile" access="property" type="String">
      <column name="FooterFile"/>
    </property>
  </class>
</hibernate-mapping>

Actually I don't mind XML files that much, except that they are cumbersome to write. But moving to code has it's merits. First of all you get the static type checking from the compiler, which is nice for avoiding spelling mistakes and such. Secondly, having your mapping directly in code makes it refactor-friendly. Renaming properties will automagically propagate to your mapping and reduce strange errors. However, unless you specify column names for your mapping, you might end up refactoring your database indirectly (depending on how you manage your schema), so keep that in mind. Third of all I like the clarity and readability of the configuration:

    public class SurveyMap : ClassMap<Survey>
    {
        public SurveyMap()
        {
            WithTable("Surveys");

            Id(x => x.Id).GeneratedBy.Assigned();

            Map(x => x.Name);
            Map(x => x.Label);
            Map(x => x.HeaderFile);
            Map(x => x.FooterFile);
        }
    }

Notice the clever use of lambdas and expressions to avoid strings. Nice indeed. The Fluent NHibernate package also includes a some "framework" classes to ease the testing of your database mappings, as outlined in this post by Jeremy Miller.

LINQ to NHibernate

I haven't had much time to try LINQ yet, so getting my NHibernate upgraded meant a chance to try out LINQ to NHibernate. Actually LINQ to NHibernate is scheduled for NHibernate 2.1, which is not out yet, but Daniel Guenter has created a backport for NHibernate 2.0. Playing around with it was a pleasant change from writing SQL or HQL in in strings. I haven't spend that much time on expanding the use of IQueryable<T> into my application yet, but I did convert my repositories so they use LINQ now. I really want to experiment more with this and I think I'll draw some inspiration from this post by Søren Skovsbøll on his repository layout.

Gotchas

I ran into a few issues when doing the actual conversion.

As my focus was to upgrade my version of NHibernate, I didn't want to convert all my mappings to Fluent NHibernate from the beginning, so I wanted to generate the XML mapping files from my ActiveRecord configuration and then use these as my basis for going fluent later. However, I was using an InPlaceConfiguration with ActiveRecord which is really just a glorified dictionary of properties for setting up connection strings and such instead of an XML file or a web.config section. ActiveRecord Configurations have a Debug property which will output the XML mapping files for you, but unfortunately this property was read-only in my old version of ActiveRecord. I actually checked and it seems to be fixed in the ActiveRecord trunk. So I converted my InPlaceConfiguration into an XML file and enabled debug to get my mappings.

There was some breaking changes in NHibernate 2.0, as outlined in this list by Ayende. The only one I ran into was that configuration values no longer were prefixed with "hibernate". This threw me off with some peculiar errors at first until I found the list.

The last thing I ran into was actually a feature from ActiveRecord that I use on application startup called "VerifyModelsAgainstDBSchema". What this does is to verify that the database schema has the necessary table and columns to fit your mapping. Since the application is question is designed to be very drop-able in terms of throwing it into a web directory and starting it up, I've included functionality to create the database if needed. Luckily, this feature is implementing using very little code. If using LINQ to NHibernate, it can be done as easy as:

try
{
    var query = (from o in Session.Linq<Object>()
                 where 1 == 0
                 select o);
    query.ToList();
    IsDBInitialized = true;
}
catch (ADOException ex)
{
    _dbExceptions.Add(ex);
}

The trick (as far as I understand) is that NHibernate supports polymorphism in query engine, so by querying for objects of type Object, you're actually grabbing all the tables in your mapping and thus checking the consistency - since the SQL statement will fail on invalid table and/or column names. By adding the always false statement 1 == 0, you make sure that you don't actually pull anything from the database. Clever.

Conclusion

In this post I described my 8-hour hike from an ancient version of ActiveRecord to NHibernate 2.0. It was actually very smooth and the problems were easily solved. I'm really looking forward to working more with these new exciting technologies. Enjoy.