You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by gg...@apache.org on 2016/07/21 21:08:06 UTC
[10/50] [abbrv] logging-log4j2 git commit: LOG4J2-1452 Fixed issue
where reusable messages broke flow tracing logic.
LOG4J2-1452 Fixed issue where reusable messages broke flow tracing logic.
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/5b1c7366
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/5b1c7366
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/5b1c7366
Branch: refs/heads/AutoCloseableLock
Commit: 5b1c7366d345aa3e8a9941c5beb6e3ba509a08aa
Parents: 3d3a30c
Author: rpopma <rp...@apache.org>
Authored: Fri Jul 1 00:26:06 2016 +0900
Committer: rpopma <rp...@apache.org>
Committed: Fri Jul 1 00:26:06 2016 +0900
----------------------------------------------------------------------
.../java/org/apache/logging/log4j/Logger.java | 9 +-
.../message/DefaultFlowMessageFactory.java | 15 +-
.../logging/log4j/spi/AbstractLogger.java | 8 +-
.../apache/logging/log4j/TraceLoggingTest.java | 317 +++++++++++++++++++
.../ReusableParameterizedMessageTest.java | 6 +
src/changes/changes.xml | 3 +
6 files changed, 350 insertions(+), 8 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/5b1c7366/log4j-api/src/main/java/org/apache/logging/log4j/Logger.java
----------------------------------------------------------------------
diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/Logger.java b/log4j-api/src/main/java/org/apache/logging/log4j/Logger.java
index f59d7dd..030c0a6 100644
--- a/log4j-api/src/main/java/org/apache/logging/log4j/Logger.java
+++ b/log4j-api/src/main/java/org/apache/logging/log4j/Logger.java
@@ -3640,11 +3640,18 @@ public interface Logger {
* // do something
* }
* </pre>
+ * <p>
+ * Avoid passing a {@code ReusableMessage} to this method (therefore, also avoid passing messages created by
+ * calling {@code logger.getMessageFactory().newMessage("some message")}): Log4j will replace such messages with
+ * an immutable message to prevent situations where the reused message instance is modified by subsequent calls to
+ * the logger before the returned {@code EntryMessage} is fully processed.
+ * </p>
*
- * @param message The message.
+ * @param message The message. Avoid specifying a ReusableMessage, use immutable messages instead.
* @return the built message
*
* @since 2.6
+ * @see org.apache.logging.log4j.message.ReusableMessage
*/
EntryMessage traceEntry(Message message);
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/5b1c7366/log4j-api/src/main/java/org/apache/logging/log4j/message/DefaultFlowMessageFactory.java
----------------------------------------------------------------------
diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/message/DefaultFlowMessageFactory.java b/log4j-api/src/main/java/org/apache/logging/log4j/message/DefaultFlowMessageFactory.java
index 2ca193c..5babca3 100644
--- a/log4j-api/src/main/java/org/apache/logging/log4j/message/DefaultFlowMessageFactory.java
+++ b/log4j-api/src/main/java/org/apache/logging/log4j/message/DefaultFlowMessageFactory.java
@@ -20,15 +20,15 @@ import java.io.Serializable;
/**
* Default factory for flow messages.
- *
+ *
* @since 2.6
*/
public class DefaultFlowMessageFactory implements FlowMessageFactory, Serializable {
-
+
private static final String EXIT_DEFAULT_PREFIX = "Exit";
private static final String ENTRY_DEFAULT_PREFIX = "Enter";
private static final long serialVersionUID = 8578655591131397576L;
-
+
private final String entryText;
private final String exitText;
@@ -172,7 +172,14 @@ public class DefaultFlowMessageFactory implements FlowMessageFactory, Serializab
*/
@Override
public EntryMessage newEntryMessage(final Message message) {
- return new SimpleEntryMessage(entryText, message);
+ return new SimpleEntryMessage(entryText, makeImmutable(message));
+ }
+
+ private Message makeImmutable(final Message message) {
+ if (!(message instanceof ReusableMessage)) {
+ return message;
+ }
+ return new SimpleMessage(message.getFormattedMessage());
}
/*
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/5b1c7366/log4j-api/src/main/java/org/apache/logging/log4j/spi/AbstractLogger.java
----------------------------------------------------------------------
diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/spi/AbstractLogger.java b/log4j-api/src/main/java/org/apache/logging/log4j/spi/AbstractLogger.java
index e47b68d..475e93f 100644
--- a/log4j-api/src/main/java/org/apache/logging/log4j/spi/AbstractLogger.java
+++ b/log4j-api/src/main/java/org/apache/logging/log4j/spi/AbstractLogger.java
@@ -27,8 +27,10 @@ import org.apache.logging.log4j.message.FlowMessageFactory;
import org.apache.logging.log4j.message.Message;
import org.apache.logging.log4j.message.MessageFactory;
import org.apache.logging.log4j.message.MessageFactory2;
+import org.apache.logging.log4j.message.ParameterizedMessage;
import org.apache.logging.log4j.message.ParameterizedMessageFactory;
import org.apache.logging.log4j.message.ReusableMessageFactory;
+import org.apache.logging.log4j.message.SimpleMessage;
import org.apache.logging.log4j.message.StringFormattedMessage;
import org.apache.logging.log4j.status.StatusLogger;
import org.apache.logging.log4j.util.Constants;
@@ -601,10 +603,10 @@ public abstract class AbstractLogger implements ExtendedLogger, Serializable {
if (Strings.isEmpty(format)) {
return flowMessageFactory.newEntryMessage(null);
}
- return flowMessageFactory.newEntryMessage(messageFactory.newMessage(format));
+ return flowMessageFactory.newEntryMessage(new SimpleMessage(format));
}
if (format != null) {
- return flowMessageFactory.newEntryMessage(messageFactory.newMessage(format, params));
+ return flowMessageFactory.newEntryMessage(new ParameterizedMessage(format, params));
}
final StringBuilder sb = new StringBuilder();
sb.append("params(");
@@ -616,7 +618,7 @@ public abstract class AbstractLogger implements ExtendedLogger, Serializable {
sb.append(parm instanceof Message ? ((Message) parm).getFormattedMessage() : String.valueOf(parm));
}
sb.append(')');
- return flowMessageFactory.newEntryMessage(messageFactory.newMessage(sb.toString()));
+ return flowMessageFactory.newEntryMessage(new SimpleMessage(sb));
}
protected EntryMessage entryMsg(final String format, final MessageSupplier... paramSuppliers) {
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/5b1c7366/log4j-api/src/test/java/org/apache/logging/log4j/TraceLoggingTest.java
----------------------------------------------------------------------
diff --git a/log4j-api/src/test/java/org/apache/logging/log4j/TraceLoggingTest.java b/log4j-api/src/test/java/org/apache/logging/log4j/TraceLoggingTest.java
new file mode 100644
index 0000000..693a174
--- /dev/null
+++ b/log4j-api/src/test/java/org/apache/logging/log4j/TraceLoggingTest.java
@@ -0,0 +1,317 @@
+/*
+ * 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;
+
+import org.apache.logging.log4j.message.DefaultFlowMessageFactory;
+import org.apache.logging.log4j.message.EntryMessage;
+import org.apache.logging.log4j.message.FlowMessageFactory;
+import org.apache.logging.log4j.message.Message;
+import org.apache.logging.log4j.message.ObjectMessage;
+import org.apache.logging.log4j.message.ParameterizedMessage;
+import org.apache.logging.log4j.message.ReusableParameterizedMessage;
+import org.apache.logging.log4j.message.ReusableParameterizedMessageTest;
+import org.apache.logging.log4j.message.ReusableSimpleMessage;
+import org.apache.logging.log4j.message.SimpleMessage;
+import org.apache.logging.log4j.spi.AbstractLogger;
+import org.junit.Test;
+
+import static org.junit.Assert.*;
+
+/**
+ *
+ */
+public class TraceLoggingTest extends AbstractLogger {
+ static final StringBuilder CHAR_SEQ = new StringBuilder("CharSeq");
+ private int charSeqCount;
+ private int objectCount;
+
+ private static class LogEvent {
+
+ String markerName;
+ Message data;
+ Throwable t;
+
+ public LogEvent(final String markerName, final Message data, final Throwable t) {
+ this.markerName = markerName;
+ this.data = data;
+ this.t = t;
+ }
+ }
+
+ private static final long serialVersionUID = 1L;
+
+ private static Level currentLevel;
+
+ private LogEvent currentEvent;
+
+ private static Throwable t = new UnsupportedOperationException("Test");
+
+ private static Class<AbstractLogger> obj = AbstractLogger.class;
+ private static String pattern = "{}, {}";
+ private static String p1 = "Long Beach";
+
+ private static String p2 = "California";
+ private static Message charSeq = new SimpleMessage(CHAR_SEQ);
+ private static Message simple = new SimpleMessage("Hello");
+ private static Message object = new ObjectMessage(obj);
+
+ private static Message param = new ParameterizedMessage(pattern, p1, p2);
+
+ private static String marker = "TEST";
+
+ @Override
+ public Level getLevel() {
+ return currentLevel;
+ }
+
+ @Override
+ public boolean isEnabled(final Level level, final Marker marker, final Message data, final Throwable t) {
+ return true;
+// assertTrue("Incorrect Level. Expected " + currentLevel + ", actual " + level, level.equals(currentLevel));
+// if (marker == null) {
+// if (currentEvent.markerName != null) {
+// fail("Incorrect marker. Expected " + currentEvent.markerName + ", actual is null");
+// }
+// } else {
+// if (currentEvent.markerName == null) {
+// fail("Incorrect marker. Expected null. Actual is " + marker.getName());
+// } else {
+// assertTrue("Incorrect marker. Expected " + currentEvent.markerName + ", actual " +
+// marker.getName(), currentEvent.markerName.equals(marker.getName()));
+// }
+// }
+// if (data == null) {
+// if (currentEvent.data != null) {
+// fail("Incorrect message. Expected " + currentEvent.data + ", actual is null");
+// }
+// } else {
+// if (currentEvent.data == null) {
+// fail("Incorrect message. Expected null. Actual is " + data.getFormattedMessage());
+// } else {
+// assertTrue("Incorrect message type. Expected " + currentEvent.data + ", actual " + data,
+// data.getClass().isAssignableFrom(currentEvent.data.getClass()));
+// assertTrue("Incorrect message. Expected " + currentEvent.data.getFormattedMessage() + ", actual " +
+// data.getFormattedMessage(),
+// currentEvent.data.getFormattedMessage().equals(data.getFormattedMessage()));
+// }
+// }
+// if (t == null) {
+// if (currentEvent.t != null) {
+// fail("Incorrect Throwable. Expected " + currentEvent.t + ", actual is null");
+// }
+// } else {
+// if (currentEvent.t == null) {
+// fail("Incorrect Throwable. Expected null. Actual is " + t);
+// } else {
+// assertTrue("Incorrect Throwable. Expected " + currentEvent.t + ", actual " + t,
+// currentEvent.t.equals(t));
+// }
+// }
+// return true;
+ }
+
+ @Override
+ public boolean isEnabled(final Level level, final Marker marker, final CharSequence data, final Throwable t) {
+ charSeqCount++;
+ return isEnabled(level, marker, (Message) new SimpleMessage(data), t);
+ }
+
+ @Override
+ public boolean isEnabled(final Level level, final Marker marker, final Object data, final Throwable t) {
+ objectCount++;
+ return isEnabled(level, marker, new ObjectMessage(data), t);
+ }
+
+ @Override
+ public boolean isEnabled(final Level level, final Marker marker, final String data) {
+ return isEnabled(level, marker, (Message) new SimpleMessage(data), null);
+ }
+
+ @Override
+ public boolean isEnabled(final Level level, final Marker marker, final String data, final Object... p1) {
+ return isEnabled(level, marker, new ParameterizedMessage(data, p1), null);
+ }
+
+ @Override
+ public boolean isEnabled(final Level level, final Marker marker, final String message, final Object p0) {
+ return isEnabled(level, marker, new ParameterizedMessage(message, p0), null);
+ }
+
+ @Override
+ public boolean isEnabled(final Level level, final Marker marker, final String message, final Object p0,
+ final Object p1) {
+ return isEnabled(level, marker, new ParameterizedMessage(message, p0, p1), null);
+ }
+
+ @Override
+ public boolean isEnabled(final Level level, final Marker marker, final String message, final Object p0,
+ final Object p1, final Object p2) {
+ return isEnabled(level, marker, new ParameterizedMessage(message, p0, p1, p2), null);
+ }
+
+ @Override
+ public boolean isEnabled(final Level level, final Marker marker, final String message, final Object p0,
+ final Object p1, final Object p2, final Object p3) {
+ return isEnabled(level, marker, new ParameterizedMessage(message, p0, p1, p2, p3), null);
+ }
+
+ @Override
+ public boolean isEnabled(final Level level, final Marker marker, final String message, final Object p0,
+ final Object p1, final Object p2, final Object p3,
+ final Object p4) {
+ return isEnabled(level, marker, new ParameterizedMessage(message, p0, p1, p2, p3, p4), null);
+ }
+
+ @Override
+ public boolean isEnabled(final Level level, final Marker marker, final String message, final Object p0,
+ final Object p1, final Object p2, final Object p3,
+ final Object p4, final Object p5) {
+ return isEnabled(level, marker, new ParameterizedMessage(message, p0, p1, p2, p3, p4, p5), null);
+ }
+
+ @Override
+ public boolean isEnabled(final Level level, final Marker marker, final String message, final Object p0,
+ final Object p1, final Object p2, final Object p3,
+ final Object p4, final Object p5, final Object p6) {
+ return isEnabled(level, marker, new ParameterizedMessage(message, p0, p1, p2, p3, p4, p5, p6), null);
+ }
+
+ @Override
+ public boolean isEnabled(final Level level, final Marker marker, final String message, final Object p0,
+ final Object p1, final Object p2, final Object p3,
+ final Object p4, final Object p5, final Object p6,
+ final Object p7) {
+ return isEnabled(level, marker, new ParameterizedMessage(message, p0, p1, p2, p3, p4, p5, p6, p7), null);
+ }
+
+ @Override
+ public boolean isEnabled(final Level level, final Marker marker, final String message, final Object p0,
+ final Object p1, final Object p2, final Object p3,
+ final Object p4, final Object p5, final Object p6,
+ final Object p7, final Object p8) {
+ return isEnabled(level, marker, new ParameterizedMessage(message, p0, p1, p2, p3, p4, p5, p6, p7, p8), null);
+ }
+
+ @Override
+ public boolean isEnabled(final Level level, final Marker marker, final String message, final Object p0,
+ final Object p1, final Object p2, final Object p3,
+ final Object p4, final Object p5, final Object p6,
+ final Object p7, final Object p8, final Object p9) {
+ return isEnabled(level, marker, new ParameterizedMessage(message, p0, p1, p2, p3, p4, p5, p6, p7, p8, p9),
+ null);
+ }
+
+ @Override
+ public boolean isEnabled(final Level level, final Marker marker, final String data, final Throwable t) {
+ return isEnabled(level, marker, (Message) new SimpleMessage(data), t);
+ }
+
+ @Override
+ public void logMessage(final String fqcn, final Level level, final Marker marker, final Message data, final Throwable t) {
+ assertTrue("Incorrect Level. Expected " + currentLevel + ", actual " + level, level.equals(currentLevel));
+ if (marker == null) {
+ if (currentEvent.markerName != null) {
+ fail("Incorrect marker. Expected " + currentEvent.markerName + ", actual is null");
+ }
+ } else {
+ if (currentEvent.markerName == null) {
+ fail("Incorrect marker. Expected null. Actual is " + marker.getName());
+ } else {
+ assertTrue("Incorrect marker. Expected " + currentEvent.markerName + ", actual " +
+ marker.getName(), currentEvent.markerName.equals(marker.getName()));
+ }
+ }
+ if (data == null) {
+ if (currentEvent.data != null) {
+ fail("Incorrect message. Expected " + currentEvent.data + ", actual is null");
+ }
+ } else {
+ if (currentEvent.data == null) {
+ fail("Incorrect message. Expected null. Actual is " + data.getFormattedMessage());
+ } else {
+ assertTrue("Incorrect message type. Expected " + currentEvent.data + ", actual " + data,
+ data.getClass().isAssignableFrom(currentEvent.data.getClass()));
+ assertTrue("Incorrect message. Expected " + currentEvent.data.getFormattedMessage() + ", actual " +
+ data.getFormattedMessage(),
+ currentEvent.data.getFormattedMessage().equals(data.getFormattedMessage()));
+ }
+ }
+ if (t == null) {
+ if (currentEvent.t != null) {
+ fail("Incorrect Throwable. Expected " + currentEvent.t + ", actual is null");
+ }
+ } else {
+ if (currentEvent.t == null) {
+ fail("Incorrect Throwable. Expected null. Actual is " + t);
+ } else {
+ assertTrue("Incorrect Throwable. Expected " + currentEvent.t + ", actual " + t,
+ currentEvent.t.equals(t));
+ }
+ }
+ }
+
+ @Test
+ public void testTraceEntryExit() {
+ currentLevel = Level.TRACE;
+ FlowMessageFactory fact = new DefaultFlowMessageFactory();
+
+ ParameterizedMessage paramMsg = new ParameterizedMessage("Tracy {}", "Logan");
+ currentEvent = new LogEvent(ENTRY_MARKER.getName(), fact.newEntryMessage(paramMsg), null);
+ EntryMessage entry = traceEntry("Tracy {}", "Logan");
+
+ ReusableParameterizedMessage msg = ReusableParameterizedMessageTest.set(
+ new ReusableParameterizedMessage(), "Tracy {}", "Logan");
+ ReusableParameterizedMessageTest.set(msg, "Some other message {}", 123);
+ currentEvent = new LogEvent(null, msg, null);
+ trace("Some other message {}", 123);
+
+ // ensure original entry message not overwritten
+ assertEquals("Tracy Logan", entry.getMessage().getFormattedMessage());
+
+ currentEvent = new LogEvent(EXIT_MARKER.getName(), fact.newExitMessage(entry), null);
+ traceExit(entry);
+
+ // ensure original entry message not overwritten
+ assertEquals("Tracy Logan", entry.getMessage().getFormattedMessage());
+ }
+
+ @Test
+ public void testTraceEntryMessage() {
+ currentLevel = Level.TRACE;
+ FlowMessageFactory fact = new DefaultFlowMessageFactory();
+
+ ParameterizedMessage paramMsg = new ParameterizedMessage("Tracy {}", "Logan");
+ currentEvent = new LogEvent(ENTRY_MARKER.getName(), fact.newEntryMessage(paramMsg), null);
+
+ ReusableParameterizedMessage msg = ReusableParameterizedMessageTest.set(
+ new ReusableParameterizedMessage(), "Tracy {}", "Logan");
+ EntryMessage entry = traceEntry(msg);
+
+ ReusableParameterizedMessageTest.set(msg, "Some other message {}", 123);
+ currentEvent = new LogEvent(null, msg, null);
+ trace("Some other message {}", 123);
+
+ // ensure original entry message not overwritten
+ assertEquals("Tracy Logan", entry.getMessage().getFormattedMessage());
+
+ currentEvent = new LogEvent(EXIT_MARKER.getName(), fact.newExitMessage(entry), null);
+ traceExit(entry);
+
+ // ensure original entry message not overwritten
+ assertEquals("Tracy Logan", entry.getMessage().getFormattedMessage());
+ }
+}
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/5b1c7366/log4j-api/src/test/java/org/apache/logging/log4j/message/ReusableParameterizedMessageTest.java
----------------------------------------------------------------------
diff --git a/log4j-api/src/test/java/org/apache/logging/log4j/message/ReusableParameterizedMessageTest.java b/log4j-api/src/test/java/org/apache/logging/log4j/message/ReusableParameterizedMessageTest.java
index 4b6182b..9f1cdff 100644
--- a/log4j-api/src/test/java/org/apache/logging/log4j/message/ReusableParameterizedMessageTest.java
+++ b/log4j-api/src/test/java/org/apache/logging/log4j/message/ReusableParameterizedMessageTest.java
@@ -26,6 +26,12 @@ import static org.junit.Assert.*;
*/
public class ReusableParameterizedMessageTest {
+ public static ReusableParameterizedMessage set(final ReusableParameterizedMessage msg, final String format,
+ final Object... params) {
+
+ return msg.set(format, params);
+ }
+
@Test
public void testNoArgs() {
final String testMsg = "Test message {}";
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/5b1c7366/src/changes/changes.xml
----------------------------------------------------------------------
diff --git a/src/changes/changes.xml b/src/changes/changes.xml
index eec3ed6..0615354 100644
--- a/src/changes/changes.xml
+++ b/src/changes/changes.xml
@@ -24,6 +24,9 @@
</properties>
<body>
<release version="2.6.2" date="2016-MM-DD" description="GA Release 2.6.2">
+ <action issue="LOG4J2-1452" dev="rpopma" due-to="Mikael St�ldal">
+ Fixed issue where reusable messages broke flow tracing logic.
+ </action>
<action issue="LOG4J2-1440" dev="rgoers">
Fix bug in OnStartupTriggeringPolicy that allowed it to roll over on every reconfiguration. Added
minSize attribute.