최근에 BSOD 분석을 넘어서 PSOD 분석을 하고 있습니다. 처음에는 gdb 사용법을 전혀 몰라서 고생을 했는데 이제는 간단한 분석은 회사 시스템을 통해서 할 수 있게 되었습니다.

디버깅을 하면서 느낀 것은 Windows Kernel Debugging과 원리는 비슷한데 실제 구현은 다르다는 것입니다. 비슷하면서 다른 점을 확인해보면 Windows kernel에 있는 spinlock이라는 개념이 동일하게 Linux와 ESXi에 있고 ESXi 에서는 spinlock을 오래 소유하면 시스템이 크래시 될 수 있습니다. Windows 에서는 Spinlock을 오래 소유하면 행만 말생하고 크래시가 되지는 않습니다. (시스템을 행 상태로 둘 것인지? 아니면 크래시를 해서라도 행을 해소하고 원인 분석을 할지는 업체마다 판단이 다릅니다.)

아래 VMware 문서의 설명을 보면 Spinlock을 오래 소유하고 있어서 Spinlock count가 한계에 달해서 시스템이 크래시 되었다고 합니다. 스택에 나오는 것은 Spinlock을 소유하기 위해 대기하는 Thread 이어서 원인을 찾기 위해서는 Spinlock을 소유한 Thread를 찾아야합니다. 일반적으로 원인은 ESXi 또는 3rd party kernel driver 가 spinlock을 해제하지 않았기 때문입니다.

Microsoft는 WinDbg를 통해서 BSOD를 분석할 수 있게 공개하였지만 VMware는 디버깅 방법이 공개되어 있지 않기 때문에(아마도 공개 안 되어 있을 것 같습니다.) VMware support 부서에 연락해서 기술지원을 받아야 할 것입니다. 만약 원인 분석 보다는 문제 예방을 원하실 경우 ESXi 와 각종 드라이버를 최신으로 update 하면 좋습니다. 신규 버그가 아니라면 패치를 설치해서 기존 문제들을 해결할 수 있습니다. 그래도 문제가 재현된다면 core dump 파일을 수집해서 업체의 분석을 받아야 합니다.

 

Understanding a "Spin count exceeded" purple diagnostic screen (1020105)

https://kb.vmware.com/s/article/1020105

VMware ESX Server [Releasebuild-207095]

Spin count exceeded (iplLock) - possible deadlock

cr2=0xb6ea3fff cr3=0x22401000 cr4=0x6f0

frame=0x14028d4 ip=0x626265

es=0xffffffff ds=0xffffffff fs=0xffffffff gs=0xffffffff

eax=0xffffffff ebx=0xffffffff ecx=0xffffffff edx=0xffffffff

ebp=0x1402a3c esi=0xffffffff edi=0xffffffff err=-1 eflags=0xffffffff

*0:1024/console 1:1094/vmm0:M100 2:1086/vmware-vm 3:1118/mks:dby-d

4:1109/vmm0:M102 5:1116/vmm0:dby- 6:1096/mks:M1000 7:1082/vmm0:M100

@BlueScreen: Spin count exceeded (iplLock) - possible deadlock

0x1402a3c:[0x626265]Panic+0x10 stack: 0x83821c, 0x2970608, 0x4

0x1402a90:[0x634ff3]SP_WaitLock+0x1ca stack: 0x2970600, 0x1402ab8, 0x9d75ef

0x1402a9c:[0x9b1386]cosShadow+0x385 stack: 0x0, 0x2865a40, 0x2865a40

0x1402ab8:[0x9d75ef]cosShadow+0x265ee stack: 0x0, 0xa8ae9be8, 0x53ac1

0x1402af0:[0x63b947]TimerBHHandlerLoop+0x18e stack: 0x1456c98, 0x0, 0x148a798

0x1402b30:[0x63e7b1]Timer_BHHandler+0xb8 stack: 0x0, 0xdf, 0x0

0x1402b88:[0x6188c5]BH_Check+0x84 stack: 0x1, 0x1402bac, 0x1754941

0x1402bac:[0x620126]IDT_HandleInterrupt+0x85 stack: 0x1402bf8, 0x0, 0x37638000

0x1402bc0:[0x62024d]IDT_IntrHandler+0x4c stack: 0x1402bf8, 0x4028, 0x4028

0x1402c70:[0x693b7c]CommonIntr+0xb stack: 0x14897a0, 0x0, 0x1402de0

0x1402e1c:[0x763234]CpuSchedDispatch+0x487 stack: 0x2391f00, 0x14897a0, 0x0

0x1402e88:[0x765a36]CpuSchedDoWaitDirectedYield+0x351 stack: 0x0, 0x1f57f60, 0x0

0x1402ea4:[0x765b66]CpuSched_WaitIRQ+0x31 stack: 0xfedcba90, 0x6, 0x1f57f60

0x1402ec4:[0x692893]VMNIXVMKSyscall_Idle+0xe2 stack: 0x1402f6c, 0x6924e3, 0x0

0x1402ecc:[0x687538]VMNIXVMKSyscallUnpackIdle+0x7 stack: 0x0, 0x0, 0x0

0x1402f6c:[0x6924e3]HostSyscall+0xf6 stack: 0x1402fbc, 0xc03dbf98, 0x1c

0x1402fe8:[0x69187f]HostVMKEntry+0xce stack: 0x0, 0x0, 0x0

VMK uptime: 6:09:43:15.399 TSC: 1472031313725856

Starting coredump to disk Starting coredump to disk Dumping using slot 1 of 1... using slot 1 of 1... log

 

 

Windows에는 Spinlock에 의한 크래시는 없지만 인터럽트의 후속처리를 하는 DPC (Linux의 Bottom half에 해당하는 것으로 보임) 에서 너무 많은 시간 동은 실행이 되면 BugCheck 0x133이 발생합니다. 일반적으로 HW 에서 인터럽트가 발생하고 DPC 루틴을 실행할 때 너무 시간이 많이 걸려서 크래시 되는 것입니다.

Bug Check 0x133 DPC_WATCHDOG_VIOLATION

https://docs.microsoft.com/ko-kr/windows-hardware/drivers/debugger/bug-check-0x133-dpc-watchdog-violation

 

DPC 루틴 하나가 너무 많은 시간을 사용한 경우 콜스택만 보면 원인을 확인할 수 있으나 다수의 DPC 루틴이 실행된 경우 원인을 찾기가 힘들어집니다. 이 경우 아래 블로그를 참고해서 xPerf를 실행해야할 수도 있습니다. (꼭 Microsoft의 지원을 받으셔야 원인을 찾을 수 있습니다.)

Determining the source of Bug Check 0x133 (DPC_WATCHDOG_VIOLATION) errors on Windows Server 2012

https://blogs.msdn.microsoft.com/ntdebugging/2012/12/07/determining-the-source-of-bug-check-0x133-dpc_watchdog_violation-errors-on-windows-server-2012/

 

아래와 같이 HP 드라이버에서 문제가 발생할 수도 있고 Windows Kernel의 문제로 발생할 수도 있습니다.

권고: HP 네트워크 서버 어댑터 - Windows Server 2012 R2에서 ocnd64.sys v11.1.145.30 드라이버를 실행하면 Bugcheck 0x133 오류가 발생할 수 있음

https://support.hpe.com/hpsc/doc/public/display?docId=emr_na-a00005104es_es

FIX: Stop error 0x133 or 0x9E occurs when WHEA record is not acknowledged by SMI in Windows

https://support.microsoft.com/en-us/help/2877237/fix-stop-error-0x133-or-0x9e-occurs-when-whea-record-is-not-acknowledg

Analyzing the dump showed the following stack

DPC_WATCHDOG_VIOLATION (133)

The DPC watchdog detected a prolonged run time at an IRQL of DISPATCH_LEVEL

or above.

Arguments:

Arg1: 0000000000000001, The system cumulatively spent an extended period of time at

DISPATCH_LEVEL or above. The offending component can usually be

identified with a stack trace.

Arg2: 0000000000003c19, The watchdog period.

Arg3: 0000000000000000

Arg4: 0000000000000000

 

Debugging Details:

------------------

 

 

DPC_TIMEOUT_TYPE: DPC_QUEUE_EXECUTION_TIMEOUT_EXCEEDED

 

DEFAULT_BUCKET_ID: WIN8_DRIVER_FAULT

 

BUGCHECK_STR: 0x133

 

PROCESS_NAME: System

 

CURRENT_IRQL: d

 

ANALYSIS_VERSION: 6.13.0015.1713 (debuggers(dbg).130203-2012) amd64fre

 

LAST_CONTROL_TRANSFER: from fffff802145e3cb3 to fffff80214464440

 

STACK_TEXT:

fffff880`0c4a54f8 fffff802`145e3cb3 : 00000000`00000133 00000000`00000001 00000000`00003c19 00000000`00000000 : nt!KeBugCheckEx

fffff880`0c4a5500 fffff802`144a8774 : fffff880`0c4a5670 00000000`0042f906 fffff880`0c4a5680 fffff780`00000320 : nt! ?? ::FNODOBFM::`string'+0x14600

fffff880`0c4a5580 fffff802`14b78eca : 00000000`00000001 fffffa80`31427a01 00000000`00275f48 fffffa80`437f7000 : nt!KeUpdateTime+0x2ec

fffff880`0c4a5760 fffff802`1445d00e : 0000009f`6bc998e4 ffff7af7`41437906 fffff802`14ba2580 00001f80`004a0260 : hal!HalpTimerClockInterrupt+0x86

fffff880`0c4a5790 fffff802`14b740ba : fffffa80`437f70b8 00000000`00010008 00000000`0000e39d fffff802`14b96e80 : nt!KiInterruptDispatchLBControl+0x1ce

fffff880`0c4a5920 fffff880`00d79c88 : 00000000`00000001 00000000`00000001 fffff802`14b96e80 00000000`00000001 : hal!HalpTimerStallExecutionProcessor+0x10b

fffff880`0c4a59b0 fffff880`00d787f8 : 00000000`00000001 fffff802`14b96e80 00000000`00000700 fffff802`1456a72d : PSHED!PshedpWaitForOperationToComplete+0x1c

fffff880`0c4a59e0 fffff880`00d77539 : fffffa80`00000609 fffff802`14b96e80 fffffa80`321fb950 fffffa80`437f7010 : PSHED!PshedpWriteErrorRecordERST+0x89

fffff880`0c4a5a10 fffff802`1456ac60 : 00000000`00000001 00000000`00000000 00000000`00000000 fffffa80`437f7038 : PSHED!PshedWriteErrorRecord+0x71

fffff880`0c4a5a40 fffff802`14b83703 : fffff880`00000728 00000000`00000000 fffff880`0c4a5ba0 fffff802`14b96e80 : nt!WheaReportHwError+0x200

fffff880`0c4a5aa0 fffff802`14b831f3 : 00000000`00000001 00000000`00000000 fffff880`0c4a5c50 00000000`00000000 : hal!HalpMcaReportError+0x53

fffff880`0c4a5c00 fffff802`14bb0485 : 00000000`00000002 00000000`00000000 00000000`00000000 00000000`00000000 : hal!HalpCmcPollProcessor+0x73

fffff880`0c4a5c50 fffff802`144a22b1 : fffff802`14690110 fffffa80`3316b700 fffff802`14bb03f0 fffff802`1446dc00 : hal!HalpCmcWorkerRoutine+0x95

fffff880`0c4a5cc0 fffff802`14437045 : fffff880`0c4a5ec0 00000000`00000080 fffff802`144a2170 fffffa80`3316b700 : nt!ExpWorkerThread+0x142

fffff880`0c4a5d50 fffff802`144eb766 : fffff880`02a47180 fffffa80`3316b700 fffff880`02a53d40 fffffa80`310ba980 : nt!PspSystemThreadStartup+0x59

fffff880`0c4a5da0 00000000`00000000 : fffff880`0c4a6000 fffff880`0c4a0000 00000000`00000000 00000000`00000000 : nt!KiStartSystemThread+0x16


감사합니다.

저작자표시 비영리 변경금지

'Windows & (Linux | vSphere)' 카테고리의 다른 글

네트워크 문제 확인하기 (Linux, ESXi, Windows)  (0) 2019.02.10
시스템 행 현상이 발생되었을 때 NMI를 이용한 덤프 분석  (0) 2019.02.09
ESXi 패치 설치 vs Windows 패치 설치  (0) 2018.12.22
디스크가 가득 차는 경우  (0) 2018.12.15
부팅 과정 및 복구 (Grub)  (0) 2018.06.17

이미 EOS 된 Windows 2003 이 자꾸 Cash 된다고 하여 덤프 분석을 진행해 봤습니다.

제일 먼저 실행해야 할 !analyze -v를 실행해 보았습니다.

 

BugCheck 0x7E 라는 코드인데 시스템의 중요 스레드에서 Exception이 발생했는데 처리하지 못해서 시스템이 크래시 된 것 입니다.

3: kd> !analyze -v

*******************************************************************************

*                                                                             *

*                        Bugcheck Analysis                                    *

*                                                                             *

*******************************************************************************

 

SYSTEM_THREAD_EXCEPTION_NOT_HANDLED (7e)

This is a very common bugcheck.  Usually the exception address pinpoints

the driver/function that caused the problem.  Always note this address

as well as the link date of the driver/image that contains this address.

Arguments:

Arg1: ffffffffc0000005, The exception code that was not handled

Arg2: fffffadf26a2ce30, The address that the exception occurred at

Arg3: fffffadf27925950, Exception Record Address

Arg4: fffffadf27925360, Context Record Address

 

Exception record를 확인하니 srv 라는 네트워크 드라이버를 담당하는 드라이버에서 Access Violation 오류가 발생한 것을 확인할 수 있습니다.

EXCEPTION_RECORD:  fffffadf27925950 -- (.exr 0xfffffadf27925950)

ExceptionAddress: fffffadf26a2ce30 (srv!memmove+0x0000000000000064)

   ExceptionCode: c0000005 (Access violation)

  ExceptionFlags: 00000000

NumberParameters: 2

   Parameter[0]: 0000000000000001

   Parameter[1]: 0000000100089458

Attempt to write to address 0000000100089458

 

 

아래의 .cxr 을 클릭하면 오류가 발생한 코드로 이동을 합니다.

CONTEXT:  fffffadf27925360 -- ( .cxr 0xfffffadf27925360 )

rax=00000000000893f0 rbx=fffffadf36263958 rcx=0000000100089458

rdx=fffffade3720f0f0 rsi=fffffadf3734cb20 rdi=00000000000893f0

rip=fffffadf26a2ce30 rsp=fffffadf27925b78 rbp=0000000000000000

 r8=0000000000000018  r9=0000000000000003 r10=0000000000000012

r11=0000000100089458 r12=0000000000000000 r13=0000000000000018

r14=00000000ffffff84 r15=0000000000000000

iopl=0         nv up ei pl nz na po nc

cs=0010  ss=0018  ds=002b  es=002b  fs=0053  gs=002b             efl=00010206

srv!memmove+0x64:

fffffadf`26a2ce30 488901          mov     qword ptr [rcx],rax ds:002b:00000001`00089458=????????????????

Resetting default scope

 

 

오류가 발생한 코드로 이동을 해보니 rcx 레지스터에 잘못된 값이 들어 있어서 문제가 발생한 것입니다. [rcx] 는 rcx 의 값에 해당하는 주소에 접근한다는 의미 입니다.

3: kd> .cxr 0xfffffadf27925360

rax=00000000000893f0 rbx=fffffadf36263958 rcx=0000000100089458

rdx=fffffade3720f0f0 rsi=fffffadf3734cb20 rdi=00000000000893f0

rip=fffffadf26a2ce30 rsp=fffffadf27925b78 rbp=0000000000000000

 r8=0000000000000018  r9=0000000000000003 r10=0000000000000012

r11=0000000100089458 r12=0000000000000000 r13=0000000000000018

r14=00000000ffffff84 r15=0000000000000000

iopl=0         nv up ei pl nz na po nc

cs=0010  ss=0018  ds=002b  es=002b  fs=0053  gs=002b             efl=00010206

srv!memmove+0x64:

fffffadf`26a2ce30 488901          mov     qword ptr [rcx],rax ds:002b:00000001`00089458=????????????????

 

 

콜스택을 확인해보니 다른 드라이버 모듈은 안 보이고 SRV만 보입니다. 아마도 네트워크 드라이브에 대한 요청을 받은 후 네트워크 요청을 처리하던 중으로 보입니다.

3: kd> k

  *** Stack trace for last set context - .thread/.cxr resets it

 # Child-SP          RetAddr           Call Site

00 fffffadf`27925b78 fffffadf`26ae24c9 srv!memmove+0x64

01 fffffadf`27925b80 fffffadf`26a2c8f7 srv!SrvSmbNtTransactionSecondary+0x3e9

02 fffffadf`27925c40 fffffadf`26a2c853 srv!SrvProcessSmb+0x19f

03 fffffadf`27925ca0 fffffadf`26a8d0f2 srv!SrvRestartReceive+0xca

04 fffffadf`27925d10 fffff800`0124f932 srv!WorkerThread+0x144

05 fffffadf`27925d70 fffff800`01020556 nt!PspSystemThreadStartup+0x3e

06 fffffadf`27925dd0 00000000`00000000 nt!KiStartSystemThread+0x16

 

 

어떤 시스템 중요 프로세스인지 확인해 봅니다.

3: kd> !process -1 0

PROCESS fffffadf38bf85a0

    SessionId: none  Cid: 0004    Peb: 00000000  ParentCid: 0000

    DirBase: 23be01000  ObjectTable: fffffa8000001bd0  HandleCount: 2717.

    Image: System

 

 

어셈블리로 분석을 해 보았지만 특이한 점이 확인되지 않아서 SrvSmbNtTransactionSecondary 함수를 인터넷에서 검색해 봅니다.

DELL 문서에서 KB2696547에 해당하는 이슈라고 확인됩니다.

Stop Code 0x50 srv.sys caused by EternalBlue Exploit

https://www.dell.com/support/article/kr/ko/krdhs1/sln306200/stop-code-0x50-srvsys-caused-by-eternalblue-exploit?lang=en

Microsoft released a Security Bulletin regarding SMBv1.0. External Link The most severe of the vulnerabilities could allow remote code execution if an attacker sends specially crafted messages to a Microsoft Server Message Block 1.0 (SMBv1) server.

 

You can identify that this issue is occuring by analyzing the Stack on the Memory Dump and finding this specific lines:

 

ffffd001`078b0700 fffff801`71252360 nt!KiPageFault+0x12f

ffffd001`078b0890 fffff801`712522a5 srv!SrvOs2FeaToNt+0x48

ffffd001`078b08c0 fffff801`7127369b srv!SrvOs2FeaListToNt+0x125

ffffd001`078b0910 fffff801`7127c8ba srv!SrvSmbOpen2+0xc3

ffffd001`078b09b0 fffff801`7127fb2e srv!ExecuteTransaction+0x2ca

ffffd001`078b09f0 fffff801`7120d84f srv!SrvSmbTransactionSecondary+0x40b

ffffd001`078b0a90 fffff801`7120da20 srv!SrvProcessSmb+0x237

ffffd001`078b0b10 fffff801`7124cac8 srv!SrvRestartReceive+0x114

ffffd001`078b0b50 fffff800`13591306 srv!WorkerThread+0x5248

ffffd001`078b0bd0 fffff800`1317f280 nt!IopThreadStart+0x26

ffffd001`078b0c00 fffff800`131d89c6 nt!PspSystemThreadStartup+0x58

ffffd001`078b0c60 00000000`00000000 nt!KiStartSystemThread+0x16

 

 

좀더 검색을 해보니 MS SMB 취역점인 MS17-010을 분석한 문서가 보입니다. 아마도 MS17-010 취약점에 대한 공격이 들어왔는데 srv 드라이버가 이를 잘 처리하지 못해서 시스템이 크래시 된 것으로 보입니다.

https://github.com/nixawk/labs/issues/9

===============

Bug5: Transaction secondary request is accepted and processed after transaction execution is started

===============

If we send a transaction secondary request to a transaction that AllDataReceived member has already been set, a server will

send back an error without processing the request.

 

For multipiece transaction, AllDataReceived is set (in SrvSmbTransactionSecondary()/SrvSmbNtTransactionSecondary()) before

executing transaction. But AllDataReceived is NOT set (in SrvSmbTransaction()/SrvSmbNtTransaction()) when transaction is

completed in 1 SMB message. This allow us to send a transaction secondary request to modify InParamter/InData buffer and

ParameterCount/DataCount while server is executing a transaction or sending a reply.

 

 

Windows Server 2003은 이미 EOS 되어 보안 취약점에 대해서도 패치를 제공하지 않은 상태입니다. 하지만 SMB 취약점은 영향도가 커서 특별히 패지가 만들어져 있습니다. 혹시 아직 Windows 2003을 운영하고 계신다면 꼭 아래 패치를 설치해주세요

Security Update for Windows Server 2003 (KB4012598)

https://www.microsoft.com/en-us/download/details.aspx?id=55248

 

감사합니다.


저작자표시 비영리 변경금지

'Debugging' 카테고리의 다른 글

System Hang 분석  (0) 2018.11.24
Symbol Server 설정 (공유, HTTP)  (0) 2018.03.04
[디버거 명령]!Mex.p  (0) 2017.09.25
[디버깅 명령]!mex.help  (0) 2017.09.24

Mex Extension 명령 중 프로세스의 정보를 보여주는 !Mex.p 에 대해서 알아보도록 하겠습니다.


우선 !Mex.p의 사용법을 확인하기 위해서 /help를 사용해 보았습니다.


0: kd> !mex.p /help

Failed converting value '/help' to System.UInt64 for argument "Process Address" (internal name = processAddress)

!p - Displays process details


Usage:

    !p [-t] [-z] [-p <PID>] [<Process Address>] 

        -t|-threads        : Show Threads

        -z                 : Show Terminated (zombie) threads

        -p|-pid <PID>      : Finds a process via its Process ID (PID)

        Process Address    : Address of _EPROCESS Object


    !p 

        !p with no params assumes current implicit process (set with .process)


    !p [-?|-h] 

        -?|-h|-help    : Display this help text


Note: In usermode, you may not specify a PID of process Address, only the current process can be displayed

Keywords: process, pid

Current Owner: mexfeedback



Mex는 파라미터로 PID나 Process Address를 받아서 Process의 상세 정보를 출력 합니다. 그럼 Explorer의 정보를 확인하기 위해 아래 명령을 사용하여 Explorere의 Prcess Address를 확인하도록 합니다.



0: kd> !process 0 0 explorer.exe

PROCESS ffffe00100fda900

    SessionId: 1  Cid: 0c8c    Peb: 7ff66a125000  ParentCid: 0db8

    DirBase: 119a35000  ObjectTable: ffffc001ce3e1c80  HandleCount: <Data Not Accessible>

    Image: explorer.exe



Explorer의 주소는 ffffe00100fda900 로 확인 되었고 Process Address 파라미터를 사용하여 !Mex.p를 실행 합니다.



0: kd> !mex.p ffffe00100fda900

Name         Address                  Ses PID          Parent       PEB              Create Time                Mods Handle Thrd User Name

============ ======================== === ============ ============ ================ ========================== ==== ====== ==== ================

explorer.exe ffffe00100fda900 (E|K|O)   1 c8c (0n3212) db8 (0n3512) 00007ff66a125000 07-10-2017 08:39:08.606 오전  184      0   47 MyPC\admin


Command Line: C:\Windows\Explorer.EXE


Memory Details:


    VM   Peak Work Set  Commit Size PP Quota NPP Quota

    ==== ==== ========= =========== ======== =========

    2 TB 2 TB 145.94 MB    58.53 MB  1.34 MB   91.5 KB


Explorer's main thread


Show LPC Port information for process


Show Threads: Unique Stacks    !mex.listthreads (!lt) ffffe00100fda900    !process ffffe00100fda900 7



실행 결과 이름, 주소, Session, PID, 부모 process, PEB, Create Time, Module 수, Handle 수 Thread 수 그리고 사용자 이름이 출력 됩니다.

프로세스의 메모리에 대한 정보가 추가로 출력 됩니다. Windows 운영체제에 추가된 보안 기능 때문에 VM이 2TB로 보입니다.

그리고 몇가지 링크가 출력되는데 Process의 상세 정보를 개별 명령을 입력해서 확인할 필요 없이 간단하게 링크를 클릭해서 결과를 확인할 수 있습니다.



0: kd> !mex.lt ffffe00100fda900

Process      PID Thread             Id State        Time Reason

============ === ================ ==== ======= ========= =============

explorer.exe c8c ffffe00101344080  fe8 Waiting   42s.937 WrUserRequest

explorer.exe c8c ffffe001014d6080  cc4 Waiting    1s.640 WrUserRequest

explorer.exe c8c ffffe00100666080  fac Waiting 6m:30.718 UserRequest

explorer.exe c8c ffffe00101522080  a54 Waiting 1m:08.265 UserRequest

explorer.exe c8c ffffe00101534700  198 Waiting 6m:30.718 UserRequest

explorer.exe c8c ffffe00101536800  3d8 Waiting 6m:03.656 UserRequest

explorer.exe c8c ffffe00101545080  418 Waiting     765ms UserRequest

explorer.exe c8c ffffe00101542800  410 Waiting     765ms UserRequest

explorer.exe c8c ffffe0010154a080  40c Waiting 6m:30.718 UserRequest

explorer.exe c8c ffffe0010155b080  31c Waiting 3m:58.531 UserRequest

explorer.exe c8c ffffe001014f9880  d94 Waiting 1m:20.468 WrQueue

explorer.exe c8c ffffe00101516080  ddc Waiting 6m:30.718 UserRequest

explorer.exe c8c ffffe0010151c080  d40 Waiting   42s.937 UserRequest

explorer.exe c8c ffffe00101564080  d34 Waiting 1m:17.968 UserRequest

explorer.exe c8c ffffe0010155c080 1004 Waiting 3m:21.046 WrUserRequest

explorer.exe c8c ffffe0010155e080 1018 Waiting 6m:30.718 UserRequest

explorer.exe c8c ffffe00101568080 1020 Waiting 1m:17.968 UserRequest

explorer.exe c8c ffffe00101573080 1034 Waiting 1m:17.968 UserRequest

explorer.exe c8c ffffe00101574080 1038 Waiting 1m:17.968 UserRequest

explorer.exe c8c ffffe00101575080 103c Waiting   42s.937 UserRequest

explorer.exe c8c ffffe00101578080 1040 Waiting 1m:17.984 UserRequest

explorer.exe c8c ffffe0010157a080 1044 Waiting 6m:30.718 WrUserRequest

explorer.exe c8c ffffe0010157c080 1050 Waiting 2m:04.281 UserRequest

explorer.exe c8c ffffe0010157d080 1054 Waiting 1m:58.546 WrUserRequest

explorer.exe c8c ffffe00101586080 1060 Waiting 1m:17.984 WrUserRequest

explorer.exe c8c ffffe00101598500 1068 Waiting   12s.843 UserRequest

explorer.exe c8c ffffe001015ae080 1080 Waiting 3m:58.593 UserRequest

explorer.exe c8c ffffe001015b5080 1088 Waiting 1m:17.968 WrUserRequest

explorer.exe c8c ffffe000ffb25080 11d0 Waiting 6m:30.718 UserRequest

explorer.exe c8c ffffe0010014b080 11e4 Waiting 6m:30.718 WrQueue

explorer.exe c8c ffffe001020b8080  f94 Waiting   42s.937 WrUserRequest

explorer.exe c8c ffffe000ff760080  360 Waiting 3m:21.187 UserRequest

explorer.exe c8c ffffe00107423880 1578 Waiting 1m:17.968 UserRequest

explorer.exe c8c ffffe00107cba380  c48 Waiting 1m:17.968 UserRequest

explorer.exe c8c ffffe00109594080 1744 Waiting     765ms UserRequest

explorer.exe c8c ffffe00109cd6880  ba4 Waiting   53s.171 UserRequest

explorer.exe c8c ffffe0010af95880 12e8 Waiting 6m:30.718 UserRequest

explorer.exe c8c ffffe0010aad1080 1714 Waiting 1m:17.984 UserRequest

explorer.exe c8c ffffe0010b1e1880 1640 Waiting   18s.265 WrQueue

explorer.exe c8c ffffe000ffe232c0  ca8 Waiting   42s.937 UserRequest

explorer.exe c8c ffffe0010b114880 148c Waiting   18s.265 WrQueue

explorer.exe c8c ffffe000ffe98880  d10 Waiting   42s.937 WrQueue

explorer.exe c8c ffffe001025f0080  b08 Waiting     765ms WrQueue

explorer.exe c8c ffffe001019d1240  3dc Waiting   13s.796 WrQueue

explorer.exe c8c ffffe00101932880  a5c Waiting   42s.937 WrQueue

explorer.exe c8c ffffe0010b1e8880  6b4 Waiting   18s.843 WrQueue

explorer.exe c8c ffffe0010abba780  f68 Waiting   42s.937 WrQueue


Thread Count: 47



위의 결과는 Mex의 list thread 명령의 출력으로 각 Thread의 주소, TID, Thread 상태, Wait 상태로 전환된지 얼마나 지났는지, 그리고 Wait 상태로 전환된 이유에 대한 설명을 출력 합니다.



0: kd> !mex.fems -s Explorer!.*WinMain !mex.t

Process                         Thread                       CID       TEB              UserTime KernelTime ContextSwitches Wait Reason      Time State   COM-Initialized

explorer.exe (ffffe00100fda900) ffffe00101344080 (E|K|W|R|V) c8c.fe8   00007ff66a12e000   5s.641    11s.984          939044 WrUserRequest 42s.937 Waiting APTKIND_APARTMENTTHREADED (STA)


WaitBlockList:

    Object           Type                 Other Waiters

    ffffe001005352f0 SynchronizationEvent             0


Priority:

    Current Base Decrement ForegroundBoost IO Page

    10      8    0         0               0  5


# Child-SP         Return           Call Site

0 ffffd000215846b0 fffff801feaa5f1e nt!KiSwapContext+0x76

1 ffffd000215847f0 fffff801feaa5999 nt!KiSwapThread+0x14e

2 ffffd00021584890 fffff801feaa4f60 nt!KiCommitThreadWait+0x129

3 ffffd00021584910 fffff96000180288 nt!KeWaitForMultipleObjects+0x3a0

4 ffffd000215849c0 fffff9600017b361 win32k!xxxRealSleepThread+0x278

5 ffffd00021584a80 fffff96000259bcf win32k!xxxSleepThread+0xc1

6 ffffd00021584ad0 fffff801feb6bab3 win32k!NtUserWaitMessage+0x20

7 ffffd00021584b00 00007ffd8399104a nt!KiSystemServiceCopyEnd+0x13

8 00000000008ff358 00007ffd821a1527 USER32!NtUserWaitMessage+0xa

9 00000000008ff360 00007ffd82356b7d SHELL32!CDesktopBrowser::_MessageLoop+0x112

a 00000000008ff3f0 00007ff66ac08498 SHELL32!SHDesktopMessageLoop+0x3d

b 00000000008ff420 00007ff66abe8c21 Explorer!wWinMain+0x5f4

c 00000000008ff710 00007ffd81fa13d2 Explorer!CApplicationUsageTracker::OnPowerBroadcastMessage+0x334

d 00000000008ff7e0 00007ffd846854e4 KERNEL32!BaseThreadInitThunk+0x22

e 00000000008ff810 0000000000000000 ntdll!RtlUserThreadStart+0x34


Explorer 의 Main Thread를 확인하는 링크를 클릭하여 나온 결과 입니다. GUI를 가진 프로세스는 WinMain 이라는 Entry 함수를 가지는데 Mex에서는 각 Thread의 Stack을 확인하여 WinMain 함수를 가진 Thread를 찾고 정보를 출력 합니다. GUI를 가진 Process가 "응답 없음" 상태가 되는 경우 Message 처리를 하지 못하는 것인데 이 경우 WinMain Thread가 어떤 동작을 하고 있는지 확인해서 원인을 찾을 수 있습니다. 



0: kd> !kdexts.alpc /lpp ffffe00100fda900


Ports created by the process ffffe00100fda900:


ffffe001014fab00('OLE68D95701484F75BAC07FBACD02B9') 0, 5 connections

ffffe00101505e40 0 ->ffffe001014f2bb0 0 ffffe000ffda2080('svchost.exe')

ffffe001015474a0 0 ->ffffe00101547910 0 ffffe000ffd736c0('svchost.exe')

ffffe001015ac7f0 0 ->ffffe001015aca20 0 ffffe000fffe3900('svchost.exe')

ffffe001091b5e40 0 ->ffffe00101fdba80 0 ffffe001091e3300('dllhost.exe')

ffffe001012e3780 0 ->ffffe0010a9b0e40 0 ffffe00101fca900('rdpclip.exe')


Ports the process ffffe00100fda900 is connected to:


ffffe000fffaa330 0 -> ffffe000fe6fdda0('ApiPort') 0 ffffe000ffcde080('csrss.exe')

ffffe000ffd4edb0 0 -> ffffe000fffe8900('ThemeApiPort') 0 ffffe000fe6a5900('svchost.exe')

ffffe000ffb494c0 0 -> ffffe000ffdbc1e0('LSMApi') 20 ffffe000ffd736c0('svchost.exe')

ffffe001014c7570 0 -> ffffe000ffd608a0('lsasspirpc') 0 ffffe000ffd4c900('lsass.exe')

ffffe001015059e0 0 -> ffffe000ffd9a8c0('epmapper') 0 ffffe000ffda2080('svchost.exe')

ffffe00101508e40 0 -> ffffe000fffcee40('DwmApiPort') 0 ffffe000ffdd8840('dwm.exe')

ffffe00101537070 0 -> ffffe000ffd78c10('ntsvcs') 38 ffffe000ffcae900('services.exe')

ffffe00101549c70 0 -> ffffe000fef70070('PdcPort') 0 ffffe000fe69d040('System')

ffffe001015415b0 0 -> ffffe000ffd9c090('actkernel') 0 ffffe000ffd736c0('svchost.exe')

ffffe00101555e40 0 -> ffffe000fef70070('PdcPort') 0 ffffe000fe69d040('System')

ffffe00101527d70 0 -> ffffe001001b7e40('FontCachePort') 0 ffffe000fffe3900('svchost.exe')

ffffe001013d7cd0 0 -> ffffe000ffda89e0('umpo') 0 ffffe000ffd736c0('svchost.exe')

ffffe000ffdafe40 0 -> ffffe000fef70070('PdcPort') 0 ffffe000fe69d040('System')

ffffe000ffd80660 0 -> ffffe001014e5c80('webcache_{7329ea82-0845-4e4c-bd18-02b67ac065cc}_S-1-5-21-2726512140-888677503-3125549036-1001') 0 ffffe001014d4900('dllhost.exe')

ffffe000ffd1be40 0 -> ffffe000ffb22090('OLE9F792F2B42A5C2F467737E8AEF83') 0 ffffe001014d4900('dllhost.exe')

ffffe000ffcb7a30 0 -> ffffe000fffcee40('DwmApiPort') 0 ffffe000ffdd8840('dwm.exe')

ffffe001014fb840 0 -> ffffe000fffe5e40('OLE613E2E13198237E01302C92BBC53') 0 ffffe000fffe3900('svchost.exe')

ffffe001014c9cf0 0 -> ffffe000fffc7e40('eventlog') 30 ffffe000fe6a7900('svchost.exe')

ffffe00101526a30 0 -> ffffe000fef70070('PdcPort') 0 ffffe000fe69d040('System')

ffffe001015cc380 0 -> ffffe001015eca50('msctf.serverDefault1') 0 ffffe000fe73e080('taskhostex.exe')

ffffe001016193d0 0 -> ffffe001015eca50('msctf.serverDefault1') 0 ffffe000fe73e080('taskhostex.exe')

ffffe0010161ca50 0 -> ffffe001015eca50('msctf.serverDefault1') 0 ffffe000fe73e080('taskhostex.exe')

ffffe0010161a770 0 -> ffffe001015eca50('msctf.serverDefault1') 0 ffffe000fe73e080('taskhostex.exe')

ffffe0010165a070 0 -> ffffe001015eca50('msctf.serverDefault1') 0 ffffe000fe73e080('taskhostex.exe')

ffffe00101608e40 0 -> ffffe000fe9a82c0('SessEnvPrivateRpc') 0 ffffe000fe6a5900('svchost.exe')

ffffe001096c76b0 0 -> ffffe001015eca50('msctf.serverDefault1') 0 ffffe000fe73e080('taskhostex.exe')

ffffe001096658d0 0 -> ffffe001090c32b0('OLE2B514DB3A33CF461692869C92314') 0 ffffe001091e3300('dllhost.exe')

ffffe0010afd4700 0 -> ffffe00100b4c1a0('TermSrvApi') 0 ffffe000fe9c3640('svchost.exe')

ffffe0010ac22e40 0 -> ffffe001015eca50('msctf.serverDefault1') 0 ffffe000fe73e080('taskhostex.exe')

ffffe001093a46b0 0 -> ffffe000ffd944b0('OLE6FAB873CEB8A01A900BB6C89EA7E') 0 ffffe00101fca900('rdpclip.exe')

ffffe00100f51660 0 -> ffffe00100e50090('OLE5BB8085653D110B414538A51314E') 0 ffffe001019f3900('TSTheme.exe')



Process의 LPC 정보를 나열 하는 링크를 클릭한 결과 입니다. LPC는 Local Procedure Call 로 간단히 이야기 하면 Process 간에 통신을 하는것입니다. Explorer 프로세스가 만든 Port에 connect 되어 있는 Process와 Explorer 가 connect 한 Process의 상태를 확인할 수 있습니다.



0: kd> !us -p ffffad8ad052a080

1 thread [stats]: ffffad8ad0528080

    fffff801f79f52f6 nt!KiSwapContext+0x76

    fffff801f78b7a9a nt!KiSwapThread+0x16a

    fffff801f78b7461 nt!KiCommitThreadWait+0x101

    fffff801f78b6d78 nt!KeWaitForSingleObject+0x2b8

    fffffbb43e64d6f8 win32kfull!xxxRealSleepThread+0x2d8

    fffffbb43e64d377 win32kfull!xxxSleepThread2+0x97

    fffffbb43e6e4242 win32kfull!NtUserWaitMessage+0x42

    fffff801f79fb413 nt!KiSystemServiceCopyEnd+0x13

    00007ffc14211204 0x7ffc14211204


1 thread [stats]: ffffad8ad22ac080

    fffff801f79f52f6 nt!KiSwapContext+0x76

    fffff801f78b7a9a nt!KiSwapThread+0x16a

    fffff801f78b7461 nt!KiCommitThreadWait+0x101

    fffff801f78b56b7 nt!KeWaitForMultipleObjects+0x217

    fffffbb43e64d6f8 win32kfull!xxxRealSleepThread+0x2d8

    fffffbb43e64d377 win32kfull!xxxSleepThread2+0x97

    fffffbb43e6509c9 win32kfull!xxxRealInternalGetMessage+0x919

    fffffbb43e64df5c win32kfull!NtUserGetMessage+0x8c

    fffff801f79fb413 nt!KiSystemServiceCopyEnd+0x13

    00007ffc14211144 0x7ffc14211144


4 threads [stats]: ffffad8ad0677080 ffffad8ad0a8d080 ffffad8ad0a8e080 ffffad8ad0a95700

    fffff801f79f52f6 nt!KiSwapContext+0x76

    fffff801f78b7a9a nt!KiSwapThread+0x16a

    fffff801f78b7461 nt!KiCommitThreadWait+0x101

    fffff801f78b6d78 nt!KeWaitForSingleObject+0x2b8

    fffff801f7d0cdb8 nt!NtWaitForSingleObject+0xf8

    fffff801f79fb413 nt!KiSystemServiceCopyEnd+0x13

    00007ffc177b5424 0x7ffc177b5424


5 threads [stats]: ffffad8ad0688080 ffffad8acdfe3080 ffffad8ad09f3080 ffffad8ad1b0a700 ffffad8ad061f080

    fffff801f79f52f6 nt!KiSwapContext+0x76

    fffff801f78b7a9a nt!KiSwapThread+0x16a

    fffff801f78b7461 nt!KiCommitThreadWait+0x101

    fffff801f78b6d78 nt!KeWaitForSingleObject+0x2b8

    fffff801f7d0c7d1 nt!ObWaitForMultipleObjects+0x2c1

    fffff801f7d0c4d9 nt!NtWaitForMultipleObjects+0xf9

    fffff801f79fb413 nt!KiSystemServiceCopyEnd+0x13

    00007ffc177b5ef4 0x7ffc177b5ef4


7 threads [stats]: ffffad8ad1de1080 ffffad8ad0aa6080 ffffad8ad05dd080 ffffad8acdfcd080 ffffad8acce87080 ffffad8ad08a3080 ffffad8acd0b8700

    fffff801f79f52f6 nt!KiSwapContext+0x76

    fffff801f78b7a9a nt!KiSwapThread+0x16a

    fffff801f78b7461 nt!KiCommitThreadWait+0x101

    fffff801f78b6d78 nt!KeWaitForSingleObject+0x2b8

    fffffbb43e64d6f8 win32kfull!xxxRealSleepThread+0x2d8

    fffffbb43e64d377 win32kfull!xxxSleepThread2+0x97

    fffffbb43e6509c9 win32kfull!xxxRealInternalGetMessage+0x919

    fffffbb43e64df5c win32kfull!NtUserGetMessage+0x8c

    fffff801f79fb413 nt!KiSystemServiceCopyEnd+0x13

    00007ffc14211144 0x7ffc14211144


10 threads [stats]: ffffad8acccfa700 ffffad8ad06fc080 ffffad8ac8ed1700 ffffad8ad15f0080 ffffad8ad0365080 ffffad8ad085c700 ffffad8ad0a63080 ffffad8ad0354080 ffffad8ace0ee080 ffffad8ad2736080

    fffff801f79f52f6 nt!KiSwapContext+0x76

    fffff801f78b7a9a nt!KiSwapThread+0x16a

    fffff801f78b7461 nt!KiCommitThreadWait+0x101

    fffff801f78b6d78 nt!KeWaitForSingleObject+0x2b8

    fffff801f789f104 nt!KiSchedulerApc+0x304

    fffff801f78b94fe nt!KiDeliverApc+0x23e

    fffff801f79f39a3 nt!KiApcInterrupt+0xc3

    fffff801f7cc0405 nt!PspUserThreadStartup+0x35

    fffff801f79f5a86 nt!KiStartUserThread+0x16

    fffff801f79f5a00 nt!KiStartUserThreadReturn

    00007ffc17780d30 0x7ffc17780d30


22 threads [stats]: ffffad8ad4141080 ffffad8ad412d040 ffffad8acba56080 ffffad8ad06a5080 ffffad8ad249b080 ffffad8ad09f6700 ffffad8ad1b8c700 ffffad8ace697080 ffffad8acba54080 ffffad8ad40a1080 ...

    fffff801f79f52f6 nt!KiSwapContext+0x76

    fffff801f78b7a9a nt!KiSwapThread+0x16a

    fffff801f78b7461 nt!KiCommitThreadWait+0x101

    fffff801f78b62e8 nt!KeRemoveQueueEx+0x238

    fffff801f78b5dfd nt!IoRemoveIoCompletion+0x8d

    fffff801f78b4beb nt!NtWaitForWorkViaWorkerFactory+0x30b

    fffff801f79fb413 nt!KiSystemServiceCopyEnd+0x13

    00007ffc177b8c34 0x7ffc177b8c34


30 threads [stats]: ffffad8ad06a1080 ffffad8ad08bc280 ffffad8ad09f4080 ffffad8ad06a6080 ffffad8acd02c080 ffffad8acba60080 ffffad8ad02b1080 ffffad8acba68080 ffffad8ad11c5700 ffffad8ad06643c0 ...

    fffff801f79f52f6 nt!KiSwapContext+0x76

    fffff801f78b7a9a nt!KiSwapThread+0x16a

    fffff801f78b7461 nt!KiCommitThreadWait+0x101

    fffff801f78b56b7 nt!KeWaitForMultipleObjects+0x217

    fffff801f7d0c7d1 nt!ObWaitForMultipleObjects+0x2c1

    fffff801f7d0c4d9 nt!NtWaitForMultipleObjects+0xf9

    fffff801f79fb413 nt!KiSystemServiceCopyEnd+0x13

    00007ffc177b5ef4 0x7ffc177b5ef4


8 stack(s) with 80 threads displayed (100 Total threads)

20 stack(s) were not displayed because we could not switch to thread context, or stack trace was empty


!us 명령은 흥미로운 Mex 명령 입니다. 디버깅을 하다보면 반복되는 콜스택이 화면 전체를 채워버리는 경우를 많이 보았을 것 입니다. 커널스택에서 Thread가 Wait 상태에 들어가면 ObWaitForMultipleObjects 함수를 호출하는 콜스택이 반복적으로 보이게 됩니다. 이 경우 !us 명령은 아주 유용합니다.

!us 는 반복적으로 보이는 콜스택은 1번만 보여주고 각 Thread의 address를 출력하여 어떤 Thread 들이 동일한 콜스택을 보이고 있는지 보여 줍니다.


!Mex.p 명령을 통해서 나오는 출력들을 사용해서 많은 정보를 확인할 수 있는데 각 Case study에 대해서는 나중에 설명하도록 하겠습니다.

'Debugging' 카테고리의 다른 글

Windows Server 2003 BugCheck 0x7E  (0) 2019.01.26
System Hang 분석  (0) 2018.11.24
Symbol Server 설정 (공유, HTTP)  (0) 2018.03.04
[디버깅 명령]!mex.help  (0) 2017.09.24

+ Recent posts

티스토리툴바