Details

    • Type: Test Test
    • Status: Resolved
    • Priority: Major Major
    • Resolution: Invalid
    • Affects Version/s: 1.2.10
    • Fix Version/s: None
    • Component/s: Core
    • Labels:
      None
    • Environment:
      windows xp sp3

      Description

      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.

        Activity

        Hide
        Dominik Psenner added a comment -

        If a call to GC.Collect() is able to "solve" the memory leak, there is no memory leak at all. GC.Collect() gives the garbage collector just poke to wake up earlier than he would do by himself.

        Show
        Dominik Psenner added a comment - If a call to GC.Collect() is able to "solve" the memory leak, there is no memory leak at all. GC.Collect() gives the garbage collector just poke to wake up earlier than he would do by himself.
        Hide
        Ron Grabowski added a comment -

        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.

        Show
        Ron Grabowski added a comment - 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.
        Hide
        rauzy added a comment -

        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"); }

        }

        Show
        rauzy added a comment - 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"); } }
        Hide
        rauzy added a comment - - edited

        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

        Show
        rauzy added a comment - - edited 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
        Hide
        rauzy added a comment -

        Her is the code for testing

        Show
        rauzy added a comment - Her is the code for testing

          People

          • Assignee:
            Unassigned
            Reporter:
            rauzy
          • Votes:
            1 Vote for this issue
            Watchers:
            2 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development