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