New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Memory leaking in ExecuteNonQuery #1650

Closed
GuyDafny opened this Issue Jul 27, 2017 · 9 comments

Comments

Projects
None yet
4 participants
@GuyDafny

GuyDafny commented Jul 27, 2017

in case of massive call to ExecuteNonQuery, memory amount needed by app is increasing up.

For the attachment code, the amount of memo needed is here:
time memory needed (MB) remarks
17:30 21 start of test
17:40 22
17:44 23
17:55 25 end of working day
20:00 55 rdp from home
23:34 71 rdp from home
08:15 171 next morning (at work)


While running more complex code at customer, it "blow the memory" in 7 hours (""out of memory").
code :
using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using System.Timers;
using Npgsql;

namespace ConsoleApplication1
{
    class Program
    {
        static void Main(string[] args)
        {
            //updating two different tables at same time (different threads)
            Tester tstr1 = new Tester("table1");
            Tester tstr2 = new Tester("table2");
            while (true) ;
        }

        /// <summary>
        /// run the test for table
        /// </summary>
        class Tester
        {
            int id = 0;
            System.Timers.Timer tmr_update = new Timer();
            dbCommector connector = new dbCommector();
            String tbl_id = "table";
            public Tester(String TableNumber)
            {
                tbl_id = TableNumber;
                tmr_update.Interval = 10;
                tmr_update.Elapsed += new ElapsedEventHandler(InsertToDB);
                tmr_update.Start();
            }

            private void InsertToDB(object sender, ElapsedEventArgs e)
            {
                if (id > 3000) 
                { 
                    id = 0; 
                }
                Console.Write("{0}  \r" , id);
                int s = (int)(DateTime.Now.Ticks & (int.MaxValue - 1));
                int r = new Random().Next();
                for (int i = 0; i < 80; i++)
                {
                    String sql = String.Format("update {0} set value = {1}, ans_time={2} where id={3}", tbl_id, r, s, id++);
                    connector.NoAnsExecute(sql);
                }
            }

        }
    }


    /// <summary>
    /// connector to DB 
    /// </summary>
    class dbCommector
    {
        private Object lockerObj = new object();
        private NpgsqlConnection conn = null;

        /// <summary>
        /// default #tor
        /// </summary>
        public dbCommector()
        {
            conn = new NpgsqlConnection("Server=127.0.0.1;User Id=user;" +
                                            "Password=password;Database=demo;");
            conn.Open();
        }

        /// <summary>
        /// update query 
        /// </summary>
        /// <param name="query"></param>
        public void NoAnsExecute(String query)
        {
            lock (lockerObj)
            {
                using (NpgsqlCommand cmd = new NpgsqlCommand(query, conn))
                {
                    //If next line is remarked, no memory leakage is detected.  this code was run on clone of the first machine at the same time.
                    cmd.ExecuteNonQuery();
                }
            }
        }
    }

}

two SQL tables was created (CTS added): table1 and table2, and fedded with data so that the ID was from 1 to 5K at list. (not all IDs are present).


CREATE TABLE table1
(
  id serial NOT NULL,
  value double precision,
  ans_time integer,
)
WITH (
  OIDS=FALSE
);
ALTER TABLE table1
  OWNER TO "user";

@GuyDafny

This comment has been minimized.

Show comment
Hide comment
@GuyDafny

GuyDafny Aug 6, 2017

Additional information - If another program (In my case it's written in Python) alters data on same table at the same time - the memory leakage rate is increased.

GuyDafny commented Aug 6, 2017

Additional information - If another program (In my case it's written in Python) alters data on same table at the same time - the memory leakage rate is increased.

@GuyDafny GuyDafny closed this Aug 6, 2017

@GuyDafny GuyDafny reopened this Aug 6, 2017

@roji

This comment has been minimized.

Show comment
Hide comment
@roji

roji Aug 14, 2017

Member

Sorry for not looking at this earlier, it's a very busy moment for me. Will try to get around to this ASAP.

Member

roji commented Aug 14, 2017

Sorry for not looking at this earlier, it's a very busy moment for me. Will try to get around to this ASAP.

@GuyDafny

This comment has been minimized.

Show comment
Hide comment
@GuyDafny

GuyDafny Aug 14, 2017

If any help is needed, feel free to call.

GuyDafny commented Aug 14, 2017

If any help is needed, feel free to call.

@duncanawoods

This comment has been minimized.

Show comment
Hide comment
@duncanawoods

duncanawoods Aug 14, 2017

If your query takes longer than ~5ms, then you might have an ever growing number of threads blocked on the lock. It would explain why you see memory grow faster with more database activity.

You can investigate this using a threadsafe counter around the lock:

    static int waitCount = 0;

    /// <summary>
    /// update query 
    /// </summary>
    /// <param name="query"></param>
    public void NoAnsExecute(String query)
    {
        Interlocked.Increment(ref waitcount);
        
        lock (lockerObj)
        {
            Interlocked.Decrement(ref waitcount);
            
            Console.WriteLine($"Currently have {waitCount} threads blocked");
        
            using (NpgsqlCommand cmd = new NpgsqlCommand(query, conn))
            {
                //If next line is remarked, no memory leakage is detected.  this code was run on clone of the first machine at the same time.
                cmd.ExecuteNonQuery();
            }
        }
    }

If the update rate is so fast the application is at risk of not keeping up, then you need to choose how your app degrades under contention e.g.

  • throttle the rate of updates - change the timer to a one-shot timer and restart it at the end of each operation. This will prevent parallel operations from the same timer - if the db is busy, you will see slower updates but it will not kill the app
  • skip updates - use Monitor.Enter instead of lock() so you can exit the lock after a timeout

You could queue tasks with ConcurrentQueue but that still risks unlimited memory growth if the database is slower than the request rate.

duncanawoods commented Aug 14, 2017

If your query takes longer than ~5ms, then you might have an ever growing number of threads blocked on the lock. It would explain why you see memory grow faster with more database activity.

You can investigate this using a threadsafe counter around the lock:

    static int waitCount = 0;

    /// <summary>
    /// update query 
    /// </summary>
    /// <param name="query"></param>
    public void NoAnsExecute(String query)
    {
        Interlocked.Increment(ref waitcount);
        
        lock (lockerObj)
        {
            Interlocked.Decrement(ref waitcount);
            
            Console.WriteLine($"Currently have {waitCount} threads blocked");
        
            using (NpgsqlCommand cmd = new NpgsqlCommand(query, conn))
            {
                //If next line is remarked, no memory leakage is detected.  this code was run on clone of the first machine at the same time.
                cmd.ExecuteNonQuery();
            }
        }
    }

If the update rate is so fast the application is at risk of not keeping up, then you need to choose how your app degrades under contention e.g.

  • throttle the rate of updates - change the timer to a one-shot timer and restart it at the end of each operation. This will prevent parallel operations from the same timer - if the db is busy, you will see slower updates but it will not kill the app
  • skip updates - use Monitor.Enter instead of lock() so you can exit the lock after a timeout

You could queue tasks with ConcurrentQueue but that still risks unlimited memory growth if the database is slower than the request rate.

@GuyDafny

This comment has been minimized.

Show comment
Hide comment
@GuyDafny

GuyDafny Aug 28, 2017

Tnx, duncanawoods.
I had tried it same way you had suggested, then when the counter hadn't increased, I made another test:
In order to test it, I'de made the next changes in my code:

  1. Printing how much threads are waiting
  2. If more then 30 threads are on wait, I'm droping them.
  3. In order to get faster results, I run 10 timers instead of one for each of the tables.

By the results I can guess that no thread leaking. for this test I used Win-XP on virtual box, But during last week I've got similar results using windows-10 on real computer, and ms-server 2012 on vmware.

results:
time vm-size memory usage waiting
00:00 33 22 6
00:23 65 58 31
00:29 74 65 30
00:48 102 79 21
//Went to sleep, next morning ...
16:00 1494 1325 26

using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using System.Timers;
using Npgsql;
using System.Diagnostics;

namespace ConsoleApplication1
{
    class Program
    {
        static void Main(string[] args)
        {
            List<Tester> tsts = new List<Tester>();
            //update two tables using 10 timers per each 
            for (int i = 0; i < 10; i++)
            {
                tsts.Add(new Tester("set_11"));
            }
            for (int i = 0; i < 10; i++)
            {
                tsts.Add(new Tester("set_14"));
            }
            while (true) ;
        }

        /// <summary>
        /// run the test for table
        /// </summary>
        class Tester
        {
            static object lock_counter = new object();
            static long counter  = 0;
            int id = 0;
            System.Timers.Timer tmr_update = new Timer();
            dbCommector connector = new dbCommector();
            String tbl_id = "table";
            public Tester(String TableNumber)
            {
                tbl_id = TableNumber;
                tmr_update.Interval = 10;
                tmr_update.Elapsed += new ElapsedEventHandler(InsertToDB);
                tmr_update.Start();
            }

            private void InsertToDB(object sender, ElapsedEventArgs e)
            {
                lock (lock_counter)
                {
                    counter++;
                }
                //See how much threads are waiting - Is the problem exists here?
                Console.Write("{0}  \r", counter);
                if (id > 3000) 
                { 
                    id = 0; 
                }
                int s = (int)(DateTime.Now.Ticks & (int.MaxValue - 1));
                int r = new Random().Next();
                for (int i = 0; i < 80; i++)
                {
                    String sql = String.Format("update {0} set value = {1}, ans_time={2} where id={3}", tbl_id, r, s, id++);
                    connector.NoAnsExecute(sql);
                }
                lock (lock_counter)
                {
                    counter--;
                }
            }
        }
    }

    /// <summary>
    /// connector to DB 
    /// </summary>
    class dbCommector
    {
        private Object lockerObj = new object();
        private NpgsqlConnection conn = null;

        /// <summary>
        /// default #tor
        /// </summary>
        public dbCommector()
        {
            conn = new NpgsqlConnection("Server=127.0.0.1;User Id=user;" +
                                            "Password=password;Database=test_db;");
        }

        /// <summary>
        /// update query 
        /// </summary>
        /// <param name="query"></param>
        public void NoAnsExecute(String query)
        {
            lock (lockerObj)
            {
                conn.Open();
                using (NpgsqlCommand cmd = new NpgsqlCommand(query, conn))
                {
                    cmd.ExecuteNonQuery();
                    cmd.Dispose();
                }
                conn.Close();
            }
        }
    }
}

GuyDafny commented Aug 28, 2017

Tnx, duncanawoods.
I had tried it same way you had suggested, then when the counter hadn't increased, I made another test:
In order to test it, I'de made the next changes in my code:

  1. Printing how much threads are waiting
  2. If more then 30 threads are on wait, I'm droping them.
  3. In order to get faster results, I run 10 timers instead of one for each of the tables.

By the results I can guess that no thread leaking. for this test I used Win-XP on virtual box, But during last week I've got similar results using windows-10 on real computer, and ms-server 2012 on vmware.

results:
time vm-size memory usage waiting
00:00 33 22 6
00:23 65 58 31
00:29 74 65 30
00:48 102 79 21
//Went to sleep, next morning ...
16:00 1494 1325 26

using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using System.Timers;
using Npgsql;
using System.Diagnostics;

namespace ConsoleApplication1
{
    class Program
    {
        static void Main(string[] args)
        {
            List<Tester> tsts = new List<Tester>();
            //update two tables using 10 timers per each 
            for (int i = 0; i < 10; i++)
            {
                tsts.Add(new Tester("set_11"));
            }
            for (int i = 0; i < 10; i++)
            {
                tsts.Add(new Tester("set_14"));
            }
            while (true) ;
        }

        /// <summary>
        /// run the test for table
        /// </summary>
        class Tester
        {
            static object lock_counter = new object();
            static long counter  = 0;
            int id = 0;
            System.Timers.Timer tmr_update = new Timer();
            dbCommector connector = new dbCommector();
            String tbl_id = "table";
            public Tester(String TableNumber)
            {
                tbl_id = TableNumber;
                tmr_update.Interval = 10;
                tmr_update.Elapsed += new ElapsedEventHandler(InsertToDB);
                tmr_update.Start();
            }

            private void InsertToDB(object sender, ElapsedEventArgs e)
            {
                lock (lock_counter)
                {
                    counter++;
                }
                //See how much threads are waiting - Is the problem exists here?
                Console.Write("{0}  \r", counter);
                if (id > 3000) 
                { 
                    id = 0; 
                }
                int s = (int)(DateTime.Now.Ticks & (int.MaxValue - 1));
                int r = new Random().Next();
                for (int i = 0; i < 80; i++)
                {
                    String sql = String.Format("update {0} set value = {1}, ans_time={2} where id={3}", tbl_id, r, s, id++);
                    connector.NoAnsExecute(sql);
                }
                lock (lock_counter)
                {
                    counter--;
                }
            }
        }
    }

    /// <summary>
    /// connector to DB 
    /// </summary>
    class dbCommector
    {
        private Object lockerObj = new object();
        private NpgsqlConnection conn = null;

        /// <summary>
        /// default #tor
        /// </summary>
        public dbCommector()
        {
            conn = new NpgsqlConnection("Server=127.0.0.1;User Id=user;" +
                                            "Password=password;Database=test_db;");
        }

        /// <summary>
        /// update query 
        /// </summary>
        /// <param name="query"></param>
        public void NoAnsExecute(String query)
        {
            lock (lockerObj)
            {
                conn.Open();
                using (NpgsqlCommand cmd = new NpgsqlCommand(query, conn))
                {
                    cmd.ExecuteNonQuery();
                    cmd.Dispose();
                }
                conn.Close();
            }
        }
    }
}

@Andrzej-W

This comment has been minimized.

Show comment
Hide comment
@Andrzej-W

Andrzej-W Oct 8, 2017

GuyDafny - take into account, that you are using a table without index on id column. From PostgreSQL doc, serial data type: "In most cases you would also want to attach a UNIQUE or PRIMARY KEY constraint to prevent duplicate values from being inserted by accident, but this is not automatic." Without key/index PostgreSQL has to read all records from the table each time you make an update - it is CPU intensive operation (your small table is buffered in memory).

In main method you have:
while (true) ;
This instruction alone creates 100% utilization for one CPU core.

Each timer ticks every 10ms and calls InsertToDB which has for loop with 80 EXPENSIVE database updates.

Unfortunately I know nothing about garbage collector internals, but maybe your CPU is overloaded and background process used to free memory doesn't have enough time to do its work. From MS doc:
"Garbage collection occurs when one of the following conditions is true:
*The system has low physical memory.
*The memory that is used by allocated objects on the managed heap surpasses an acceptable threshold. This threshold is continuously adjusted as the process runs."
If you have enough free RAM and high CPU load it is possible that garbage collection doesn't occur and process simply allocates more memory. You can try to call GC.Collect in InsertToDB to force garbage collection. This is not recommended in production code but you can use it for testing.

Andrzej-W commented Oct 8, 2017

GuyDafny - take into account, that you are using a table without index on id column. From PostgreSQL doc, serial data type: "In most cases you would also want to attach a UNIQUE or PRIMARY KEY constraint to prevent duplicate values from being inserted by accident, but this is not automatic." Without key/index PostgreSQL has to read all records from the table each time you make an update - it is CPU intensive operation (your small table is buffered in memory).

In main method you have:
while (true) ;
This instruction alone creates 100% utilization for one CPU core.

Each timer ticks every 10ms and calls InsertToDB which has for loop with 80 EXPENSIVE database updates.

Unfortunately I know nothing about garbage collector internals, but maybe your CPU is overloaded and background process used to free memory doesn't have enough time to do its work. From MS doc:
"Garbage collection occurs when one of the following conditions is true:
*The system has low physical memory.
*The memory that is used by allocated objects on the managed heap surpasses an acceptable threshold. This threshold is continuously adjusted as the process runs."
If you have enough free RAM and high CPU load it is possible that garbage collection doesn't occur and process simply allocates more memory. You can try to call GC.Collect in InsertToDB to force garbage collection. This is not recommended in production code but you can use it for testing.

@GuyDafny

This comment has been minimized.

Show comment
Hide comment
@GuyDafny

GuyDafny Oct 8, 2017

Andrzej-W - First thing thank you for your help. the code I'd upload had been written in order to reproduce the problem as fast as possible, and isn't the production code. The real code handles udp packages that originally sent by some hundreds of embedded controllers and were added to DB using C#, while some python code reads this data, process it and update it. It's too complicated to be as example, This is the reason for the "while (true)" loop, and the lazy job I've done while creating the DB.

I had altered the loop like this:

            while (true)
            {
                System.Threading.Thread.Sleep(1000);
                GC.Collect();
            };

The CPU usage went down from 89% to 20%, but the memory still leaking.

The production machine is ms-server2012 with 16 GB ram, two processors (I do not knowthe full configuration). the test machine (after the customer said the system craches every week or so) is virtual machine with windows xp, emulated 2 GB of ram and single dual core processor.

If I'm the only one to have this problem, it might be wasting of your time to fix it.

Anyhow, when i change the next function (remark the line "cmd.ExecuteNonQuery();" ) - no memory leakage. remove the remark from it, the problem returns.

      /// <summary>
       /// update query 
       /// </summary>
       /// <param name="query"></param>
       public void NoAnsExecute(String query)
       {
           lock (lockerObj)
           {
               if (conn.State != System.Data.ConnectionState.Open)
               {
                   conn.Open();
                   cmd = new NpgsqlCommand();
                   cmd.Connection = conn;
               }
               cmd.CommandText = query;
               //cmd.ExecuteNonQuery();
           }
       }

The point isn't how much RAM do I have on this computer, but the fuct that the memory usage increased more and more (so at the end no free memory, It simply takes more time if you have more RAM).

GuyDafny commented Oct 8, 2017

Andrzej-W - First thing thank you for your help. the code I'd upload had been written in order to reproduce the problem as fast as possible, and isn't the production code. The real code handles udp packages that originally sent by some hundreds of embedded controllers and were added to DB using C#, while some python code reads this data, process it and update it. It's too complicated to be as example, This is the reason for the "while (true)" loop, and the lazy job I've done while creating the DB.

I had altered the loop like this:

            while (true)
            {
                System.Threading.Thread.Sleep(1000);
                GC.Collect();
            };

The CPU usage went down from 89% to 20%, but the memory still leaking.

The production machine is ms-server2012 with 16 GB ram, two processors (I do not knowthe full configuration). the test machine (after the customer said the system craches every week or so) is virtual machine with windows xp, emulated 2 GB of ram and single dual core processor.

If I'm the only one to have this problem, it might be wasting of your time to fix it.

Anyhow, when i change the next function (remark the line "cmd.ExecuteNonQuery();" ) - no memory leakage. remove the remark from it, the problem returns.

      /// <summary>
       /// update query 
       /// </summary>
       /// <param name="query"></param>
       public void NoAnsExecute(String query)
       {
           lock (lockerObj)
           {
               if (conn.State != System.Data.ConnectionState.Open)
               {
                   conn.Open();
                   cmd = new NpgsqlCommand();
                   cmd.Connection = conn;
               }
               cmd.CommandText = query;
               //cmd.ExecuteNonQuery();
           }
       }

The point isn't how much RAM do I have on this computer, but the fuct that the memory usage increased more and more (so at the end no free memory, It simply takes more time if you have more RAM).

@Andrzej-W

This comment has been minimized.

Show comment
Hide comment
@Andrzej-W

Andrzej-W Oct 8, 2017

Hi @GuyDafny
If there is a memory leak in ExecuteNonQuery it should be visible in less stressful test. I think that my previous suggestion about garbage collection was wrong, although there are some important observations. You call InsertToDB every 10ms from a few timers. In each call you try to do 80 database updates. Database table does not have index - PostgreSQL has to make full table scan. I think that InsertToDB needs more than 10 ms to execute, especially on slow virtual machine. If that is true you have this situation (from MSDN doc)

If processing of the Elapsed event lasts longer than Interval, the event might be raised again on another ThreadPool thread.

and here we can read:

All requests above that number remain queued until thread pool threads become available.

So, your "memory leak" is probably growing queue in ThreadPool. There is no public interface to check the queue length, but you can check GetAvailableThreads and if it returns 0 there is a big chance that internal queue is growing. Disable your timers for a while, and enable them when there is a reasonable number free threads in the pool. Alternatively add primary key on id column in all test tables and make only single update in InsertToDB. This function have to execute in less than 10 ms.

It's important to note that your "lock counter" implemented earlier is not directly related to queue in ThreadPool. Although we see that you have about 20-30 threads inside InsertToDB function and only 10 timers. This means that single call to InsertToDB takes longer than 10 ms, and as I said earlier internal queue in ThreadPool probably grows indefinitely.

Andrzej-W commented Oct 8, 2017

Hi @GuyDafny
If there is a memory leak in ExecuteNonQuery it should be visible in less stressful test. I think that my previous suggestion about garbage collection was wrong, although there are some important observations. You call InsertToDB every 10ms from a few timers. In each call you try to do 80 database updates. Database table does not have index - PostgreSQL has to make full table scan. I think that InsertToDB needs more than 10 ms to execute, especially on slow virtual machine. If that is true you have this situation (from MSDN doc)

If processing of the Elapsed event lasts longer than Interval, the event might be raised again on another ThreadPool thread.

and here we can read:

All requests above that number remain queued until thread pool threads become available.

So, your "memory leak" is probably growing queue in ThreadPool. There is no public interface to check the queue length, but you can check GetAvailableThreads and if it returns 0 there is a big chance that internal queue is growing. Disable your timers for a while, and enable them when there is a reasonable number free threads in the pool. Alternatively add primary key on id column in all test tables and make only single update in InsertToDB. This function have to execute in less than 10 ms.

It's important to note that your "lock counter" implemented earlier is not directly related to queue in ThreadPool. Although we see that you have about 20-30 threads inside InsertToDB function and only 10 timers. This means that single call to InsertToDB takes longer than 10 ms, and as I said earlier internal queue in ThreadPool probably grows indefinitely.

@roji

This comment has been minimized.

Show comment
Hide comment
@roji

roji Jun 9, 2018

Member

Agree with @Andrzej-W:any leak here seems to be a result more of the test scenario and not as a result of any issue with Npgsql itself. No leaks have been reported and Npgsql is in wide production use. I'll reopen if a simpler demonstration of the problem is submitted - there's really no need for a massively concurrent system to demonstrate a leak, a simple loop should suffice.

Member

roji commented Jun 9, 2018

Agree with @Andrzej-W:any leak here seems to be a result more of the test scenario and not as a result of any issue with Npgsql itself. No leaks have been reported and Npgsql is in wide production use. I'll reopen if a simpler demonstration of the problem is submitted - there's really no need for a massively concurrent system to demonstrate a leak, a simple loop should suffice.

@roji roji closed this Jun 9, 2018

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment