Looks like one of the parameters to a log message is a HashMap which
gets modified while the log message was being constructed in another
thread. Using a synchronous appender would avoid the issue from
popping up since it's an issue of thread safety.
On Sat, 23 May 2020 at 17:46, Mitchell Rathbun (BLOOMBERG/ 731 LEX)
<mrathb...@bloomberg.net> wrote:
>
> We recently started occasionally getting the following error:
>
> 2020-05-22 05:54:07,995 INFO STDERR [Thread-2] {} 2020-05-22 05:54:07,994
> Log4j2-TF-2-AsyncLoggerConfig-1 ERROR An exception occurred processing
> Appender WINGMAN java.util.ConcurrentModificationException
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> java.util.HashMap$HashIterator.nextNode(HashMap.java:1442)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> java.util.HashMap$KeyIterator.next(HashMap.java:1466)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.message.ParameterFormatter.appendCollection(ParameterFormatter.java:599)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.message.ParameterFormatter.appendPotentiallyRecursiveValue(ParameterFormatter.java:507)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.message.ParameterFormatter.recursiveDeepToString(ParameterFormatter.java:432)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.message.ParameterFormatter.formatMessage2(ParameterFormatter.java:189)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.message.ParameterizedMessage.formatTo(ParameterizedMessage.java:225)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.core.pattern.MessagePatternConverter.format(MessagePatternConverter.java:119)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.core.pattern.PatternFormatter.format(PatternFormatter.java:38)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.core.layout.PatternLayout$PatternSerializer.toSerializable(PatternLayout.java:333)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.core.layout.PatternLayout.toText(PatternLayout.java:232)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.core.layout.PatternLayout.encode(PatternLayout.java:217)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.core.layout.PatternLayout.encode(PatternLayout.java:57)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.directEncodeEvent(AbstractOutputStreamAppender.java:177)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:170)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:161)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.core.appender.RollingRandomAccessFileAppender.append(RollingRandomAccessFileAppender.java:218)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:156)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:129)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:120)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:448)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.core.async.AsyncLoggerConfig.asyncCallAppenders(AsyncLoggerConfig.java:115)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.core.async.AsyncLoggerConfigDisruptor$Log4jEventWrapperHandler.onEvent(AsyncLoggerConfigDisruptor.java:112)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> org.apache.logging.log4j.core.async.AsyncLoggerConfigDisruptor$Log4jEventWrapperHandler.onEvent(AsyncLoggerConfigDisruptor.java:98)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> com.lmax.disruptor.BatchEventProcessor.processEvents(BatchEventProcessor.java:169)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:126)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {} at
> java.lang.Thread.run(Thread.java:748)
> 2020-05-22 05:54:07,996 INFO STDERR [Thread-2] {}
>
> We are using a RollingRandomAccessFileAppeneder with an AsyncLogger, and
> recently upgraded our log4j2 version to 2.13.2. The system property
> Log4jContextSelector is set to
> org.apache.logging.log4j.core.selector.BasicContextSelector. It seems from
> the few posts I have seen online that this shouldn't happen if async logging
> is being used. So I have two questions:
>
> 1. Why are we seeing this/what generally could cause this?
>
> 2. When this error occurs, the file that logs were being written to gets
> overwritten completely with the stack trace posted above. The process
> continues to run after this but no new logs ever get written to the file.
> This makes this a critical error and also makes it very difficult to debug
> why this error is happening to begin with. Is there a way to prevent this
> from happening so that the error just gets appended to the file instead of
> overwriting everything that is there?
--
Matt Sicker <boa...@gmail.com>
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-user-unsubscr...@logging.apache.org
For additional commands, e-mail: log4j-user-h...@logging.apache.org
