Debugging simple user-space deadlock scenario with WinDBG

Let’s see how to point out a simple deadlock scenario in Windows using the de-facto debuggers.

First lets take a look at how to code and debug the issue under Windows.

We will be using fundamental user space constructs from the Windows API such as CRITICAL_SECTION, CreateThread and WaitForMultipleObjects.

Here the code has some really basic mistake and that is an inverted order in the acquire/release order between two different code paths, code may work for some time but destiny is impossible to avoid and we would end up with a very dumb deadlock.

You may want to tweak the code to launch more threads (editing MAX_THREADS), but for the basic example spawning 2 threads is just OK, as the WinDBG default output is quite noisy and don’t want to make an extra large article filled with non-practical information.

#include <iostream>
#include <windows.h>
#include <vector>

using namespace std;

#define MAX_THREADS 2

CRITICAL_SECTION cs1, cs2;

DWORD WINAPI threadProc2(LPVOID lpParameter)
{
    while (true) {
        EnterCriticalSection(&cs2);
        EnterCriticalSection(&cs1);
        cout << "Running threadProc2, from Thread " << GetCurrentThreadId() << endl;
        LeaveCriticalSection(&cs2);
        LeaveCriticalSection(&cs1);

        Sleep(100);
    }
    return 0;
}

DWORD WINAPI threadProc1(LPVOID lpParameter)
{
    while (true) { 
        EnterCriticalSection(&cs1);
        EnterCriticalSection(&cs2);
        cout << "Running threadProc1, from Thread " << GetCurrentThreadId() << endl;
        LeaveCriticalSection(&cs1);
        LeaveCriticalSection(&cs2);

        Sleep(100);
    }
    return 0;
}

int main()
{
    DWORD tIds[MAX_THREADS];
    HANDLE hThreads[MAX_THREADS];

    InitializeCriticalSection(&cs1);
    InitializeCriticalSection(&cs2);

    for (int i = 0; i < MAX_THREADS; i++) {
        // Odd numbers run threadProc1 and even run threadProc2
        if (i & 1) {
            hThreads[i] = CreateThread(NULL, 0, (LPTHREAD_START_ROUTINE)threadProc1, 
                NULL, 0, &tIds[i]);
        }
        else
        {
            hThreads[i] = CreateThread(NULL, 0, (LPTHREAD_START_ROUTINE)threadProc2, 
                NULL, 0, &tIds[i]);
        }
    }

    WaitForMultipleObjects(MAX_THREADS, hThreads, true, INFINITE);

    DeleteCriticalSection(&cs1);
    DeleteCriticalSection(&cs2);
}

We launch WinDBG go to -> File -> Start Debugging -> Launch Executable and select our freshly build buggy application and hit Go (command line g).

Optionally you can launch the app and wait for it to be deadlocked and attach WinDBG same results either way.

We should have one main thread, the 2 threads we spawned using CreateThread and some other worker threads, that we can safely ignore as this are part of any application and required by a Windows application to work properly (think of IPC message pumps and similar Windows internal tasks we don’t handle directly).

Our two manually spawned threads are the only subjects of interest for this exercise, the code has build in release mode so it will be a little bit harder to pull information out of the running application.

The cryptic command “~*k” tells the debugger to iterate through all the threads while setting the context (“~” command) on each one (“*” wildcard) and print their stacks (“k” command)

0:000> g
ModLoad: 00007ffc`2ec20000 00007ffc`2ec52000   C:\Windows\System32\IMM32.DLL
(5ca8.6bf8): Break instruction exception - code 80000003 (first chance)
ntdll!DbgBreakPoint:
00007ffc`30a50bb0 cc              int     3

0:006> ~*k

   0  Id: 5ca8.6d4c Suspend: 1 Teb: 000000d5`7cfc0000 Unfrozen
 # Child-SP          RetAddr               Call Site
00 000000d5`7cd2f778 00007ffc`2e420460     ntdll!NtWaitForMultipleObjects+0x14
01 000000d5`7cd2f780 00007ffc`2e42035e     KERNELBASE!WaitForMultipleObjectsEx+0xf0
02 000000d5`7cd2fa70 00007ff7`87f011c6     KERNELBASE!WaitForMultipleObjects+0xe
03 000000d5`7cd2fab0 00007ff7`87f016b0     CriticalSectionExample!main+0xa6
04 (Inline Function) --------`--------     CriticalSectionExample!invoke_main+0x22
05 000000d5`7cd2fb10 00007ffc`2eaa74b4     CriticalSectionExample!__scrt_common_main_seh+0x10c
06 000000d5`7cd2fb50 00007ffc`30a026a1     KERNEL32!BaseThreadInitThunk+0x14
07 000000d5`7cd2fb80 00000000`00000000     ntdll!RtlUserThreadStart+0x21

   1  Id: 5ca8.60e8 Suspend: 1 Teb: 000000d5`7cfc2000 Unfrozen
 # Child-SP          RetAddr               Call Site
00 000000d5`7d0ff638 00007ffc`30a02e17     ntdll!NtWaitForWorkViaWorkerFactory+0x14
01 000000d5`7d0ff640 00007ffc`2eaa74b4     ntdll!TppWorkerThread+0x2f7
02 000000d5`7d0ff940 00007ffc`30a026a1     KERNEL32!BaseThreadInitThunk+0x14
03 000000d5`7d0ff970 00000000`00000000     ntdll!RtlUserThreadStart+0x21

   2  Id: 5ca8.de0 Suspend: 1 Teb: 000000d5`7cfc4000 Unfrozen
 # Child-SP          RetAddr               Call Site
00 000000d5`7d1ffb88 00007ffc`30a02e17     ntdll!NtWaitForWorkViaWorkerFactory+0x14
01 000000d5`7d1ffb90 00007ffc`2eaa74b4     ntdll!TppWorkerThread+0x2f7
02 000000d5`7d1ffe90 00007ffc`30a026a1     KERNEL32!BaseThreadInitThunk+0x14
03 000000d5`7d1ffec0 00000000`00000000     ntdll!RtlUserThreadStart+0x21

   3  Id: 5ca8.7234 Suspend: 1 Teb: 000000d5`7cfc6000 Unfrozen
 # Child-SP          RetAddr               Call Site
00 000000d5`7d2ff598 00007ffc`30a02e17     ntdll!NtWaitForWorkViaWorkerFactory+0x14
01 000000d5`7d2ff5a0 00007ffc`2eaa74b4     ntdll!TppWorkerThread+0x2f7
02 000000d5`7d2ff8a0 00007ffc`30a026a1     KERNEL32!BaseThreadInitThunk+0x14
03 000000d5`7d2ff8d0 00000000`00000000     ntdll!RtlUserThreadStart+0x21

   4  Id: 5ca8.6cec Suspend: 1 Teb: 000000d5`7cfc8000 Unfrozen
 # Child-SP          RetAddr               Call Site
00 000000d5`7d3ff818 00007ffc`30a138ad     ntdll!NtWaitForAlertByThreadId+0x14
01 000000d5`7d3ff820 00007ffc`30a13762     ntdll!RtlpWaitOnAddressWithTimeout+0x81
02 000000d5`7d3ff850 00007ffc`30a1357d     ntdll!RtlpWaitOnAddress+0xae
03 000000d5`7d3ff8c0 00007ffc`309dfcb4     ntdll!RtlpWaitOnCriticalSection+0xfd
04 000000d5`7d3ff9a0 00007ffc`309dfae2     ntdll!RtlpEnterCriticalSectionContended+0x1c4
05 000000d5`7d3ffa00 00007ff7`87f0102a     ntdll!RtlEnterCriticalSection+0x42
06 000000d5`7d3ffa30 00007ffc`2eaa74b4     CriticalSectionExample!threadProc2+0x2a
07 000000d5`7d3ffa60 00007ffc`30a026a1     KERNEL32!BaseThreadInitThunk+0x14
08 000000d5`7d3ffa90 00000000`00000000     ntdll!RtlUserThreadStart+0x21

   5  Id: 5ca8.6ebc Suspend: 1 Teb: 000000d5`7cfca000 Unfrozen
 # Child-SP          RetAddr               Call Site
00 000000d5`7d4ff788 00007ffc`30a138ad     ntdll!NtWaitForAlertByThreadId+0x14
01 000000d5`7d4ff790 00007ffc`30a13762     ntdll!RtlpWaitOnAddressWithTimeout+0x81
02 000000d5`7d4ff7c0 00007ffc`30a1357d     ntdll!RtlpWaitOnAddress+0xae
03 000000d5`7d4ff830 00007ffc`309dfcb4     ntdll!RtlpWaitOnCriticalSection+0xfd
04 000000d5`7d4ff910 00007ffc`309dfae2     ntdll!RtlpEnterCriticalSectionContended+0x1c4
05 000000d5`7d4ff970 00007ff7`87f010ba     ntdll!RtlEnterCriticalSection+0x42
06 000000d5`7d4ff9a0 00007ffc`2eaa74b4     CriticalSectionExample!threadProc1+0x2a
07 000000d5`7d4ff9d0 00007ffc`30a026a1     KERNEL32!BaseThreadInitThunk+0x14
08 000000d5`7d4ffa00 00000000`00000000     ntdll!RtlUserThreadStart+0x21

#  6  Id: 5ca8.6bf8 Suspend: 1 Teb: 000000d5`7cfcc000 Unfrozen
 # Child-SP          RetAddr               Call Site
00 000000d5`7d5ff9a8 00007ffc`30a7cc2e     ntdll!DbgBreakPoint
01 000000d5`7d5ff9b0 00007ffc`2eaa74b4     ntdll!DbgUiRemoteBreakin+0x4e
02 000000d5`7d5ff9e0 00007ffc`30a026a1     KERNEL32!BaseThreadInitThunk+0x14
03 000000d5`7d5ffa10 00000000`00000000     ntdll!RtlUserThreadStart+0x21

We can see how threads number 4 and 5 are the extra ones we spawned as they have both our binary in their stacks and are also trying to get into a critical section and are NOT the main thread.

Let’s first examine the thread number 4, the command “~4k” tells the debugger to set the context to the thread number 4 and print its stack.

Now lets move to the frame where our code is stuck using the command “.frame 6”, this will automatically load our source inside WinDBG as we can see here the thread is currently stuck on threadProc2 trying to acquire “cs1”.

Yeah I know the debugger marks the next line and is a common issue with WinDBG the only truth is told by the stack traces, remember this clearly and hope never get to debug complex or recursive lambda expressions in crash dumps as live debugging like this is way more manageable for those cases.

Now let’s take a look at thread number 5, here we are trying to acquire “cs2”.

As we control all this code is easy to tell that thread 4 is holding “cs2” and now waits for “cs1” while the thread 5 holds “cs1” and now waits for “cs2”, this is the most basic deadlock scenario you can find.

We can confirm this with a build-in command from WinDBG called !critsec which will print out some stats for the critical section structure while also telling us who’s the current owner.

Remember when we printed out all the thread stacks? Well there we got the thread numbers and also their IDs (used in the !critsec output), we can also get that by executing “~*” which will iterate all threads and print their basic info (this time without the stacks).

0:005> ~*
   0  Id: 5ca8.6d4c Suspend: 1 Teb: 000000d5`7cfc0000 Unfrozen
      Start: CriticalSectionExample!mainCRTStartup (00007ff7`87f01720)
      Priority: 0  Priority class: 32  Affinity: ffff
   1  Id: 5ca8.60e8 Suspend: 1 Teb: 000000d5`7cfc2000 Unfrozen
      Start: ntdll!TppWorkerThread (00007ffc`30a02b20)
      Priority: 0  Priority class: 32  Affinity: ffff
   2  Id: 5ca8.de0 Suspend: 1 Teb: 000000d5`7cfc4000 Unfrozen
      Start: ntdll!TppWorkerThread (00007ffc`30a02b20)
      Priority: 0  Priority class: 32  Affinity: ffff
   3  Id: 5ca8.7234 Suspend: 1 Teb: 000000d5`7cfc6000 Unfrozen
      Start: ntdll!TppWorkerThread (00007ffc`30a02b20)
      Priority: 0  Priority class: 32  Affinity: ffff
   4  Id: 5ca8.6cec Suspend: 1 Teb: 000000d5`7cfc8000 Unfrozen
      Start: CriticalSectionExample!threadProc2 (00007ff7`87f01000)
      Priority: 0  Priority class: 32  Affinity: ffff
.  5  Id: 5ca8.6ebc Suspend: 1 Teb: 000000d5`7cfca000 Unfrozen
      Start: CriticalSectionExample!threadProc1 (00007ff7`87f01090)
      Priority: 0  Priority class: 32  Affinity: ffff
#  6  Id: 5ca8.6bf8 Suspend: 1 Teb: 000000d5`7cfcc000 Unfrozen
      Start: ntdll!DbgUiRemoteBreakin (00007ffc`30a7cbe0)
      Priority: 0  Priority class: 32  Affinity: ffff

0:005> !critsec cs1

CritSec CriticalSectionExample!cs1+0 at 00007ff787f05628
WaiterWoken        No
LockCount          1
RecursionCount     1
OwningThread       6ebc
EntryCount         0
ContentionCount    3b
*** Locked
0:005> !critsec cs2

CritSec CriticalSectionExample!cs2+0 at 00007ff787f05650
WaiterWoken        No
LockCount          1
RecursionCount     1
OwningThread       6cec
EntryCount         0
ContentionCount    2d
*** Locked

Well this is the most primitive way to get behind a CriticalSection deadlock in Windows, there are some powerful extensions that will greatly simplify this task, we may talk about them later.