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 "Ron Gonzalez (JIRA)" <ji...@apache.org> on 2016/03/22 13:12:25 UTC

[jira] [Commented] (LOG4J2-1324) Async Logger - Consumer thread dying - new thread unable to start

    [ https://issues.apache.org/jira/browse/LOG4J2-1324?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15206245#comment-15206245 ] 

Ron Gonzalez commented on LOG4J2-1324:
--------------------------------------

bq. Looking at the Thread Dump, the AsyncLoggerConfig-1 thread is not actually dead,
Sorry Remko I did not provide you the full thread dump, but I can assure you that in the screenshot provided you are looking at two different stack traces : pre and post "crash".  What I mean by crash is that logging stops altogether.  As you can see from the heap dump the ringbuffer is full (195MB) and we have rollover configured for the log file at 200mb (however our log file on disk was only 64MB).  

So in the stack trace where I am showing "AsyncLoggerConfig-2" thread, there is assuredly no other thread called "AsyncLoggerConfig-1" consumer.  So that means that when logging stops completely, we have no consumer thread.  All we see is the AsyncLoggerConfig-2 thread at that point and as you can see, that thread is not starting properly.

bq. About the AsyncLoggerConfig-2 thread, looking at the Thread Dump it is waiting for data to become available in a LinkedBlockingQueue. I don't know what this thread is. The thread name suggests it is a log4j thread, but as far as I know we don't use LinkedBlockingQueue in log4j... Did you create a ThreadPool with log4j's DaemonThreadFactory?

I think org.apache.logging.log4j.core.async.DaemonThreadFactory is creating that secondary thread when the AsyncLoggerConfig-1 thread exits.  However I don't think the -1 thread is exiting cleanly, so I think that's why we see the second asyncloggerconfig - 2 thread in a weird stack, as it is unable to startup.

bq. Previously someone reported a similar issue (LOG4J2-1221, external issue https://github.com/LMAX-Exchange/disruptor/issues/138)

We did look at log4j-1221 and think it is very closely related, however, in that particular issue, they did no see "AsyncLoggerConfig-1" disappear, nor did they report a new thread being created called "AsyncLoggerConfig-2".

We'll do some more research on the thread dumps to determine if perhaps these threads are simply exiting and being recreated as thread dumps are simply a very small snapshot in time.  But do your consumer threads then enter and exit very quickly?  Or do the consumer threads stay alive for a length of time.  My feeling is that the consumer threads once created shouldn't exit.  That's why I think some unhandled exception is causing them to exit.

> Async Logger - Consumer thread dying - new thread unable to start
> -----------------------------------------------------------------
>
>                 Key: LOG4J2-1324
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-1324
>             Project: Log4j 2
>          Issue Type: Bug
>          Components: Core
>    Affects Versions: 2.2
>         Environment: LOG4J CORE Release Version 2.2
> Disruptor Bundle-Version 3.3.2
> ORACLE jdk1.8.0_45
>            Reporter: Ron Gonzalez
>         Attachments: 2016-03-18_17-44-06.jpg, BatchEventProcessor.png, log4j2_config.xml
>
>
> We are seeing a situation where the consumer thread
> "AsyncLoggerConfig-1" is apparently dying.
> We do see a new consumer thread trying to start up, but it is blocked
> waiting for a lock, so no logging is happening.
> Is this a defect in log4j?
> Is the original consumer thread dying due to perhaps an unhandled exception ?
> Is that original consumer thread not terminating gracefully and
> releasing the locked object so the new consumer thread can start?
> Please see attached screenshot.  Top of screen is normal
> asyncloggerconfig thread (consumer).
> Bottom is thread trace when logging stops, we no longer see an
> "asyncloggerconfig-1" thread, instead a new thread is trying to start
> but never does "asyncloggerconfig-2".



--
This message was sent by Atlassian JIRA
(v6.3.4#6332)

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