Hi Ceki,

Thanks for your responses.  Absolutely; I'll create a JIRA shortly.

As to your question about a test case, I'll see if I can get something working over the next 1-2 days. Unfortunately, even if I am successful, the test case is likely to only sometimes detect this particular problem (since threads are generally not deterministic).

The performance questions (i.e. the costs of volatile) are a bit harder to answer and I'm not sure I'm presently equipped to execute the necessary performance testing. I'll give this more thought.

Aaron



On 3/3/2016 3:13 AM, Ceki Gulcu wrote:

Hi again,

Would you please create a JIRA issue for the problem you raised on the mailing list?

--
Ceki

On 3/3/2016 9:16, Ceki Gulcu wrote:
Hi Aaron,

Comments inline.

On 3/2/2016 23:40, Aaron Curley wrote:

 > Hello all,
 >
> I’m most likely missing something here, but reviewing AsyncAppender in
 > logback classic 1.1.6, I’m not sure how it’s entirely thread safe,
 > especially with respect to the “started” flag in its grandparent
 > class (UnsynchronizedAppenderBase).
 >
 > In particular, the doAppend() method in UnsynchronizedAppenderBase
 > checks the “started” boolean member's value (line 72) before
 > actually appending, yet, no synchronization primitives are (or appear
 > to be, from my perspective) used to ensure that the “started”
 > member is visible to all threads once it is updated via start().  I
 > would have thought that AsyncAppender would have inherited from
 > AppenderBase (which is thread safe and does mark “started” as
 > volatile) rather than extending UnsynchronizedAppenderBase.  Baring
 > this, I would have thought that the “started” member would be
 > “overridden” with AsyncAppender’s own volatile version of this
 > flag or access to started would be protected with a lock.
 >
 > As a result, isn’t it possible that if one thread calls start() and
 > then another thread immediately logs something (calling doAppend()),
 > the logging thread would see “started” as false?  Wouldn’t this
 > result in “skipping” certain log messages entirely (if the
 > appender was very recently started)?

You are absolutely right. Events generated in other threads could be
lost until the new value (true) of start was propagated to those
threads. Good catch.

 > I think I must be missing something.  Can someone clarify how this
 > works?  Thanks in advance!
 >
 > Best Regards,
 >
 > Aaron Curley
 > accw...@gmail.com
 >
 > P. S.  I would have also expected start() and stop() (in
 > AsyncAppender or its parent) to be overridden to introduce
 > synchronization, since AsyncAppender is generally used by multiple
 > threads.  Right now, it appears that start & stop operations are not
 > idempotent nor are multiple (simultaneous) calls prevented.

The idempotency could be enforced by introducing a check if(isStarted())
{return;} at the top of the start() method. But again, good catch.

Here are a couple of questions for you.

1) How would you write a test case for asserting the correct propagation
of start?
2) What would be the computational cost of having a volatile start?
3) What would you suggest to minimize the cost if the cost was elevated?

Best regards,

--
Ceki

_______________________________________________
logback-dev mailing list
logback-dev@qos.ch
http://mailman.qos.ch/mailman/listinfo/logback-dev
_______________________________________________
logback-dev mailing list
logback-dev@qos.ch
http://mailman.qos.ch/mailman/listinfo/logback-dev

_______________________________________________
logback-dev mailing list
logback-dev@qos.ch
http://mailman.qos.ch/mailman/listinfo/logback-dev

Reply via email to