[
https://issues.apache.org/jira/browse/LOG4J2-2725?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16976424#comment-16976424
]
Remko Popma commented on LOG4J2-2725:
-------------------------------------
That sounds like it would be a good improvement.
Will you be able to provide a pull request?
> 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
> Attachments: RingBufferLogEvent_OOM.log,
> RingBufferLogEvent_dominator_tree.txt
>
>
> 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)
