You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by rp...@apache.org on 2016/11/20 15:50:45 UTC

logging-log4j2 git commit: LOG4J2-1719 Fixed race condition in ObjectMessage and SimpleMessage, ensuring that the log message contains the value the object has during the logging call.

Repository: logging-log4j2
Updated Branches:
  refs/heads/master b47e49688 -> 3d87ed70a


LOG4J2-1719 Fixed race condition in ObjectMessage and SimpleMessage, ensuring that the log message contains the value the object has during the logging call.


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

Branch: refs/heads/master
Commit: 3d87ed70a04568426d06b4f10f005e0222c1995b
Parents: b47e496
Author: rpopma <rp...@apache.org>
Authored: Mon Nov 21 00:50:35 2016 +0900
Committer: rpopma <rp...@apache.org>
Committed: Mon Nov 21 00:50:35 2016 +0900

----------------------------------------------------------------------
 .../logging/log4j/message/ObjectMessage.java    |  6 ++-
 .../logging/log4j/message/SimpleMessage.java    |  6 ++-
 .../log4j/message/ObjectMessageTest.java        | 18 +++++++-
 .../log4j/message/SimpleMessageTest.java        | 40 +++++++++++++++++
 .../log4j/message/ThreadDumpMessageTest.java    | 47 +++++++++++++++++++-
 src/changes/changes.xml                         |  3 ++
 6 files changed, 115 insertions(+), 5 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/3d87ed70/log4j-api/src/main/java/org/apache/logging/log4j/message/ObjectMessage.java
----------------------------------------------------------------------
diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/message/ObjectMessage.java b/log4j-api/src/main/java/org/apache/logging/log4j/message/ObjectMessage.java
index 33f7c30..ecd874c 100644
--- a/log4j-api/src/main/java/org/apache/logging/log4j/message/ObjectMessage.java
+++ b/log4j-api/src/main/java/org/apache/logging/log4j/message/ObjectMessage.java
@@ -59,7 +59,11 @@ public class ObjectMessage implements Message, StringBuilderFormattable {
 
     @Override
     public void formatTo(final StringBuilder buffer) {
-        StringBuilders.appendValue(buffer, obj);
+        if (objectString != null) { //
+            buffer.append(objectString);
+        } else {
+            StringBuilders.appendValue(buffer, obj);
+        }
     }
 
     /**

http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/3d87ed70/log4j-api/src/main/java/org/apache/logging/log4j/message/SimpleMessage.java
----------------------------------------------------------------------
diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/message/SimpleMessage.java b/log4j-api/src/main/java/org/apache/logging/log4j/message/SimpleMessage.java
index 0c209e5..3e9b70c 100644
--- a/log4j-api/src/main/java/org/apache/logging/log4j/message/SimpleMessage.java
+++ b/log4j-api/src/main/java/org/apache/logging/log4j/message/SimpleMessage.java
@@ -69,7 +69,11 @@ public class SimpleMessage implements Message, StringBuilderFormattable, CharSeq
 
     @Override
     public void formatTo(final StringBuilder buffer) {
-        buffer.append(charSequence);
+        if (message != null) {
+            buffer.append(message);
+        } else {
+            buffer.append(charSequence);
+        }
     }
 
     /**

http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/3d87ed70/log4j-api/src/test/java/org/apache/logging/log4j/message/ObjectMessageTest.java
----------------------------------------------------------------------
diff --git a/log4j-api/src/test/java/org/apache/logging/log4j/message/ObjectMessageTest.java b/log4j-api/src/test/java/org/apache/logging/log4j/message/ObjectMessageTest.java
index 5a3dc0c..8f547ae 100644
--- a/log4j-api/src/test/java/org/apache/logging/log4j/message/ObjectMessageTest.java
+++ b/log4j-api/src/test/java/org/apache/logging/log4j/message/ObjectMessageTest.java
@@ -67,7 +67,7 @@ public class ObjectMessageTest {
         final String actual = msg.getFormattedMessage();
         assertEquals("Should use initial param value", "abc", actual);
     }
-    
+
     @Test
     public void testSerializeWithSerializableParam() {
         final BigDecimal big = BigDecimal.valueOf(123.456);
@@ -75,7 +75,7 @@ public class ObjectMessageTest {
         final ObjectMessage other = SerialUtil.deserialize(SerialUtil.serialize(msg));
         assertEquals(msg, other);
     }
-    
+
     @Test
     public void testDeserializeNonSerializableParamEqualIfToStringSame() {
         class NonSerializable {
@@ -92,4 +92,18 @@ public class ObjectMessageTest {
         assertEquals(msg, other);
         assertEquals(other, msg);
     }
+
+    @Test
+    public void formatTo_usesCachedMessageString() throws Exception {
+        final StringBuilder charSequence = new StringBuilder("initial value");
+        final ObjectMessage message = new ObjectMessage(charSequence);
+        assertEquals("initial value", message.getFormattedMessage());
+
+        charSequence.setLength(0);
+        charSequence.append("different value");
+
+        final StringBuilder result = new StringBuilder();
+        message.formatTo(result);
+        assertEquals("initial value", result.toString());
+    }
 }

http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/3d87ed70/log4j-api/src/test/java/org/apache/logging/log4j/message/SimpleMessageTest.java
----------------------------------------------------------------------
diff --git a/log4j-api/src/test/java/org/apache/logging/log4j/message/SimpleMessageTest.java b/log4j-api/src/test/java/org/apache/logging/log4j/message/SimpleMessageTest.java
new file mode 100644
index 0000000..383ecb4
--- /dev/null
+++ b/log4j-api/src/test/java/org/apache/logging/log4j/message/SimpleMessageTest.java
@@ -0,0 +1,40 @@
+/*
+ * 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.message;
+
+import org.junit.Test;
+
+import static org.junit.Assert.*;
+
+/**
+ * Tests the SimpleMessage class.
+ */
+public class SimpleMessageTest {
+    @Test
+    public void formatTo_usesCachedMessageString() throws Exception {
+        final StringBuilder charSequence = new StringBuilder("initial value");
+        final SimpleMessage message = new SimpleMessage(charSequence);
+        assertEquals("initial value", message.getFormattedMessage());
+
+        charSequence.setLength(0);
+        charSequence.append("different value");
+
+        final StringBuilder result = new StringBuilder();
+        message.formatTo(result);
+        assertEquals("initial value", result.toString());
+    }
+}

http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/3d87ed70/log4j-api/src/test/java/org/apache/logging/log4j/message/ThreadDumpMessageTest.java
----------------------------------------------------------------------
diff --git a/log4j-api/src/test/java/org/apache/logging/log4j/message/ThreadDumpMessageTest.java b/log4j-api/src/test/java/org/apache/logging/log4j/message/ThreadDumpMessageTest.java
index 24a962b..e088234 100644
--- a/log4j-api/src/test/java/org/apache/logging/log4j/message/ThreadDumpMessageTest.java
+++ b/log4j-api/src/test/java/org/apache/logging/log4j/message/ThreadDumpMessageTest.java
@@ -16,6 +16,7 @@
  */
 package org.apache.logging.log4j.message;
 
+import java.util.concurrent.CountDownLatch;
 import java.util.concurrent.locks.ReentrantLock;
 
 import org.junit.Test;
@@ -88,10 +89,31 @@ public class ThreadDumpMessageTest {
         };
         other.start();
         other.join();
-        
+
         assertTrue("No mention of other thread in msg", !actual[0].contains("OtherThread"));
     }
 
+    @Test
+    public void formatTo_usesCachedMessageString() throws Exception {
+
+        final ThreadDumpMessage message = new ThreadDumpMessage("");
+        final String initial = message.getFormattedMessage();
+        assertFalse("no ThreadWithCountDownLatch thread yet", initial.contains("ThreadWithCountDownLatch"));
+
+        final CountDownLatch started = new CountDownLatch(1);
+        final CountDownLatch keepAlive = new CountDownLatch(1);
+        final ThreadWithCountDownLatch thread = new ThreadWithCountDownLatch(started, keepAlive);
+        thread.start();
+        started.await(); // ensure thread is running
+
+        final StringBuilder result = new StringBuilder();
+        message.formatTo(result);
+        assertFalse("no ThreadWithCountDownLatch captured",
+                result.toString().contains("ThreadWithCountDownLatch"));
+        assertEquals(initial, result.toString());
+        keepAlive.countDown(); // allow thread to die
+    }
+
     private class Thread1 extends Thread {
         private final ReentrantLock lock;
 
@@ -116,8 +138,31 @@ public class ThreadDumpMessageTest {
         @Override
         public void run() {
             synchronized (obj) {
+            }
+        }
+    }
 
+    private class ThreadWithCountDownLatch extends Thread {
+        private final CountDownLatch started;
+        private CountDownLatch keepAlive;
+        volatile boolean finished;
+
+        public ThreadWithCountDownLatch(final CountDownLatch started, final CountDownLatch keepAlive) {
+            super("ThreadWithCountDownLatch");
+            this.started = started;
+            this.keepAlive = keepAlive;
+            setDaemon(true);
+        }
+
+        @Override
+        public void run() {
+            started.countDown();
+            try {
+                keepAlive.await();
+            } catch (InterruptedException e) {
+                // ignored
             }
+            finished = true;
         }
     }
 }

http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/3d87ed70/src/changes/changes.xml
----------------------------------------------------------------------
diff --git a/src/changes/changes.xml b/src/changes/changes.xml
index 2ea1e92..a41ae98 100644
--- a/src/changes/changes.xml
+++ b/src/changes/changes.xml
@@ -24,6 +24,9 @@
   </properties>
   <body>
     <release version="2.8" date="2016-MM-DD" description="GA Release 2.8">
+      <action issue="LOG4J2-1719" dev="rpopma" type="fix">
+        Fixed race condition in ObjectMessage and SimpleMessage, ensuring that the log message contains the value the object has during the logging call.
+      </action>
       <action issue="LOG4J2-1688" dev="rpopma" type="fix">
         Fixed bug where elements of a log message parameter array were nulled out in garbage-free mode.
       </action>