Archive for February 9th, 2007

Crash Dump Analysis Patterns (Part 9a)

Friday, February 9th, 2007

Next pattern is Deadlock. If you don’t know what “deadlock” is read Dumps for Dummes (Part 4). Deadlocks do not only happen with synchronization primitives like mutexes, events or more complex objects (built upon primitives) like critical sections or executive resources (ERESOURCE). They can happen from high level or systems perspective in inter-process or inter-component communication, for example, mutually waiting on messages: GUI window messages, LPC messages, RPC calls. This is a big pattern and I’m going to split it into several parts.

How can we see deadlocks in dumps? Let’s start with user dumps and critical sections.

First I would recommend to read the following excellent MSDN article to understand various members of CRITICAL_SECTION structure:

Break Free of Code Deadlocks in Critical Sections Under Windows

WinDbg !locks command will examine process critical section list and display all locked critical sections, lock count and thread id of current critical section owner. This is the output from a dump of hanging Windows print spooler process (spoolsv.exe):

0:000> !locks
CritSec NTDLL!LoaderLock+0 at 784B0348
LockCount          4
RecursionCount     1
OwningThread       624
EntryCount         6c3
ContentionCount    6c3
*** Locked

CritSec LOCALSPL!SpoolerSection+0 at 76AB8070
LockCount          3
RecursionCount     1
OwningThread       1c48
EntryCount         646
ContentionCount    646
*** Locked

If we look at threads #624 and #1c48 we could see them mutually waiting for each other:

  • TID#624 owns CritSec 784B0348 and is waiting for CritSec 76AB8070

  • TID#1c48 owns CritSec 76AB8070 and is waiting for CritSec 784B0348


. 12 Id: bc0.624 Suspend: 1 Teb: 7ffd3000 Unfrozen
0000024c 00000000 00000000 NTDLL!ZwWaitForSingleObject+0xb
76ab8000 76a815ef 76ab8070 NTDLL!RtlpWaitForCriticalSection+0×9e
76ab8070 76a844f8 00cd1f38 NTDLL!RtlEnterCriticalSection+0×46
00cd1f38 76a8a1d7 00000000 LOCALSPL!EnterSplSem+0xb
00000000 00000000 00cd1f38 LOCALSPL!FindSpoolerByNameIncRef+0×1f
00000000 777f19bc 00000001 LOCALSPL!LocalGetPrinterDriverDirectory+0xe
00000000 777f19bc 00000001 spoolss!GetPrinterDriverDirectoryW+0×59
00000000 777f19bc 00000001 spoolsv!YGetPrinterDriverDirectory+0×27
00000000 777f19bc 00000001 WINSPOOL!GetPrinterDriverDirectoryW+0×7b
50000000 00000001 00000000 BRHLUI04+0×14ea
50002ea0 50000000 00000001 BRHLUI04!DllGetClassObject+0×1705
00000000 00000000 000cb570 NTDLL!LdrpRunInitializeRoutines+0×1df
000cc8f8 0288ea30 0288ea38 NTDLL!LdrpLoadDll+0×2e6
000cc8f8 0288ea30 0288ea38 NTDLL!LdrLoadDll+0×17)
000c1258 00000000 00000008 KERNEL32!LoadLibraryExW+0×231
000c150c 0288efd8 00000000 UNIDRVUI!PLoadCommonInfo+0×17e
000c150c 0288efd8 00000007 UNIDRVUI!DwDeviceCapabilities+0×1a
00070000 00071378 00000045 UNIDRVUI!DrvDeviceCapabilities+0×19

. 13 Id: bc0.1c48 Suspend: 1 Teb: 7ffd2000 Unfrozen
0000010c 00000000 00000000 NTDLL!ZwWaitForSingleObject+0xb
784b0301 78468d38 784b0348 NTDLL!RtlpWaitForCriticalSection+0×9e
784b0348 74fb4344 00000000 NTDLL!RtlEnterCriticalSection+0×46
74fb0000 02c0f2a8 00000000 NTDLL!LdrpGetProcedureAddress+0×122
74fb0000 02c0f2a8 00000000 NTDLL!LdrGetProcedureAddress+0×17
74fb0000 74fb4344 02c0f449 KERNEL32!GetProcAddress+0×41
017924b0 00000000 00000001 ws2_32!CheckForHookersOrChainers+0×1f
00000101 02c0f344 017924b0 ws2_32!WSAStartup+0×10f
00cdf79c 02c0f4f4 76a8c9bc LOCALSPL!GetDNSMachineName+0×1e
00000000 76a8c9bc 780276a2 LOCALSPL!GetPrinterUrl+0×2c
0176f570 ffffffff 01000000 LOCALSPL!UpdateDsSpoolerKey+0×322
0176f570 76a8c9bc 01792b90 LOCALSPL!RecreateDsKey+0×50
00000000 00000002 01792b90 LOCALSPL!SplAddPrinter+0×521
01791faa 0176a684 76a5cd34 WIN32SPL!InternalAddPrinterConnection+0×1b4
01791faa 02c0fa00 02c0fabc WIN32SPL!AddPrinterConnectionW+0×15
00076f1c 02c0fabc 01006873 spoolss!AddPrinterConnectionW+0×49
00076f1c 00000001 77107fb0 spoolsv!YAddPrinterConnection+0×17
00076f1c 02020202 00000001 spoolsv!RpcAddPrinterConnection+0xb
01006868 02c0fac0 00000001 rpcrt4!Invoke+0×30
00000000 00000000 000d22c8 rpcrt4!NdrStubCall2+0×655
000d22c8 00076fe0 000d22c8 rpcrt4!NdrServerCall2+0×17
010045fc 000d22c8 02c0fe0c rpcrt4!DispatchToStubInC+0×32
0000002b 00000000 02c0fe0c rpcrt4!RPC_INTERFACE::DispatchToStubWorker+0×100
000d22c8 00000000 02c0fe0c rpcrt4!RPC_INTERFACE::DispatchToStub+0×5e
000d3210 00076608 813b0013 rpcrt4!LRPC_SCALL::DealWithRequestMessage+0×1dd
000d21d0 02c0fe50 000d3210 rpcrt4!LRPC_ADDRESS::DealWithLRPCRequest+0×10c
770c9ad0 00076608 770cb6d8 rpcrt4!LRPC_ADDRESS::ReceiveLotsaCalls+0×229
00076608 770cb6d8 0288f9a8 rpcrt4!RecvLotsaCallsWrapper+0×9
00074a50 02c0ffec 77e7438b rpcrt4!BaseCachedThreadRoutine+0×11f
00076e68 770cb6d8 0288f9a8 rpcrt4!ThreadStartRoutine+0×18
770d1c54 00076e68 00000000 KERNEL32!BaseThreadStart+0×52

This analysis looks pretty simple and easy. What about kernel and complete memory dumps? Of course we cannot see user space critical sections in kernel memory dumps but we can see them in complete memory dumps after switching to appropriate process context and using !ntsdexts.locks. This can be done via simple script adapted from debugger.chm: Deadlocks and Critical Sections

Why it is so easy to see deadlocks when critical sections are involved? Because their structures have a member that records their owner. So it is very easy to map them to corresponding threads. The same is with kernel ERESOURCE synchronization objects (we will see them in the next part). Other objects do not have an owner, for example, in case of events it is not so easy to find an owner just by looking at an event object. You need to examine thread call stacks, other structures or have access to source code.

- Dmitry Vostokov @ -