logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Remko Popma (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (LOG4J2-807) Disruptor is null when configuration is reloaded (asyncRoot + monitorInterval)
Date Mon, 22 Sep 2014 10:06:34 GMT

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

Remko Popma commented on LOG4J2-807:
------------------------------------

The problem is caused by a bug in AbstractConfiguration: 
During reconfiguration, a new configuration is started with new appenders and loggers. This
increases the AsyncLoggerConfigHelper ref count  to 2. (So far so good.)
After that, the old configuration is stopped. This logic has a bug, resulting in the root
async logger being stopped twice. This brings down the ref count to zero and the Disruptor
is shut down. Subsequent logging will fail.

Apart from fixing this bug, I'll also improve the trace logging for async loggers a little
so that it is easier to see what is going on. The current log does not show that it is the
same logger that is stopped twice, because the root logger name is the empty string. I'll
output "root" instead in the trace logs to aid future debugging.

Current:
{code}
2014-09-22 19:01:50,617 TRACE AsyncLoggerConfig[] stopping...
2014-09-22 19:01:50,617 TRACE AsyncLoggerConfigHelper: not shutting down disruptor: ref count
is 1.
2014-09-22 19:01:50,617 TRACE AsyncLoggerConfig[] stopping...
2014-09-22 19:01:50,617 TRACE AsyncLoggerConfigHelper: shutting down disruptor: ref count
is 0.
{code}
After:
{code}
2014-09-22 19:01:50,617 TRACE AsyncLoggerConfig[root] stopping...
2014-09-22 19:01:50,617 TRACE AsyncLoggerConfigHelper: not shutting down disruptor: ref count
is 1.
2014-09-22 19:01:50,617 TRACE AsyncLoggerConfig[root] stopping...
2014-09-22 19:01:50,617 TRACE AsyncLoggerConfigHelper: shutting down disruptor: ref count
is 0.
{code}

> Disruptor is null when configuration is reloaded (asyncRoot + monitorInterval)
> ------------------------------------------------------------------------------
>
>                 Key: LOG4J2-807
>                 URL: https://issues.apache.org/jira/browse/LOG4J2-807
>             Project: Log4j 2
>          Issue Type: Bug
>    Affects Versions: 2.0.2
>            Reporter: Florin Marinoiu
>            Assignee: Remko Popma
>             Fix For: 2.1
>
>         Attachments: async-root-reload - trace.log, async-root-reload-test.zip, async-root-reload.log
>
>
> We have a XML configuration with <asyncRoot> and monitorInterval. When the configuration
file is reloaded I have a NPE and log4j become unavailable:
> {code}
> 2014-08-29 10:39:59,079 ERROR Could not register mbeans java.lang.NullPointerException
> 	at org.apache.logging.log4j.core.async.AsyncLoggerConfigHelper.createRingBufferAdmin(AsyncLoggerConfigHelper.java:360)
> 	at org.apache.logging.log4j.core.async.AsyncLoggerConfig.createRingBufferAdmin(AsyncLoggerConfig.java:148)
> {code}
> Here is my config:
> {code}
> <?xml version="1.0" encoding="UTF-8"?>
> <Configuration name="asynRootConfig" monitorInterval="5" status="debug">
>     <Appenders>
>         <RandomAccessFile name="FILE_APPENDER" fileName="application.log" immediateFlush="false"
append="true">
>             <PatternLayout>
>                 <Pattern>%d  %-5p [%c{1.}] %m%n</Pattern>
>             </PatternLayout>
>         </RandomAccessFile>
>     </Appenders>
>     <Loggers>
>         <asyncRoot level="debug">
>             <AppenderRef ref="FILE_APPENDER" />
>         </asyncRoot>
>     </Loggers>
> </Configuration>
> {code}
> And a code snippet to reproduce:
> {code}
> public class Log4jAsyncRootReloadTest {
>     public static void main(String[] args) throws InterruptedException {
>         final File config = new File("./log4j2.xml");
>         System.setProperty("log4j.configurationFile", "file://" + config.getAbsolutePath().replaceAll("\\\\",
"/"));
>         Logger logger = LogManager.getLogger(Log4jAsyncRootReloadTest.class);
>         logger.info("Log4j configured, will be reconfigured in aprox. 5 sec");
>         config.setLastModified(System.currentTimeMillis());
>         for (int i = 0; i < 10; i++) {
>             Thread.sleep(1000);
>             logger.info("Log4j waiting for reconfiguration");
>         }
>     }
> }
> {code}



--
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


Mime
View raw message