Crash Dump Analysis Patterns (Part 42b)

Here 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 -

9 Responses to “Crash Dump Analysis Patterns (Part 42b)”

  1. Crash Dump Analysis » Blog Archive » Crash Dump Analysis Patterns (Part 73) Says:

    […] is too small unless we have obvious crash or hang signs inside, for example, exceptions, deadlock, wait chain or blocked thread waiting for another coupled […]

  2. Crash Dump Analysis » Blog Archive » Memory leak, spiking threads, wait chain, high critical section contention and module variety: pattern cooperation Says:

    […] 117 and 13 were waiting for a critical section […]

  3. Crash Dump Analysis » Blog Archive » Manual dump, wait chain, blocked thread, dynamic memory corruption and historical information: pattern cooperation Says:

    […] As usual the critical section list was checked for any locked sections and to find wait chains: […]

  4. Crash Dump Analysis » Blog Archive » 10 Common Mistakes in Memory Analysis (Part 4) Says:

    […] didn’t allow a user connection to proceed. If more users tried to connect we would have seen critical section wait chains that are absent in this […]

  5. Crash Dump Analysis » Blog Archive » Wait Chain Patterns Says:

    […] Wait Chain (critical sections) […]

  6. Crash Dump Analysis » Blog Archive » Critical section high contention and wait chains, blocked threads, and periodic error: memory dump and trace analysis pattern cooperation Says:

    […] problem was gone away. A complete memory dump was saved on the next occurrence and it revealed critical section wait chains in that process but no critical section […]

  7. Crash Dump Analysis » Blog Archive » Main thread, critical section wait chains, critical section deadlock, stack trace collection, execution residue, data contents locality, self-diagnosis and not my version: pattern cooperation Says:

    […] spooler service process was hanging and its user memory dump shows many threads blocked waiting for critical sections including the main […]

  8. Crash Dump Analysis » Blog Archive » Strong process coupling, stack trace collection, critical section coruption and wait chains, message box, self-diagnosis and hidden exception and dynamic memory corruption: pattern cooperation Says:

    […] command shows wait chains and signs of critical section corruption. Here is the commented […]

  9. Crash Dump Analysis » Blog Archive » Stack trace collection, special process, LPC and critical section wait chains, blocked thread, coupled machines, thread waiting time and IRP distribution anomaly: pattern cooperation Says:

    […] order to get a critical section wait chain starting from the above thread we need to set the process context, use !cs WinDbg command, then […]

Leave a Reply