Crash Dump Analysis Patterns (Part 13f)
Monday, January 5th, 2009Sometimes there is not enough physical memory and the system experiences the so called disk or page file thrashing trying to resolve page faults. This can be seen in some memory dumps coming from frozen environments showing signs of double traps in running threads, the first one is a normal memory access fault (blue) and the other is forced NMI bugcheck to save a memory dump (red):
1: kd> .bugcheck
Bugcheck code 00000080
Arguments 004f4454 00000000 00000000 00000000
1: kd> !thread
THREAD 88939b20 Cid 360.378 Teb: 7ffdb000 Win32Thread: a20a7ac8 RUNNING
IRP List:
86be9e68: (0006,0100) Flags: 00000070 Mdl: 00000000
88939e68: (0006,0100) Flags: 00000070 Mdl: 00000000
88939128: (0006,0100) Flags: 00000070 Mdl: 00000000
Not impersonating
Owning Process 889456e0
Wait Start TickCount 2357431 Elapsed Ticks: 9
Context Switch Count 18267 LargeStack
UserTime 0:00:08.0218
KernelTime 0:12:28.0109
Start Address KERNEL32!BaseThreadStartThunk (0x7c57b740)
Win32 Start Address msafd!SockAsyncThread (0x74fd3113)
Stack Init bef9e000 Current bef9db60 Base bef9e000 Limit bef9b000 Call 0
Priority 11 BasePriority 11 PriorityDecrement 0 DecrementCount 0
ChildEBP RetAddr
8904aff0 80469211 hal!HalHandleNMI+0×193
8904aff0 80438621 nt!KiTrap02+0×41
bef9dc10 8043799a nt!MiTrimWorkingSet+0xa7
bef9dc38 804378ec nt!MiDoReplacement+0×2e
bef9dc50 804453cf nt!MiLocateAndReserveWsle+0×1e
bef9dc68 804444e0 nt!MiAddValidPageToWorkingSet+0×89
bef9dc8c 804443a2 nt!MiCompleteProtoPteFault+0xf6
bef9dcb8 804436e8 nt!MiResolveProtoPteFault+0×160
bef9dcfc 8044ccd0 nt!MiDispatchFault+0xfc
bef9dd4c 8046b063 nt!MmAccessFault+0xd1c
bef9dd4c 74fd31e0 nt!KiTrap0E+0xc7
016effb4 7c57b3bc msafd!SockAsyncThread+0xcd
016effec 00000000 KERNEL32!BaseThreadStart+0×52
If we check virtual memory stats we see the low number of available pages:
1: kd> !vm
*** Virtual Memory Usage ***
Physical Memory: 524165 ( 2096660 Kb)
Page File: \??\C:\pagefile.sys
Current: 4190208Kb Free Space: 3298704Kb
Minimum: 4190208Kb Maximum: 4190208Kb
Page File: \??\E:\pagefile.sys
Current: 4190208Kb Free Space: 3339860Kb
Minimum: 4190208Kb Maximum: 4190208Kb
Available Pages: 1098 ( 4392 Kb)
ResAvail Pages: 410646 ( 1642584 Kb)
Modified Pages: 282384 ( 1129536 Kb)
NonPagedPool Usage: 10046 ( 40184 Kb)
NonPagedPool Max: 68609 ( 274436 Kb)
PagedPool 0 Usage: 15391 ( 61564 Kb)
PagedPool 1 Usage: 1906 ( 7624 Kb)
PagedPool 2 Usage: 1925 ( 7700 Kb)
PagedPool 3 Usage: 1937 ( 7748 Kb)
PagedPool 4 Usage: 1892 ( 7568 Kb)
PagedPool Usage: 23051 ( 92204 Kb)
PagedPool Maximum: 87040 ( 348160 Kb)
Shared Commit: 16867 ( 67468 Kb)
Special Pool: 0 ( 0 Kb)
Free System PTEs: 65288 ( 261152 Kb)
Shared Process: 38655 ( 154620 Kb)
PagedPool Commit: 23051 ( 92204 Kb)
Driver Commit: 1060 ( 4240 Kb)
Committed pages: 1049592 ( 4198368 Kb)
Commit limit: 2580155 (10320620 Kb)
[…]
In W2K dumps we can also see locking on a working set resource (I guess the name from Ws shortcut here):
1: kd> !locks
**** DUMP OF ALL RESOURCE OBJECTS ****
Resource @ nt!MmSystemWsLock (0×804869c0) Exclusively owned
Contention Count = 33083
NumberOfExclusiveWaiters = 237
[…]
and huge number of threads in Ready state for every thread priority.
Looking at the current process owning the running thread shows the large number of page faults and increased kernel CPU time compared to time spent in user mode:
1: kd> !process 889456e0
PROCESS 889456e0 SessionId: 0 Cid: 0360 Peb: 7ffdf000 ParentCid: 01a8
DirBase: 102af000 ObjectTable: 88945c08 TableSize: 622.
Image: Application.EXE
VadRoot 88944468 Clone 0 Private 838. Modified 30691412. Locked 188.
DeviceMap 89049288
Token e28db550
ElapsedTime 10:13:30.0684
UserTime 0:00:12.0578
KernelTime 0:12:38.0625
QuotaPoolUsage[PagedPool] 31568
QuotaPoolUsage[NonPagedPool] 68266
Working Set Sizes (now,min,max) (49, 50, 345) (196KB, 200KB, 1380KB)
PeakWorkingSetSize 1956
VirtualSize 131 Mb
PeakVirtualSize 131 Mb
PageFaultCount 46180598
MemoryPriority BACKGROUND
BasePriority 10
CommitCharge 1247
- Dmitry Vostokov @ DumpAnalysis.org -
