WinDbg 디버깅2015. 1. 27. 23:05
반응형

얼마 전부터 Visual Studio를 실행할 때 거의 1~2분간 행이 걸려 있는 현상이 발생했었다.


뭐가 문제인지 어떻게 확인할까 하다가...

배운게 도둑질이라고 행이 걸려 있을 때 전체 덤프를 떠 버렸다. ^^


Windbg로 덤프를 열고 먼저 msdev.exe 프로세스를 찾아서 실행중인 스레드를 봤다.


0: kd> !process 0 3f msdev.exe

PROCESS fffffa800fce6b30

    SessionId: 1  Cid: 1a10    Peb: 7efdf000  ParentCid: 1268

    DirBase: 1dfa1c000  ObjectTable: fffff8a00862a110  HandleCount: 314.

    Image: MSDEV.EXE

    VadRoot fffffa80107d3c90 Vads 367 Clone 0 Private 12752. Modified 197443. Locked 0.

    DeviceMap fffff8a007ec5160

    Token                             fffff8a0157176f0

    ElapsedTime                       00:00:45.997

    UserTime                          00:00:00.000

    KernelTime                        00:00:00.062

    ...

        THREAD fffffa80126a0060  Cid 1a10.19d8  Teb: 000000007efdb000 Win32Thread: fffff900c2d53c20 RUNNING on processor 3

        Not impersonating

        DeviceMap                 fffff8a007ec5160

        Owning Process            fffffa800fce6b30       Image:         MSDEV.EXE

        Attached Process          N/A            Image:         N/A

        Wait Start TickCount      131878         Ticks: 0

        Context Switch Count      156311         IdealProcessor: 7                 LargeStack

        UserTime                  00:00:21.762

        KernelTime                00:00:13.041

*** ERROR: Module load completed but symbols could not be loaded for MSDEV.EXE

        Win32 Start Address MSDEV (0x000000000040155c)

        Stack Init fffff8800c441530 Current fffff8800c441210

        Base fffff8800c442000 Limit fffff8800c435000 Call fffff8800c441580

        Priority 9 BasePriority 8 UnusualBoost 0 ForegroundBoost 0 IoPriority 2 PagePriority 5


        Child-SP          RetAddr           Call Site

        fffff880`0c440680 fffff880`012aa404 Ntfs!NtfsFindPrefix+0x222

        fffff880`0c440730 fffff880`012a7af3 Ntfs!NtfsFindStartingNode+0x6e4

        fffff880`0c440800 fffff880`0128a149 Ntfs!NtfsCommonCreate+0x3d3

        fffff880`0c4409d0 fffff880`01140367 Ntfs!NtfsNetworkOpenCreate+0x119

        fffff880`0c440cb0 fffff880`011438ba fltmgr!FltpPerformFastIoCall+0x357

        fffff880`0c440d10 fffff880`01161a9f fltmgr!FltpPassThroughFastIo+0xda

        fffff880`0c440d50 fffff800`035d3c72 fltmgr!FltpFastIoQueryOpen+0x10f

        fffff880`0c440df0 fffff800`035cf878 nt!IopParseDevice+0x1249

        fffff880`0c440f50 fffff800`035d0a96 nt!ObpLookupObjectName+0x588

        fffff880`0c441040 fffff800`035aef66 nt!ObOpenObjectByName+0x306

        fffff880`0c441110 fffff800`032d2e53 nt!NtQueryAttributesFile+0x145

        fffff880`0c4413a0 00000000`7754168a nt!KiSystemServiceCopyEnd+0x13 (TrapFrame @ fffff880`0c4413a0)

        00000000`0008c9f8 00000000`73a2ae19 ntdll!NtQueryAttributesFile+0xa

        00000000`0008ca00 00000000`73a1d18f wow64!whNtQueryAttributesFile+0x91

        00000000`0008ca80 00000000`750c2776 wow64!Wow64SystemServiceEx+0xd7

        00000000`0008d340 00000000`73a1d286 wow64cpu!ServiceNoTurbo+0x2d

        00000000`0008d400 00000000`73a18a90 wow64!RunCpuSimulation+0xa

        00000000`0008d450 00000000`739e2c52 wow64!Wow64KiUserCallbackDispatcher+0x204

        00000000`0008d7a0 00000000`775411f5 wow64win!whcbfnDWORD+0xe2

        00000000`0008e190 00000000`739efe4a ntdll!KiUserCallbackDispatcherContinue (TrapFrame @ 00000000`0008e058)

        00000000`0008e218 00000000`739caf02 wow64win!ZwUserMessageCall+0xa

        00000000`0008e220 00000000`739e281f wow64win!whNT32NtUserMessageCallCB+0x32

        00000000`0008e270 00000000`739cb03e wow64win!Wow64DoMessageThunk+0x8b

        00000000`0008e2b0 00000000`73a1d18f wow64win!whNtUserMessageCall+0x12e

        00000000`0008e350 00000000`750c2776 wow64!Wow64SystemServiceEx+0xd7

        00000000`0008ec10 00000000`73a1d286 wow64cpu!ServiceNoTurbo+0x2d

        00000000`0008ecd0 00000000`73a1c69e wow64!RunCpuSimulation+0xa

        00000000`0008ed20 00000000`77534966 wow64!Wow64LdrpInitialize+0x42a

        00000000`0008f270 00000000`77531937 ntdll!LdrpInitializeProcess+0x17e3

        00000000`0008f760 00000000`7751c34e ntdll! ?? ::FNODOBFM::`string'+0x28ff0

        00000000`0008f7d0 00000000`00000000 ntdll!LdrInitializeThunk+0xe



나머지 스레드들은 모두 대기중이라 크게 의미 없었다.

현재 실행중인 스레드를 보니 NTFS에서 어떤 파일을 처리중인데 NtQueryAttributesFile 요청으로부터 진행됐다.
이 파일이 뭔지가 궁금했는데 64비트라 살짝 난감했다. 파라미터를 확인할 수 있을지 없을지 몰라서...ㅋㅋ

그래도 궁금해서 NtQueryAttributesFile의 첫번째 파라미터를 찾아보기로 했다.


1. 파라미터가 저장된 스택 영역 찾기

NtQueryAttributesFile의 함수 원형은 다음과 같고 우리가 관심있는 파라미터는 파일 이름이 들어 있는 첫번째 파라미터 ObjectAttributes다.

NTSTATUS NtQueryAttributesFile(
  _In_   POBJECT_ATTRIBUTES ObjectAttributes,
  _Out_  PFILE_BASIC_INFORMATION FileInformation
);


이제 NtQueryAttributesFile의 코드를 좀 살펴 보자.

0: kd> uf nt!NtQueryAttributesFile

nt!NtQueryAttributesFile:

fffff800`035aee20 48895c2418      mov     qword ptr [rsp+18h],rbx

fffff800`035aee25 56              push    rsi

fffff800`035aee26 57              push    rdi

fffff800`035aee27 4154            push    r12

fffff800`035aee29 4881ec70020000  sub     rsp,270h

fffff800`035aee30 488b05a9fbe9ff  mov     rax,qword ptr [nt!_security_cookie (fffff800`0344e9e0)]

fffff800`035aee37 4833c4          xor     rax,rsp

fffff800`035aee3a 4889842460020000 mov     qword ptr [rsp+260h],rax

fffff800`035aee42 488bda          mov     rbx,rdx

fffff800`035aee45 488bf1          mov     rsi,rcx  ; 첫번째 파라미터 저장 (rsi <= rcx)

fffff800`035aee48 65488b042588010000 mov   rax,qword ptr gs:[188h]

fffff800`035aee51 0fb6b8f6010000  movzx   edi,byte ptr [rax+1F6h]

fffff800`035aee58 4084ff          test    dil,dil

fffff800`035aee5b 7432            je      nt!NtQueryAttributesFile+0x6e (fffff800`035aee8f)


nt!NtQueryAttributesFile+0x3d:

fffff800`035aee5d 488bca          mov     rcx,rdx

fffff800`035aee60 f6c207          test    dl,7

fffff800`035aee63 750e            jne     nt!NtQueryAttributesFile+0x53 (fffff800`035aee73)


nt!NtQueryAttributesFile+0x45:

fffff800`035aee65 488b0594c1f5ff  mov     rax,qword ptr [nt!MmUserProbeAddress (fffff800`0350b000)]

fffff800`035aee6c 483bd0          cmp     rdx,rax

fffff800`035aee6f 7308            jae     nt!NtQueryAttributesFile+0x58 (fffff800`035aee79)


nt!NtQueryAttributesFile+0x51:

fffff800`035aee71 eb09            jmp     nt!NtQueryAttributesFile+0x5b (fffff800`035aee7c)


nt!NtQueryAttributesFile+0x53:

fffff800`035aee73 e818070b00      call    nt!ExRaiseDatatypeMisalignment (fffff800`0365f590)

fffff800`035aee78 cc              int     3


nt!NtQueryAttributesFile+0x58:

fffff800`035aee79 488bc8          mov     rcx,rax


nt!NtQueryAttributesFile+0x5b:

fffff800`035aee7c 0fb601          movzx   eax,byte ptr [rcx]

fffff800`035aee7f 8801            mov     byte ptr [rcx],al

fffff800`035aee81 0fb64127        movzx   eax,byte ptr [rcx+27h]

fffff800`035aee85 884127          mov     byte ptr [rcx+27h],al

fffff800`035aee88 eb05            jmp     nt!NtQueryAttributesFile+0x6e (fffff800`035aee8f)


nt!NtQueryAttributesFile+0x6e:

fffff800`035aee8f 41bcb8000000    mov     r12d,0B8h

fffff800`035aee95 4d8bc4          mov     r8,r12

fffff800`035aee98 33d2            xor     edx,edx

fffff800`035aee9a 488d4c2450      lea     rcx,[rsp+50h]

fffff800`035aee9f e8ec6ed2ff      call    nt!memset (fffff800`032d5d90)

fffff800`035aeea4 41bb08000000    mov     r11d,8

fffff800`035aeeaa 6644895c2450    mov     word ptr [rsp+50h],r11w

fffff800`035aeeb0 664489642452    mov     word ptr [rsp+52h],r12w

fffff800`035aeeb6 b807000000      mov     eax,7

fffff800`035aeebb 6689842496000000 mov     word ptr [rsp+96h],ax

fffff800`035aeec3 c78424a800000001000000 mov dword ptr [rsp+0A8h],1

fffff800`035aeece c784249000000000402000 mov dword ptr [rsp+90h],204000h

fffff800`035aeed9 48899c24b0000000 mov     qword ptr [rsp+0B0h],rbx

fffff800`035aeee1 488d842410010000 lea     rax,[rsp+110h]

fffff800`035aeee9 48898424b8000000 mov     qword ptr [rsp+0B8h],rax

fffff800`035aeef1 c68424d100000001 mov     byte ptr [rsp+0D1h],1

fffff800`035aeef9 488d842450010000 lea     rax,[rsp+150h]

fffff800`035aef01 48898424d8000000 mov     qword ptr [rsp+0D8h],rax

fffff800`035aef09 4889b42480000000 mov     qword ptr [rsp+80h],rsi     <= rsi 값을 스택 영역에 저장

fffff800`035aef11 c78424e000000020000000 mov dword ptr [rsp+0E0h],20h

fffff800`035aef1c 65488b042588010000 mov   rax,qword ptr gs:[188h]

fffff800`035aef25 48ff8030030000  inc     qword ptr [rax+330h]

fffff800`035aef2c 65ff042564220000 inc     dword ptr gs:[2264h]

fffff800`035aef34 488d442440      lea     rax,[rsp+40h]

fffff800`035aef39 4889442430      mov     qword ptr [rsp+30h],rax

fffff800`035aef3e 488d442450      lea     rax,[rsp+50h]

fffff800`035aef43 4889442428      mov     qword ptr [rsp+28h],rax

fffff800`035aef48 c744242080000000 mov     dword ptr [rsp+20h],80h

fffff800`035aef50 4533c9          xor     r9d,r9d

fffff800`035aef53 440fb6c7        movzx   r8d,dil

fffff800`035aef57 488b15eac0f5ff  mov     rdx,qword ptr [nt!IoFileObjectType (fffff800`0350b048)]

fffff800`035aef5e 488bce          mov     rcx,rsi    <= rsi 값을 첫번째 파라미터로 전달

fffff800`035aef61 e82a180200      call    nt!ObOpenObjectByName (fffff800`035d0790)



일단 64비트에서는 첫번째 파라미터를 rcx로 전달한다는 것을 알고 있으므로 첫번째 파라미터를 추적해 볼 수 있다. 
함수 진입부에서부터 ObOpenObjectByName을 호출할 때까지의 rcx 값의 이동을 추적하면 된다.

fffff800`035aee45에서 rcx값을 rsi에 저장한다.
fffff800`035aef09에서 rsi값을 [rsp+80h]에 저장한다.
fffff800`035aef5e에서 ObOpenObjectByName을 호출하기 위해 rsi를 첫번째 파라미터 rcx로 전달한다.

ObOpenObjectByName의 첫번째 파라미터도 POBJECT_ATTRIBUTES 이기 때문이다.

NTSTATUS STDCALL
ObOpenObjectByName(
  POBJECT_ATTRIBUTES ObjectAttributes,
  POBJECT_TYPE ObjectType,
  PVOID ParseContext,
  KPROCESSOR_MODE AccessMode,
  ACCESS_MASK DesiredAccess,
  PACCESS_STATE PassedAccessState,
  PHANDLE Handle);


fffff800`035aee45와 fffff800`035aef61 사이에서는 rsi값이 변하지 않기 때문에 이 구간에서 rsi는 NtQueryAttributesFile의 첫번째 파라미터인 POBJECT_ATTRIBUTES다.

fffff800`035aef09에서 rsi값을 [rsp+80h]에 저장해 놓았으므로 이 값을 찾으면 된다. 


2. 스택 기준 주소 찾기

NtQueryAttributesFile 내부 코드가 실행될 때 사용하던 rsp를 찾아야 하는데 이것은 콜스택에서 찾을 수 있다.

        Child-SP          RetAddr           Call Site

        ...

        fffff880`0c441040 fffff800`035aef66 nt!ObOpenObjectByName+0x306

        fffff880`0c441110 fffff800`032d2e53 nt!NtQueryAttributesFile+0x145



WinDbg 콜스택을 보면 친절하게 Child-SP라는 것을 보여주는데 이것이 함수에서 사용하는 rsp다.
따라서 NtQueryAttributesFile의 rsp는  fffff880`0c441110이다.

사실 rsp가 스택 포인터라 함수 내부에서 계속 변할 것이라고 생각했는데 NtQueryAttributesFile 함수 코드를 들여다보면 알 수 있듯이 함수 prolog에서 rsp를 설정하고 나면 함수 내부에서 rsp 값은 변경되지 않는다. 그래서 rsp는 마치 32비트의 ebp처럼 사용된다. 64비트 콜스택에서 왜 Child-SP라는 것을 보여주는지 잘 몰랐었는데 이제야 쓸모가 있는 정보였다는 것을 알게 되었다.


3. 파라미터 내용 확인

본론으로 돌아와서 [rsp+80]을 확인해 보자.

0: kd> dq fffff880`0c441110+80

fffff880`0c441190  00000000`0008d2e0 00000000`00000000

fffff880`0c4411a0  00070000`00200000 00000000`00000000

...


[rsp+80]에 저장된 00000000`0008d2e0이 POBJECT_ATTRIBUTES 다.



0: kd> dt _OBJECT_ATTRIBUTES

ntdll!_OBJECT_ATTRIBUTES

   +0x000 Length           : Uint4B

   +0x008 RootDirectory    : Ptr64 Void

   +0x010 ObjectName       : Ptr64 _UNICODE_STRING

   +0x018 Attributes       : Uint4B

   +0x020 SecurityDescriptor : Ptr64 Void

   +0x028 SecurityQualityOfService : Ptr64 Void



내용을 보면 각 필드의 값을 알 수 있다.


0: kd> dq 00000000`0008d2e0

00000000`0008d2e0  00000032`00000030 00000000`00000000

00000000`0008d2f0  00000000`0008d2d0 00000000`00000040

00000000`0008d300  00000000`00000000 00000000`00000000

...



필드를 대입해 보면 다음과 같다.


Length: 30

RootDirectory: 0

ObjectName: 00000000`0008d2d0

Attributes: 40

SecurityDescriptor: 0

SecurityQualityOfService: 0



_UNICODE_STRING 타입인 ObjectName 00000000`0008d2d0를 확인해 보면 다음과 같다.


0: kd> dt _UNICODE_STRING 00000000`0008d2d0

ntdll!_UNICODE_STRING

 "\??\D:\TEMP\Project\TestTool\dummy\dummy.cpp"

   +0x000 Length           : 0x5A

   +0x002 MaximumLength    : 0x21a

   +0x008 Buffer           : 0x00000000`04ffd1b8  "\??\D:\TEMP\Project\TestTool\dummy\dummy.cpp"




4. 문제의 원인


파일 경로를 보니 번뜩 머리를 스치는 것이 있다.


'아뿔싸... 저 경로는 현재 존재하지 않는 경로다.'


얼마전에 개발 장비를 변경하면서 개발 환경을 그대로 복사한게 문제였다.

Visual Studio의 임시 파일들을 그대로 복사해 왔는데 데이터 디스크(D:)는 새로 구성하는 바람에 D:\TEMP는 존재하지 않는다. 

존재하지 않는 경로의 파일을 읽어대려고 Visual Studio는 그렇게 버벅대고 있었나 부다.


Visual Studio의 임시 파일들을 모두 삭제하고 나니 행이 없어졌다.

만세!!!





반응형
Posted by GreeMate