You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by rp...@apache.org on 2016/11/20 14:37:28 UTC
logging-log4j2 git commit: LOG4J2-1718 Introduce marker interface
AsynchronouslyFormattable;
clarified how Message::getFormattedMessage should be implemented to be safely
used with asynchronous logging
Repository: logging-log4j2
Updated Branches:
refs/heads/master 01049ed4e -> b47e49688
LOG4J2-1718 Introduce marker interface AsynchronouslyFormattable; clarified how Message::getFormattedMessage should be implemented to be safely used with asynchronous logging
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/b47e4968
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/b47e4968
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/b47e4968
Branch: refs/heads/master
Commit: b47e496883a14b86f12f1120ea2430fc45e28957
Parents: 01049ed
Author: rpopma <rp...@apache.org>
Authored: Sun Nov 20 23:37:07 2016 +0900
Committer: rpopma <rp...@apache.org>
Committed: Sun Nov 20 23:37:07 2016 +0900
----------------------------------------------------------------------
.../message/AsynchronouslyFormattable.java | 51 ++++++++++++++++++++
.../apache/logging/log4j/message/Message.java | 10 +++-
.../log4j/core/appender/AsyncAppender.java | 9 +++-
.../logging/log4j/core/async/AsyncLogger.java | 8 ++-
.../log4j/core/async/RingBufferLogEvent.java | 8 ++-
.../log4j/core/impl/MutableLogEvent.java | 8 ++-
src/changes/changes.xml | 3 ++
7 files changed, 92 insertions(+), 5 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/b47e4968/log4j-api/src/main/java/org/apache/logging/log4j/message/AsynchronouslyFormattable.java
----------------------------------------------------------------------
diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/message/AsynchronouslyFormattable.java b/log4j-api/src/main/java/org/apache/logging/log4j/message/AsynchronouslyFormattable.java
new file mode 100644
index 0000000..dfe865a
--- /dev/null
+++ b/log4j-api/src/main/java/org/apache/logging/log4j/message/AsynchronouslyFormattable.java
@@ -0,0 +1,51 @@
+/*
+ * 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;
+
+/**
+ * Marker interface that signals to asynchronous logging components that messages of this type can safely be passed to
+ * a background thread without calling {@link Message#getFormattedMessage()} first.
+ * <p>
+ * Generally, logging mutable objects asynchronously always has the risk that the object is modified between the time
+ * the logger is called and the time the log message is formatted and written to disk. Strictly speaking it is the
+ * responsibility of the application to ensure that mutable objects are not modified after they have been logged,
+ * but this is not always possible.
+ * </p><p>
+ * Log4j prevents the above race condition as follows:
+ * </p><ol>
+ * <li>If the Message implements {@link ReusableMessage}, asynchronous logging components in the Log4j implementation
+ * will copy the message content (formatted message, parameters) onto the queue rather than passing the
+ * {@code Message} instance itself. This ensures that the formatted message will not change
+ * when the mutable object is modified.
+ * </li>
+ * <li>If the Message implements {@link AsynchronouslyFormattable}, it can be passed to another thread as is.</li>
+ * <li>Otherwise, asynchronous logging components in the Log4j implementation will call
+ * {@link Message#getFormattedMessage()} before passing the Message object to another thread.
+ * This gives the Message implementation class a chance to create a formatted message String with the current value
+ * of the mutable object. The intention is that the Message implementation caches this formatted message and returns
+ * it on subsequent calls.
+ * (See <a href="https://issues.apache.org/jira/browse/LOG4J2-763">LOG4J2-763</a>.)
+ * </li>
+ * </ol>
+ *
+ * @see Message
+ * @see ReusableMessage
+ * @see <a href="https://issues.apache.org/jira/browse/LOG4J2-763">LOG4J2-763</a>
+ * @since 2.8
+ */
+public interface AsynchronouslyFormattable {
+}
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/b47e4968/log4j-api/src/main/java/org/apache/logging/log4j/message/Message.java
----------------------------------------------------------------------
diff --git a/log4j-api/src/main/java/org/apache/logging/log4j/message/Message.java b/log4j-api/src/main/java/org/apache/logging/log4j/message/Message.java
index 2c5e8fa..be9f33d 100644
--- a/log4j-api/src/main/java/org/apache/logging/log4j/message/Message.java
+++ b/log4j-api/src/main/java/org/apache/logging/log4j/message/Message.java
@@ -50,7 +50,15 @@ public interface Message extends Serializable {
* appropriate way to format the data encapsulated in the Message. Messages that provide
* more than one way of formatting the Message will implement MultiformatMessage.
* <p>
- * This method will not be called for Messages that implement the
+ * When configured to log asynchronously, this method is called before the Message is queued, unless this
+ * message implements either {@link ReusableMessage} or {@link AsynchronouslyFormattable}.
+ * This gives the Message implementation class a chance to create a formatted message String with the current value
+ * of any mutable objects.
+ * The intention is that the Message implementation caches this formatted message and returns it on subsequent
+ * calls. (See <a href="https://issues.apache.org/jira/browse/LOG4J2-763">LOG4J2-763</a>.)
+ * </p>
+ * <p>
+ * When logging synchronously, this method will not be called for Messages that implement the
* {@link StringBuilderFormattable} interface: instead, the
* {@link StringBuilderFormattable#formatTo(StringBuilder) formatTo(StringBuilder)} method will be called so the
* Message can format its contents without creating intermediate String objects.
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/b47e4968/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppender.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppender.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppender.java
index f0f5c0e..1c56ade 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppender.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/AsyncAppender.java
@@ -49,6 +49,8 @@ import org.apache.logging.log4j.core.config.plugins.validation.constraints.Requi
import org.apache.logging.log4j.core.impl.Log4jLogEvent;
import org.apache.logging.log4j.core.util.Constants;
import org.apache.logging.log4j.core.util.Log4jThread;
+import org.apache.logging.log4j.message.AsynchronouslyFormattable;
+import org.apache.logging.log4j.message.Message;
/**
* Appends to one or more Appenders asynchronously. You can configure an AsyncAppender with one or more Appenders and an
@@ -154,7 +156,7 @@ public final class AsyncAppender extends AbstractAppender {
if (!isStarted()) {
throw new IllegalStateException("AsyncAppender " + getName() + " is not active");
}
- if (!Constants.FORMAT_MESSAGES_IN_BACKGROUND) { // LOG4J2-898: user may choose
+ if (!canFormatMessageInBackground(logEvent.getMessage())) {
logEvent.getMessage().getFormattedMessage(); // LOG4J2-763: ask message to freeze parameters
}
final Log4jLogEvent memento = Log4jLogEvent.createMemento(logEvent, includeLocation);
@@ -170,6 +172,11 @@ public final class AsyncAppender extends AbstractAppender {
}
}
+ private boolean canFormatMessageInBackground(final Message message) {
+ return Constants.FORMAT_MESSAGES_IN_BACKGROUND // LOG4J2-898: user wants to format all msgs in background
+ || message instanceof AsynchronouslyFormattable; // LOG4J2-1718
+ }
+
private boolean transfer(final LogEvent memento) {
return queue instanceof TransferQueue
? ((TransferQueue<LogEvent>) queue).tryTransfer(memento)
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/b47e4968/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLogger.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLogger.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLogger.java
index 45fa666..12aa5a8 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLogger.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLogger.java
@@ -35,6 +35,7 @@ import org.apache.logging.log4j.core.util.Clock;
import org.apache.logging.log4j.core.util.ClockFactory;
import org.apache.logging.log4j.core.util.Constants;
import org.apache.logging.log4j.core.util.NanoClock;
+import org.apache.logging.log4j.message.AsynchronouslyFormattable;
import org.apache.logging.log4j.message.Message;
import org.apache.logging.log4j.message.MessageFactory;
import org.apache.logging.log4j.message.ReusableMessage;
@@ -243,7 +244,7 @@ public class AsyncLogger extends Logger implements EventTranslatorVararg<RingBuf
return;
}
// if the Message instance is reused, there is no point in freezing its message here
- if (!Constants.FORMAT_MESSAGES_IN_BACKGROUND && !isReused(message)) { // LOG4J2-898: user may choose
+ if (!canFormatMessageInBackground(message) && !isReused(message)) {
message.getFormattedMessage(); // LOG4J2-763: ask message to freeze parameters
}
// calls the translateTo method on this AsyncLogger
@@ -251,6 +252,11 @@ public class AsyncLogger extends Logger implements EventTranslatorVararg<RingBuf
thrown);
}
+ private boolean canFormatMessageInBackground(final Message message) {
+ return Constants.FORMAT_MESSAGES_IN_BACKGROUND // LOG4J2-898: user wants to format all msgs in background
+ || message instanceof AsynchronouslyFormattable; // LOG4J2-1718
+ }
+
/*
* (non-Javadoc)
*
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/b47e4968/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEvent.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEvent.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEvent.java
index 48f89b3..ff4c5cc 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEvent.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEvent.java
@@ -23,6 +23,7 @@ import java.util.Map;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.Marker;
import org.apache.logging.log4j.ThreadContext.ContextStack;
+import org.apache.logging.log4j.message.AsynchronouslyFormattable;
import org.apache.logging.log4j.util.ReadOnlyStringMap;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.impl.ContextDataFactory;
@@ -123,13 +124,18 @@ public class RingBufferLogEvent implements LogEvent, ReusableMessage, CharSequen
}
} else {
// if the Message instance is reused, there is no point in freezing its message here
- if (!Constants.FORMAT_MESSAGES_IN_BACKGROUND && msg != null) { // LOG4J2-898: user may choose
+ if (!canFormatMessageInBackground(msg) && msg != null) {
msg.getFormattedMessage(); // LOG4J2-763: ask message to freeze parameters
}
this.message = msg;
}
}
+ private boolean canFormatMessageInBackground(final Message message) {
+ return Constants.FORMAT_MESSAGES_IN_BACKGROUND // LOG4J2-898: user wants to format all msgs in background
+ || message instanceof AsynchronouslyFormattable; // LOG4J2-1718
+ }
+
private StringBuilder getMessageTextForWriting() {
if (messageText == null) {
// Should never happen:
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/b47e4968/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/MutableLogEvent.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/MutableLogEvent.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/MutableLogEvent.java
index ad970ae..4184eca 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/MutableLogEvent.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/MutableLogEvent.java
@@ -24,6 +24,7 @@ import java.util.Map;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.Marker;
import org.apache.logging.log4j.ThreadContext;
+import org.apache.logging.log4j.message.AsynchronouslyFormattable;
import org.apache.logging.log4j.util.ReadOnlyStringMap;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.util.Constants;
@@ -214,13 +215,18 @@ public class MutableLogEvent implements LogEvent, ReusableMessage {
}
} else {
// if the Message instance is reused, there is no point in freezing its message here
- if (!Constants.FORMAT_MESSAGES_IN_BACKGROUND && msg != null) { // LOG4J2-898: user may choose
+ if (!canFormatMessageInBackground(msg) && msg != null) {
msg.getFormattedMessage(); // LOG4J2-763: ask message to freeze parameters
}
this.message = msg;
}
}
+ private boolean canFormatMessageInBackground(final Message message) {
+ return Constants.FORMAT_MESSAGES_IN_BACKGROUND // LOG4J2-898: user wants to format all msgs in background
+ || message instanceof AsynchronouslyFormattable; // LOG4J2-1718
+ }
+
private StringBuilder getMessageTextForWriting() {
if (messageText == null) {
// Should never happen:
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/b47e4968/src/changes/changes.xml
----------------------------------------------------------------------
diff --git a/src/changes/changes.xml b/src/changes/changes.xml
index 2ca53f9..2ea1e92 100644
--- a/src/changes/changes.xml
+++ b/src/changes/changes.xml
@@ -150,6 +150,9 @@
<action issue="LOG4J2-1379" dev="mattsicker" type="add">
Add documentation regarding YAML configuration format.
</action>
+ <action issue="LOG4J2-1718" dev="rpopma" type="add">
+ Introduce marker interface AsynchronouslyFormattable.
+ </action>
<action issue="LOG4J2-1681" dev="rpopma" type="add">
Introduce interfaces IndexedStringMap and IndexedReadOnlyStringMap, supporting garbage-free iteration over sorted map.
</action>