Investigating dumps with exception

Dump that contains concrete exception is useful in case of "Sometimes"-issues. "Sometimes"-issue is an issue, which description is started from one of the words - sometimes, rarely, suddenly etc. Do you recall some of such cases, and how often they are closed as not-reproducible? Memory dump is your friend here :)

In case of any exception I would suggest to gather dump the same as in case for OOM exception, which is described here. Do not forget to load needed modules and symbols, and after that you are ready to start investigation.


Actually, dump with concrete exception is simplest situation.

!threads :)

1. !threads. First that you should run is !threads command. This will give us an output of all threads that existed at the moment of gathering dump - running or waiting.

0:082> !threads


ThreadCount: 64
UnstartedThread: 0
BackgroundThread: 55
PendingThread: 0
DeadThread: 0
Hosted Runtime: no
                                      PreEmptive   GC Alloc           Lock
            ID     OSID    ThreadOBJ     State     GC       Context       Domain   Count APT Exception
  20        1     1e74       000e2d20   1808220 Enabled  00000000:00000000 000c9228     0 MTA (Threadpool Worker)
  34        2      1940        000f6fa0        b220 Enabled  00000000:00000000 000c9228     0 MTA (Finalizer)
  35        3      1464       0010f7c8     80a220 Enabled  00000000:00000000 000c9228     0 MTA (Threadpool Completion Port)
[...]
  81      2d      dac        182f1aa8   200b020 Enabled  00000000:00000000 001138c0     0 MTA
  82      2f       1e7c      182aa338         b020 Enabled  51822aec:51824958 001138c0     0 MTA System.Net.WebException (51822964)
  12      31       1dcc     18341690           220 Enabled  00000000:00000000 000c9228     0 Ukn
[...]


Now look at the last column. Do you see there any Exception? If yes, cool, this is what we are hunting on!
Let's enter thread 82, where our exception is referenced.

2. ~82s

This ~IDs command switches us to the desired thread.

3. !clrstack. One more powerful command that you will use heavily. It shows stack of calls on the current thread.

0:082> !clrstack

OS Thread Id: 0x1e7c (82)
ESP       EIP     
2809dff8 77e4bef7 [HelperMethodFrame: 2809dff8] 
2809e048 7a56063b System.Net.PooledStream.Activate(System.Object, Boolean, Int32, System.Net.GeneralAsyncDelegate)
2809e0fc 7a5603fa System.Net.Connection.CompleteStartConnection(Boolean, System.Net.HttpWebRequest)
2809e144 7a5888ea System.Net.Connection.CompleteStartRequest(Boolean, System.Net.HttpWebRequest, System.Net.TriState)
2809e174 7a588233 System.Net.Connection.SubmitRequest(System.Net.HttpWebRequest)
2809e1b8 7a587bac System.Net.ServicePoint.SubmitRequest(System.Net.HttpWebRequest, System.String)
2809e1f0 7a587479 System.Net.HttpWebRequest.SubmitRequest(System.Net.ServicePoint)
2809e21c 7aaaa4d4 System.Net.HttpWebRequest.GetResponse()
2809e25c 27fc5e5c Sitecore.Analytics.Lookups.MaxMindProvider.RequestMaxMind(System.String)
2809e294 27fc587b Sitecore.Analytics.Lookups.MaxMindProvider.GetInformationByIp(System.String, System.String)
2809e2c4 27fc56e2 Sitecore.Analytics.Lookups.LookupManager.GetInformationByIp(System.String, System.String)
2809e2d4 27fc55fc Sitecore.Analytics.Lookups.LookupUpdater.Process(Sitecore.Analytics.Lookups.LookupData)
2809e2f8 27fc1f74 Sitecore.Analytics.Lookups.LookupWorker.Process()
2809e32c 27ffecd1 Sitecore.Analytics.Lookups.LookupWorker.WorkLoop()
2809e35c 792d6e46 System.Threading.ThreadHelper.ThreadStart_Context(System.Object)
2809e368 792f5781 System.Threading.ExecutionContext.runTryCode(System.Object)
2809e798 79e71b4c [HelperMethodFrame_PROTECTOBJ: 2809e798] System.Runtime.CompilerServices.RuntimeHelpers.ExecuteCodeWithGuaranteedCleanup(TryCode, CleanupCode, System.Object)
2809e800 792f5677 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
2809e81c 792e02a5 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
2809e834 792d6dc4 System.Threading.ThreadHelper.ThreadStart()
2809ea60 79e71b4c [GCFrame: 2809ea60] 
2809ed50 79e71b4c [ContextTransitionFrame: 2809ed50] 

Hmmm... It's definitely something related to Sitecore.Analytics! Let's find out, where is the exact culprit.


!clrstack also has parameters. For example, you may use -a option to get all parameters of  methods on the stack, but I should say that in 90% situations you'll get <no data>. So to find out which objects are on stack, I would definitely use another one:

4. !dso

!dso stands for "!DumpStackObjects", and this command outputs all objects that are currently on stack. Objects are output corresponding to the sequence of method calls, from bottom to top, so it is often easy to find out which methods are called with which parameters:


0:082> !dso
OS Thread Id: 0x1e7c (82)
ESP/REG  Object   Name
2809df5c 51822964 System.Net.WebException
2809dfa4 51822964 System.Net.WebException
2809dfb4 4e83ecf4 System.Net.HttpWebRequest
2809dfb8 4e83bf00 System.Net.Connection
2809dfc4 4e83ecf4 System.Net.HttpWebRequest
2809dfcc 4e83bf00 System.Net.Connection
2809dfd0 0895c118 System.String    The remote name could not be resolved
2809e064 51822964 System.Net.WebException
2809e080 51822964 System.Net.WebException
2809e0c0 4e83bf00 System.Net.Connection
2809e100 4e83bf00 System.Net.Connection
2809e140 4e8203c8 System.Net.HttpWebRequest
2809e170 4e8203c8 System.Net.HttpWebRequest
2809e178 4e8203c8 System.Net.HttpWebRequest
2809e17c 4e83bf00 System.Net.Connection
2809e1bc 4e83be80 System.Net.ConnectionGroup
2809e1c0 4e8203c8 System.Net.HttpWebRequest
2809e1dc 4e83ecf4 System.Net.HttpWebRequest
2809e1ec 4e83be68 System.String    S>
2809e1f0 4e8203c8 System.Net.HttpWebRequest
2809e204 4e83eb64 System.String    http://sitecore1.maxmind.com/app/sc?i=111.111.111.11&l=2222222222222200000000
2809e208 4e83ecf4 System.Net.HttpWebRequest
2809e20c 0bf7a88c System.Net.TimerThread+TimerQueue
2809e21c 4e83ecf4 System.Net.HttpWebRequest
2809e228 4e8203c8 System.Net.HttpWebRequest
2809e244 0895b9e8 System.Text.Latin1Encoding
2809e248 4e83eb64 System.String    http://sitecore1.maxmind.com/app/sc?i=111.111.111.11&l=2222222222222200000000
2809e24c 4e83ec80 System.Uri
2809e250 0895b9e8 System.Text.Latin1Encoding
2809e25c 08ffd014 System.String    22222222222222
2809e268 06fb01d0 System.String    
2809e27c 06fb01d0 System.String    
2809e284 4e820208 Sitecore.Analytics.Lookups.WhoIsInformation
2809e298 0895abc8 Sitecore.Configuration.ProviderHelper`2[[Sitecore.Analytics.Lookups.LookupProviderBase, Sitecore.Analytics],[Sitecore.Analytics.Lookups.LookupProviderCollection, Sitecore.Analytics]]
2809e2c0 4e8201a0 System.String    111.111.111.11
2809e2c4 4e820150 Sitecore.Analytics.Lookups.LookupData
2809e300 4e8201f0 System.Collections.Generic.List`1+Enumerator[[Sitecore.Analytics.Lookups.LookupData, Sitecore.Analytics]]
2809e424 03fb0098 System.Runtime.CompilerServices.RuntimeHelpers+TryCode
2809e598 03fb0098 System.Runtime.CompilerServices.RuntimeHelpers+TryCode
2809e7d4 03fb0098 System.Runtime.CompilerServices.RuntimeHelpers+TryCode
2809e7d8 03fb00b8 System.Runtime.CompilerServices.RuntimeHelpers+CleanupCode
2809e7dc 089563a4 System.Threading.ExecutionContext+ExecutionContextRunData
2809e804 0dfb00b4 System.Threading.ContextCallback
2809e818 2f68b5f4 System.Threading.ThreadHelper
2809e830 2f68b5f4 System.Threading.ThreadHelper
2809ea84 2f68822c Sitecore.Security.Accounts.User
2809ea8c 2f68b608 System.Threading.ThreadStart
2809ea94 2f68b5bc System.Threading.Thread

It is very useful, that strings are output as is in the stack of objects :) strings often may be used as "milestones" to catch your attention and understand where at the call stack we are.

Here comes Reflector, where we can look at the methods and their variables/parameters, and compare what gives us the Reflector to what we've got with clrstack and dso.

In this concrete case you may easily find that exception is being brought by  WebRequest.Create(requestUri).GetResponse() called from Sitecore.Analytics.Lookups.MaxMindProvider.RequestMaxMind, and our requestUri in question is http://sitecore1.maxmind.com/app/sc?i=111.111.111.11&l=2222222222222200000000, where http://sitecore1.maxmind.com/app/sc is Url taken from web.config setting, MaxMind.Url, 111.111.111.11 is IP read from Analytics database, 2222...0000 is License ID. 


All numbers are fictitious :)


So we have found where the problem is and even which url is guilty. In Sitecore logs we will have only "Failed to perform MaxMind lookup" message, that is not that informative.


Sometimes you'll also need to use 
!do [address] command to dump some concrete objects, 
!da [address] command to dump an array, 
!da -details [address] to dump an array with all its members
and possibly some more commands, but it depends on the case. Hope I will run into some specific case later and will add more useful commands and ideas to this post.

Credits for images to 

http://www.matchingpegs.com

http://scwww.awdit.com