드라이버를 개발할 때 Verifier 를 사용하면 매우 유용합니다.
사소 한 버그부터 심각한 오류까지 확실하게 체크해 주기 때문입니다.
Verifier가 오류를 발견했을 때 발생시키는 Bugcheck 중 오늘은 0xD6에 대 해서
살펴보도록 하겠습니다.
*** Fatal System Error: 0x000000d6
(0x82C5D000,0x00000000,0xF48BE08D,0x00000000)
Driver at fault:
*** MyDrv.sys - Address F48BE08D base at F48BA000, DateStamp 4507c937
.
Break instruction exception - code 80000003 (first chance)
A fatal system error has occurred.
Debugger entered on first try; Bugcheck callbacks have not been invoked.
A fatal system error has occurred.
Connected to Windows XP 2600 x86 compatible target, ptr64 FALSE
Loading Kernel Symbols
...........................................................................................................................
Loading User Symbols
.............................
Loading unloaded module list
....................
****************************************************************************
* *
* Bugcheck Analysis *
* *
****************************************************************************
Use !analyze -v to get detailed debugging information.
BugCheck D6, {82c5d000, 0, f48be08d, 0}
Probably caused by : MyDrv.sys ( MyDrv+408d )
Followup: MachineOwner
---------
nt!RtlpBreakWithStatusInstruction:
804e5592 cc int 3
기본적인 내용들이 보이지만 역시 하라는 대로 !analyze -v 먼저 해 봅 니다.
kd> !analyze -v
****************************************************************************
* *
* Bugcheck Analysis *
* *
****************************************************************************
DRIVER_PAGE_FAULT_BEYOND_END_OF_ALLOCATION (d6)
N bytes of memory was allocated and more than N bytes are being referenced.
This cannot be protected by try-except.
When possible, the guilty driver's name (Unicode string) is printed on
the bugcheck screen and saved in KiBugCheckDriver.
Arguments:
Arg1: 82c5d000, memory referenced
Arg2: 00000000, value 0 = read operation, 1 = write operation
Arg3: f48be08d, if non-zero, the address which referenced memory.
Arg4: 00000000, (reserved)
Debugging Details:
------------------
READ_ADDRESS: 82c5d000 Special pool
FAULTING_IP:
MyDrv!my_strlen+d [d:\mytest\mydrv\my_str.c @ 67]
f48be08d 0fbe11 movsx edx,byte ptr [ecx]
MM_INTERNAL_CODE: 0
IMAGE_NAME: MyDrv.sys
DEBUG_FLR_IMAGE_TIMESTAMP: 4507c937
MODULE_NAME: MyDrv
FAULTING_MODULE: f48ba000 MyDrv
DEFAULT_BUCKET_ID: DRIVER_FAULT
BUGCHECK_STR: 0xD6
PROCESS_NAME: explorer.exe
TRAP_FRAME: f490977c -- (.trap fffffffff490977c)
ErrCode = 00000000
eax=82c5d000 ebx=81b85c00 ecx=82c5d000 edx=ffffff83 esi=81bd5e30 edi=81bdbd38
eip=f48be08d esp=f49097f0 ebp=f49097f4 iopl=0 nv up ei ng nz na po nc
cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000 efl=00010282
MyDrv!my_strlen+0xd:
f48be08d 0fbe11 movsx edx,byte ptr [ecx] ds:0023:82c5d000=??
Resetting default scope
LAST_CONTROL_TRANSFER: from 8053425b to 804e5592
STACK_TEXT:
f49092cc 8053425b 00000003 82c5d000 00000000 nt!RtlpBreakWithStatusInstruction
f4909318 80534d2e 00000003 806f0298 c020b174 nt!KiBugCheckDebugBreak+0x19
f49096f8 8053531e 00000050 82c5d000 00000000 nt!KeBugCheck2+0x574
f4909718 80525f44 00000050 82c5d000 00000000 nt!KeBugCheckEx+0x1b
f4909764 804e3718 00000000 82c5d000 00000000 nt!MmAccessFault+0x6f5
f4909764 f48be08d 00000000 82c5d000 00000000 nt!KiTrap0E+0xcc
f49097f4 f48bce5f 82c5cfe0 f490980c 81bd1740 MyDrv!my_strlen+0xd [d:\mytest\mydrv\my_str.c @ 67]
f4909814 f48bcfa5 82c5cfe0 82c5cf00 f4909890 MyDrv!IsMyFilePath1+0xf [d:\mytest\mydrv\my_path.c @ 949]
f490982c f48bd01d 82c5cfe0 00000000 f4909890 MyDrv!IsMyFilePath+0x15 [d:\mytest\mydrv\my_path.c @ 990]
f490984c f48bb10f 81bd1710 81bd1700 f4909890 MyDrv!CompFilePath+0x4d [d:\mytest\mydrv\my_path.c @ 1013]
f4909864 f46eb2ce 81bd1710 81bd1700 f4909890 MyDrv!MyDrv_CompFilePath+0x2f [d:\mytest\mydrv\my_exp.c @ 142]
...
STACK_COMMAND: kb
FOLLOWUP_IP:
MyDrv!my_strlen+d [d:\mytest\mydrv\my_str.c @ 67]
f48be08d 0fbe11 movsx edx,byte ptr [ecx]
FAULTING_SOURCE_CODE:
63: size_t my_strlen(LPCSTR str)
64: {
65: const char *eos = str;
66:
> 67: while( *eos++ ) ;
68:
69: return( (int)(eos - str - 1) );
70: }
71:
SYMBOL_STACK_INDEX: 6
FOLLOWUP_NAME: MachineOwner
SYMBOL_NAME: MyDrv!my_strlen+d
FAILURE_BUCKET_ID: 0xD6_VRF_MyDrv!my_strlen+d
BUCKET_ID: 0xD6_VRF_MyDrv!my_strlen+d
Followup: MachineOwner
---------
역시 설명을 가만히 읽어보시기 바랍니다.
N 바이트 할당된 메모리인 데 N 바이트 보다 많이 읽으려고 시도했다는 내용입니다.
Verifier 에서 Special Memory Pool 옵션을 켜면 이런 상황을 잡아줍니다.
Verifier 의 도움없이 이런 버그를 잡는 일은 생각만 해도 끔찍합니다. ^^
메시지에서 하라는 대로 KiBugCheckDriver 변수의 내용을 살펴봅니다.
kd> db KiBugCheckDriver
8055be00 1c d2 d0 81 00 00 00 00-00 00 00 00 00 00 00 00 ................
8055be10 00 00 00 00 00 00 00 00-00 00 00 00 00 00 00 00 ................
이런... 포인터군요.
kd> dd KiBugCheckDriver
8055be00 81d0d21c 00000000 00000000 00000000
8055be10 00000000 00000000 00000000 00000000
kd> db 81d0d21c
81d0d21c 14 00 14 00 3c d2 d0 81-00 40 10 0b 01 00 04 00 ....<....@......
81d0d22c ff ff ff ff bf e5 01 00-fe ff ff ff 00 00 00 00 ................
81d0d23c 4d 00 79 00 44 00 72 00-76 00 2e 00 73 00 79 00 M.y.D.r.v...s.y.
81d0d24c 73 00 00 00 00 00 00 00-5c 00 57 00 0e 00 1f 0a s.......\.W.....
메모리의 내용을 보아하니 UNICODE_STRING 구조체인 것 같습니다.
dt 명령어로 구조체 내용을 확인해 봅니다.
kd> dt _UNICODE_STRING 81d0d21c
"MyDrv.sys"
+0x000 Length : 0x14
+0x002 MaximumLength : 0x14
+0x004 Buffer : 0x81d0d23c "MyDrv.sys"
문제의 드라이버 이름이 잘 보이고 있네요.
사실 !analyze -v 메시지 에 MyDrv.sys 라는 이름이 수도 없이 나오기 때문에 구지
이렇게 보지 않아도 됩니다만 그래도 WinDbg가 하라는 것은 한번 해보는 것이 좋습니다.
메시지 중간에 TRAP_FRAME: f490977c -- (.trap fffffffff490977c) 가 있었으므로
이것도 역시 실행해 줍니다.
kd> .trap fffffffff490977c
ErrCode = 00000000
eax=82c5d000 ebx=81b85c00 ecx=82c5d000 edx=ffffff83 esi=81bd5e30 edi=81bdbd38
eip=f48be08d esp=f49097f0 ebp=f49097f4 iopl=0 nv up ei ng nz na po nc
cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000 efl=00010282
MyDrv!my_strlen+0xd:
f48be08d 0fbe11 movsx edx,byte ptr [ecx] ds:0023:82c5d000=??
kv 명령으로 확인해 보면 위에 보였던 콜스택에서 변화가 생겼음을 확인 할 수 있습니다.
kd> kv
*** Stack trace for last set context - .thread/.cxr resets it
ChildEBP RetAddr Args to Child
f49097f4 f48bce5f 82c5cfe0 f490980c 81bd1740 MyDrv!my_strlen+0xd
f4909814 f48bcfa5 82c5cfe0 82c5cf00 f4909890 MyDrv!IsMyFilePath1+0xf ...
f490982c f48bd01d 82c5cfe0 00000000 f4909890 MyDrv!IsMyFilePath+0x15 ...
f490984c f48bb10f 81bd1710 81bd1700 f4909890 MyDrv!CompFilePath+0x4d ...
f4909864 f46eb2ce 81bd1710 81bd1700 f4909890 MyDrv!MyDrv_CompFilePath+0x2f ...
...
이번에도 kn 으로 콜스택을 살펴보고 하나씩 따라 올라가면서 문제를 살 펴봅니다.
kd> kn
*** Stack trace for last set context - .thread/.cxr resets it
# ChildEBP RetAddr
00 f49097f4 f48bce5f MyDrv!my_strlen+0xd [d:\mytest\mydrv\my_str.c @ 67]
01 f4909814 f48bcfa5 MyDrv!IsMyFilePath1+0xf [d:\mytest\mydrv\my_path.c @ 949]
02 f490982c f48bd01d MyDrv!IsMyFilePath+0x15 [d:\mytest\mydrv\my_path.c @ 990]
03 f490984c f48bb10f MyDrv!CompFilePath+0x4d [d:\mytest\mydrv\my_path.c @ 1013]
04 f4909864 f46eb2ce MyDrv!MyDrv_CompFilePath+0x2f [d:\mytest\mydrv\my_exp.c @ 142]
...
스택 프레임 00 에서 문제가 발생한 것으로 보입니다.
바로 지역변수 를 확인해 봅니다.
kd> dv
str = 0x82c5cfe0 "\Device\HarddiskVolume1\???"
eos = 0x82c5d000 ""
eos 가 문제가 발생했다는 주소와 일치합니다.
Arguments:
Arg1: 82c5d000, memory referenced
Arg2: 00000000, value 0 = read operation, 1 = write operation
이 주소를 읽다가 죽었다는 의미입니다.
위 메시지에 나와있는 소스 코드를 보면 str 로부터 시작해서 eos까지 읽다가 죽은 것으로 보입니다.
str부터 eos까지 어떤 내용이 들어있는지 봅니다.
kd> db 0x82c5cfe0
82c5cfe0 5c 44 65 76 69 63 65 5c-48 61 72 64 64 69 73 6b \Device\Harddisk
82c5cff0 56 6f 6c 75 6d 65 31 5c-c3 c3 c3 c3 c3 c3 c3 c3 Volume1\........
82c5d000 ?? ?? ?? ?? ?? ?? ?? ??-?? ?? ?? ?? ?? ?? ?? ?? ????????????????
82c5d010 ?? ?? ?? ?? ?? ?? ?? ??-?? ?? ?? ?? ?? ?? ?? ?? ????????????????
문자열인데 NULL 로 끝나지 않는 것이 문제라는 것을 한눈에 알 수 있습 니다.
소스코드의 while( *eos++ )은 NULL 을 만나야 끝나는데 NULL 이 없으니 계속
진행하다가 ?? 에서 죽은 겁니다.
왜 NULL 로 끝나지 않은 문자열이 전달된 것인지 콜스택을 따라가며 알 아 봅니다.
kd> .frame 1
01 f4909814 f48bcfa5 MyDrv!IsMyFilePath1+0xf [d:\mytest\mydrv\my_path.c @ 949]
kd> dv
pszPath = 0x82c5cfe0 "\Device\HarddiskVolume1\???"
상위에서 전달받은 변수네요.
kd> .frame 2
02 f490982c f48bd01d MyDrv!IsMyFilePath+0x15 [d:\mytest\mydrv\my_path.c @ 990]
kd> dv
pszPath = 0x82c5cfe0 "\Device\HarddiskVolume1\???"
역시 상위에서 전달받은 변수군요.
kd> .frame 3
03 f490984c f48bb10f MyDrv!CompFilePath+0x4d [d:\mytest\mydrv\my_path.c @ 1013]
kd> dv
pszPath = 0x81bd1710 "\Device\HarddiskVolume1\"
nPathLen = 0x18
pszPathA = 0x82c5cfe0 "\Device\HarddiskVolume1\???"
여기에서 만들어져서 전달한 변수인 것 같습니다.
사실 이 내용은 kv 명령의 콜스택만 가만히 봐도 파악할 수 있는 사항입니다.
kd> kv
*** Stack trace for last set context - .thread/.cxr resets it
ChildEBP RetAddr Args to Child
f49097f4 f48bce5f 82c5cfe0 f490980c 81bd1740 MyDrv!my_strlen+0xd
f4909814 f48bcfa5 82c5cfe0 82c5cf00 f4909890 MyDrv!IsMyFilePath1+0xf
f490982c f48bd01d 82c5cfe0 00000000 f4909890 MyDrv!IsMyFilePath+0x15
f490984c f48bb10f 81bd1710 81bd1700 f4909890 MyDrv!CompFilePath+0x4d
f4909864 f46eb2ce 81bd1710 81bd1700 f4909890 MyDrv!MyDrv_CompFilePath+0x2f
각라인에서 세번째 보이는 값들이 첫번째 인자이므로 82c5cfe0 는 계속 첫번째 인자로
전달되었음을 알 수 있습니다. 이것을 시작한 녀석이 CompFilePath 라는 것도
보입니다. 이 함수의 내용을 보면
BOOL CompFilePath(IN LPCTSTR pszPath)
{
UINT nPathLen;
LPSTR pszPathA;
...
nPathLen = my_strlen(pszPath);
pszPathA = (LPSTR)my_malloc(nPathLen+4);
if (pszPathA)
{
UnicodeToAnsi(pszPath, pszPathA, nPathLen);
bRet = IsMyFilePath(pszPathA);
}
...
}
이 함수는 전달받았던 pszPath를 pazPathA 로 변환한 후에 하위함수들로 전달합니다.
두개의 내용을 비교해 봅니다.
kd> db 0x81bd1710
81bd1710 5c 00 44 00 65 00 76 00-69 00 63 00 65 00 5c 00 \.D.e.v.i.c.e.\.
81bd1720 48 00 61 00 72 00 64 00-64 00 69 00 73 00 6b 00 H.a.r.d.d.i.s.k.
81bd1730 56 00 6f 00 6c 00 75 00-6d 00 65 00 31 00 5c 00 V.o.l.u.m.e.1.\.
81bd1740 00 00 00 00 43 15 01 00-00 d4 01 00 71 10 01 00 ....C.......q...
kd> db 0x82c5cfe0
82c5cfe0 5c 44 65 76 69 63 65 5c-48 61 72 64 64 69 73 6b \Device\Harddisk
82c5cff0 56 6f 6c 75 6d 65 31 5c-c3 c3 c3 c3 c3 c3 c3 c3 Volume1\........
82c5d000 ?? ?? ?? ?? ?? ?? ?? ??-?? ?? ?? ?? ?? ?? ?? ?? ????????????????
82c5d010 ?? ?? ?? ?? ?? ?? ?? ??-?? ?? ?? ?? ?? ?? ?? ?? ????????????????
유니코드 문자열 일때는 NULL로 끝나는 것이 보이는데 ANSI 로 변환한 후에는 NULL
이 보이지 않습니다. 이렇게 되면 소스코드에서 보이는 변 환함수인 UnicodeToAnsi()
가 문제의 주범이라는 사실이 밝혀집니다. 왜 변환하면서 NULL을 붙이지 않는지
확인해 보면 이 덤프의 원인이 나오 게 됩니다.
덤프는 이렇게 분석이 끝났지만 위에서 보이는 문제의 메모리에서 c3 과 ?? 라는
내용에 대해서 조금 더 이해하고 있으면 좋을 것 같습니다.
!pool 명령으로 메모리를 살펴봅니다.
kd> !pool 82c5cfe0
Pool page 82c5cfe0 region is Special pool
*82c5cfe0 size: 1c pagable special pool, Tag is MDRV
Owning component : Unknown (update pooltag.txt)
Special pool 영역이라고 나옵니다.
Verifier 에서 Special Memory Pool 옵션을 켜야 BugCheck 0xD6가 발생한다고
이미 위에서 언급했습니 다. 이 Special Pool 이란 메모리 할당, 해제, 사용에
대한 버그를 잡기 위해서 특별히 사용되는 메모리 영역을 의미합니다.
Special Pool 은 메모리를 하나 할당할 때마다 최소 2 Page(4KB)를 사용 합니다.
첫번째 Page는 사용자가 사용하는 영역이고 두번째 Page는 Guard Page 입니다.
Invalid 한 메모리 영역을 지정해 놓고 만약 이곳 을 접근하게 되면 Fault 가
발생하도록 설정해 놓은 것입니다. 이것이 바로 ?? 로 나오는 부분의 의미입니다.
이번 예제도 NULL을 못찾은 코드가 계속 진행하여 이 Guard Page 에 접 근하면서
문제가 발견된 것입니다.
Speical Pool 은 사용자가 1c 만큼만 할당해도 실제로는 8KB 의 메모리 가 할당될
만큼 메모리 낭비가 심하기 때문에 Special Pool 로 예약된 영역을 모두 소진하면
Special Pool 에서 할당하지 않고 일반 메모리에 서 할당합니다. 물론 Special
Pool 이 여유가 생기면 다시 Special Pool 할당이 운영됩니다. 따라서 Special
Pool 이 항상 모든 문제를 체크할 수는 없다는 점도 참고하시기 바랍니다.
위에서 설명한 Special Pool 의 구조를 확인해 봅니다.
문제의 메모 리를 조금 당겨서 확인해 보면
kd> db 82c5cfe0 - 10
82c5cfd0 c3 c3 c3 c3 c3 c3 c3 c3-c3 c3 c3 c3 c3 c3 c3 c3 ................
82c5cfe0 5c 44 65 76 69 63 65 5c-48 61 72 64 64 69 73 6b \Device\Harddisk
82c5cff0 56 6f 6c 75 6d 65 31 5c-c3 c3 c3 c3 c3 c3 c3 c3 Volume1\........
82c5c000 ?? ?? ?? ?? ?? ?? ?? ??-?? ?? ?? ?? ?? ?? ?? ?? ????????????????
c3 으로 채워져 있고 Guard Page 가 나오기 전에 우리가 사용한 내용이 저장되어
있습니다. Guard Page 직전의 영역을 사용자에게 할당해서 Guard Page 가 효과를
보기 쉽도록 구성되어 있습니다. 사용자는 항상 첫번째 Page의 뒷부분을 기준으로
할당 받습니다.
이 메모리의 헤더는 첫 페이지의 맨 앞부분입니다.
kd> db 82c5c000
82c5c000 1c c0 c3 00 4d 44 53 56-00 00 00 00 08 4f f1 81 ....MDRV.....O..
82c5c010 c3 c3 c3 c3 c3 c3 c3 c3-c3 c3 c3 c3 c3 c3 c3 c3 ................
82c5c020 c3 c3 c3 c3 c3 c3 c3 c3-c3 c3 c3 c3 c3 c3 c3 c3 ................
82c5c030 c3 c3 c3 c3 c3 c3 c3 c3-c3 c3 c3 c3 c3 c3 c3 c3 ................
첫번째 바이트 1c 가 할당된 메모리 크기입니다.
두번째 바이트 c0 는 뭔지 모르겠네요.
세번째 바이트 c3 는 Page 를 채워놓는 값입니다. 82c5c010 ~ 82c5cfe0 모두 이 값
으로 채워져 있습니다. 이 값은 아마도 Verifier가 메모리가 깨진 것을 확인할 때
사용될 것입니다.
네번재 바이트부터 4바이트는 메모리 태그입니다.
그 뒤는 역시 뭔지 잘 모르겠 네요.
이 내용과 !pool 에서 출력된 결과를 보면 동일하다는 것을 알 수 있을 것입니다.
이렇게 해서 Special Pool 로 발생한 BugCheck와 Special Pool 에 대한 내용을
살펴봤습니다. 아주 유용한 Verifier와 Special Pool 모두 잘 활 용하시기 바랍니다.