Windbg로 살펴보는 Win32 Critical Section
그러고 보니, 제 블로그에서 Critical Section에 대한 글을 쓴 적이 없군요. ^^; 기본적인 사용법은 이미 다른 글에 많이 소개돼 있기 때문에, 대신 Windbg로 추적하는 과정을 보겠습니다.
자, 그럼 이를 위해 간단하게 다음과 같이 예제 코드를 작성하고,
#include <Windows.h>
#include <iostream>
using namespace std;
CRITICAL_SECTION g_cs; // 전역 변수
int main()
{
InitializeCriticalSection(&g_cs);
CRITICAL_SECTION l_cs; // 로컬 변수
cout << "Before InitializeCriticalSection" << endl;
cin.get();
InitializeCriticalSection(&l_cs);
cout << "Before EnterCriticalSection" << endl;
cin.get();
EnterCriticalSection(&l_cs);
cout << "Before LeaveCriticalSection" << endl;
cin.get();
LeaveCriticalSection(&l_cs);
cout << "Before DeleteCriticalSection" << endl;
cin.get();
DeleteCriticalSection(&l_cs);
cout << "Press any key to exit" << endl;
cin.get();
return 0;
}
첫 번째 "cin.get()" 호출에서 실행을 멈췄을 때 Windbg로 붙여 cs 변수를 이런 식으로 찾아들어갈 수 있습니다.
0:005> ~
0 Id: e554.ac68 Suspend: 1 Teb: 00000017`812b6000 Unfrozen
1 Id: e554.10064 Suspend: 1 Teb: 00000017`812b8000 Unfrozen
2 Id: e554.b98 Suspend: 1 Teb: 00000017`812ba000 Unfrozen
3 Id: e554.9dd0 Suspend: 1 Teb: 00000017`812bc000 Unfrozen
4 Id: e554.b598 Suspend: 1 Teb: 00000017`812c0000 Unfrozen
. 5 Id: e554.10508 Suspend: 1 Teb: 00000017`812c4000 Unfrozen
0:004> ~0s
ntdll!NtReadFile+0x14:
00007ffe`2cb5f8b4 c3 ret
0:000> k
# Child-SP RetAddr Call Site
00 00000017`8112f1f8 00007ffe`29c4d71d ntdll!NtReadFile+0x14
01 00000017`8112f200 00007ffc`d946760c KERNELBASE!ReadFile+0x8d
02 00000017`8112f270 00007ffc`d9466a53 ucrtbased!_read_nolock+0xb9c [minkernel\crts\ucrt\src\appcrt\lowio\read.cpp @ 566]
03 00000017`8112f370 00007ffc`d940fc26 ucrtbased!_read+0x333 [minkernel\crts\ucrt\src\appcrt\lowio\read.cpp @ 396]
04 00000017`8112f3d0 00007ffc`d94104d0 ucrtbased!common_refill_and_read_nolock<char>+0x1f6 [minkernel\crts\ucrt\src\appcrt\stdio\_filbuf.cpp @ 146]
05 00000017`8112f460 00007ffc`d93c717e ucrtbased!__acrt_stdio_refill_and_read_narrow_nolock+0x20 [minkernel\crts\ucrt\src\appcrt\stdio\_filbuf.cpp @ 181]
06 00000017`8112f4a0 00007ffc`d93c749e ucrtbased!_fgetc_nolock+0x10e [minkernel\crts\ucrt\src\appcrt\stdio\fgetc.cpp @ 23]
07 00000017`8112f510 00007ffd`425f6359 ucrtbased!fgetc+0x28e [minkernel\crts\ucrt\src\appcrt\stdio\fgetc.cpp @ 52]
08 00000017`8112f5a0 00007ffd`42603515 MSVCP140D!std::_Fgetc<char>+0x19 [D:\a\_work\1\s\src\vctools\crt\github\stl\inc\__msvc_filebuf.hpp @ 75]
09 00000017`8112f5e0 00007ffd`426038b8 MSVCP140D!std::basic_filebuf<char,std::char_traits<char> >::uflow+0xc5 [D:\a\_work\1\s\src\vctools\crt\github\stl\inc\__msvc_filebuf.hpp @ 490]
0a 00000017`8112f6d0 00007ffd`42610671 MSVCP140D!std::basic_filebuf<char,std::char_traits<char> >::underflow+0x78 [D:\a\_work\1\s\src\vctools\crt\github\stl\inc\__msvc_filebuf.hpp @ 470]
0b 00000017`8112f730 00007ffd`4266c96f MSVCP140D!std::basic_streambuf<char,std::char_traits<char> >::sgetc+0x51 [D:\a\_work\1\s\src\vctools\crt\github\stl\inc\streambuf @ 129]
0c 00000017`8112f770 00007ff6`8dcd695f MSVCP140D!std::basic_istream<char,std::char_traits<char> >::get+0x7f [D:\a\_work\1\s\src\vctools\crt\github\stl\inc\istream @ 347]
0d 00000017`8112f7d0 00007ff6`8dcd2f09 ConsoleApplication1!main+0x6f [C:\temp\ConsoleApplication1\ConsoleApplication1\ConsoleApplication1.cpp @ 14]
0e 00000017`8112f910 00007ff6`8dcd2db2 ConsoleApplication1!invoke_main+0x39 [D:\a\_work\1\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 79]
0f 00000017`8112f960 00007ff6`8dcd2c6e ConsoleApplication1!__scrt_common_main_seh+0x132 [D:\a\_work\1\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 288]
10 00000017`8112f9d0 00007ff6`8dcd2f9e ConsoleApplication1!__scrt_common_main+0xe [D:\a\_work\1\s\src\vctools\crt\vcstartup\src\startup\exe_common.inl @ 331]
11 00000017`8112fa00 00007ffe`2babe8d7 ConsoleApplication1!mainCRTStartup+0xe [D:\a\_work\1\s\src\vctools\crt\vcstartup\src\startup\exe_main.cpp @ 17]
12 00000017`8112fa30 00007ffe`2cabbf6c KERNEL32!BaseThreadInitThunk+0x17
13 00000017`8112fa60 00000000`00000000 ntdll!RtlUserThreadStart+0x2c
0:000> .frame 0d
0d 00000017`8112f7d0 00007ff6`8dcd2f09 ConsoleApplication1!main+0x6f [C:\temp\ConsoleApplication1\ConsoleApplication1\ConsoleApplication1.cpp @ 14]
0:000> dv /v
00000017`8112f7f8 l_cs = struct _RTL_CRITICAL_SECTION
l_cs 변수의 주소와 구조체 이름을 얻었으니 간단하게 dt 명령어로 내부 필드를 볼 수 있습니다.
// InitializeCriticalSection 호출 전의 변수 상태
0:000> dt _RTL_CRITICAL_SECTION 00000017`8112f7f8
ConsoleApplication1!_RTL_CRITICAL_SECTION
+0x000 DebugInfo : 0xcccccccc`cccccccc _RTL_CRITICAL_SECTION_DEBUG
+0x008 LockCount : 0n-858993460
+0x00c RecursionCount : 0n-858993460
+0x010 OwningThread : 0xcccccccc`cccccccc Void
+0x018 LockSemaphore : 0xcccccccc`cccccccc Void
+0x020 SpinCount : 0xcccccccc`cccccccc
아직은 뭐, 지역 변수로 위치만 잡고 있는 상태이기 때문에 쓰레기 값이 들어가 있는 정도인데요, 이후 InitializeCriticalSection 함수를 호출하면 이런 식으로 초기화가 됩니다.
ConsoleApplication1!_RTL_CRITICAL_SECTION
+0x000 DebugInfo : 0xffffffff`ffffffff _RTL_CRITICAL_SECTION_DEBUG
+0x008 LockCount : 0n-1
+0x00c RecursionCount : 0n0
+0x010 OwningThread : (null)
+0x018 LockSemaphore : (null)
+0x020 SpinCount : 0x20007d0
그다음
EnterCriticalSection 함수를 호출하면 OwningThread에 값이 기록되고,
0:005> dt _RTL_CRITICAL_SECTION 00000017`8112f7f8
ConsoleApplication1!_RTL_CRITICAL_SECTION
+0x000 DebugInfo : 0xffffffff`ffffffff _RTL_CRITICAL_SECTION_DEBUG
+0x008 LockCount : 0n-2
+0x00c RecursionCount : 0n1
+0x010 OwningThread : 0x00000000`0000ac68 Void
+0x018 LockSemaphore : (null)
+0x020 SpinCount : 0x20007d0
0:005> ~
0 Id: e554.ac68 Suspend: 1 Teb: 00000017`812b6000 Unfrozen
1 Id: e554.10064 Suspend: 1 Teb: 00000017`812b8000 Unfrozen
2 Id: e554.b98 Suspend: 1 Teb: 00000017`812ba000 Unfrozen
3 Id: e554.9dd0 Suspend: 1 Teb: 00000017`812bc000 Unfrozen
4 Id: e554.b598 Suspend: 1 Teb: 00000017`812c0000 Unfrozen
. 5 Id: e554.10508 Suspend: 1 Teb: 00000017`812c4000 Unfrozen
따라서 현재 어떤 스레드가 Critical Section을 소유하고 있는지 확인할 수 있습니다. 이후
LeaveCriticalSection 함수를 호출하면 OwningThread에 NULL이 기록될 것이고,
ConsoleApplication1!_RTL_CRITICAL_SECTION
+0x000 DebugInfo : 0xffffffff`ffffffff _RTL_CRITICAL_SECTION_DEBUG
+0x008 LockCount : 0n-1
+0x00c RecursionCount : 0n0
+0x010 OwningThread : (null)
+0x018 LockSemaphore : (null)
+0x020 SpinCount : 0x20007d0
마지막으로
DeleteCriticalSection 함수를 호출하면 이런 식으로 자원이 정리됩니다.
ConsoleApplication1!_RTL_CRITICAL_SECTION
+0x000 DebugInfo : (null)
+0x008 LockCount : 0n0
+0x00c RecursionCount : 0n0
+0x010 OwningThread : (null)
+0x018 LockSemaphore : (null)
+0x020 SpinCount : 0
만약 Critical Section으로 인한 hang 현상이 발생했다면, 위에서 살펴봤듯이 OwningThread를 확인하면 어떤 스레드가 Critical Section을 소유하고 있는지 확인할 수 있고, 그 스레드로 이동해 호출 스택을 확인함으로써 문제의 원인을 찾을 수 있습니다.
WinDbg : Debugging A Critical Section Based Dead Lock Scenario
; https://jumpdollar.blogspot.com/2014/10/windbg-debugging-critical-section-based.html
게다가 Critical Section을 열거하는
!cs 명령어도 제공하는데요,
// -l 옵션을 함께 주면 "LOCKED" 상태인 Critical Section만 출력
0:000> !cs
-----------------------------------------
DebugInfo = 0x00007ffe2cbd1fc0
Critical section = 0x00007ffe2cbd1f00 (ntdll!RtlpProcessHeapsLock+0x0)
NOT LOCKED
LockSemaphore = 0x0
SpinCount = 0x00000000020007d0
-----------------------------------------
DebugInfo = 0x00007ffe2cbd1ff0
Critical section = 0x0000026848da02c0 (+0x26848DA02C0)
NOT LOCKED
LockSemaphore = 0x0
SpinCount = 0x00000000020007d0
-----------------------------------------
DebugInfo = 0x00007ffe2cbd2020
Critical section = 0x0000026848d002c0 (+0x26848D002C0)
NOT LOCKED
LockSemaphore = 0x0
SpinCount = 0x00000000020007d0
-----------------------------------------
DebugInfo = 0x00007ffe2cbca860
Critical section = 0x00007ffe2cbca838 (ntdll!LdrpSnapsLock+0x0)
NOT LOCKED
LockSemaphore = 0x0
SpinCount = 0x0000000004000000
인자로 개별 Critical Section을 지정해서 조회하는 것도 가능하고,
// CRITICAL_SECTION 지역 변수의 주소가 0000000d`c32ffa48인 것으로 가정
0:000> !cs 0000000d`c32ffa48
-----------------------------------------
Critical section = 0x0000000dc32ffa48 (+0xDC32FFA48)
DebugInfo = 0xffffffffffffffff
LOCKED
LockCount = 0x0
WaiterWoken = No
OwningThread = 0x000000000000f2c8
RecursionCount = 0x1
LockSemaphore = 0x0
SpinCount = 0x00000000020007d0
전역 변수라면 심벌을 이용해 바로 찾을 수도 있습니다.
0:001> !cs ConsoleApplication1!g_cs
-----------------------------------------
Critical section = 0x00007ff7c714d750 (ConsoleApplication1!g_cs+0x0)
DebugInfo = 0xffffffffffffffff
NOT LOCKED
LockSemaphore = 0x0
SpinCount = 0x00000000020007d0
참고로 (Exts.dll 확장 DLL에서 제공하는) !cs 명령어와 함께 Ntsdexts.dll 확장 DLL에서도 이와 유사한 !critsec 명령어가 있긴 하지만,
0:001> !critsec ConsoleApplication1!g_cs
DebugInfo for CritSec at 00007ff7c714d750 could not be read
Probably NOT an initialized critical section.
CritSec ConsoleApplication1!g_cs+0 at 00007ff7c714d750
LockCount NOT LOCKED
RecursionCount 0
OwningThread 0
그다지 알 필요는 없을 듯합니다. ^^;
그런데, !cs 명령어의 출력 결과를 보면 예제 코드에서 우리가 직접 정의한 Critical Section의 전역 변수(g_cs)와 지역 변수(l_cs)가 모두 누락돼 있습니다. 정확한 선정 기준은 알 수 없지만 테스트를 통해 짐작은 할 수 있는데요, 이를 위해 다음과 같이 예제 코드를 변경해 보겠습니다.
#include <Windows.h>
#include <iostream>
#include <thread>
using namespace std;
CRITICAL_SECTION g_cs;
void DoWork(CRITICAL_SECTION* pcs, int seconds)
{
EnterCriticalSection(pcs);
Sleep(1000 * seconds);
LeaveCriticalSection(pcs);
}
int main()
{
InitializeCriticalSection(&g_cs);
CRITICAL_SECTION l_cs;
InitializeCriticalSection(&l_cs);
cout << "addr of l_cs: " << &l_cs << endl;
cout << "addr of g_cs: " << &g_cs << endl;
thread t1([&]() {
DoWork(&g_cs, 2);
DoWork(&l_cs, 5);
});
thread t2([&]() {
DoWork(&g_cs, 2);
DoWork(&l_cs, 5);
});
t1.join();
t2.join();
cout << "Press ENTER key to exit..." << endl;
cin.get();
return 0;
}
위와 같이, 한 번이라도 경합을 벌이고 나면 이제 !cs 명령어의 출력에 g_cs, l_cs 변수가 포함됩니다.
0:004> !cs
-----------------------------------------
...[생략]...
-----------------------------------------
DebugInfo = 0x00007ffe2cbd2050
Critical section = 0x0000028fbc9402c0 (+0x28FBC9402C0) // 지역 변수 l_cs
NOT LOCKED
LockSemaphore = 0x0
SpinCount = 0x00000000020007d0
-----------------------------------------
DebugInfo = 0x00007ffe2cbd2080
Critical section = 0x00007ff7f5ff1470 (ConsoleApplication2!g_cs+0x0) // 전역 변수 g_cs
NOT LOCKED
LockSemaphore = 0xFFFFFFFF
SpinCount = 0x00000000020007cf
위의 출력에서 재미있는 점은, DebugInfo 필드의 값도 새롭게 채워져 있다는 점입니다. 아마도 DebugInfo 값이 채워지는 그 시점에 !cs 명령어가 알 수 있는 Critical Section의 목록에 추가되는 것으로 짐작됩니다.
그리고 DebugInfo 역시 _RTL_CRITICAL_SECTION_DEBUG로 알려진 구조체이므로 이 값을 조회하는 것도 가능합니다.
0:004> dt _RTL_CRITICAL_SECTION_DEBUG 0x00007ffe2cbd2080
ConsoleApplication2!_RTL_CRITICAL_SECTION_DEBUG
+0x000 Type : 0
+0x002 CreatorBackTraceIndex : 0
+0x008 CriticalSection : 0x00007ff7`f5ff1470 _RTL_CRITICAL_SECTION
+0x010 ProcessLocksList : _LIST_ENTRY [ 0x00007ffe`2cbca8d0 - 0x00007ffe`2cbd2060 ]
+0x020 EntryCount : 0
+0x024 ContentionCount : 1
+0x028 Flags : 0
+0x02c CreatorBackTraceIndexHigh : 0
+0x02e Identifier : 0x4353
참고로 아래는 SDK에 담긴 헤더 파일에서 확인한 구조체 정의입니다.
// winnt.h
typedef struct _RTL_CRITICAL_SECTION_DEBUG {
WORD Type;
WORD CreatorBackTraceIndex;
struct _RTL_CRITICAL_SECTION *CriticalSection;
LIST_ENTRY ProcessLocksList;
DWORD EntryCount;
DWORD ContentionCount; // 경합이 발생한 누적 횟수
DWORD Flags;
WORD CreatorBackTraceIndexHigh;
WORD Identifier;
} RTL_CRITICAL_SECTION_DEBUG, *PRTL_CRITICAL_SECTION_DEBUG, RTL_RESOURCE_DEBUG, *PRTL_RESOURCE_DEBUG;
typedef struct _RTL_CRITICAL_SECTION {
PRTL_CRITICAL_SECTION_DEBUG DebugInfo;
//
// The following three fields control entering and exiting the critical
// section for the resource
//
LONG LockCount;
LONG RecursionCount; // 동일한 스레드가 같은 lock을 진입한 횟수
HANDLE OwningThread; // from the thread's ClientId->UniqueThread
HANDLE LockSemaphore;
ULONG_PTR SpinCount; // force size on 64-bit systems when packed
} RTL_CRITICAL_SECTION, *PRTL_CRITICAL_SECTION;
// minwinbase.h
typedef RTL_CRITICAL_SECTION CRITICAL_SECTION;
[이 글에 대해서 여러분들과 의견을 공유하고 싶습니다. 틀리거나 미흡한 부분 또는 의문 사항이 있으시면 언제든 댓글 남겨주십시오.]