Crash Dump Analysis Patterns (Part 29)
Some Windows synchronization objects like executive resources and critical sections have a struct member called ContentionCount. This is the number of times a resource was accessed or, in another words, it is the accumulated number of threads waiting for an object: when a thread tries to acquire an object and put into a wait state the count is incremented. Hence the name of this pattern: High Contention.
Here is an example. In a kernel memory dump we have just one exclusively owned lock and seems no other threads were blocked by it at the time the dump was saved. However the high contention count reveals CPU spike:
3: kd> !locks
**** DUMP OF ALL RESOURCE OBJECTS ****
KD: Scanning for held locks...
Resource @ 0x8abc11f0 Exclusively owned
Contention Count = 19648535
Threads: 896395f8-01<*>
KD: Scanning for held locks…
Resource @ 0x896fab88 Shared 1 owning threads
Threads: 88c78608-01<*>
KD: Scanning for held locks...
15464 total locks, 2 locks currently held
3: kd> !thread 896395f8
THREAD 896395f8 Cid 04c0.0138 Teb: 7ffde000 Win32Thread: bc922d20 RUNNING on processor 1
Not impersonating
DeviceMap e3d4c008
Owning Process 8a035020 Image: MyApp.exe
Wait Start TickCount 36969283 Ticks: 0
Context Switch Count 1926423 LargeStack
UserTime 00:00:53.843
KernelTime 00:13:10.703
Win32 Start Address 0×00401478
Start Address 0×77e617f8
Stack Init ba14b000 Current ba14abf8 Base ba14b000 Limit ba146000 Call 0
Priority 11 BasePriority 6 PriorityDecrement 5
ChildEBP RetAddr Args to Child
ba14ac94 bf8c6505 001544c8 bf995948 000c000a nt!_wcsicmp+0×3a (FPO: [Non-Fpo])
ba14ace0 bf8c6682 00000000 00000000 00000000 win32k!_FindWindowEx+0xfb (FPO: [Non-Fpo])
ba14ad48 8088978c 00000000 00000000 0012f8d4 win32k!NtUserFindWindowEx+0xef (FPO: [Non-Fpo])
ba14ad48 7c8285ec 00000000 00000000 0012f8d4 nt!KiFastCallEntry+0xfc (FPO: [0,0] TrapFrame @ ba14ad64)
3: kd> !process 8a035020
PROCESS 8a035020 SessionId: 9 Cid: 04c0 Peb: 7ffdf000 ParentCid: 10e8
DirBase: cffaf7a0 ObjectTable: e4ba30a0 HandleCount: 73.
Image: MyApp.exe
VadRoot 88bc1bf8 Vads 82 Clone 0 Private 264. Modified 0. Locked 0.
DeviceMap e3d4c008
Token e5272028
ElapsedTime 00:14:19.360
UserTime 00:00:53.843
KernelTime 00:13:10.703
QuotaPoolUsage[PagedPool] 40660
QuotaPoolUsage[NonPagedPool] 3280
Working Set Sizes (now,min,max) (1139, 50, 345) (4556KB, 200KB, 1380KB)
PeakWorkingSetSize 1141
VirtualSize 25 Mb
PeakVirtualSize 27 Mb
PageFaultCount 1186
MemoryPriority BACKGROUND
BasePriority 6
CommitCharge 315
- Dmitry Vostokov @ DumpAnalysis.org -
July 9th, 2008 at 1:51 pm
In user space we can see contention too:
0:070> !locks
CritSec +32b870 at 0032b870
WaiterWoken No
LockCount 0
RecursionCount 1
OwningThread 6f8c
EntryCount 0
ContentionCount 7f3c6
*** Locked
CritSec +3680a50 at 03680a50
WaiterWoken No
LockCount 0
RecursionCount 1
OwningThread 6f8c
EntryCount 0
ContentionCount 0
*** Locked
CritSec +261f86c at 0261f86c
WaiterWoken No
LockCount 0
RecursionCount 1
OwningThread 6f8c
EntryCount 0
ContentionCount 0
*** Locked
Scanned 3248 critical sections
September 10th, 2008 at 2:46 pm
[…] we discussed High Contention pattern in kernel mode involving executive resources. The same pattern can be observed in user […]
June 3rd, 2010 at 11:22 pm
[…] see High Contention (executive resources) pattern. What we actually see is a runaway system […]
June 18th, 2010 at 10:47 am
[…] we introduce an icon for High Contention (executive resources) […]
August 13th, 2010 at 7:10 pm
[…] 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 […]
September 21st, 2010 at 10:46 am
[…] High Contention (executive resources) […]
March 22nd, 2013 at 1:20 pm
High contention may also be visible from non-locked objects too:
0: kd> !locks -v
**** DUMP OF ALL RESOURCE OBJECTS ****
Resource @ nt!ExpFirmwareTableResource (0xfffff80001a315c0) Available
Resource @ nt!PsLoadedModuleResource (0xfffff80001a596a0) Available
Resource @ nt!MmSectionExtendResource (0xfffff80001a59440) Available
Resource @ nt!MmSectionExtendSetResource (0xfffff80001a594c0) Available
Contention Count = 68
Resource @ nt!SepRmDbLock (0xfffff80001a2e340) Available
Contention Count = 1710
Resource @ nt!SepRmDbLock (0xfffff80001a2e3a8) Available
Contention Count = 387
Resource @ nt!SepRmDbLock (0xfffff80001a2e410) Available
Contention Count = 256
Resource @ nt!SepRmDbLock (0xfffff80001a2e478) Available
Contention Count = 212
Resource @ nt!SepRmGlobalSaclLock (0xfffff80001a2e4e0) Available
Resource @ nt!SepLsaAuditQueueInfo (0xfffff80001a2e240) Available
Resource @ nt!SepLsaDeletedLogonQueueInfo (0xfffff80001a2e0e0) Available
Resource @ 0xfffffa804dc09920 Available
Resource @ nt!PnpRegistryDeviceResource (0xfffff80001a8f9e0) Available
Contention Count = 23562
Resource @ nt!PopPolicyLock (0xfffff80001a3b9e0) Available
Contention Count = 19
Resource @ 0xfffffa80b04008d0 Available
Resource @ 0xfffffa80b0400850 Available
Resource @ CI!g_StoreLock (0xfffff88000c05cc0) Available
Resource @ nt!CmpRegistryLock (0xfffff80001a10000) Available
Contention Count = 21297917
[…]