Crash Dump Analysis Patterns (Part 9g)

Now we illustrate a synchronization block deadlock pattern in managed code. Here we can use either manual !syncblk WinDbg command coupled stack trace and disassembly analysis or SOSEX extension !dlk command (which automates the whole detection process).

0:011> !syncblk
Index SyncBlock MonitorHeld Recursion Owning Thread Info  SyncBlock Owner
373 052cbf1c            3         1 08f69280   bc0  14   0a1ffd84 System.String
375 052cbd3c            3         1 08f68728   b6c  12   0a1ffd4c System.String

0:011> ~12s
[…]

0:012> k
ChildEBP RetAddr
WARNING: Stack unwind information not available. Following frames may be wrong.
09c8ebd0 79ed98fd ntdll!KiFastSystemCallRet
09c8ec38 79ed9889 mscorwks!WaitForMultipleObjectsEx_SO_TOLERANT+0x6f
09c8ec58 79ed9808 mscorwks!Thread::DoAppropriateAptStateWait+0x3c
09c8ecdc 79ed96c4 mscorwks!Thread::DoAppropriateWaitWorker+0x13c
09c8ed2c 79ed9a62 mscorwks!Thread::DoAppropriateWait+0x40
09c8ed88 79e78944 mscorwks!CLREvent::WaitEx+0xf7
09c8ed9c 79ed7b37 mscorwks!CLREvent::Wait+0x17
09c8ee28 79ed7a9e mscorwks!AwareLock::EnterEpilog+0x8c
09c8ee44 79ebd7e4 mscorwks!AwareLock::Enter+0x61
09c8eee4 074c1f38 mscorwks!JIT_MonEnterWorker_Portable+0xb3
09c8ef0c 793b0d1f 0×74c1f38
09c8ef14 79373ecd mscorlib_ni+0×2f0d1f
09c8ef28 793b0c68 mscorlib_ni+0×2b3ecd
09c8ef40 79e7c74b mscorlib_ni+0×2f0c68
09c8ef50 79e7c6cc mscorwks!CallDescrWorker+0×33
09c8efd0 79e7c8e1 mscorwks!CallDescrWorkerWithHandler+0xa3
09c8f110 79e7c783 mscorwks!MethodDesc::CallDescr+0×19c
09c8f12c 79e7c90d mscorwks!MethodDesc::CallTargetWorker+0×1f
09c8f140 79fc58cd mscorwks!MethodDescCallSite::Call_RetArgSlot+0×18
09c8f328 79ef3207 mscorwks!ThreadNative::KickOffThread_Worker+0×190
09c8f33c 79ef31a3 mscorwks!Thread::DoADCallBack+0×32a
09c8f3d0 79ef30c3 mscorwks!Thread::ShouldChangeAbortToUnload+0xe3
09c8f40c 79f01723 mscorwks!Thread::ShouldChangeAbortToUnload+0×30a
09c8f41c 79f02a5d mscorwks!Thread::RaiseCrossContextException+0×434
09c8f4cc 79f02ab7 mscorwks!Thread::DoADCallBack+0xda
09c8f4e8 79ef31a3 mscorwks!Thread::DoADCallBack+0×310
09c8f57c 79ef30c3 mscorwks!Thread::ShouldChangeAbortToUnload+0xe3
09c8f5b8 79ef4826 mscorwks!Thread::ShouldChangeAbortToUnload+0×30a
09c8f5e0 79fc57b1 mscorwks!Thread::ShouldChangeAbortToUnload+0×33e
09c8f5f8 79fc56ac mscorwks!ManagedThreadBase::KickOff+0×13
09c8f694 79f95a2e mscorwks!ThreadNative::KickOffThread+0×269
09c8fd34 76573833 mscorwks!Thread::intermediateThreadProc+0×49
09c8fd40 77c1a9bd kernel32!BaseThreadInitThunk+0xe
09c8fd80 00000000 ntdll!LdrInitializeThunk+0×4d

0:012> ub 074c1f38
074c1f11 eb10            jmp     074c1f23
074c1f13 8b0df8927b02    mov     ecx,dword ptr ds:[27B92F8h]
074c1f19 e8367ef271      call    mscorlib_ni+0×329d54 (793e9d54)
074c1f1e e89272a472      call    mscorwks!JIT_EndCatch (79f091b5)
074c1f23 b9d0070000      mov     ecx,7D0h
074c1f28 e8c432b072      call    mscorwks!ThreadNative::Sleep (79fc51f1)
074c1f2d 8b0d88dc7b02    mov     ecx,dword ptr ds:[27BDC88h]
074c1f33 e811389b72      call    mscorwks!JIT_MonEnterWorker (79e75749)

0:012> dp 27BDC88h l1
027bdc88  0a1ffd84

0:012> ~14s

0:014> k
ChildEBP RetAddr
WARNING: Stack unwind information not available. Following frames may be wrong.
0b83ed04 79ed98fd ntdll!KiFastSystemCallRet
0b83ed6c 79ed9889 mscorwks!WaitForMultipleObjectsEx_SO_TOLERANT+0x6f
0b83ed8c 79ed9808 mscorwks!Thread::DoAppropriateAptStateWait+0x3c
0b83ee10 79ed96c4 mscorwks!Thread::DoAppropriateWaitWorker+0x13c
0b83ee60 79ed9a62 mscorwks!Thread::DoAppropriateWait+0x40
0b83eebc 79e78944 mscorwks!CLREvent::WaitEx+0xf7
0b83eed0 79ed7b37 mscorwks!CLREvent::Wait+0x17
0b83ef5c 79ed7a9e mscorwks!AwareLock::EnterEpilog+0x8c
0b83ef78 79ebd7e4 mscorwks!AwareLock::Enter+0x61
0b83f018 074c5681 mscorwks!JIT_MonEnterWorker_Portable+0xb3
0b83f01c 793b0d1f 0×74c5681
0b83f024 79373ecd mscorlib_ni+0×2f0d1f
0b83f038 793b0c68 mscorlib_ni+0×2b3ecd
0b83f050 79e7c74b mscorlib_ni+0×2f0c68
0b83f060 79e7c6cc mscorwks!CallDescrWorker+0×33
0b83f0e0 79e7c8e1 mscorwks!CallDescrWorkerWithHandler+0xa3
0b83f220 79e7c783 mscorwks!MethodDesc::CallDescr+0×19c
0b83f23c 79e7c90d mscorwks!MethodDesc::CallTargetWorker+0×1f
0b83f250 79fc58cd mscorwks!MethodDescCallSite::Call_RetArgSlot+0×18
0b83f438 79ef3207 mscorwks!ThreadNative::KickOffThread_Worker+0×190
0b83f44c 79ef31a3 mscorwks!Thread::DoADCallBack+0×32a
0b83f4e0 79ef30c3 mscorwks!Thread::ShouldChangeAbortToUnload+0xe3
0b83f51c 79f01723 mscorwks!Thread::ShouldChangeAbortToUnload+0×30a
0b83f52c 79f02a5d mscorwks!Thread::RaiseCrossContextException+0×434
0b83f5dc 79f02ab7 mscorwks!Thread::DoADCallBack+0xda
0b83f5f8 79ef31a3 mscorwks!Thread::DoADCallBack+0×310
0b83f68c 79ef30c3 mscorwks!Thread::ShouldChangeAbortToUnload+0xe3
0b83f6c8 79ef4826 mscorwks!Thread::ShouldChangeAbortToUnload+0×30a
0b83f6f0 79fc57b1 mscorwks!Thread::ShouldChangeAbortToUnload+0×33e
0b83f708 79fc56ac mscorwks!ManagedThreadBase::KickOff+0×13
0b83f7a4 79f95a2e mscorwks!ThreadNative::KickOffThread+0×269
0b83ff3c 76573833 mscorwks!Thread::intermediateThreadProc+0×49
0b83ff48 77c1a9bd kernel32!BaseThreadInitThunk+0xe
0b83ff88 00000000 ntdll!LdrInitializeThunk+0×4d

0:014> ub 074c5681
074c565c 080c54          or      byte ptr [esp+edx*2],cl
074c565f 07              pop     es
074c5660 8b0d88dc7b02    mov     ecx,dword ptr ds:[27BDC88h]
074c5666 e8de009b72      call    mscorwks!JIT_MonEnterWorker (79e75749)
074c566b a1240a5407      mov     eax,dword ptr ds:[07540A24h]
074c5670 3105280a5407    xor     dword ptr ds:[7540A28h],eax
074c5676 8b0d84dc7b02    mov     ecx,dword ptr ds:[27BDC84h]
074c567c e8c8009b72      call    mscorwks!JIT_MonEnterWorker (79e75749)

0:014> dp 27BDC84h l1
027bdc84  0a1ffd4c

0:014> !dlk
Examining SyncBlocks...
Scanning for ReaderWriterLock instances...
Scanning for holders of ReaderWriterLock locks...
Scanning for ReaderWriterLockSlim instances...
Scanning for holders of ReaderWriterLockSlim locks...
Examining CriticalSections...
Could not find symbol ntdll!RtlCriticalSectionList.
Scanning for threads waiting on SyncBlocks...
Scanning for threads waiting on ReaderWriterLock locks...
Scanning for threads waiting on ReaderWriterLocksSlim locks...
Scanning for threads waiting on CriticalSections...
*DEADLOCK DETECTED*
CLR thread 0xd holds the lock on SyncBlock 052cbd3c OBJ:0a1ffd4c[System.String] STRVAL=critical section 1
…and is waiting for the lock on SyncBlock 052cbf1c OBJ:0a1ffd84[System.String] STRVAL=critical section 2
CLR thread 0xb holds the lock on SyncBlock 052cbf1c OBJ:0a1ffd84[System.String] STRVAL=critical section 2
…and is waiting for the lock on SyncBlock 052cbd3c OBJ:0a1ffd4c[System.String] STRVAL=critical section 1
CLR Thread 0xd is waiting at UserQuery+ClassMain.thread_proc_1()(+0×42 IL)(+0×60 Native)
CLR Thread 0xb is waiting at UserQuery+ClassMain.thread_proc_2()(+0×19 IL)(+0×21 Native)

1 deadlock detected.

- Dmitry Vostokov @ DumpAnalysis.org + TraceAnalysis.org -

Leave a Reply