You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by ck...@apache.org on 2018/04/23 18:46:55 UTC
logging-log4j2 git commit: LOG4J2-2269:
ReusableLogEventFactory.release clears MutableLogEvent
Repository: logging-log4j2
Updated Branches:
refs/heads/master 58232a162 -> b28496e32
LOG4J2-2269: ReusableLogEventFactory.release clears MutableLogEvent
Fixes a memory leak where parameter references were held beyond
MutableLogEvent usage.
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/b28496e3
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/b28496e3
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/b28496e3
Branch: refs/heads/master
Commit: b28496e325663f770bc0889d7f5ed2e07505851d
Parents: 58232a1
Author: Carter Kozak <ck...@apache.org>
Authored: Fri Apr 13 19:27:54 2018 -0700
Committer: Carter Kozak <ck...@apache.org>
Committed: Mon Apr 23 14:45:39 2018 -0400
----------------------------------------------------------------------
.../core/impl/ReusableLogEventFactory.java | 4 +-
.../core/EventParameterMemoryLeakTest.java | 138 +++++++++++++++++++
.../core/impl/ReusableLogEventFactoryTest.java | 11 +-
.../resources/EventParameterMemoryLeakTest.xml | 19 +++
src/changes/changes.xml | 4 +
5 files changed, 171 insertions(+), 5 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/b28496e3/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/ReusableLogEventFactory.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/ReusableLogEventFactory.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/ReusableLogEventFactory.java
index 5404144..300b1b9 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/ReusableLogEventFactory.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/ReusableLogEventFactory.java
@@ -98,7 +98,9 @@ public class ReusableLogEventFactory implements LogEventFactory {
*/
public static void release(final LogEvent logEvent) { // LOG4J2-1583
if (logEvent instanceof MutableLogEvent) {
- ((MutableLogEvent) logEvent).reserved = false;
+ MutableLogEvent mutableLogEvent = (MutableLogEvent) logEvent;
+ mutableLogEvent.clear();
+ mutableLogEvent.reserved = false;
}
}
}
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/b28496e3/log4j-core/src/test/java/org/apache/logging/log4j/core/EventParameterMemoryLeakTest.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/EventParameterMemoryLeakTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/EventParameterMemoryLeakTest.java
new file mode 100644
index 0000000..de99eef
--- /dev/null
+++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/EventParameterMemoryLeakTest.java
@@ -0,0 +1,138 @@
+/*
+ * Licensed to the Apache Software Foundation (ASF) under one or more
+ * contributor license agreements. See the NOTICE file distributed with
+ * this work for additional information regarding copyright ownership.
+ * The ASF licenses this file to You under the Apache license, Version 2.0
+ * (the "License"); you may not use this file except in compliance with
+ * the License. You may obtain a copy of the License at
+ *
+ * http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the license for the specific language governing permissions and
+ * limitations under the license.
+ */
+package org.apache.logging.log4j.core;
+
+import com.google.common.io.ByteStreams;
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
+import org.apache.logging.log4j.core.config.ConfigurationFactory;
+import org.junit.BeforeClass;
+import org.junit.Test;
+
+import java.io.BufferedReader;
+import java.io.Closeable;
+import java.io.File;
+import java.io.FileReader;
+import java.io.IOException;
+import java.io.OutputStream;
+import java.util.concurrent.CountDownLatch;
+import java.util.concurrent.TimeUnit;
+import java.util.concurrent.atomic.AtomicBoolean;
+
+import static org.hamcrest.MatcherAssert.assertThat;
+import static org.hamcrest.Matchers.containsString;
+import static org.junit.Assert.assertNull;
+import static org.junit.Assert.assertTrue;
+
+public class EventParameterMemoryLeakTest {
+
+ @BeforeClass
+ public static void beforeClass() {
+ System.setProperty("log4j2.enable.threadlocals", "true");
+ System.setProperty("log4j2.enable.direct.encoders", "true");
+ System.setProperty("log4j2.is.webapp", "false");
+ System.setProperty(ConfigurationFactory.CONFIGURATION_FILE_PROPERTY, "EventParameterMemoryLeakTest.xml");
+ }
+
+ @Test
+ public void testParametersAreNotLeaked() throws Exception {
+ final File file = new File("target", "EventParameterMemoryLeakTest.log");
+ assertTrue("Deleted old file before test", !file.exists() || file.delete());
+
+ final Logger log = LogManager.getLogger("com.foo.Bar");
+ CountDownLatch latch = new CountDownLatch(1);
+ log.info("Message with parameter {}", new ParameterObject("paramValue", latch));
+ CoreLoggerContexts.stopLoggerContext(file);
+ final BufferedReader reader = new BufferedReader(new FileReader(file));
+ final String line1 = reader.readLine();
+ final String line2 = reader.readLine();
+ reader.close();
+ file.delete();
+ assertThat(line1, containsString("Message with parameter paramValue"));
+ assertNull("Expected only a single line", line2);
+ GarbageCollectionHelper gcHelper = new GarbageCollectionHelper();
+ gcHelper.run();
+ try {
+ assertTrue("Parameter should have been garbage collected", latch.await(30, TimeUnit.SECONDS));
+ } finally {
+ gcHelper.close();
+ }
+ }
+
+ private static final class ParameterObject {
+ private final String value;
+ private final CountDownLatch latch;
+ ParameterObject(String value, CountDownLatch latch) {
+ this.value = value;
+ this.latch = latch;
+ }
+
+ @Override
+ public String toString() {
+ return value;
+ }
+
+ @Override
+ protected void finalize() throws Throwable {
+ latch.countDown();
+ super.finalize();
+ }
+ }
+
+ private static final class GarbageCollectionHelper implements Closeable, Runnable {
+ private static final OutputStream sink = ByteStreams.nullOutputStream();
+ public final AtomicBoolean running = new AtomicBoolean();
+ private final CountDownLatch latch = new CountDownLatch(1);
+ private final Thread gcThread = new Thread(new Runnable() {
+ @Override
+ public void run() {
+ try {
+ while (running.get()) {
+ // Allocate data to help suggest a GC
+ try {
+ // 1mb of heap
+ sink.write(new byte[1024 * 1024]);
+ } catch (IOException ignored) {
+ }
+ // May no-op depending on the jvm configuration
+ System.gc();
+ }
+ } finally {
+ latch.countDown();
+ }
+ }
+ });
+
+ @Override
+ public void run() {
+ if (running.compareAndSet(false, true)) {
+ gcThread.start();
+ }
+ }
+
+ @Override
+ public void close() {
+ running.set(false);
+ try {
+ assertTrue("GarbageCollectionHelper did not shut down cleanly",
+ latch.await(10, TimeUnit.SECONDS));
+ } catch (InterruptedException e) {
+ throw new RuntimeException(e);
+ }
+ }
+ }
+}
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/b28496e3/log4j-core/src/test/java/org/apache/logging/log4j/core/impl/ReusableLogEventFactoryTest.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/impl/ReusableLogEventFactoryTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/impl/ReusableLogEventFactoryTest.java
index 61eb8d7..cb9eea3 100644
--- a/log4j-core/src/test/java/org/apache/logging/log4j/core/impl/ReusableLogEventFactoryTest.java
+++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/impl/ReusableLogEventFactoryTest.java
@@ -122,10 +122,13 @@ public class ReusableLogEventFactoryTest {
public void testCreateEventInitFieldsProperly() throws Exception {
final ReusableLogEventFactory factory = new ReusableLogEventFactory();
final LogEvent event = callCreateEvent(factory, "logger", Level.INFO, new SimpleMessage("xyz"), null);
- ReusableLogEventFactory.release(event);
- assertNotNull(event.getContextMap());
- assertNotNull(event.getContextData());
- assertNotNull(event.getContextStack());
+ try {
+ assertNotNull(event.getContextMap());
+ assertNotNull(event.getContextData());
+ assertNotNull(event.getContextStack());
+ } finally {
+ ReusableLogEventFactory.release(event);
+ }
}
}
\ No newline at end of file
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/b28496e3/log4j-core/src/test/resources/EventParameterMemoryLeakTest.xml
----------------------------------------------------------------------
diff --git a/log4j-core/src/test/resources/EventParameterMemoryLeakTest.xml b/log4j-core/src/test/resources/EventParameterMemoryLeakTest.xml
new file mode 100644
index 0000000..b626375
--- /dev/null
+++ b/log4j-core/src/test/resources/EventParameterMemoryLeakTest.xml
@@ -0,0 +1,19 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<Configuration status="ERROR">
+ <Appenders>
+ <File name="File"
+ fileName="target/EventParameterMemoryLeakTest.log"
+ bufferedIO="false"
+ immediateFlush="true"
+ append="false">
+ <PatternLayout>
+ <Pattern>%d %p %c{1.} [%t] %m%n</Pattern>
+ </PatternLayout>
+ </File>
+ </Appenders>
+ <Loggers>
+ <Root level="trace">
+ <AppenderRef ref="File"/>
+ </Root>
+ </Loggers>
+</Configuration>
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/b28496e3/src/changes/changes.xml
----------------------------------------------------------------------
diff --git a/src/changes/changes.xml b/src/changes/changes.xml
index 5939f53..a327984 100644
--- a/src/changes/changes.xml
+++ b/src/changes/changes.xml
@@ -139,6 +139,7 @@
<action issue="LOG4J2-2317" dev="ckozak" type="fix">
MutableLogEvent.getNonNullImmutableMessage and Log4jLogEvent.makeMessageImmutable retain format and parameters.
</action>
+<<<<<<< HEAD
<action issue="LOG4J2-2318" dev="ckozak" type="fix">
Messages are no longer mutated when the asynchronous queue is full. A warning is logged to the status logger instead.
</action>
@@ -155,6 +156,9 @@
Custom ContextSelector implementations which select an AsyncLoggerContext disable LoggerConfig.includeLocation
by default for parity with AsyncLoggerContextSelector.
</action>
+ <action issue="LOG4J2-2269" dev="ckozak" type="fix">
+ MutableLogEvent references to other objects are cleared after each use.
+ </action>
</release>
<release version="2.11.1" date="2018-MM-DD" description="GA Release 2.11.1">
<action issue="LOG4J2-2268" dev="rgoers" type="fix" due-to="Tilman Hausherr">