Insufficient memory, handle leak, process factory, high contention and busy system: pattern cooperation
CARE: Crash Analysis Report Environment
DATA (Dump Analysis + Trace Analysis) Facebook group
Please join the community of memory (dump) and trace analysis engineers. This group promotes scientific methods and memory dump-based worldview.
Twitter @ DumpAnalysis You can now follow portal and blog news at DumpAnalysis on Twitter
LinkedIn Group Dr. Watson Enthusiasts All about Dr. Watson errors and more. Get news, excerpts and progress reports about the forthcoming book The Science of Dr. Watson: An Illustrated History of Debugging (ISBN 978-1906717070)
2010 (0x7DA) - The Year of Dump Analysis 2011 (0x7DB) - 2020 (0x7E4) The Debugging Decade
It was reported that one system became slower and slower and eventually the complete memory dump was generated for analysis. Usual !vm 4 command shows pool allocation errors and particularly insufficient session pool memory for user session 1:
1: kd> !vm 4
*** Virtual Memory Usage ***
Physical Memory: 1048503 ( 4194012 Kb)
Page File: \??\C:\pagefile.sys
Current: 5109760 Kb Free Space: 3668764 Kb
Minimum: 5109760 Kb Maximum: 5109760 Kb
Available Pages: 409409 ( 1637636 Kb)
ResAvail Pages: 708135 ( 2832540 Kb)
Locked IO Pages: 108 ( 432 Kb)
Free System PTEs: 137566 ( 550264 Kb)
Free NP PTEs: 27288 ( 109152 Kb)
Free Special NP: 0 ( 0 Kb)
Modified Pages: 780 ( 3120 Kb)
Modified PF Pages: 771 ( 3084 Kb)
NonPagedPool Usage: 37587 ( 150348 Kb)
NonPagedPool Max: 65214 ( 260856 Kb)
PagedPool 0 Usage: 21583 ( 86332 Kb)
PagedPool 1 Usage: 3054 ( 12216 Kb)
PagedPool 2 Usage: 3076 ( 12304 Kb)
PagedPool 3 Usage: 3050 ( 12200 Kb)
PagedPool 4 Usage: 3040 ( 12160 Kb)
PagedPool Usage: 33803 ( 135212 Kb)
PagedPool Maximum: 66560 ( 266240 Kb)
********** 185454 pool allocations have failed **********
Shared Commit: 123289 ( 493156 Kb)
Special Pool: 0 ( 0 Kb)
Shared Process: 101937 ( 407748 Kb)
PagedPool Commit: 33850 ( 135400 Kb)
Driver Commit: 1697 ( 6788 Kb)
Committed pages: 1159581 ( 4638324 Kb)
Commit limit: 2283111 ( 9132444 Kb)
[...]
Session ID 1 @ af925000:
Paged Pool Usage: 16868K
*** 371034 Pool Allocation Failures ***
Commit Usage: 17960K
Session ID 2 @ af927000:
Paged Pool Usage: 2856K
Commit Usage: 3860K
[...]
The exploration of session 1 processes shows Process Factory pattern (5,000 launched processes) with explorer.exe ran amok:
1: kd> !sprocess 1
Dumping Session 1
_MM_SESSION_SPACE af925000
_MMSESSION af925d80
PROCESS 87db34a0 SessionId: 1 Cid: 4a68 Peb: 7ffd4000 ParentCid: 01b8
DirBase: cffb6d20 ObjectTable: e6084268 HandleCount: 11677.
Image: csrss.exe
PROCESS 86083020 SessionId: 1 Cid: 4560 Peb: 7ffde000 ParentCid: 2978
DirBase: cffb6f40 ObjectTable: e6c41410 HandleCount: 79.
Image: AnotherApp.exe
PROCESS 8607c020 SessionId: 1 Cid: 44c8 Peb: 7ffdc000 ParentCid: 4cf8
DirBase: cffb7080 ObjectTable: e3c9fd38 HandleCount: 25407.
Image: explorer.exe
[...]
PROCESS 85e94738 SessionId: 1 Cid: 4868 Peb: 7ffde000 ParentCid: 44c8
DirBase: cffb7c00 ObjectTable: e7038840 HandleCount: 39.
Image: application.exe
PROCESS 85e5c020 SessionId: 1 Cid: 4668 Peb: 7ffd4000 ParentCid: 4a50
DirBase: cffb7de0 ObjectTable: e11891d0 HandleCount: 172.
Image: application.exe
PROCESS 85e51578 SessionId: 1 Cid: 4c9c Peb: 7ffde000 ParentCid: 44c8
DirBase: cffb7e40 ObjectTable: e2ee0070 HandleCount: 39.
Image: application.exe
[...]
PROCESS 85c81020 SessionId: 1 Cid: 53a4 Peb: 7ffd7000 ParentCid: 44c8
DirBase: cffb89c0 ObjectTable: e6d2f600 HandleCount: 39.
Image: application.exe
PROCESS 85c6fb18 SessionId: 1 Cid: 53a8 Peb: 7ffd7000 ParentCid: 44c8
DirBase: cffb89e0 ObjectTable: e54df078 HandleCount: 39.
Image: application.exe
PROCESS 85c60020 SessionId: 1 Cid: 53bc Peb: 7ffdf000 ParentCid: 44c8
DirBase: cffb8a40 ObjectTable: e1214e90 HandleCount: 39.
Image: application.exe
[...]
We can also see the very big number of handles in both csrss.exe and explorer.exe. If we look at one of 5,000 application.exe processes we would see that it is a GUI application and this explains session pool exhaustion:
1: kd> !process 85c60020 1f
PROCESS 85c60020 SessionId: 1 Cid: 53bc Peb: 7ffdf000 ParentCid: 44c8
DirBase: cffb8a40 ObjectTable: e1214e90 HandleCount: 39.
Image: application.exe
VadRoot 85c97450 Vads 80 Clone 0 Private 173. Modified 159. Locked 0.
DeviceMap e3743340
Token e2ead5e0
ElapsedTime 00:54:17.218
UserTime 00:00:00.015
KernelTime 00:00:00.000
QuotaPoolUsage[PagedPool] 32460
QuotaPoolUsage[NonPagedPool] 3200
Working Set Sizes (now,min,max) (30, 50, 345) (120KB, 200KB, 1380KB)
PeakWorkingSetSize 778
VirtualSize 16 Mb
PeakVirtualSize 17 Mb
PageFaultCount 829
MemoryPriority BACKGROUND
BasePriority 8
CommitCharge 212
THREAD 85c25db0 Cid 53bc.5470 Teb: 7ffde000 Win32Thread: bd1a18a8 WAIT: (Unknown) UserMode Non-Alertable
85bbf2a8 SynchronizationEvent
Not impersonating
DeviceMap e3743340
Owning Process 85c60020 Image: application.exe
Wait Start TickCount 1121133 Ticks: 206877 (0:00:53:52.453)
Context Switch Count 19355 NoStackSwap LargeStack
UserTime 00:00:00.015
KernelTime 00:00:00.000
Win32 Start Address application (0x00402a38)
Start Address kernel32!BaseProcessStartThunk (0x7c8217f8)
Stack Init ad2b8000 Current ad2b7b1c Base ad2b8000 Limit ad2b4000 Call 0
Priority 8 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr
ad2b7b34 80833ec5 nt!KiSwapContext+0x26
ad2b7b60 80829bc0 nt!KiSwapThread+0x2e5
ad2b7ba8 bf89aacc nt!KeWaitForSingleObject+0x346
ad2b7c04 bf8c4816 win32k!xxxSleepThread+0×1be
ad2b7ca0 bf8a134f win32k!xxxInterSendMsgEx+0×798
ad2b7cec bf85ae3c win32k!xxxSendMessageTimeout+0×1f3
ad2b7d10 bf8c13dc win32k!xxxWrapSendMessage+0×1b
ad2b7d40 8088ad3c win32k!NtUserMessageCall+0×9d
ad2b7d40 7c9485ec nt!KiFastCallEntry+0xfc (TrapFrame @ ad2b7d64)
0012f814 00000000 ntdll!KiFastSystemCallRet
We also see extremely high executive resource contention and various signs of a busy system like the fact that all processors are busy and very high number of ready threads at normal priority (about 1,000):
1: kd> !locks
**** DUMP OF ALL RESOURCE OBJECTS ****
Resource @ DriverA (0xbae016a0) Exclusively owned
Contention Count = 277088870
NumberOfExclusiveWaiters = 3591
Threads: 83b46db0-01<*> << Too many exclusive waiters to list>>
1: kd> !running
System Processors ff (affinity mask)
Idle Processors 0
Prcb Current Next
0 ffdff120 86300b40 …………….
1 f772f120 f77320a0 852fadb0 …………….
2 f7737120 f773a0a0 861528d0 …………….
3 f773f120 f77420a0 877a4020 …………….
4 f7747120 f774a0a0 865909a8 …………….
5 f774f120 f77520a0 83d62cd0 …………….
6 f7757120 f775a0a0 841aa020 …………….
7 f775f120 f77620a0 ffb7b5e0 …………….
1: kd> !ready
Processor 0: No threads in READY state
Processor 1: Ready Threads at priority 10
THREAD 861b1898 Cid 4860.4894 Teb: 7ffd8000 Win32Thread: bc1669a8 READY
Processor 1: Ready Threads at priority 9
THREAD 83b46db0 Cid 44c8.a11c Teb: 7f8f8000 Win32Thread: bcbabb38 READY
Processor 1: Ready Threads at priority 8
THREAD 851408d0 Cid 6338.6398 Teb: 7ffdf000 Win32Thread: bc9bfbb8 READY
THREAD 83eb1730 Cid 8f30.9568 Teb: 7ffdf000 Win32Thread: 00000000 READY
THREAD fd310af8 Cid d53c.b4d8 Teb: 7ffdf000 Win32Thread: 00000000 READY
THREAD 83bce8d0 Cid abec.6450 Teb: 7ffdd000 Win32Thread: 00000000 READY
THREAD 83de2388 Cid a618.d79c Teb: 7ffde000 Win32Thread: 00000000 READY
THREAD 84197b40 Cid 44c8.6974 Teb: 7fe6a000 Win32Thread: bc662d48 READY
[…]
Processor 1: Ready Threads at priority 7
THREAD 86d0c890 Cid 3524.365c Teb: 7ff8e000 Win32Thread: bc403bb0 READY
Processor 2: No threads in READY state
Processor 3: No threads in READY state
Processor 4: No threads in READY state
Processor 5: No threads in READY state
Processor 6: No threads in READY state
Processor 7: No threads in READY state
There is AnotherApp.exe in the session process list that executes a VBS script:
1: kd> .process /r /p 86083020
Implicit process is now 86083020
Loading User Symbols
1: kd> !process 86083020
[...]
THREAD 860b0db0 Cid 4560.4e4c Teb: 7ffdd000 Win32Thread: bc1bf4d0 WAIT: (Unknown) KernelMode Non-Alertable
860b0e28 NotificationTimer
1: kd> .thread 860b0db0
Implicit thread is now 860b0db0
1: kd> kv 100
ChildEBP RetAddr Args to Child
ae7ec76c 80833ec5 860b0db0 860b0ea0 00000000 nt!KiSwapContext+0x26
ae7ec798 80829069 0000001e 00000000 bae016a0 nt!KiSwapThread+0x2e5
ae7ec7e0 badff394 00000000 00000000 ffdff5f0 nt!KeDelayExecutionThread+0x2ab
[...]
0012f6ac 7c8024d5 00000000 00000000 00a43280 kernel32!CreateProcessInternalA+0x28b
0012f6e4 00401b31 00000000 00a43280 00000000 kernel32!CreateProcessA+0×2c
[…]
1: kd> da /c 100 00a43280
00a43280 “wscript.exe C:\Scripts\script.vbs parameters”
The examination of that script showed that it contained a coding error resulted in an infinite loop.
- Dmitry Vostokov @ DumpAnalysis.org -
_1125.png)
Coming Soon:
Debugging Notebook: Essential Concepts, WinDbg Commands and Tools
Crash Dump Analysis for System Administrators and Support Engineers
New Magazines:
Debugged! MZ/PE: MagaZine for/from Practicing Engineers
New Books:
Memory Dump Analysis Anthology, Volume 3
First Fault Software Problem Solving: A Guide for Engineers, Managers and Users
x64 Windows Debugging: Practical Foundations
Also available:
Windows Debugging: Practical Foundations
DLL List Landscape: The Art from Computer Memory Space
Dumps, Bugs and Debugging Forensics: The Adventures of Dr. Debugalov
WinDbg: A Reference Poster and Learning Cards
Memory Dump Analysis Anthology, Volume 2
Memory Dump Analysis Anthology, Volume 1
New Children's Book:
