오늘은 BugCheck 0xA 의 두번째 시간으로 분석은 열심히 하지만 결국 원인을 찾을 수 없는 예제를 살펴보겠습니다. ^^
제가 BugCheck 0xA 를 싫어하는 가장 큰 이유는 누군가가 메모리를 깨뜨렸을 경우에도 BugCheck 0xA 가 많이 발생한다는 점입니다. 메모리를 깨먹는 것 만큼 잡기어려운 버그도 없지요.
BugCheck 0xA 가 IRQL 을 잘못 사용할 경우에만 발생한다면 여기에 촛점을 맞출 수 있겠지만 메모리를 깨뜨려서 이러한 효과가 발생하는 등 다른 경우가 있기 때문에 아주 골치가 아프게 됩니다.
은둔고수중에는 메모리를 깨뜨려서 죽은 덤프도 예리하게 분석하여 원인을 알아내는 분들도 계시지만 저에게는 아직 더 수련이 필요한 부분입니다.
시작부터 너무 기를 죽였네요. -_-;
원인을 알아낼 수 있는 건지 없는 건지는 분석을 시도하지 않고서는 알 수 없습니다.
죽이되든 밥이되든 일단은 가보는 겁니다. ^^
kd> !analyze -v
****************************************************************************
* *
* Bugcheck Analysis *
* *
****************************************************************************
IRQL_NOT_LESS_OR_EQUAL (a)
An attempt was made to access a pageable (or completely invalid) address at an
interrupt request level (IRQL) that is too high. This is usually
caused by drivers using improper addresses.
If a kernel debugger is available get the stack backtrace.
Arguments:
Arg1: 00ed0fab, memory referenced
Arg2: 00000002, IRQL
Arg3: 00000000, value 0 = read operation, 1 = write operation
Arg4: 804eead8, address which referenced memory
Debugging Details:
------------------
READ_ADDRESS: 00ed0fab
CURRENT_IRQL: 2
FAULTING_IP:
nt!KiUnwaitThread+3a
804eead8 80b80302000002 cmp byte ptr [eax+0x203],0x2
DEFAULT_BUCKET_ID: DRIVER_FAULT
BUGCHECK_STR: 0xA
LAST_CONTROL_TRANSFER: from 804eed19 to 804eead8
TRAP_FRAME: f7f27a08 -- (.trap fffffffff7f27a08)
ErrCode = 00000000
eax=00ed0da8 ebx=00000009 ecx=00000008 edx=820ec808 esi=822c8980 edi=0000000a
eip=804eead8 esp=f7f27a7c ebp=f7f27a8c iopl=0 nv up ei pl nz na po nc
cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000 efl=00010206
nt!KiUnwaitThread+0x3a:
804eead8 80b80302000002 cmp byte ptr [eax+0x203],0x2 ds:0023:00ed0fab=??
Resetting default scope
STACK_TEXT:
f7f27a8c 804eed19 00000002 00000000 0000000a nt!KiUnwaitThread+0x3a
f7f27aa4 bf80229d 81ece808 00000002 00000000 nt!KeSetEvent+0x44
f7f27ae4 bf801267 00000022 0073fff4 f7f27d44 win32k!SetWakeBit+0xb7
f7f27d44 bf801e46 f7f374e4 f7f27d64 0073fff4 win32k!RawInputThread+0x585
f7f27d54 804dc1dd 00000000 00000022 00000000 win32k!NtUserCallOneParam+0x20
f7f27d54 7ffe0304 00000000 00000022 00000000 nt!KiSystemService+0xc4
0073ffe0 75aa4faa 75aac27b 00000000 00000022 SharedUserData!SystemCallStub+0x4
0073ffe8 00000000 00000022 00000004 00000000 winsrv!NtUserCallOneParam+0xc
FOLLOWUP_IP:
win32k!SetWakeBit+b7
bf80229d e90cf3ffff jmp win32k!SetWakeBit+0xb7 (bf8015ae)
SYMBOL_STACK_INDEX: 2
FOLLOWUP_NAME: MachineOwner
SYMBOL_NAME: win32k!SetWakeBit+b7
MODULE_NAME: win32k
IMAGE_NAME: win32k.sys
DEBUG_FLR_IMAGE_TIMESTAMP: 41127907
STACK_COMMAND: .trap fffffffff7f27a08 ; kb
FAILURE_BUCKET_ID: 0xA_win32k!SetWakeBit+b7
BUCKET_ID: 0xA_win32k!SetWakeBit+b7
Followup: MachineOwner
---------
그동안 우리의 주인공이었던 MyDrv.sys 가 콜스택에서 보이지 않습니다.
분석을 더 해야 할까요? 말아야 할까요?
보통 우리는 자신이 작성한 드라이버가 콜스택에서 보이지 않으면 분석을 바로 중단합니다.
하지만 자신의 제품 또는 드라이버가 동작한 후에 이런 덤프가 발생했다고 보고된다면 심도있는 분석을 해 볼 필요가 있습니다.
콜스택에 OS 모듈들만 보이는 것으로 보아 괴로운 분석이 될 것이라 예상되는군요. ^^
자... 일단 하라는 거 해야죠.
kd> .trap fffffffff7f27a08 ; kb
ErrCode = 00000000
eax=00ed0da8 ebx=00000009 ecx=00000008 edx=820ec808 esi=822c8980 edi=0000000a
eip=804eead8 esp=f7f27a7c ebp=f7f27a8c iopl=0 nv up ei pl nz na po nc
cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000 efl=00010206
nt!KiUnwaitThread+0x3a:
804eead8 80b80302000002 cmp byte ptr [eax+0x203],0x2 ds:0023:00ed0fab=??
*** Stack trace for last set context - .thread/.cxr resets it
ChildEBP RetAddr Args to Child
f7f27a8c 804eed19 00000002 00000000 0000000a nt!KiUnwaitThread+0x3a
f7f27aa4 bf80229d 81ece808 00000002 00000000 nt!KeSetEvent+0x44
f7f27ae4 bf801267 00000022 0073fff4 f7f27d44 win32k!SetWakeBit+0xb7
f7f27d44 bf801e46 f7f374e4 f7f27d64 0073fff4 win32k!RawInputThread+0x585
f7f27d54 804dc1dd 00000000 00000022 00000000 win32k!NtUserCallOneParam+0x20
f7f27d54 7ffe0304 00000000 00000022 00000000 nt!KiSystemService+0xc4
0073ffe0 75aa4faa 75aac27b 00000000 00000022 SharedUserData!SystemCallStub+0x4
0073ffe8 00000000 00000022 00000004 00000000 winsrv!NtUserCallOneParam+0xc
죽은 곳을 보면
nt!KiUnwaitThread+0x3a:
804eead8 80b80302000002 cmp byte ptr [eax+0x203],0x2 ds:0023:00ed0fab=??
이때 eax 가 다음과 같은 값이라 eax+203 = 00ed0fab 를 읽다가 죽은 겁니다.
이 주소가 존재하지 않는 엉뚱한 주소구요.
kd> r eax
Last set context:
eax=00ed0da8
KiUnwaitThread 함수 시작부터 보면
kd> u nt!KiUnwaitThread L20
nt!KiUnwaitThread:
804eea9e 55 push ebp
804eea9f 8bec mov ebp,esp
804eeaa1 51 push ecx
804eeaa2 53 push ebx
804eeaa3 56 push esi
804eeaa4 8955fc mov [ebp-0x4],edx
804eeaa7 8bf1 mov esi,ecx ; 3) esi = ecx
804eeaa9 e8d8010000 call nt!KiUnlinkThread (804eec86)
804eeaae 8a5e33 mov bl,[esi+0x33]
804eeab1 80fb10 cmp bl,0x10
804eeab4 8b4644 mov eax,[esi+0x44] ; 2) eax = [esi+0x44]
804eeab7 0f8d79130000 jnl nt!KiUnwaitThread+0xa6 (804efe36)
804eeabd 807e6e00 cmp byte ptr [esi+0x6e],0x0
804eeac1 7530 jnz nt!KiUnwaitThread+0x70 (804eeaf3)
804eeac3 80bebb01000000 cmp byte ptr [esi+0x1bb],0x0
804eeaca 7527 jnz nt!KiUnwaitThread+0x70 (804eeaf3)
804eeacc 8a566c mov dl,[esi+0x6c]
804eeacf 0fbeca movsx ecx,dl
804eead2 57 push edi
804eead3 8b7d08 mov edi,[ebp+0x8]
804eead6 03f9 add edi,ecx
804eead8 80b80302000002 cmp byte ptr [eax+0x203],0x2 ; 1) eax = 00ed0da8
804eeadf 8bcf mov ecx,edi
804eeae1 0f84d5190000 je nt!KiUnwaitThread+0x45 (804f04bc)
1) 죽은 곳이구요 그 위쪽 어디에서 eax 에 00ed0da8 을 채웠는지 찾아봐야 합니다.
2) 여기서 eax 를 채우는 코드가 보이므로 esi가 뭔지 알 필요가 있습니다.
kd> r esi
Last set context:
esi=822c8980
3) 여기서 esi 가 설정되는데 이것은 nt!KiUnwaitThread로 넘겨진 ecx가 됩니다.
nt!KiUnwaitThread은 FASTCALL 타입의 함수이므로 ecx는 첫번째 파라미터구요
nt!KiUnwaitThread의 첫번째 파라미터는 KTHREAD 포인터 입니다.
그래서 이 쓰레드를 살펴보면
kd> dt _KTHREAD 822c8980
+0x000 Header : _DISPATCHER_HEADER
+0x010 MutantListHead : _LIST_ENTRY [ 0x822c8990 - 0x822c8990 ]
+0x018 InitialStack : 0xf7f98000
+0x01c StackLimit : 0xf7f92000
+0x020 Teb : 0x7ffde000
+0x024 TlsArray : (null)
+0x028 KernelStack : 0xf7f97c20
+0x02c DebugActive : 0 ''
+0x02d State : 0x5 ''
+0x02e Alerted : [2] ""
+0x030 Iopl : 0 ''
+0x031 NpxState : 0xa ''
+0x032 Saturation : 0 ''
+0x033 Priority : 9 ''
+0x034 ApcState : _KAPC_STATE
+0x04c ContextSwitches : 0x820387be
+0x050 IdleSwapBlock : 0 ''
+0x051 Spare0 : [3] ""
+0x054 WaitStatus : 0
+0x058 WaitIrql : 0 ''
+0x059 WaitMode : 1 ''
+0x05a WaitNext : 0 ''
+0x05b WaitReason : 0xd ''
+0x05c WaitBlockList : 0x822c89f0
+0x060 WaitListEntry : _LIST_ENTRY [ 0x8215dbf8 - 0x820ec8d0 ]
+0x060 SwapListEntry : _SINGLE_LIST_ENTRY
+0x068 WaitTime : 0x45f99c
+0x06c BasePriority : 8 ''
+0x06d DecrementCount : 0x10 ''
+0x06e PriorityDecrement : 0 ''
+0x06f Quantum : -127 ''
+0x070 WaitBlock : [4] _KWAIT_BLOCK
+0x0d0 LegoData : (null)
+0x0d4 KernelApcDisable : 0
+0x0d8 UserAffinity : 1
+0x0dc SystemAffinityActive : 0 ''
+0x0dd PowerState : 0 ''
+0x0de NpxIrql : 0 ''
+0x0df InitialNode : 0 ''
+0x0e0 ServiceTable : 0x8054e500
+0x0e4 Queue : (null)
+0x0e8 ApcQueueLock : 0
+0x0f0 Timer : _KTIMER
+0x118 QueueListEntry : _LIST_ENTRY [ 0x0 - 0x0 ]
+0x120 SoftAffinity : 1
+0x124 Affinity : 1
+0x128 Preempted : 0 ''
+0x129 ProcessReadyQueue : 0 ''
+0x12a KernelStackResident : 0x1 ''
+0x12b NextProcessor : 0 ''
+0x12c CallbackStack : (null)
+0x130 Win32Thread : 0xe22acaa8
+0x134 TrapFrame : 0xf7f97d64
+0x138 ApcStatePointer : [2] 0x822c89b4
+0x140 PreviousMode : 1 ''
+0x141 EnableStackSwap : 0x1 ''
+0x142 LargeStack : 0x1 ''
+0x143 ResourceIndex : 0x1 ''
+0x144 KernelTime : 0xe
+0x148 UserTime : 0x12
+0x14c SavedApcState : _KAPC_STATE
+0x164 Alertable : 0 ''
+0x165 ApcStateIndex : 0 ''
+0x166 ApcQueueable : 0x1 ''
+0x167 AutoAlignment : 0 ''
+0x168 StackBase : 0xf7f98000
+0x16c SuspendApc : _KAPC
+0x19c SuspendSemaphore : _KSEMAPHORE
+0x1b0 ThreadListEntry : _LIST_ENTRY [ 0x821a05c0 - 0x81ed0df8 ]
+0x1b8 FreezeCount : 0 ''
+0x1b9 SuspendCount : 0 ''
+0x1ba IdealProcessor : 0 ''
+0x1bb DisableBoost : 0 ''
문제의 esi+44 즉, KTHREAD + 44 는
+0x034 ApcState : _KAPC_STATE
+0x04c ContextSwitches : 0x820387be
ApcState 와 ContextSwitches 사이의 영역이므로 ApcState 구조체의 영역입니다.
이것을 살펴보면
kd> dt _KAPC_STATE 822c8980+34
+0x000 ApcListHead : [2] _LIST_ENTRY [ 0x822c89b4 - 0x822c89b4 ]
+0x010 Process : 0x00ed0da8
+0x014 KernelApcInProgress : 0 ''
+0x015 KernelApcPending : 0 ''
+0x016 UserApcPending : 0 ''
에서 문제의 esi+44 는 esi+34+10 (822c8980+34+10) 이고 Process의 포인터라는 것을 알 수 있습니다.
즉, KTHREAD 구조체중의 ApcState의 Process 포인터에 0x00ed0da8 라는 엉뚱한 값이 들어가 있어서 죽은 겁니다.
822c8980 가 KTHREAD 포인터이므로 다음과 같이 !thread 로 확인해 보면
kd> !thread 822c8980
THREAD 822c8980 Cid 0644.0648 Teb: 7ffde000 Win32Thread: e22acaa8 WAIT: (WrUserRequest) UserMode Non-Alertable
00ece808 NotificationEvent
Not impersonating
Owning Process ed0da8 Image: <Unknown>
Context Switch Count -2113697858 LargeStack
UserTime 00:00:00.0180
KernelTime 00:00:00.0140
Start Address KERNEL32!BaseProcessStartThunk (0x77e413f2)
Win32 Start Address 0x0040e760
Stack Init f7f98000 Current f7f97c20 Base f7f98000 Limit f7f92000 Call 0
Priority 9 BasePriority 8 PriorityDecrement 0 DecrementCount 16
ChildEBP RetAddr Args to Child
f7f97c38 804ee05a 822c89f0 822c8980 804eec74 nt!KiSwapContext+0x2e (FPO: [EBP 0xf7f97c6c] [0,0,4])
f7f97c44 804eec74 000025ff e22acaa8 00000000 nt!KiSwapThread+0x44 (FPO: [0,0,2])
f7f97c6c bf8024a2 00000001 0000000d 00000001 nt!KeWaitForSingleObject+0x1c0 (FPO: [Non-Fpo])
f7f97ca8 bf80292c 000025ff 00000000 00000001 win32k!xxxSleepThread+0x189 (FPO: [Non-Fpo])
f7f97cec bf8028e1 f7f97d18 000025ff 00000000 win32k!xxxRealInternalGetMessage+0x40f (FPO: [Non-Fpo])
f7f97d4c 804dc1dd 00416f5c 00000000 00000000 win32k!NtUserGetMessage+0x27 (FPO: [Non-Fpo])
f7f97d4c 7ffe0304 00416f5c 00000000 00000000 nt!KiSystemService+0xc4 (FPO: [0,0] TrapFrame @ f7f97d64)
0012fec4 00000000 00000000 00000000 00000000 SharedUserData!SystemCallStub+0x4 (FPO: [0,0,0])
Process 정보를 다음과 같이 Image: <Unknown>
다른 정보들은 멀쩡한것 같은데 프로세스 포인터만 잘못되어 있는게 좀 특이하네요.
이 상태에서는 어떤 원인에 의해서 이 부분만 잘못 되었는지는 파악이 불가능합니다.
추정해 볼 수 있는 것이라고는 어떤 녀석이 아무렇게나 깨먹은게 재수없게 이 부분이었다라는 정도구요.
그래도 최소한 메모리를 깨뜨리는 문제가 있다는 것으로 결론을 낼 수가 있었습니다.
이런 분석도 하지 않는다면 소스에서 IRQL 다루는 부분만 열심히 쏘아보는 헛수고를 하고 있어야 겠지요. ^^
편집후기) 어떤 은둔고수는 유사한 케이스에서 깨뜨린 값 0x00ed0da8 4바이트의 형태를 가지고 메모리의 이곳 저곳을 비교해가면서 깨뜨리는 녀석을 찾아내는 경이로움을 보여주시는 분도 있었답니다.
http://www.driveronline.org/bbs/view.asp?tb=tipbbs&GotoPage=3&s_bulu=&s_key=&no=65
