오래간만에 덤프분석 하나 해 보겠습니다.
오늘은 BugCheck 0x7F 입니다.
사실 결론부터 말하자면 BugCheck 0x7F-8 는 Kernel Stack Overflow 입니다.
이 바닥에서 잔뼈가 굵으신 몇몇 분들은 이미 BugCheck Code 만 보고 이것을 짐작하시고 계실 겁니다. ^^
BugCheck 0x7F 이고 첫번째 인자가 8 인 경우 WinDbg Help 조차 kernel stack overflow 일 수 있다고 친절하게 설명하고 있습니다. 저희같이 하드웨어를 가지지 않는 필터 드라이버 종류를 주로 작성하는 경우 7F 덤프를 받으시면 kernel stack overflow 겠거니 하고 분석을 시작하시면 됩니다.
극소수의 경우 BugCheck 0x7F-8 이 하드웨어 오류인 경우를 나타내는데 저는 이런 것을 받아본 적이 한번도 없습니다. MS 같은 곳에서는 이런 가능성까지 신경쓰면서 분석을 해야 겠지요.
덤프 분석에서 BugCheck Code 가 중요한 이유가 바로 이것입니다. 문제의 방향을 미리 설정하고 분석을 시작할 수 있다는 것이죠.
자... 시작해 보겠습니다.
0: kd> !analyze -v
***************************************************************************
* *
* Bugcheck Analysis *
* *
***************************************************************************
UNEXPECTED_KERNEL_MODE_TRAP (7f)
This means a trap occurred in kernel mode, and it's a trap of a kind
that the kernel isn't allowed to have/catch (bound trap) or that
is always instant death (double fault). The first number in the
bugcheck params is the number of the trap (8 = double fault, etc)
Consult an Intel x86 family manual to learn more about what these
traps are. Here is a *portion* of those codes:
If kv shows a taskGate
use .tss on the part before the colon, then kv.
Else if kv shows a trapframe
use .trap on that value
Else
.trap on the appropriate frame will show where the trap was taken
(on x86, this will be the ebp that goes with the procedure KiTrap)
Endif
kb will then show the corrected stack.
Arguments:
Arg1: 00000008, EXCEPTION_DOUBLE_FAULT
Arg2: 80042000
Arg3: 00000000
Arg4: 00000000
Debugging Details:
------------------
BUGCHECK_STR: 0x7f_8
TSS: 00000028 -- (.tss 28)
eax=ebee4010 ebx=00000000 ecx=ebee4010 edx=00000000 esi=867818e8 edi=86781900
eip=80701ab8 esp=ebee4000 ebp=ebee401c iopl=0 nv up ei pl zr na pe nc
cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000 efl=00010246
hal!KeReleaseQueuedSpinLock+0x10:
80701ab8 53 push ebx
Resetting default scope
DEFAULT_BUCKET_ID: DRIVER_FAULT
PROCESS_NAME: MyApp.exe
LAST_CONTROL_TRANSFER: from 804de605 to 80701ab8
STACK_TEXT:
ebee3ffc 804de605 ebee42cc e1023cc8 00000000 hal!KeReleaseQueuedSpinLock+0x10
ebee401c f769b89b ebee429c ebee4040 f769d3a9 nt!ExReleaseResourceLite+0x8d
ebee4028 f769d3a9 ebee429c e1023cc8 00000000 Ntfs!NtfsReleaseFcb+0x4e
ebee4040 f769b497 ebee429c 00000000 ebee429c Ntfs!NtfsReleaseAllResources+0x62
ebee4058 f769b6e6 ebee429c 00000001 e1023cc8 Ntfs!NtfsCleanupIrpContext+0x23
ebee4070 f76c0cd3 ebee429c 858b2420 00000000 Ntfs!NtfsCompleteRequest+0x35
ebee4280 f76c0d83 ebee429c 858b2420 86739488 Ntfs!NtfsCommonCleanup+0x2601
ebee43f8 804e33d9 8677b020 858b2420 86717270 Ntfs!NtfsFsdCleanup+0xcf
ebee4408 f7743bbf 85d89160 858b2430 ebee4444 nt!IopfCallDriver+0x31
ebee4418 804e33d9 867393d0 858b2420 8609a6f0 sr!SrCleanup+0xb3
ebee4428 ec631f92 85d89160 00000000 8644bf20 nt!IopfCallDriver+0x31
WARNING: Stack unwind information not available. Following frames may be wrong.
ebee4444 ec62de51 8644be68 858b2420 00000000 AhnFlt2K+0x4f92
ebee445c 804e33d9 8644be68 858b2420 858b2420 AhnFlt2K+0xe51
ebee446c 8057e627 85d89148 867e7e70 00000001 nt!IopfCallDriver+0x31
ebee449c 80570943 858b2978 8644be68 00120089 nt!IopCloseFile+0x26b
ebee44cc 80570a96 858b2978 01d89148 867e7e70 nt!ObpDecrementHandleCount+0x11b
ebee44f4 805709bc e26299e0 85d89160 000000c8 nt!ObpCloseHandleTableEntry+0x14d
ebee453c 80570a06 000000c8 00000000 00000000 nt!ObpCloseHandle+0x87
ebee4550 804df99f 000000c8 ebee4de8 804e5487 nt!NtClose+0x1d
ebee4550 804e5487 000000c8 ebee4de8 804e5487 nt!KiFastCallEntry+0xfc
ebee45cc f7d86552 000000c8 00000160 00000000 nt!ZwClose+0x11
ebee4de8 f7d8661d f7d865b0 00000000 00000000 MyDrv!OpenClose+0xc2 [e:\test\mydrv\mydrv.c @ 264]
ebee5d9c f7d86648 00000000 00000000 00000000 MyDrv!UseStack2+0x1d [e:\test\mydrv\mydrv.c @ 286]
ebee6d4c f7d86678 00000000 00000000 00000000 MyDrv!UseStack1+0x18 [e:\test\mydrv\mydrv.c @ 293]
ebee7cfc f7d871c2 0000004c 00000000 ebee7d1c MyDrv!BugCheck7F+0x18 [e:\test\mydrv\mydrv.c @ 300]
ebee8c40 804e33d9 85ad7030 866af7d8 80701410 MyDrv!MyDrvDeviceControl+0x312 [e:\test\mydrv\mydrv.c @ 460]
ebee8c50 8057150b 866af848 86409b88 866af7d8 nt!IopfCallDriver+0x31
ebee8c64 80582fb1 85ad7030 866af7d8 86409b88 nt!IopSynchronousServiceTail+0x60
ebee8d00 8058909e 000000d4 00000000 00000000 nt!IopXxxControlFile+0x5ef
ebee8d34 804df99f 000000d4 00000000 00000000 nt!NtDeviceIoControlFile+0x2a
ebee8d34 7c93eb94 000000d4 00000000 00000000 nt!KiFastCallEntry+0xfc
0012f898 00000000 00000000 00000000 00000000 0x7c93eb94
STACK_COMMAND: .tss 0x28 ; kb
FOLLOWUP_IP:
AhnFlt2K+4f92
ec631f92 e99e010000 jmp AhnFlt2K+0x5135 (ec632135)
SYMBOL_STACK_INDEX: b
SYMBOL_NAME: AhnFlt2K+4f92
FOLLOWUP_NAME: MachineOwner
MODULE_NAME: AhnFlt2K
IMAGE_NAME: AhnFlt2K.sys
DEBUG_FLR_IMAGE_TIMESTAMP: 451abe53
FAILURE_BUCKET_ID: 0x7f_8_AhnFlt2K+4f92
BUCKET_ID: 0x7f_8_AhnFlt2K+4f92
Followup: MachineOwner
---------
메시지를 읽어보면 KERNEL MODE TRAP 인데 뭐 여러가지 가능성이 있다고 설명합니다.
어떤 상황이면 어떻게 해보라고 알려주기도 하는데 그 아래에서 WinDbg 가 알아서 분석한 정보들을 보여주고 우리가 어떻게 해야 할지도 보여줍니다.
첫번째 인자 8 에 대해서는 EXCEPTION_DOUBLE_FAULT 라고 알려주네요.
메시지 중간에 보여주는 다음 라인이 우리가 처음에 해야할 일입니다.
TSS: 00000028 -- (.tss 28)
STACK_COMMAND: .tss 0x28 ; kb
!analyze 에서 보여준 콜스택과 정보는 WinDbg 가 이것을 적용한 결과를 출력해 주는 것입니다.
현재 상태를 확인해 보시면 아직 위에서 보이는 콜스택과 같은 상태가 아님을 알 수 있습니다.
0: kd> kv
ChildEBP RetAddr Args to Child
00000000 80701ab8 00000000 00000000 00000000 nt!KiTrap08+0x48 (FPO: TSS 28:0)
ebee3ffc 804de605 ebee42cc e1023cc8 00000000 hal!KeReleaseQueuedSpinLock+0x10 (FPO: [0,0,0])
ebee401c f769b89b ebee429c ebee4040 f769d3a9 nt!ExReleaseResourceLite+0x8d (FPO: [Non-Fpo])
ebee4028 f769d3a9 ebee429c e1023cc8 00000000 Ntfs!NtfsReleaseFcb+0x4e (FPO: [Non-Fpo])
...
이제 메시지에서 하라는대로 해야죠? ^^ 두 메시지는 결국 .tss 0x28 을 하라는 뜻입니다.
바로 위에서 보이는 nt!KiTrap08+0x48 (FPO: TSS 28:0) 를 봤을 때도 이것을 알아채는 센스가 있어야 합니다. ^^
0: kd> .tss 0x28
eax=ebee4010 ebx=00000000 ecx=ebee4010 edx=00000000 esi=867818e8 edi=86781900
eip=80701ab8 esp=ebee4000 ebp=ebee401c iopl=0 nv up ei pl zr na pe nc
cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000 efl=00010246
hal!KeReleaseQueuedSpinLock+0x10:
80701ab8 53 push ebx
레지스터값들이 죽었을 때 상황으로 돌아갔네요.
0: kd> kv
*** Stack trace for last set context - .thread/.cxr resets it
ChildEBP RetAddr Args to Child
ebee3ffc 804de605 ebee42cc e1023cc8 00000000 hal!KeReleaseQueuedSpinLock+0x10 (FPO: [0,0,0])
ebee401c f769b89b ebee429c ebee4040 f769d3a9 nt!ExReleaseResourceLite+0x8d (FPO: [Non-Fpo])
ebee4028 f769d3a9 ebee429c e1023cc8 00000000 Ntfs!NtfsReleaseFcb+0x4e (FPO: [Non-Fpo])
...
위에서 보였던 KiTrap08 이 사라졌습니다.
자... 이제 완전하게 죽었을 때 상황으로 돌아온 것입니다.
.tss 를 하는 이유는 인텔 CPU 구조에 있는 TSS(Task State Segment) 에 죽었을 때의 상황이 저장되어 있기 때문입니다. 이것은 Kernel stack overflow 와 double fault 라는 특성때문에 그런건데요.
Kernel stack overflow 가 발생하면 일단 fault 가 한번 발생합니다. 보통 fault 가 발생하면 스택에 exception record 를 기록하려고 하는데 이 경우는 이미 스택을 사용할 수 없는 상황이므로 exception record 를 기록하려다가 다시 한번 fault 가 발생합니다. 이렇게 해서 double fault 가 되고 이와 같이 스택에 exception record 를 저장할 수 없는 상황에 이 정보가 TSS 에 저장되기 때문에 .tss 를 사용해서 이것을 추출하는 것입니다.
정말 kernel stack overflow 인지 확인해 볼까요?
위에서 마지막에 보이는 ChildEBP 는 ebee3ffc 입니다. 이것이 현재 쓰레드의 커널 스택 영역과 어떤 관계가 있는지 보면 됩니다.
0: kd> !thread
THREAD 85a604d8 Cid 0c1c.0c20 Teb: 7ffdf000 Win32Thread: e27122d0 RUNNING on processor 0
...
Context Switch Count 1044 LargeStack
...
Stack Init ebee9000 Current ebee405c Base ebee9000 Limit ebee4000 Call 0
Stack Base 는 ebee9000 이고 Limit 는 ebee4000 입니다.
일단 ebee3ffc 는 Limit 인 ebee4000 보다 아래에 있는 주소이므로 스택 경계를 넘어간 overflow 가 맞습니다.
재미있는 것은 보통 커널 스택은 12KB 인 것으로 알고 있는데 여기서는 LargeStack 이라고 표시되어 있고 20KB 를 사용하고 있습니다. 어떤 경우에 LargeStack 이 사용되는 것인지는 잘 모르겠네요.
현장검증은 이정도로 하고 이제 범인을 잡으러가야 겠네요. ^^
!analyze 가 해준 초동수사에서 유력한 용의자는 다음과 같이 AhnFlt2K 로 지목되었습니다.
MODULE_NAME: AhnFlt2K
IMAGE_NAME: AhnFlt2K.sys
대부분의 경우 !analyze 의 날카로운 추리력에 의해 범인이 바로 지목되는데요.
이번 경우는 좀 다릅니다.
현장을 마지막으로 방문했었던 AhnFlt2K 를 범인으로 지목하기에는 좀 성급한 면이 있다는 거죠.
이번 문제가 Kernel stack overflow 로 밝혀진 이상 stack 을 많이 사용하는 녀석을 찾아야 진짜 범인을 찾는다는 겁니다. 위 콜스택에서 봤을 때 커널을 제외하고 추가로 용의선상에 올려놓을 수 있는 녀석들은 Ntfs, sr, MyDrv 입니다. 가만 보니 현장을 마지막으로 방문했었던 녀석들은 Ntfs, sr 인데 자기네 편이라고 용의선상에서 제외시켰군여. 나쁜넘들...
실제로 스택 사용량을 검토하는 방법은 위 콜스택에서 맨 왼쪽에 나오는 ChildEBP 의 변화량을 모듈별로 보는 것입니다. 일일이 손으로 계산해도 상관없으나 kf 명령어를 사용하면 노가다가 필요없습니다. 콜스택이 다소 길어서 최대한 보여주라고 인자로 100 을 줬습니다.
0: kd> kf 100
Memory ChildEBP RetAddr
ebee3ffc 804de605 hal!KeReleaseQueuedSpinLock+0x10
20 ebee401c f769b89b nt!ExReleaseResourceLite+0x8d
c ebee4028 f769d3a9 Ntfs!NtfsReleaseFcb+0x4e
18 ebee4040 f769b497 Ntfs!NtfsReleaseAllResources+0x62
18 ebee4058 f769b6e6 Ntfs!NtfsCleanupIrpContext+0x23
18 ebee4070 f76c0cd3 Ntfs!NtfsCompleteRequest+0x35
210 ebee4280 f76c0d83 Ntfs!NtfsCommonCleanup+0x2601
178 ebee43f8 804e33d9 Ntfs!NtfsFsdCleanup+0xcf
10 ebee4408 f7743bbf nt!IopfCallDriver+0x31
10 ebee4418 804e33d9 sr!SrCleanup+0xb3
10 ebee4428 ec631f92 nt!IopfCallDriver+0x31
WARNING: Stack unwind information not available. Following frames may be wrong.
1c ebee4444 ec62de51 AhnFlt2K+0x4f92
18 ebee445c 804e33d9 AhnFlt2K+0xe51
10 ebee446c 8057e627 nt!IopfCallDriver+0x31
30 ebee449c 80570943 nt!IopCloseFile+0x26b
30 ebee44cc 80570a96 nt!ObpDecrementHandleCount+0x11b
28 ebee44f4 805709bc nt!ObpCloseHandleTableEntry+0x14d
48 ebee453c 80570a06 nt!ObpCloseHandle+0x87
14 ebee4550 804df99f nt!NtClose+0x1d
0 ebee4550 804e5487 nt!KiFastCallEntry+0xfc
7c ebee45cc f7d86552 nt!ZwClose+0x11
81c ebee4de8 f7d8661d MyDrv!OpenClose+0xc2 [e:\test\mydrv\mydrv.c @ 264]
fb4 ebee5d9c f7d86648 MyDrv!UseStack2+0x1d [e:\test\mydrv\mydrv.c @ 286]
fb0 ebee6d4c f7d86678 MyDrv!UseStack1+0x18 [e:\test\mydrv\mydrv.c @ 293]
fb0 ebee7cfc f7d871c2 MyDrv!BugCheck7F+0x18 [e:\test\mydrv\mydrv.c @ 300]
f44 ebee8c40 804e33d9 MyDrv!MyDrvDeviceControl+0x312 [e:\test\mydrv\mydrv.c @ 460]
10 ebee8c50 8057150b nt!IopfCallDriver+0x31
14 ebee8c64 80582fb1 nt!IopSynchronousServiceTail+0x60
9c ebee8d00 8058909e nt!IopXxxControlFile+0x5ef
34 ebee8d34 804df99f nt!NtDeviceIoControlFile+0x2a
0 ebee8d34 7c93eb94 nt!KiFastCallEntry+0xfc
맨 왼쪽에 보이는 숫자들이 각 함수가 소진한 스택의 량입니다.
한 눈에 보면 MyDrv 가 문제가 있는 녀석이라고 느껴집니다.
사용한 양을 계산해 보면
0: kd> ? 81c + fb4 + fb0 + fb0 + f44
Evaluate expression: 18036 = 00004674
우와~~~ 자그마치 18KB 를 사용하고 있습니다.
도대체 뭘 하느라고 스택을 저렇게 사용할까요? 함수 이름도 범상치 않군여... 한번 봅시다.
void UseStack1(void)
{
char szBuf[4000];
UseStack2();
아... 네... 지역변수를 4000 바이트 사용했네요. 이런일 없어야 겠습니다.
이 녀석이야 예제라지만 이름이 UseStack 도 아니면서 저렇게 사용하는 경우.... 실제 상황에서 종종 봤습니다. -_-;;;
4000 바이트 까지야 없겠지만 100 바이트 이상은 많았습니다. 하나의 함수가 사용하는 지역변수 크기의 합이 100 바이트 넘어가면 문제 있다고 보셔야 합니다.
그런 관점에서 Ntfs 저 녀석도 범인으로 봐야 합니다. 스택 사용량이 가장 큰 함수 두개만 더해봐도
0: kd> ? 210 + 178
Evaluate expression: 904 = 00000388
거의 1KB 가까이 사용하고 있습니다. 치사하게 커널 스택을 아껴쓰라고 주장하는 MS 에서는 스택을 마음대로 사용하고 자기들은 OS 의 일부라고 우깁니다. 뭐... 힘이 없으니 어쩔 수 없구요. ^^
여하튼 범인은 MyDrv 로 밝혀 졌습니다. MyDrv 의 함수들이 스택을 아껴쓰도록 수정하면 문제가 해결될 것입니다.
만약 파일시스템 필터 드라이버를 작성하신다면 스택사용량에 더욱 각별히 신경쓰셔야 할 겁니다.
Kernel stack overflow 는 파일 필터 분야에서 늘 있어왔던 문제이고 필터들이 워낙 많기 때문에 우리 드라이버가 사용할 공간이 늘 협소하다고 가정해야 합니다.
함수 하나당 100 바이트 이하... 너무 엄격한 기준은 아니겠지요? ^^
http://www.driveronline.org/bbs/view.asp?tb=tipbbs&GotoPage=4&s_bulu=&s_key=&no=47
