You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@logging.apache.org by "Remko Popma (JIRA)" <ji...@apache.org> on 2017/09/11 13:39:00 UTC
[jira] [Commented] (LOG4J2-1988)
java.util.ConcurrentModificationException with AsyncLogger?
[ https://issues.apache.org/jira/browse/LOG4J2-1988?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16161245#comment-16161245 ]
Remko Popma commented on LOG4J2-1988:
-------------------------------------
The stack trace shows that the log event contains a {{ParameterizedMessage}} whose {{getFormattedMessage}} method was not invoked before the event was handed off to the background thread.
What I suspect (but cannot confirm from the stack trace) that happened is that somehow a Log4jLogEvent was being logged, even though system property {{-Dlog4j2.enable.threadlocals=true}} was set. (When this property is set, LoggerConfig installs a ReusableLogEventFactory, which only generates MutableLogEvents, not Log4jLogEvents.)
While I don't understand how the Log4jLogEvent came into play, it would explain the exception: AsyncLoggerConfigDisruptor does not correctly handle Log4jLogEvent with ParameterizedMessages. It should call {{ParameterizedMessage.getFormattedMessage}} but that logic is missing.
I will add that missing call and also will see if I can add more diagnostic logging to help troubleshoot if this does not resolve the issue.
> java.util.ConcurrentModificationException with AsyncLogger?
> -----------------------------------------------------------
>
> Key: LOG4J2-1988
> URL: https://issues.apache.org/jira/browse/LOG4J2-1988
> Project: Log4j 2
> Issue Type: Question
> Components: Layouts
> Affects Versions: 2.8.2
> Environment: Java 1.8.0_111, Linux
> Reporter: Corneliu C
> Assignee: Remko Popma
> Priority: Minor
>
> Hi,
> I see java.util.ConcurrentModificationException even with AsyncLogger and I don't know if it's something I can configure to get rid of these exceptions. The application uses Apache Camel framework and there is a mixture of Async Appender and Async Logger defined.
> I don't see many of these but they happen from time to time; they are printed in the Console appender.
> * Stacktrace:
> {code}
> 2017-07-19 11:53:56,024 Log4j2-TF-11-AsyncLoggerConfig-4 ERROR An exception occurred processing Appender ApacheCamel java.util.ConcurrentModificationException
> at java.util.LinkedHashMap$LinkedHashIterator.nextNode(Unknown Source)
> at java.util.LinkedHashMap$LinkedEntryIterator.next(Unknown Source)
> at java.util.LinkedHashMap$LinkedEntryIterator.next(Unknown Source)
> at org.apache.logging.log4j.message.ParameterFormatter.appendMap(ParameterFormatter.java:569)
> at org.apache.logging.log4j.message.ParameterFormatter.appendPotentiallyRecursiveValue(ParameterFormatter.java:505)
> at org.apache.logging.log4j.message.ParameterFormatter.recursiveDeepToString(ParameterFormatter.java:432)
> at org.apache.logging.log4j.message.ParameterFormatter.formatMessage2(ParameterFormatter.java:189)
> at org.apache.logging.log4j.message.ParameterizedMessage.formatTo(ParameterizedMessage.java:225)
> at org.apache.logging.log4j.core.pattern.MessagePatternConverter.format(MessagePatternConverter.java:119)
> at org.apache.logging.log4j.core.pattern.PatternFormatter.format(PatternFormatter.java:38)
> at org.apache.logging.log4j.core.layout.PatternLayout$PatternSerializer.toSerializable(PatternLayout.java:333)
> at org.apache.logging.log4j.core.layout.PatternLayout.toText(PatternLayout.java:232)
> at org.apache.logging.log4j.core.layout.PatternLayout.encode(PatternLayout.java:217)
> at org.apache.logging.log4j.core.layout.PatternLayout.encode(PatternLayout.java:57)
> at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.directEncodeEvent(AbstractOutputStreamAppender.java:177)
> at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:170)
> at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:161)
> at org.apache.logging.log4j.core.appender.RollingRandomAccessFileAppender.append(RollingRandomAccessFileAppender.java:218)
> at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
> at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
> at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
> at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
> at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:448)
> at org.apache.logging.log4j.core.async.AsyncLoggerConfig.asyncCallAppenders(AsyncLoggerConfig.java:115)
> at org.apache.logging.log4j.core.async.AsyncLoggerConfigDisruptor$Log4jEventWrapperHandler.onEvent(AsyncLoggerConfigDisruptor.java:112)
> at org.apache.logging.log4j.core.async.AsyncLoggerConfigDisruptor$Log4jEventWrapperHandler.onEvent(AsyncLoggerConfigDisruptor.java:98)
> at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:129)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
> at java.lang.Thread.run(Unknown Source)
> {code}
> * Log4j.xml configuration:
> {code}
> <?xml version="1.0" encoding="UTF-8"?>
> <Configuration status="TRACE" name="Test" packages=""
> monitorInterval="10" dest="log4j2-console.log" verbose="false">
> <Properties>
> <Property name="instanceName">${hostName}-app</Property>
> </Properties>
> <Appenders>
> ...
> <Appenders>
> <AlertAppender name="Alert" />
> <EventAppender name="Event" />
> <Console name="Console" target="SYSTEM_OUT">
> <PatternLayout pattern="%d{COMPACT}{UTC} %-5p %t %C{1}:%l [%X{camel.breadcrumbId}] %m{nolookups}%n%ex{full}" />
> </Console>
> ...
> <RollingRandomAccessFile name="ApacheCamel"
> fileName="${instanceName}-apache-camel.log" filePattern="${instanceName}-apache-camel.log.%d{yyMMdd}-%i"
> immediateFlush="false">
> <PatternLayout>
> <Pattern>%d{COMPACT}{UTC} %-5p %t %c{1} [%X{camel.breadcrumbId}] %m{nolookups}%n%ex{full}</Pattern>
> </PatternLayout>
> <Policies>
> <TimeBasedTriggeringPolicy interval="1"
> modulate="true" />
> <SizeBasedTriggeringPolicy size="100 MB" />
> </Policies>
> <DefaultRolloverStrategy max="20"/>
> </RollingRandomAccessFile>
> ...
> <Loggers>
> <AsyncLogger name="org.apache.camel" level="TRACE" additivity="false"
> includeLocation="false">
> <AppenderRef ref="ApacheCamel" />
> </AsyncLogger>
> ...
> <Root level="INFO" includeLocation="false">
> <AppenderRef ref="Async" />
> </Root>
> </Loggers>
> </Configuration>
> {code}
> As environment parameters these are configured:
> {code}
> -Dlog4j2.disable.jmx=true -Dlog4j2.enable.threadlocals=true -Dlog4j2.enable.direct.encoders=true -Dlog4j2.garbagefree.threadContextMap=true -DAsyncLoggerConfig.RingBufferSize=10240
> {code}
> Following libs are in classpath:
> disruptor-3.3.6.jar
> log4j-api-2.8.2.jar
> log4j-core-2.8.2.jar
> log4j-jul-2.1.jar
> log4j-slf4j-impl-2.8.2.jar
> log4j-web-2.8.2.jar
> slf4j-api-1.7.21.jar
> Thank you
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)