logging-log4net-user mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Dominik Psenner" <dpsen...@gmail.com>
Subject AW: AppenderSkeletion lock in DoAppend
Date Thu, 05 Mar 2015 13:02:06 GMT
Taking this to log4net dev since this goes well beyond the usage of log4net, too.

 

Logs are typically written by software that is programmed, aren’t they? Thus one could happen
to recursively trying to log something in his source code without being aware of it. Maybe
the example was not clear enough and I apologize for not being verbose enough.

 

I tried to say that a log event could try to get a formatted message of the event by doing
an invoke of another method and that method could again try to format the log message by calling
the other method. This then ends up in a cyclic/recursive invoke and I believe that the recursive
check tries to tackle this issue so that the application does not crash by trying to log something
that might be totally unimportant.

 

I’m not sure if I understand what you mean with not threadsafe. A method that is not threadsafe
can only be not threadsafe if it modifies data that is out of scope. It’s up to you how
you implement the interface, but it might well happen that data gets modified without you
being aware of it. One good example is the GlobalContext, which can easily be used in a manner
that is not threadsafe at all.

 

Cheers

 

Von: Gert Kello [mailto:gert.kello@gmail.com] 
Gesendet: Donnerstag, 05. März 2015 12:09
An: Log4NET User
Betreff: Re: AppenderSkeletion lock in DoAppend

 

Sorry but I fail to understand this example... Log event programmed? I didn't know I can program
it... (without changing log4net source).

So far I know/see two cases where recursive logging can happen:

1. Something called from Appender.Append calls anu ILog logging methods

2. According to comment in https://issues.apache.org/jira/browse/LOG4NET-288 the bad configuration
can also cause the recursion.

I assume that's all that can cause recursions... As I plan to save logs from another thread
I have to pay special attention to item 1. as any logging from database save procedure would
cause the same logging to be executed again (tested). Without recursion but still flooding
log system with endless messages.

But what about IFilter.Decide? Should I assume it is not threadsafe?

 

Gert

 

 

On 4 March 2015 at 16:51, Dominik Psenner <dpsenner@gmail.com <mailto:dpsenner@gmail.com>
> wrote:

A log event might be badly programmed and recursive by definition. Think of two objects that
try each to log while trying to format each other:

 

A {

DoWork() {

   Log(“A: {0}”, B)

}

}

B {

DoWork () {

   Log(“B: {0}”, A)

}

}

 

I might be wrong, but something like that does the recursive guard detect and resolve.

 

For the other question you’ll have to accept my apologies because I can’t answer the question
„how to write code“. :)

 

Von: Gert Kello [mailto:gert.kello@gmail.com <mailto:gert.kello@gmail.com> ] 
Gesendet: Mittwoch, 04. März 2015 15:16
An: Log4NET User
Betreff: Re: AppenderSkeletion lock in DoAppend

 

But what about this m_recursiveGuard? Is the recursion protection needed? Perhaps it is, if
log saving code logs something by itself? (Like warning that database operation takes longer
than expected)?

Well, as I plan to make the database saving asyn I need to tackle this problem anyway... I
think I would like to log the performance problem. But not when the problem occurs during
saving log about the same performance problem. Is there any guideline how to write such code?
Something like using OnlyOnceErrorHandler or is there anything similar for warnings?

 

Gert

 

On 4 March 2015 at 15:38, Dominik Psenner <dpsenner@gmail.com <mailto:dpsenner@gmail.com>
> wrote:

Hi,

 

from what I can recall it could happen that the formatted representation of a logging event
gets mixed up with data from other events and thus the characters streamed to a sink become
garbage (i.e. a file, console, ..) if this lock is removed.

 

Internally a lot of things are cached to improve performance and these caches actually require
proper locking.

 

But my memory might be wrong, so feel free to remove the lock and let several threads log
events to your appender to see if it can handle it properly. :)

 

Cheers

 

Von: Gert Kello [mailto:gert.kello@gmail.com <mailto:gert.kello@gmail.com> ] 
Gesendet: Mittwoch, 04. März 2015 09:28
An: log4net-user@logging.apache.org <mailto:log4net-user@logging.apache.org> 
Betreff: AppenderSkeletion lock in DoAppend

 

Hi.

I'm trying to create a database appender which high throughput... I looked at code in AppenderSekeletion.DoAppend()
method and saw following comment:

    public void DoAppend(LoggingEvent loggingEvent)
    {
      // This lock is absolutely critical for correct formatting
      // of the message in a multi-threaded environment.  Without
      // this, the message may be broken up into elements from
      // multiple thread contexts (like get the wrong thread ID).

      lock (this)
      {

I would like to remove this lock from my code but there's a couple of issues I do not understand:

1. As I do not know the internals of log4net well enough I do not understand why lock is important
for message formatting? Is it because the Layout.Format is not supposed to be thread safe?
Or is it because the same instance of m_renderWriter could be used by multiple threads (well,
usage of m_renderWriter is protected by another lock, added later. But AFAIK the RenderLoggingEvent(LoggingEvent
loggingEvent) is still not 100% thread safe)

2. The comment does not mention that lock is crucial for m_recursiveGuard to work correctly.
That's my main complaint: I almost overlooked the issue of potentially skipped logging events.

3. What about implementations of IFilter.Decide? Are those (supposed to be) thread safe?

Gert

 

 


Mime
View raw message