[
https://issues.apache.org/jira/browse/LOG4J2-392?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Remko Popma reopened LOG4J2-392:
--------------------------------
Reopening this issue: When investigating LOG4J2-593 with a configuration
containing an {{<AsyncLogger>}}, I found that the fix still has problems.
This is what happens:
{code}
2014-06-14 23:45:46,080 TRACE AsyncLoggerConfigHelper not starting new
disruptor, using existing object. Ref count is 2.
2014-06-14 23:45:46,080 TRACE AbstractConfiguration stopping...
2014-06-14 23:45:46,080 TRACE AsyncLoggerConfigHelper: not shutting down
disruptor: ref count is 1.
2014-06-14 23:45:46,081 TRACE AbstractConfiguration stopped 1
AsyncLoggerConfigs.
2014-06-14 23:45:46,081 TRACE AsyncAppender stopping. Queue still has 0 events.
2014-06-14 23:45:46,081 TRACE AsyncAppender.AsyncThread shutting down.
Processing remaining 0 queue events.
2014-06-14 23:45:46,081 TRACE AsyncAppender.AsyncThread stopped. Queue has 0
events remaining. Processed 0 and ignored 0 events since shutdown started.
2014-06-14 23:45:46,082 TRACE AsyncAppender stopped. Queue has 0 events.
2014-06-14 23:45:46,082 TRACE AbstractConfiguration stopped 1 AsyncAppenders.
2014-06-14 23:45:46,082 TRACE AbstractConfiguration stopped 3 Appenders.
2014-06-14 23:45:46,082 TRACE AsyncLoggerConfigHelper: shutting down disruptor:
ref count is 0.
2014-06-14 23:45:46,083 TRACE AbstractConfiguration stopped 2 Loggers.
2014-06-14 23:45:46,083 DEBUG Unregistering MBean
org.apache.logging.log4j2:type=AsyncLoggerContext
...
2014-06-14 23:45:46,084 DEBUG Unregistering MBean
org.apache.logging.log4j2:type=AsyncLoggerContext,component=Loggers,name=com.foo.Bar
2014-06-14 23:45:46,084 DEBUG Unregistering MBean
org.apache.logging.log4j2:type=AsyncLoggerContext,component=Loggers,name=
...
2014-06-14 23:45:46,086 DEBUG Unregistering MBean
org.apache.logging.log4j2:type=AsyncLoggerContext,component=Loggers,name=com.foo.Bar,subtype=RingBuffer
2014-06-14 23:45:46,087 DEBUG Registering MBean
org.apache.logging.log4j2:type=AsyncLoggerContext
...
2014-06-14 23:45:46,088 DEBUG Registering MBean
org.apache.logging.log4j2:type=AsyncLoggerContext,component=Loggers,name=
2014-06-14 23:45:46,088 DEBUG Registering MBean
org.apache.logging.log4j2:type=AsyncLoggerContext,component=Loggers,name=com.foo.Bar
2014-06-14 23:45:46,089 ERROR Could not register mbeans
java.lang.NullPointerException
at
org.apache.logging.log4j.core.async.AsyncLoggerConfigHelper.createRingBufferAdmin(AsyncLoggerConfigHelper.java:357)
at
org.apache.logging.log4j.core.async.AsyncLoggerConfig.createRingBufferAdmin(AsyncLoggerConfig.java:146)
at
org.apache.logging.log4j.core.jmx.Server.registerLoggerConfigs(Server.java:328)
at
org.apache.logging.log4j.core.jmx.Server.reregisterMBeansAfterReconfigure(Server.java:158)
at
org.apache.logging.log4j.core.jmx.Server.reregisterMBeansAfterReconfigure(Server.java:119)
at
org.apache.logging.log4j.core.LoggerContext.setConfiguration(LoggerContext.java:362)
at
org.apache.logging.log4j.core.LoggerContext.start(LoggerContext.java:169)
at
org.apache.logging.log4j.core.jmx.LoggerContextAdmin.setConfigText(LoggerContextAdmin.java:183)
{code}
AsyncLoggerConfigHelper currently has a single static Disruptor instance that
is shared between multiple AsyncLoggerConfig instances. It keeps track of the
reference count to decide when there are no more references and the Disruptor
should be shut down.
The reference count is increased when an AsyncLoggerConfig is started, and
decreased when an AsyncLoggerConfig is stopped.
With the current fix for this issue, {{AbstractConfiguration.stop()} may call
{{AsyncLoggerConfig.stop()}} multiple times on the same instance, which results
in an incorrect reference count, causing the NPE above.
> Intermittent errors with appenders
> ----------------------------------
>
> Key: LOG4J2-392
> URL: https://issues.apache.org/jira/browse/LOG4J2-392
> Project: Log4j 2
> Issue Type: Bug
> Components: Appenders
> Affects Versions: 2.0-beta8, 2.0-beta9
> Environment: Windows 7 SP1 64bit
> Reporter: ilynaf
> Assignee: Remko Popma
> Fix For: 2.0-rc2, 2.1
>
> Attachments: AppenderOverwhelmer.java, Log4J2.zip, log4j2.xml
>
>
> I intermittently receive following errors after upgrading to beta 8.
> EVERYTHING was working well with beta 6:
> * 1st error (happens most frequently)
> 2013-09-05 10:48:37,722 ERROR Attempted to append to non-started appender
> LogFile
> * 2nd error:
> 2013-09-05 10:49:38,268 ERROR Attempted to append to non-started appender
> LogFile
> 2013-09-05 10:49:38,268 ERROR Unable to write to stream
> log/ui-selenium-tests.log for appender LogFile
> 2013-09-05 10:49:38,269 ERROR An exception occurred processing Appender
> LogFile org.apache.logging.log4j.core.appender.AppenderRuntimeException:
> Error writing to RandomAccessFile log/ui-selenium-tests.log
> at
> org.apache.logging.log4j.core.appender.rolling.FastRollingFileManager.flush(FastRollingFileManager.java:108)
> at
> org.apache.logging.log4j.core.appender.rolling.FastRollingFileManager.write(FastRollingFileManager.java:89)
> at
> org.apache.logging.log4j.core.appender.OutputStreamManager.write(OutputStreamManager.java:129)
> at
> org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:115)
> at
> org.apache.logging.log4j.core.appender.FastRollingFileAppender.append(FastRollingFileAppender.java:97)
> at
> org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:102)
> at
> org.apache.logging.log4j.core.appender.AsyncAppender$AsyncThread.run(AsyncAppender.java:228)
> Caused by: java.io.IOException: Write error
> at java.io.RandomAccessFile.writeBytes(Native Method)
> at java.io.RandomAccessFile.write(Unknown Source)
> at
> org.apache.logging.log4j.core.appender.rolling.FastRollingFileManager.flush(FastRollingFileManager.java:105)
> ... 6 more
--
This message was sent by Atlassian JIRA
(v6.2#6252)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
