2009/07/10 Monitor Lock에 의한 hang 현상 debugging
2009/07/08 일부 레지스터의 사용에 관하여 2009/07/01 메시지(Window Message) 따라 디버깅 2009/06/22 성능로그를 통한 GC에 의한 High CPU 확인 2009/06/15 Internet Explorer+VB Runtime에서의 Crash 현상 .NET에서 lock 을 목적으로 가장 많이 사용되는 것이 Monitor 가 아닐까 한다. (사실 Multiple Processes사이에서의 Lock이 필요하다면, Mutex를 이용하는 데, 그렇지 않은 경우라면 좀처럼 Mutex를 이용하지 않는 다. 이유는 대략 Monitor에 비해 50여배정도의 low Performance를 나타낸다고 한다. –C# 3.0 in a nutshell에 의하면) 쉽게 Enter/TryEnter 나 Exit 을 통해 Object에 Lock 을 거는 형태인데, single thread 만 허용하도록 하는 데 목적이 있다. C#에서는 단순하게 lock keyword 를 사용하는 경우가 Monitor를 대신하는 역할을 한다. 그러므로, Exit이 호출되기까지 마치 Critical Section Lock이 걸린 듯하게 된다. 그러므로, Multiple Threaded 환경에서 Exit이 되지 않은 상태에서 Exception이 발생하거나 Thread가 Drop되는 경우 등등에서 Application Hang이 발생할 수도 있고, 또한 DeadLock이 발생할 수도 있다. 이런 hang 상태일 경우를 메모리dump에서 확인하는 과정은 !syncblk 라는 SOS Extension에서 제공하는 Command를 이용하는 방법이다. 0:005> !syncblk Index SyncBlock MonitorHeld Recursion Owning Thread Info SyncBlock Owner 20 0017439c 7 1 0018fe10 a5c 17 08e05824 System.Web.Compilation.BuildManager 0:005> !threads ThreadCount: 14 UnstartedThread: 0 BackgroundThread: 14 PendingThread: 0 DeadThread: 0 Hosted Runtime: no PreEmptive GC Alloc Lock ID OSID ThreadOBJ State GC Context Domain Count APT Exception 5 1 aac 00151e18 2008220 Enabled 04e843b8:04e84fe8 00191270 1 Ukn 11 2 69c 00160500 b220 Enabled 00000000:00000000 00157258 0 MTA (Finalizer) 12 3 ad8 00176250 80a220 Enabled 00000000:00000000 00157258 0 MTA (Threadpool Completion Port) 13 4 a0c 0018d698 8801220 Enabled 00000000:00000000 00157258 0 Ukn (Threadpool Completion Port) 14 5 aa4 0018dd30 380b220 Enabled 08e8e38c:08e8efe8 00191270 1 MTA (Threadpool Worker) 15 6 a94 0018e5f8 8801220 Enabled 00000000:00000000 00157258 0 Ukn (Threadpool Completion Port) 1 7 948 0018eda0 880a220 Enabled 00000000:00000000 00157258 0 MTA (Threadpool Completion Port) 16 8 ab4 0018f658 8801220 Enabled 00000000:00000000 00157258 0 Ukn (Threadpool Completion Port) 17 9 a5c 0018fe10 180b220 Enabled 0ce914f8:0ce92fe8 00191270 4 MTA (Threadpool Worker) 18 a ae0 00190918 1220 Enabled 00000000:00000000 00157258 0 Ukn 19 b aa8 00192e18 180b220 Enabled 0cecf71c:0ced0fe8 00191270 1 MTA (Threadpool Worker) 21 c 7a4 001dc8e0 180b222 Disabled 04eec338:04eecfe8 00191270 3 MTA (Threadpool Worker) 22 d 664 00201108 380b220 Enabled 0ceca780:0cecafe8 00191270 1 MTA (Threadpool Worker) 25 e 500 0021b030 180b220 Enabled 00f10350:00f10814 00191270 1 MTA (Threadpool Worker) !syncblk의 결과값을 보면, 오브젝트 System.Web.Compilation.BuildManager(08e05824)가 Lock이 걸려있는 상태임을 알 수 있다. 그리고, MonitorHeld 가 7이라는 것은 (7-1)/2 하여 대략 3개의 Thread가 해당 Object를 접근하려고 기다리는 것임을 알 수 있다. 보통은 아래와 같은 Thread가 접근하는 Thread가 되겠다. ChildEBP RetAddr Args to Child 1ce4edec 7c59a23d 00000001 1ce4ee14 00000001 NTDLL!ZwWaitForMultipleObjects+0xb 1ce4ee3c 79f8ead4 1ce4ee14 00000001 00000000 KERNEL32!WaitForMultipleObjectsEx+0xea 1ce4eea4 79f17522 00000001 001743b0 00000000 mscorwks!WaitForMultipleObjectsEx_SO_TOLERANT+0x6f 1ce4eec4 79f17493 00000001 001743b0 00000000 mscorwks!Thread::DoAppropriateAptStateWait+0x3c 1ce4ef48 79f1732f 00000001 001743b0 00000000 mscorwks!Thread::DoAppropriateWaitWorker+0x144 1ce4ef98 79f8ea4d 00000001 001743b0 00000000 mscorwks!Thread::DoAppropriateWait+0x40 1ce4eff4 79e77f50 ffffffff 00000001 00000000 mscorwks!CLREvent::WaitEx+0xf7 1ce4f004 7a0fd9c3 ffffffff 00000001 00000000 mscorwks!CLREvent::Wait+0x17 1ce4f090 7a0fdbbf 00201108 ffffffff 0017439c mscorwks!AwareLock::EnterEpilog+0x94 1ce4f0ac 7a0fdd2a f6aa917c 00201108 00201108 mscorwks!AwareLock::Enter+0x61 1ce4f110 7a094352 ffffffff f6aa91dc 0ceca598 mscorwks!AwareLock::Contention+0x16c 1ce4f1b0 65fb7bcf 79e73dce 08e05824 00000000 mscorwks!JITutil_MonContention+0xa3 1ce4f1f0 65fcf629 00000000 00000000 00000000 System_Web_ni!System.Web.Compilation.BuildManager.GetBuildResultFromCacheInternal(System.String, Boolean, System.Web.VirtualPath, Int64)+0x77 1ce4f26c 65fcf2ef 00000000 00000000 00000000 System_Web_ni!System.Web.Compilation.BuildManager.GetVPathBuildResultFromCacheInternal(System.Web.VirtualPath)+0x29 1ce4f26c 65fcf266 00000000 00000000 00000000 System_Web_ni!System.Web.Compilation.BuildManager.GetVPathBuildResultInternal(System.Web.VirtualPath, Boolean, Boolean, Boolean)+0x37 1ce4f2a8 66036b2d 00000000 00000000 00000000 System_Web_ni!System.Web.Compilation.BuildManager.GetVPathBuildResultWithNoAssert(System.Web.HttpContext, System.Web.VirtualPath, Boolean, Boolean, Boolean)+0x5e 1ce4f2d4 661528dc 00000000 00000000 00000000 System_Web_ni!System.Web.Compilation.BuildManager.GetVPathBuildResult(System.Web.HttpContext, System.Web.VirtualPath)+0x31 1ce4f2d4 69926307 00000000 00000000 00000000 System_Web_ni!System.Web.UI.WebServiceParser.GetCompiledType(System.String, System.Web.HttpContext)+0x2c 1ce4f2ec 65fb94bc 00000000 00000000 00000000 System_Web_Services_ni!System.Web.Services.Protocols.WebServiceHandlerFactory.GetHandler(System.Web.HttpContext, System.String, System.String, System.String)+0x47 1ce4f32c 65fce689 00000000 00000000 00000000 System_Web_ni!System.Web.HttpApplication.MapHttpHandler(System.Web.HttpContext, System.String, System.Web.VirtualPath, System.String, Boolean)+0xb0 Monitor Lock의 내부적인 구조는 mscorwks!AwareLock이다. 그러므로, mscorwks!AwareLock::Enter 는 Monitor Lock의 Enter에 해당한다고 보면 된다. 그리고, !syncblk의 결과에서 owning thread는 Lock안에 들어가 있는 Thread가 된다. 그러므로, 17번 Thread가 현재 System.Web.Compilation.BuildManager(08e05824)를 잡고 있는 Thread이므로 해당 Thread에서 exit 되지 않으며 다른 3개의 Thread에서의 처리를 요청한 User는 Hang을 느낄 수 있다. 0:017> !dso OS Thread Id: 0xa5c (17) ESP/REG Object Name . . . 1a3cf2f0 08e05824 System.Web.Compilation.BuildManager 0:017> kb ChildEBP RetAddr Args to Child 1a3ccd60 7c59a072 000001cc 00000000 00000000 NTDLL!ZwWaitForSingleObject+0xb 1a3ccd88 79e77fd1 000001cc ffffffff 00000000 KERNEL32!WaitForSingleObjectEx+0x71 1a3ccdcc 79e77f9a 000001cc ffffffff 00000000 mscorwks!PEImage::LoadImage+0x199 1a3cce1c 79e77f50 ffffffff 00000000 00000000 mscorwks!CLREvent::WaitEx+0x117 1a3cce2c 79f3b282 ffffffff 00000000 00000000 mscorwks!CLREvent::Wait+0x17 1a3cce3c 79f75d6a 00000000 f072ae20 00000000 mscorwks!SVR::GCHeap::WaitUntilGCComplete+0x32 1a3cce78 79e7ada1 f072aedc 00000000 1a3ccef8 mscorwks!Thread::RareDisablePreemptiveGC+0x1a1 1a3cceb0 79e7a6c9 79e7a6bd 0014a290 79e7a2c3 mscorwks!CrstBase::Enter+0x1e6 1a3cceb4 79e7a6bd 0014a290 79e7a2c3 7a38cf40 mscorwks!EEEnterCriticalSection+0x9 1a3ccebc 79e7a2c3 7a38cf40 0014a290 79eab324 mscorwks!CExecutionEngine::AcquireLock+0x9 1a3ccec8 79eab324 0014a290 002148f0 7a144ea3 mscorwks!ClrEnterCriticalSection+0xf 1a3cced4 7a144ea3 f072af58 00000000 002148f0 mscorwks!CCriticalSection::Lock+0x17 1a3cdb80 7a14560a 00000000 0000000a 00000000 mscorwks!CAssemblyCacheItem::MoveAssemblyToFinalLocation+0x31f 1a3cdbc8 7a143a97 0000000a 00000000 00000000 mscorwks!CAssemblyCacheItem::LegacyCommit+0x245 1a3cdc04 7a15e4b4 002148f0 00000000 00000000 mscorwks!CAssemblyCacheItem::Commit+0x5d 1a3ce2b0 7a15e936 1a3ce644 001f79c0 1a3ce328 mscorwks!CAsmDownloadMgr::CreateAssembly+0x85b 1a3ce2ec 7a15f074 1a3ce644 001f79c0 1a3ce328 mscorwks!CAsmDownloadMgr::DoSetupPushToCache+0x50 1a3ce574 79f8e8f8 001fc230 001f79c0 1a3ce644 mscorwks!CAsmDownloadMgr::DoSetup+0x26a 1a3ce5c0 79f8c05c 1a3ce644 00000000 f0728598 mscorwks!CAssemblyDownload::DoSetup+0x7b 1a3ce5f4 79f8bf74 00000000 1a3ce644 00000000 mscorwks!CAssemblyDownload::DownloadComplete+0xb6 상위에서는 PEImage가 Load 될 때까지는 Lock이 풀리지 않을 듯… 레지스터는 CPU 연산에 필요한 데이타를 사용하기 위한 저장고이다. IA32 체계에서 EAX, EBX ECX, ESI, EDI 등등의 명칭으로 사용되고 있는 데, 각 register가 사용되는 용도가 구분되어 있다. (참고: http://ko.wikipedia.org/wiki/IA32#.EB.A0.88.EC.A7.80.EC.8A.A4.ED.84.B0) Debugging 하다 보면, Assembly 언어를 분석할 때, register의 용도에 따라서 적절히 분석되는 것이 필요한데 몇가지 문서에 언급외에 독특한 register의 사용에 대해서 언급하고자 한다. 0:000> u 766dbf97-10 766dbf97+10 wininet!MEMMAP_FILE::ValidateListGroupOffset+0x38: 766dbf87 038d34118bc6 add ecx,dword ptr [ebp-3974EECCh] 766dbf8d 5e pop esi 766dbf8e 5d pop ebp 766dbf8f c20400 ret 4 766dbf92 90 nop 766dbf93 90 nop 766dbf94 90 nop 766dbf95 90 nop 766dbf96 90 nop wininet!MEMMAP_FILE::GrowMapFile: 766dbf97 8bff mov edi,edi 766dbf99 55 push ebp 766dbf9a 8bec mov ebp,esp 766dbf9c 56 push esi 766dbf9d 8bf1 mov esi,ecx 766dbf9f 8b4604 mov eax,dword ptr [esi+4] 766dbfa2 8b4e18 mov ecx,dword ptr [esi+18h] 766dbfa5 69c080ed0100 imul eax,eax,offset <Unloaded_es_kr.dll>+0x1ed6f (0001ed80) Nop 는 No-operation이다. 근데, Function starting point에 (노란색 블럭)mov edi, edi 가 보인다. 사실 그 아래 push ebp; mov ebp, esp; 는 일반적으로 Stack Frame을 만드는 시작 code이다. ebp가 stack의 base address이므로, 앞선 Function의 stack frame에 대한 base address를 stack에 save 하여 보존하고, 현 시점의 stack pointer를 base address로 지정하여 새로운 stack frame을 시작하도록 하는 역할을 한다. 그러므로, 그 앞서서 있는 mov edi, edi는 아무런 의미가 없다. 즉, nop와 동일하다. 다른 점이라면, 2bytes opcode로써의 nop라는 점이다. 이는 나중에 jmp code로 변경하여 Hot patching에 이용되도록 집어 넣어둔 code이다. 이와 같은 방식은 CLR에서 method jitting의 경우도 방법자체로 보면 유사하다. MethodDesc 는 RVA라는 거의 의미 없는 값을 가지고 있다가 나중에 JIT에 의해서 code가 generation된 이후에는 jmp instruction으로 해당 code address를 가리키도록 op code가 변경되는 구조를 갖는 다. 그 다음은 ecx/esi 에 대한 부분이다. ecx는 일반적으로 loop의 counter역할을 담당한다. 하지만, Debugging 할때 가장 많이 경험하는 것은 counter의 역할보다는 this pointer를 넘기는 데, 많이 사용된다. ChildEBP RetAddr Args to Child 00125bfc 76698bd7 00004000 00125c74 00000020 wininet!MEMMAP_FILE::GrowMapFile+0xb0 (FPO: [1,0,0]) 00125c38 7667ff81 00001000 00000031 00000000 wininet!MEMMAP_FILE::AllocateEntry+0x4d (FPO: [Non-Fpo]) 0:000> ub 76698bd7 . . . 76698bcf 50 push eax 76698bd0 8bcb mov ecx,ebx <- - - this pointer wininet!MEMMAP_FILE Class 76698bd2 e8c0330400 call wininet!MEMMAP_FILE::GrowMapFile (766dbf97) This pointer는 곧바로 esi register로 mov 된다. ecx register는 Frame 안에서 counter와 같은 범용레지스터로 사용되기 때문에 this pointer보존을 위해 esi로 mov 하고, esi+offset 형태로 this class의 member function이나 member property에 접근할 수 있다. 아래와 같은 assembly code 형태가 말해준다. 766dbf9c 56 push esi 766dbf9d 8bf1 mov esi,ecx 766dbf9f 8b4604 mov eax,dword ptr [esi+4] 766dbfa2 8b4e18 mov ecx,dword ptr [esi+18h] 그리고, 또한 eax register 의 역할이다. 아래 assembly code를 보면, function이 call되기 전에 push에 의해서 parameter를 전송하는 아름다운 모습이 보인다. 이는 Function의 calling convention에 의존적이다. 그리고, 나면, 저 아래께 쯤에 cmp instruction에 뜬금없는 eax와 ecx의 비교가 보인다. ecx는 esi+offset의 언급한 this class의 member property로 부터 온것임을 알 수 있다. 그럼, eax는 무엇인가 . 766dbfc2 6a02 push 2 766dbfc4 6a00 push 0 766dbfc6 57 push edi 766dbfc7 ff761c push dword ptr [esi+1Ch] 766dbfca ff1570116676 call dword ptr [wininet!_imp__SetFilePointer (76661170)] 766dbfd0 8b4e18 mov ecx,dword ptr [esi+18h] 766dbfd3 03cf add ecx,edi 766dbfd5 3bc1 cmp eax,ecx 이는 SetFilePointer function의 return value 이다. eax는 항상 function call이후에 return 값을 저장하는 데, 사용된다. Message 기반의 Window에서 특히 MFC Application 같은, Debugging 시에 특정 Button을 Click 하면 Button Click에 대한 Function Call이 호출되고 어쩌구저쩌구 하는 경우, 간혹, 정확한 정보를 모르는 상태에서 Debugging을 하다 보면 난감할 때가 있다. 이런 경우, 가장 유용한 방법이 SPY Tool을 이용하는 것이다. 예를 들어, button하나 누르는 MFC Application을 가지고 살펴보면, 아래는 SPY로 main window를 잡은 화면이다. 지금 하고자 하는 것은 button click하는 함수를 찾아 들어가는 것이다. (굳이 왜 이런 짓을 ..
SPY TOOL을 열어놓고, 메뉴의 Search 에서 Find Window 하여 MFC Application의 Main window에 drag하면 Windows1 화면에서 Highlighted 된 Window가 바로 그놈 이다. 이름이 MfcBtnTest 라는 놈이다. 그리고, View 메뉴에서 속성을 확인하면 Property Inspector라는 창이 뜬다. 원하는 정보는 WinProc 이다. 여기에 5804f141 이라는 Address가 보인다. 이게 뭘까 …. WinDbg로 해당 Application에 걸면 WinProc Function이 보일 테이다. 아래와 같다. 아시다시피 AfxWndProcBase 이다. MFC Application의 기본적인 WinProc 이 되겠다. 보통 일반적인 Window Application 이라면, WindowProc (http://msdn.microsoft.com/en-us/library/ms633573(VS.85).aspx) 일 텐데.. 0:001> ln 5b04f141 f:\dd\vctools\vc7libs\ship\atlmfc\src\mfc\afxstate.cpp(439) ß아시다시피 해당 소스는 VS에서 구할 수 있다. C:\Program Files\Microsoft Visual Studio 9.0\VC\atlmfc\src (5b04f141) mfc90u!AfxWndProcBase | (5b04f1c1) mfc90u!AfxGetAppModuleState Exact matches: mfc90u!AfxWndProcBase (struct HWND__ *, unsigned int, unsigned int, long) 조금은 복잡하게 됐다. 그리고, button click에 대한 Function을 쫓아 갈 차례다. WindowProc이건 AfcWndProcBase 건 간에 Message ID로 주고 받는 다. 이것도 역시 SPY로 정보를 얻을 수 있다. Main Window에서 Message Filtering을 하는 데, WM_COMMAND 를 잡으면 된다.
wID 는 Msg 정보를 나타낸다. 1000(0x3e8) 이것이 Message 정보이다. 그러므로, Message Handler로 0x3e8 이 처리되는 것이 바로 내가 원하는 Button Click 시의 Message 를 나타낸다. 간단하게는 WindowProc의 Assembly Code에서 0x3e8을 Handling 하는 놈을 찾으면 되겠다. MFC에서는 _AfxDispatchCmdMsg 함수에서 0x3e8(두 번째 parameter)을 Handling 하여 원하는 Function으로 보낸다. 0:000> kp ChildEBP RetAddr 001af54c 5b080346 mfc90u!_AfxDispatchCmdMsg(class CCmdTarget * pTarget = 0x001afc20, unsigned int nID = 0x3e8, int nCode = 1766796, <function> * pfn = 0x01031440, void * pExtra = 0x00000000, unsigned int nSig = 0, struct AFX_CMDHANDLERINFO * pHandlerInfo = 0x00000000) [f:\dd\vctools\vc7libs\ship\atlmfc\src\mfc\cmdtarg.cpp @ 54] 001af568 5b070e92 mfc90u!CCmdTarget::OnCmdMsg(unsigned int nID = 0x3e8, int nCode = 0, void * pExtra = 0x00000000, struct AFX_CMDHANDLERINFO * pHandlerInfo = 0x00000000)+0x124 [f:\dd\vctools\vc7libs\ship\atlmfc\src\mfc\cmdtarg.cpp @ 381] . . . 0:000> ln 0x01031440 g:\codes\mfcbtntest\mfcbtntest\mfcbtntestdlg.cpp(154) (01031440) MfcBtnTest!CMfcBtnTestDlg::OnBnClickedButton1 | (01031460) MfcBtnTest!CDialog::Create Exact matches: MfcBtnTest!CMfcBtnTestDlg::OnBnClickedButton1 (void) 0:000> uf 0x01031440 MfcBtnTest!CMfcBtnTestDlg::OnBnClickedButton1 [g:\codes\mfcbtntest\mfcbtntest\mfcbtntestdlg.cpp @ 154]: 154 01031440 6a00 push 0 156 01031442 68e0350301 push offset MfcBtnTest!`string' (010335e0) 156 01031447 68e0350301 push offset MfcBtnTest!`string' (010335e0) 156 0103144c 6a00 push 0 156 0103144e ff15b8300301 call dword ptr [MfcBtnTest!_imp__MessageBoxW (010330b8)] 157 01031454 c3 ret 아 왜 이런 쓸데없는 짓을 그냥 OnBnClickButton1에 Break을 걸면 되지 않나.. 머 이럴수도 있겠다만, 맞는 말이다. 하지만, 여러 3rd party application을 Debugging 하다 보면, 복잡한 UI에서 도대체 Button을 Click 하면 어떤 Function으로 들어가는지 아무도 모르는 경우가 존재한다. 또 그런 Application을 Debugging 할 기회(?)도 존재한다. 그와 같은 때 유용하며, 이렇게 SPY와 WinDBG를 통해서 Message를 쫓아가는 경우는 여러 가지 응용도 가능하겠다. Garbage Collector(GC)는 .Net Framework / CLR 에서 Memory를 관리해주는 Module 이다. 그러므로, 개발자의 의도와 상관없이 적절한 시점에 GC가 수행하고, 그것도 비동기적으로 발생하며, 그에 의해 메모리를 효율적으로 사용할 수 있도록 해준다. 문제는 GC가 비동기적으로 수행됨에 의해 임의의 시점에 GC의 수행과 더불어 응용프로그램의 성능에 영향을 줄 수도 있다라는 것이다. 성능에 영향을 미친다는 것은 예상보다 긴 시간 동안에 GC가 수행되고 이에 의해 High CPU상태가 User가 견디기 힘들 정도로 지속될 수 도 있다는 것이다. 그렇다면, .NET Application이 High CPU일 경우에 GC에 의해 영향을 받은 것인지 어떻게 체크할 수 있을 까. 사실 해당 작업은 그렇게 쉽게 확인할 수 없지만, 몇 가지 요소를 통해서 문제를 좁혀나갈 수 있다. 첫 번째로는 %Time IN GC/.NET CLR Memory 성능 카운터의 값을 확인하는 것이다. 이 값은 최근 GC가 수행함에 의해 소요된 시간의 백분율 값이다. 설명은 그렇게 되어 있는 데, 일단, 50% 이상으로 높다라면, Managed Heap에서 Allocation 되는 패턴을 확인해야 한다. 일반적으로 평균 5% 정도나 10%이하라면 신경 쓸 필요가 없어 보인다. 그리고, 5% 이하라면 의미 있는 Data가 아니므로, 어떠한 판단을 하기가 어렵다. 하지만, 50% 이상이라면, Allocated Bytes/sec 를 확인하여 Allocation rate 를 확인하는 것이 필요하다. 실제로, Performance Monitoring을 통해서 % Processor Time이 High CPU상태로 어느 정도 지속이 된다면, 문제라고 판단한다. 그러므로, High CPU를 유발하는 Thread를 Check 하고, Thread Stack을 Check하여 Looping과 같은 Code에 의해 Thread가 High CPU를 유발하는 것이 아닌가 확인하는 작업이 필요하게 되는 데, 해당 Thread가 역시 GC Thread일 수도 있다. 이는 Memory Dump에서 성능로그에 High CPU를 유지하는 Thread ID를 Check하여 해당 Thread ID에 대한 메모리 덤프의 Thread를 Check했을 때, SOS extension에서 제공하는 !threads 의 result 중 GC라고 표시된 Thread와 일치한다면, GC에 의해서 High CPU라고 확인할 수 있을 것이다. 또는 %Time IN GC의 값이 변동이 있을 때, 예를 들어, High에서 Low로 떨어지거나 Low에서 High로 상승하는 시점에 %Processor Time이 Peak를 친다면, GC에 의해서 High CPU가 유발되었다고 추측할 수도 있다. 이는 메모리 덤프에 의한 Double check가 필요하다. % Time IN GC가 높아서 High CPU라는 것은 결국, GC가 너무 자주 수행되거나 오랫동안 수행된다는 것이다. 그러므로, 이미 언급한 것처럼, 일반적인 Allocation rate이 높아서 GC가 자주 발생하는 것이라면, Allocation pattern에 대한 체크가 필요하며, 두 번째는 # GenX GC counters를 확인하는 것이다. 이는 얼마나 자주 GC가 수행되는 지 확인할 수 있을 것이다. 일반적으로 초점이 되는 것은 Gen2 GC이다. Gen0/Gen1은 Performance에 크게 영향을 주지 않는 다. 하지만, Gen2나 Large Object Heap의 경우는 Performance에 영향을 많이 준다. 일반적으로 gen2:gen1 의 비율이 1:10+ 정도라면 크게 우려할 정도가 아니다. 하지만, 그렇지 않다면, gen2에서의 GC 수행이 영향을 미쳤다고 추측하게 된다. 이 경우는 응용프로그램이 gen2에 적재되어 있을 수 있고, 계속해서 promotion이 gen1으으부터 이뤄지고 있다고 판단할 수 있는 데, 결국, gen2까지 살아남은 Objects에 대한 Verification이 필요하다. Gen2까지 살아 남을 필요가 있는 Objects들인가.. 이는 메모리 덤프에서 SOS !dumpheap –stat 및 –gen2 command를 통해서 Objects를 확인할 수 있다. 그러므로, 응용프로그램의 Performance를 위해서 Objects의 조기에 release 하는 Code적인 장치가 필요할 수도 있다. 결국, 이러한 경우에는 개발자가 성능적인 이유를 위해서 적절한 Objects release 를 간여해야 한다는 것이다. GC만을 믿을 수 없다. 마지막으로는 모호하긴 하지만, #induced GC값이다. 해당 값은 프로세스가 시작된 이후에 GC의 발생횟수를 나타낸다. 이 값이 너무 큰 값이라면, 이는 응용프로그램의 버그를 의심할 수 있다. 가끔 메모리 힙의 크기가 증가되는 것을 줄이기 위해서 강제적으로 GC.Collect 를 호출하는 경우가 있는 데, 이로 인하여 오히려 performance 에 문제가 된 것은 아닌지 확인해 볼 수도 있을 것 같으며, 그렇지 않으면, Heap이 Corruption 발생하여 비 정상적인 동작이 있을 수도 있다. 이 경우도 High CPU가 될 수 있음을 확인해야 할 것이다 사실 아직까지 VB runtime이 Internet Explorer에 올라가 있다는 것은 그리 놀랍지 않다. COM개발이 도입이 되면서 ActiveX Control의 개발은 VB가 대체로 대세였다. 개발의 속도 면에서 그리고, User Interface를 쉽게 제공해주는 면에서 거부할 수 없는 선택 이였다. 하지만, VB runtime의 태생적인 Threading Model의 한계는 Internet Explorer가 마치 Server Application Environment 처럼 변모하면서 너무나 많은 제약을 얻을 수 밖에 없게 되었다. 다음의 Crash 현상 역시 이러한 변화 속에서 드러나는 단면이다. 0:000> kbL ChildEBP RetAddr Args to Child WARNING: Frame IP not in any known module. Following frames may be wrong. 001273e8 66107873 0eddbd00 00000000 00127494 <Unloaded_es_kr.dll>+0x64ff81 00127400 66107bec 00000000 00127424 03ffe070 MSVBVM60!ExHandleLBFailure+0x20 00127458 661079e5 03ffe070 80010003 00000004 MSVBVM60!ExLateIdNamed+0xca 00127484 66108b9a 03ffe070 80010003 fffffffd MSVBVM60!ExLateIdSt+0x4a 0012749c 06977430 03ffe070 80010003 00000004 MSVBVM60!__vbaLateIdSt+0x16 00127508 660ca914 0cd4f1d0 00000000 0cd4f1d0 ttt!DllCanUnloadNow+0x2e61e 00127564 660cae57 00000006 00000001 0e801210 MSVBVM60!RUN_INSTMGR::ExecuteInitTerm+0x178 00127598 660caab3 00000000 00000013 0400758c MSVBVM60!RUN_INSTMGR::CreateObjInstanceWithParts+0x1e4 00127618 660cbc3a 0cd4f1ec 00000000 00127a00 MSVBVM60!RUN_INSTMGR::CreateObjInstance+0x14d 001278cc 66072b6e 001278e4 00000000 03ffa66d MSVBVM60!TipCreateInstanceEx+0xd5 00127908 66078642 01572100 06930000 00000000 MSVBVM60!CThreadPool::CreateInstanceFactory+0xfd 00127a04 66078226 03ff4e8c 00000000 00000000 MSVBVM60!CPrivClassFactory::CreateInstanceLic+0x16e 00127a20 7e605619 03ff4e8c 00000000 7e3a3028 MSVBVM60!CPrivClassFactory::CreateInstance+0x1a 00127a5c 7e60aa10 031d8e48 031d9654 80004005 mshtml!COleSite::InstantiateObjectFromCF+0x114 00129ae0 7e60b386 7e3b919c 03ff4e8c 031d9654 mshtml!COleSite::CreateObjectNow+0xa5 00129b04 7e60bc1a 031d9610 7e3b919c 03ff4e8c mshtml!CCodeLoad::OnObjectAvailable+0x84 00129b78 7e60bf76 7e391b04 00129c68 031d8e00 mshtml!CCodeLoad::BindToObject+0x460 00129b98 7e605369 031d8e00 00129c68 7e60f904 mshtml!CCodeLoad::Init+0x287 00129c18 7e60f85c 00129c68 13ca5100 031d9470 mshtml!COleSite::CreateObject+0x26d 0012ddc8 7e5f393b 7e4306e9 13c9b6c0 00000020 mshtml!CObjectElement::CreateObject+0x72a es_kr.dll 이 unload되었다고 믿기 어렵다. 최종 Stack에서 Assembly를 Check하더라고 이것이 정확한 instruction인지 믿기 어려운 상황이다. 0:000> u <Unloaded_es_kr.dll>+0x64ff81: 00650072 6f outs dx,dword ptr [esi] 00650073 bc46c045c0 mov esp,0C045C046h 00650078 0000 add byte ptr [eax],al 0065007a 0000 add byte ptr [eax],al 0065007c e8e8448a00 call <Unloaded_es_kr.dll>+0xef4478 (00ef4569) 00650081 0000 add byte ptr [eax],al 00650083 0000 add byte ptr [eax],al 00650085 008001000000 add byte ptr [eax+1],al 이러한 경우는 최종적으로 Thread Stack이 정상적으로 보이는 Frame에서 EIP가 잘못될 가능성이 없는 지를 Check 해야 한다. ChildEBP RetAddr Args to Child 001273e8 66107873 0eddbd00 00000000 00127494 <Unloaded_es_kr.dll>+0x64ff81 00127400 66107bec 00000000 00127424 03ffe070 MSVBVM60!ExHandleLBFailure+0x20 0:000> ub 66107873 MSVBVM60!ExHandleLBFailure+0xc: 6610785f ff15b8100066 call dword ptr [MSVBVM60!_imp__TlsGetValue (660010b8)] 66107865 8bd8 mov ebx,eax <--- eax 는 TlsGetValue의 return 값 66107867 8b03 mov eax,dword ptr [ebx] 66107869 85c0 test eax,eax 6610786b 7409 je MSVBVM60!ExHandleLBFailure+0x23 (66107876) 6610786d 8b08 mov ecx,dword ptr [eax] <--- ecx 는 eax address 값 6610786f 50 push eax 66107870 ff5108 call dword ptr [ecx+8] 0:000> r eax=0eddbd00 ebx=001e1f38 ecx=0ce1ef38 edx=04009b10 esi=00127494 edi=00000000 eip=00650072 esp=001273ec ebp=00127400 iopl=0 nv up ei pl nz na pe nc cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00240206 <Unloaded_es_kr.dll>+0x64ff81: 00650072 6f outs dx,dword ptr [esi] ds:0023:00127494=fffffffd 0:000> ? 0ce1ef38+8 Evaluate expression: 216133440 = 0ce1ef40 <--- call dword ptr[0ce1ef40] 하지만, 아래 data를 보면, Method로 보이진 않는 다. 단지 String Data로 보인다. 그러므로, Tls 가 Broken 된 것으로 추측할 수 있다. 0:000> dc 0ce1ef40 0ce1ef40 00650072 003a0072 00680020 00740074 r.e.r.:. .h.t.t. 0ce1ef50 003a0070 002f002f 00300037 0032002e p.:././.7.0...2. 0ce1ef60 0031002e 00300034 0031002e 00300034 ..1.4.0...1.4.0. 0ce1ef70 0039003a 00310030 002f0036 00740068 :.9.0.1.6./.h.t. 0ce1ef80 006c006d 00700043 002f0063 00720070 m.l.C.p.c./.p.r. 0ce1ef90 002f006f 0048004d 0046005f 00310030 o./.M.H._.F.0.1. 0ce1efa0 0030005f 002e0031 0073006a 000d0070 _.0.1...j.s.p... 0ce1efb0 0041000a 00630063 00700065 002d0074 ..A.c.c.e.p.t.-. 0:000> dc 0ce1ef40-10 0ce1ef30 00a20016 030a01ee 0e98bb18 00650066 ............f.e. 0ce1ef40 00650072 003a0072 00680020 00740074 r.e.r.:. .h.t.t. 0ce1ef50 003a0070 002f002f 00300037 0032002e p.:././.7.0...2. 0ce1ef60 0031002e 00300034 0031002e 00300034 ..1.4.0...1.4.0. 0ce1ef70 0039003a 00310030 002f0036 00740068 :.9.0.1.6./.h.t. 0ce1ef80 006c006d 00700043 002f0063 00720070 m.l.C.p.c./.p.r. 0ce1ef90 002f006f 0048004d 0046005f 00310030 o./.M.H._.F.0.1. 0ce1efa0 0030005f 002e0031 0073006a 000d0070 _.0.1...j.s.p... 0:000> u MSVBVM60!ExHandleLBFailure 66107873 MSVBVM60!ExHandleLBFailure: 66107853 55 push ebp 66107854 8bec mov ebp,esp 66107856 53 push ebx 66107857 56 push esi 66107858 57 push edi 66107859 ff357cee1066 push dword ptr [MSVBVM60!g_itlsEbthread (6610ee7c)] 6610785f ff15b8100066 call dword ptr [MSVBVM60!_imp__TlsGetValue (660010b8)] 66107865 8bd8 mov ebx,eax 66107867 8b03 mov eax,dword ptr [ebx] 66107869 85c0 test eax,eax 6610786b 7409 je MSVBVM60!ExHandleLBFailure+0x23 (66107876) 6610786d 8b08 mov ecx,dword ptr [eax] 6610786f 50 push eax 66107870 ff5108 call dword ptr [ecx+8] Thread Stack은 다르더라도 상위의 TLS(Thread Local Storage)연산에 대한 Assembly code는 기억해둘 필요가 있다. VB runtime은 Thread Safe 한 처리를 이유로 주로 TLS를 이용한다. 하지만, IE7 이상의 Browser에서 TAB Browser의 처리에 따라서 동일한 VB ActiveX Control이 중복해서 하나의 Browser에 load되는 가능성도 커졌다. 이에 따라서 TLS slot이 고갈되어 VB Runtime의 TLS 연산에서 crash가 발생하는 경우가 빈번해졌다. 만일, Vista OS 사용한다면, 같이 shipping된 VB runtime에서는 문제되지 않지만, XP machine이라면 이러한 Crash를 볼 수 있다. 최근에 Internet Explorer와 같은 Multiple Threaded 환경에서 ActiveX Control로써 VB 를 사용하는 경우는 확실히 줄었지만, 과거의 Control을 유지 보수하는 차원에서 존재하는 것이라면, VB Runtime에서의 Crash는 당황될 수 있다. 가장 많이 보고 되는 것이 1) vb6ko.dll 이라는 모듈이 System32 Directory에 존재하지 않아서 Crash가 발생하는 경우와 2)TLS Operation에서의 VB runtime에서의 Crash이다. (설마 아직도 IE/VB Control을 Single Threading으로 사용하여 Crash되는 경우가 있을 거라고는 ... 생각치 않는다.) TLS Operation에서의 VB runtime Crash의 경우는 쉽게 Vista OS에 shipping된 VB Runtime은 XP Box에 copy하여 배포하는 경우도 있고, KB930828에서 제공하는 VB runtime으로 Update 하는 방법이 존재한다. 이 경우는 Microsoft 기술지원부를 Contact해야 하는 번거로움이 존재한다.
|
카테고리
이글루링크
최근 등록된 덧글
그러세요
by 강세윤 at 12/15 오늘 많이 헤매다..알게 .. by youna at 12/14 글 잘 읽었습니다 . 전 .. by 위시 at 11/26 어렷다 by klhk at 11/09 dhjjgbem by kl at 11/09 17번부터 어떻게 접는지.. by tykim0131 at 10/28 ATL이나 MFC를 이용하.. by 김명신 at 09/24 복원되었군요.. 제 RSS.. by 강세윤 at 09/24 허걱, 하고 있는 것으로.. by 강세윤 at 09/15 RSS 주소 서비스는 안 .. by 정성태 at 09/15 이글루 파인더
| |||||