Possible NHibernate SessionFactory (LRUMap) Memory Leak?

[Rasmus Kromann-Larsen]

Hi,

I have been trying to pin down a memory leak in my wep app these past
few weeks - and digging into my application with WinDbg revealed
something fishy with the NHibernate SessionFactory in memory.

Context: It's a standard ASP.NET application using NHibernate
2.0.0.4000. I only use 1 SessionFactory since that seems to be the
defacto standard - and my Sessions are disposed using something along
the lines of Ayende's unit of work.

I have been analyzing a memory dump of a ~800mb .NET heap to figure
out why it kept growing. One thing I found was around 1.9 million
NHibernate.SqlCommand.SqlStrings and ~90000 HQLQueryPlans

MT Count TotalSize Class Name
0f7fb3e4 92382 3695280 NHibernate.Engine.Query.HQLQueryPlan
0eafd714 1939496 31031936 NHibernate.SqlCommand.SqlString

Digging down into the roots of one of these SqlStrings revealed that
it was being stored in the query plan cache in the SessionFactoryImpl:

067016bc(NHibernate.Impl.SessionFactoryImpl)->
06702470(NHibernate.Engine.Query.QueryPlanCache)->
06703050(NHibernate.Util.SoftLimitMRUCache)->
067030a0(NHibernate.Util.LRUMap)->
067030d4(System.Collections.Hashtable)->
0c8af170(System.Collections.Hashtable+bucket[])->
02e30ccc(NHibernate.Util.SequencedHashMap+Entry)->
02e2efdc(NHibernate.Engine.Query.HQLQueryPlan)->
02e2f1dc(System.Object[])->
02e2f1f0(NHibernate.Hql.Classic.QueryTranslator)->
02e2f4c4(System.Collections.Generic.List`1
[[NHibernate.SqlCommand.SqlString, NHibernate]])

I checked and there was exactly 1 instance of the SessionFactoryImpl
in the dump - checking it's size took a few hours, which is not
surprising:

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

That is one big SessionFactory :-) Still tracking the SqlString I
explored the query plan cache and ended up at the LRUMap, which
according to the code is supposed to keep the last (128 in this case)
most recently used queries in cache. The LRUMap looked like this:

Name: NHibernate.Util.LRUMap
Fields:
MT Field Offset Type VT Attr Value
Name
0f76a554 4000e40 c ...ncedHashMap+Entry 0 instance 067030bc
_sentinel
79101fe4 4000e41 10 ...ections.Hashtable 0 instance 067030d4
_entries
790ffcc8 4000e42 4 System.Int64 1 instance 104874
_modCount
79102290 4000e51 14 System.Int32 1 instance 128
maximumSize

That is, 128 max size. Examining the hashtable called Entries in the
LRUMap revealed this though (some lines removed):

Name: System.Collections.Hashtable
Size: 56(0x38) bytes
Fields:
MT Field Offset Type VT Attr Value
Name
7912d9bc 400092b 4 ...ashtable+bucket[] 0 instance 0c8af170
buckets
79102290 400092c 1c System.Int32 1 instance 92382
count
79102290 400092d 20 System.Int32 1 instance 35331
occupancy
79102290 400092e 24 System.Int32 1 instance 112634
loadsize
79102290 4000930 2c System.Int32 1 instance 92391
version

Supposedly it contains ~90000 objects (count field) and a big
(reachable) object size:
sizeof(067030d4) = 716798264 bytes (System.Collections.Hashtable)

I have examined the LRUMap source and can't find any glaring mistakes,
I looked at the LRUMapFixture, which didn't seem to contain any tests
that verify that it actually is limited to it's max size. However, I
made a unit test in my own test project:

[Test]
public void LRUTest()
{
LRUMap map = new LRUMap(10);

for (int i = 0; i < 20000; i++)
map.Add("str" + i, i);

Assert.AreEqual(10, map.Count);
}

and this passed just fine.

Now this is where I am stumped, somehow my application manages to
squeeze all these objects into the cache, but I haven't been able to
reproduce it with simple tests.

Does anyone have an idea what could be the culprit?

[Ayende Rahien]

multi threaded stuff?

I'll review the code again 

[Ayende Rahien]

It is not multi threaded safe, but I would say that it should certainly work.

On Thu, Dec 11, 2008 at 7:11 AM, Rasmus Kromann-Larsen <rasm...@gmail.com> wrote:

[Rasmus Kromann-Larsen]

Well, obviously it isn't - I just haven't noticed it before switching
to NHibernate 2.

I am using Linq to NHibernate and Fluent NHibernate too though, but
they shouldn't affect stuff this deep in the SessionFactory?

Odd. I guess I will have to dig deeper.

On Dec 11, 10:18 pm, "Ayende Rahien" <aye...@ayende.com> wrote:
> It is not multi threaded safe, but I would say that it should certainly
> work.
>
> On Thu, Dec 11, 2008 at 7:11 AM, Rasmus Kromann-Larsen

> <rasmu...@gmail.com>wrote:

[Ayende Rahien]

I can tell you for sure that this is not something that we have seen in other apps.

Although this is way too deep in the guts of NH for an extension to change.

[Ben Lovell]

Long shot but I had experienced a similar issue which was related to caching. Check this out:

http://jira.nhibernate.org/browse/NH-604

B
http://benl.wordpress.com

[Rasmus Kromann-Larsen]

Oh... I just tested it out on my integration test - it failed single
threaded too. Then I wrote some reflection code to inspect the fields
etc - and finally I got the idea of testing the SoftLimitMRUCache
instead.

This test fails:

[Test]
public void SimpleTest()
{
SoftLimitMRUCache cache = new SoftLimitMRUCache(128);

for(var i=0;i<200;i++)
cache.Put("str"+i, i);

Assert.That(cache.Count, Is.EqualTo(128));
}

Atleast on my setup - can anyone test it on the trunk? :-)

It appears to be a variation of the same problem as Ben described.

On Dec 11, 10:47 pm, "Ben Lovell" <benjamin.lov...@gmail.com> wrote:
> Long shot but I had experienced a similar issue which was related to
> caching. Check this out:
>
> http://jira.nhibernate.org/browse/NH-604
>

> Bhttp://benl.wordpress.com

>
> On Thu, Dec 11, 2008 at 9:37 PM, Ayende Rahien <aye...@ayende.com> wrote:
> > I can tell you for sure that this is not something that we have seen in

> > other apps.Although this is way too deep in the guts of NH for an

[Rasmus Kromann-Larsen]

It is an issue in the LRUMap.

This passes:

[Test]
public void SimpleLRUTest()
{
LRUMap map = new LRUMap(128);

for (var i = 0; i < 200; i++)

map.Add("str" + i, i);

Assert.That(map.Count, Is.EqualTo(128));
}

and this fails:

[Test]
public void SimpleLRUTest2()
{
LRUMap map = new LRUMap(128);

for (var i = 0; i < 200; i++)
map["str" + i] = i;

Assert.That(map.Count, Is.EqualTo(128));
}

Checking the NHibernate source, the Add method has bounds checking for
the cache-size while the indexer's set method is just:

set
{
base[key] = value;
}

Woo.

[Fabio Maulo]

Thanks.

2008/12/11 Rasmus Kromann-Larsen <rasm...@gmail.com>

--
Fabio Maulo

[Davy Brion]

just fixed it in the trunk (revision 3953)

thanks for finding this :)

--
Davy Brion
http://davybrion.com

[Paul Alves]

I found this post about the memory leak problem in LRUMap and I would ask to check this problem again, please.

On Sunday, December 14, 2008 at 4:18:21 PM UTC-2, Davy Brion wrote:

just fixed it in the trunk (revision 3953)

thanks for finding this :)

On Thu, Dec 11, 2008 at 11:08 PM, Rasmus Kromann-Larsen <rasm...@gmail.com> wrote:1.