Memory Leak in Ninject

Question

I'm investigating a webapp which ran up to 10gb of memory, by analysing a memory dump using Windbg.

Here's the bottom of the !dumpheap -stat output:

00007ff9545df5d0   166523     13321840 System.Runtime.Caching.MemoryCache
00007ff9545df4a0   166523     14654024 System.Runtime.Caching.CacheMemoryMonitor
00007ff9545de990   166523     14654024 System.Runtime.Caching.SRef[]
00007ff9545dcef0   166523     14654024 System.Runtime.Caching.GCHandleRef`1[[System.Runtime.Caching.MemoryCacheStore, System.Runtime.Caching]][]
00007ff9545dfb28   166523     19982760 System.Runtime.Caching.MemoryCacheStatistics
00007ff956778510   333059     21315680 System.Int64[]
00007ff95679c988    41597     31250111 System.Byte[]
00007ff9545e08c8  1332184     31972416 System.Runtime.Caching.MemoryCacheEqualityComparer
00007ff9545dfe48  1332184     31972416 System.Runtime.Caching.SRef
00007ff956780ff0  1332200     31972800 System.SizedReference
00007ff956724620  1498777     35970648 System.Threading.TimerHolder
00007ff95677fb30  1536170     36868080 System.Runtime.Remoting.Messaging.CallContextSecurityData
00007ff956796f28  1606960     38567040 System.Object
00007ff9545df810  1332184     42629888 System.Runtime.Caching.GCHandleRef`1[[System.Runtime.Caching.MemoryCacheStore, System.Runtime.Caching]]
00007ff9545dda38  1332184     42629888 System.Runtime.Caching.UsageBucket[]
00007ff9567ae930  1332268     42632576 Microsoft.Win32.SafeHandles.SafeWaitHandle
00007ff9545df968  1498707     47958624 System.Runtime.Caching.GCHandleRef`1[[System.Threading.Timer, mscorlib]]
00007ff9567adbf8  1498777     47960864 System.Threading.Timer
00007ff9545dff50  1332184     53287360 System.Runtime.Caching.CacheUsage
00007ff94986ead8  1536137     61445480 System.Web.Hosting.AspNetHostExecutionContextManager+AspNetHostExecutionContext
00007ff9567a2838  1332210     63946080 System.Threading.ManualResetEvent
00007ff956796948   293525     66384986 System.String
00007ff9545dfef0  1332184     74602304 System.Runtime.Caching.CacheExpires
00007ff9567add20  1498760     95920640 System.Threading.TimerCallback
00007ff9545dfa90  1332184    106574720 System.Runtime.Caching.MemoryCacheStore
00007ff95679b3b0  1333289    106663120 System.Collections.Hashtable
00007ff95678f138  1536171    110604312 System.Runtime.Remoting.Messaging.LogicalCallContext
00007ff9545dffb0  1332184    127889664 System.Runtime.Caching.UsageBucket
00007ff95679d1e0  1333292    128664768 System.Collections.Hashtable+bucket[]
00007ff9567245c0  1498777    131892376 System.Threading.TimerQueueTimer
00007ff9567aec48  1536255    135190440 System.Threading.ExecutionContext
00007ff9545dcf78  1332184    351696576 System.Runtime.Caching.ExpiresBucket[]
000000f82c79d9f0   473339    385303992      Free
00007ff956799220 40309535   1617342672 System.Int32[]
00007ff9545e0468 39965520   3836689920 System.Runtime.Caching.ExpiresBucket

So there are nearly 40 million instances of System.Runtime.Caching.ExpiresBucket, totally nearly 4gb of the used memory. System.Runtime.Caching classes appear quite a lot in the top offenders.

I took a random instance of a System.Runtime.Caching.ExpiresBucket class, and did a !gcroot on it. It took ages (maybe 30 mins) to produce 1 thread...there may have been more but I interrupted the operation at this point.

The chain of references is over 1.5 million lines long! But I can show the important bits here:

0:000> !gcroot 000000f82dd4bc28
Thread 1964:
    000000fcbdbce6a0 00007ff8f9bbe388 Microsoft.AspNet.SignalR.SqlServer.ObservableDbOperation.ExecuteReaderWithUpdates(System.Action`2<System.Data.IDataRecord,Microsoft.AspNet.SignalR.SqlServer.DbOperation>)
        rbp-58: 000000fcbdbce6e8
            ->  000000fa2d1f26a0 Microsoft.AspNet.SignalR.SqlServer.ObservableDbOperation+<>c__DisplayClass1e
            ->  000000fa2d1f2110 Microsoft.AspNet.SignalR.SqlServer.ObservableDbOperation
            ->  000000fa2d1f24d0 System.Action
            ->  000000fa2d1f24a8 System.Object[]
            ->  000000fa2d1f2468 System.Action
            ->  000000fa2d1f1008 Microsoft.AspNet.SignalR.SqlServer.SqlReceiver
            ->  000000fa2d1f1330 System.Action
            ->  000000fa2d1f1308 System.Object[]
            ->  000000fa2d1f12c8 System.Action
            ->  000000fa2d1efb70 Microsoft.AspNet.SignalR.SqlServer.SqlStream
            ->  000000fa2d1f1528 System.Action
            ->  000000fa2d1f1500 System.Object[]
            ->  000000fa2d1f14c0 System.Action
            ->  000000fa2d1efb20 Microsoft.AspNet.SignalR.SqlServer.SqlMessageBus+<>c__DisplayClass3
            ->  000000f92d0b84e0 Microsoft.AspNet.SignalR.SqlServer.SqlMessageBus
            ->  000000f92d0b9568 System.Threading.Timer
            ->  000000f92d0b96d8 System.Threading.TimerHolder
            ->  000000f92d0b95a0 System.Threading.TimerQueueTimer
[... about 100 lines of the same TimerQueueTimer line above, but different memory addresses each time]
           ->  000000f92cf1be68 System.Threading.TimerQueueTimer
            ->  000000f92cf1be08 System.Threading.TimerCallback
            ->  000000f92cf1bb48 System.Web.RequestTimeoutManager
            ->  000000f92cf1bb80 System.Web.Util.DoubleLinkList[]
            ->  000000f92cf1bc00 System.Web.Util.DoubleLinkList
            ->  000000fb61323860 System.Web.RequestTimeoutManager+RequestTimeoutEntry
            ->  000000fb6131fd38 System.Web.HttpContext
            ->  000000fbe682a480 ASP.global_asax
            ->  000000fbe682ac00 System.Web.HttpModuleCollection
            ->  000000fbe682ac60 System.Collections.ArrayList
            ->  000000fbe682b598 System.Object[]
            ->  000000fbe682b018 System.Collections.Specialized.NameObjectCollectionBase+NameObjectEntry
            ->  000000fbe682b000 System.Web.Routing.UrlRoutingModule
            ->  000000faacec1f40 System.Web.Routing.RouteCollection
            ->  000000faacec2030 System.Collections.Generic.List`1[[System.Web.Routing.RouteBase, System.Web]]
            ->  000000fa2cfe4d80 System.Web.Routing.RouteBase[]
            ->  000000f9acf14cd8 System.Web.Http.WebHost.Routing.HttpWebRoute
            ->  000000f9acf149f8 System.Web.Http.Routing.RouteCollectionRoute
            ->  000000f9acf1f4f0 System.Web.Http.Routing.SubRouteCollection
            ->  000000f9acf1f510 System.Collections.Generic.List`1[[System.Web.Http.Routing.IHttpRoute, System.Web.Http]]
            ->  000000fa2cf8f310 System.Web.Http.Routing.IHttpRoute[]
            ->  000000fa2ceff770 System.Web.Http.Routing.HttpRoute
            ->  000000fa2ceff678 System.Web.Http.Routing.HttpRouteValueDictionary
            ->  000000fa2ceff6f0 System.Collections.Generic.Dictionary`2+Entry[[System.String, mscorlib],[System.Object, mscorlib]][]
            ->  000000fa2cef9e78 System.Web.Http.Controllers.HttpActionDescriptor[]
            ->  000000fa2cef7898 System.Web.Http.Controllers.ReflectedHttpActionDescriptor
            ->  000000f9aced4608 System.Web.Http.HttpConfiguration
            ->  000000f9aced4db0 System.Net.Http.Formatting.MediaTypeFormatterCollection
            ->  000000f9aced6f40 System.Collections.Generic.List`1[[System.Net.Http.Formatting.MediaTypeFormatter, System.Net.Http.Formatting]]
            ->  000000f9aced6f80 System.Net.Http.Formatting.MediaTypeFormatter[]
            ->  000000f9aced4df8 System.Net.Http.Formatting.JsonMediaTypeFormatter
            ->  000000f9acf1f448 System.Web.Http.Validation.ModelValidationRequiredMemberSelector
            ->  000000f9acf1f468 System.Collections.Generic.List`1[[System.Web.Http.Validation.ModelValidatorProvider, System.Web.Http]]
            ->  000000f9acf1f490 System.Web.Http.Validation.ModelValidatorProvider[]
            ->  000000f9acf1db40 Ninject.Web.WebApi.Validation.NinjectDefaultModelValidatorProvider
            ->  000000faaceca438 Ninject.StandardKernel
            ->  000000faaceca498 Ninject.Components.ComponentContainer
            ->  000000faaceca538 System.Collections.Generic.Dictionary`2[[System.Type, mscorlib],[Ninject.Components.INinjectComponent, Ninject]]
            ->  000000f9acece000 System.Collections.Generic.Dictionary`2+Entry[[System.Type, mscorlib],[Ninject.Components.INinjectComponent, Ninject]][]
            ->  000000f9acecdac8 Ninject.Activation.Caching.GarbageCollectionCachePruner
            ->  000000f9acecdcb8 System.Threading.Timer
            ->  000000f9acecdd30 System.Threading.TimerHolder
            ->  000000f9acecdcd8 System.Threading.TimerQueueTimer
[... just under 1.5 million lines of the same TimerQueueTimer line above, but different memory addresses each time]
            ->  000000f82dd4c028 System.Threading.TimerQueueTimer
            ->  000000f82dd4bfc8 System.Threading.TimerCallback
            ->  000000f82dd4ada0 System.Runtime.Caching.CacheExpires
            ->  000000f82dd4add8 System.Runtime.Caching.ExpiresBucket[]
            ->  000000f82dd4bc28 System.Runtime.Caching.ExpiresBucket

Running !objsize on the 000000faaceca438 Ninject.StandardKernel seems to take forever, implying that it references an awful lot of objects, possibly all 40 million of those System.Runtime.Caching.ExpiresBucket objects...

What is causing the leak? How should I go about identifying the offending class or code? There is no reference to any of our own code in the gcroot output, so is it due to a bug in one of the installed libraries we're using? Is it in Ninject? We're using v3.2.2 (not the latest, I know)

Answer 1

Posting as an answer because it's too long for a comment:

Seems to me Ninject is tracking an awful lot of scope-objects. AFAIR that's what the GarbageCollectionPruner is for. A scope object is something that is defined with .InScope(...this object here...) or with some of the overloads like InRequestScope(). GarbageCollectionPruner has a timer that periodically checks whether the scope is still "alive". And if it is not alive anymore (garbage collected) it will dispose & forget all objects associated with that scope.

Unless there's not a bug in ninject, this would mean your application is creating an awful lot of scopes in a short interval or they are not properly cleaned up (meaning: problem with your or other 3rd party code).

By the way, if the scope object implements INotifyWhenDisposed (ninject interface) the periodical IsAlive check is not necessary and also gives the benefit of "determnistic" disposal, i.E. just when the scope ends the scoped objects are disposed, too. Otherwise this is dependent on the GC and the timer in Ninject...