J & J - 정성태의 닷넷 이야기

사용자

메뉴

최근 덧글

[정성태] VT sequences to "CONOUT$" vs. STD_O...[정성태] NetCoreDbg is a managed code debugg...[정성태] Evaluating tail call elimination in...[정성태] What’s new in System.Text.Json in ....[정성태] What's new in .NET 9: Cryptography ...[정성태] 아... 제시해 주신 "https://akrzemi1.wordp...[정성태] 다시 질문을 정리할 필요가 있을 것 같습니다. 제가 본문에...[이승준] 완전히 잘못 짚었습니다. 댓글 지우고 싶네요. 검색을 해보...[정성태] 우선 답글 감사합니다. ^^ 그런데, 사실 저 예제는 (g...[이승준] 수정이 안되어서... byteArray는 BYTE* 타입입니다...

글쓰기

제목

이름

암호

전자우편

HTML

홈페이지

유형

내용

<div style='display: inline'>
<h1 style='font-family: Malgun Gothic, Consolas; font-size: 20pt; color: #006699; text-align: center; font-weight: bold'>C# - Thread.Suspend 호출 시 응용 프로그램 hang 현상 (2)</h1>

지난 글에서, 
 
<pre style='margin: 10px 0px 10px 10px; padding: 10px 0px 10px 10px; background-color: #fbedbb; overflow: auto; font-family: Consolas, Verdana;' >
C# - Thread.Suspend 호출 시 응용 프로그램 hang 현상
; <a target='tab' href='https://www.sysnet.pe.kr/2/0/11473'>https://www.sysnet.pe.kr/2/0/11473</a>
</pre>
 
마지막에 ETW 이벤트를 실시간으로 잡을 수 있다면 deadlock 현상을 피할 수 있을 것처럼 설명했는데요. 가만 보니, CRL Profiler 측의 콜백 이벤트가 gc가 아닌 COR_PRF_MONITOR_SUSPENDS 유에 속하는 것이라서, 
 
<div style='BACKGROUND-COLOR: #ccffcc; padding: 10px 10px 5px 10px; MARGIN: 0px 10px 10px 10px; FONT-FAMILY: Malgun Gothic, Consolas, Verdana; COLOR: #005555'>
COR_PRF_MONITOR Enumeration 
; <a target='tab' href='https://learn.microsoft.com/en-us/dotnet/framework/unmanaged-api/profiling/cor-prf-monitor-enumeration'>https://learn.microsoft.com/en-us/dotnet/framework/unmanaged-api/profiling/cor-prf-monitor-enumeration</a> 
 
COR_PRF_MONITOR_SUSPENDS - Controls the RuntimeSuspend*, RuntimeResume*, RuntimeThreadSuspended, and RuntimeThreadResumed callbacks in the ICorProfilerCallback interface. 
</div> 
 
시스템 부하 없이 가능할 것 같아 테스트를 해봤습니다. 이름이 유추하는 것에 따라, 각각의 ETW 이벤트는 ICorProfilerCallback 콜백에 대해 다음과 같이 대응을 하는데요, 
 
<pre style='margin: 10px 0px 10px 10px; padding: 10px 0px 10px 10px; background-color: #fbedbb; overflow: auto; font-family: Consolas, Verdana;' >
GCSuspendEE_V1 ==&gt; <a target='tab' href='https://learn.microsoft.com/en-us/dotnet/framework/unmanaged-api/profiling/icorprofilercallback-runtimesuspendstarted-method'>RuntimeSuspendStarted</a>
GCSuspendEEEnd_V1 ==&gt; RuntimeSuspendFinished
GCStart_V1 ==&gt; (COR_PRF_MONITOR_GC 범주의) GarbageCollectionStarted
GCEnd_V1 ==&gt; (COR_PRF_MONITOR_GC 범주의) GarbageCollectionFinished
GCRestartEEBegin_V1 ==&gt; RuntimeResumeStarted
GCRestartEEEnd_V1 ==&gt; <a target='tab' href='https://learn.microsoft.com/en-us/dotnet/framework/unmanaged-api/profiling/icorprofilercallback-runtimeresumefinished-method?view=vs-2017'>RuntimeResumeFinished</a>
</pre>
 
자, 그럼 기본으로 만들어 둔 <a target='tab' href='https://www.sysnet.pe.kr/2/0/10950'>CLR Profiler 예제 코드</a>에 아래의 추가 코드를 넣고, 
 
<pre style='margin: 10px 0px 10px 10px; padding: 10px 0px 10px 10px; background-color: #fbedbb; overflow: auto; font-family: Consolas, Verdana;' >
static int s_suspend = 0;
static int s_resumed = 0;
volatile static unsigned long s_intLock = 0;

__declspec(dllexport) bool __stdcall IsRunningGC()
{
    return s_intLock == 1;
}

HRESULT CBasicClrProfiler::RuntimeSuspendStarted(COR_PRF_SUSPEND_REASON suspendReason)
{
    s_suspend++;
    s_intLock = 1;

return S_OK;
}

HRESULT CBasicClrProfiler::RuntimeResumeFinished()
{
    s_intLock = 0;
    s_resumed++;

return S_OK;
}
</pre>
 
재현 코드의 GetCallStack 메서드는 IsRunningGC == false인 상태에서만 호출하게 변경합니다. 
 
<pre style='margin: 10px 0px 10px 10px; padding: 10px 0px 10px 10px; background-color: #fbedbb; overflow: auto; font-family: Consolas, Verdana;' >
[DllImport("SampleProfiler.dll")]
[return: MarshalAs(UnmanagedType.Bool)]
public static extern bool IsRunningGC();

private static string GetCallStack(Thread t)
{
    System.Diagnostics.StackTrace trace = null;
    bool suspended = false;

try
    {
        if (IsRunningGC() == false)
        {
            t.Suspend();
            suspended = true;

trace = new System.Diagnostics.StackTrace(t, false);
            return trace.ToString();
        }
    }
    catch { }
    finally
    {
        if (suspended == true)
        {
            t.Resume();
        }
    }

return "";
}
</pre>
 
그런데, 실제로 실행해 보면 이번에도 데드락이 걸리는 것은 마찬가지입니다. 그 상태의 덤프를 떠서 windbg로 분석해 보면, 
 
<pre style='margin: 10px 0px 10px 10px; padding: 10px 0px 10px 10px; background-color: #fbedbb; overflow: auto; font-family: Consolas, Verdana;' >
.loadby sos clr

0:000&gt; !threads
ThreadCount: 7
UnstartedThread: 0
BackgroundThread: 6
PendingThread: 0
DeadThread: 0
Hosted Runtime: no
 Lock 
 ID OSID ThreadOBJ State GC Mode GC Alloc Context Domain Count Apt Exception
 0 1 609c 000001751bcd0850 2a020 Preemptive 000001751D8F5D28:000001751D8F5FB0 000001751bc96960 0 MTA 
 6 2 85b8 000001751bcf96b0 2b220 Preemptive 0000000000000000:0000000000000000 000001751bc96960 0 MTA (Finalizer) 
 7 3 a8a8 000001751bd29ae0 2b220 Preemptive 0000000000000000:0000000000000000 000001751bc96960 0 MTA 
 8 4 183c 000001751bd2d0f0 ab224 Preemptive 0000000000000000:0000000000000000 000001751bc96960 0 MTA 
 9 5 9ddc 000001751bd2f650 2b220 Preemptive 0000000000000000:0000000000000000 000001751bc96960 0 MTA 
 10 6 b970 000001751bd3c0f0 2b220 Preemptive 0000000000000000:0000000000000000 000001751bc96960 0 MTA 
 11 7 7c5c 000001751bd433c0 21220 Preemptive 0000000000000000:0000000000000000 000001751bc96960 0 Ukn 
</pre>
 
<a target='tab' href='https://www.sysnet.pe.kr/2/0/11475'>지난번 덤프 분석</a>과 마찬가지로 스레드 호출 스택의 대상이 되는 스레드는 trigger_gc_for_alloc을 호출하며 중지해 있고, 
 
<pre style='margin: 10px 0px 10px 10px; padding: 10px 0px 10px 10px; background-color: #fbedbb; overflow: auto; font-family: Consolas, Verdana;' >
0:008&gt; !ThreadState ab224
 User Suspend Pending
 Legal to Join
 Background
 CLR Owns
 CoInitialized
 In Multi Threaded Apartment
 Fully initialized
 Sync Suspended

0:008&gt; k
 # Child-SP RetAddr Call Site
...[생략]...

08 0000004e`50cfe7e0 00007ff8`6dd6e69f clr!GCToEEInterface::EnablePreemptiveGC+0x3d
09 0000004e`50cfe810 00007ff8`6e2b992b clr!WKS::GCHeap::GarbageCollectGeneration+0x97
0a 0000004e`50cfe860 00007ff8`6e0cd99c clr!WKS::gc_heap::trigger_gc_for_alloc+0x37
0b 0000004e`50cfe8a0 00007ff8`6de549fa clr!WKS::gc_heap::try_allocate_more_space+0x278f80
0c 0000004e`50cfe900 00007ff8`6de5498b clr!WKS::gc_heap::allocate_more_space+0x26
...[생략]...
</pre>
 
GetCallStack 메서드를 호출 중인 0번 스레드는 wait_for_gc_done 호출 상태라 멈춰 있습니다. 
 
<pre style='margin: 10px 0px 10px 10px; padding: 10px 0px 10px 10px; background-color: #fbedbb; overflow: auto; font-family: Consolas, Verdana;' >
0:000&gt; k
 # Child-SP RetAddr Call Site
...[생략]...
04 0000004e`504fea40 00007ff8`6dd71732 clr!CLREventBase::WaitEx+0x71
05 0000004e`504fead0 00007ff8`6dd742f6 clr!WKS::gc_heap::wait_for_gc_done+0x2b
06 0000004e`504feb00 00007ff8`6dd50848 clr!WKS::GCHeap::Alloc+0x276
...[생략]...
</pre>
 
그리고 이때의 C++ profiler 측 전역 변수를 살펴보면, 
 
<pre style='margin: 10px 0px 10px 10px; padding: 10px 0px 10px 10px; background-color: #fbedbb; overflow: auto; font-family: Consolas, Verdana;' >
0:000&gt; x SampleProfiler!s_suspend
00007ff8`6b3944bc SampleProfiler!s_suspend = 0n333

0:000&gt; x SampleProfiler!s_resumed
00007ff8`6b3944c0 SampleProfiler!s_resumed = 0n333

0:000&gt; x SampleProfiler!s_intLock
00007ff8`6b3944b4 SampleProfiler!s_intLock = 0
</pre>
 
현재 trigger_gc_for_alloc 호출로 인해 런타임이 suspend 되었을 것임에도 불구하고 ICorProfilerCallback의 RuntimeSuspendStarted, RuntimeResumeFinished 이벤트는 쌍을 이뤄 이미 호출이 완료된 상태입니다. 이러한 결과에 대한 해석을 제대로 하려면 CLR 측 소스 코드를 면밀히 분석해야 하는데... 제 실력이 아직 거기까지는 안 되는군요. (혹시 이에 대해 아시는 분은 덧글 부탁드립니다. ^^) 
 
<hr style='width: 50%' /> 
 
그런데, 사실 저 동작이 정확하게 지켜졌다고 해도, IsRunningGC() 호출 결과 false일 때만 호출 스택을 구하는 것 역시 불안정하긴 마찬가지입니다. 왜냐하면, IsRunningGC 호출로 false을 얻은 바로 그 순간 GC가 발생한다면 마찬가지로 데드락에 빠질 수 있는 위험이 있기 때문입니다. 
 
그러니까, 결국 GetCallStack 메서드의 호출과 GC는 최대한 엮이지 않는 것이 최선입니다. 이와 관련해서 생각나는 글이 있는데, 
 
<pre style='margin: 10px 0px 10px 10px; padding: 10px 0px 10px 10px; background-color: #fbedbb; overflow: auto; font-family: Consolas, Verdana;' >
C# - Thread.Suspend 호출 시 응용 프로그램 hang 현상을 해결하기 위한 시도
; <a target='tab' href='https://www.sysnet.pe.kr/2/0/12028'>https://www.sysnet.pe.kr/2/0/12028</a>
</pre>
 
위에서는 GC가 임박한 경우 GetCallStack을 호출하지 않도록 변경했었는데요, 그러지 말고 GetCallStack 메서드를 호출하는 동안에는 GC가 발생하지 않도록 만드는 것은 어떨까요? 마침 .NET 4.6부터 이에 대한 기능이 추가되었습니다. 
 
<pre style='margin: 10px 0px 10px 10px; padding: 10px 0px 10px 10px; background-color: #fbedbb; overflow: auto; font-family: Consolas, Verdana;' >
GC.TryStartNoGCRegion Method
; <a target='tab' href='https://learn.microsoft.com/en-us/dotnet/api/system.gc.trystartnogcregion'>https://learn.microsoft.com/en-us/dotnet/api/system.gc.trystartnogcregion</a>

GC.EndNoGCRegion Method
; <a target='tab' href='https://learn.microsoft.com/en-us/dotnet/api/system.gc.endnogcregion'>https://learn.microsoft.com/en-us/dotnet/api/system.gc.endnogcregion</a>
</pre>
 
따라서 GetCallStack을 다음과 같이 만들어 두면, 
 
<pre style='margin: 10px 0px 10px 10px; padding: 10px 0px 10px 10px; background-color: #fbedbb; overflow: auto; font-family: Consolas, Verdana;' >
private static string GetCallStack(Thread t)
{
 System.Diagnostics.StackTrace trace = null;
 bool suspended = false;

try
 {
 if (GC.TryStartNoGCRegion(1024 * 1024 * 10) == true)
 {
 t.Suspend();
 suspended = true;

trace = new System.Diagnostics.StackTrace(t, false);
 return trace.ToString();
 }
 }
 catch { }
 finally
 {
 if (GCSettings.LatencyMode == GCLatencyMode.NoGCRegion)
 {
 GC.EndNoGCRegion();
 }

if (suspended == true)
        {
            t.Resume();
        }
    }

return "";
}
</pre>
 
<a target='tab' href='https://www.sysnet.pe.kr/2/0/11869#12'>TryStartNoGCRegion</a> 호출 시점에 미리 10MB의 힙 공간을 확보해 두고 new System.Diagnostics.StackTrace(t, false).ToString()을 호출하게 되므로 이 과정에서 GC가 발생하지 않게 됩니다. 따라서 위의 예제를 실행하면 이전과 달리 데드락 문제가 발생하지 않습니다. 
 
<a name='gc_segment'></a>
위의 코드에서 한 가지 애매한 점이 있다면, 호출 스택을 구하기 위해 미리 확보하는 10MB의 크기입니다. 사실 호출 스택은 그 깊이에 따라 천차만별일 수 있기 때문에 정확한 값을 지정할 수 없습니다. 그저 적당한 값을 넣어야 하는데 글쎄요... 10MB면 될까요? 알 수 없습니다. 참고로, 이 크기는 Ephemeral generation의 최대 세그먼트까지 지정할 수 있는데, 
 
<pre style='margin: 10px 0px 10px 10px; padding: 10px 0px 10px 10px; background-color: #fbedbb; overflow: auto; font-family: Consolas, Verdana;' >
Ephemeral generations and segments
; <a target='tab' href='https://learn.microsoft.com/en-us/dotnet/standard/garbage-collection/fundamentals#ephemeral-generations-and-segments'>https://learn.microsoft.com/en-us/dotnet/standard/garbage-collection/fundamentals#ephemeral-generations-and-segments</a>
</pre>
 
위의 문서에 명시하듯이 32비트는 16MB, 64비트는 256MB로 가정하면 모든 환경에서 사용할 수 있습니다. 
 
<pre style='margin: 10px 0px 10px 10px; padding: 10px 0px 10px 10px; background-color: #fbedbb; overflow: auto; font-family: Consolas, Verdana;' >
Workstation GC: 32비트 - 16MB, 64비트 - 256MB
Server GC: 32비트 - 64MB, 64비트 - 4GB
Server GC with &gt; 4 logical CPUs: 32비트 - 32MB, 64비트 - 2GB
Server GC with &gt; 8 logical CPUs: 32비트 - 16MB, 64비트 - 1GB
</pre>
 
(<a target='tab' href='https://www.sysnet.pe.kr/bbs/DownloadAttachment.aspx?fid=1763&boardid=331301885'>첨부 파일은 이 글의 예제 코드를 포함</a>합니다.) 
 
<hr style='width: 50%' /> 
 
이걸로 해결이 된 듯싶지만, 실제로 상용 코드에 저 방법을 적용할 수는 없었습니다. 저 간단한 예제는 통과를 했지만, 제가 가지고 있는 ASP.NET 웹 애플리케이션 테스트 사이트에 저 코드를 넣었더니 특정 테스트 머신에서 불특정하게 crash가 발생했으며 이때의 덤프를 보면 다음과 같은 faulting 오류가 보입니다. 
 
<div style='BACKGROUND-COLOR: #ccffcc; padding: 10px 10px 5px 10px; MARGIN: 0px 10px 10px 10px; FONT-FAMILY: Malgun Gothic, Consolas, Verdana; COLOR: #005555'>
CLR!SVR::GC_HEAP::FIND_FIRST_OBJECT+83In ....dmp the assembly instruction at clr!SVR::gc_heap::find_first_object+83 in C:\Windows\Microsoft.NET\Framework64\v4.0.30319\clr.dll from Microsoft Corporation has caused an access violation exception (0xC0000005) when trying to read from memory location 0x00000000 on thread 18 
</div> 
 
<pre style='margin: 10px 0px 10px 10px; padding: 10px 0px 10px 10px; background-color: #fbedbb; overflow: auto; font-family: Consolas, Verdana;' >
0:018&gt; k
 # Child-SP RetAddr Call Site
00 000000c6`30c7d678 00007fff`a337bf56 clr!SVR::gc_heap::find_first_object+0x83
01 000000c6`30c7d690 00007fff`a32c9c50 clr!SVR::GCHeap::Promote+0x147
02 000000c6`30c7d710 00007fff`a32c9d8a clr!GcEnumObject+0x218
03 000000c6`30c7d760 00007fff`a32c8587 clr!GcInfoDecoder::EnumerateLiveSlots+0xdf3
04 000000c6`30c7dbe0 00007fff`a32c819e clr!GcStackCrawlCallBack+0x307
05 000000c6`30c7e000 00007fff`a33748de clr!GCToEEInterface::GcScanRoots+0x469
06 000000c6`30c7f4c0 00007fff`a3373a47 clr!SVR::gc_heap::mark_phase+0x1de
07 000000c6`30c7f560 00007fff`a3373cb6 clr!SVR::gc_heap::gc1+0xa7
08 000000c6`30c7f5b0 00007fff`a3373448 clr!SVR::gc_heap::garbage_collect+0x870
09 000000c6`30c7f650 00007fff`a3316107 clr!SVR::gc_heap::gc_thread_function+0x74
0a 000000c6`30c7f680 00007fff`a3317e14 clr!SVR::gc_heap::gc_thread_stub+0x7e
0b 000000c6`30c7f9c0 00007fff`b13b7974 clr!GCThreadStub+0x24
0c 000000c6`30c7f9f0 00007fff`b169a2d1 kernel32!BaseThreadInitThunk+0x14
0d 000000c6`30c7fa20 00000000`00000000 ntdll!RtlUserThreadStart+0x21
</pre>
 
<pre style='margin: 10px 0px 10px 10px; padding: 10px 0px 10px 10px; background-color: #fbedbb; overflow: auto; font-family: Consolas, Verdana;' >
로그 이름: Application
원본: .NET Runtime
...[생략]...
설명:
Application: w3wp.exe
Framework Version: v4.0.30319
Description: The process was terminated due to an internal error in the .NET Runtime at IP 00007FF89FE91036 (00007FF89FDE0000) with exit code 80131506.
</pre>
 
프로세스 crash이기 때문에 별도 로그를 남겨본 결과 GC.TryStartNoGCRegion 메서드까지 호출은 했으나, 그 이후에 남은 로그가 없는 걸로 봐서는 이로 인해 GC가 발생했고, (ASP.NET의 ServerGC 유형으로) 그것을 처리하는 GC 전용 스레드에서 find_first_object 호출 시 crash로 이어지는 듯합니다. 물론, 테스트를 위한 응용 프로그램이어서 약간 복잡하긴 했지만... 그래도 저 오류가 발생하는 것은 심각할 수밖에 없습니다.

<hr />[이 글에 대해서 여러분들과 의견을 공유하고 싶습니다. 틀리거나 미흡한 부분 또는 의문 사항이 있으시면 언제든 댓글 남겨주십시오.]

</div>

첨부파일

스팸 방지용 인증 번호

1755 (왼쪽의 숫자를 입력해야 합니다.)