Hi,
We're in the process of updating our logging from version 1.2.0 beta 8 (DLL
version 1.2.0.30714) to the 1.2.9 beta and are experiencing an uncaught error
when our test system is placed under load.
We're running version 1.1 of the MS .Net framework on Windows 2003 Server, and
have also seen this on Windows XP Pro SP2.
We have a server process which catches all exceptions and logs them as errors.
The stack trace we are getting is as follows:
ERROR[slf5s.PRIORITY]
(null)[slf5s.NDC]
2132[slf5s.THREAD]
com.esendex.ems.ScheduledSubmissionServer[slf5s.CATEGORY]
com.esendex.common.statusservice.Status.LogError(:0)[slf5s.LOCATION]
Error calling ProcessMessages[slf5s.MESSAGE]
System.IndexOutOfRangeException: Probable I/O race condition detected while
copying memory. The I/O package is not thread safe by default. In
multithreaded applications, a stream must be accessed in a thread-safe way,
such as a thread-safe wrapper returned by TextReader's or TextWriter's
Synchronized methods. This also applies to classes like StreamWriter and
StreamReader.
Server stack trace:
at System.Buffer.InternalBlockCopy(Array src, Int32 srcOffset, Array dst,
Int32 dstOffset, Int32 count)
at System.IO.StreamWriter.Write(Char[] buffer, Int32 index, Int32 count)
at System.IO.TextWriter.WriteLine(String value)
at System.IO.SyncTextWriter.WriteLine(String value)
at log4net.Util.LogLog.Error(String message, Exception exception)
at log4net.Util.AppenderAttachedImpl.AppendLoopOnAppenders(LoggingEvent
loggingEvent)
at log4net.Repository.Hierarchy.Logger.CallAppenders(LoggingEvent
loggingEvent)
at log4net.Repository.Hierarchy.Logger.ForcedLog(Type
callerStackBoundaryDeclaringType, Level level, Object message, Exception
exception)
at log4net.Repository.Hierarchy.Logger.Log(Type
callerStackBoundaryDeclaringType, Level level, Object message, Exception
exception)
at log4net.Core.LogImpl.Debug(Object message)
at
com.esendex.ems.datamappers.ScheduledSubmissionBatchDM.SelectBatchForDateTime(DateTime
date)
at
com.esendex.ems.implementation.facades.ScheduledSubmissionFacadeImpl.GetBatchesToSubmit(DateTime
date)
at
com.esendex.ems.facades.ScheduledSubmissionFacade.GetBatchesToSubmit(DateTime
date)
at
System.Runtime.Remoting.Messaging.StackBuilderSink.PrivateProcessMessage(MethodBase
mb, Object[] args, Object server, Int32 methodPtr, Boolean fExecuteInContext,
Object[]& outArgs)
at
System.Runtime.Remoting.Messaging.StackBuilderSink.SyncProcessMessage(IMessage
msg, Int32 methodPtr, Boolean fExecuteInContext)
Exception rethrown at [0]:
at System.Runtime.Remoting.Proxies.RealProxy.HandleReturnMessage(IMessage
reqMsg, IMessage retMsg)
at System.Runtime.Remoting.Proxies.RealProxy.PrivateInvoke(MessageData&
msgData, Int32 type)
at
com.esendex.ems.facades.ScheduledSubmissionFacade.GetBatchesToSubmit(DateTime
date)
at com.esendex.ems.ScheduledSubmissionServer.ProcessMessages()
at com.esendex.ems.ScheduledSubmissionServer.Run()
The server process is logging to one file, while the Debug line (the line "at
log4net.Core.LogImpl.Debug(Object message)" in the stack trace) is meant to log
to a different file (which other threads will be logging to). The server code
is in a DLL that is late loaded from the GAC by a host EXE program. This is
logging correctly as the above trace is from that log. The server DLL then
calls through to a COM+ component. The COM+ component late loads an
implementation assembly from the GAC. It is the logging within this
implementation DLL that is throwing the exception.
I'm logging to a log4net.Appender.RollingFileAppender with the following
configuration:
<appender name="EsendexRollingFileAppender"
type="log4net.Appender.RollingFileAppender">
<param name="File" value="${log.dir.unix}/${namespace}.txt" />
<param name="AppendToFile" value="true" />
<param name="MaxSizeRollBackups" value="10" />
<param name="MaximumFileSize" value="5000000" />
<param name="RollingStyle" value="Size" />
<param name="StaticLogFileName" value="true" />
<layout type="log4net.Layout.PatternLayout">
<param name="Header" value="---Start of session---\r\n" />
<param name="Footer" value="---End of session---\r\n" />
<param name="ConversionPattern"
value="[slf5s.start]%d{DATE}[slf5s.DATE]%n%p[slf5s.PRIORITY]%n%x[slf5s.NDC]%n%t[slf5s.THREAD]%n%c[slf5s.CATEGORY]%n%l[slf5s.LOCATION]%n%m[slf5s.MESSAGE]%n%n"
/>
</layout>
</appender>
(${log.dir.unix} and ${namespace} are other variables within the config file)
I've had a look around the known bugs with this version and haven't found a
resolution to this. We are not experiencing this problem with the older
version 1.2.0 either.
Is there anything we can do to stop this exception being thrown?
Apologies if this is a known problem with a simple resolution, but I've been
looking for a solution all day and haven't found anything.
Regards
Ian Dykes
-
Software Developer
Esendex Ltd
49 Stoney Street
Nottingham NG1 1LX
http://www.esendex.com
Tel: +44 (0) 115 959 7962
Fax: +44 (0) 115 959 7966
Esendex voted as one of O2's "50 To Watch In Mobile". Read the full story at
http://www.realbusiness.co.uk/mobile
