You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-dev@logging.apache.org by Louis Jacomet <lj...@gmail.com> on 2010/12/10 10:11:14 UTC

Race condition in AsyncAppender

Hi all,

I recently investigated a deadlock happening inside our JBoss AS.
I tracked down the root cause to the AsyncAppender of log4j.
We use it in blocking mode, with the default buffer size of 128. I was able
to reproduce the deadlock live even when increasing the buffer size to 512.

The problem comes from a race condition when the dispatcher thread dies from
an exception. When that happens, if the buffer has been filled up by other
threads doing logging, the thread currently waiting on the buffer to be
emptied will never be notified and wait there forever.
As a category lock is held to access the appender, this lead other threads
to block forever.

I found a bug in the database:
https://issues.apache.org/bugzilla/show_bug.cgi?id=45915
However, the root cause was associated to logging from the Dispatcher
thread. I have attached a test cause causing the deadlock, showing it can
occur even when not logging from the dispatcher thread.

Should I reopen that bug or create a new one?

We are using log4j 1.2.14 and JBoss AS 4.3.0.
The latest trunk version of AsyncAppender still suffers from the race
condition.

Regards,
Louis

Re: Race condition in AsyncAppender

Posted by Louis Jacomet <lj...@gmail.com>.
Follow up on the issue mentionned.

You will find attached the smallest change that fixes the issue and should
not change any current AsyncAppender behavior.

Regards,
Louis

On Fri, Dec 10, 2010 at 10:11 AM, Louis Jacomet <lj...@gmail.com> wrote:

> Hi all,
>
> I recently investigated a deadlock happening inside our JBoss AS.
> I tracked down the root cause to the AsyncAppender of log4j.
> We use it in blocking mode, with the default buffer size of 128. I was able
> to reproduce the deadlock live even when increasing the buffer size to 512.
>
> The problem comes from a race condition when the dispatcher thread dies
> from an exception. When that happens, if the buffer has been filled up by
> other threads doing logging, the thread currently waiting on the buffer to
> be emptied will never be notified and wait there forever.
> As a category lock is held to access the appender, this lead other threads
> to block forever.
>
> I found a bug in the database:
> https://issues.apache.org/bugzilla/show_bug.cgi?id=45915
> However, the root cause was associated to logging from the Dispatcher
> thread. I have attached a test cause causing the deadlock, showing it can
> occur even when not logging from the dispatcher thread.
>
> Should I reopen that bug or create a new one?
>
> We are using log4j 1.2.14 and JBoss AS 4.3.0.
> The latest trunk version of AsyncAppender still suffers from the race
> condition.
>
> Regards,
> Louis
>

Re: Race condition in AsyncAppender

Posted by Louis Jacomet <lj...@gmail.com>.
Hello Curt,

Here is the reference to the created bug:
https://issues.apache.org/bugzilla/show_bug.cgi?id=50463

<https://issues.apache.org/bugzilla/show_bug.cgi?id=50463>Regards,
Louis

On Mon, Dec 13, 2010 at 5:44 AM, Curt Arnold <ca...@apache.org> wrote:

> Thanks for the report and patch.  Creating a new bug would be better.
>  Patch looks good on a first visual check.
>
>
> On Dec 10, 2010, at 3:11 AM, Louis Jacomet wrote:
>
> > Hi all,
> >
> > I recently investigated a deadlock happening inside our JBoss AS.
> > I tracked down the root cause to the AsyncAppender of log4j.
> > We use it in blocking mode, with the default buffer size of 128. I was
> able to reproduce the deadlock live even when increasing the buffer size to
> 512.
> >
> > The problem comes from a race condition when the dispatcher thread dies
> from an exception. When that happens, if the buffer has been filled up by
> other threads doing logging, the thread currently waiting on the buffer to
> be emptied will never be notified and wait there forever.
> > As a category lock is held to access the appender, this lead other
> threads to block forever.
> >
> > I found a bug in the database:
> https://issues.apache.org/bugzilla/show_bug.cgi?id=45915
> > However, the root cause was associated to logging from the Dispatcher
> thread. I have attached a test cause causing the deadlock, showing it can
> occur even when not logging from the dispatcher thread.
> >
> > Should I reopen that bug or create a new one?
> >
> > We are using log4j 1.2.14 and JBoss AS 4.3.0.
> > The latest trunk version of AsyncAppender still suffers from the race
> condition.
> >
> > Regards,
> > Louis
> > <Log4JAsyncAppenderDeadLock.java>
> > ---------------------------------------------------------------------
> > To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> > For additional commands, e-mail: log4j-dev-help@logging.apache.org
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-dev-help@logging.apache.org
>
>

Re: Race condition in AsyncAppender

Posted by Curt Arnold <ca...@apache.org>.
Thanks for the report and patch.  Creating a new bug would be better.  Patch looks good on a first visual check.


On Dec 10, 2010, at 3:11 AM, Louis Jacomet wrote:

> Hi all,
> 
> I recently investigated a deadlock happening inside our JBoss AS.
> I tracked down the root cause to the AsyncAppender of log4j.
> We use it in blocking mode, with the default buffer size of 128. I was able to reproduce the deadlock live even when increasing the buffer size to 512.
> 
> The problem comes from a race condition when the dispatcher thread dies from an exception. When that happens, if the buffer has been filled up by other threads doing logging, the thread currently waiting on the buffer to be emptied will never be notified and wait there forever.
> As a category lock is held to access the appender, this lead other threads to block forever.
> 
> I found a bug in the database: https://issues.apache.org/bugzilla/show_bug.cgi?id=45915
> However, the root cause was associated to logging from the Dispatcher thread. I have attached a test cause causing the deadlock, showing it can occur even when not logging from the dispatcher thread.
> 
> Should I reopen that bug or create a new one?
> 
> We are using log4j 1.2.14 and JBoss AS 4.3.0.
> The latest trunk version of AsyncAppender still suffers from the race condition.
> 
> Regards,
> Louis
> <Log4JAsyncAppenderDeadLock.java>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
> For additional commands, e-mail: log4j-dev-help@logging.apache.org


---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org