Things to ignore when debugging an ASP.NET hang
When looking at a dump, a lot of the art of debugging (I like to call it an art because it makes me feel more important:)) is knowing what you can ignore so you can get to the goodies.
Especially if you are looking at a hang, it’s nice to know what the most common threads are so you can just scan them and say not that one, not that one, well you get the idea.
Since I work mostly with asp.net I’m going to dissect a w3wp.exe dump (IIS 6) and show you some of the more common stacks. Common for all of these is that they are all in a sleeping or waiting state, waiting for more work. So if you see them like this in a hang dump, they are not the cause of the hang… if you see them in any other state, they are executing work and then of course they become far more interesting:)
I’ll divide them up into a few different tags
- CLR Threads
- W3WP Threads
- RPC Threads
- Other COM Threads
CLR Threads
The ThreadPool manager has five main thread types
Completion Port/IO Threads, and Worker Threads which execute your managed/.net code. A gate thread that creates or destroys worker threads and IO threads based on CPU utilization, GC frequency and worker queue size. Wait threads, used for waiting on synchronization objects. I.e. if a developer uses the WaitHandle class, it will internally cause this thread to “waitforsingleobject”. And finally the timer threads which are used to implement timer callback functionality
This is how they look in their idle states in .net 1.1.
Idle CLR WorkerThread
11 Id: fb8.268 Suspend: 0 Teb: 7ffaa000 Unfrozen
ChildEBP RetAddr Args to Child
0199fdf8 7c822124 77e6baa8 00000234 00000000 ntdll!KiFastSystemCallRet
0199fdfc 77e6baa8 00000234 00000000 0199fe40 ntdll!NtWaitForSingleObject+0xc
0199fe6c 77e6ba12 00000234 00009c40 00000000 kernel32!WaitForSingleObjectEx+0xac
0199fe80 791d401f 00000234 00009c40 00000000 kernel32!WaitForSingleObject+0x12
0199fea4 791fdacc 00000000 00000000 80a56bcc mscorsvr!ThreadpoolMgr::WorkerThreadStart+0x3a
0199ffb8 77e66063 000b6da8 00000000 00000000 mscorsvr!ThreadpoolMgr::intermediateThreadProc+0x44
0199ffec 00000000 791fda8b 000b6da8 00000000 kernel32!BaseThreadStart+0x34
Idle CLR Completion Port / IO Thread
9 Id: fb8.ef8 Suspend: 0 Teb: 7ffac000 Unfrozen
ChildEBP RetAddr Args to Child
0191fec0 7c821bf4 77e6611a 0000023c 0191ff1c ntdll!KiFastSystemCallRet
0191fec4 77e6611a 0000023c 0191ff1c 0191ff08 ntdll!NtRemoveIoCompletion+0xc
0191fef0 791fdb22 0000023c 0191ff18 0191ff1c kernel32!GetQueuedCompletionStatus+0x29
0191ff24 791fdacc 00000001 809a05fe 7ffac000 mscorsvr!ThreadpoolMgr::CompletionPortThreadStart+0x49
0191ffb8 77e66063 000b6da8 00000000 00000000 mscorsvr!ThreadpoolMgr::intermediateThreadProc+0x44
0191ffec 00000000 791fda8b 000b6da8 00000000 kernel32!BaseThreadStart+0x34
Idle CLR Gate Thread
10 Id: fb8.bdc Suspend: 0 Teb: 7ffab000 Unfrozen
ChildEBP RetAddr Args to Child
0195fe50 7c821364 77e42439 00000000 0195fe94 ntdll!KiFastSystemCallRet
0195fe54 77e42439 00000000 0195fe94 00000000 ntdll!NtDelayExecution+0xc
0195febc 77e424b7 000001f4 00000000 0195ffb8 kernel32!SleepEx+0x68
0195fecc 791bf4f9 000001f4 0b2646e6 00000939 kernel32!Sleep+0xf
0195ffb8 77e66063 00000000 00000000 00000000 mscorsvr!ThreadpoolMgr::GateThreadStart+0x54
0195ffec 00000000 791bf4a5 00000000 00000000 kernel32!BaseThreadStart+0x34
Idle CLR Wait Thread
25 Id: 230.ac0 Suspend: 0 Teb: 7ff4c000 Unfrozen
ChildEBP RetAddr Args to Child
1b88ff6c 7c573a4e 00000001 1b88ff84 00000000 NTDLL!ZwDelayExecution+0xb
1b88ff8c 7923558c ffffffff 00000001 198ba828 KERNEL32!SleepEx+0x32
1b88ffb4 7c57438b 00000000 198ba828 197f7498 mscorsvr!ThreadpoolMgr::WaitThreadStart+0x45
1b88ffec 00000000 7923556a 1973b3d0 00000000 KERNEL32!BaseThreadStart+0x52
Idle CLR Timer Thread
18 Id: fb8.914 Suspend: 0 Teb: 7ff5f000 Unfrozen
ChildEBP RetAddr Args to Child
0224ff38 7c821364 77e42439 00000001 0224ff7c ntdll!KiFastSystemCallRet
0224ff3c 77e42439 00000001 0224ff7c 000003e8 ntdll!NtDelayExecution+0xc
0224ffa4 791cc578 000003e8 00000001 00000000 kernel32!SleepEx+0x68
0224ffb8 77e66063 00000000 00000000 00000000 mscorsvr!ThreadpoolMgr::TimerThreadStart+0x30
0224ffec 00000000 791cc548 00000000 00000000 kernel32!BaseThreadStart+0x34
Apart from these we also have some other threads created by the CLR:
On a multi-proc box, in a process that hosts the CLR (server version of GC) we have one Garbage Collector thread per processor or two per proc if running on a hyper threaded system. These take care of garbage collecting the managed heaps.
We have one finalizer thread per process, and this is where all your finalize methods run. In both hang and high memory situations, watch out for this thread. If it is blocked in any way when finalizing an object your managed variables will not be properly cleaned up and you may end up with a memory leak, and/or a high cpu situation since the GC will have to work over time to keep your memory usage up.
Finally, we have the DebuggerThread used for interfacing with the Debugging APIs
Idle CLR GC Thread
13 Id: fb8.c10 Suspend: 0 Teb: 7ffa8000 Unfrozen
ChildEBP RetAddr Args to Child
01d6fefc 7c822124 77e6baa8 000002b4 00000000 ntdll!KiFastSystemCallRet
01d6ff00 77e6baa8 000002b4 00000000 00000000 ntdll!NtWaitForSingleObject+0xc
01d6ff70 77e6ba12 000002b4 ffffffff 00000000 kernel32!WaitForSingleObjectEx+0xac
01d6ff84 791fe6b0 000002b4 ffffffff 00000000 kernel32!WaitForSingleObject+0x12
01d6ffac 792356be 00000000 01d6ffec 77e66063 mscorsvr!gc_heap::gc_thread_function+0x2f
01d6ffb8 77e66063 000d2ed8 00000000 00000000 mscorsvr!gc_heap::gc_thread_stub+0x1e
01d6ffec 00000000 792356a0 000d2ed8 00000000 kernel32!BaseThreadStart+0x34
Idle CLR Finalizer Thread
17 Id: fb8.7b0 Suspend: 0 Teb: 7ffa4000 Unfrozen
ChildEBP RetAddr Args to Child
01e6fdf8 7c822114 77e6711b 00000002 01e6fe48 ntdll!KiFastSystemCallRet
01e6fdfc 77e6711b 00000002 01e6fe48 00000001 ntdll!NtWaitForMultipleObjects+0xc
01e6fea4 77e61075 00000002 793eee08 00000000 kernel32!WaitForMultipleObjectsEx+0x11a
01e6fec0 7927826b 00000002 793eee08 00000000 kernel32!WaitForMultipleObjects+0x18
01e6fee0 791fecf4 000002dc 00000000 792376a4 mscorsvr!WaitForFinalizerEvent+0x5a
01e6ff24 79245681 00000000 809a05fe 7ffa4000 mscorsvr!GCHeap::FinalizerThreadStart+0x96
01e6ffb8 77e66063 000d5500 00000000 00000000 mscorsvr!Thread::intermediateThreadProc+0x44
01e6ffec 00000000 79245640 000d5500 00000000 kernel32!BaseThreadStart+0x34
Idle CLR Debugger Thread
12 Id: fb8.b30 Suspend: 0 Teb: 7ffa9000 Unfrozen
ChildEBP RetAddr Args to Child
01adfe70 7c822114 77e6711b 00000003 01adfec0 ntdll!KiFastSystemCallRet
01adfe74 77e6711b 00000003 01adfec0 00000001 ntdll!NtWaitForMultipleObjects+0xc
01adff1c 77e61075 00000003 01adff5c 00000000 kernel32!WaitForMultipleObjectsEx+0x11a
01adff38 79238fd6 00000003 01adff5c 00000000 kernel32!WaitForMultipleObjects+0x18
01adffa0 79238f4d 00000000 00000000 00000000 mscorsvr!DebuggerRCThread::MainLoop+0x90
01adffb0 7923a714 01adffec 77e66063 019d1eb0 mscorsvr!DebuggerRCThread::ThreadProc+0x68
01adffb8 77e66063 019d1eb0 00000000 00000000 mscorsvr!DebuggerRCThread::ThreadProcStatic+0xb
01adffec 00000000 7923a709 019d1eb0 00000000 kernel32!BaseThreadStart+0x34
W3wp Threads
The basic threads in w3wp are the main thread, the Thread Pool Threads and the Compression thread.
The main Thread is responsible for starting and shutting down the process. The thread pool threads handle incoming requests and the compression thread just like the name suggests handles compression.
W3wp main thread
. 0 Id: fb8.fd8 Suspend: 0 Teb: 7ffdf000 Unfrozen
ChildEBP RetAddr Args to Child
0006fc08 7c822124 77e6baa8 00000184 00000000 ntdll!KiFastSystemCallRet
0006fc0c 77e6baa8 00000184 00000000 00000000 ntdll!NtWaitForSingleObject+0xc
0006fc7c 77e6ba12 00000184 ffffffff 00000000 kernel32!WaitForSingleObjectEx+0xac
0006fc90 5a36467a 00000184 ffffffff 00000000 kernel32!WaitForSingleObject+0x12
0006fca0 5a366e63 00254ff8 5a3af41d 00000000 w3dt!WP_CONTEXT::RunMainThreadLoop+0x10
0006fca8 5a3af41d 00000000 64711da9 00000000 w3dt!UlAtqStartListen+0x2d
0006fcb8 5a3bc259 0100141c 010013e4 010012d0 w3core!W3_SERVER::StartListen+0xbd
0006ff0c 0100187c 00000007 002538e0 00000000 w3core!UlW3Start+0x26e
0006ff44 01001a23 00000007 002538e0 002543d0 w3wp!wmain+0x22a
0006ffc0 77e523cd 00000000 00000000 7ffd7000 w3wp!wmainCRTStartup+0x12b
0006fff0 00000000 010018f8 00000000 78746341 kernel32!BaseProcessStart+0x23
Idle w3wp ThreadPoolThread
2 Id: fb8.c5c Suspend: 0 Teb: 7ffd9000 Unfrozen
ChildEBP RetAddr Args to Child
00c8ff24 7c821bf4 77e6611a 00000170 00c8ff80 ntdll!KiFastSystemCallRet
00c8ff28 77e6611a 00000170 00c8ff80 00c8ff6c ntdll!NtRemoveIoCompletion+0xc
00c8ff54 5a30249e 00000170 00c8ff7c 00c8ff80 kernel32!GetQueuedCompletionStatus+0x29
00c8ff8c 5a3026bc 00000000 00258580 5a300000 w3tp!THREAD_POOL_DATA::ThreadPoolThread+0x33
00c8ffa0 5a301db9 00000102 00000000 00000000 w3tp!THREAD_POOL_DATA::ThreadPoolThread+0x24
00c8ffb8 77e66063 00258580 00000000 00000000 w3tp!THREAD_MANAGER::ThreadManagerThread+0x39
00c8ffec 00000000 5a301d80 00258580 00000000 kernel32!BaseThreadStart+0x34
Idle w3wp Compression Thread
7 Id: fb8.b20 Suspend: 0 Teb: 7ffaf000 Unfrozen
ChildEBP RetAddr Args to Child
017dfa84 7c822124 77e6baa8 000001d0 00000000 ntdll!KiFastSystemCallRet
017dfa88 77e6baa8 000001d0 00000000 00000000 ntdll!NtWaitForSingleObject+0xc
017dfaf8 77e6ba12 000001d0 ffffffff 00000000 kernel32!WaitForSingleObjectEx+0xac
017dfb0c 5a3b8147 000001d0 ffffffff 00000000 kernel32!WaitForSingleObject+0x12
017dffb8 77e66063 00000000 00000000 00000000 w3core!HTTP_COMPRESSION::CompressionThread+0x126
017dffec 00000000 5a3b8021 00000000 00000000 kernel32!BaseThreadStart+0x34
RPC Threads
Having idle LRPC worker threads means that we can handle more local and remote COM activation and local COM method calls.
Having idle RPC worker threads means that we can manage more remote COM method calls.
See the RPC Threading Model doc for more info
Idle RPC Worker Thread
29 Id: fb8.7fc Suspend: 0 Teb: 7ffa1000 Unfrozen
ChildEBP RetAddr Args to Child
02ddfeac 7c821bf4 77e6611a 00000078 02ddff04 ntdll!KiFastSystemCallRet
02ddfeb0 77e6611a 00000078 02ddff04 02ddfef4 ntdll!NtRemoveIoCompletion+0xc
02ddfedc 77c604c3 00000078 02ddff14 02ddff04 kernel32!GetQueuedCompletionStatus+0x29
02ddff18 77c60655 ffffffff 02ddff6c 02ddff70 rpcrt4!COMMON_ProcessCalls+0xa1
02ddff84 77c5f9f1 02ddffac 77c5f7dd 00090250 rpcrt4!LOADABLE_TRANSPORT::ProcessIOEvents+0x117
02ddff8c 77c5f7dd 00090250 00000000 00000000 rpcrt4!ProcessIOEventsWrapper+0xd
02ddffac 77c5de88 0008e610 02ddffec 77e66063 rpcrt4!BaseCachedThreadRoutine+0x9d
02ddffb8 77e66063 029515e8 00000000 00000000 rpcrt4!ThreadStartRoutine+0x1b
02ddffec 00000000 77c5de6d 029515e8 00000000 kernel32!BaseThreadStart+0x34
Idle LRPC Worker Thread
33 Id: fb8.b24 Suspend: 0 Teb: 7ffdb000 Unfrozen
ChildEBP RetAddr Args to Child
02e1fe18 7c821c54 77c7538c 00000138 02e1ff74 ntdll!KiFastSystemCallRet
02e1fe1c 77c7538c 00000138 02e1ff74 00000000 ntdll!ZwReplyWaitReceivePortEx+0xc
02e1ff84 77c5778f 02e1ffac 77c5f7dd 0009d660 rpcrt4!LRPC_ADDRESS::ReceiveLotsaCalls+0x198
02e1ff8c 77c5f7dd 0009d660 00000000 00000000 rpcrt4!RecvLotsaCallsWrapper+0xd
02e1ffac 77c5de88 0008e610 02e1ffec 77e66063 rpcrt4!BaseCachedThreadRoutine+0x9d
02e1ffb8 77e66063 05057c08 00000000 00000000 rpcrt4!ThreadStartRoutine+0x1b
02e1ffec 00000000 77c5de6d 05057c08 00000000 kernel32!BaseThreadStart+0x34
Other COM Threads
Single threaded components must be handled by the Host (Main) STA Thread which is the first COM STA Thread created.
Having an idle STA Thread means that we can handle more STA activation and method calls.
For more info see the COM threads doc.
Host STA Thread
31 Id: fb8.b3c Suspend: 0 Teb: 7ff4e000 Unfrozen
ChildEBP RetAddr Args to Child
049cff14 7739c78d 7739c7c0 049cff58 00000000 ntdll!KiFastSystemCallRet
049cff34 77694ff1 049cff58 00000000 00000000 user32!NtUserGetMessage+0xc
049cff74 776cf35b 00007530 77e6ba20 02a40fe0 ole32!CDllHost::STAWorkerLoop+0x72
049cff90 776cf2a3 049cffb8 776b2307 77790438 ole32!CDllHost::WorkerThread+0xc8
049cff98 776b2307 77790438 00000000 02a40fe0 ole32!DLLHostThreadEntry+0xd
049cffac 776b2374 00000000 049cffec 77e66063 ole32!CRpcThread::WorkerLoop+0x1e
049cffb8 77e66063 02a40fe0 00000000 00000000 ole32!CRpcThreadCache::RpcWorkerThreadEntry+0x20
049cffec 00000000 776b2354 02a40fe0 00000000 kernel32!BaseThreadStart+0x34
Idle STA Thread
14 Id: e5c.d90 Suspend: 1 Teb: 7ffac000 Unfrozen
ChildEBP RetAddr Args to Child
0140fdcc 77f4372d 77e41bfa 00000003 0140fe1c SharedUserData!SystemCallStub+0x4
0140fdd0 77e41bfa 00000003 0140fe1c 00000001 ntdll!NtWaitForMultipleObjects+0xc
0140fe78 77d076f5 00000003 0140fea0 00000000 kernel32!WaitForMultipleObjectsEx+0x11a
0140fed4 77d077f5 00000002 0140ff74 ffffffff USER32!RealMsgWaitForMultipleObjectsEx+0x13f
0140fef0 7563439d 00000002 0140ff74 00000000 USER32!MsgWaitForMultipleObjects+0x1d
0140ff84 77bc91ed 000b6eb8 00000000 00000000 COMSVCS!CSTAThread::WorkerLoop+0x1e3
0140ffb8 77e4a990 00268a58 00000000 00000000 msvcrt!_threadstartex+0x6f
0140ffec 00000000 77bc917e 00268a58 00000000 kernel32!BaseThreadStart+0x34
Note: This is by no means a complete list of the types of threads you can see but it should give you a good idea of what you are looking at and what threads you can immediately ignore when searching for the culprit of your hang.
Merry X-mas to all