Microsoft MVP성태의 닷넷 이야기
글쓴 사람
정성태 (techsharer at outlook.com)
홈페이지
첨부 파일
 
(연관된 글이 2개 있습니다.)
(시리즈 글이 3개 있습니다.)
디버깅 기술: 92. windbg - C# Monitor Lock을 획득하고 있는 스레드 찾는 방법
; https://www.sysnet.pe.kr/2/0/11268

닷넷: 2214. windbg - Monitor.Enter의 thin lock과 fat lock
; https://www.sysnet.pe.kr/2/0/13552

닷넷: 2215. windbg - thin/fat lock 없이 동작하는 Monitor.Wait + Pulse
; https://www.sysnet.pe.kr/2/0/13553




windbg - C# Monitor Lock을 획득하고 있는 스레드 찾는 방법

이에 대해서는 다음의 글에 방법이 잘 나옵니다.

Analyzing Monitor-Based Deadlocks with SOS.dll
; http://blogs.microsoft.co.il/sasha/2009/10/17/analyzing-monitor-based-deadlocks-with-sosdll/

그런데 직접 실습을 해보니 약간 달라진 면이 있어서 기록을 남깁니다.




우선, 재현을 위해 간단한 테스트 프로그램을 다음과 같이 만들어 볼 수 있습니다.

using System;
using System.Threading;

namespace ConsoleApp1
{
    class Program
    {
        static void Main(string[] args)
        {
            object _objLock1 = new object();
            object _objLock2 = new object();

            Thread t1 = new Thread(threadFunc1);
            t1.IsBackground = true;
            t1.Start(_objLock1);

            Thread t2 = new Thread(threadFunc2);
            t2.IsBackground = true;
            t2.Start(_objLock2);

            lock (_objLock1)
                lock (_objLock2)
                {
                    Console.WriteLine("Enter...");
                    Console.ReadLine();
                    Console.WriteLine("Exit...");
                }
        }

        private static void threadFunc1(object obj)
        {
            lock (obj)
            {
                Console.WriteLine("threadFunc1");
            }
        }

        private static void threadFunc2(object obj)
        {
            lock (obj)
            {
                Console.WriteLine("threadFunc2");
            }
        }
    }
}

결국, Main 스레드가 2개의 lock을 이미 소유한 상태에서 threadFunc1과 threadFunc2의 실행이 hang 상태가 된 것을 표현한 것입니다.

위의 프로그램을 실행하고 작업 관리자를 이용해 덤프를 남긴 후 windbg로 읽어들입니다. 당연히 ".loadby sos clr"로 sos 확장을 로드하고 다음과 같이 현재 열려 있는 lock의 수를 확인할 수 있습니다.

0:000> !syncblk
Index SyncBlock MonitorHeld Recursion Owning Thread Info  SyncBlock Owner
    3 0000027ecd80ece8            3         1 0000027ecd7b2b00 7744   0   0000027ecf3a3ea8 System.Object
    4 0000027ecd80ed38            3         1 0000027ecd7b2b00 7744   0   0000027ecf3a3ec0 System.Object
-----------------------------
Total           4
CCW             0
RCW             0
ComClassFactory 0
Free            0

보는 바와 같이 총 2개의 lock이 사용 중이고, 현재 그것을 점유하고 있는 "Owing Thread"는 0000027ecd7b2b00으로 나옵니다. 이에 해당하는 스레드 정보는 !threads 명령어로 확인할 수 있습니다.

0:000> !threads
ThreadCount:      4
UnstartedThread:  0
BackgroundThread: 3
PendingThread:    0
DeadThread:       0
Hosted Runtime:   no
                                                                                                        Lock  
       ID OSID ThreadOBJ           State GC Mode     GC Alloc Context                  Domain           Count Apt Exception
   0    1 7744 0000027ecd7b2b00    2a020 Preemptive  0000027ECF3A9FA8:0000027ECF3A9FD0 0000027ecd783180 3     MTA 
   5    2 44c0 0000027ecd7dbe40    2b220 Preemptive  0000000000000000:0000000000000000 0000027ecd783180 0     MTA (Finalizer) 
   6    3 7d7c 0000027ecd80e470  202b220 Preemptive  0000027ECF3A6018:0000027ECF3A7FD0 0000027ecd783180 0     MTA 
   7    4 1338 0000027ecd814970  202b220 Preemptive  0000000000000000:0000000000000000 0000027ecd783180 0     MTA 

0번 스레드인데 당연히 Main 메서드를 실행 중일 테니 굳이 확인할 필요도 없어 보입니다.

나머지 중에 5번 스레드는 Finalizer고 6번과 7번이 우리가 생성했던 스레드였을 텐데 이 중에서 6번을 먼저 살펴보겠습니다.

0:000> ~6s
ntdll!NtWaitForMultipleObjects+0x14:
00007fff`499f5ef4 c3              ret

0:006> !clrstack
OS Thread Id: 0x7d7c (6)
        Child SP               IP Call Site
000000e3b82ff0f8 00007fff499f5ef4 [GCFrame: 000000e3b82ff0f8] 
000000e3b82ff238 00007fff499f5ef4 [GCFrame: 000000e3b82ff238] 
000000e3b82ff278 00007fff499f5ef4 [HelperMethodFrame_1OBJ: 000000e3b82ff278] System.Threading.Monitor.Enter(System.Object)
000000e3b82ff370 00007ffed33f0775 ConsoleApp1.Program.threadFunc1(System.Object) [E:\ConsoleApp1\ConsoleApp1\Program.cs @ 32]
000000e3b82ff3c0 00007fff2f06ca72 System.Threading.ExecutionContext.RunInternal(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
000000e3b82ff490 00007fff2f06c904 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object, Boolean)
000000e3b82ff4c0 00007fff2f06c8c2 System.Threading.ExecutionContext.Run(System.Threading.ExecutionContext, System.Threading.ContextCallback, System.Object)
000000e3b82ff510 00007fff2fa40ffc System.Threading.ThreadHelper.ThreadStart(System.Object)
000000e3b82ff768 00007fff329f6753 [GCFrame: 000000e3b82ff768] 
000000e3b82ffab8 00007fff329f6753 [DebuggerU2MCatchHandlerFrame: 000000e3b82ffab8] 

콜스택 상단에 Monitor.Enter가 있으므로 현재 lock을 대기 중임을 알 수 있습니다. 그렇다면 어떤 object를 대상으로 lock을 건 것일까요? 이를 위해 native 레벨의 callstack을 확인해 보면 단서를 찾을 수 있습니다.

0:006> kv
 # Child-SP          RetAddr           : Args to Child                                                           : Call Site
00 000000e3`b82feb38 00007fff`4677dd20 : 00000099`00000000 00000000`00000010 00000002`00000002 00007fff`00000010 : ntdll!NtWaitForMultipleObjects+0x14
01 000000e3`b82feb40 00007fff`32bb401e : ffffffff`fffffffe 00007fff`00000000 000000e3`b82ff0f8 00000000`00000000 : KERNELBASE!WaitForMultipleObjectsEx+0xf0
02 000000e3`b82fee40 00007fff`32bb3eb0 : 00000000`00000001 00000000`00000000 0000027e`cd80e470 00000000`ffffffff : clr!WaitForMultipleObjectsEx_SO_TOLERANT+0x62
03 000000e3`b82feea0 00007fff`32bb3ca9 : 0000027e`cd80e470 00000000`00000001 00000000`00000000 00007ffe`00000000 : clr!Thread::DoAppropriateWaitWorker+0x1e4
04 000000e3`b82fefa0 00007fff`32bb42b9 : 00000000`00000000 00007fff`00000001 0000027e`cd80e470 00007fff`329ff1af : clr!Thread::DoAppropriateWait+0x7d
05 000000e3`b82ff020 00007fff`32bb458e : 0000027e`cd80ece8 000000e3`b82ff3b0 00000000`00000000 0000027e`cd80e470 : clr!CLREventBase::WaitEx+0xc4
06 000000e3`b82ff0b0 00007fff`32bb44a2 : 0000027e`cd80ece8 0000027e`cd80ece8 00007ffe`00000000 0000027e`cf3a3ea8 : clr!AwareLock::EnterEpilogHelper+0xca
07 000000e3`b82ff170 00007fff`32bb41b2 : 0000027e`cd80e470 0000027e`cd80e470 00000000`00000000 0000027e`cd80ece8 : clr!AwareLock::EnterEpilog+0x62
08 000000e3`b82ff1d0 00007ffe`d33f0775 : 0000027e`cf3a3fa0 000000e3`b82ff3a8 0000027e`cf3a4080 00000000`00000000 : clr!JITutil_MonEnterWorker+0xe2
09 000000e3`b82ff370 00007fff`2f06ca72 : 0000027e`cf3a3ea8 0000027e`cf3a3ea8 000000e3`b82ff3f0 00000000`00000000 : 0x00007ffe`d33f0775
0a 000000e3`b82ff3c0 00007fff`2f06c904 : 0000027e`cf3a4080 0000027e`cf3a3fa0 0000027e`cf3a3f78 00000000`00000000 : mscorlib_ni+0x4dca72
0b 000000e3`b82ff490 00007fff`2f06c8c2 : 0000027e`cf3a3f78 00000000`00000000 00000000`cf3a3ea8 00000000`00000000 : mscorlib_ni+0x4dc904
0c 000000e3`b82ff4c0 00007fff`2fa40ffc : 000000e3`b82ff668 000000e3`b82ff668 000000e3`b82ff570 00000000`00000000 : mscorlib_ni+0x4dc8c2
0d 000000e3`b82ff510 00007fff`329f6753 : 0000027e`cf3a3fe0 0000027e`cf3a3ea8 00000000`00000000 00000000`00000000 : mscorlib_ni+0xeb0ffc
0e 000000e3`b82ff550 00007fff`329f6649 : 00000000`00000001 00007fff`32b3f8e3 000000e3`b82ff828 00000000`00000000 : clr!CallDescrWorkerInternal+0x83
0f 000000e3`b82ff590 00007fff`329f732d : 00000000`00000002 000000e3`b82ff748 000000e3`b82ff768 000000e3`b82ff828 : clr!CallDescrWorkerWithHandler+0x4e
10 000000e3`b82ff5d0 00007fff`32b096e9 : 000000e3`b82ffbe0 000000e3`b82ffb20 00007fff`2f28e720 000000e3`b82ffb20 : clr!MethodDescCallSite::CallTargetWorker+0xf8
11 000000e3`b82ff6d0 00007fff`329f7c9d : 00000000`00001f80 00007fff`32b095e0 000000e3`b82ffb20 ffffffff`ffffffff : clr!ThreadNative::KickOffThread_Worker+0x109
12 000000e3`b82ff930 00007fff`329f7c18 : 000000e3`b82ffb20 00007fff`329f6051 0000027e`00000000 00000000`00000018 : clr!Frame::Push+0x59
13 000000e3`b82ff970 00007fff`329f7b56 : 00000000`00000001 00000000`00000000 00000000`00000000 00000000`00000000 : clr!MarshalInfo::SetupArgumentSizes+0x234
14 000000e3`b82ffa70 00007fff`329f7cdf : ffffffff`ffffffff 0000027e`cd80e470 0000027e`cd80e470 0000027e`cd806190 : clr!MarshalInfo::SetupArgumentSizes+0x15d
15 000000e3`b82ffb00 00007fff`32b095cb : 0000027e`cd80e470 000000e3`00000001 0000027e`cd806190 00000000`00000003 : clr!MarshalInfo::SetupArgumentSizes+0xe3
16 000000e3`b82ffb60 00007fff`32b31c3f : 0000027e`cd806190 0000027e`cd80e470 000000e3`b82ffbb8 00000000`00000000 : clr!ThreadNative::KickOffThread+0xdb
17 000000e3`b82ffc30 00007fff`47152774 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : clr!Thread::intermediateThreadProc+0x86
18 000000e3`b82ffd70 00007fff`499c0d51 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : kernel32!BaseThreadInitThunk+0x14
19 000000e3`b82ffda0 00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x21

콜스택에 보면 clr!CLREventBase::WaitEx 호출이 보이는데 그것의 첫 번째 인자(0000027e`cd80ece8) 값이 바로 syncblock 값과 일치하게 나옵니다.

0:000> !syncblk
Index SyncBlock MonitorHeld Recursion Owning Thread Info  SyncBlock Owner
    3 0000027ecd80ece8            3         1 0000027ecd7b2b00 7744   0   0000027ecf3a3ea8 System.Object
    4 0000027ecd80ed38            3         1 0000027ecd7b2b00 7744   0   0000027ecf3a3ec0 System.Object

즉, 6번 스레드는 0000027ecd80ece8에 해당하는 lock을 대기하고 있는 중이며 그 lock을 현재 소유하고 있는 스레드는 0000027ecd7b2b00인 0번 스레드임이 밝혀집니다. 이 정도면... ^^ 실전에서 충분히 추적할만한 단서가 되겠지요.




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

[연관 글]






[최초 등록일: ]
[최종 수정일: 8/14/2017]

Creative Commons License
이 저작물은 크리에이티브 커먼즈 코리아 저작자표시-비영리-변경금지 2.0 대한민국 라이센스에 따라 이용하실 수 있습니다.
by SeongTae Jeong, mailto:techsharer at outlook.com

비밀번호

댓글 작성자
 




... 121  122  123  124  125  126  127  128  129  130  [131]  132  133  134  135  ...
NoWriterDateCnt.TitleFile(s)
1779정성태10/15/201419624오류 유형: 248. Active Directory에서 OU가 지워지지 않는 경우
1778정성태10/10/201418068오류 유형: 247. The Netlogon service could not create server share C:\Windows\SYSVOL\sysvol\[도메인명]\SCRIPTS.
1777정성태10/10/201421177오류 유형: 246. The processing of Group Policy failed. Windows attempted to read the file \\[도메인]\sysvol\[도메인]\Policies\{...GUID...}\gpt.ini
1776정성태10/10/201418183오류 유형: 245. 이벤트 로그 - Name resolution for the name _ldap._tcp.dc._msdcs.[도메인명]. timed out after none of the configured DNS servers responded.
1775정성태10/9/201419290오류 유형: 244. Visual Studio 디버깅 (2) - Unable to break execution. This process is not currently executing the type of code that you selected to debug.
1774정성태10/9/201426530개발 환경 구성: 246. IIS 작업자 프로세스의 20분 자동 재생(Recycle)을 끄는 방법
1773정성태10/8/201429728.NET Framework: 471. 웹 브라우저로 다운로드가 되는 파일을 왜 C# 코드로 하면 안되는 걸까요? [1]
1772정성태10/3/201418484.NET Framework: 470. C# 3.0의 기본 인자(default parameter)가 .NET 1.1/2.0에서도 실행될까? [3]
1771정성태10/2/201428002개발 환경 구성: 245. 실행된 프로세스(EXE)의 명령행 인자를 확인하고 싶다면 - Sysmon [4]
1770정성태10/2/201421602개발 환경 구성: 244. 매크로 정의를 이용해 파일 하나로 C++과 C#에서 공유하는 방법 [1]파일 다운로드1
1769정성태10/1/201424024개발 환경 구성: 243. Scala 개발 환경 구성(JVM, 닷넷) [1]
1768정성태10/1/201419424개발 환경 구성: 242. 배치 파일에서 Thread.Sleep 효과를 주는 방법 [5]
1767정성태10/1/201424586VS.NET IDE: 94. Visual Studio 2012/2013에서의 매크로 구현 - Visual Commander [2]
1766정성태10/1/201422388개발 환경 구성: 241. 책 "프로그래밍 클로저: Lisp"을 읽고 나서. [1]
1765정성태9/30/201425962.NET Framework: 469. Unity3d에서 transform을 변수에 할당해 사용하는 특별한 이유가 있을까요?
1764정성태9/30/201422183오류 유형: 243. 파일 삭제가 안 되는 경우 - The action can't be comleted because the file is open in System
1763정성태9/30/201423793.NET Framework: 468. PDB 파일을 연동해 소스 코드 라인 정보를 알아내는 방법파일 다운로드1
1762정성태9/30/201424502.NET Framework: 467. 닷넷에서 EIP/RIP 레지스터 값을 구하는 방법 [1]파일 다운로드1
1761정성태9/29/201421501.NET Framework: 466. 윈도우 운영체제의 보안 그룹 이름 및 설명 문자열을 바꾸는 방법파일 다운로드1
1760정성태9/28/201419769.NET Framework: 465. ICorProfilerInfo::GetILToNativeMapping 메서드가 0x80131358을 반환하는 경우
1759정성태9/27/201430954개발 환경 구성: 240. Visual C++ / x64 환경에서 inline-assembly를 매크로 어셈블리로 대체하는 방법파일 다운로드1
1758정성태9/23/201437778개발 환경 구성: 239. 원격 데스크톱 접속(RDP)을 기존의 콘솔 모드처럼 사용하는 방법 [1]
1757정성태9/23/201418361오류 유형: 242. Lync로 모임 참여 시 소리만 들리지 않는 경우 - 두 번째 이야기
1756정성태9/23/201427339기타: 48. NVidia 제품의 과다한 디스크 사용 [2]
1755정성태9/22/201434126오류 유형: 241. Unity Web Player를 설치해도 여전히 설치하라는 화면이 나오는 경우 [4]
1754정성태9/22/201424501VC++: 80. 내 컴퓨터에서 C++ AMP 코드가 실행이 될까요? [1]
... 121  122  123  124  125  126  127  128  129  130  [131]  132  133  134  135  ...