Repository: logging-log4j2
Updated Branches:
  refs/heads/master b54045f77 -> f8113c029


[LOG4J2-2352] Reusable event message mementos are memoized

Fixed RingBufferLogEvent.memento which returned a
ParameterizedMessage rather than a MememntoMessage.


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

Branch: refs/heads/master
Commit: f8113c029ef1f8dd2402bea99096f6d0cc12c522
Parents: b54045f
Author: Carter Kozak <cko...@apache.org>
Authored: Tue Jun 12 11:03:43 2018 -0400
Committer: Carter Kozak <cko...@apache.org>
Committed: Wed Jun 13 18:30:12 2018 -0400

----------------------------------------------------------------------
 .../log4j/core/async/RingBufferLogEvent.java    | 14 ++---
 .../log4j/core/impl/MutableLogEvent.java        | 13 ++---
 .../AsyncLoggersWithAsyncAppenderTest.java      | 14 ++---
 .../core/async/RingBufferLogEventTest.java      | 55 ++++++++++++++++----
 ...MutableLogEventWithReusableParamMsgTest.java |  8 +++
 .../AsyncLoggersWithAsyncAppenderTest.xml       |  2 +-
 src/changes/changes.xml                         |  8 +++
 7 files changed, 76 insertions(+), 38 deletions(-)
----------------------------------------------------------------------


http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/f8113c02/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEvent.java
----------------------------------------------------------------------
diff --git 
a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEvent.java
 
b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEvent.java
index 5e24d14..96059a9 100644
--- 
a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEvent.java
+++ 
b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEvent.java
@@ -293,11 +293,10 @@ public class RingBufferLogEvent implements LogEvent, 
ReusableMessage, CharSequen
 
     @Override
     public Message memento() {
-        if (message != null) {
-            return message;
+        if (message == null) {
+            message = new MementoMessage(String.valueOf(messageText), 
messageFormat, getParameters());
         }
-        final Object[] params = parameters == null ? new Object[0] : 
Arrays.copyOf(parameters, parameterCount);
-        return new ParameterizedMessage(messageText.toString(), params);
+        return message;
     }
 
     // CharSequence impl
@@ -317,11 +316,6 @@ public class RingBufferLogEvent implements LogEvent, 
ReusableMessage, CharSequen
         return messageText.subSequence(start, end);
     }
 
-
-    private Message getNonNullImmutableMessage() {
-        return message != null ? message : new 
MementoMessage(String.valueOf(messageText), messageFormat, getParameters());
-    }
-
     @Override
     public Throwable getThrown() {
         // after deserialization, thrown is null but thrownProxy may be 
non-null
@@ -461,7 +455,7 @@ public class RingBufferLogEvent implements LogEvent, 
ReusableMessage, CharSequen
                 .setLoggerFqcn(fqcn) //
                 .setLoggerName(loggerName) //
                 .setMarker(marker) //
-                .setMessage(getNonNullImmutableMessage()) // ensure non-null & 
immutable
+                .setMessage(memento()) // ensure non-null & immutable
                 .setNanoTime(nanoTime) //
                 .setSource(location) //
                 .setThreadId(threadId) //

http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/f8113c02/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/MutableLogEvent.java
----------------------------------------------------------------------
diff --git 
a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/MutableLogEvent.java
 
b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/MutableLogEvent.java
index 44d3c1e..80c086a 100644
--- 
a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/MutableLogEvent.java
+++ 
b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/MutableLogEvent.java
@@ -305,11 +305,10 @@ public class MutableLogEvent implements LogEvent, 
ReusableMessage, ParameterVisi
 
     @Override
     public Message memento() {
-        if (message != null) {
-            return message;
+        if (message == null) {
+            message = new MementoMessage(String.valueOf(messageText), 
messageFormat, getParameters());
         }
-        final Object[] params = parameters == null ? new Object[0] : 
Arrays.copyOf(parameters, parameterCount);
-        return new MementoMessage(messageText.toString(), messageFormat, 
params);
+        return message;
     }
 
     @Override
@@ -488,7 +487,7 @@ public class MutableLogEvent implements LogEvent, 
ReusableMessage, ParameterVisi
                 .setLoggerFqcn(loggerFqcn) //
                 .setLoggerName(loggerName) //
                 .setMarker(marker) //
-                .setMessage(getNonNullImmutableMessage()) // ensure non-null & 
immutable
+                .setMessage(memento()) // ensure non-null & immutable
                 .setNanoTime(nanoTime) //
                 .setSource(source) //
                 .setThreadId(threadId) //
@@ -499,8 +498,4 @@ public class MutableLogEvent implements LogEvent, 
ReusableMessage, ParameterVisi
                 .setInstant(instant) //
         ;
     }
-
-    private Message getNonNullImmutableMessage() {
-        return message != null ? message : new 
MementoMessage(String.valueOf(messageText), messageFormat, getParameters());
-    }
 }

http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/f8113c02/log4j-core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggersWithAsyncAppenderTest.java
----------------------------------------------------------------------
diff --git 
a/log4j-core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggersWithAsyncAppenderTest.java
 
b/log4j-core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggersWithAsyncAppenderTest.java
index 2a4fc70..0b345ec 100644
--- 
a/log4j-core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggersWithAsyncAppenderTest.java
+++ 
b/log4j-core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggersWithAsyncAppenderTest.java
@@ -38,17 +38,17 @@ public class AsyncLoggersWithAsyncAppenderTest {
     @Test
     public void testLoggingWorks() throws Exception {
         final Logger logger = LogManager.getLogger();
-        logger.error("This is a test");
-        logger.warn("Hello world!");
+        logger.error("This {} a test", "is");
+        logger.warn("Hello {}!", "world");
         Thread.sleep(100);
         final List<String> list = 
context.getListAppender("List").getMessages();
         assertNotNull("No events generated", list);
-        assertTrue("Incorrect number of events. Expected 2, got " + 
list.size(), list.size() == 2);
+        assertEquals("Incorrect number of events ", 2, list.size());
         String msg = list.get(0);
-        String expected = getClass().getName() + " This is a test";
-        assertTrue("Expected " + expected + ", Actual " + msg, 
expected.equals(msg));
+        String expected = getClass().getName() + " This {} a test - [is] - 
This is a test";
+        assertEquals(expected, msg);
         msg = list.get(1);
-        expected = getClass().getName() + " Hello world!";
-        assertTrue("Expected " + expected + ", Actual " + msg, 
expected.equals(msg));
+        expected = getClass().getName() + " Hello {}! - [world] - Hello 
world!";
+        assertEquals(expected, msg);
     }
 }

http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/f8113c02/log4j-core/src/test/java/org/apache/logging/log4j/core/async/RingBufferLogEventTest.java
----------------------------------------------------------------------
diff --git 
a/log4j-core/src/test/java/org/apache/logging/log4j/core/async/RingBufferLogEventTest.java
 
b/log4j-core/src/test/java/org/apache/logging/log4j/core/async/RingBufferLogEventTest.java
index f89a101..bb891cd 100644
--- 
a/log4j-core/src/test/java/org/apache/logging/log4j/core/async/RingBufferLogEventTest.java
+++ 
b/log4j-core/src/test/java/org/apache/logging/log4j/core/async/RingBufferLogEventTest.java
@@ -44,6 +44,7 @@ import org.junit.Assert;
 import org.junit.Test;
 import org.junit.experimental.categories.Category;
 
+import static org.hamcrest.CoreMatchers.sameInstance;
 import static org.junit.Assert.*;
 
 /**
@@ -193,18 +194,50 @@ public class RingBufferLogEventTest {
         final Level level = Level.TRACE;
         ReusableMessageFactory factory = new ReusableMessageFactory();
         Message message = factory.newMessage("Hello {}!", "World");
-        final Throwable t = new InternalError("not a real error");
-        final ContextStack contextStack = new 
MutableThreadContextStack(Arrays.asList("a", "b"));
-        final String threadName = "main";
-        final StackTraceElement location = null;
-        evt.setValues(null, loggerName, marker, fqcn, level, message, t, 
(StringMap) evt.getContextData(),
-                contextStack, -1, threadName, -1, location, new 
FixedPreciseClock(12345, 678), new DummyNanoClock(1));
-        ((StringMap) evt.getContextData()).putValue("key", "value");
+        try {
+            final Throwable t = new InternalError("not a real error");
+            final ContextStack contextStack = new 
MutableThreadContextStack(Arrays.asList("a", "b"));
+            final String threadName = "main";
+            final StackTraceElement location = null;
+            evt.setValues(null, loggerName, marker, fqcn, level, message, t, 
(StringMap) evt.getContextData(),
+                    contextStack, -1, threadName, -1, location, new 
FixedPreciseClock(12345, 678), new DummyNanoClock(1));
+            ((StringMap) evt.getContextData()).putValue("key", "value");
+
+            final Message actual = evt.createMemento().getMessage();
+            assertEquals("Hello {}!", actual.getFormat());
+            assertArrayEquals(new String[]{"World"}, actual.getParameters());
+            assertEquals("Hello World!", actual.getFormattedMessage());
+        } finally {
+            ReusableMessageFactory.release(message);
+        }
+    }
 
-        final Message actual = evt.createMemento().getMessage();
-        assertEquals("Hello {}!", actual.getFormat());
-        assertArrayEquals(new String[] { "World" }, actual.getParameters());
-        assertEquals("Hello World!", actual.getFormattedMessage());
+    @Test
+    public void testMementoReuse() {
+        final RingBufferLogEvent evt = new RingBufferLogEvent();
+        // Initialize the event with parameters
+        evt.swapParameters(new Object[10]);
+        final String loggerName = "logger.name";
+        final Marker marker = MarkerManager.getMarker("marked man");
+        final String fqcn = "f.q.c.n";
+        final Level level = Level.TRACE;
+        ReusableMessageFactory factory = new ReusableMessageFactory();
+        Message message = factory.newMessage("Hello {}!", "World");
+        try {
+            final Throwable t = new InternalError("not a real error");
+            final ContextStack contextStack = new 
MutableThreadContextStack(Arrays.asList("a", "b"));
+            final String threadName = "main";
+            final StackTraceElement location = null;
+            evt.setValues(null, loggerName, marker, fqcn, level, message, t, 
(StringMap) evt.getContextData(),
+                    contextStack, -1, threadName, -1, location, new 
FixedPreciseClock(12345, 678), new DummyNanoClock(1));
+            ((StringMap) evt.getContextData()).putValue("key", "value");
+
+            final Message memento1 = evt.memento();
+            final Message memento2 = evt.memento();
+            assertThat(memento1, sameInstance(memento2));
+        } finally {
+            ReusableMessageFactory.release(message);
+        }
     }
 
     @Test

http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/f8113c02/log4j-core/src/test/java/org/apache/logging/log4j/message/MutableLogEventWithReusableParamMsgTest.java
----------------------------------------------------------------------
diff --git 
a/log4j-core/src/test/java/org/apache/logging/log4j/message/MutableLogEventWithReusableParamMsgTest.java
 
b/log4j-core/src/test/java/org/apache/logging/log4j/message/MutableLogEventWithReusableParamMsgTest.java
index 3cf523e..1371ed2 100644
--- 
a/log4j-core/src/test/java/org/apache/logging/log4j/message/MutableLogEventWithReusableParamMsgTest.java
+++ 
b/log4j-core/src/test/java/org/apache/logging/log4j/message/MutableLogEventWithReusableParamMsgTest.java
@@ -19,6 +19,9 @@ package org.apache.logging.log4j.message;
 import org.apache.logging.log4j.core.impl.MutableLogEvent;
 import org.junit.Test;
 
+import static org.hamcrest.MatcherAssert.assertThat;
+import static org.hamcrest.core.IsSame.sameInstance;
+
 /**
  * LOG4J2-1409
  */
@@ -49,5 +52,10 @@ public class MutableLogEventWithReusableParamMsgTest {
         msg.set("Hello {} {} {}", 1, 2, 3);
         evt.setMessage(msg);
         evt.clear();
+
+        Message mementoMessage = evt.memento();
+        Message mementoMessageSecondInvocation = evt.memento();
+        // MutableLogEvent.memento should be cached
+        assertThat(mementoMessage, 
sameInstance(mementoMessageSecondInvocation));
     }
 }

http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/f8113c02/log4j-core/src/test/resources/AsyncLoggersWithAsyncAppenderTest.xml
----------------------------------------------------------------------
diff --git 
a/log4j-core/src/test/resources/AsyncLoggersWithAsyncAppenderTest.xml 
b/log4j-core/src/test/resources/AsyncLoggersWithAsyncAppenderTest.xml
index 0775cde..12c5925 100644
--- a/log4j-core/src/test/resources/AsyncLoggersWithAsyncAppenderTest.xml
+++ b/log4j-core/src/test/resources/AsyncLoggersWithAsyncAppenderTest.xml
@@ -2,7 +2,7 @@
 <Configuration status="ERROR">
   <Appenders>
     <List name="List">
-      <PatternLayout pattern="%c %m"/>
+      <PatternLayout pattern="%c %testformat - %testparameters - %m"/>
     </List>
     <Async name="Async" includeLocation="true" error-ref="STDOUT">
       <AppenderRef ref="List"/>

http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/f8113c02/src/changes/changes.xml
----------------------------------------------------------------------
diff --git a/src/changes/changes.xml b/src/changes/changes.xml
index e823ca5..35a42a1 100644
--- a/src/changes/changes.xml
+++ b/src/changes/changes.xml
@@ -183,6 +183,10 @@
       <action issue="LOG4J2-2351" dev="ckozak" type="update">
         Added AbstractLogEvent.getMutableInstant to allow the MutableInstant 
instance to be modified by classes extending AbstractLogEvent.
       </action>
+      <action issue="LOG4J2-2352" dev="ckozak" type="fix">
+        RingBufferLogEvent memento messages provide the expected format 
string, and no longer attempt to substitute parameters into curly braces in 
parameter toString values.
+        Both RingBufferLogEvent and MutableLogEvent memento implementations 
memoize results to avoid rebuilding formatted string values.
+      </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">
@@ -259,6 +263,10 @@
       <action issue="LOG4J2-2351" dev="ckozak" type="update">
         Added AbstractLogEvent.getMutableInstant to allow the MutableInstant 
instance to be modified by classes extending AbstractLogEvent.
       </action>
+      <action issue="LOG4J2-2352" dev="ckozak" type="fix">
+        RingBufferLogEvent memento messages provide the expected format 
string, and no longer attempt to substitute parameters into curly braces in 
parameter toString values.
+        Both RingBufferLogEvent and MutableLogEvent memento implementations 
memoize results to avoid rebuilding formatted string values.
+      </action>
     </release>
     <release version="2.11.0" date="2018-xx-xx" description="GA Release 
2.11.0">
       <action issue="LOG4J2-2104" dev="rgoers" type="fix">

Reply via email to