Well, you were right there was something fishy with the deserialization. If the ObjectMessage parameter is not Serializable, it gets serialized as a string. Then, originalObjectMessage.equals(deserializedObjectMessage) returns false since ObjectMessage.equals does not take into account that the parameter may have been turned into a string.
I've added a JUnit test to illustrate the problem (now @Ignored or it would break the build). I propose that we modify the equals method to also compare the string version of the objMessage parameter. Thoughts? On Tue, Aug 12, 2014 at 8:33 AM, Remko Popma <[email protected]> wrote: > I'll add a junit test, but this is what it was before I started touching > that class (except for obj.toString() -> String.valueOf(obj)). > > Sent from my iPhone > > > On 2014/08/12, at 8:02, Ralph Goers <[email protected]> wrote: > > > > Serialization does: > > > > if (obj instanceof Serializable) { > > out.writeObject(obj); > > } else { > > out.writeObject(String.valueOf(obj)); > > } > > > > Deserialization does: > > > > in.defaultReadObject(); > > obj = in.readObject(); > > > > So if obj is not Serializable a String will be written. Upon > deserialization obj will be set to either the the deserialized version of > the object or to the String. I guess this will work. > > > > Ralph > > > > > >> On Aug 11, 2014, at 2:46 PM, Remko Popma <[email protected]> wrote: > >> > >> I didn't change the serialization behavior. I only changed > >> obj.toString() > >> to > >> String.valueOf(obj) > >> > >> The stringValue field wasn't there originally (I incorrectly added it > as non-transient in my first attempt). It is now transient so serialized > form should be the same as pre-change. > >> > >> The serialization behavior of ObjectMessage has always been to > serialize as Object if possible (Serializable), otherwise as String. > Deserialization will just read whatever was serialized. That may not be the > same object field but is the best we can do. > >> > >> Or did I miss something? (away from PC) > >> > >> Sent from my iPhone > >> > >>> On 2014/08/12, at 2:38, Ralph Goers <[email protected]> > wrote: > >>> > >>> I believe this breaks deserialization of ObjectMessage. It is being > serialized as either the serialized form of the Object or as a String. > Deserialization doesn't account for this. > >>> > >>> Ralph > >>> > >>>> On Aug 11, 2014, at 7:16 AM, [email protected] wrote: > >>>> > >>>> Author: rpopma > >>>> Date: Mon Aug 11 14:16:22 2014 > >>>> New Revision: 1617291 > >>>> > >>>> URL: http://svn.apache.org/r1617291 > >>>> Log: > >>>> LOG4J2-763: use different mechanism to solve this problem: instead of > initializing the formatted message string in the message constructor, > postpone this as long as possible until getFormattedMessage() is called. > Async loggers and AsyncAppender now call message.getFormattedMessage() > before passing the log event to the background thread. Added more tests. > >>>> > >>>> Modified: > >>>> > logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/FormattedMessage.java > >>>> > logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/LocalizedMessage.java > >>>> > logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/MessageFormatMessage.java > >>>> > logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/ObjectMessage.java > >>>> > logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/StringFormattedMessage.java > >>>> > logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/FormattedMessageTest.java > >>>> > logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/LocalizedMessageTest.java > >>>> > logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/MessageFormatMessageTest.java > >>>> > logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/ObjectMessageTest.java > >>>> > logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/StringFormattedMessageTest.java > >>>> > logging/log4j/log4j2/trunk/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppender.java > >>>> > logging/log4j/log4j2/trunk/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLogger.java > >>>> > logging/log4j/log4j2/trunk/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerConfigHelper.java > >>>> logging/log4j/log4j2/trunk/src/changes/changes.xml > >>>> > >>>> Modified: > logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/FormattedMessage.java > >>>> URL: > http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/FormattedMessage.java?rev=1617291&r1=1617290&r2=1617291&view=diff > >>>> > ============================================================================== > >>>> --- > logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/FormattedMessage.java > (original) > >>>> +++ > logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/FormattedMessage.java > Mon Aug 11 14:16:22 2014 > >>>> @@ -46,7 +46,6 @@ public class FormattedMessage implements > >>>> this.messagePattern = messagePattern; > >>>> this.argArray = arguments; > >>>> this.throwable = throwable; > >>>> - getFormattedMessage(); // LOG4J2-763 take snapshot of > parameters at message construction time > >>>> } > >>>> > >>>> public FormattedMessage(final String messagePattern, final Object[] > arguments) { > >>>> > >>>> Modified: > logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/LocalizedMessage.java > >>>> URL: > http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/LocalizedMessage.java?rev=1617291&r1=1617290&r2=1617291&view=diff > >>>> > ============================================================================== > >>>> --- > logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/LocalizedMessage.java > (original) > >>>> +++ > logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/LocalizedMessage.java > Mon Aug 11 14:16:22 2014 > >>>> @@ -78,7 +78,6 @@ public class LocalizedMessage implements > >>>> this.baseName = baseName; > >>>> this.resourceBundle = null; > >>>> this.locale = locale; > >>>> - getFormattedMessage(); // LOG4J2-763 take snapshot of > parameters at message construction time > >>>> } > >>>> > >>>> public LocalizedMessage(final ResourceBundle bundle, final Locale > locale, final String key, > >>>> @@ -89,7 +88,6 @@ public class LocalizedMessage implements > >>>> this.baseName = null; > >>>> this.resourceBundle = bundle; > >>>> this.locale = locale; > >>>> - getFormattedMessage(); // LOG4J2-763 take snapshot of > parameters at message construction time > >>>> } > >>>> > >>>> public LocalizedMessage(final Locale locale, final String key, final > Object[] arguments) { > >>>> > >>>> Modified: > logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/MessageFormatMessage.java > >>>> URL: > http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/MessageFormatMessage.java?rev=1617291&r1=1617290&r2=1617291&view=diff > >>>> > ============================================================================== > >>>> --- > logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/MessageFormatMessage.java > (original) > >>>> +++ > logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/MessageFormatMessage.java > Mon Aug 11 14:16:22 2014 > >>>> @@ -49,7 +49,6 @@ public class MessageFormatMessage implem > >>>> if (arguments != null && arguments.length > 0 && > arguments[arguments.length - 1] instanceof Throwable) { > >>>> this.throwable = (Throwable) arguments[arguments.length - 1]; > >>>> } > >>>> - getFormattedMessage(); // LOG4J2-763 take snapshot of > parameters at message construction time > >>>> } > >>>> > >>>> /** > >>>> > >>>> Modified: > logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/ObjectMessage.java > >>>> URL: > http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/ObjectMessage.java?rev=1617291&r1=1617290&r2=1617291&view=diff > >>>> > ============================================================================== > >>>> --- > logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/ObjectMessage.java > (original) > >>>> +++ > logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/ObjectMessage.java > Mon Aug 11 14:16:22 2014 > >>>> @@ -29,7 +29,7 @@ public class ObjectMessage implements Me > >>>> private static final long serialVersionUID = -5903272448334166185L; > >>>> > >>>> private transient Object obj; > >>>> - private final String objectString; > >>>> + private transient String objectString; > >>>> > >>>> /** > >>>> * Create the ObjectMessage. > >>>> @@ -40,9 +40,6 @@ public class ObjectMessage implements Me > >>>> obj = "null"; > >>>> } > >>>> this.obj = obj; > >>>> - > >>>> - // LOG4J2-763: take snapshot of parameters at message > construction time > >>>> - objectString = String.valueOf(obj); > >>>> } > >>>> > >>>> /** > >>>> @@ -51,6 +48,10 @@ public class ObjectMessage implements Me > >>>> */ > >>>> @Override > >>>> public String getFormattedMessage() { > >>>> + // LOG4J2-763: cache formatted string in case obj changes > later > >>>> + if (objectString == null) { > >>>> + objectString = String.valueOf(obj); > >>>> + } > >>>> return objectString; > >>>> } > >>>> > >>>> @@ -60,7 +61,7 @@ public class ObjectMessage implements Me > >>>> */ > >>>> @Override > >>>> public String getFormat() { > >>>> - return objectString; > >>>> + return getFormattedMessage(); > >>>> } > >>>> > >>>> /** > >>>> @@ -69,7 +70,7 @@ public class ObjectMessage implements Me > >>>> */ > >>>> @Override > >>>> public Object[] getParameters() { > >>>> - return new Object[]{obj}; > >>>> + return new Object[] { obj }; > >>>> } > >>>> > >>>> @Override > >>>> @@ -82,8 +83,7 @@ public class ObjectMessage implements Me > >>>> } > >>>> > >>>> final ObjectMessage that = (ObjectMessage) o; > >>>> - > >>>> - return !(obj != null ? !obj.equals(that.obj) : that.obj != > null); > >>>> + return obj == null ? that.obj == null : obj.equals(that.obj); > >>>> } > >>>> > >>>> @Override > >>>> @@ -93,7 +93,7 @@ public class ObjectMessage implements Me > >>>> > >>>> @Override > >>>> public String toString() { > >>>> - return "ObjectMessage[obj=" + objectString + ']'; > >>>> + return "ObjectMessage[obj=" + getFormattedMessage() + ']'; > >>>> } > >>>> > >>>> private void writeObject(final ObjectOutputStream out) throws > IOException { > >>>> @@ -101,7 +101,7 @@ public class ObjectMessage implements Me > >>>> if (obj instanceof Serializable) { > >>>> out.writeObject(obj); > >>>> } else { > >>>> - out.writeObject(obj.toString()); > >>>> + out.writeObject(String.valueOf(obj)); > >>>> } > >>>> } > >>>> > >>>> > >>>> Modified: > logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/StringFormattedMessage.java > >>>> URL: > http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/StringFormattedMessage.java?rev=1617291&r1=1617290&r2=1617291&view=diff > >>>> > ============================================================================== > >>>> --- > logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/StringFormattedMessage.java > (original) > >>>> +++ > logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/StringFormattedMessage.java > Mon Aug 11 14:16:22 2014 > >>>> @@ -48,7 +48,6 @@ public class StringFormattedMessage impl > >>>> if (arguments != null && arguments.length > 0 && > arguments[arguments.length - 1] instanceof Throwable) { > >>>> this.throwable = (Throwable) arguments[arguments.length - 1]; > >>>> } > >>>> - getFormattedMessage(); // LOG4J2-763 take snapshot of > parameters at message construction time > >>>> } > >>>> > >>>> /** > >>>> > >>>> Modified: > logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/FormattedMessageTest.java > >>>> URL: > http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/FormattedMessageTest.java?rev=1617291&r1=1617290&r2=1617291&view=diff > >>>> > ============================================================================== > >>>> --- > logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/FormattedMessageTest.java > (original) > >>>> +++ > logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/FormattedMessageTest.java > Mon Aug 11 14:16:22 2014 > >>>> @@ -85,14 +85,27 @@ public class FormattedMessageTest { > >>>> } > >>>> > >>>> @Test > >>>> - public void testSafeWithMutableParams() { // LOG4J2-763 > >>>> + public void testUnsafeWithMutableParams() { // LOG4J2-763 > >>>> final String testMsg = "Test message %s"; > >>>> final Mutable param = new Mutable().set("abc"); > >>>> - FormattedMessage msg = new FormattedMessage(testMsg, param); > >>>> + final FormattedMessage msg = new FormattedMessage(testMsg, > param); > >>>> > >>>> // modify parameter before calling msg.getFormattedMessage > >>>> param.set("XYZ"); > >>>> - String actual = msg.getFormattedMessage(); > >>>> + final String actual = msg.getFormattedMessage(); > >>>> + assertEquals("Expected most recent param value", "Test > message XYZ", actual); > >>>> + } > >>>> + > >>>> + @Test > >>>> + public void testSafeAfterGetFormattedMessageIsCalled() { // > LOG4J2-763 > >>>> + final String testMsg = "Test message %s"; > >>>> + final Mutable param = new Mutable().set("abc"); > >>>> + final FormattedMessage msg = new FormattedMessage(testMsg, > param); > >>>> + > >>>> + // modify parameter after calling msg.getFormattedMessage > >>>> + msg.getFormattedMessage(); // freeze the formatted message > >>>> + param.set("XYZ"); > >>>> + final String actual = msg.getFormattedMessage(); > >>>> assertEquals("Should use initial param value", "Test message > abc", actual); > >>>> } > >>>> } > >>>> > >>>> Modified: > logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/LocalizedMessageTest.java > >>>> URL: > http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/LocalizedMessageTest.java?rev=1617291&r1=1617290&r2=1617291&view=diff > >>>> > ============================================================================== > >>>> --- > logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/LocalizedMessageTest.java > (original) > >>>> +++ > logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/LocalizedMessageTest.java > Mon Aug 11 14:16:22 2014 > >>>> @@ -65,15 +65,27 @@ public class LocalizedMessageTest { > >>>> } > >>>> > >>>> @Test > >>>> - public void testSafeWithMutableParams() { // LOG4J2-763 > >>>> + public void testUnsafeWithMutableParams() { // LOG4J2-763 > >>>> final String testMsg = "Test message %s"; > >>>> final Mutable param = new Mutable().set("abc"); > >>>> - LocalizedMessage msg = new LocalizedMessage(testMsg, param); > >>>> + final LocalizedMessage msg = new LocalizedMessage(testMsg, > param); > >>>> > >>>> // modify parameter before calling msg.getFormattedMessage > >>>> param.set("XYZ"); > >>>> - String actual = msg.getFormattedMessage(); > >>>> - assertEquals("Should use initial param value", "Test message > abc", actual); > >>>> + final String actual = msg.getFormattedMessage(); > >>>> + assertEquals("Expected most recent param value", "Test > message XYZ", actual); > >>>> } > >>>> > >>>> + @Test > >>>> + public void testSafeAfterGetFormattedMessageIsCalled() { // > LOG4J2-763 > >>>> + final String testMsg = "Test message %s"; > >>>> + final Mutable param = new Mutable().set("abc"); > >>>> + final LocalizedMessage msg = new LocalizedMessage(testMsg, > param); > >>>> + > >>>> + // modify parameter after calling msg.getFormattedMessage > >>>> + msg.getFormattedMessage(); > >>>> + param.set("XYZ"); > >>>> + final String actual = msg.getFormattedMessage(); > >>>> + assertEquals("Should use initial param value", "Test message > abc", actual); > >>>> + } > >>>> } > >>>> > >>>> Modified: > logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/MessageFormatMessageTest.java > >>>> URL: > http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/MessageFormatMessageTest.java?rev=1617291&r1=1617290&r2=1617291&view=diff > >>>> > ============================================================================== > >>>> --- > logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/MessageFormatMessageTest.java > (original) > >>>> +++ > logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/MessageFormatMessageTest.java > Mon Aug 11 14:16:22 2014 > >>>> @@ -63,14 +63,27 @@ public class MessageFormatMessageTest { > >>>> } > >>>> > >>>> @Test > >>>> - public void testSafeWithMutableParams() { // LOG4J2-763 > >>>> + public void testUnsafeWithMutableParams() { // LOG4J2-763 > >>>> final String testMsg = "Test message {0}"; > >>>> final Mutable param = new Mutable().set("abc"); > >>>> - MessageFormatMessage msg = new MessageFormatMessage(testMsg, > param); > >>>> + final MessageFormatMessage msg = new > MessageFormatMessage(testMsg, param); > >>>> > >>>> // modify parameter before calling msg.getFormattedMessage > >>>> param.set("XYZ"); > >>>> - String actual = msg.getFormattedMessage(); > >>>> + final String actual = msg.getFormattedMessage(); > >>>> + assertEquals("Expected most recent param value", "Test > message XYZ", actual); > >>>> + } > >>>> + > >>>> + @Test > >>>> + public void testSafeAfterGetFormattedMessageIsCalled() { // > LOG4J2-763 > >>>> + final String testMsg = "Test message {0}"; > >>>> + final Mutable param = new Mutable().set("abc"); > >>>> + final MessageFormatMessage msg = new > MessageFormatMessage(testMsg, param); > >>>> + > >>>> + // modify parameter after calling msg.getFormattedMessage > >>>> + msg.getFormattedMessage(); > >>>> + param.set("XYZ"); > >>>> + final String actual = msg.getFormattedMessage(); > >>>> assertEquals("Should use initial param value", "Test message > abc", actual); > >>>> } > >>>> } > >>>> > >>>> Modified: > logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/ObjectMessageTest.java > >>>> URL: > http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/ObjectMessageTest.java?rev=1617291&r1=1617290&r2=1617291&view=diff > >>>> > ============================================================================== > >>>> --- > logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/ObjectMessageTest.java > (original) > >>>> +++ > logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/ObjectMessageTest.java > Mon Aug 11 14:16:22 2014 > >>>> @@ -41,13 +41,25 @@ public class ObjectMessageTest { > >>>> } > >>>> > >>>> @Test > >>>> - public void testSafeWithMutableParams() { // LOG4J2-763 > >>>> + public void testUnsafeWithMutableParams() { // LOG4J2-763 > >>>> final Mutable param = new Mutable().set("abc"); > >>>> - ObjectMessage msg = new ObjectMessage(param); > >>>> + final ObjectMessage msg = new ObjectMessage(param); > >>>> > >>>> // modify parameter before calling msg.getFormattedMessage > >>>> param.set("XYZ"); > >>>> - String actual = msg.getFormattedMessage(); > >>>> + final String actual = msg.getFormattedMessage(); > >>>> + assertEquals("Expected most recent param value", "XYZ", > actual); > >>>> + } > >>>> + > >>>> + @Test > >>>> + public void testSafeAfterGetFormattedMessageIsCalled() { // > LOG4J2-763 > >>>> + final Mutable param = new Mutable().set("abc"); > >>>> + final ObjectMessage msg = new ObjectMessage(param); > >>>> + > >>>> + // modify parameter after calling msg.getFormattedMessage > >>>> + msg.getFormattedMessage(); > >>>> + param.set("XYZ"); > >>>> + final String actual = msg.getFormattedMessage(); > >>>> assertEquals("Should use initial param value", "abc", actual); > >>>> } > >>>> } > >>>> > >>>> Modified: > logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/StringFormattedMessageTest.java > >>>> URL: > http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/StringFormattedMessageTest.java?rev=1617291&r1=1617290&r2=1617291&view=diff > >>>> > ============================================================================== > >>>> --- > logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/StringFormattedMessageTest.java > (original) > >>>> +++ > logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/StringFormattedMessageTest.java > Mon Aug 11 14:16:22 2014 > >>>> @@ -62,14 +62,27 @@ public class StringFormattedMessageTest > >>>> } > >>>> > >>>> @Test > >>>> - public void testSafeWithMutableParams() { // LOG4J2-763 > >>>> + public void testUnsafeWithMutableParams() { // LOG4J2-763 > >>>> final String testMsg = "Test message %s"; > >>>> final Mutable param = new Mutable().set("abc"); > >>>> - StringFormattedMessage msg = new > StringFormattedMessage(testMsg, param); > >>>> + final StringFormattedMessage msg = new > StringFormattedMessage(testMsg, param); > >>>> > >>>> // modify parameter before calling msg.getFormattedMessage > >>>> param.set("XYZ"); > >>>> - String actual = msg.getFormattedMessage(); > >>>> + final String actual = msg.getFormattedMessage(); > >>>> + assertEquals("Should use initial param value", "Test message > XYZ", actual); > >>>> + } > >>>> + > >>>> + @Test > >>>> + public void testSafeAfterGetFormattedMessageIsCalled() { // > LOG4J2-763 > >>>> + final String testMsg = "Test message %s"; > >>>> + final Mutable param = new Mutable().set("abc"); > >>>> + final StringFormattedMessage msg = new > StringFormattedMessage(testMsg, param); > >>>> + > >>>> + // modify parameter after calling msg.getFormattedMessage > >>>> + msg.getFormattedMessage(); > >>>> + param.set("XYZ"); > >>>> + final String actual = msg.getFormattedMessage(); > >>>> assertEquals("Should use initial param value", "Test message > abc", actual); > >>>> } > >>>> } > >>>> > >>>> Modified: > logging/log4j/log4j2/trunk/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppender.java > >>>> URL: > http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppender.java?rev=1617291&r1=1617290&r2=1617291&view=diff > >>>> > ============================================================================== > >>>> --- > logging/log4j/log4j2/trunk/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppender.java > (original) > >>>> +++ > logging/log4j/log4j2/trunk/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppender.java > Mon Aug 11 14:16:22 2014 > >>>> @@ -138,6 +138,7 @@ public final class AsyncAppender extends > >>>> } > >>>> logEvent = ((RingBufferLogEvent) logEvent).createMemento(); > >>>> } > >>>> + logEvent.getMessage().getFormattedMessage(); // LOG4J2-763: > ask message to freeze parameters > >>>> final Log4jLogEvent coreEvent = (Log4jLogEvent) logEvent; > >>>> boolean appendSuccessful = false; > >>>> if (blocking) { > >>>> > >>>> Modified: > logging/log4j/log4j2/trunk/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLogger.java > >>>> URL: > http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLogger.java?rev=1617291&r1=1617290&r2=1617291&view=diff > >>>> > ============================================================================== > >>>> --- > logging/log4j/log4j2/trunk/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLogger.java > (original) > >>>> +++ > logging/log4j/log4j2/trunk/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLogger.java > Mon Aug 11 14:16:22 2014 > >>>> @@ -226,6 +226,7 @@ public class AsyncLogger extends Logger > >>>> > >>>> @Override > >>>> public void logMessage(final String fqcn, final Level level, final > Marker marker, final Message message, final Throwable thrown) { > >>>> + // TODO refactor to reduce size to <= 35 bytecodes to allow > JVM to inline it > >>>> Info info = threadlocalInfo.get(); > >>>> if (info == null) { > >>>> info = new Info(new RingBufferLogEventTranslator(), > Thread.currentThread().getName(), false); > >>>> @@ -245,6 +246,7 @@ public class AsyncLogger extends Logger > >>>> config.loggerConfig.log(getName(), fqcn, marker, level, > message, thrown); > >>>> return; > >>>> } > >>>> + message.getFormattedMessage(); // LOG4J2-763: ask message to > freeze parameters > >>>> final boolean includeLocation = > config.loggerConfig.isIncludeLocation(); > >>>> info.translator.setValues(this, getName(), marker, fqcn, level, > message, // > >>>> // don't construct ThrowableProxy until required > >>>> > >>>> Modified: > logging/log4j/log4j2/trunk/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerConfigHelper.java > >>>> URL: > http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerConfigHelper.java?rev=1617291&r1=1617290&r2=1617291&view=diff > >>>> > ============================================================================== > >>>> --- > logging/log4j/log4j2/trunk/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerConfigHelper.java > (original) > >>>> +++ > logging/log4j/log4j2/trunk/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerConfigHelper.java > Mon Aug 11 14:16:22 2014 > >>>> @@ -316,6 +316,7 @@ class AsyncLoggerConfigHelper { > >>>> * calling thread needs to process the event itself > >>>> */ > >>>> public boolean callAppendersFromAnotherThread(final LogEvent event) { > >>>> + // TODO refactor to reduce size to <= 35 bytecodes to allow > JVM to inline it > >>>> final Disruptor<Log4jEventWrapper> temp = disruptor; > >>>> if (temp == null) { // LOG4J2-639 > >>>> LOGGER.fatal("Ignoring log event after log4j was shut down"); > >>>> @@ -336,6 +337,8 @@ class AsyncLoggerConfigHelper { > >>>> if (event instanceof RingBufferLogEvent) { > >>>> logEvent = ((RingBufferLogEvent) event).createMemento(); > >>>> } > >>>> + logEvent.getMessage().getFormattedMessage(); // > LOG4J2-763: ask message to freeze parameters > >>>> + > >>>> // Note: do NOT use the temp variable above! > >>>> // That could result in adding a log event to the disruptor > after it was shut down, > >>>> // which could cause the publishEvent method to hang and > never return. > >>>> > >>>> Modified: logging/log4j/log4j2/trunk/src/changes/changes.xml > >>>> URL: > http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/src/changes/changes.xml?rev=1617291&r1=1617290&r2=1617291&view=diff > >>>> > ============================================================================== > >>>> --- logging/log4j/log4j2/trunk/src/changes/changes.xml (original) > >>>> +++ logging/log4j/log4j2/trunk/src/changes/changes.xml Mon Aug 11 > 14:16:22 2014 > >>>> @@ -29,8 +29,7 @@ > >>>> Startup takes a long time if you have empty packages attribute. > >>>> </action> > >>>> <action issue="LOG4J2-763" dev="rpopma" type="fix" due-to="Stephen > Connolly"> > >>>> - Improved FormattedMessage, StringFormattedMessage, > LocalizedMessage, MessageFormatMessage and > >>>> - ObjectMessage for asynchronous logging to ensure the > formatted message does not change even if > >>>> + Improved asynchronous loggers and appenders to ensure the > formatted message does not change even if > >>>> parameters are modified by the application. > (ParameterizedMessage was already safe.) > >>>> Improved documentation. > >>>> </action> > >>> > >>> > >>> --------------------------------------------------------------------- > >>> To unsubscribe, e-mail: [email protected] > >>> For additional commands, e-mail: [email protected] > >> > >> --------------------------------------------------------------------- > >> To unsubscribe, e-mail: [email protected] > >> For additional commands, e-mail: [email protected] > > > > > > --------------------------------------------------------------------- > > To unsubscribe, e-mail: [email protected] > > For additional commands, e-mail: [email protected] > > >
