Memory leaks with large multi-threaded application.

[Noel Lysaght <nl...@zarion.com>]

Hi folks,

I'm pretty sure I've found a large memory leak when running
multi-threaded applications and using log4net tracing. I've isolated it
down to log4net by commenting out the <log4net> node out of the
configuration file.

We've coded log4net (the latest beta version 1.2.0-beta8) into our
application. With log4net enabled we see our virtual memory increasing
and never decreasing, over a period of time and particularly with stress
testing the server runs out of memory and everything grinds to a halt.

I'm afraid I don't have time to try and reproduce the problem in a
sample project for you as I now need to look at switching back to
release 1.0 of log4net to see if that will sort out the problem.

What I can point out to you is the following; I hope it helps in
diagnosing the issue also I'll include the configuration I'm using at
the end of the mail.
1.	It happens with both FileAppenders and
OutputDebugStringAppenders, I have not tried it with any others.
2.	When analyzing the memory usage using a memory profiler, the
managed heap memory was fine all the memory seemed to be allocated to
Win32.
3.	The number of handles used never decreases and gets very large,
when running 50 simulatenous threads which have logging contained in
their execution paths then number of handles in the application rose to
several thousand quite quickly.
4.	It happens in both debug and release builds of our application.
5.	I'm only using the release build of log4net for .NET version
1.1.
6.	The platform is WindowsXP Profession (for developers) and W2K
Server deployment.
7.	Most annoyingly, it does not happen all the time. For example I
noticed the memory issue a while ago and tried to trace it down. I did
not pin it down and then it stopped happening. We deployed the software
to a test server (W2K) and it leaked like a sieve as soon as it started
running there. I spent 2 days tracking down the problem and then the W2K
machine stopped leaking memory without any changes been applied. The W2K
machine had been rebooted several times over the course of those 2 days.
8.	Once it does start leaking memory, it keeps leaking memory after
every run. Commenting out the log4net node in the config file, stops the
memory leak and commenting it back in again starts the memory leak.
9.	You have to comment out the log4net node for it to stop, setting
the reporting level to ERROR or FATAL when nothing should normally be
logged still reproduces the leak.

I'm not joking about this bug or trying to lead you up the garden path.
Please feel free to contact me about any questions you have, my business
email address and contact details are below. Like I said, I'd love to
get a small sample project together to reproduce this issue but we are
under severe time constrains on the project delivery (isn't everyone).

Here's the configuration node I am using.
	<log4net>
		<appender name="FileAppender"
type="log4net.Appender.FileAppender">
			<param name="File" value="log-file.txt" />
			<param name="AppendToFile" value="true" />
			<layout type="log4net.Layout.PatternLayout">
				<param name="ConversionPattern"
value="%d [%t] %-5p %c [%x] %M - %m%n" />
			</layout>
		</appender>
		<appender name="OutputDebugStringAppender"
type="log4net.Appender.OutputDebugStringAppender" >
			<layout type="log4net.Layout.PatternLayout">
				<param name="ConversionPattern"
value="%d\t[%t]\t%-5p\t%c\t[%x]\t%m%n" />
			</layout>
		</appender>
		<root>
			<level value="Error" />
	<!--		<appender-ref ref="OutputDebugStringAppender" />
-->
			<appender-ref ref="FileAppender" />
		</root>
	</log4net>

Here's a sample of how we are using it in code.
	Initialized by the following code..
        log4net.Config.DOMConfigurator.Configure()
        _Log.Info("Initialised Logging")

	Utilized in a class by the following
    Private Shared _Log As log4net.ILog =
log4net.LogManager.GetLogger(GetType(PoolManager))

	Here's a sample method of a class method with logging contained.
    Public Shared Sub [Stop]()
        _Log.Info("Push")
        Try
            SyncLock _LockContext
 
'-----------------------------------------------------------------------
-----------------------------
                ' Stop the service but only if it was started, again we
want to proivide synchronous access to this
                ' request so we put a SyncLock (Monitor object) around
the block.
 
'-----------------------------------------------------------------------
-----------------------------
                If _State = StateEnum.Starting OrElse _State =
StateEnum.Started Then
                    _State = StateEnum.Stopped
                    ConnectionMonitor.StopMonitoring()
                    Call LogoutPoolUsers()
                    _State = StateEnum.Stopped
                Else
                    _Log.Warn("Attempting to stop the pool manager when
it was not started.....")
                End If
            End SyncLock
        Catch ex As Exception
            _Log.Error(ex)
            Throw
        End Try
        _Log.Info("Pop")
    End Sub




Noel Lysaght
Zarion Ltd.
3 Westland Square, Pearse St.
Dublin 2, Ireland.

Simplifying, Automating and Integrating Business Processes
Voice: +353-(0)1-240-5200               UK: +44-(0)20-7495-7511
Direct: +353-(0)1-240-5210
Fax:    +353-(0)1-670-7868              UK: +44-(0)20-7153-4401
Web:   <www.zarion.com>
Email:  nlysaght@zarion.com <ma...@zarion.com>
This e-mail message and attachments is strictly confidential and is
intended for use by the addressee only. If you are not the intended
recipient then you have received this item in error and should contact
the sender by reply e-mail immediately and permanently delete the
material. If you have received this item in error you must not copy,
print, store, use or disclose the contents of this email to anybody
else.