This is an issue I come across once in a while and since I am not a COM expert by any means I actually had to check in with our COM guys to see what was going on in this case, and as it turned out (this is embarrassing:)) I had already written about the root cause of this issue before (here).  So what I am learning from this is that perhaps I should at least check my blog before asking questions:)

Problem description

Intermittently the application will stall, so all requests will hang until they run an IIS Reset. At this point the CPU usage for the process is very low.

Gathering memory dumps

A memory dump was gathered using Debug Diagnostics 1.1, by right clicking on the w3wp.exe process and choosing "Create Full Userdump" while the application was hanging.

Debugging the issue

I opened up the memory dump in windbg and ran the basic commands to set up the environment

.symfix c:\websymbols  (to set up the symbol path)
.reload (to reload the symbols)
.loadby sos mscorwks  (to load up the sos dll in order to view .net objects and stacks)

As always with hangs, the most interesting thing to look at is what the threads are doing, so the 3 standard commands I run are

~* kb 2000 (to see the native stacks)
~* e !clrstack (to see the .net stacks)
!threads (to get information about the managed/.net threads)

When I browse through the native call stacks I noticed that plenty of them were sitting in this type of callstack

If you have followed the blog you will probably know that the fact that we are sitting in mscorwks!AwareLock::Enter means that we are waiting for a .net lock.  i.e. on a line like the bolded line below, or alternatively in a Monitor.Enter()

lock(obj){
  // do something
}

If we switch to this thread (71) and run !clrstack on we get the .net stack so that we know where we are waiting for this lock/monitor

and in this case it is in the MyFramework.User.VerifyUser() method that we are waiting for the lock.

Another interesting point about this stack is that we can see that this request hasn't started executing yet, it is still in the Authenticate module which explains why the requests don't simply time out.

The next step is to figure out who is holding this lock to determine why we are stuck here, and we find the owner by running !syncblk

We have two different syncblocks (locks) in this process and it is a bit hard to guess which one is which.  The first one locking on object 1d107964 is held by thread 41 and it has 3 monitors which means that it has one waiter.  The way you calculate how many waiters a monitor has is by taking (MonitorHeld-1)/2.  This is because the owner will take one monitor, and each waiter takes two monitors.

The second lock (1d107334) is owned by thread 40 and has 30 waiters ((61-1)/2).

Oh, btw, when I say owner, I mean the thread that has entered into the lock statement and is now doing something while holding the lock so that thread is essentially keeping the "waiters" waiting.

If we look at our native stack we had

10f2f510 0be7cbbb 1d107334 00000001 00000000 mscorwks!JITutil_MonContention+0xa3

The 1st parameter to JITUtil_MonContention (the 3rd column here) identifies the object we are waiting on, so with this information we now know that our thread (thread 71) is waiting for the lock held by thread 40.

Next we check what this thread is doing and we find that this thread is also waiting for a lock, but this time in ConfigManager.get_Instance(), and lower down in the call chain we can see our VerifyUser method which is why we are holding the lock that thread 71 is waiting for.

We go through the same drill again, finding the owner in the !syncbkl output and this time our first parameter to JITUtil_MonContention is 1d107964 which was the one held by thread 41.

Thread 41 is a bit different than the other threads,  we can see from the .net callstack that we are doing Marshal.ReleaseComObject from the OnConfigRemoveCallback method, and going into the native callstack we can see that this in turn has to make a transition to an STA thread to clean up (GetToSTA).  The reason for this is because the component we are trying to release is an STA component.

Preferably we shouldn't be using STA components in ASP.NET because of the need for transitions between threads and potential waits which of course cause performance degradations.  If this would have been an MTA component we could have simply released it on the same thread.

However, still it should not be sitting like this, waiting indefinitely.  The appropriate STA thread should handle the request and this thread should return, releasing the lock and thus releasing the other locks as well.

We can grab the 1st parameter to GetToSTA to figure out what thread it is trying to get to

0a25ead0 77789905 049d75c0 0ca91600 00000000 ole32!GetToSTA+0x6f

If we dump it out with dc, the 2nd and 3rd dword will tell us what process it is trying to get to as well as the thread id  (the reason we have to go in a little roundabout fashion to find these is because public symbols don't have type information, otherwise we could have dumped out the parameter with dt or looked at it in windbg, but now you will just have to rely on the fact that it is dword 2 and 3 (at least in this version of the dll)

The PID (process ID) here is 91d0 and the thread id is 9a04

Just to verify that we are going to a thread in this process we can run "|" to get basic process information to compare agains

And then we can dump out the threads using !threads to identify the thread with the OS thread ID 9a04

Looking at the 1st thread in the list (Thread 30), we can see that the OSID is 9a04 so this is our guy. 

  30    1 9a04 049a6c28   3808220 Enabled  00000000:00000000 04b0f008     1 STA (Threadpool Worker)

There are a few other things that are interesting about it as well.

1. It is an STA thread (as it should be since we are doing GetToSTA to get here) and 
2. It is a ThreadPool Worker thread, meaning that it is a regular .net thread, so not really a thread that would be pumping messages like an STA thread should

If we would look at the stack for it we would see that this thread is actually also waiting for the lock held by thread 40 so we are stuck in a deadlock where

thread 30 is waiting for a lock held by thread 40 
thread 40 is waiting for a lock held by thread 41
thread 41 needs to get to thread 30 in order to release an STA component

What about the solution?

The problem we need to solve here is that we need to make sure that thread 41 is not trying to get to a managed thread (or another thread not pumping messages) to release the STA component.

As it turns out, the reason that thread 30 is marked as an STA thread (it should really be MTA) is because the first thread created by the threadpool is created without specifying the appartment model.  If this thread happens to handle a request where it uses an STA component this thread will then be marked as STA for the rest of it's life, but unfortunately, as opposed to proper STA threads, it will not be pumping messages so you may block while trying to get to it.

To resolve the issue, install the hotfix discussed in this article http://support.microsoft.com/default.aspx?scid=kb;EN-US;928569

Laters,

Tess