IIS나 ASP.Net 관련 Dump 분석에서 많이 참고하는 Tess의 MSDN 블로그에 덤프 분석에 유용하게 사용 될 수 있는 Posting이 있어서 소개 합니다.

 

이 포스트는 Tess의 Things to ignore when debugging an ASP.NET hang(http://blogs.msdn.com/tess/archive/2005/12/20/505862.aspx) 을 약간 번역(오역?) 한 내용 입니다. 기술 내용의 특징상 사람이 보려고 만든 내용은 아닐 듯 한데 생각보다 많은 분들이 관련 내용에 관심을 가지시더군요.

 

어떤 문제가 발생한 덤프를 분석한다는 것이 쉬운 일은 아닙니다. 특히, 어느 특정 시점에 작동 중이 프로세스의 Snapshot인 Dump만으로 이전/이후 상황을 설명하고 파악한다는 것은 나름 많은 기반 지식과 경험이 필요한 일 입니다.

 

분석 중 가장 필요한 내용 중 하나가 정상 적인 Thread의 Stack trace를 빨리 무시(?) 해 나가는 것 입니다.

아래의 Stack Trace들은 IIS 6.0 W3WP.EXE 프로세스에서 실행 중인 Thread들의 내용입니다. 특이 이들 Thread들은 대부분 대기 상태인 Worker Thread들이기 때문에 (일이 없어서 쉬는 상태 - Idle)  덤프 분석 중 무시 하실 수 있습니다. 분석의 속도를 높여 줄 수 있겠지요.


Tess의 포스트에서 노트로도 나옵니다만 아래 Thread의 Stack Trace는 실제 프로세스 덤프에서 확인 하실 수 있는 대표적인 것들만 요약한 것이며 더 많은 복잡한 Thread들이 작동 중일 수 있습니다.

 

원래 IIS에서 실행되는 Thread들의 종료가 많기 때문에 Tess는 아래와 같이 Thread들을 분류 하고 있습니다.

 

- CLR Threads
- W3WP Threads
- RPC Threads
- Other COM Threads

 

CLR Threads

.Net Framework과 관련된 Thread들 입니다. .Net Framework의 ThreadPool은 5가지 종류의 Thead 가 있습니다.

 

프로그래머가 작성한 코드 (Managed 내지는 .Net CLR 코드) 는 Completion Port/IO Threads와 Worker Thread들에 의해서 실행 됩니다.

Gate Thread( 문지기)는 서버 CPU 사용량, GC(Garbage Collection) 주기와 Worker Queue의 크기를 전반적으로 고려해서 필요한 경우 Worker Thread와 IO Thread들을 만들거나 파괴 합니다. Wait Thread들은 동기화 객체들에 대해서 대기하는 경우 사용 됩니다. 즉, 개발자가 사용하는 WaitHandle 클래스를 사용하는 경우 결과적으로 "WaitForSingleObject"가 호출이 되겠지요. 마지막으로 Timer Callback을 구현하는데는 Timer Thread들에 사용 됩니다.

그럼 이들 Thread들이 ASP.Net 1.1을 서비스하는 W3WP.exe 프로세스의 덤프에서 어떻게 나타나는지 보도록 하겠습니다.

 

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

 

 

.Net Framework의 수행 과정에서 빠질 수 없는 중요 Thread 몇가지를 아래에서 설명하고 있습니다.

이들중 가장 중요한 것으로 GC(Garbage Collector) Thread가 있습니다. GC Thread는 CLR의 Managed Heap 메모리를 관리합니다.

프로세서(Processor, CPU가 여러개 설치 되어 있거나 최근의 Multi-Core CPU를 사용하는 경우) 서버 버젼의 GC Thread는 CPU 들 마다 하나 씩 생성이 됩니다. Hyper-Threading 방식의 다중 CPU의 경우에는 서버 설정에 따라서 2개 CPU당 (Task Manager에서 확인되는) 하나의 GC Thread가 만들어 질 수 있습니다.

잠시 서버 버젼이라는 얘기가 나와서 부연 설명을 하자면 .Net Framework 1.1에서는 Server 버젼과 Workstation 버젼의 2개의 GC가 존재하며 서버 버젼의 경우 프로세스에 MSCORSVR.DLL 이, 클라이언트의 경우 (WinForm Application과 같은 경우) MSCORWKS.DLL이 로딩됩니다.

GC Thread와 달리 Finalizer Thread는 프로세스당 하나가 실행 됩니다. Hang이나 메모리 사용량이 많은 문제가 있는 프로세스에서는 Finalizer를 자세히 관찰할 필요가 있습니다. Finalize가 정상 작동 하지 않고 멈춰있는 경우 Finalzing이 정상적으로 되지 못해 완전히 파괴되지 못한 객체들 때문에 memory leak (점진적인 메모리 점유 현상)이 발생할 수 있고 이때문에 잦은 GC 가 발생하여 CPU 사용량이 높아지는 경우도 있습니다.

마지막으로 Debugging 시 사용되는 Debugger Thread도 나오네요.

 

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 Thread들

W3WP 프로세서에서는 기본적으로 main Thread, W3WP Thread Pool Thread와 Compression Thread(HTTP Stream 압축용) 가 생성/작동 됩니다.

Main Thread는 프로세스의 시작고 종료를 담당 합니다. 웹서버에 전달되는 Request들은 Thread Pool Thread가 처리 합니다.

아래 Thread들의 Stack Trace들 여기 일없이 대기 중인 것 들 입니다.

 

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

놀고 있는 (Idle) LRPC Worker Thread들이 보인다면 이는 프로세스가 좀더 많은 리모트 COM 객체를 활성화 하거나 로컬 또는 리모트 COM method call들을 처리 할 수 있다는 뜻 입니다.

RPC Threading Model에 대해서는 http://msdn.microsoft.com/library/default.asp?url=/library/en-us/rpc/rpc/scalability.asp  을 참고하세요.

 

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

 
기타 COM Threads

STA컴퍼넌트(Single threaded component)들은 Main STA Thread에서 처리가 됩니다. Main STA는 최초로 실행된 COM STA Thread가 생성을 하게 되구요.

이전과 마찬 가지로 STA Thread들이 놀고 있다는 얘기는 현재 전달되어  Request가 적거나 없고 앞으로 전달 되는 Request들을 더 많이 처리 할 수 있다는 뜻 입니다.

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

 

COM Threading에 대해서는 다음의 URL을 참고 하세요.

COM Threading and Application Architecture in COM+ Applications

http://msdn.microsoft.com/library/default.asp?url=/library/en-us/dncomser/html/comthread.asp