You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4net-user@logging.apache.org by Ananth Tatachar <an...@gmail.com> on 2014/08/14 17:51:11 UTC
Inconsistent results observed while using BufferingForwardAppender
I am working with log4net version : 1.2.12.0 .
I am getting inconsistent results , while using RollingFileAppender with
BufferingForwardAppender.
My application is a multithreaded application. I spawned 5 threads Each
will call the constructor of MyClass and SomeFunction once.
My application's sertup is as follows:
Web.config:
-------------------------------
<appender name="RollingLocalFileAppender" type="
log4net.Appender.RollingFileAppender
<http://opengrok.factset.com/source/s?path=log4net.Appender.RollingFileAppender&project=/platform/wauds/mainline>
">
<file type="log4net.Util.PatternString
<http://opengrok.factset.com/source/s?path=log4net.Util.PatternString&project=/platform/wauds/mainline>
" value="C:\Logs\TFile.log" />
<rollingStyle value="Date" />
<datePattern value="yyyy-MM-dd" />
<maxSizeRollBackups value="10" />
<appendToFile value="true" />
<layout type="log4net.Layout.PatternLayout
<http://opengrok.factset.com/source/s?path=log4net.Layout.PatternLayout&project=/platform/wauds/mainline>
">
<conversionPattern value="%level %date{yyyy-MM-dd'T'HH:mm:ss.fffzzz
<http://opengrok.factset.com/source/s?path=ss.fffzzz&project=/platform/wauds/mainline>}
%property{hostname} %property{guid} %message%newline" />
</layout>
</appender>
<appender name="BufferedFileAppender" type="
log4net.Appender.BufferingForwardingAppender
<http://opengrok.factset.com/source/s?path=log4net.Appender.BufferingForwardingAppender&project=/platform/wauds/mainline>
">
<bufferSize value="512" />
<evaluator type="log4net.Core.TimeEvaluator
<http://opengrok.factset.com/source/s?path=log4net.Core.TimeEvaluator&project=/platform/wauds/mainline>
">
<interval value="10" />
<!--Send buffered events immediately if 10 seconds pass-->
</evaluator>
<Fix value="0" />
<!--Buffering can have severe performance degradation if this is set
to the default (ALL)-->
</appender>
Logging Class:
--------------------------
Class MyClass
{
public MyClass()
{
Log4net.ThreadContext.Properties["guid"] = Guid.NewGuid();
}
public void SomeFunction()
{
Ilog log = LogManager.GetLogger(typeof(MyClass));
Log.Info("my message");
}
}
Tfile.log(Result)
----------------------
Observed Results:
INFO 2014-08-14T10:47:36.659-04:00 ANANTHTATACHAR MyAudsDigest
[LQR-Y8c71EmtWl7ZqItYoQ] my message
INFO 2014-08-14T10:47:36.659-04:00 ANANTHTATACHAR MyAudsDigest
[9hDzS-_Su0SrEoXZF_aGMw] my message
INFO 2014-08-14T10:47:36.729-04:00 ANANTHTATACHAR MyAudsDigest
[GsxT7aTfNEq1uIsqPYeZ5w] my message
INFO 2014-08-14T10:47:36.789-04:00 ANANTHTATACHAR MyAudsDigest
[9hDzS-_Su0SrEoXZF_aGMw] my message
INFO 2014-08-14T10:47:36.955-04:00 ANANTHTATACHAR MyAudsDigest
[9hDzS-_Su0SrEoXZF_aGMw] my message
Expected Results:
Unique guid in all the messages.
--------------------------------------------------------------------------------------------------------------------------------------
I understand that Fix value NONE in
log4net.Appender.BufferingForwardingAppender
<http://opengrok.factset.com/source/s?path=log4net.Appender.BufferingForwardingAppender&project=/platform/wauds/mainline>
will not fix any volatile variables , but making it all results in all my
guids in all the 5 messages becoming same.
Could anybody please tell me how to fix this issue?
Re: Inconsistent results observed while using BufferingForwardAppender
Posted by Ananth Tatachar <an...@gmail.com>.
Thanks a lot Sir, I will implement this idea and I will let you know if it
works for me.
On Thu, Aug 14, 2014 at 1:45 PM, Michael Schall <mi...@gmail.com>
wrote:
> Try adding the thread name to your conversion to ensure it is a different
> thread
>
> <conversionPattern value="%level %date{yyyy-MM-dd'T'HH:mm:ss.fffzzz
> <http://opengrok.factset.com/source/s?path=ss.fffzzz&project=/platform/wauds/mainline>}
> %property{hostname} [%thread] %property{guid} %message%newline" />
>
> It seems more likely that a thread is being reused.
>
> Mike
>
>
> On Thu, Aug 14, 2014 at 10:51 AM, Ananth Tatachar <
> ananth.tatachar@gmail.com> wrote:
>
>> I am working with log4net version : 1.2.12.0 .
>>
>>
>>
>> I am getting inconsistent results , while using RollingFileAppender with
>> BufferingForwardAppender.
>>
>> My application is a multithreaded application. I spawned 5 threads Each
>> will call the constructor of MyClass and SomeFunction once.
>>
>> My application's sertup is as follows:
>>
>>
>>
>> Web.config:
>>
>> -------------------------------
>>
>> <appender name="RollingLocalFileAppender" type="
>> log4net.Appender.RollingFileAppender
>> <http://opengrok.factset.com/source/s?path=log4net.Appender.RollingFileAppender&project=/platform/wauds/mainline>
>> ">
>> <file type="log4net.Util.PatternString
>> <http://opengrok.factset.com/source/s?path=log4net.Util.PatternString&project=/platform/wauds/mainline>
>> " value="C:\Logs\TFile.log" />
>> <rollingStyle value="Date" />
>> <datePattern value="yyyy-MM-dd" />
>> <maxSizeRollBackups value="10" />
>> <appendToFile value="true" />
>> <layout type="log4net.Layout.PatternLayout
>> <http://opengrok.factset.com/source/s?path=log4net.Layout.PatternLayout&project=/platform/wauds/mainline>
>> ">
>> <conversionPattern value="%level %date{yyyy-MM-dd'T'HH:mm:
>> ss.fffzzz
>> <http://opengrok.factset.com/source/s?path=ss.fffzzz&project=/platform/wauds/mainline>}
>> %property{hostname} %property{guid} %message%newline" />
>> </layout>
>> </appender>
>> <appender name="BufferedFileAppender" type="
>> log4net.Appender.BufferingForwardingAppender
>> <http://opengrok.factset.com/source/s?path=log4net.Appender.BufferingForwardingAppender&project=/platform/wauds/mainline>
>> ">
>> <bufferSize value="512" />
>> <evaluator type="log4net.Core.TimeEvaluator
>> <http://opengrok.factset.com/source/s?path=log4net.Core.TimeEvaluator&project=/platform/wauds/mainline>
>> ">
>>
>> <interval value="10" />
>> <!--Send buffered events immediately if 10 seconds pass-->
>> </evaluator>
>> <Fix value="0" />
>> <!--Buffering can have severe performance degradation if this is
>> set to the default (ALL)-->
>> </appender>
>>
>>
>>
>>
>>
>> Logging Class:
>>
>> --------------------------
>>
>>
>>
>> Class MyClass
>>
>> {
>>
>> public MyClass()
>>
>> {
>>
>> Log4net.ThreadContext.Properties["guid"] = Guid.NewGuid();
>>
>> }
>>
>>
>>
>> public void SomeFunction()
>>
>> {
>>
>> Ilog log = LogManager.GetLogger(typeof(MyClass));
>>
>> Log.Info("my message");
>>
>> }
>>
>>
>>
>> }
>>
>>
>>
>>
>>
>> Tfile.log(Result)
>>
>> ----------------------
>>
>> Observed Results:
>>
>>
>>
>> INFO 2014-08-14T10:47:36.659-04:00 ANANTHTATACHAR MyAudsDigest
>> [LQR-Y8c71EmtWl7ZqItYoQ] my message
>>
>> INFO 2014-08-14T10:47:36.659-04:00 ANANTHTATACHAR MyAudsDigest
>> [9hDzS-_Su0SrEoXZF_aGMw] my message
>>
>> INFO 2014-08-14T10:47:36.729-04:00 ANANTHTATACHAR MyAudsDigest
>> [GsxT7aTfNEq1uIsqPYeZ5w] my message
>>
>> INFO 2014-08-14T10:47:36.789-04:00 ANANTHTATACHAR MyAudsDigest
>> [9hDzS-_Su0SrEoXZF_aGMw] my message
>>
>> INFO 2014-08-14T10:47:36.955-04:00 ANANTHTATACHAR MyAudsDigest
>> [9hDzS-_Su0SrEoXZF_aGMw] my message
>>
>>
>>
>>
>>
>>
>>
>> Expected Results:
>>
>> Unique guid in all the messages.
>>
>>
>>
>>
>>
>>
>>
>>
>>
>>
>>
>>
>> --------------------------------------------------------------------------------------------------------------------------------------
>>
>>
>>
>> I understand that Fix value NONE in
>> log4net.Appender.BufferingForwardingAppender
>> <http://opengrok.factset.com/source/s?path=log4net.Appender.BufferingForwardingAppender&project=/platform/wauds/mainline>
>> will not fix any volatile variables , but making it all results in all my
>> guids in all the 5 messages becoming same.
>>
>>
>>
>> Could anybody please tell me how to fix this issue?
>>
>
>
Re: Inconsistent results observed while using BufferingForwardAppender
Posted by Michael Schall <mi...@gmail.com>.
Try adding the thread name to your conversion to ensure it is a different
thread
<conversionPattern value="%level %date{yyyy-MM-dd'T'HH:mm:ss.fffzzz
<http://opengrok.factset.com/source/s?path=ss.fffzzz&project=/platform/wauds/mainline>}
%property{hostname} [%thread] %property{guid} %message%newline" />
It seems more likely that a thread is being reused.
Mike
On Thu, Aug 14, 2014 at 10:51 AM, Ananth Tatachar <ananth.tatachar@gmail.com
> wrote:
> I am working with log4net version : 1.2.12.0 .
>
>
>
> I am getting inconsistent results , while using RollingFileAppender with
> BufferingForwardAppender.
>
> My application is a multithreaded application. I spawned 5 threads Each
> will call the constructor of MyClass and SomeFunction once.
>
> My application's sertup is as follows:
>
>
>
> Web.config:
>
> -------------------------------
>
> <appender name="RollingLocalFileAppender" type="
> log4net.Appender.RollingFileAppender
> <http://opengrok.factset.com/source/s?path=log4net.Appender.RollingFileAppender&project=/platform/wauds/mainline>
> ">
> <file type="log4net.Util.PatternString
> <http://opengrok.factset.com/source/s?path=log4net.Util.PatternString&project=/platform/wauds/mainline>
> " value="C:\Logs\TFile.log" />
> <rollingStyle value="Date" />
> <datePattern value="yyyy-MM-dd" />
> <maxSizeRollBackups value="10" />
> <appendToFile value="true" />
> <layout type="log4net.Layout.PatternLayout
> <http://opengrok.factset.com/source/s?path=log4net.Layout.PatternLayout&project=/platform/wauds/mainline>
> ">
> <conversionPattern value="%level %date{yyyy-MM-dd'T'HH:mm:
> ss.fffzzz
> <http://opengrok.factset.com/source/s?path=ss.fffzzz&project=/platform/wauds/mainline>}
> %property{hostname} %property{guid} %message%newline" />
> </layout>
> </appender>
> <appender name="BufferedFileAppender" type="
> log4net.Appender.BufferingForwardingAppender
> <http://opengrok.factset.com/source/s?path=log4net.Appender.BufferingForwardingAppender&project=/platform/wauds/mainline>
> ">
> <bufferSize value="512" />
> <evaluator type="log4net.Core.TimeEvaluator
> <http://opengrok.factset.com/source/s?path=log4net.Core.TimeEvaluator&project=/platform/wauds/mainline>
> ">
>
> <interval value="10" />
> <!--Send buffered events immediately if 10 seconds pass-->
> </evaluator>
> <Fix value="0" />
> <!--Buffering can have severe performance degradation if this is set
> to the default (ALL)-->
> </appender>
>
>
>
>
>
> Logging Class:
>
> --------------------------
>
>
>
> Class MyClass
>
> {
>
> public MyClass()
>
> {
>
> Log4net.ThreadContext.Properties["guid"] = Guid.NewGuid();
>
> }
>
>
>
> public void SomeFunction()
>
> {
>
> Ilog log = LogManager.GetLogger(typeof(MyClass));
>
> Log.Info("my message");
>
> }
>
>
>
> }
>
>
>
>
>
> Tfile.log(Result)
>
> ----------------------
>
> Observed Results:
>
>
>
> INFO 2014-08-14T10:47:36.659-04:00 ANANTHTATACHAR MyAudsDigest
> [LQR-Y8c71EmtWl7ZqItYoQ] my message
>
> INFO 2014-08-14T10:47:36.659-04:00 ANANTHTATACHAR MyAudsDigest
> [9hDzS-_Su0SrEoXZF_aGMw] my message
>
> INFO 2014-08-14T10:47:36.729-04:00 ANANTHTATACHAR MyAudsDigest
> [GsxT7aTfNEq1uIsqPYeZ5w] my message
>
> INFO 2014-08-14T10:47:36.789-04:00 ANANTHTATACHAR MyAudsDigest
> [9hDzS-_Su0SrEoXZF_aGMw] my message
>
> INFO 2014-08-14T10:47:36.955-04:00 ANANTHTATACHAR MyAudsDigest
> [9hDzS-_Su0SrEoXZF_aGMw] my message
>
>
>
>
>
>
>
> Expected Results:
>
> Unique guid in all the messages.
>
>
>
>
>
>
>
>
>
>
>
>
> --------------------------------------------------------------------------------------------------------------------------------------
>
>
>
> I understand that Fix value NONE in
> log4net.Appender.BufferingForwardingAppender
> <http://opengrok.factset.com/source/s?path=log4net.Appender.BufferingForwardingAppender&project=/platform/wauds/mainline>
> will not fix any volatile variables , but making it all results in all my
> guids in all the 5 messages becoming same.
>
>
>
> Could anybody please tell me how to fix this issue?
>