Crash Dump Analysis Patterns (Part 42b)
Wednesday, December 19th, 2007Here is another example of Wait Chain pattern where objects are critical sections.
WinDbg can detect them if we use !analyze -v -hang command but it detects only one and not necessarily the longest or widest chain in cases with multiple wait chains:
DERIVED_WAIT_CHAIN:
Dl Eid Cid WaitType
-- --- ------- --------------------------
2 8d8.90c Critical Section -->
4 8d8.914 Critical Section -->
66 8d8.f9c Unknown
Looking at threads we see this chain and we also see that the final thread is blocked waiting for socket.
0:167> ~~[90c]kvL
ChildEBP RetAddr Args to Child
00bbfd9c 7c942124 7c95970f 00000ea0 00000000 ntdll!KiFastSystemCallRet
00bbfda0 7c95970f 00000ea0 00000000 00000000 ntdll!NtWaitForSingleObject+0xc
00bbfddc 7c959620 00000000 00000004 00000000 ntdll!RtlpWaitOnCriticalSection+0x19c
00bbfdfc 6748d2f9 06018b50 00000000 00000000 ntdll!RtlEnterCriticalSection+0xa8
…
…
…
00bbffb8 7c82608b 00315218 00000000 00000000 msvcrt!_endthreadex+0xa3
00bbffec 00000000 77b9b4bc 00315218 00000000 kernel32!BaseThreadStart+0×34
0:167> ~~[914]kvL 100
ChildEBP RetAddr Args to Child
00dbf1cc 7c942124 7c95970f 000004b0 00000000 ntdll!KiFastSystemCallRet
00dbf1d0 7c95970f 000004b0 00000000 00000000 ntdll!NtWaitForSingleObject+0xc
00dbf20c 7c959620 00000000 00000004 0031abcc ntdll!RtlpWaitOnCriticalSection+0x19c
00dbf22c 6748d244 0031abd8 003174e0 00dbf254 ntdll!RtlEnterCriticalSection+0xa8
…
…
…
00dbffb8 7c82608b 00315218 00000000 00000000 msvcrt!_endthreadex+0xa3
00dbffec 00000000 77b9b4bc 00315218 00000000 kernel32!BaseThreadStart+0×34
0:167> ~~[f9c]kvL 100
ChildEBP RetAddr Args to Child
0fe2a09c 7c942124 71933a09 00000b50 00000001 ntdll!KiFastSystemCallRet
0fe2a0a0 71933a09 00000b50 00000001 0fe2a0c8 ntdll!NtWaitForSingleObject+0xc
0fe2a0dc 7194576e 00000b50 00000234 00000000 mswsock!SockWaitForSingleObject+0x19d
0fe2a154 71a12679 00000234 0fe2a1b4 00000001 mswsock!WSPRecv+0x203
0fe2a190 62985408 00000234 0fe2a1b4 00000001 WS2_32!WSARecv+0x77
0fe2a1d0 6298326b 00000234 0274ebc6 00000810 component!wait+0x338
...
...
...
0fe2ffb8 7c82608b 060cfc70 00000000 00000000 msvcrt!_endthreadex+0xa3
0fe2ffec 00000000 77b9b4bc 060cfc70 00000000 kernel32!BaseThreadStart+0x34
If we look at all held critical sections we would see another thread that blocked +125 other threads:
0:167> !locks
CritSec +31abd8 at 0031abd8
WaiterWoken No
LockCount 6
RecursionCount 1
OwningThread f9c
EntryCount 0
ContentionCount 17
*** Locked
CritSec +51e4bd8 at 051e4bd8
WaiterWoken No
LockCount 125
RecursionCount 1
OwningThread 830
EntryCount 0
ContentionCount 7d
*** Locked
CritSec +5f40620 at 05f40620
WaiterWoken No
LockCount 0
RecursionCount 1
OwningThread 920
EntryCount 0
ContentionCount 0
*** Locked
CritSec +60b6320 at 060b6320
WaiterWoken No
LockCount 1
RecursionCount 1
OwningThread 8a8
EntryCount 0
ContentionCount 1
*** Locked
CritSec +6017c60 at 06017c60
WaiterWoken No
LockCount 0
RecursionCount 1
OwningThread 914
EntryCount 0
ContentionCount 0
*** Locked
CritSec +6018b50 at 06018b50
WaiterWoken No
LockCount 3
RecursionCount 1
OwningThread 914
EntryCount 0
ContentionCount 3
*** Locked
CritSec +6014658 at 06014658
WaiterWoken No
LockCount 2
RecursionCount 1
OwningThread 928
EntryCount 0
ContentionCount 2
*** Locked
0:167> ~~[830]kvL 100
ChildEBP RetAddr Args to Child
0ff2f300 7c942124 7c95970f 000004b0 00000000 ntdll!KiFastSystemCallRet
0ff2f304 7c95970f 000004b0 00000000 00000000 ntdll!NtWaitForSingleObject+0xc
0ff2f340 7c959620 00000000 00000004 0031abcc ntdll!RtlpWaitOnCriticalSection+0x19c
0ff2f360 6748d244 0031abd8 003174e0 0ff2f388 ntdll!RtlEnterCriticalSection+0xa8
…
…
…
0ff2ffb8 7c82608b 060cf9a0 00000000 00000000 msvcrt!_endthreadex+0xa3
0ff2ffec 00000000 77b9b4bc 060cf9a0 00000000 kernel32!BaseThreadStart+0×34
Searching for any thread waiting for critical section 051e4bd8 gives us:
8 Id: 8d8.924 Suspend: 1 Teb: 7ffd5000 Unfrozen
ChildEBP RetAddr Args to Child
011ef8e0 7c942124 7c95970f 00000770 00000000 ntdll!KiFastSystemCallRet
011ef8e4 7c95970f 00000770 00000000 00000000 ntdll!NtWaitForSingleObject+0xc
011ef920 7c959620 00000000 00000004 00000000 ntdll!RtlpWaitOnCriticalSection+0x19c
011ef940 677b209d 051e4bd8 011efa0c 057bd36c ntdll!RtlEnterCriticalSection+0xa8
…
…
…
011effb8 7c82608b 00315510 00000000 00000000 msvcrt!_endthreadex+0xa3
011effec 00000000 77b9b4bc 00315510 00000000 kernel32!BaseThreadStart+0×34
and we can construct yet another wait chain:
8 8d8.924 Critical Section -->
67 8d8.830 Critical Section -->
66 8d8.f9c Unknown
- Dmitry Vostokov @ DumpAnalysis.org -