Locate CRITICAL_SECTION location

I am tracing critical section leaks and trying to figure out how to locate the source code behind which holds the critical section. I have an app which contains PDB file and I created memory dump.

For example, critical section below is one of the most busiest (high ContentionCount) and I would like to understand where in the source is the critical section created. For some reason I am not able to use Display Type (dt) command for some critical sections, for some critical sections dt command works fine.

Does all critical sections listed in user mode memory dump belong to process or is it possible that some belong to drivers ?

Any guidelines how to track down the location of critical section ?

0:000> !locks -v

CritSec +adf30be8 at 0000003eadf30be8
LockCount          NOT LOCKED
RecursionCount     0
OwningThread       0
EntryCount         0
ContentionCount    797047

0:000> dt _RTL_CRITICAL_SECTION 0000003eadf30be8
myapp!_RTL_CRITICAL_SECTION
   +0x000 DebugInfo        : 0x00000089`3a3d81a0 _RTL_CRITICAL_SECTION_DEBUG
   +0x008 LockCount        : 0n-1
   +0x00c RecursionCount   : 0n0
   +0x010 OwningThread     : (null) 
   +0x018 LockSemaphore    : 0xffffffff`ffffffff Void
   +0x020 SpinCount        : 0x200013c
0:000> dx -r1 ((myapp!_RTL_CRITICAL_SECTION_DEBUG *)0x893a3d81a0)
((myapp!_RTL_CRITICAL_SECTION_DEBUG *)0x893a3d81a0)                 : 0x893a3d81a0 [Type: _RTL_CRITICAL_SECTION_DEBUG *]
    [+0x000] Type             : 0x0 [Type: unsigned short]
    [+0x002] CreatorBackTraceIndex : 0x0 [Type: unsigned short]
    [+0x008] CriticalSection  : 0x3eadf30be8 [Type: _RTL_CRITICAL_SECTION *]
    [+0x010] ProcessLocksList [Type: _LIST_ENTRY]
    [+0x020] EntryCount       : 0x0 [Type: unsigned long]
    [+0x024] ContentionCount  : 0x797047 [Type: unsigned long]
    [+0x028] Flags            : 0x0 [Type: unsigned long]
    [+0x02c] CreatorBackTraceIndexHigh : 0x0 [Type: unsigned short]
    [+0x02e] SpareWORD        : 0x74 [Type: unsigned short]
0:000> dx -r1 ((myapp!_RTL_CRITICAL_SECTION *)0x3eadf30be8)
((myapp!_RTL_CRITICAL_SECTION *)0x3eadf30be8)                 : 0x3eadf30be8 [Type: _RTL_CRITICAL_SECTION *]
    [+0x000] DebugInfo        : 0x893a3d81a0 [Type: _RTL_CRITICAL_SECTION_DEBUG *]
    [+0x008] LockCount        : -1 [Type: long]
    [+0x00c] RecursionCount   : 0 [Type: long]
    [+0x010] OwningThread     : 0x0 [Type: void *]
    [+0x018] LockSemaphore    : 0xffffffffffffffff [Type: void *]
    [+0x020] SpinCount        : 0x200013c [Type: unsigned __int64]

0:000> dt 0000003eadf30be8
Symbol not found at address 0000003eadf30be8.
0:000> ln 0000003eadf30be8
Browse module
Set bu breakpoint

For some reason I am not able to use Display Type (dt) command for some critical sections, for some critical sections dt command works fine.

No, you have issued two very different commands.

0:000> dt _RTL_CRITICAL_SECTION 0000003eadf30be8

That tells the debugger to pretend that this address is an ‘RTL_CRITICAL_SECTION’ structure and show you the contents.

0:000> dt 0000003eadf30be8
Symbol not found at address 0000003eadf30be8.

That tells the debugger to go figure out which module that contains that address, then go find the symbol file for that module, then look up that address in the symbol file, then figure out what type of thing is stored at that address, and dump it. If that address is not in one of your modules, then you won’t have symbol files. And if the structure was allocated from the heap, the debugger won’t be able to find anything at all.

1 Like

Tim, thanks for explanations.

Now I am still kind of stuck, I would like to find the module who created that very busy critical section. And other sections I don’t have reference in my symbol file.

The memory dump in question was created using ProcDump -mp (Write a dump file with thread and handle information, and all read/write process memory).

  1. Does !locks -v give me a true output and I can suspect critical section leak when comparing user mode memory dump output over time (lets say 24 hour) ?
  2. How to find the module behind CritSec memory address ?

I’m not sure what you mean by “critical section leak”. Unlike other synchronization objects, critical sections aren’t centrally allocated – the user allocates the space from normal memory. “!locks -v” is supposed to show you every critical section that has been initialized in this process, but it can’t know about kernel locks. No one knows which code initialized the section. You could set a breakpoint at RtlInitializeCriticalSection and do a traceback to figure out who called it.

By leak I mean that the output of !locks -v grows over time.

0:000> !locks -v
...
Scanned 80400 critical sections

Wait 24 hours

0:000> !locks -v
...
Scanned 83344 critical sections

I created 2 very simple test applications using VS2008:

  1. do not call any InitializeCriticalSection
  2. call 100 x InitializeCriticalSection, see example below.

Both times windbg did not indicate any increase of critical sections. It reported 4 ciritical sections, none of them were initialized by test app.


So, I still do not follow which module created 4 ciritical sections. I assume that they are coming from CRT or any other system module listed by !peb ?
Any reason why I wasn’t able to see the following static critical sections listed under windbg ?



int main(int argc, _TCHAR* argv[])
{
    static CRITICAL_SECTION psc[CRITSEC_COUNT];

    printf( "%d\n", GetCurrentProcessId() );

    for (int i=0; i<CRITSEC_COUNT; i++)
        InitializeCriticalSection( &psc[i] );    

    Sleep(0xFFFFFFFF);

    return 0;
}

All Your Code Does is initialize 256 CriticalSections.

why do you think !locks will show some increase or decrease ?

what is the reason for the 24 hours wait before trying to do another !locks ?

if this were not a dump but a live session you could try !gflags “user stack trace database”
to locate your creation with !cs -o

the lock count increases only if a thread Entered Your Critical Section and successfully acquired it

the lock count will decrease if the thread that acquired the CriticalSection Relinquished it with LeaveCriticalSection

A thread can die without relinquishing the ownership of Critical Section

if a CriticalSection is owned and locked by a thread any other thread that tried to acquire it will not be granted ownership and will go into a WaitState if the other thread went into a waitstate the contention count will be increased .

check the code and windbg display

this code Initialises one CriticalSection.

and creates ten threads.

each one of the thread will try to acquire ownership of the criticalsection

the first thread will succeed but it has a 10 second long work to perform before it can relinquish the CriticalSection

so all other thread will get into a wait state so the contention count will be 9 when

#include <stdio.h>
#include <windows.h>
#define THNO 10
CRITICAL_SECTION mycritty;
int counter = 0;
DWORD WINAPI tproc( LPVOID  ) 
{
    EnterCriticalSection(&mycritty);
    counter++;
    printf("%d\n",counter);
    Sleep(10000);
    LeaveCriticalSection(&mycritty);
    return 0;
}

int main(void)
{
    ULONG htid[THNO] = {0};
    HANDLE hth[THNO] = {NULL};
    InitializeCriticalSection( &mycritty );
    for(int i = 0; i < THNO; i++) 
    {
        hth[i] = CreateThread(NULL,0,&tproc,NULL,0,&htid[0]);
    }
    WaitForMultipleObjects(THNO, hth, TRUE, INFINITE);
    return getchar();    
}

when you reach the main there is no Critical Section

0:000> g critter!main
eax=015632b0 ebx=7ffdf000 ecx=99378b00 edx=76e570f4 esi=0013a778 edi=01560fb8
eip=000f1050 esp=003ef97c ebp=003ef9c0 iopl=0         nv up ei pl nz na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000202
critter!main:
000f1050 55              push    ebp
$$ noCriticalSections have been initialised yet @main
0:000> ?? critter!mycritty
struct _RTL_CRITICAL_SECTION
   +0x000 DebugInfo        : (null) 
   +0x004 LockCount        : 0n0
   +0x008 RecursionCount   : 0n0
   +0x00c OwningThread     : (null) 
   +0x010 LockSemaphore    : (null) 
   +0x014 SpinCount        : 0 

on executing the InitializeCritical Section() Api a critical section is initialized with NULL will be created

>   20:     InitializeCriticalSection( &mycritty );
critter!main+0x50:
000f10a0 68d0991300      push    offset critter!mycritty (001399d0)
0:000> 
eax=00000000 ebx=7ffdf000 ecx=01561a70 edx=013effb8 esi=0013a778 edi=01560fb8
eip=000f10ab esp=003ef920 ebp=003ef978 iopl=0         nv up ei pl zr na pe nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000246
>   21:     for(int i = 0; i < THNO; i++) 
critter!main+0x5b:
000f10ab c745a800000000  mov     dword ptr [ebp-58h],0 ss:0023:003ef920=76e6eea6
0:000> ?? critter!mycritty
struct _RTL_CRITICAL_SECTION
   +0x000 DebugInfo        : 0x01561aa0 _RTL_CRITICAL_SECTION_DEBUG
   +0x004 LockCount        : 0n-1
   +0x008 RecursionCount   : 0n0
   +0x00c OwningThread     : (null) 
   +0x010 LockSemaphore    : (null) 
   +0x014 SpinCount        : 0

Setting a breakpoint on the ThreadProc and continuing all the threads will be created and the first hit on ThreadProc will happen

0:000> bp critter!tproc
0:000> g
Breakpoint 0 hit
eax=76b8ed5a ebx=00000000 ecx=00000000 edx=000f1000 esi=00000000 edi=00000000
eip=000f1000 esp=0024fe44 ebp=0024fe4c iopl=0         nv up ei pl zr na pe nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000246
>    7: {
critter!tproc:
000f1000 55              push    ebp

if you keep on stepping you can see the contetion count increasing upto 9 when all the ten threads have called thier ThreadProcs thecounter increased by 1 by the thread which suceeded to acquire the CriticalSection .

the gflags +ust is also enabled so stack trace is also available

0:010> ~
   0  Id: 15c0.ad4 Suspend: 1 Teb: 7ffde000 Unfrozen
   2  Id: 15c0.1360 Suspend: 1 Teb: 7ffd4000 Unfrozen
   3  Id: 15c0.df8 Suspend: 1 Teb: 7ffd5000 Unfrozen
   4  Id: 15c0.8e4 Suspend: 1 Teb: 7ffd6000 Unfrozen
   5  Id: 15c0.17a4 Suspend: 1 Teb: 7ffd7000 Unfrozen
   6  Id: 15c0.1760 Suspend: 1 Teb: 7ffd8000 Unfrozen
   7  Id: 15c0.16ec Suspend: 1 Teb: 7ffd9000 Unfrozen
   8  Id: 15c0.12bc Suspend: 1 Teb: 7ffda000 Unfrozen
   9  Id: 15c0.171c Suspend: 1 Teb: 7ffdb000 Unfrozen
. 10  Id: 15c0.6a4 Suspend: 1 Teb: 7ffdc000 Unfrozen
0:010> ? critter!counter
Evaluate expression: 1284584 = 001399e8
0:010> ? poi(critter!counter)
Evaluate expression: 2 = 00000002
0:010> dx -r2 (ntdll!_RTL_CRITIcalSection*) &(critter!mycritty)
Error: Unable to find type '_RTL_CRITIcalSection *' for cast.
0:010> dx -r2 (ntdll!_RTL_CRITICAL_SECTION *) &(critter!mycritty)
(ntdll!_RTL_CRITICAL_SECTION *) &(critter!mycritty)                 : 0x1399d0 [Type: _RTL_CRITICAL_SECTION *]
    [+0x000] DebugInfo        : 0x1561aa0 [Type: _RTL_CRITICAL_SECTION_DEBUG *]
        [+0x000] Type             : 0x0 [Type: unsigned short]
        [+0x002] CreatorBackTraceIndex : 0x12 [Type: unsigned short]
        [+0x004] CriticalSection  : 0x1399d0 [Type: _RTL_CRITICAL_SECTION *]
        [+0x008] ProcessLocksList [Type: _LIST_ENTRY]
        [+0x010] EntryCount       : 0x0 [Type: unsigned long]
        [+0x014] ContentionCount  : 0x9 [Type: unsigned long]
        [+0x018] Flags            : 0x0 [Type: unsigned long]
        [+0x01c] CreatorBackTraceIndexHigh : 0x0 [Type: unsigned short]
        [+0x01e] SpareUSHORT      : 0x6e [Type: unsigned short]
    [+0x004] LockCount        : -34 [Type: long]
    [+0x008] RecursionCount   : 1 [Type: long]
    [+0x00c] OwningThread     : 0x6a4 [Type: void *]
    [+0x010] LockSemaphore    : 0x48 [Type: void *]
    [+0x014] SpinCount        : 0x0 [Type: unsigned long]
0:010> !csa -o critter!mycritty
No export csa found
0:010> !cs -o critter!mycritty
-----------------------------------------
Critical section   = 0x001399d0 (critter!mycritty+0x0)
DebugInfo          = 0x01561aa0
LOCKED
LockCount          = 0x8
WaiterWoken        = No
OwningThread       = 0x000006a4
RecursionCount     = 0x1
LockSemaphore      = 0x48
SpinCount          = 0x00000000
OwningThread DbgId = ~10s
OwningThread Stack =
	ChildEBP RetAddr  Args to Child              
	0179f9fc 76b8ed6c 00000000 0179fa48 76e737eb critter!tproc+0x3a (FPO: [Non-Fpo]) (CONV: stdcall)
	0179fa08 76e737eb 00000000 76c8333b 00000000 kernel32!BaseThreadInitThunk+0xe (FPO: [Non-Fpo])
	0179fa48 76e737be 000f1000 00000000 00000000 ntdll!__RtlUserThreadStart+0x70 (FPO: [Non-Fpo])
	0179fa60 00000000 000f1000 00000000 00000000 ntdll!_RtlUserThreadStart+0x1b (FPO: [Non-Fpo])

@raj_r said:
why do you think !locks will show some increase or decrease ?

There seems to be a misunderstanding. I am not tracing the owner thread of the lock. I am trying to understand and “interpret” the output of the !locks -v command. The question is why does the count of locks grows over time. Is it a leak ?

what is the reason for the 24 hours wait before trying to do another !locks ?

!locks -v is extremely slow, it takes 30 minutes to list the output to the console or to file. Considering there are more than 100K locks in the output. Majority of these locks in the output do not belong to my process, at least lock address points to “Symbol not found at address”.

Can anyone create a sample program that will demonstrate the “leaking” locks problem ? I would understand the locks issue more clearly if I was able to re-create the output of memory dump. For example, create memory dump, let test process run, create another memory dump – the output of !locks command needs to be an increasing number.

Majority of these locks in the output do not belong to my process

No ntsdexts!locks output is for the current process only

if the output contains > 100K then your process must behaving them

yes !locks -v is a time consuming operation

if you need a very quick confirmation of the count you can run this script to get the count of CriticalSections

.echotime
r $t0 = ntdll!RtlCriticalSectionList
r $t1 = poi(@$t0)
r $t2 = 0
.while (@$t1 != @$t0) { r$t1 = poi(@$t1) ; r $t2= @$t2+1}
? @$t2
.echotime
!locks
.echotime
!locks -v
.echotime

executing the script you can see the comparative time

0:000> $$>a< e:\wdscr\critsectcount.wds
Debugger  time: Thu Nov  5 01:42:38.844 2020 
Evaluate expression: 17 = 00000011
Debugger time: Thu Nov  5 01:42:38.972 2020    <<< 0.1 ms for 17 cs
Scanned 17 critical sections
Debugger time: Thu Nov  5 01:42:40.876 2020   <<<  2 seconds without -v
Scanned 17 critical sections
Debugger time: Thu Nov  5 01:42:45.847 2020   <<<  5 seconds with -v 
1 Like

if the output contains > 100K then your process must behaving them
and
if the structure was allocated from the heap, the debugger won’t be able to find anything at all

Can someone demonstrate C code that will generate an increasing locks output ?

I hope explorer.exe is an acceptable program

As just using commctrl File->Open Dialog can show the locks increasing

To Check you can debug windbg with windbg

write 2 scripts as follows

Script 1

C:\>cat prompt.txt
.prompt_allow -src -ea -reg -dis -sym
.pcmd -s "$$>a< c:\cscount.txt"
g

Script 2

C:\>cat cscount.txt
r $t0 = ntdll!RtlCriticalSectionList
r $t1 = poi(@$t0)
r $t2 = 0
.while (@$t1 != @$t0) { r$t1 = poi(@$t1) ; r $t2= @$t2+1}
? @$t2

The first script disables all output in command window

and sets a prompt command which will always be executed

when ctrl+break or alt+delete is hit or DebugMenu->break is Clicked

Second Script is just a fast critical section counter

Same as !locks output’s last line which says scanned xxx cs

execute

C:\>windbg -c "$$>a< c:\prompt.txt" windbg

this will open windbg as debugger execute the prompt script and run the
debuggee

hit ctrl+break

you will see an output like

(15c4.1660): Break instruction exception - code 80000003 (first chance)
Evaluate expression: 318 = 0000013e 

you can run !locks or !locks-v if you want to just in case

hit g to continue and in the debuggee use file->open
but do not select any file

return to the debugger and hit ctrl+break

you will see a tremndous increase in locks

(15c4.164c): Break instruction exception - code 80000003 (first chance)
Evaluate expression: 1452 = 000005ac

hit g to continue and hit cancel in File->Open Dialog and return to
repeat in debugger

you can see critical sections count has gone down considerably

(15c4.164c): Break instruction exception - code 80000003 (first chance)
Evaluate expression: 1452 = 000005ac
0:008> g
(15c4.c68): Break instruction exception - code 80000003 (first chance)
Evaluate expression: 1111 = 00000457

Repeat but this time click some more icons like desktop / etc and break

(15c4.16dc): Break instruction exception - code 80000003 (first chance)
Evaluate expression: 3163 = 00000c5b

select a file as debugees’s debugee

(15c4.138): Break instruction exception - code 80000003 (first chance)
Evaluate expression: 1988 = 000007c4

as you can see if you had dumped the process in these scenerios

you will get different counts of locks so count of locks isn’t a suitable metric to prove or disprove leak