System hang 등의 시스템 장애 원인 분석을 위해 위해 키보드 또는 Bang 유틸리티를 일반적으로 많이 사용합니다만 Notmyfault 유틸리티를 사용하면 좀 더 다양한 유형의 Crash 또는 Memory Leak 을 발생시킬 수 있습니다.
NotMyfault 유틸리티는 NotMyfault.exe 와 myfault.sys 2개의 파일로 구성되어 있으며 참고자료에 링크된 Mark Russinovich's technical blog 에 가시면 32, 64bit 버전의 툴을 다운로드 받을 수 있습니다.
[시나리오]
200MB 이상 Nonpaged pool leak 을 발생시킨 후 High IRQL fault 발생
[환경]
Windows Server 2003 SP2
Physical Memory : 1GB
[NotMyfault 실행]
1. NotMyfault.exe 실행
2. Leak/second : 1000KB
3. Leak Nonpaged 클릭 - 작업 관리자에서 Paged Pool 이 200MB 에 도달하였을 때 STOP
4. High IRQL fault - Do Bug (Crash 발생)
[결과확인]
WinDbg 를 통해 crash driver 와 paged pool 사용 정보를 확인합니다.
[참고자료]
Unkillable Processes
http://blogs.technet.com/markrussinovich/archive/2005/08/17/unkillable-processes.aspx
작성자 : Lai Go / 작성일자 : 2009.10.29
NotMyfault 유틸리티는 NotMyfault.exe 와 myfault.sys 2개의 파일로 구성되어 있으며 참고자료에 링크된 Mark Russinovich's technical blog 에 가시면 32, 64bit 버전의 툴을 다운로드 받을 수 있습니다.
[시나리오]
200MB 이상 Nonpaged pool leak 을 발생시킨 후 High IRQL fault 발생
[환경]
Windows Server 2003 SP2
Physical Memory : 1GB
[NotMyfault 실행]
1. NotMyfault.exe 실행
2. Leak/second : 1000KB
3. Leak Nonpaged 클릭 - 작업 관리자에서 Paged Pool 이 200MB 에 도달하였을 때 STOP
4. High IRQL fault - Do Bug (Crash 발생)
[결과확인]
WinDbg 를 통해 crash driver 와 paged pool 사용 정보를 확인합니다.
BugCheck D1, {e14c0008, 2, 0, f799f579}
*** ERROR: Module load completed but symbols could not be loaded for myfault.sys
*** ERROR: Module load completed but symbols could not be loaded for NotMyfault.exe
Probably caused by : myfault.sys ( myfault+579 )
DRIVER_IRQL_NOT_LESS_OR_EQUAL (d1)
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 kernel debugger is available get stack backtrace.
Arguments:
Arg1: e14c0008, memory referenced
Arg2: 00000002, IRQL
Arg3: 00000000, value 0 = read operation, 1 = write operation
Arg4: f799f579, address which referenced memory
kd> .trap 0xfffffffff3c2db7c
ErrCode = 00000000
eax=e14c0008 ebx=85ec7b88 ecx=3e7f8123 edx=e14a6008 esi=e14a6008 edi=00000000
eip=f799f579 esp=f3c2dbf0 ebp=f3c2dbf8 iopl=0 nv up ei ng nz na po nc
cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000 efl=00010282
myfault+0x579:
f799f579 8b08 mov ecx,dword ptr [eax] ds:0023:e14c0008=????????
kd> kvL
*** Stack trace for last set context - .thread/.cxr resets it
ChildEBP RetAddr Args to Child
WARNING: Stack unwind information not available. Following frames may be wrong.
f3c2dbf8 f799f770 85ec7b70 f3c2dc3c f799f7fc myfault+0x579
f3c2dc04 f799f7fc 85ba4028 00000001 00000000 myfault+0x770
f3c2dc3c 8081d5a3 86053448 85ec7b70 85ba4028 myfault+0x7fc
f3c2dc50 808ed3e1 85ec7be0 85ba4028 85ec7b70 nt!IofCallDriver+0x45 (FPO: [0,0,4])
f3c2dc64 808ee169 86053448 85ec7b70 85ba4028 nt!IopSynchronousServiceTail+0x10b (FPO: [7,0,4])
f3c2dd00 808e6cca 000000c0 00000000 00000000 nt!IopXxxControlFile+0x5e5 (FPO: [SEH])
f3c2dd34 80883908 000000c0 00000000 00000000 nt!NtDeviceIoControlFile+0x2a (FPO: [10,0,0])
f3c2dd34 7c9685ec 000000c0 00000000 00000000 nt!KiFastCallEntry+0xf8 (FPO: [0,0] TrapFrame @ f3c2dd64)
0012f9bc 7c966fcb 7c8016f5 000000c0 00000000 ntdll!KiFastSystemCallRet (FPO: [0,0,0])
0012f9c0 7c8016f5 000000c0 00000000 00000000 ntdll!NtDeviceIoControlFile+0xc (FPO: [10,0,0])
0012fa24 00401a5b 000000c0 83360018 00000000 kernel32!DeviceIoControl+0x137 (FPO: [SEH])
0012fa68 77dea24c 01010061 005a0049 0012fa90 NotMyfault+0x1a5b
0012faf4 77dea304 01010061 00000043 01100085 USER32!ClientFrame+0xe0 (FPO: [6,25,0])
0012fb18 77e0d3e2 01010061 0012fb34 00000000 USER32!DrawFocusRect+0x40 (FPO: [2,0,4])
0012fb84 07b7742e 77dfb6e3 00040162 00000111 USER32!xxxBNDrawText+0x3e9 (FPO: [4,20,4])
0012fbf4 77dfb82a 00000000 00000000 00000000 0x7b7742e
00401860 10a10000 330040e0 248489c4 0000012c USER32!UserCallWinProcCheckWow+0x5c (FPO: [SEH])
00401884 00000000 0271870f 4f740000 7410fd83 0x10a10000
kd> !vm
*** Virtual Memory Usage ***
Physical Memory: 262010 ( 1048040 Kb)
Page File: \??\C:\pagefile.sys
Current: 1572864 Kb Free Space: 1565400 Kb
Minimum: 1572864 Kb Maximum: 3145728 Kb
Available Pages: 166628 ( 666512 Kb)
ResAvail Pages: 199386 ( 797544 Kb)
Locked IO Pages: 156 ( 624 Kb)
Free System PTEs: 218491 ( 873964 Kb)
Free NP PTEs: 1891 ( 7564 Kb)
Free Special NP: 0 ( 0 Kb)
Modified Pages: 359 ( 1436 Kb)
Modified PF Pages: 359 ( 1436 Kb)
NonPagedPool Usage: 49746 ( 198984 Kb)
NonPagedPool Max: 51967 ( 207868 Kb)
********** Excessive NonPaged Pool Usage *****
PagedPool 0 Usage: 3639 ( 14556 Kb)
PagedPool 1 Usage: 675 ( 2700 Kb)
PagedPool 2 Usage: 675 ( 2700 Kb)
PagedPool Usage: 4989 ( 19956 Kb)
PagedPool Maximum: 70656 ( 282624 Kb)
kd> !poolused /t 3 2
Sorting by NonPaged Pool Consumed
Pool Used:
NonPaged Paged
Tag Allocs Used Allocs Used
Leak 23 193024000 0 0 UNKNOWN pooltag 'Leak', please update pooltag.txt
LSwi 1 2576384 0 0 initial work context
TCPt 33 1422640 0 0 TCP/IP network protocol , Binary: TCP
TOTAL 23954 203162872 32342 19144784
kd> !for_each_module s-a @#Base @#End "Leak"
0040b3a4 4c 65 61 6b 20 26 4e 6f-6e 70 61 67 65 64 00 00 Leak &Nonpaged..
0040b3c0 4c 65 61 6b 20 26 50 61-67 65 64 00 31 30 30 30 Leak &Paged.1000
f799f63f 4c 65 61 6b ff 75 0c ff-75 08 ff 15 24 fb 99 f7 Leak.u..u...$...
kd> u f799f63f
myfault+0x63f:
f799f63f 4c dec esp
f799f640 6561 popad
f799f642 6bff75 imul edi,edi,75h
f799f645 0cff or al,0FFh
f799f647 7508 jne myfault+0x651 (f799f651)
f799f649 ff1524fb99f7 call dword ptr [myfault+0xb24 (f799fb24)]
f799f64f 85c0 test eax,eax
f799f651 7422 je myfault+0x675 (f799f675)
kd> u 0040b3c0
NotMyfault+0xb3c0:
0040b3c0 4c dec esp
0040b3c1 6561 popad
0040b3c3 6b2026 imul esp,dword ptr [eax],26h
0040b3c6 50 push eax
0040b3c7 61 popad
0040b3c8 67 ???
0040b3c9 65 ???
0040b3ca 640031 add byte ptr fs:[ecx],dh
kd> u 0040b3a4
NotMyfault+0xb3a4:
0040b3a4 4c dec esp
0040b3a5 6561 popad
0040b3a7 6b2026 imul esp,dword ptr [eax],26h
0040b3aa 4e dec esi
0040b3ab 6f outs dx,dword ptr [esi]
0040b3ac 6e outs dx,byte ptr [esi]
0040b3ad 7061 jo NotMyfault+0xb410 (0040b410)
0040b3af 67 ???
kd> lmvm notmyfault
start end module name
00400000 00412000 NotMyfault (no symbols)
Loaded symbol image file: NotMyfault.exe
Image path: D:\Temp\Notmyfault\exe\Release\NotMyfault.exe
Image name: NotMyfault.exe
Timestamp: Sun Mar 08 09:42:41 2009 (49B31481)
CheckSum: 0001F62F
ImageSize: 00012000
File version: 3.0.0.0
Product version: 3.0.0.0
File flags: 0 (Mask 3F)
File OS: 40004 NT Win32
File type: 1.0 App
File date: 00000000.00000000
Translations: 0409.04b0
CompanyName: Sysinternals - www.sysinternals.com
ProductName: Sysinternals Notmyfault
InternalName: Sysinternals NotMyfault
OriginalFilename: NotMyfault.exe
ProductVersion: 3.0
FileVersion: 3.0
FileDescription: Driver bug test program
LegalCopyright: Copyright © 2004-2009 Mark Russinovich
*** ERROR: Module load completed but symbols could not be loaded for myfault.sys
*** ERROR: Module load completed but symbols could not be loaded for NotMyfault.exe
Probably caused by : myfault.sys ( myfault+579 )
DRIVER_IRQL_NOT_LESS_OR_EQUAL (d1)
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 kernel debugger is available get stack backtrace.
Arguments:
Arg1: e14c0008, memory referenced
Arg2: 00000002, IRQL
Arg3: 00000000, value 0 = read operation, 1 = write operation
Arg4: f799f579, address which referenced memory
kd> .trap 0xfffffffff3c2db7c
ErrCode = 00000000
eax=e14c0008 ebx=85ec7b88 ecx=3e7f8123 edx=e14a6008 esi=e14a6008 edi=00000000
eip=f799f579 esp=f3c2dbf0 ebp=f3c2dbf8 iopl=0 nv up ei ng nz na po nc
cs=0008 ss=0010 ds=0023 es=0023 fs=0030 gs=0000 efl=00010282
myfault+0x579:
f799f579 8b08 mov ecx,dword ptr [eax] ds:0023:e14c0008=????????
kd> kvL
*** Stack trace for last set context - .thread/.cxr resets it
ChildEBP RetAddr Args to Child
WARNING: Stack unwind information not available. Following frames may be wrong.
f3c2dbf8 f799f770 85ec7b70 f3c2dc3c f799f7fc myfault+0x579
f3c2dc04 f799f7fc 85ba4028 00000001 00000000 myfault+0x770
f3c2dc3c 8081d5a3 86053448 85ec7b70 85ba4028 myfault+0x7fc
f3c2dc50 808ed3e1 85ec7be0 85ba4028 85ec7b70 nt!IofCallDriver+0x45 (FPO: [0,0,4])
f3c2dc64 808ee169 86053448 85ec7b70 85ba4028 nt!IopSynchronousServiceTail+0x10b (FPO: [7,0,4])
f3c2dd00 808e6cca 000000c0 00000000 00000000 nt!IopXxxControlFile+0x5e5 (FPO: [SEH])
f3c2dd34 80883908 000000c0 00000000 00000000 nt!NtDeviceIoControlFile+0x2a (FPO: [10,0,0])
f3c2dd34 7c9685ec 000000c0 00000000 00000000 nt!KiFastCallEntry+0xf8 (FPO: [0,0] TrapFrame @ f3c2dd64)
0012f9bc 7c966fcb 7c8016f5 000000c0 00000000 ntdll!KiFastSystemCallRet (FPO: [0,0,0])
0012f9c0 7c8016f5 000000c0 00000000 00000000 ntdll!NtDeviceIoControlFile+0xc (FPO: [10,0,0])
0012fa24 00401a5b 000000c0 83360018 00000000 kernel32!DeviceIoControl+0x137 (FPO: [SEH])
0012fa68 77dea24c 01010061 005a0049 0012fa90 NotMyfault+0x1a5b
0012faf4 77dea304 01010061 00000043 01100085 USER32!ClientFrame+0xe0 (FPO: [6,25,0])
0012fb18 77e0d3e2 01010061 0012fb34 00000000 USER32!DrawFocusRect+0x40 (FPO: [2,0,4])
0012fb84 07b7742e 77dfb6e3 00040162 00000111 USER32!xxxBNDrawText+0x3e9 (FPO: [4,20,4])
0012fbf4 77dfb82a 00000000 00000000 00000000 0x7b7742e
00401860 10a10000 330040e0 248489c4 0000012c USER32!UserCallWinProcCheckWow+0x5c (FPO: [SEH])
00401884 00000000 0271870f 4f740000 7410fd83 0x10a10000
kd> !vm
*** Virtual Memory Usage ***
Physical Memory: 262010 ( 1048040 Kb)
Page File: \??\C:\pagefile.sys
Current: 1572864 Kb Free Space: 1565400 Kb
Minimum: 1572864 Kb Maximum: 3145728 Kb
Available Pages: 166628 ( 666512 Kb)
ResAvail Pages: 199386 ( 797544 Kb)
Locked IO Pages: 156 ( 624 Kb)
Free System PTEs: 218491 ( 873964 Kb)
Free NP PTEs: 1891 ( 7564 Kb)
Free Special NP: 0 ( 0 Kb)
Modified Pages: 359 ( 1436 Kb)
Modified PF Pages: 359 ( 1436 Kb)
NonPagedPool Usage: 49746 ( 198984 Kb)
NonPagedPool Max: 51967 ( 207868 Kb)
********** Excessive NonPaged Pool Usage *****
PagedPool 0 Usage: 3639 ( 14556 Kb)
PagedPool 1 Usage: 675 ( 2700 Kb)
PagedPool 2 Usage: 675 ( 2700 Kb)
PagedPool Usage: 4989 ( 19956 Kb)
PagedPool Maximum: 70656 ( 282624 Kb)
kd> !poolused /t 3 2
Sorting by NonPaged Pool Consumed
Pool Used:
NonPaged Paged
Tag Allocs Used Allocs Used
Leak 23 193024000 0 0 UNKNOWN pooltag 'Leak', please update pooltag.txt
LSwi 1 2576384 0 0 initial work context
TCPt 33 1422640 0 0 TCP/IP network protocol , Binary: TCP
TOTAL 23954 203162872 32342 19144784
kd> !for_each_module s-a @#Base @#End "Leak"
0040b3a4 4c 65 61 6b 20 26 4e 6f-6e 70 61 67 65 64 00 00 Leak &Nonpaged..
0040b3c0 4c 65 61 6b 20 26 50 61-67 65 64 00 31 30 30 30 Leak &Paged.1000
f799f63f 4c 65 61 6b ff 75 0c ff-75 08 ff 15 24 fb 99 f7 Leak.u..u...$...
kd> u f799f63f
myfault+0x63f:
f799f63f 4c dec esp
f799f640 6561 popad
f799f642 6bff75 imul edi,edi,75h
f799f645 0cff or al,0FFh
f799f647 7508 jne myfault+0x651 (f799f651)
f799f649 ff1524fb99f7 call dword ptr [myfault+0xb24 (f799fb24)]
f799f64f 85c0 test eax,eax
f799f651 7422 je myfault+0x675 (f799f675)
kd> u 0040b3c0
NotMyfault+0xb3c0:
0040b3c0 4c dec esp
0040b3c1 6561 popad
0040b3c3 6b2026 imul esp,dword ptr [eax],26h
0040b3c6 50 push eax
0040b3c7 61 popad
0040b3c8 67 ???
0040b3c9 65 ???
0040b3ca 640031 add byte ptr fs:[ecx],dh
kd> u 0040b3a4
NotMyfault+0xb3a4:
0040b3a4 4c dec esp
0040b3a5 6561 popad
0040b3a7 6b2026 imul esp,dword ptr [eax],26h
0040b3aa 4e dec esi
0040b3ab 6f outs dx,dword ptr [esi]
0040b3ac 6e outs dx,byte ptr [esi]
0040b3ad 7061 jo NotMyfault+0xb410 (0040b410)
0040b3af 67 ???
kd> lmvm notmyfault
start end module name
00400000 00412000 NotMyfault (no symbols)
Loaded symbol image file: NotMyfault.exe
Image path: D:\Temp\Notmyfault\exe\Release\NotMyfault.exe
Image name: NotMyfault.exe
Timestamp: Sun Mar 08 09:42:41 2009 (49B31481)
CheckSum: 0001F62F
ImageSize: 00012000
File version: 3.0.0.0
Product version: 3.0.0.0
File flags: 0 (Mask 3F)
File OS: 40004 NT Win32
File type: 1.0 App
File date: 00000000.00000000
Translations: 0409.04b0
CompanyName: Sysinternals - www.sysinternals.com
ProductName: Sysinternals Notmyfault
InternalName: Sysinternals NotMyfault
OriginalFilename: NotMyfault.exe
ProductVersion: 3.0
FileVersion: 3.0
FileDescription: Driver bug test program
LegalCopyright: Copyright © 2004-2009 Mark Russinovich
[참고자료]
Unkillable Processes
http://blogs.technet.com/markrussinovich/archive/2005/08/17/unkillable-processes.aspx
작성자 : Lai Go / 작성일자 : 2009.10.29
