Crash Dump Analysis Patterns (Part 42b)
CARE: Crash Analysis Report Environment
DATA (Dump Analysis + Trace Analysis) Facebook group
Please join the community of memory (dump) and trace analysis engineers. This group promotes scientific methods and memory dump-based worldview.
Twitter @ DumpAnalysis You can now follow portal and blog news at DumpAnalysis on Twitter
LinkedIn Group Dr. Watson Enthusiasts All about Dr. Watson errors and more. Get news, excerpts and progress reports about the forthcoming book The Science of Dr. Watson: An Illustrated History of Debugging (ISBN 978-1906717070)
2010 (0x7DA) - The Year of Dump Analysis 2011 (0x7DB) - 2020 (0x7E4) The Debugging Decade
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 -
_1125.png)
Coming Soon:
Debugging Notebook: Essential Concepts, WinDbg Commands and Tools
Crash Dump Analysis for System Administrators and Support Engineers
New Magazines:
Debugged! MZ/PE: MagaZine for/from Practicing Engineers
New Books:
Memory Dump Analysis Anthology, Volume 3
First Fault Software Problem Solving: A Guide for Engineers, Managers and Users
x64 Windows Debugging: Practical Foundations
Also available:
Windows Debugging: Practical Foundations
DLL List Landscape: The Art from Computer Memory Space
Dumps, Bugs and Debugging Forensics: The Adventures of Dr. Debugalov
WinDbg: A Reference Poster and Learning Cards
Memory Dump Analysis Anthology, Volume 2
Memory Dump Analysis Anthology, Volume 1
New Children's Book:
July 30th, 2008 at 12:44 am
[…] 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 […]
January 26th, 2009 at 1:24 am
[…] 117 and 13 were waiting for a critical section […]
March 14th, 2009 at 8:37 am
[…] As usual the critical section list was checked for any locked sections and to find wait chains: […]
July 3rd, 2009 at 4:42 pm
[…] 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 […]
September 18th, 2009 at 12:15 pm
[…] Wait Chain (critical sections) […]
October 9th, 2009 at 2:32 pm
[…] 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 […]