Freigeben über

ASP.NET Crash: Bad CacheItemRemovedCallback - Part II

  • Artikel

In August I wrote about how you could cause a nasty high memory situation by using CacheItemRemovedCallbacks improperly, today I got a case where improper use of CacheItemRemovedCallback caused a crash, so I figured I'll use it to show you how you can use them to bring down your website in seconds...

Problem description

The scenario is a web site that constantly crashes within minutes or seconds of startup, and a dump has been taken on process shutdown (adplus -crash -pn w3wp.exe)

Debugging the issue

If we open the memory dump with windbg and take a quick peak at the callstack that calls Kernel32!TerminateProcess (with kb) we see:

 0:026> kb
ChildEBP RetAddr Args to Child 
03744980 7a059b67 ffffffff 800703e9 9fa3661f kernel32!TerminateProcess
037449e4 7a059c79 0374498c 00166268 00004000 mscorwks!EEPolicy::HandleFatalStackOverflow+0xd8
03744a08 79fce2f0 00000001 00000000 00000000 mscorwks!EEPolicy::HandleStackOverflow+0x157
03744a24 7c82eeb2 03744b08 0376f27c 03744b1c mscorwks!COMPlusFrameHandler+0xd8
03744a48 7c82ee84 03744b08 0376f27c 03744b1c ntdll!ExecuteHandler2+0x26
03744af0 7c82ecc6 03743000 03744b1c 03744b08 ntdll!ExecuteHandler+0x24
03744af0 77e55e02 03743000 03744b1c 03744b08 ntdll!KiUserExceptionDispatcher+0xe
03744e3c 79feef3c e053534f 00000000 00000000 kernel32!RaiseException+0x53
03744e54 7a0900a3 00000001 79124228 03744ec8 mscorwks!ReportStackOverflow+0x7e
03744e64 79e88774 00000094 00000000 00080000 mscorwks!Alloc+0x3b
03744f30 79e7e877 653dbde2 03744fe0 00000001 mscorwks!AllocateArrayEx+0x1d1
03744ff4 652c012b 00000000 1cd07984 1cd07a0c mscorwks!JIT_NewArr1+0x167

So the cause for the process termination was a fatal stackoverflow, which is typically caused by a recursive loop.

The next step is to take a look at the .net callstack (with !clrstack from sos.dll), and doing so will reveal a long callstack with the following contents

 <stack cut to save space>
03761b14 6601bc92 System.Web.Caching.Cache.Insert(System.String, System.Object, System.Web.Caching.CacheDependency, System.DateTime, System.TimeSpan, System.Web.Caching.CacheItemPriority, System.Web.Caching.CacheItemRemovedCallback)
03761b4c 05d54422 MyNameSpace.MyClass.RefreshCache(System.String, System.Object, System.Web.Caching.CacheItemRemovedReason) 
03761b8c 6601e39c System.Web.Caching.CacheEntry.CallCacheItemRemovedCallback(System.Web.Caching.CacheItemRemovedCallback, System.Web.Caching.CacheItemRemovedReason)
03761bc8 6601e60d System.Web.Caching.CacheEntry.Close(System.Web.Caching.CacheItemRemovedReason)
03761c04 6630239c System.Web.Caching.CacheSingle.UpdateCache(System.Web.Caching.CacheKey, System.Web.Caching.CacheEntry, Boolean, System.Web.Caching.CacheItemRemovedReason, System.Object ByRef)
03761cd4 65fa82ea System.Web.Caching.CacheMultiple.UpdateCache(System.Web.Caching.CacheKey, System.Web.Caching.CacheEntry, Boolean, System.Web.Caching.CacheItemRemovedReason, System.Object ByRef)
03761cf8 65fa8e2a System.Web.Caching.CacheInternal.DoInsert(Boolean, System.String, System.Object, System.Web.Caching.CacheDependency, System.DateTime, System.TimeSpan, System.Web.Caching.CacheItemPriority, System.Web.Caching.CacheItemRemovedCallback, Boolean)
03761d54 6601bc92 System.Web.Caching.Cache.Insert(System.String, System.Object, System.Web.Caching.CacheDependency, System.DateTime, System.TimeSpan, System.Web.Caching.CacheItemPriority, System.Web.Caching.CacheItemRemovedCallback)
03761d8c 05d54422 MyNameSpace.MyClass.RefreshCache(System.String, System.Object, System.Web.Caching.CacheItemRemovedReason) 
03761dcc 6601e39c System.Web.Caching.CacheEntry.CallCacheItemRemovedCallback(System.Web.Caching.CacheItemRemovedCallback, System.Web.Caching.CacheItemRemovedReason)
03761e08 6601e60d System.Web.Caching.CacheEntry.Close(System.Web.Caching.CacheItemRemovedReason)
03761e44 6630239c System.Web.Caching.CacheSingle.UpdateCache(System.Web.Caching.CacheKey, System.Web.Caching.CacheEntry, Boolean, System.Web.Caching.CacheItemRemovedReason, System.Object ByRef)
03761f14 65fa82ea System.Web.Caching.CacheMultiple.UpdateCache(System.Web.Caching.CacheKey, System.Web.Caching.CacheEntry, Boolean, System.Web.Caching.CacheItemRemovedReason, System.Object ByRef)
03761f38 65fa8e2a System.Web.Caching.CacheInternal.DoInsert(Boolean, System.String, System.Object, System.Web.Caching.CacheDependency, System.DateTime, System.TimeSpan, System.Web.Caching.CacheItemPriority, System.Web.Caching.CacheItemRemovedCallback, Boolean)
03761f94 6601bc92 System.Web.Caching.Cache.Insert(System.String, System.Object, System.Web.Caching.CacheDependency, System.DateTime, System.TimeSpan, System.Web.Caching.CacheItemPriority, System.Web.Caching.CacheItemRemovedCallback)
03761fcc 05d54422 MyNameSpace.MyClass.RefreshCache(System.String, System.Object, System.Web.Caching.CacheItemRemovedReason) 
0376200c 6601e39c System.Web.Caching.CacheEntry.CallCacheItemRemovedCallback(System.Web.Caching.CacheItemRemovedCallback, System.Web.Caching.CacheItemRemovedReason)
03762048 6601e60d System.Web.Caching.CacheEntry.Close(System.Web.Caching.CacheItemRemovedReason)
03762084 6630239c System.Web.Caching.CacheSingle.UpdateCache(System.Web.Caching.CacheKey, System.Web.Caching.CacheEntry, Boolean, System.Web.Caching.CacheItemRemovedReason, System.Object ByRef)
03762154 65fa82ea System.Web.Caching.CacheMultiple.UpdateCache(System.Web.Caching.CacheKey, System.Web.Caching.CacheEntry, Boolean, System.Web.Caching.CacheItemRemovedReason, System.Object ByRef)
03762178 65fa8e2a System.Web.Caching.CacheInternal.DoInsert(Boolean, System.String, System.Object, System.Web.Caching.CacheDependency, System.DateTime, System.TimeSpan, System.Web.Caching.CacheItemPriority, System.Web.Caching.CacheItemRemovedCallback, Boolean)
037621d4 6601bc92 System.Web.Caching.Cache.Insert(System.String, System.Object, System.Web.Caching.CacheDependency, System.DateTime, System.TimeSpan, System.Web.Caching.CacheItemPriority, System.Web.Caching.CacheItemRemovedCallback)
0376220c 05d54422 MyNameSpace.MyClass.RefreshCache(System.String, System.Object, System.Web.Caching.CacheItemRemovedReason) 
0376224c 6601e39c System.Web.Caching.CacheEntry.CallCacheItemRemovedCallback(System.Web.Caching.CacheItemRemovedCallback, System.Web.Caching.CacheItemRemovedReason)
03762288 6601e60d System.Web.Caching.CacheEntry.Close(System.Web.Caching.CacheItemRemovedReason)
037622c4 6630239c System.Web.Caching.CacheSingle.UpdateCache(System.Web.Caching.CacheKey, System.Web.Caching.CacheEntry, Boolean, System.Web.Caching.CacheItemRemovedReason, System.Object ByRef)
03762394 65fa82ea System.Web.Caching.CacheMultiple.UpdateCache(System.Web.Caching.CacheKey, System.Web.Caching.CacheEntry, Boolean, System.Web.Caching.CacheItemRemovedReason, System.Object ByRef)
037623b8 65fa8e2a System.Web.Caching.CacheInternal.DoInsert(Boolean, System.String, System.Object, System.Web.Caching.CacheDependency, System.DateTime, System.TimeSpan, System.Web.Caching.CacheItemPriority, System.Web.Caching.CacheItemRemovedCallback, Boolean)
03762414 6601bc92 System.Web.Caching.Cache.Insert(System.String, System.Object, System.Web.Caching.CacheDependency, System.DateTime, System.TimeSpan, System.Web.Caching.CacheItemPriority, System.Web.Caching.CacheItemRemovedCallback)
0376244c 05d54422 MyNameSpace.MyClass.RefreshCache(System.String, System.Object, System.Web.Caching.CacheItemRemovedReason) 
0376248c 6601e39c System.Web.Caching.CacheEntry.CallCacheItemRemovedCallback(System.Web.Caching.CacheItemRemovedCallback, System.Web.Caching.CacheItemRemovedReason)
037624c8 6601e60d System.Web.Caching.CacheEntry.Close(System.Web.Caching.CacheItemRemovedReason)
<stack cut to save space>

So what do we have here?

Well, we can see that MyNameSpace.MyClass.RefreshCache inserts something in cache, which in turn updates the cache and for some reason closes out a cache item, and calls the RefreshCache function again.

If we take a peak at the MyNameSpace.MyClass.RefreshCache function it looks like this:

 protected void RefreshCache(string key, object item, CacheItemRemovedReason reason)
{
    ...
    ContextHandler.Cache.Insert(
       "MyCacheItem", 
       CacheValue, 
       null, 
       DateTime.Now.AddHours(9), 
       TimeSpan.Zero, 
       CacheItemPriority.NotRemovable, 
       new CacheItemRemovedCallback(this.RefreshCache)); 
}

 

So from first look, it looks like a very logical way to perform what needs to be performed.  What we want to do is insert a new item, and in the case where it is removed we want to reinsert it using the same function.  In fact, from looking at it, it is very hard to see how this could ever cause a problem.

But, dear Watson, there is a major problem with this code....

When an item is inserted the first time into cache everything will be cool, but what will happen the next time you go through this function? 

Answer:  The insert will insert a new cache item "MyCacheItem", and at the same time it will remove the previous copy of this item, causing the CacheItemRemovedCallback handler to be called (RefreshCache), this will in turn insert a new copy, remove the old one and so on and so on... and we have ourselves a neverending recursive loop that causes a stackoverflow and a crashing website.

Final thoughts

The morale of the story is, don't use the CacheItemRemovedCallback to add a new copy of the same cache item. Instead use sliding expiration, and instead add the cached item when you try to access the cached item and this item is null.   

Til next time,
Tess

Comments

  • Anonymous
    November 27, 2006
    I discovered your blog today (my bad). Good stuff ! -- Henkk

  • Anonymous
    November 28, 2006
    Common Gotcha: Don't forget to when adding providers [Via: ScottGu ] Mounting ISO Images with Vista...

  • Anonymous
    January 23, 2007
    Hi, I don't understand this - can you explain a bit better why the RefreshCache function causes a recursive loop? From what I see, the cache item is removed, the event fires, RefreshCache() is run and the item is re-inserted. How come the previous cache item is still there when it tries to insert the replacement? Surely is must have already been removed or the event wouldn't have fired?! Help, I don't understand! Rob

  • Anonymous
    January 23, 2007
    The cached item is still there when the event fires.   Without going through the code and looking at the exact details I would hazard to guess that this is to allow the eventhandler to still access the properties of this object. Of course, once the event is fired the object should then go away.

  • Anonymous
    January 24, 2007
    thanks, i guess that sort of makes sense. shame, it would be nice to easily refresh a cache every 30mins without a user having to initiate it and take the performance hit.

  • Anonymous
    June 15, 2007
    Dude, this is awesome.  I came across this article while trying to see what KiFastSystemCall does. There is no documentation whatsoever about what this mysterious function does.

  • Anonymous
    June 17, 2007
    When you see it on top of a stack in a dump it is usually an effect of the debugger stepping in to momentarily pause the threads to gather the stack. You can just ignore it and go on to the next frame on the stack...

  • Anonymous
    July 03, 2007
    Add 'if' statement to your RefreshCache(string key, object item, CacheItemRemovedReason reason) method like this: if (reason == CacheItemRemovedReason.Removed || reason == CacheItemRemovedReason.Underused) return; and now it will go into recursive loop.

  • Anonymous
    August 07, 2007
    "don't use the CacheItemRemovedCallback to add a new copy of the same cache item"... uhm... not the best practice. Simply put your code into an 'if' statement if ( reason == CacheItemRemovedReason.DependencyChanged || reason == CacheItemRemovedReason.Expired || reason == CacheItemRemovedReason.Underused) {      //your code. }

  • Anonymous
    May 05, 2008
    I have written a few posts about stackoverflow exceptions, here, here , here and here . The one I am

  • Anonymous
    August 03, 2009
    The comment has been removed

  • Anonymous
    December 01, 2009
    I have used the following VB code... and it works... but according to this article, it shouldn't work.   If I set the expiry to 1 minute and debug, the cache is reset every 1 minute.  If I put a breakpoint in the code to see what the value of the cache item is (theCache(Common.CACHE_AllRates), where Common.CACHE_AllRates is just a string constant), the cache item = Nothing when the CacheItemRemovedCallback is executed. I'm confused.  Is some fluke causing my code to work?  Do you know of a case where this code would break? ' in Global.asax.vb ... Shared theCache As Cache ...    Sub Application_Start(ByVal sender As Object, ByVal e As EventArgs)        ' Fires when the application is started        'set global cache variable        theCache = Context.Cache        Dim dsAllRates As DataSet = Common.GetAllRates()        theCache.Insert(Common.CACHE_AllRates, _                        dsAllRates.Tables(0), _                        Nothing, _                        Date.Now.AddMinutes(15), _                        Cache.NoSlidingExpiration, _                        CacheItemPriority.Default, _                        New CacheItemRemovedCallback(AddressOf Update_DS_AllRates))    End Sub    Shared Sub Update_DS_AllRates(ByVal key As String, ByVal item As Object, ByVal reason As CacheItemRemovedReason)        Try            'get all ActiveEmployees            Dim dsAllRates As DataSet = Common.GetAllRates()            'store dataset in cache            theCache.Insert(Common.CACHE_AllRates, _                            dsAllRates.Tables(0), _                            Nothing, _                            Date.Now.AddMinutes(15), _                            Cache.NoSlidingExpiration, _                            CacheItemPriority.Default, _                            New CacheItemRemovedCallback(AddressOf Update_DS_AllRates))        Catch ex As Exception            ...        End Try    End Sub ...