Crash Dump Analysis Patterns (Part 13c)
Crash Dump Analysis Patterns (Part 13c)
번역: 김희준(drost@naver.com, https://insidekernel.net)
핸들 릭이 메모리 풀 부족을 불러 일으키기도 하지만, 많은 드라이버들은 자신만의 private 메모리를 할당하여 4글자로 된 ASCII 태그를 할당합니다, 예를 들어서 제 x64 Vista 워크스테이션의 non-paged 풀의 경우에는 :
lkd> !poolused 3
Sorting by NonPaged Pool Consumed
Pool Used:
NonPaged
Tag Allocs Frees Diff Used
EtwB 304 134 170 6550080 Etw Buffer , Binary: nt!etw
File 32630649 32618671 11978 3752928 File objects
Pool 16 11 5 3363472 Pool tables, etc.
Ntfr 204791 187152 17639 2258704 ERESOURCE , Binary: ntfs.sys
FMsl 199039 187685 11354 2179968 STREAM_LIST_CTRL structure , Binary: fltmgr.sys
MmCa 250092 240351 9741 2134368 Mm control areas for mapped files , Binary: nt!mm
ViMm 135503 134021 1482 1783824 Video memory manager , Binary: dxgkrnl.sys
Cont 53 12 41 1567664 Contiguous physical memory allocations for device drivers
Thre 72558 71527 1031 1234064 Thread objects , Binary: nt!ps
VoSm 872 851 21 1220544 Bitmap allocations , Binary: volsnap.sys
NtFs 8122505 8110933 11572 1190960 StrucSup.c , Binary: ntfs.sys
AmlH 1 0 1 1048576 ACPI AMLI Pooltags
SaSc 20281 14820 5461 1048512 UNKNOWN pooltag ‘SaSc’, please update pooltag.txt
RaRS 1000 0 1000 960000 UNKNOWN pooltag ‘RaRS’, please update pooltag.txt
…
…
…
만약 pool tag가 누구의 것인지 모르겠다면 Microsoft article KB298102 문서에서 어떻게 해당 드라이버를 찾는지 알려줍니다. 또한 WinDbg에서 커널 영역 주소들(kernel space addresses)을 찾기 위해 메모리 검색을 사용할 수 있고 어떤 모듈들이 그에 대응하는지 확인할 수 있습니다.
WinDbg는 풀 할당이 실패한 숫자를 보여주고 풀 사용량이 거의 최대치에 이르렀다는 메시지를 보여줍니다. 아래에 문제 해결 힌트와 함께 예제 몇 개를 적어놓았습니다.
Session pool
3: kd> !vm
*** Virtual Memory Usage ***
Physical Memory: 1572637 ( 6290548 Kb)
Page File: \??\C:\pagefile.sys
Current: 3145728 Kb Free Space: 3001132 Kb
Minimum: 3145728 Kb Maximum: 3145728 Kb
Available Pages: 1317401 ( 5269604 Kb)
ResAvail Pages: 1478498 ( 5913992 Kb)
Locked IO Pages: 114 ( 456 Kb)
Free System PTEs: 194059 ( 776236 Kb)
Free NP PTEs: 32766 ( 131064 Kb)
Free Special NP: 0 ( 0 Kb)
Modified Pages: 443 ( 1772 Kb)
Modified PF Pages: 442 ( 1768 Kb)
NonPagedPool Usage: 13183 ( 52732 Kb)
NonPagedPool Max: 65215 ( 260860 Kb)
PagedPool 0 Usage: 11328 ( 45312 Kb)
PagedPool 1 Usage: 1473 ( 5892 Kb)
PagedPool 2 Usage: 1486 ( 5944 Kb)
PagedPool 3 Usage: 1458 ( 5832 Kb)
PagedPool 4 Usage: 1505 ( 6020 Kb)
PagedPool Usage: 17250 ( 69000 Kb)
PagedPool Maximum: 65536 ( 262144 Kb)
********** 3441 pool allocations have failed **********
Shared Commit: 8137 ( 32548 Kb)
Special Pool: 0 ( 0 Kb)
Shared Process: 8954 ( 35816 Kb)
PagedPool Commit: 17312 ( 69248 Kb)
Driver Commit: 2095 ( 8380 Kb)
Committed pages: 212476 ( 849904 Kb)
Commit limit: 2312654 ( 9250616 Kb)
Paged와 non-paged pool 사용량이 최대 사용량에 비해 한참 아래이기 때문에 session pool을 체크해봐야 합니다:
3: kd> !vm 4
Terminal Server Memory Usage By Session:
Session Paged Pool Maximum is 32768K
Session View Space Maximum is 20480K
Session ID 0 @ f79a1000:
Paged Pool Usage: 9824K
Commit Usage: 10148K
Session ID 2 @ f7989000:
Paged Pool Usage: 1212K
Commit Usage: 2180K
Session ID 9 @ f79b5000:
Paged Pool Usage: 32552K
*** 7837 Pool Allocation Failures ***
Commit Usage: 33652K
Microsoft article KB840342 를 참고하세요.
Paged pool
직접적인 경고 메시지를 가질 수 있습니다:
1: kd> !vm
*** Virtual Memory Usage ***
Physical Memory: 511881 ( 2047524 Kb)
Page File: \??\S:\pagefile.sys
Current: 2098176Kb Free Space: 1837740Kb
Minimum: 2098176Kb Maximum: 2098176Kb
Page File: \??\R:\pagefile.sys
Current: 1048576Kb Free Space: 792360Kb
Minimum: 1048576Kb Maximum: 1048576Kb
Available Pages: 201353 ( 805412 Kb)
ResAvail Pages: 426839 ( 1707356 Kb)
Modified Pages: 45405 ( 181620 Kb)
NonPagedPool Usage: 10042 ( 40168 Kb)
NonPagedPool Max: 68537 ( 274148 Kb)
PagedPool 0 Usage: 26820 ( 107280 Kb)
PagedPool 1 Usage: 1491 ( 5964 Kb)
PagedPool 2 Usage: 1521 ( 6084 Kb)
PagedPool 3 Usage: 1502 ( 6008 Kb)
PagedPool 4 Usage: 1516 ( 6064 Kb)
********** Excessive Paged Pool Usage *****
PagedPool Usage: 32850 ( 131400 Kb)
PagedPool Maximum: 40960 ( 163840 Kb)
Shared Commit: 14479 ( 57916 Kb)
Special Pool: 0 ( 0 Kb)
Free System PTEs: 135832 ( 543328 Kb)
Shared Process: 15186 ( 60744 Kb)
PagedPool Commit: 32850 ( 131400 Kb)
Driver Commit: 1322 ( 5288 Kb)
Committed pages: 426786 ( 1707144 Kb)
Commit limit: 1259456 ( 5037824 Kb)
또한 만약 경고 메시지가 없다면 사이즈를 일일이 수동으로 체크할 수 있고 만약 paged pool 사용량이 최대 사용량에 가깝고 non-paged pool은 아니라면 paged pool로부터 할당은 대부분 실패하게 됩니다:
0: kd> !vm
*** Virtual Memory Usage ***
Physical Memory: 4193696 ( 16774784 Kb)
Page File: \??\C:\pagefile.sys
Current: 4193280 Kb Free Space: 3313120 Kb
Minimum: 4193280 Kb Maximum: 4193280 Kb
Available Pages: 3210617 ( 12842468 Kb)
ResAvail Pages: 4031978 ( 16127912 Kb)
Locked IO Pages: 120 ( 480 Kb)
Free System PTEs: 99633 ( 398532 Kb)
Free NP PTEs: 26875 ( 107500 Kb)
Free Special NP: 0 ( 0 Kb)
Modified Pages: 611 ( 2444 Kb)
Modified PF Pages: 590 ( 2360 Kb)
NonPagedPool 0 Used: 8271 ( 33084 Kb)
NonPagedPool 1 Used: 13828 ( 55312 Kb)
NonPagedPool Usage: 37846 ( 151384 Kb)
NonPagedPool Max: 65215 ( 260860 Kb)
PagedPool 0 Usage: 82308 ( 329232 Kb)
PagedPool 1 Usage: 12700 ( 50800 Kb)
PagedPool 2 Usage: 25702 ( 102808 Kb)
PagedPool Usage: 120710 ( 482840 Kb)
PagedPool Maximum: 134144 ( 536576 Kb)
********** 818 pool allocations have failed **********
Shared Commit: 80168 ( 320672 Kb)
Special Pool: 0 ( 0 Kb)
Shared Process: 55654 ( 222616 Kb)
PagedPool Commit: 120772 ( 483088 Kb)
Driver Commit: 1890 ( 7560 Kb)
Committed pages: 1344388 ( 5377552 Kb)
Commit limit: 5177766 ( 20711064 Kb)
!poolused 4 WinDbg 명령은 pool tag로 정렬된 paged pool 소비량을 보여줄 것입니다:
0: kd> !poolused 4
Sorting by Paged Pool Consumed
Pool Used:
NonPaged Paged
Tag Allocs Used Allocs Used
MmSt 0 0 85622 140642616 Mm section object prototype ptes , Binary: nt!mm
Ntff 5 1040 63715 51991440 FCB_DATA , Binary: ntfs.sys
여기에선 Microsoft article KB312362 를 참고하세요.
Non-paged pool
0: kd> !vm
*** Virtual Memory Usage ***
Physical Memory: 851775 ( 3407100 Kb)
Page File: \??\C:\pagefile.sys
Current: 4190208 Kb Free Space: 4175708 Kb
Minimum: 4190208 Kb Maximum: 4190208 Kb
Available Pages: 147274 ( 589096 Kb)
ResAvail Pages: 769287 ( 3077148 Kb)
Locked IO Pages: 118 ( 472 Kb)
Free System PTEs: 184910 ( 739640 Kb)
Free NP PTEs: 110 ( 440 Kb)
Free Special NP: 0 ( 0 Kb)
Modified Pages: 168 ( 672 Kb)
Modified PF Pages: 168 ( 672 Kb)
NonPagedPool Usage: 64445 ( 257780 Kb)
NonPagedPool Max: 64640 ( 258560 Kb)
********** Excessive NonPaged Pool Usage *****
PagedPool 0 Usage: 21912 ( 87648 Kb)
PagedPool 1 Usage: 691 ( 2764 Kb)
PagedPool 2 Usage: 706 ( 2824 Kb)
PagedPool 3 Usage: 704 ( 2816 Kb)
PagedPool 4 Usage: 708 ( 2832 Kb)
PagedPool Usage: 24721 ( 98884 Kb)
PagedPool Maximum: 134144 ( 536576 Kb)
********** 429 pool allocations have failed **********
Shared Commit: 5274 ( 21096 Kb)
Special Pool: 0 ( 0 Kb)
Shared Process: 3958 ( 15832 Kb)
PagedPool Commit: 24785 ( 99140 Kb)
Driver Commit: 19289 ( 77156 Kb)
Committed pages: 646282 ( 2585128 Kb)
Commit limit: 1860990 ( 7443960 Kb)
!poolused 3 WinDbg 명령은 pool tag에 의해 정렬된 non-paged pool 소비량을 보여줄 것입니다:
0: kd> !poolused 3
Sorting by NonPaged Pool Consumed
Pool Used:
NonPaged
Tag Allocs Frees Diff
Ddk 9074558 3859522 5215036 Default for driver allocated memory (user’s of ntddk.h)
MmCm 43787 42677 1110 Calls made to MmAllocateContiguousMemory , Binary: nt!mm
LSwi 1 0 1 initial work context
TCPt 3281838 3281808 30 TCP/IP network protocol , Binary: TCP
이전에 쓴 DDK tag 글을 참고하세요:
다음 Microsoft article KB293857 에서는 Windows 2003 덤프에서도 작동하는 이전 kdex2x86.dll 익스텐션에 있는 xpool 명령어를 어떻게 사용하는지에 대해서 설명합니다:
0: kd> !w2kfre\kdex2x86.xpool -map
unable to get NT!MmSizeOfNonPagedMustSucceed location
unable to get NT!MmSubsectionTopPage location
unable to get NT!MmKseg2Frame location
unable to get NT!MmNonPagedMustSucceed location
Status Map of Pool Area Pages
==============================
'O': one page in use ('P': paged out)
'<': start page of contiguous pages in use ('{': paged out)
'>': last page of contiguous pages in use ('}': paged out)
'=': intermediate page of contiguous pages in use ('-': paged out)
'.': one page not used
Non-Paged Pool Area Summary
----------------------------
Maximum Number of Pages = 64640 pages
Number of Pages In Use = 36721 pages (56.8%)
+00000 +08000 +10000 +18000 +20000 +28000 +30000 +38000
82780000: ..OO.OO.OO..O.OO .O..OO.OO.OO..O. OO.O..OO.O..OO.. ..OO.O..OO.OO.OO
827c0000: .O..OO....OO..O. OO.OO.OO....OO.. O....O..OO....OO .O..OO.O..OO..O.
82800000: ..O............. ................ ................ ................
82840000: ................ ................ ................ ................
82880000: ......O.....O... ..O.O.....O..... O.....O.....O... ..O.....O.......
828c0000: ..O.........O... ......OOO.....O. ....O.....O..... O.....O.........
82900000: .O.........OO... O....O........O. ......OO........ OO.O..O.........
82940000: ...............O ..O.OO........OO ................ ...O.....O......
82980000: O.........O..O.. ....O.........O. ........O.....O. ..O.........O...
829c0000: ........O....... ..O...........O. .O..O...O..O.... ..O.........O...
82a00000: ......O..O...... O.........O..... ....O.........O. ................
82a40000: ............O... O..O.O......OO.. ......O.....O... ..O.....O...O.OO
...
...
...
893c0000: ................ ................ ................ ................
89400000: ..........=..=.. ....=.....=..... =..=......=..=.. ....=..=......=.
89440000: ..=............. ............=... =..=.....=..=... =...=.=.....==..
89480000: ....==......=.=. .........=...... ====.=.=........ ................
894c0000: ................ ................ ..........=.=... ...==...........
89500000: ..=............. ..=............. ..=............. ..=.............
89540000: ..=............. ..=............. ..=............. ..=...=.....=..=
89580000: ......=..=...... =..=......=.==== ==..==.=....=... .=....=....=.==.
895c0000: =.....==........ ..=............. =..=......=...=. ................
89600000: ........=...=..= .....=......=..= ==....=......... .........=....=.
89640000: ..=...===...=... ==......=..=..=. ..=..=......=... ......=.=.....=.
...
...
...
여기 다른 예제가 있습니다:
0: kd> !vm
*** Virtual Memory Usage ***
Physical Memory: 786299 ( 3145196 Kb)
Page File: \??\C:\pagefile.sys
Current: 4193280Kb Free Space: 3407908Kb
Minimum: 4193280Kb Maximum: 4193280Kb
Available Pages: 200189 ( 800756 Kb)
ResAvail Pages: 657130 ( 2628520 Kb)
Modified Pages: 762 ( 3048 Kb)
NonPagedPool Usage: 22948 ( 91792 Kb)
NonPagedPool Max: 70145 ( 280580 Kb)
PagedPool 0 Usage: 19666 ( 78664 Kb)
PagedPool 1 Usage: 3358 ( 13432 Kb)
PagedPool 2 Usage: 3306 ( 13224 Kb)
PagedPool 3 Usage: 3312 ( 13248 Kb)
PagedPool 4 Usage: 3309 ( 13236 Kb)
********** Excessive Paged Pool Usage *****
PagedPool Usage: 32951 ( 131804 Kb)
PagedPool Maximum: 40960 ( 163840 Kb)
Shared Commit: 9664 ( 38656 Kb)
Special Pool: 0 ( 0 Kb)
Free System PTEs: 103335 ( 413340 Kb)
Shared Process: 45024 ( 180096 Kb)
PagedPool Commit: 32951 ( 131804 Kb)
Driver Commit: 1398 ( 5592 Kb)
Committed pages: 864175 ( 3456700 Kb)
Commit limit: 1793827 ( 7175308 Kb)
0: kd> !poolused 4
Sorting by Paged Pool Consumed
Pool Used:
NonPaged Paged
Tag Allocs Used Allocs Used
CM 85 5440 11045 47915424
MyAV 0 0 186 14391520
MmSt 0 0 11795 13235744
Obtb 709 90752 2712 11108352
Ntff 5 1120 9886 8541504
…
…
…
MyAV 태그는 MyAVDrv 모듈에 대한 prefix로 보이며, 이것이 우연은 아닐 것입니다. 드라이버들의 리스트를 살펴보면 MyAVDrv.sys가 몇번에 걸쳐서 로드되고 언로드 되었음을 볼 수 있습니다. 이 드라이버는 non-paged pool 할당을 free하지 않았을까요?
0: kd> lmv m MyAVDrv.sys
start end module name
Unloaded modules:
a5069000 a5084000 MyAVDrv.sys
Timestamp: unavailable (00000000)
Checksum: 00000000
a5069000 a5084000 MyAVDrv.sys
Timestamp: unavailable (00000000)
Checksum: 00000000
a5069000 a5084000 MyAVDrv.sys
Timestamp: unavailable (00000000)
Checksum: 00000000
b93e1000 b93fc000 MyAVDrv.sys
Timestamp: unavailable (00000000)
Checksum: 00000000
b9ae5000 b9b00000 MyAVDrv.sys
Timestamp: unavailable (00000000)
Checksum: 00000000
be775000 be790000 MyAVDrv.sys
Timestamp: unavailable (00000000)
Checksum: 00000000
또한 pool tag 목록에서 CM tag가 가장 많은 메모리 할당량을 가지고 있고 !locks 명령어가 심한 경쟁(High Contention) 패턴의 한 예가 될 수 있는 레지스트리를 기다리고 있는 수많은 스레드들을 보여줍니다,
0: kd> !locks
Resource @ nt!CmpRegistryLock (0x80478b00) Shared 10 owning threads
Contention Count = 9149810
NumberOfSharedWaiters = 718
NumberOfExclusiveWaiters = 21
그러하다면 우리는 이 메모리 덤프에 최소 두 가지 문제점이 있음을 볼 수 있습니다: 너무 많은 paged pool 소비와 레지스트리 리소스에 대한 높은 스레드 경쟁으로 시스템을 다운시키거나 느려지게 한 문제점이 그것입니다.
- Dmitry Vostokov @ DumpAnalysis.org -