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 <rpo...@apache.org> Authored: Sun Nov 20 23:37:07 2016 +0900 Committer: rpopma <rpo...@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>