Crash Dump Analysis Patterns (Part 79)

Sometimes there are so many shared locks on the system that it might point to some problems in subsystems that own them. For example, there are two large swarms of them in this memory dump from a system running 90 user sessions:

0: kd> !session
Sessions on machine: 90

0: kd> !locks
**** DUMP OF ALL RESOURCE OBJECTS ****
KD: Scanning for held locks....

Resource @ nt!CmpRegistryLock (0x808ad4c0)    Shared 210 owning threads
    Contention Count = 1432
     Threads: 88bf1590-01<*> 8a78a660-01<*> 8a787660-01<*> 8825a3a8-01<*>
              89003358-01<*> 86723b90-01<*> 865bbb00-01<*> 89634638-01<*>
              888d9508-01<*> 88da6b48-01<*> 87db9db0-01<*> 86a9e610-01<*>
              89ff7410-01<*> 87450db0-01<*> 86bdedb0-01<*> 86d604c8-01<*>
              88d465d8-01<*> 86c3b6a0-01<*> 87c89020-01<*> 88e73db0-01<*>
              865fe5b0-01<*> 88450020-01<*> 86bd9db0-01<*> 8a73e838-01<*>
              88dc3db0-01<*> 88035708-01<*> 8833a2f0-01<*> 88608350-01<*>
              87aca020-01<*> 87e007c0-01<*> 86ec39b8-01<*> 893be1b8-01<*>
              8671ddb0-01<*> 8679a718-01<*> 89fe34c8-01<*> 86ccd720-01<*>
              881b1db0-01<*> 86771b20-01<*> 86d71db0-01<*> 89574db0-01<*>
              87dfac50-01<*> 86597020-01<*> 874b3488-01<*> 873b59b0-01<*>
              88e792f8-01<*> 878d2430-01<*> 8853d480-01<*> 889e2020-01<*>
              88c36db0-01<*> 8824f990-01<*> 8719b830-01<*> 884ba020-01<*>
              88e1d768-01<*> 89523db0-01<*> 896529f8-01<*> 887e2870-01<*>
              8a022db0-01<*> 867253a0-01<*> 865f0448-01<*> 87d35640-01<*>
              8715d968-01<*> 87ce0c50-01<*> 87d44730-01<*> 86d69aa8-01<*>
              88e5b020-01<*> 88734410-01<*> 898f2b40-01<*> 8a00a510-01<*>
              87e69db0-01<*> 8722b860-01<*> 86d8e308-01<*> 87263c50-01<*>
              8706ddb0-01<*> 892136e8-01<*> 8875b020-01<*> 8833ca48-01<*>
              8a100db0-01<*> 86b77590-01<*> 888bc020-01<*> 865c3db0-01<*>
              89fba910-01<*> 8a789660-01<*> 8670b2a8-01<*> 868737a8-01<*>
              868326d0-01<*> 871cdaf0-01<*> 8852edb0-01<*> 882b23b8-01<*>
              877e29e0-01<*> 8774f558-01<*> 876aa020-01<*> 89187518-01<*>
              8664b8e0-01<*> 865b4478-01<*> 88135020-01<*> 8686f020-01<*>
              866a0190-01<*> 87316758-01<*> 894dab18-01<*> 87938560-01<*>
              8658f5f0-01<*> 88e54020-01<*> 867f6350-01<*> 89246af8-01<*>
              86801430-01<*> 86db2af0-01<*> 865cf588-01<*> 86ab64f8-01<*>
              8a4a61e8-01<*> 885f3020-01<*> 86ea9af0-01<*> 8a4a7ba8-01<*>
              8a746b08-01<*> 89fc4790-01<*> 87093b10-01<*> 8659bc50-01<*>
              86681db0-01<*> 87102228-01<*> 866145a0-01<*> 866dddb0-01<*>
              86bda990-01<*> 88257db0-01<*> 8687d590-01<*> 867a9db0-01<*>
              89898848-01<*> 8a49b920-01<*> 86596db0-01<*> 8a0f7db0-01<*>
              866c1b40-01<*> 8754e020-01<*> 87fc1428-01<*> 8658c870-01<*>
              880d6a90-01<*> 88be6c50-01<*> 86bbcdb0-01<*> 8a37b8f8-01<*>
              866a13e0-01<*> 873e33d0-01<*> 87d43db0-01<*> 88a5adb0-01<*>
              884a5440-01<*> 883646f0-01<*> 87128020-01<*> 88e1d020-01<*>
              888e6418-01<*> 875c7c50-01<*> 871dd020-01<*> 890d5838-01<*>
              88d061f0-01<*> 88a09428-01<*> 8972f780-01<*> 87325b08-01<*>
              86deb020-01<*> 878b31b8-01<*> 891ac8a8-01<*> 86b234c0-01<*>
              86dd2190-01<*> 875f9db0-01<*> 87bbf200-01<*> 8a1a9c40-01<*>
              88628020-01<*> 87919020-01<*> 87c2a660-01<*> 877dc7c0-01<*>
              8a08adb0-01<*> 87c0f628-01<*> 87ca9a28-01<*> 8880a210-01<*>
              86ec0020-01<*> 88571020-01<*> 8a01edb0-01<*> 88115db0-01<*>
              87a9adb0-01<*> 879ecdb0-01<*> 8868ddb0-01<*> 872bcb58-01<*>
              884a0100-01<*> 8929f020-01<*> 87087020-01<*> 886e75a8-01<*>
              885a5908-01<*> 8762c020-01<*> 89550db0-01<*> 8a554768-01<*>
              89f10680-01<*> 87b322e8-01<*> 87cc74d0-01<*> 883ee2d0-01<*>
              8956caf8-01<*> 8788f330-01<*> 87d5c320-01<*> 86b99db0-01<*>
              876f42e0-01<*> 88e812d0-01<*> 8687cdb0-01<*> 8677a310-01<*>
              89711b40-01<*> 89b013a8-01<*> 86abcdb0-01<*> 89fd7bb0-01<*>
              877c22b0-01<*> 883fc850-01<*> 889e11f8-01<*> 892ff0e0-01<*>
              878ac490-01<*> 86de5c50-01<*> 87741db0-01<*> 8679f020-01<*>
              880ac6d0-01<*> 86d8fb00-01<*>
KD: Scanning for held locks….

Resource @ Ntfs!NtfsData (0xf71665b0)    Shared 1 owning threads
     Threads: 8a78d660-01<*>
KD: Scanning for held locks.

Resource @ 0x8a5c7734    Shared 1 owning threads
    Contention Count = 507565
    NumberOfSharedWaiters = 128
    NumberOfExclusiveWaiters = 1
     Threads: 894b4db0-01    87c773e0-01    88de7020-01    891c9db0-01   
              894d2020-01    865af5f8-01    87867340-01    88c964a0-01<*>
              88e57c98-01    87ae3020-01    86dbe730-01    88343790-01   
              871102e8-01    8855f020-01    87c99920-01    8796a318-01   
              88028db0-01    88ad6610-01    88b73db0-01    89fba3f0-01   
              87d8bc00-01    86f4c5c8-01    8a028608-01    88c783f0-01   
              88c138e0-01    89236910-01    896fbb78-01    88523600-01   
              8926f3b0-01    88a49a48-01    87c19750-01    86c88c50-01   
              88adfad8-01    872b0020-01    87ecab18-01    88b02020-01   
              875f9b10-01    8755e020-01    86f9fdb0-01    86a1cab8-01   
              86816858-01    881eedb0-01    894a99f0-01    87c97740-01   
              8a3bf4b0-01    867765a8-01    8a787660-01    86810330-01   
              876ad268-01    87af3320-01    865fedb0-01    88eb8230-01   
              86b0c438-01    881c0230-01    888b67c8-01    883e3210-01   
              87acbc50-01    873d6648-01    86ed0db0-01    88e2d020-01   
              89fdadb0-01    8934e830-01    870f89f0-01    8756c5e0-01   
              878c88d0-01    86fec608-01    88fdb420-01    87fa0628-01   
              87cad8d8-01    88ee3978-01    86fc49a0-01    875d5020-01   
              871a5020-01    89667a60-01    87170db0-01    88254ae0-01   
              8775e408-01    88204db0-01    87989890-01    873b89a8-01   
              888e6bf8-01    88cc3db0-01    88bf1590-01    879565a0-01   
              86773db0-01    8731a020-01    88aa7a78-01    8759cdb0-01   
              87e555f8-01    86de5678-01    86e28020-01    86ec9320-01   
              86871af0-01    8719cba0-01    8723f820-01    884dac20-01   
              89249020-01    889da168-01    8900b810-01    8a78d660-01   
              88cac758-01    892984c8-01    87d0c020-01    87ecec50-01   
              87ad8c90-01    88109aa8-01    86ef5bf0-01    8a78d3f0-01   
              88d2b020-01    88640db0-01    86fec878-01    895b12d8-01   
              86dd6708-01    87386930-01    888e34e0-01    86a56c50-01   
              8815f768-01    886c42a0-01    898f2020-01    87ca3610-01   
              886dd448-01    86ada210-01    8a37adb0-01    8896c940-01   
              8800e898-01    8733d4b8-01    865fa358-01    88ae1af0-01   
              868dd020-01   
     Threads Waiting On Exclusive Access:
              8a78b020
     

Both swarms are grouped around NTFS structures as can be seen from thread stack traces but also have another module in common: PGPsdk

0: kd> !thread 88bf1590 1f
THREAD 88bf1590  Cid 4354.2338  Teb: 7ffdf000 Win32Thread: bc3e88f8 WAIT: (Unknown) KernelMode Non-Alertable
    8a7a73d8  Semaphore Limit 0x7fffffff
    88bf1608  NotificationTimer
IRP List:
    86fb39d0: (0006,0268) Flags: 00000004  Mdl: 00000000
Not impersonating
DeviceMap                 e13c9ca0
Owning Process            869a6d88       Image:         ApplicationA.exe
Wait Start TickCount      15423469       Ticks: 30 (0:00:00:00.468)
Context Switch Count      6465                 LargeStack
UserTime                  00:00:00.343
KernelTime                00:00:01.062
Win32 Start Address 0x0056f122
Start Address 0x77e617f8
Stack Init 97e9d000 Current 97e9c788 Base 97e9d000 Limit 97e98000 Call 0
Priority 14 BasePriority 8 PriorityDecrement 6
ChildEBP RetAddr 
97e9c7a0 8083d5b1 nt!KiSwapContext+0x26
97e9c7cc 8083df9e nt!KiSwapThread+0x2e5
97e9c814 8081e05b nt!KeWaitForSingleObject+0x346
97e9c850 80824ba8 nt!ExpWaitForResource+0xd5
97e9c870 f718a07d nt!ExAcquireResourceSharedLite+0xf5
97e9c884 f717b2eb Ntfs!NtfsAcquireSharedVcb+0×23
97e9c8f0 f717a2e2 Ntfs!NtfsCommonFlushBuffers+0xf5
97e9c954 80840153 Ntfs!NtfsFsdFlushBuffers+0×92

97e9c968 f7272c45 nt!IofCallDriver+0×45
97e9c990 80840153 fltmgr!FltpDispatch+0×6f
97e9c9a4 f6fb1835 nt!IofCallDriver+0×45
WARNING: Stack unwind information not available. Following frames may be wrong.
97e9c9b8 f6fad69a PGPsdk+0×5835
97e9c9c4 80840153 PGPsdk+0×169a

86fb39d0 00000000 nt!IofCallDriver+0×45

0: kd> !thread 88c964a0 1f
THREAD 88c964a0  Cid 323c.43f0  Teb: 7ffad000 Win32Thread: bc2ceea8 WAIT: (Unknown) KernelMode Non-Alertable
    88268338  SynchronizationEvent
    88c96518  NotificationTimer
IRP List:
    86dad430: (0006,0268) Flags: 00000404  Mdl: 00000000
Not impersonating
DeviceMap                 e16c8eb0
Owning Process            8886ac88       Image:         ApplicationB.EXE
Wait Start TickCount      15423352       Ticks: 147 (0:00:00:02.296)
Context Switch Count      1660                 LargeStack
UserTime                  00:00:00.078
KernelTime                00:00:00.109
Win32 Start Address 0x14225c34
Start Address 0x77e617ec
Stack Init 96835000 Current 96834640 Base 96835000 Limit 96832000 Call 0
Priority 14 BasePriority 8 PriorityDecrement 6
ChildEBP RetAddr 
96834658 8083d5b1 nt!KiSwapContext+0x26
96834684 8083df9e nt!KiSwapThread+0x2e5
968346cc 8081e05b nt!KeWaitForSingleObject+0x346
96834708 8082e012 nt!ExpWaitForResource+0xd5
96834728 f714b89b nt!ExAcquireResourceExclusiveLite+0x8d
96834738 f718b194 Ntfs!NtfsAcquirePagingResourceExclusive+0×20
9683493c f718b8d9 Ntfs!NtfsCommonCleanup+0×193
96834aac 80840153 Ntfs!NtfsFsdCleanup+0xcf

96834ac0 f7272c45 nt!IofCallDriver+0×45
96834ae8 80840153 fltmgr!FltpDispatch+0×6f
96834afc f6fb196c nt!IofCallDriver+0×45
WARNING: Stack unwind information not available. Following frames may be wrong.
96834b10 f6fad69a PGPsdk+0×596c
96834b1c 80840153 PGPsdk+0×169a

86dad430 00000000 nt!IofCallDriver+0×45

Because no processors are busy except the one that processes crash dump request via NMI interrupt and there are no ready threads it would be natural to assume that the problem with paging started some time ago and some checks for 3rd-party volume encryption software are necessary as PGP name of the module suggests:

0: kd> lmv m PGPsdk
start    end        module name
f6fac000 f6fb7000   PGPsdk     (no symbols)          
    Loaded symbol image file: PGPsdk.sys
    Image path: \SystemRoot\System32\Drivers\PGPsdk.sys
    Image name: PGPsdk.sys
    Timestamp:        Wed Jun 09 11:44:04 2004 (40C6E9F4)
    CheckSum:         00010F72
    ImageSize:        0000B000
    Translations:     0000.04b0 0000.04e0 0409.04b0 0409.04e0

0: kd> !running

System Processors f (affinity mask)
  Idle Processors e

     Prcb      Current   Next   
  0  ffdff120  808a68c0  86841588  ................

0: kd> !thread 808a68c0 1f
THREAD 808a68c0  Cid 0000.0000  Teb: 00000000 Win32Thread: 00000000 RUNNING on processor 0
Not impersonating
Owning Process            808a6b40       Image:         Idle
Wait Start TickCount      0              Ticks: 15423499 (2:18:56:32.171)
Context Switch Count      100782385            
UserTime                  00:00:00.000
KernelTime                2 Days 12:18:49.343
Stack Init 808a38b0 Current 808a35fc Base 808a38b0 Limit 808a08b0 Call 0
Priority 0 BasePriority 0 PriorityDecrement 0
ChildEBP RetAddr 
808a07bc 80a84df7 nt!KeBugCheckEx+0x1b
808a080c 80834b83 hal!HalHandleNMI+0x1a5
808a080c 80a80853 nt!KiTrap02+0x136 (TrapFrame @ 808a0820)
808a3570 f7659ca2 hal!HalpClockInterrupt+0xff (TrapFrame @ 808a3570)
808a3600 80839b12 intelppm!AcpiC1Idle+0x12
808a3604 00000000 nt!KiIdleLoop+0xa

0: kd> !ready
Processor 0: No threads in READY state
Processor 1: No threads in READY state
Processor 2: No threads in READY state
Processor 3: No threads in READY state

- Dmitry Vostokov @ DumpAnalysis.org -

2 Responses to “Crash Dump Analysis Patterns (Part 79)”

  1. Crash Dump Analysis » Blog Archive » Swarm of shared locks, blocked threads and waiting time: pattern cooperation Says:

    […] Crash Dump Analysis Exploring Crash Dumps and Debugging Techniques on Windows Platforms « Crash Dump Analysis Patterns (Part 79) […]

  2. Crash Dump Analysis » Blog Archive » Crash Dump Analysis Patterns (Part 94a) Says:

    […] and of them is Size Deviation (a super pattern), be it a handle table size, a heap size, a  number of contended locks, time spent in kernel, and so on. Every system or process property has its average and mean values […]

Leave a Reply