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/08/06 21:38:19 UTC

logging-log4j2 git commit: [LOG4J2-2201] Fix memory leak in ReusableParameterizedMessage

Repository: logging-log4j2
Updated Branches:
  refs/heads/master 346eac050 -> e2b5ef243


[LOG4J2-2201] Fix memory leak in ReusableParameterizedMessage

When emptyReplacement length is less than 10 but large enough for
the current paramers, the ReusableParameterizedMessage would
retain references to the most recently logged parameters.


Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/e2b5ef24
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/e2b5ef24
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/e2b5ef24

Branch: refs/heads/master
Commit: e2b5ef243f373c8421a50b5b3f0949eca20c222d
Parents: 346eac0
Author: Carter Kozak <ck...@apache.org>
Authored: Mon Aug 6 16:49:22 2018 -0400
Committer: Carter Kozak <ck...@apache.org>
Committed: Mon Aug 6 17:37:58 2018 -0400

----------------------------------------------------------------------
 .../message/ReusableParameterizedMessage.java   |  4 ++
 .../core/EventParameterMemoryLeakTest.java      | 48 -------------
 .../log4j/core/GarbageCollectionHelper.java     | 71 ++++++++++++++++++++
 ...sableParameterizedMessageMemoryLeakTest.java | 66 ++++++++++++++++++
 src/changes/changes.xml                         |  6 ++
 5 files changed, 147 insertions(+), 48 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/e2b5ef24/log4j-api/src/main/java/org/apache/logging/log4j/message/ReusableParameterizedMessage.java
----------------------------------------------------------------------
diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/message/ReusableParameterizedMessage.java b/log4j-api/src/main/java/org/apache/logging/log4j/message/ReusableParameterizedMessage.java
index cdd4dab..c0f5884 100644
--- a/log4j-api/src/main/java/org/apache/logging/log4j/message/ReusableParameterizedMessage.java
+++ b/log4j-api/src/main/java/org/apache/logging/log4j/message/ReusableParameterizedMessage.java
@@ -73,6 +73,10 @@ public class ReusableParameterizedMessage implements ReusableMessage, ParameterV
                 if (argCount <= emptyReplacement.length) {
                     // copy params into the specified replacement array and return that
                     System.arraycopy(params, 0, emptyReplacement, 0, argCount);
+                    // Do not retain references to objects in the reusable params array.
+                    for (int i = 0; i < argCount; i++) {
+                        params[i] = null;
+                    }
                     result = emptyReplacement;
                 } else {
                     // replacement array is too small for current content and future content: discard it

http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/e2b5ef24/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
index ed68ae5..9996f8b 100644
--- 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
@@ -16,7 +16,6 @@
  */
 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;
@@ -24,14 +23,10 @@ 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;
@@ -118,47 +113,4 @@ public class EventParameterMemoryLeakTest {
             return "ObjectThrowable " + object;
         }
     }
-
-    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/e2b5ef24/log4j-core/src/test/java/org/apache/logging/log4j/core/GarbageCollectionHelper.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/GarbageCollectionHelper.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/GarbageCollectionHelper.java
new file mode 100644
index 0000000..01b9d8a
--- /dev/null
+++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/GarbageCollectionHelper.java
@@ -0,0 +1,71 @@
+/*
+ * 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 java.io.Closeable;
+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.junit.Assert.assertTrue;
+
+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/e2b5ef24/log4j-core/src/test/java/org/apache/logging/log4j/core/ReusableParameterizedMessageMemoryLeakTest.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/ReusableParameterizedMessageMemoryLeakTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/ReusableParameterizedMessageMemoryLeakTest.java
new file mode 100644
index 0000000..c08f705
--- /dev/null
+++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/ReusableParameterizedMessageMemoryLeakTest.java
@@ -0,0 +1,66 @@
+/*
+ * 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 org.apache.logging.log4j.message.ReusableMessage;
+import org.apache.logging.log4j.message.ReusableMessageFactory;
+import org.junit.Test;
+
+import java.util.concurrent.CountDownLatch;
+import java.util.concurrent.TimeUnit;
+
+import static org.junit.Assert.assertTrue;
+
+public class ReusableParameterizedMessageMemoryLeakTest {
+
+    @Test
+    @SuppressWarnings("UnusedAssignment") // parameter set to null to allow garbage collection
+    public void testParametersAreNotLeaked() throws Exception {
+        CountDownLatch latch = new CountDownLatch(1);
+        ReusableMessage message = (ReusableMessage) ReusableMessageFactory.INSTANCE.newMessage(
+                "foo {}", new ParameterObject("paramValue", latch));
+        // Large enough for the parameters, but smaller than the default reusable array size.
+        message.swapParameters(new Object[5]);
+        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();
+        }
+    }
+}

http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/e2b5ef24/src/changes/changes.xml
----------------------------------------------------------------------
diff --git a/src/changes/changes.xml b/src/changes/changes.xml
index 42d3b4f..0ec3927 100644
--- a/src/changes/changes.xml
+++ b/src/changes/changes.xml
@@ -236,6 +236,9 @@
       <action issue="LOG4J2-2365" dev="ckozak" type="fix" due-to="Eugene Zimichev">
         NameAbbreviator correctly abbreviates first fragments (#188).
       </action>
+      <action issue="LOG4J2-2201" dev="ckozak" type="fix">
+        Fix memory leak in ReusableParameterizedMessage.
+      </action>
     </release>
     <release version="2.11.2" date="2018-MM-DD" description="GA Release 2.11.2">
       <action issue="LOG4J2-2391" dev="ckozak" type="update">
@@ -250,6 +253,9 @@
       <action issue="LOG4J2-2365" dev="ckozak" type="fix" due-to="Eugene Zimichev">
         NameAbbreviator correctly abbreviates first fragments (#188).
       </action>
+      <action issue="LOG4J2-2201" dev="ckozak" type="fix">
+        Fix memory leak in ReusableParameterizedMessage.
+      </action>
     </release>
     <release version="2.11.1" date="2018-07-22" description="GA Release 2.11.1">
       <action issue="LOG4J2-2389" dev="rgoers" type="fix" due-to="Liu Wen">