You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4net-dev@logging.apache.org by "rauzy (JIRA)" <ji...@apache.org> on 2009/02/07 00:32:59 UTC

[jira] Created: (LOG4NET-198) Memory leak on a very basic code

Memory leak on a very basic code
--------------------------------

                 Key: LOG4NET-198
                 URL: https://issues.apache.org/jira/browse/LOG4NET-198
             Project: Log4net
          Issue Type: Test
          Components: Core
    Affects Versions: 1.2.10
         Environment: windows xp sp3
            Reporter: rauzy


I build a simple form with a single button that start a timer execute every second, the task of this timer is to execute the following line:

log.Debug("Hello");

and I observe a memory leak.

See Below.


using System;
using System.Collections.Generic;
using System.ComponentModel;
using System.Data;
using System.Drawing;
using System.Text;
using System.Windows.Forms;
using log4net;
using log4net.Config;

namespace WindowsFormsApplication1
{
    public partial class Form1 : Form
    {
        private static readonly ILog log = LogManager.GetLogger(typeof(Form1));
        public Form1()
        {
            InitializeComponent();
        }

        private void button1_Click(object sender, EventArgs e)
        {
            XmlConfigurator.Configure();
            FreqTimers.Start();
        }

        private void FreqTimers_Tick(object sender, EventArgs e)
        {
            log.Debug("demo");
        }
    }
}

with an app.config like 


<?xml version="1.0" encoding="utf-8" ?>
<configuration>
  <configSections>
    <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
  </configSections>
  <log4net debug="true">
    <appender name="RollingLogFileAppender" type="log4net.Appender.RollingFileAppender">
      <file value="C:\\Temp\\TestMailer.log" />
      <appendToFile value="true" />
      <rollingStyle value="Size" />
      <maxSizeRollBackups value="10" />
      <maximumFileSize value="10MB" />
      <staticLogFileName value="true" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%-5p %d - %m  %-18.18M %n" />
      </layout>
    </appender>
    <root>
      <level value="DEBUG" />
      <appender-ref ref="RollingLogFileAppender" />
    </root>
  </log4net>
</configuration>

If you monitor the application, you see that the memory usage increase. Why? I can post the source solution if needed.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Issue Comment Edited: (LOG4NET-198) Memory leak on a very basic code

Posted by "rauzy (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/LOG4NET-198?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12671377#action_12671377 ] 

lecedre edited comment on LOG4NET-198 at 2/6/09 3:59 PM:
-------------------------------------------------------

You can see as well that if you switch the root logging from DEBUG to INFO, you don't have a memory leak any more so it should be a dispose method somewhere which is missing

      was (Author: lecedre):
    You can see as well that if you switch the root logging from DEBUG to INFO, you don't have a memory leak any more so it should be a dispose method somewhere.
  
> Memory leak on a very basic code
> --------------------------------
>
>                 Key: LOG4NET-198
>                 URL: https://issues.apache.org/jira/browse/LOG4NET-198
>             Project: Log4net
>          Issue Type: Test
>          Components: Core
>    Affects Versions: 1.2.10
>         Environment: windows xp sp3
>            Reporter: rauzy
>         Attachments: WindowsFormsApplication1.zip
>
>
> I build a simple form with a single button that start a timer execute every second, the task of this timer is to execute the following line:
> log.Debug("Hello");
> and I observe a memory leak.
> See Below.
> using System;
> using System.Collections.Generic;
> using System.ComponentModel;
> using System.Data;
> using System.Drawing;
> using System.Text;
> using System.Windows.Forms;
> using log4net;
> using log4net.Config;
> namespace WindowsFormsApplication1
> {
>     public partial class Form1 : Form
>     {
>         private static readonly ILog log = LogManager.GetLogger(typeof(Form1));
>         public Form1()
>         {
>             InitializeComponent();
>         }
>         private void button1_Click(object sender, EventArgs e)
>         {
>             XmlConfigurator.Configure();
>             FreqTimers.Start();
>         }
>         private void FreqTimers_Tick(object sender, EventArgs e)
>         {
>             log.Debug("demo");
>         }
>     }
> }
> with an app.config like 
> <?xml version="1.0" encoding="utf-8" ?>
> <configuration>
>   <configSections>
>     <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
>   </configSections>
>   <log4net debug="true">
>     <appender name="RollingLogFileAppender" type="log4net.Appender.RollingFileAppender">
>       <file value="C:\\Temp\\TestMailer.log" />
>       <appendToFile value="true" />
>       <rollingStyle value="Size" />
>       <maxSizeRollBackups value="10" />
>       <maximumFileSize value="10MB" />
>       <staticLogFileName value="true" />
>       <layout type="log4net.Layout.PatternLayout">
>         <conversionPattern value="%-5p %d - %m  %-18.18M %n" />
>       </layout>
>     </appender>
>     <root>
>       <level value="DEBUG" />
>       <appender-ref ref="RollingLogFileAppender" />
>     </root>
>   </log4net>
> </configuration>
> If you monitor the application, you see that the memory usage increase. Why? I can post the source solution if needed.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Updated: (LOG4NET-198) Memory leak on a very basic code

Posted by "rauzy (JIRA)" <ji...@apache.org>.
     [ https://issues.apache.org/jira/browse/LOG4NET-198?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

rauzy updated LOG4NET-198:
--------------------------

    Attachment: WindowsFormsApplication1.zip

Her is the code for testing

> Memory leak on a very basic code
> --------------------------------
>
>                 Key: LOG4NET-198
>                 URL: https://issues.apache.org/jira/browse/LOG4NET-198
>             Project: Log4net
>          Issue Type: Test
>          Components: Core
>    Affects Versions: 1.2.10
>         Environment: windows xp sp3
>            Reporter: rauzy
>         Attachments: WindowsFormsApplication1.zip
>
>
> I build a simple form with a single button that start a timer execute every second, the task of this timer is to execute the following line:
> log.Debug("Hello");
> and I observe a memory leak.
> See Below.
> using System;
> using System.Collections.Generic;
> using System.ComponentModel;
> using System.Data;
> using System.Drawing;
> using System.Text;
> using System.Windows.Forms;
> using log4net;
> using log4net.Config;
> namespace WindowsFormsApplication1
> {
>     public partial class Form1 : Form
>     {
>         private static readonly ILog log = LogManager.GetLogger(typeof(Form1));
>         public Form1()
>         {
>             InitializeComponent();
>         }
>         private void button1_Click(object sender, EventArgs e)
>         {
>             XmlConfigurator.Configure();
>             FreqTimers.Start();
>         }
>         private void FreqTimers_Tick(object sender, EventArgs e)
>         {
>             log.Debug("demo");
>         }
>     }
> }
> with an app.config like 
> <?xml version="1.0" encoding="utf-8" ?>
> <configuration>
>   <configSections>
>     <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
>   </configSections>
>   <log4net debug="true">
>     <appender name="RollingLogFileAppender" type="log4net.Appender.RollingFileAppender">
>       <file value="C:\\Temp\\TestMailer.log" />
>       <appendToFile value="true" />
>       <rollingStyle value="Size" />
>       <maxSizeRollBackups value="10" />
>       <maximumFileSize value="10MB" />
>       <staticLogFileName value="true" />
>       <layout type="log4net.Layout.PatternLayout">
>         <conversionPattern value="%-5p %d - %m  %-18.18M %n" />
>       </layout>
>     </appender>
>     <root>
>       <level value="DEBUG" />
>       <appender-ref ref="RollingLogFileAppender" />
>     </root>
>   </log4net>
> </configuration>
> If you monitor the application, you see that the memory usage increase. Why? I can post the source solution if needed.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (LOG4NET-198) Memory leak on a very basic code

Posted by "rauzy (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/LOG4NET-198?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12671377#action_12671377 ] 

rauzy commented on LOG4NET-198:
-------------------------------

You can see as well that if you switch the root logging from DEBUG to INFO, you don't have a memory leak any more so it should be a dispose method somewhere.

> Memory leak on a very basic code
> --------------------------------
>
>                 Key: LOG4NET-198
>                 URL: https://issues.apache.org/jira/browse/LOG4NET-198
>             Project: Log4net
>          Issue Type: Test
>          Components: Core
>    Affects Versions: 1.2.10
>         Environment: windows xp sp3
>            Reporter: rauzy
>         Attachments: WindowsFormsApplication1.zip
>
>
> I build a simple form with a single button that start a timer execute every second, the task of this timer is to execute the following line:
> log.Debug("Hello");
> and I observe a memory leak.
> See Below.
> using System;
> using System.Collections.Generic;
> using System.ComponentModel;
> using System.Data;
> using System.Drawing;
> using System.Text;
> using System.Windows.Forms;
> using log4net;
> using log4net.Config;
> namespace WindowsFormsApplication1
> {
>     public partial class Form1 : Form
>     {
>         private static readonly ILog log = LogManager.GetLogger(typeof(Form1));
>         public Form1()
>         {
>             InitializeComponent();
>         }
>         private void button1_Click(object sender, EventArgs e)
>         {
>             XmlConfigurator.Configure();
>             FreqTimers.Start();
>         }
>         private void FreqTimers_Tick(object sender, EventArgs e)
>         {
>             log.Debug("demo");
>         }
>     }
> }
> with an app.config like 
> <?xml version="1.0" encoding="utf-8" ?>
> <configuration>
>   <configSections>
>     <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
>   </configSections>
>   <log4net debug="true">
>     <appender name="RollingLogFileAppender" type="log4net.Appender.RollingFileAppender">
>       <file value="C:\\Temp\\TestMailer.log" />
>       <appendToFile value="true" />
>       <rollingStyle value="Size" />
>       <maxSizeRollBackups value="10" />
>       <maximumFileSize value="10MB" />
>       <staticLogFileName value="true" />
>       <layout type="log4net.Layout.PatternLayout">
>         <conversionPattern value="%-5p %d - %m  %-18.18M %n" />
>       </layout>
>     </appender>
>     <root>
>       <level value="DEBUG" />
>       <appender-ref ref="RollingLogFileAppender" />
>     </root>
>   </log4net>
> </configuration>
> If you monitor the application, you see that the memory usage increase. Why? I can post the source solution if needed.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


RE: [jira] Commented: (LOG4NET-198) Memory leak on a very basic code

Posted by "Walden H. Leverich" <Wa...@TechSoftInc.com>.
> I have fixed this issue by editing...

No you haven't. All you've done is force the GC (well, actually strongly suggest to the GC) that it run now. Apparently the GC didn't see a need to run, so it didn't. Remember GC doesn't say it will clean up memory as soon as it's released, but rather that it will clean up memory at some point. A better test would be to add memory pressure and see if the GC kicks in.

-Walden

-- 
Walden H Leverich III
Tech Software
(516) 627-3800 x3051
WaldenL@TechSoftInc.com
http://www.TechSoftInc.com

Quiquid latine dictum sit altum viditur.
(Whatever is said in Latin seems profound.)

[jira] Commented: (LOG4NET-198) Memory leak on a very basic code

Posted by "rauzy (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/LOG4NET-198?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12671451#action_12671451 ] 

rauzy commented on LOG4NET-198:
-------------------------------

I have fixed this issue by editing Logger.cs and adding the following line in Log : GC.Collect();

See below:

		virtual public void Log(Type callerStackBoundaryDeclaringType, Level level, object message, Exception exception) 
		{
			try
			{
				if (IsEnabledFor(level))
				{
					ForcedLog((callerStackBoundaryDeclaringType != null) ? callerStackBoundaryDeclaringType : ThisDeclaringType, level, message, exception);
                    GC.Collect();
				}
			}
			catch (Exception ex)
			{
				log4net.Util.LogLog.Error("Log: Exception while logging", ex);
			}
			catch
			{
				log4net.Util.LogLog.Error("Log: Exception while logging");
			}
		}


> Memory leak on a very basic code
> --------------------------------
>
>                 Key: LOG4NET-198
>                 URL: https://issues.apache.org/jira/browse/LOG4NET-198
>             Project: Log4net
>          Issue Type: Test
>          Components: Core
>    Affects Versions: 1.2.10
>         Environment: windows xp sp3
>            Reporter: rauzy
>         Attachments: WindowsFormsApplication1.zip
>
>
> I build a simple form with a single button that start a timer execute every second, the task of this timer is to execute the following line:
> log.Debug("Hello");
> and I observe a memory leak.
> See Below.
> using System;
> using System.Collections.Generic;
> using System.ComponentModel;
> using System.Data;
> using System.Drawing;
> using System.Text;
> using System.Windows.Forms;
> using log4net;
> using log4net.Config;
> namespace WindowsFormsApplication1
> {
>     public partial class Form1 : Form
>     {
>         private static readonly ILog log = LogManager.GetLogger(typeof(Form1));
>         public Form1()
>         {
>             InitializeComponent();
>         }
>         private void button1_Click(object sender, EventArgs e)
>         {
>             XmlConfigurator.Configure();
>             FreqTimers.Start();
>         }
>         private void FreqTimers_Tick(object sender, EventArgs e)
>         {
>             log.Debug("demo");
>         }
>     }
> }
> with an app.config like 
> <?xml version="1.0" encoding="utf-8" ?>
> <configuration>
>   <configSections>
>     <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
>   </configSections>
>   <log4net debug="true">
>     <appender name="RollingLogFileAppender" type="log4net.Appender.RollingFileAppender">
>       <file value="C:\\Temp\\TestMailer.log" />
>       <appendToFile value="true" />
>       <rollingStyle value="Size" />
>       <maxSizeRollBackups value="10" />
>       <maximumFileSize value="10MB" />
>       <staticLogFileName value="true" />
>       <layout type="log4net.Layout.PatternLayout">
>         <conversionPattern value="%-5p %d - %m  %-18.18M %n" />
>       </layout>
>     </appender>
>     <root>
>       <level value="DEBUG" />
>       <appender-ref ref="RollingLogFileAppender" />
>     </root>
>   </log4net>
> </configuration>
> If you monitor the application, you see that the memory usage increase. Why? I can post the source solution if needed.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.


[jira] Commented: (LOG4NET-198) Memory leak on a very basic code

Posted by "Ron Grabowski (JIRA)" <ji...@apache.org>.
    [ https://issues.apache.org/jira/browse/LOG4NET-198?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=12671515#action_12671515 ] 

Ron Grabowski commented on LOG4NET-198:
---------------------------------------

When I run the code below without starting logTimer Environment.WorkingSet stays the same. When I run the code as shown the WorkingSet slowly increases:

namespace ConsoleApplication1
{
    class Program
    {
        private static readonly ILog log = LogManager.GetLogger(typeof(Program)); 

        static void Main(string[] args)
        {
            XmlConfigurator.Configure();

            var logTimer = new Timer(1000);
            logTimer.Elapsed += delegate { log.Debug("Hello World"); };
            logTimer.Start();

            var workingSetTimer = new Timer(500);
            workingSetTimer.Elapsed += delegate { Console.WriteLine(Environment.WorkingSet); };
            workingSetTimer.Start();
            
            Console.ReadLine();
        }
    }
}

When I use the BasicConfigurator with this appender:

class NullAppender : IAppender
{
    public void Close()
    {
        // empty
    }

    public void DoAppend(LoggingEvent loggingEvent)
    {
        // empty
    }

    public string Name
    {
        get { return "NullAppender"; }
        set { /* empty */ }
    }
}

The WorkingSet value remains the same. That leads me to believe that if there is any kind of leak its not in the core log4net code. I also ran this to see if there is a natural increase in memory usage when you're writing to the file system using a typical FileStream due to the Framework's internal buffering:

 var fs = File.OpenWrite("log.txt");
 var sw = new StreamWriter(fs);
 var logTimer = new Timer(1000);
 logTimer.Elapsed += delegate { sw.Write("Hello World"); };
 logTimer.Start();

There wasn't an increase in the WorkingSet. 

That's my 15min short dive into the problem. I'm not sure WorkingSet is the best measure for this type of stuff. I ran that code through ANTS Memory Profiler but nothing jumped out at me. I don't think GC.Collect() is the correct fix. If there's a problem it'll most likely be at the appender level.

> Memory leak on a very basic code
> --------------------------------
>
>                 Key: LOG4NET-198
>                 URL: https://issues.apache.org/jira/browse/LOG4NET-198
>             Project: Log4net
>          Issue Type: Test
>          Components: Core
>    Affects Versions: 1.2.10
>         Environment: windows xp sp3
>            Reporter: rauzy
>         Attachments: WindowsFormsApplication1.zip
>
>
> I build a simple form with a single button that start a timer execute every second, the task of this timer is to execute the following line:
> log.Debug("Hello");
> and I observe a memory leak.
> See Below.
> using System;
> using System.Collections.Generic;
> using System.ComponentModel;
> using System.Data;
> using System.Drawing;
> using System.Text;
> using System.Windows.Forms;
> using log4net;
> using log4net.Config;
> namespace WindowsFormsApplication1
> {
>     public partial class Form1 : Form
>     {
>         private static readonly ILog log = LogManager.GetLogger(typeof(Form1));
>         public Form1()
>         {
>             InitializeComponent();
>         }
>         private void button1_Click(object sender, EventArgs e)
>         {
>             XmlConfigurator.Configure();
>             FreqTimers.Start();
>         }
>         private void FreqTimers_Tick(object sender, EventArgs e)
>         {
>             log.Debug("demo");
>         }
>     }
> }
> with an app.config like 
> <?xml version="1.0" encoding="utf-8" ?>
> <configuration>
>   <configSections>
>     <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
>   </configSections>
>   <log4net debug="true">
>     <appender name="RollingLogFileAppender" type="log4net.Appender.RollingFileAppender">
>       <file value="C:\\Temp\\TestMailer.log" />
>       <appendToFile value="true" />
>       <rollingStyle value="Size" />
>       <maxSizeRollBackups value="10" />
>       <maximumFileSize value="10MB" />
>       <staticLogFileName value="true" />
>       <layout type="log4net.Layout.PatternLayout">
>         <conversionPattern value="%-5p %d - %m  %-18.18M %n" />
>       </layout>
>     </appender>
>     <root>
>       <level value="DEBUG" />
>       <appender-ref ref="RollingLogFileAppender" />
>     </root>
>   </log4net>
> </configuration>
> If you monitor the application, you see that the memory usage increase. Why? I can post the source solution if needed.

-- 
This message is automatically generated by JIRA.
-
You can reply to this email to add a comment to the issue online.