log4j2 ParameterFormatter.appendCollection 中的 ConcurrentModificationException，当我增加 tomcat 的负载时

Question

当我使用 apache benchmark 向 1000 个并发客户端发送 200000 个请求时，我得到了 CME，但是如果将这些值保持在低水平，它就可以正常工作。下面是堆栈跟踪：

2016-07-11 21:02:26,829 http-bio-8080-exec-284 ERROR An exception occurred processing Appender debug-log java.util.ConcurrentModificationException
at java.util.ArrayList$Itr.checkForComodification(ArrayList.java:901)
at java.util.ArrayList$Itr.next(ArrayList.java:851)
at org.apache.logging.log4j.message.ParameterFormatter.appendCollection(ParameterFormatter.java:575)
at org.apache.logging.log4j.message.ParameterFormatter.appendPotentiallyRecursiveValue(ParameterFormatter.java:483)
at org.apache.logging.log4j.message.ParameterFormatter.recursiveDeepToString(ParameterFormatter.java:429)
at org.apache.logging.log4j.message.ParameterFormatter.formatMessage2(ParameterFormatter.java:189)
at org.apache.logging.log4j.message.ParameterizedMessage.formatTo(ParameterizedMessage.java:217)
at org.apache.logging.log4j.core.pattern.MessagePatternConverter.format(MessagePatternConverter.java:65)
at org.apache.logging.log4j.core.pattern.PatternFormatter.format(PatternFormatter.java:38)
at org.apache.logging.log4j.core.layout.PatternLayout$PatternSerializer.toSerializable(PatternLayout.java:288)
at org.apache.logging.log4j.core.layout.PatternLayout.toText(PatternLayout.java:194)
at org.apache.logging.log4j.core.layout.PatternLayout.encode(PatternLayout.java:180)
at org.apache.logging.log4j.core.layout.PatternLayout.encode(PatternLayout.java:57)
at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.directEncodeEvent(AbstractOutputStreamAppender.java:120)
at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.tryAppend(AbstractOutputStreamAppender.java:113)
at org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender.append(AbstractOutputStreamAppender.java:104)
at org.apache.logging.log4j.core.appender.RollingFileAppender.append(RollingFileAppender.java:86)
at org.apache.logging.log4j.core.config.AppenderControl.tryCallAppender(AppenderControl.java:155)
at org.apache.logging.log4j.core.config.AppenderControl.callAppender0(AppenderControl.java:128)
at org.apache.logging.log4j.core.config.AppenderControl.callAppenderPreventRecursion(AppenderControl.java:119)
at org.apache.logging.log4j.core.config.AppenderControl.callAppender(AppenderControl.java:84)
at org.apache.logging.log4j.core.config.LoggerConfig.callAppenders(LoggerConfig.java:390)
at org.apache.logging.log4j.core.config.LoggerConfig.processLogEvent(LoggerConfig.java:375)
at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:359)
at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:349)
at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:63)
at org.apache.logging.log4j.core.Logger.logMessage(Logger.java:146)
at org.apache.logging.log4j.spi.AbstractLogger.logMessage(AbstractLogger.java:2025)
at org.apache.logging.log4j.spi.AbstractLogger.logIfEnabled(AbstractLogger.java:1898)
at org.apache.logging.slf4j.Log4jLogger.debug(Log4jLogger.java:129)

编辑：我使用的是 log4j2 2.6

Answer 1

您似乎正在记录一个正在修改的集合，而 Log4j 2 ParameterFormatter 正在迭代其元素以创建文本表示。

从堆栈跟踪中，Log4j 2 被配置为同步记录，因此可能集合被另一个线程修改，而不是正在记录的应用程序线程。

关于同步日志记录的另一件事是，您的基准测试结果可能只是反映磁盘 I/O 的成本，或者，如果您的基准测试是多线程的，则反映 Log4j 2 appender 中的锁争用成本。这很可能是主要成本。如果这是您想要测量的，那就太好了。否则我强烈建议使用 Log4j 2 的Async Loggers。使用 Async Loggers 的最简单方法是设置单个系统属性：将 Log4jContextSelector 设置为 org.apache.logging.log4j.core.async.AsyncLoggerContextSelector。