My guess is that the values to ParameterizedMessage could be mutable and would change by the time they were logged. I thought I remembered reading a similar issue with ThreadContext or something elsewhere, but I can't find it right now.
On 10 August 2014 09:56, Ralph Goers <[email protected]> wrote: > I think there was a reason ParameterizedMessage got the strings up front, > but I don't know what it is. If it is possible to defer that I think that > would be great. > > Sent from my iPad > > On Aug 10, 2014, at 6:19 AM, Remko Popma <[email protected]> wrote: > > Ralph is saying that lazy initialization is better because the message may > be filtered out and end up not being logged. In that case we don't need to > pay the cost of constructing the formatted string unnecessarily. > > I'll take a look at it again later next week. > > (ParameterizedMessage was not lazy enough then: it always makes strings > of its arguments in the constructor. That should be postponed until > getFormattedMessage() is called.) > > > On Sunday, August 10, 2014, Gary Gregory <[email protected]> wrote: > >> Does that mean more fields can be made final? >> >> Gary >> >> >> -------- Original message -------- >> From: Remko Popma >> Date:08/10/2014 08:55 (GMT-05:00) >> To: Log4J Developers List >> Subject: Re: svn commit: r1617051 - in /logging/log4j/log4j2/trunk: >> log4j-api/src/main/java/org/apache/logging/log4j/message/ >> log4j-api/src/test/java/org/apache/logging/log4j/message/ src/changes/ >> src/site/xdoc/manual/ >> >> True. Until now getFormattedMessage() used lazy initialization in many >> messages. The LOG4J2-763 changes mean initialization always happens in the >> constructor so the code can be simplified. I won't have time for this >> tonight though. >> >> Sent from my iPhone >> >> > On 2014/08/10, at 21:12, Gary Gregory <[email protected]> wrote: >> > >> > Instead of calling getFormattedMessage(), how about refactoring it and >> call an initSomething method. This will make the call sites less smelly of >> programming by side effect. >> > >> > Gary >> > >> > >> > -------- Original message -------- >> > From: [email protected] >> > Date:08/10/2014 02:40 (GMT-05:00) >> > To: [email protected] >> > Subject: svn commit: r1617051 - in /logging/log4j/log4j2/trunk: >> log4j-api/src/main/java/org/apache/logging/log4j/message/ >> log4j-api/src/test/java/org/apache/logging/log4j/message/ src/changes/ >> src/site/xdoc/manual/ >> > >> > Author: rpopma >> > Date: Sun Aug 10 06:40:14 2014 >> > New Revision: 1617051 >> > >> > URL: http://svn.apache.org/r1617051 >> > Log: >> > LOG4J2-763: Improved FormattedMessage, StringFormattedMessage, >> LocalizedMessage, MessageFormatMessage and ObjectMessage for asynchronous >> logging to ensure the formatted message does not change even if parameters >> are modified by the application. Improved docs for MapMessage and >> StructuredDataMessage. Improved site docs. >> > >> > Added: >> > >> logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/Mutable.java >> (with props) >> > 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/MapMessage.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/main/java/org/apache/logging/log4j/message/StructuredDataMessage.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/MapMessageTest.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/ParameterizedMessageTest.java >> > >> logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/StringFormattedMessageTest.java >> > >> logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/StructuredDataMessageTest.java >> > >> logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/ThreadDumpMessageTest.java >> > logging/log4j/log4j2/trunk/src/changes/changes.xml >> > logging/log4j/log4j2/trunk/src/site/xdoc/manual/async.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=1617051&r1=1617050&r2=1617051&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 >> Sun Aug 10 06:40:14 2014 >> > @@ -46,12 +46,11 @@ 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) { >> > - this.messagePattern = messagePattern; >> > - this.argArray = arguments; >> > - this.throwable = null; >> > + this(messagePattern, arguments, null); >> > } >> > >> > /** >> > @@ -60,9 +59,7 @@ public class FormattedMessage implements >> > * @param arg The parameter. >> > */ >> > public FormattedMessage(final String messagePattern, final Object >> arg) { >> > - this.messagePattern = messagePattern; >> > - this.argArray = new Object[] {arg}; >> > - this.throwable = null; >> > + this(messagePattern, new Object[] {arg}, null); >> > } >> > >> > /** >> > >> > 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=1617051&r1=1617050&r2=1617051&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 >> Sun Aug 10 06:40:14 2014 >> > @@ -78,6 +78,7 @@ 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, >> > @@ -88,6 +89,7 @@ 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/MapMessage.java >> > URL: >> http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/MapMessage.java?rev=1617051&r1=1617050&r2=1617051&view=diff >> > >> ============================================================================== >> > --- >> logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/MapMessage.java >> (original) >> > +++ >> logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/MapMessage.java >> Sun Aug 10 06:40:14 2014 >> > @@ -26,6 +26,11 @@ import org.apache.logging.log4j.util.Str >> > >> > /** >> > * Represents a Message that consists of a Map. >> > + * <p> >> > + * Thread-safety note: the contents of this message can be modified >> after construction. >> > + * When using asynchronous loggers and appenders it is not recommended >> to modify this message after the message is >> > + * logged, because it is undefined whether the logged message string >> will contain the old values or the modified >> > + * values. >> > */ >> > public class MapMessage implements MultiformatMessage { >> > /** >> > >> > 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=1617051&r1=1617050&r2=1617051&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 >> Sun Aug 10 06:40:14 2014 >> > @@ -49,6 +49,7 @@ 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=1617051&r1=1617050&r2=1617051&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 >> Sun Aug 10 06:40:14 2014 >> > @@ -29,6 +29,7 @@ public class ObjectMessage implements Me >> > private static final long serialVersionUID = -5903272448334166185L; >> > >> > private transient Object obj; >> > + private final String objectString; >> > >> > /** >> > * Create the ObjectMessage. >> > @@ -39,6 +40,9 @@ public class ObjectMessage implements Me >> > obj = "null"; >> > } >> > this.obj = obj; >> > + >> > + // LOG4J2-763: take snapshot of parameters at message >> construction time >> > + objectString = String.valueOf(obj); >> > } >> > >> > /** >> > @@ -47,7 +51,7 @@ public class ObjectMessage implements Me >> > */ >> > @Override >> > public String getFormattedMessage() { >> > - return obj.toString(); >> > + return objectString; >> > } >> > >> > /** >> > @@ -56,7 +60,7 @@ public class ObjectMessage implements Me >> > */ >> > @Override >> > public String getFormat() { >> > - return obj.toString(); >> > + return objectString; >> > } >> > >> > /** >> > @@ -89,7 +93,7 @@ public class ObjectMessage implements Me >> > >> > @Override >> > public String toString() { >> > - return "ObjectMessage[obj=" + obj.toString() + ']'; >> > + return "ObjectMessage[obj=" + objectString + ']'; >> > } >> > >> > private void writeObject(final ObjectOutputStream out) throws >> IOException { >> > >> > 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=1617051&r1=1617050&r2=1617051&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 >> Sun Aug 10 06:40:14 2014 >> > @@ -48,6 +48,7 @@ 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/main/java/org/apache/logging/log4j/message/StructuredDataMessage.java >> > URL: >> http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/StructuredDataMessage.java?rev=1617051&r1=1617050&r2=1617051&view=diff >> > >> ============================================================================== >> > --- >> logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/StructuredDataMessage.java >> (original) >> > +++ >> logging/log4j/log4j2/trunk/log4j-api/src/main/java/org/apache/logging/log4j/message/StructuredDataMessage.java >> Sun Aug 10 06:40:14 2014 >> > @@ -22,6 +22,11 @@ import org.apache.logging.log4j.util.Eng >> > >> > /** >> > * Represents a Message that conforms to an RFC 5424 StructuredData >> element along with the syslog message. >> > + * <p> >> > + * Thread-safety note: the contents of this message can be modified >> after construction. >> > + * When using asynchronous loggers and appenders it is not recommended >> to modify this message after the message is >> > + * logged, because it is undefined whether the logged message string >> will contain the old values or the modified >> > + * values. >> > * >> > * @see <a href="https://tools.ietf.org/html/rfc5424";>RFC 5424</a> >> > */ >> > >> > 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=1617051&r1=1617050&r2=1617051&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 >> Sun Aug 10 06:40:14 2014 >> > @@ -83,4 +83,16 @@ public class FormattedMessageTest { >> > result = msg.getFormattedMessage(); >> > assertEquals(testMsg, result); >> > } >> > + >> > + @Test >> > + public void testSafeWithMutableParams() { // LOG4J2-763 >> > + final String testMsg = "Test message %s"; >> > + final Mutable param = new Mutable().set("abc"); >> > + FormattedMessage msg = new FormattedMessage(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); >> > + } >> > } >> > >> > 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=1617051&r1=1617050&r2=1617051&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 >> Sun Aug 10 06:40:14 2014 >> > @@ -64,4 +64,16 @@ public class LocalizedMessageTest { >> > assertEquals("This is test number 1 with string argument >> Test.", msg.getFormattedMessage()); >> > } >> > >> > + @Test >> > + public void testSafeWithMutableParams() { // LOG4J2-763 >> > + final String testMsg = "Test message %s"; >> > + final Mutable param = new Mutable().set("abc"); >> > + 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); >> > + } >> > + >> > } >> > >> > Modified: >> logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/MapMessageTest.java >> > URL: >> http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/MapMessageTest.java?rev=1617051&r1=1617050&r2=1617051&view=diff >> > >> ============================================================================== >> > --- >> logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/MapMessageTest.java >> (original) >> > +++ >> logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/MapMessageTest.java >> Sun Aug 10 06:40:14 2014 >> > @@ -70,4 +70,22 @@ public class MapMessageTest { >> > final String expected = "{message=\"Test message {}\", >> project=\"Log4j\"}"; >> > assertEquals(expected, result); >> > } >> > + >> > + @Test >> > + public void testMutableByDesign() { // LOG4J2-763 >> > + MapMessage msg = new MapMessage(); >> > + >> > + // modify parameter before calling msg.getFormattedMessage >> > + msg.put("key1", "value1"); >> > + msg.put("key2", "value2"); >> > + final String result = msg.getFormattedMessage(new >> String[]{"Java"}); >> > + final String expected = "{key1=\"value1\", key2=\"value2\"}"; >> > + assertEquals(expected, result); >> > + >> > + // modify parameter after calling msg.getFormattedMessage >> > + msg.put("key3", "value3"); >> > + final String result2 = msg.getFormattedMessage(new >> String[]{"Java"}); >> > + final String expected2 = "{key1=\"value1\", key2=\"value2\", >> key3=\"value3\"}"; >> > + assertEquals(expected2, result2); >> > + } >> > } >> > >> > 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=1617051&r1=1617050&r2=1617051&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 >> Sun Aug 10 06:40:14 2014 >> > @@ -61,4 +61,16 @@ public class MessageFormatMessageTest { >> > final Throwable t = msg.getThrowable(); >> > assertNotNull("No Throwable", t); >> > } >> > + >> > + @Test >> > + public void testSafeWithMutableParams() { // LOG4J2-763 >> > + final String testMsg = "Test message {0}"; >> > + final Mutable param = new Mutable().set("abc"); >> > + MessageFormatMessage msg = new MessageFormatMessage(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); >> > + } >> > } >> > >> > Added: >> logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/Mutable.java >> > URL: >> http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/Mutable.java?rev=1617051&view=auto >> > >> ============================================================================== >> > --- >> logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/Mutable.java >> (added) >> > +++ >> logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/Mutable.java >> Sun Aug 10 06:40:14 2014 >> > @@ -0,0 +1,34 @@ >> > +/* >> > + * 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; >> > + >> > +/** >> > + * Helper class for JUnit tests. >> > + */ >> > +class Mutable { >> > + private String value; >> > + >> > + public Mutable set(String value) { >> > + this.value = value; >> > + return this; >> > + } >> > + >> > + @Override >> > + public String toString() { >> > + return this.value; >> > + } >> > +} >> > \ No newline at end of file >> > >> > Propchange: >> logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/Mutable.java >> > >> ------------------------------------------------------------------------------ >> > svn:eol-style = native >> > >> > 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=1617051&r1=1617050&r2=1617051&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 >> Sun Aug 10 06:40:14 2014 >> > @@ -39,4 +39,15 @@ public class ObjectMessageTest { >> > final String result = msg.getFormattedMessage(); >> > assertEquals(testMsg, result); >> > } >> > + >> > + @Test >> > + public void testSafeWithMutableParams() { // LOG4J2-763 >> > + final Mutable param = new Mutable().set("abc"); >> > + ObjectMessage msg = new ObjectMessage(param); >> > + >> > + // modify parameter before calling msg.getFormattedMessage >> > + param.set("XYZ"); >> > + 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/ParameterizedMessageTest.java >> > URL: >> http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/ParameterizedMessageTest.java?rev=1617051&r1=1617050&r2=1617051&view=diff >> > >> ============================================================================== >> > --- >> logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/ParameterizedMessageTest.java >> (original) >> > +++ >> logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/ParameterizedMessageTest.java >> Sun Aug 10 06:40:14 2014 >> > @@ -36,4 +36,16 @@ public class ParameterizedMessageTest { >> > result = msg.getFormattedMessage(); >> > assertEquals(testMsg, result); >> > } >> > + >> > + @Test >> > + public void testSafeWithMutableParams() { // LOG4J2-763 >> > + final String testMsg = "Test message {}"; >> > + final Mutable param = new Mutable().set("abc"); >> > + ParameterizedMessage msg = new ParameterizedMessage(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); >> > + } >> > } >> > >> > 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=1617051&r1=1617050&r2=1617051&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 >> Sun Aug 10 06:40:14 2014 >> > @@ -60,4 +60,16 @@ public class StringFormattedMessageTest >> > final Throwable t = msg.getThrowable(); >> > assertNotNull("No Throwable", t); >> > } >> > + >> > + @Test >> > + public void testSafeWithMutableParams() { // LOG4J2-763 >> > + final String testMsg = "Test message %s"; >> > + final Mutable param = new Mutable().set("abc"); >> > + StringFormattedMessage msg = new >> StringFormattedMessage(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); >> > + } >> > } >> > >> > Modified: >> logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/StructuredDataMessageTest.java >> > URL: >> http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/StructuredDataMessageTest.java?rev=1617051&r1=1617050&r2=1617051&view=diff >> > >> ============================================================================== >> > --- >> logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/StructuredDataMessageTest.java >> (original) >> > +++ >> logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/StructuredDataMessageTest.java >> Sun Aug 10 06:40:14 2014 >> > @@ -43,4 +43,23 @@ public class StructuredDataMessageTest { >> > final StructuredDataMessage msg = new >> StructuredDataMessage("MsgId@12345", testMsg, "Alert"); >> > msg.put("This is a very long key that will violate the key >> length validation", "Testing"); >> > } >> > + >> > + @Test >> > + public void testMutableByDesign() { // LOG4J2-763 >> > + final String testMsg = "Test message {}"; >> > + StructuredDataMessage msg = new StructuredDataMessage("MsgId@1", >> testMsg, "Alert"); >> > + >> > + // modify parameter before calling msg.getFormattedMessage >> > + msg.put("message", testMsg); >> > + msg.put("project", "Log4j"); >> > + final String result = msg.getFormattedMessage(); >> > + final String expected = "Alert [MsgId@1 message=\"Test >> message {}\" project=\"Log4j\"] Test message {}"; >> > + assertEquals(expected, result); >> > + >> > + // modify parameter after calling msg.getFormattedMessage >> > + msg.put("memo", "Added later"); >> > + final String result2 = msg.getFormattedMessage(); >> > + final String expected2 = "Alert [MsgId@1 memo=\"Added later\" >> message=\"Test message {}\" project=\"Log4j\"] Test message {}"; >> > + assertEquals(expected2, result2); >> > + } >> > } >> > >> > Modified: >> logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/ThreadDumpMessageTest.java >> > URL: >> http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/ThreadDumpMessageTest.java?rev=1617051&r1=1617050&r2=1617051&view=diff >> > >> ============================================================================== >> > --- >> logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/ThreadDumpMessageTest.java >> (original) >> > +++ >> logging/log4j/log4j2/trunk/log4j-api/src/test/java/org/apache/logging/log4j/message/ThreadDumpMessageTest.java >> Sun Aug 10 06:40:14 2014 >> > @@ -73,6 +73,22 @@ public class ThreadDumpMessageTest { >> > assertEquals(expected, msg.toString()); >> > } >> > >> > + @Test >> > + public void testUseConstructorThread() throws InterruptedException >> { // LOG4J2-763 >> > + final ThreadDumpMessage msg = new ThreadDumpMessage("Test"); >> > + >> > + final String[] actual = new String[1]; >> > + Thread other = new Thread("OtherThread") { >> > + public void run() { >> > + actual[0] = msg.getFormattedMessage(); >> > + } >> > + }; >> > + other.start(); >> > + other.join(); >> > + >> > + assertTrue("No mention of other thread in msg", >> !actual[0].contains("OtherThread")); >> > + } >> > + >> > private class Thread1 extends Thread { >> > private final ReentrantLock lock; >> > >> > >> > Modified: logging/log4j/log4j2/trunk/src/changes/changes.xml >> > URL: >> http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/src/changes/changes.xml?rev=1617051&r1=1617050&r2=1617051&view=diff >> > >> ============================================================================== >> > --- logging/log4j/log4j2/trunk/src/changes/changes.xml (original) >> > +++ logging/log4j/log4j2/trunk/src/changes/changes.xml Sun Aug 10 >> 06:40:14 2014 >> > @@ -22,6 +22,12 @@ >> > </properties> >> > <body> >> > <release version="2.0.2" date="2014-0?-??" description="Bug fixes >> and enhancements"> >> > + <action issue="LOG4J2-763" dev="rpopma" type="fix"> >> > + Improved FormattedMessage, StringFormattedMessage, >> LocalizedMessage, MessageFormatMessage and >> > + ObjectMessage for asynchronous logging to ensure the formatted >> message does not change even if >> > + parameters are modified by the application. >> (ParameterizedMessage was already safe.) >> > + Improved documentation. >> > + </action> >> > <action issue="LOG4J2-729" dev="rpopma" type="fix"> >> > Emit warning message to console if no configuration file found. >> > </action> >> > >> > Modified: logging/log4j/log4j2/trunk/src/site/xdoc/manual/async.xml >> > URL: >> http://svn.apache.org/viewvc/logging/log4j/log4j2/trunk/src/site/xdoc/manual/async.xml?rev=1617051&r1=1617050&r2=1617051&view=diff >> > >> ============================================================================== >> > --- logging/log4j/log4j2/trunk/src/site/xdoc/manual/async.xml (original) >> > +++ logging/log4j/log4j2/trunk/src/site/xdoc/manual/async.xml Sun Aug >> 10 06:40:14 2014 >> > @@ -124,6 +124,26 @@ >> > logging in addition to synchronous >> > logging for the audit trail.) >> > </li> >> > + <li>In some rare cases, care must be taken with mutable messages. >> > + Most of the time you don't need to worry about this. Log4 will >> ensure that log messages like >> > + <code>logger.debug("My object is {}", myObject)</code> will use >> the state of the >> > + <code>myObject</code> parameter at the time of the call to >> <code>logger.debug()</code>. >> > + The log message will not change even if <code>myObject</code> is >> modified later. >> > + It is safe to asynchronously log mutable objects because most >> > + <a >> href="../log4j-api/apidocs/org/apache/logging/log4j/message/Message.html">Message</a> >> > + implementations built-in to Log4j take a snapshot of the >> parameters. >> > + There are some exceptions however: >> > + <a >> href="../log4j-api/apidocs/org/apache/logging/log4j/message/MapMessage.html">MapMessage</a> >> > + and >> > + <a >> href="../log4j-api/apidocs/org/apache/logging/log4j/message/StructuredDataMessage.html">StructuredDataMessage</a> >> > + are mutable by design: fields can be added to these messages after >> the message object was created. >> > + These messages should not be modified after they are logged with >> asynchronous loggers or >> > + asynchronous appenders; you may or may not see the modifications >> in the resulting log output. >> > + Similarly, custom >> > + <a >> href="../log4j-api/apidocs/org/apache/logging/log4j/message/Message.html">Message</a> >> > + implementations should be designed with asynchronous use in mind, >> and either take a snapshot >> > + of their parameters at construction time, or document their >> thread-safety characteristics. >> > + </li> >> > </ul> >> > </subsection> >> > <a name="AllAsync" /> >> > >> > >> >> --------------------------------------------------------------------- >> To unsubscribe, e-mail: [email protected] >> For additional commands, e-mail: [email protected] >> >> -- Matt Sicker <[email protected]>
