Swarm of shared locks, blocked threads and waiting time: pattern cooperation
Here is further analysis of a memory dump used to illustrate Swarm of Shared Locks pattern. In that dump there were also exclusively held locks with many blocked threads:
Resource @ 0x8a04c408 Exclusively owned
Contention Count = 344875
NumberOfExclusiveWaiters = 6
Threads: 87eb3db0-01<*>
Threads Waiting On Exclusive Access:
88573db0 87b90378 86a49db0 891f4610
8662b020 87127db0
Resource @ 0x89678e80 Exclusively owned
Contention Count = 10261
NumberOfExclusiveWaiters = 2
Threads: 87eb3db0-01<*>
Threads Waiting On Exclusive Access:
89131bf0 88d12db0
Resource @ 0x88d099d8 Exclusively owned
Contention Count = 562811
NumberOfExclusiveWaiters = 4
Threads: 873611d8-01<*>
Threads Waiting On Exclusive Access:
88b8bb88 88a72c50 89359af0 88d865e8
Resource @ 0x86db9248 Exclusively owned
Contention Count = 1382269
NumberOfSharedWaiters = 2
NumberOfExclusiveWaiters = 11
Threads: 86ab2020-01<*> 8769cdb0-01 880c77b8-01
Threads Waiting On Exclusive Access:
87bf4020 890dc020 874c01c0 884ef020
86913af8 875bab10 88e8a0d8 8923cdb0
894eca18 86aa6830 86f293a8
Resource @ 0x873a88d0 Exclusively owned
Contention Count = 719758
NumberOfExclusiveWaiters = 8
Threads: 88d5f990-01<*>
Threads Waiting On Exclusive Access:
8759ea88 871b6db0 88117710 87cb4718
883eb638 87239020 881ad020 891b9188
Resource @ 0x88c379a0 Exclusively owned
Contention Count = 126686
NumberOfSharedWaiters = 1
NumberOfExclusiveWaiters = 8
Threads: 882b8020-01<*> 88951520-01
Threads Waiting On Exclusive Access:
877d34a8 8939fdb0 87fc5668 8851fdb0
86fad850 87f1f450 8a1749f0 876a78d0
Resource @ 0x88ca9250 Exclusively owned
Contention Count = 319721
NumberOfExclusiveWaiters = 4
Threads: 88607908-01<*>
Threads Waiting On Exclusive Access:
86829370 892ae8e8 87205208 87b6d7e0
Resource @ 0x86a90ef8 Exclusively owned
Contention Count = 852830
NumberOfExclusiveWaiters = 12
Threads: 87571640-01<*>
Threads Waiting On Exclusive Access:
88a9c9b0 88a50db0 87117928 890e4c50
874ffb30 88b540f8 8705d020 8687edb0
87143188 8703e430 885b6aa0 8842bc50
Resource @ 0x88954538 Exclusively owned
Contention Count = 40708
NumberOfExclusiveWaiters = 1
Threads: 87571640-01<*>
Threads Waiting On Exclusive Access:
878ee980
Resource @ 0x88617eb8 Exclusively owned
Contention Count = 43531
NumberOfExclusiveWaiters = 2
Threads: 87571640-01<*>
Threads Waiting On Exclusive Access:
88851db0 87382c50
Resource @ 0x87288bc8 Exclusively owned
Contention Count = 644675
NumberOfExclusiveWaiters = 2
Threads: 874e4508-01<*>
Threads Waiting On Exclusive Access:
88863b08 89479650
Resource @ 0x87c3d8b0 Exclusively owned
Contention Count = 335064
NumberOfExclusiveWaiters = 8
Threads: 87f44520-01<*>
Threads Waiting On Exclusive Access:
88277190 88eceb48 87f0d308 8694d460
88461db0 876734a8 871721b0 88c2adb0
All threads owning various locks exclusively are stuck in processing page fault code, for example:
0: kd> !thread 87eb3db0 1f
THREAD 87eb3db0 Cid 47ac.57c8 Teb: 7ffd7000 Win32Thread: bc151230 WAIT: (Unknown) KernelMode Non-Alertable
8743e4e0 NotificationEvent
IRP List:
8660c900: (0006,0094) Flags: 00000900 Mdl: 00000000
Not impersonating
DeviceMap e1003890
Owning Process 88e49918 Image: csrss.exe
Wait Start TickCount 15420972 Ticks: 2527 (0:00:00:39.484)
Context Switch Count 1430991 LargeStack
UserTime 00:00:00.000
KernelTime 00:00:02.734
Start Address 0×75a8e96c
Stack Init a3cf7000 Current a3cf6430 Base a3cf7000 Limit a3cf4000 Call 0
Priority 14 BasePriority 13 PriorityDecrement 0
ChildEBP RetAddr
a3cf6448 8083d5b1 nt!KiSwapContext+0×26
a3cf6474 8083df9e nt!KiSwapThread+0×2e5
a3cf64bc 8082629e nt!KeWaitForSingleObject+0×346
a3cf64e4 80826480 nt!MiWaitForInPageComplete+0×1f
a3cf656c 8084790e nt!MiDispatchFault+0xda3
a3cf65c8 80836c2a nt!MmAccessFault+0×64a
a3cf65c8 bfa38de0 nt!KiTrap0E+0xdc (TrapFrame @ a3cf65e0)
a3cf6a24 bf854a72 win32k!vSetPointer+0×36f
a3cf6a50 bf8b1b74 win32k!GreSetPointer+0×66
a3cf6a7c bf883183 win32k!zzzUpdateCursorImage+0×1cc
a3cf6a8c bf884b06 win32k!zzzSetFMouseMoved+0xd5
a3cf6ad4 bf81530a win32k!ProcessQueuedMouseEvents+0×1c4
a3cf6d30 bf86fd25 win32k!RawInputThread+0×5b4
a3cf6d40 bf898a52 win32k!xxxCreateSystemThreads+0×60
a3cf6d54 80833bef win32k!NtUserCallOneParam+0×23
a3cf6d54 7c8285ec nt!KiFastCallEntry+0xfc (TrapFrame @ a3cf6d64)
0: kd> !thread 87571640 1f
THREAD 87571640 Cid 49f4.65b4 Teb: 7ffdf000 Win32Thread: bc011680 WAIT: (Unknown) KernelMode Non-Alertable
8870db90 NotificationEvent
Not impersonating
DeviceMap e24f6570
Owning Process 87be4a00 Image: ApplicationC.EXE
Wait Start TickCount 15420974 Ticks: 2525 (0:00:00:39.453)
Context Switch Count 25640 LargeStack
UserTime 00:00:00.921
KernelTime 00:00:03.859
Win32 Start Address 0×30002658
Start Address 0×77e617f8
Stack Init 9a318600 Current 9a317b70 Base 9a319000 Limit 9a314000 Call 9a31860c
Priority 14 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr
9a317b88 8083d5b1 nt!KiSwapContext+0×26
9a317bb4 8083df9e nt!KiSwapThread+0×2e5
9a317bfc 8082629e nt!KeWaitForSingleObject+0×346
9a317c24 80826480 nt!MiWaitForInPageComplete+0×1f
9a317cac 8084790e nt!MiDispatchFault+0xda3
9a317d08 80836c2a nt!MmAccessFault+0×64a
9a317d08 bf8b5485 nt!KiTrap0E+0xdc (TrapFrame @ 9a317d20)
9a317db4 bf8b526c win32k!vSolidFillRect1+0xb0
9a317f58 bf8ad7d2 win32k!vDIBSolidBlt+0×102
9a317fc4 bfa285d1 win32k!EngBitBlt+0xe1
9a3180c8 bf899b57 win32k!GrePatBltLockedDC+0×1ea
9a318160 bf8b32bb win32k!GrePolyPatBltInternal+0×17c
9a31819c bf8bd71c win32k!GrePolyPatBlt+0×45
9a31822c bf85e3d5 win32k!DrawEdge+0×23a
9a318274 bf8ae338 win32k!xxxDrawWindowFrame+0×170
9a3182d4 bf8847d1 win32k!xxxRealDefWindowProc+0×7a7
9a3182ec bf884801 win32k!xxxWrapRealDefWindowProc+0×16
9a318308 bf8c1769 win32k!NtUserfnDWORD+0×27
9a318340 80833bef win32k!NtUserMessageCall+0xc0
9a318340 7c8285ec nt!KiFastCallEntry+0xfc (TrapFrame @ 9a318364)
We also see that their waiting time is almost the same, 39 seconds. This means that the problem with paging probably started at that time before the crash dump was forced.
- Dmitry Vostokov @ DumpAnalysis.org -