That sounds good to me. Sent from my iPad
> On Aug 12, 2014, at 6:10 AM, Remko Popma <[email protected]> wrote: > > 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] >> > >
