Windbg, how to read the !locks output?

Question

I am debugging a program which I suspect there could be deadlock or other mutli-thread related bug, I follow people's suggestions to use WinDBG to open the crash dump file and used !locks to get the following output:

CritSec MSVCR100D!lclcritsects+48 at 73541e40
WaiterWoken        No
LockCount          6
RecursionCount     1
OwningThread       164c
EntryCount         0
ContentionCount    9
*** Locked

*** ERROR: Symbol file could not be found.  Defaulted to export symbols for qsqlited4.dll - 
CritSec qsqlited4!qt_plugin_instance+a1b21 at 70fc301c
WaiterWoken        No
LockCount          0
RecursionCount     1
OwningThread       2344
EntryCount         0
ContentionCount    0
*** Locked

CritSec +73c2380 at 073c2380
WaiterWoken        No
LockCount          0
RecursionCount     4
OwningThread       2344
EntryCount         0
ContentionCount    0
*** Locked

CritSec +73bf9e8 at 073bf9e8
WaiterWoken        No
LockCount          0
RecursionCount     1
OwningThread       2344
EntryCount         0
ContentionCount    0    
*** Locked

Scanned 817 critical sections

I am confused by the output, could anyone help to explain it?

Bidle

msdn.microsoft.com/en-us/library/windows/hardware/… Shows you :) – Dusty

Thanks, but what does the *** Locked means after each section? It is not explained in the MS's page. – Bidle

It means the CRITICAL_SECTION is currently locked :). You can always try to dump a CRITICAL_SECTION which you know is not locked. I'd expect output to differ – Dusty

!cs -l will list the same, but maybe better output. !cs -l -o is my favorite, it shows also stack of the owning thread. – Poultryman

Answer 1

!locks can be confusing. If you really want to debug a deadlock situation, do a ~*kvn (or kb whichever you like) find threads waiting on critical sections which will end in a **WaitForSingleObject and before that a RtlEnterCriticalSection call. Find the Critical section most of the threads are wating on. Dump the critical section. If you are debugging x64 based dumps and narrow down to the frame which is carrying RtlCrticalSection using .frame /c post you are in thread context ~[threadnum]s, rbx will contain your critical section.

Dump the critical section find the owner. If the owner is waiting find out what's owner waiting on and so on till we reach end of chain or a reason why things are blocked. !cs -l -o can be confusing if we don't put it in context.

Hope this helps.

Prosimian

Thanks, but could you explain more about how to find out which critical section a thread is waiting on? – Bidle

And I have used ~*kvn, each thread starts with something like this: Id: 1920.164c Suspend: 0 Teb: 7ef28000 Unfrozen, what does the suspend, teb and unfrozen mean? – Bidle

Didn't really have time to logon to the site, I guess will have to experiment more however following links shows the technique to dump out CS blogs.msdn.com/b/ntdebugging/archive/2012/02/28/… – Prosimian

even the dumpanalysis anthology has some patterns arround it . books.google.co.in/… – Prosimian

~*kvn doesn't work in kernel mode debugging. Is there a good kernel mode alternative? – Forcible

Answer 2

Teb is address to the thread environment block, Suspend & frozen not relevant for now

Assuming that it’s a 32 bit scenario, you can reveal which critical section a thread is waiting by:

a) Switch to the thread
b) dump stack
c) Find 1 argument to RtlEnterCriticalSection

(If 64 follow the recept from Addy above)

Poultryman

Answer 3

Here's my understanding of how to interpret the information, from the first lock displayed in your sample output:

CritSec MSVCR100D!lclcritsects+48 at 73541e40 - address of the lock
WaiterWoken        No - unclear, ignore
LockCount          6 - how many threads are waiting to acquire the lock
RecursionCount     1 - how many times the owner thread has acquired the lock
OwningThread       164c - the thread ID of the owner, in hex
EntryCount         0 - obsolete?
ContentionCount    9 - the highest LockCount value seen
*** Locked - this indicates that the critical is currently held

So, we can see that thread 164c owns the lock, but not recursively. There are six threads waiting to acquire the lock. At some point in the past there were nine threads trying to acquire the lock.

Probably what you want to do is switch to the owning thread and see what it's doing, why it's still holding the lock, etc. You can look for the thread in the windbg Processes and Threads number or do it from the command window:

First, list all threads:

~*

Then, find the thread of interest, look for the thread ID of interest, and switch to it. For instance, you might find this output:

9  Id: 15b8.164c Suspend: 0 Teb: fffa4000 Unfrozen
   Priority: 10

9 is the thread number 15b8.164c is the process ID and thread ID. Since 164c is what you're looking for that means that the thread of interest is number 9, so you would issue this command:

~9s

Then you can look at the stack and figure out what is going on. In my case I found that my thread is waiting on an event while holding the loader lock, and we need to not do that.

Pastime

Answer 4

To find deadlocks caused by critical sections, try SOSEX's !dlk command. Although the extension seems to be for .NET only, the !dlk command will also identify deadlocks in native critical sections.

Benefit: if it identifies a deadlock, it's very easy to read. If it does not, you still need to apply other techniques (e.g. in case the chain includes other types of synchronization objects).

Example output (not specifically for critical section):

0:010> !dlk
Deadlock detected:
CLR thread 4 holds sync block 00000000024c6970 OBJ:000000007fff0f80[System.String] STRVAL=SYNC1
             waits sync block 00000000024c6928 OBJ:000000007fff0fa8[System.String] STRVAL=SYNC2
CLR thread 5 holds sync block 00000000024c6928 OBJ:000000007fff0fa8[System.String] STRVAL=SYNC2
             waits sync block 00000000024c6970 OBJ:000000007fff0f80[System.String] STRVAL=SYNC1
CLR Thread 4 is waiting at ConsoleTestApp.ConsoleTestApp.MonitorDeadlockThreadProc()+0xa4(IL) [C:\dev\ConsoleTestApp\ConsoleTestApp.cs, line 195]
CLR Thread 5 is waiting at ConsoleTestApp.ConsoleTestApp.MonitorDeadlockThreadProc()+0xa4(IL) [C:\dev\ConsoleTestApp\ConsoleTestApp.cs, line 195]

1 deadlock detected. 

Martijn