Windows System Software -- Consulting, Training, Development -- Unique Expertise, Guaranteed Results

Before Posting...
Please check out the Community Guidelines in the Announcements and Administration Category.

More Info on Driver Writing and Debugging


The free OSR Learning Library has more than 50 articles on a wide variety of topics about writing and debugging device drivers and Minifilters. From introductory level to advanced. All the articles have been recently reviewed and updated, and are written using the clear and definitive style you've come to expect from OSR over the years.


Check out The OSR Learning Library at: https://www.osr.com/osr-learning-library/


Locate CRITICAL_SECTION location

nkeemiknkeemik Member Posts: 6

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

Comments

  • Tim_RobertsTim_Roberts Member - All Emails Posts: 13,695

    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.

    Tim Roberts, [email protected]
    Providenza & Boekelheide, Inc.

  • nkeemiknkeemik Member Posts: 6

    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 ?
  • Tim_RobertsTim_Roberts Member - All Emails Posts: 13,695

    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.

    Tim Roberts, [email protected]
    Providenza & Boekelheide, Inc.

  • nkeemiknkeemik Member Posts: 6

    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;
    }
    
  • raj_rraj_r Member - All Emails Posts: 986

    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


    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])
    
  • nkeemiknkeemik Member Posts: 6
    edited November 3

    @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".

  • nkeemiknkeemik Member Posts: 6

    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.

  • raj_rraj_r Member - All Emails Posts: 986

    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 
    
  • nkeemiknkeemik Member Posts: 6

    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 ?

  • raj_rraj_r Member - All Emails Posts: 986

    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

Sign In or Register to comment.

Howdy, Stranger!

It looks like you're new here. If you want to get involved, click one of these buttons!

Upcoming OSR Seminars
OSR has suspended in-person seminars due to the Covid-19 outbreak. But, don't miss your training! Attend via the internet instead!
Writing WDF Drivers 7 Dec 2020 LIVE ONLINE
Internals & Software Drivers 25 Jan 2021 LIVE ONLINE
Developing Minifilters 8 March 2021 LIVE ONLINE