You are viewing a plain text version of this content. The canonical link for it is here.
Posted to notifications@logging.apache.org by "Carter Kozak (Jira)" <ji...@apache.org> on 2019/12/08 02:53:00 UTC
[jira] [Updated] (LOG4J2-2725) RingBufferLogEvent.clear() is not
called in case of OutOfMemoryError (or any other exception/error)
[ https://issues.apache.org/jira/browse/LOG4J2-2725?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Carter Kozak updated LOG4J2-2725:
---------------------------------
Fix Version/s: 2.13.0
> RingBufferLogEvent.clear() is not called in case of OutOfMemoryError (or any other exception/error)
> ---------------------------------------------------------------------------------------------------
>
> Key: LOG4J2-2725
> URL: https://issues.apache.org/jira/browse/LOG4J2-2725
> Project: Log4j 2
> Issue Type: Bug
> Components: Core
> Affects Versions: 2.12.1
> Reporter: Dzmitry Anikechanka
> Priority: Major
> Labels: OOM
> Fix For: 2.13.0
>
> Attachments: RingBufferLogEvent_OOM.log, RingBufferLogEvent_dominator_tree.txt, domitator_tree_report_clear_called.txt, domitator_tree_report_clear_not_called.txt, image-2019-11-27-11-38-50-296.png, image-2019-11-27-11-39-49-904.png
>
> Time Spent: 1h 10m
> Remaining Estimate: 0h
>
> Please see the following class [https://logging.apache.org/log4j/2.x/log4j-core/apidocs/src-html/org/apache/logging/log4j/core/async/RingBufferLogEventHandler.html]
> There is the following code in the onEvent() method:
> {code:java}
> event.execute(endOfBatch);
> event.clear();{code}
> But in case of an exception (or error) in the execute() method - method clear() will not be invoked, event will be not cleared (and logged message as well) and will be in the memory (probably try/catch will be enough to fix the issue).
> I've faced this issue when OutOfMemoryError occurred due to very large messages logging (also message is duplication in the SimpleMessage class, please see related issue https://issues.apache.org/jira/browse/LOG4J2-2724) - all these event are still in memory and it causes a lot of another OOM errors as memory is not released (because clear() method was not invoked).
> Please see attached [^RingBufferLogEvent_dominator_tree.txt] report from Eclipse Memory Analyzer ([https://www.eclipse.org/mat/]). As you can see there are a log of RingBufferLogEvent object that were not cleared and garbage collected:
> {code:java}
> Class Name | Shallow Heap | Retained Heap | Percentage
> ------------------------------------------------------------------------------------------------------------------------------------------
> | | |
> com.lmax.disruptor.RingBuffer @ 0x9f29a550 | 144 | 1,205,392,112 | 57.52%
> '- java.lang.Object[262208] @ 0xb3d00000 | 1,048,848 | 1,205,391,968 | 57.52%
> |- org.apache.logging.log4j.core.async.RingBufferLogEvent @ 0xa35f7f08 | 104 | 233,251,104 | 11.13%
> |- org.apache.logging.log4j.core.async.RingBufferLogEvent @ 0x8727b4d8 | 104 | 185,151,488 | 8.84%
> |- org.apache.logging.log4j.core.async.RingBufferLogEvent @ 0x8728ef48 | 104 | 115,523,080 | 5.51%
> |- org.apache.logging.log4j.core.async.RingBufferLogEvent @ 0x87264ae0 | 104 | 83,109,992 | 3.97%
> |- org.apache.logging.log4j.core.async.RingBufferLogEvent @ 0xb1bd6950 | 104 | 69,825,312 | 3.33%
> |- org.apache.logging.log4j.core.async.RingBufferLogEvent @ 0x872730d0 | 104 | 67,399,704 | 3.22%
> |- org.apache.logging.log4j.core.async.RingBufferLogEvent @ 0x872651c8 | 104 | 67,209,496 | 3.21%
> |- org.apache.logging.log4j.core.async.RingBufferLogEvent @ 0x828e61d8 | 104 | 48,321,480 | 2.31%
> |- org.apache.logging.log4j.core.async.RingBufferLogEvent @ 0x828ca708 | 104 | 42,499,912 | 2.03%
> ................{code}
> Also please see [^RingBufferLogEvent_OOM.log] log file with OOM stacktrace:
> {code:java}
> java.lang.OutOfMemoryError: Java heap spacejava.lang.OutOfMemoryError: Java heap space at java.util.Arrays.copyOf(Arrays.java:3332) at java.lang.AbstractStringBuilder.expandCapacity(AbstractStringBuilder.java:137) at java.lang.AbstractStringBuilder.ensureCapacityInternal(AbstractStringBuilder.java:121) at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:421) at java.lang.StringBuilder.append(StringBuilder.java:136) at org.apache.logging.log4j.core.pattern.LineSeparatorPatternConverter.format(LineSeparatorPatternConverter.java:66) 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.RollingFileAppender.append(RollingFileAppender.java:268) 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.config.LoggerConfig.processLogEvent(LoggerConfig.java:433) at org.apache.logging.log4j.core.config.LoggerConfig.log(LoggerConfig.java:417) at org.apache.logging.log4j.core.config.AwaitCompletionReliabilityStrategy.log(AwaitCompletionReliabilityStrategy.java:79) at org.apache.logging.log4j.core.async.AsyncLogger.actualAsyncLog(AsyncLogger.java:337) at org.apache.logging.log4j.core.async.RingBufferLogEvent.execute(RingBufferLogEvent.java:161) at org.apache.logging.log4j.core.async.RingBufferLogEventHandler.onEvent(RingBufferLogEventHandler.java:45) at org.apache.logging.log4j.core.async.RingBufferLogEventHandler.onEvent(RingBufferLogEventHandler.java:29) at com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:129) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) {code}
> Could you please fix it or explain if such behavior is expected?
> Thanks,
> Dzmitry
--
This message was sent by Atlassian Jira
(v8.3.4#803005)