This is an automated email from the ASF dual-hosted git repository. pkarwasz pushed a commit to branch fix/lazy-location in repository https://gitbox.apache.org/repos/asf/logging-log4j2.git
commit b5316062553abbac04aa4f128dda05321ff6d3f8 Author: Piotr P. Karwasz <[email protected]> AuthorDate: Thu Feb 29 13:19:12 2024 +0100 Make location and formatted message more lazy We move the computation of location and message formatting to the last method call executed before a message leaves the current thread. --- .../org/apache/log4j/bridge/LogEventWrapper.java | 8 +- .../logging/log4j/async/logger/AsyncLogger.java | 91 ++------------- .../log4j/async/logger/AsyncLoggerConfig.java | 6 - .../async/logger/AsyncLoggerConfigDisruptor.java | 75 ++++++------- .../log4j/async/logger/RingBufferLogEvent.java | 6 + .../async/logger/RingBufferLogEventTranslator.java | 87 +++++++-------- .../log4j/core/impl/MutableLogEventTest.java | 6 +- .../logging/log4j/core/AbstractLogEvent.java | 6 + .../org/apache/logging/log4j/core/LogEvent.java | 25 +++-- .../java/org/apache/logging/log4j/core/Logger.java | 1 - .../logging/log4j/core/appender/AsyncAppender.java | 6 +- .../core/appender/rewrite/RewriteAppender.java | 3 +- .../log4j/core/async/InternalAsyncUtil.java | 34 ++++++ .../logging/log4j/core/impl/Log4jLogEvent.java | 23 ++-- .../logging/log4j/core/impl/MementoLogEvent.java | 79 +++++-------- .../logging/log4j/core/impl/MutableLogEvent.java | 44 ++++---- .../logging/log4j/flume/appender/FlumeEvent.java | 6 + .../logging/log4j/kit/logger/AbstractLogger.java | 122 +++++++++------------ .../log4j/kit/logger/AbstractLoggerTest.java | 14 +-- 19 files changed, 294 insertions(+), 348 deletions(-) diff --git a/log4j-1.2-api/src/main/java/org/apache/log4j/bridge/LogEventWrapper.java b/log4j-1.2-api/src/main/java/org/apache/log4j/bridge/LogEventWrapper.java index 5e1266008e..b02ae30934 100644 --- a/log4j-1.2-api/src/main/java/org/apache/log4j/bridge/LogEventWrapper.java +++ b/log4j-1.2-api/src/main/java/org/apache/log4j/bridge/LogEventWrapper.java @@ -37,6 +37,7 @@ import org.apache.logging.log4j.spi.MutableThreadContextStack; import org.apache.logging.log4j.util.BiConsumer; import org.apache.logging.log4j.util.ReadOnlyStringMap; import org.apache.logging.log4j.util.TriConsumer; +import org.jspecify.annotations.Nullable; /** * Exposes a Log4j 1 logging event as a Log4j 2 LogEvent. @@ -109,12 +110,17 @@ public class LogEventWrapper implements LogEvent { } @Override - public StackTraceElement getSource() { + public @Nullable StackTraceElement peekSource() { final LocationInfo info = event.getLocationInformation(); return new StackTraceElement( info.getClassName(), info.getMethodName(), info.getFileName(), Integer.parseInt(info.getLineNumber())); } + @Override + public StackTraceElement getSource() { + return peekSource(); + } + @Override public String getThreadName() { return event.getThreadName(); diff --git a/log4j-async-logger/src/main/java/org/apache/logging/log4j/async/logger/AsyncLogger.java b/log4j-async-logger/src/main/java/org/apache/logging/log4j/async/logger/AsyncLogger.java index 29259e4e2c..7143a5b7b7 100644 --- a/log4j-async-logger/src/main/java/org/apache/logging/log4j/async/logger/AsyncLogger.java +++ b/log4j-async-logger/src/main/java/org/apache/logging/log4j/async/logger/AsyncLogger.java @@ -39,7 +39,6 @@ import org.apache.logging.log4j.message.Message; import org.apache.logging.log4j.message.MessageFactory; import org.apache.logging.log4j.spi.recycler.Recycler; import org.apache.logging.log4j.spi.recycler.RecyclerFactory; -import org.apache.logging.log4j.util.StackLocatorUtil; import org.apache.logging.log4j.util.StringMap; import org.jspecify.annotations.NullMarked; import org.jspecify.annotations.Nullable; @@ -124,33 +123,6 @@ public class AsyncLogger extends Logger { return nanoClock; } - /** - * Enqueues the specified log event data for logging in a background thread. - * <p> - * This re-uses a {@code RingBufferLogEventTranslator} instance cached in a {@code ThreadLocal} to avoid creating - * unnecessary objects with each event. - * - * @param fqcn fully qualified name of the caller - * @param level level at which the caller wants to log the message - * @param marker message marker - * @param message the log message - * @param thrown a {@code Throwable} or {@code null} - */ - @Override - public void logMessage( - final String fqcn, final Level level, final Marker marker, final Message message, final Throwable thrown) { - // Implementation note: this method is tuned for performance. MODIFY WITH CARE! - - final RingBufferLogEventTranslator translator = translatorRecycler.acquire(); - try { - initTranslator(translator, fqcn, level, marker, message, thrown); - translator.updateThreadValues(); - publish(translator); - } finally { - translatorRecycler.release(translator); - } - } - /** * Enqueues the specified log event data for logging in a background thread. * <p> @@ -170,7 +142,7 @@ public class AsyncLogger extends Logger { final @Nullable StackTraceElement location, final Level level, final @Nullable Marker marker, - final Message message, + final @Nullable Message message, final @Nullable Throwable throwable) { // Implementation note: this method is tuned for performance. MODIFY WITH CARE! @@ -220,11 +192,11 @@ public class AsyncLogger extends Logger { private void initTranslator( final RingBufferLogEventTranslator translator, final String fqcn, - final StackTraceElement location, + final @Nullable StackTraceElement location, final Level level, - final Marker marker, - final Message message, - final Throwable thrown) { + final @Nullable Marker marker, + final @Nullable Message message, + final @Nullable Throwable thrown) { translator.setBasicValues( this, @@ -232,57 +204,16 @@ public class AsyncLogger extends Logger { marker, fqcn, level, - message, // + message, // don't construct ThrowableProxy until required thrown, - // needs shallow copy to be fast (LOG4J2-154) - ThreadContext.getImmutableStack(), // + ThreadContext.getImmutableStack(), location, - clock, // - nanoClock, // - contextDataInjector); - } - - private void initTranslator( - final RingBufferLogEventTranslator translator, - final String fqcn, - final Level level, - final Marker marker, - final Message message, - final Throwable thrown) { - - translator.setBasicValues( - this, - getName(), - marker, - fqcn, - level, - message, // - // don't construct ThrowableProxy until required - thrown, - - // needs shallow copy to be fast (LOG4J2-154) - ThreadContext.getImmutableStack(), // - - // location (expensive to calculate) - calcLocationIfRequested(fqcn), // - clock, // - nanoClock, // - contextDataInjector); - } - - /** - * Returns the caller location if requested, {@code null} otherwise. - * - * @param fqcn fully qualified caller name. - * @return the caller location if requested, {@code null} otherwise. - */ - private StackTraceElement calcLocationIfRequested(final String fqcn) { - // location: very expensive operation. LOG4J2-153: - // Only include if "includeLocation=true" is specified, - // exclude if not specified or if "false" was specified. - return includeLocation ? StackLocatorUtil.calcLocation(fqcn) : null; + clock, + nanoClock, + contextDataInjector, + requiresLocation()); } /** diff --git a/log4j-async-logger/src/main/java/org/apache/logging/log4j/async/logger/AsyncLoggerConfig.java b/log4j-async-logger/src/main/java/org/apache/logging/log4j/async/logger/AsyncLoggerConfig.java index da022e4749..b8591342bb 100644 --- a/log4j-async-logger/src/main/java/org/apache/logging/log4j/async/logger/AsyncLoggerConfig.java +++ b/log4j-async-logger/src/main/java/org/apache/logging/log4j/async/logger/AsyncLoggerConfig.java @@ -165,7 +165,6 @@ public class AsyncLoggerConfig extends LoggerConfig { private void logToAsyncDelegate(final LogEvent event) { // Passes on the event to a separate thread that will call // asyncCallAppenders(LogEvent). - populateLazilyInitializedFields(event); if (!delegate.tryEnqueue(event, this)) { handleQueueFull(event); } @@ -193,11 +192,6 @@ public class AsyncLoggerConfig extends LoggerConfig { } } - private void populateLazilyInitializedFields(final LogEvent event) { - event.getSource(); - event.getThreadName(); - } - void logInBackgroundThread(final LogEvent event) { delegate.enqueueEvent(event, this); } diff --git a/log4j-async-logger/src/main/java/org/apache/logging/log4j/async/logger/AsyncLoggerConfigDisruptor.java b/log4j-async-logger/src/main/java/org/apache/logging/log4j/async/logger/AsyncLoggerConfigDisruptor.java index b132e6ae84..a17aa97760 100644 --- a/log4j-async-logger/src/main/java/org/apache/logging/log4j/async/logger/AsyncLoggerConfigDisruptor.java +++ b/log4j-async-logger/src/main/java/org/apache/logging/log4j/async/logger/AsyncLoggerConfigDisruptor.java @@ -16,6 +16,8 @@ */ package org.apache.logging.log4j.async.logger; +import static org.apache.logging.log4j.core.async.InternalAsyncUtil.makeMessageImmutable; + import com.lmax.disruptor.EventFactory; import com.lmax.disruptor.EventHandler; import com.lmax.disruptor.EventTranslatorTwoArg; @@ -39,7 +41,6 @@ import org.apache.logging.log4j.core.async.AsyncQueueFullPolicyFactory; import org.apache.logging.log4j.core.async.DiscardingAsyncQueueFullPolicy; import org.apache.logging.log4j.core.async.EventRoute; import org.apache.logging.log4j.core.async.InternalAsyncUtil; -import org.apache.logging.log4j.core.impl.Log4jLogEvent; import org.apache.logging.log4j.core.impl.Log4jPropertyKey; import org.apache.logging.log4j.core.impl.LogEventFactory; import org.apache.logging.log4j.core.impl.MutableLogEvent; @@ -84,8 +85,8 @@ public class AsyncLoggerConfigDisruptor extends AbstractLifeCycle implements Asy */ public void clear() { loggerConfig = null; - if (event instanceof ReusableLogEvent) { - ((ReusableLogEvent) event).clear(); + if (event instanceof ReusableLogEvent reusable) { + reusable.clear(); } else { event = null; } @@ -149,7 +150,7 @@ public class AsyncLoggerConfigDisruptor extends AbstractLifeCycle implements Asy */ private static final EventTranslatorTwoArg<Log4jEventWrapper, LogEvent, AsyncLoggerConfig> TRANSLATOR = (ringBufferElement, sequence, logEvent, loggerConfig) -> { - ringBufferElement.event = logEvent; + ringBufferElement.event = coerceToImmutableEvent(loggerConfig, logEvent); ringBufferElement.loggerConfig = loggerConfig; }; @@ -158,7 +159,9 @@ public class AsyncLoggerConfigDisruptor extends AbstractLifeCycle implements Asy */ private static final EventTranslatorTwoArg<Log4jEventWrapper, LogEvent, AsyncLoggerConfig> MUTABLE_TRANSLATOR = (ringBufferElement, sequence, logEvent, loggerConfig) -> { - ((MutableLogEvent) ringBufferElement.event).initFrom(logEvent); + initLazyFields(loggerConfig, logEvent); + makeMessageImmutable(logEvent.getMessage()); + ((MutableLogEvent) ringBufferElement.event).moveValuesFrom(logEvent); ringBufferElement.loggerConfig = loggerConfig; }; @@ -168,7 +171,7 @@ public class AsyncLoggerConfigDisruptor extends AbstractLifeCycle implements Asy private volatile Disruptor<Log4jEventWrapper> disruptor; private long backgroundThreadId; // LOG4J2-471 private EventTranslatorTwoArg<Log4jEventWrapper, LogEvent, AsyncLoggerConfig> translator; - private volatile boolean alreadyLoggedWarning; + private static volatile boolean alreadyLoggedWarning; private final AsyncWaitStrategyFactory asyncWaitStrategyFactory; private WaitStrategy waitStrategy; @@ -333,8 +336,7 @@ public class AsyncLoggerConfigDisruptor extends AbstractLifeCycle implements Asy public void enqueueEvent(final LogEvent event, final AsyncLoggerConfig asyncLoggerConfig) { // LOG4J2-639: catch NPE if disruptor field was set to null after our check above try { - final LogEvent logEvent = prepareEvent(event); - enqueue(logEvent, asyncLoggerConfig); + enqueue(event, asyncLoggerConfig); } catch (final NullPointerException npe) { // Note: NPE prevents us from adding a log event to the disruptor after it was shut down, // which could cause the publishEvent method to hang and never return. @@ -347,30 +349,36 @@ public class AsyncLoggerConfigDisruptor extends AbstractLifeCycle implements Asy } } - private LogEvent prepareEvent(final LogEvent event) { - LogEvent logEvent = ensureImmutable(event); + /** + * Makes the event immutable. + * <p> + * Note: the original event may be modified in any po + * </p> + * @param event A possibly mutable event. + * @return An immutable event. + */ + private static LogEvent coerceToImmutableEvent(final AsyncLoggerConfig loggerConfig, final LogEvent event) { + initLazyFields(loggerConfig, event); + final LogEvent logEvent = event.toImmutable(); if (logEvent.getMessage() instanceof ReusableMessage) { - if (logEvent instanceof Log4jLogEvent) { - ((Log4jLogEvent) logEvent).makeMessageImmutable(); - } else if (logEvent instanceof MutableLogEvent) { - // MutableLogEvents need to be translated into the RingBuffer by the MUTABLE_TRANSLATOR. - // That translator calls MutableLogEvent.initFrom to copy the event, which will makeMessageImmutable the - // message. - if (translator != MUTABLE_TRANSLATOR) { // should not happen... - // TRANSLATOR expects an immutable LogEvent - logEvent = logEvent.toImmutable(); - } - } else { // custom log event, with a ReusableMessage - showWarningAboutCustomLogEventWithReusableMessage(logEvent); - } + showWarningAboutCustomLogEventWithReusableMessage(logEvent); } else { // message is not a ReusableMessage; makeMessageImmutable it to prevent // ConcurrentModificationExceptions - InternalAsyncUtil.makeMessageImmutable(logEvent.getMessage()); // LOG4J2-1988, LOG4J2-1914 + makeMessageImmutable(logEvent.getMessage()); // LOG4J2-1988, LOG4J2-1914 } return logEvent; } - private void showWarningAboutCustomLogEventWithReusableMessage(final LogEvent logEvent) { + private static void initLazyFields(final AsyncLoggerConfig loggerConfig, final LogEvent event) { + // TODO: make thread info eager + event.getThreadId(); + event.getThreadName(); + event.getThreadPriority(); + // Compute location + InternalAsyncUtil.makeLocationImmutable(loggerConfig, event); + } + + private static void showWarningAboutCustomLogEventWithReusableMessage(final LogEvent logEvent) { if (!alreadyLoggedWarning) { LOGGER.warn( "Custom log event of type {} contains a mutable message of type {}." @@ -410,22 +418,7 @@ public class AsyncLoggerConfigDisruptor extends AbstractLifeCycle implements Asy @Override public boolean tryEnqueue(final LogEvent event, final AsyncLoggerConfig asyncLoggerConfig) { - final LogEvent logEvent = prepareEvent(event); - return disruptor.getRingBuffer().tryPublishEvent(translator, logEvent, asyncLoggerConfig); - } - - private LogEvent ensureImmutable(final LogEvent event) { - LogEvent result = event; - if (event instanceof RingBufferLogEvent) { - // Deal with special case where both types of Async Loggers are used together: - // RingBufferLogEvents are created by the all-loggers-async type, but - // this event is also consumed by the some-loggers-async type (this class). - // The original event will be re-used and modified in an application thread later, - // so take a snapshot of it, which can be safely processed in the - // some-loggers-async background thread. - result = event.toMemento(); - } - return result; + return disruptor.getRingBuffer().tryPublishEvent(translator, event, asyncLoggerConfig); } // package-protected for tests diff --git a/log4j-async-logger/src/main/java/org/apache/logging/log4j/async/logger/RingBufferLogEvent.java b/log4j-async-logger/src/main/java/org/apache/logging/log4j/async/logger/RingBufferLogEvent.java index 4c4b6da4c2..c3a512a6c2 100644 --- a/log4j-async-logger/src/main/java/org/apache/logging/log4j/async/logger/RingBufferLogEvent.java +++ b/log4j-async-logger/src/main/java/org/apache/logging/log4j/async/logger/RingBufferLogEvent.java @@ -42,6 +42,7 @@ import org.apache.logging.log4j.message.TimestampMessage; import org.apache.logging.log4j.util.StringBuilders; import org.apache.logging.log4j.util.StringMap; import org.apache.logging.log4j.util.Strings; +import org.jspecify.annotations.Nullable; /** * When the Disruptor is started, the RingBuffer is populated with event objects. These objects are then re-used during @@ -430,6 +431,11 @@ public class RingBufferLogEvent implements ReusableLogEvent, ReusableMessage, Ch @Override public StackTraceElement getSource() { + return peekSource(); + } + + @Override + public @Nullable StackTraceElement peekSource() { return location; } diff --git a/log4j-async-logger/src/main/java/org/apache/logging/log4j/async/logger/RingBufferLogEventTranslator.java b/log4j-async-logger/src/main/java/org/apache/logging/log4j/async/logger/RingBufferLogEventTranslator.java index 96948902be..f4ad99fb63 100644 --- a/log4j-async-logger/src/main/java/org/apache/logging/log4j/async/logger/RingBufferLogEventTranslator.java +++ b/log4j-async-logger/src/main/java/org/apache/logging/log4j/async/logger/RingBufferLogEventTranslator.java @@ -24,7 +24,10 @@ import org.apache.logging.log4j.core.ContextDataInjector; import org.apache.logging.log4j.core.time.Clock; import org.apache.logging.log4j.core.time.NanoClock; import org.apache.logging.log4j.message.Message; +import org.apache.logging.log4j.util.StackLocatorUtil; import org.apache.logging.log4j.util.StringMap; +import org.jspecify.annotations.NullMarked; +import org.jspecify.annotations.Nullable; /** * This class is responsible for writing elements that make up a log event into @@ -32,29 +35,33 @@ import org.apache.logging.log4j.util.StringMap; * the ringbuffer event, the disruptor will update the sequence number so that * the event can be consumed by another thread. */ +@NullMarked public class RingBufferLogEventTranslator implements EventTranslator<RingBufferLogEvent> { private ContextDataInjector contextDataInjector; private AsyncLogger asyncLogger; String loggerName; - protected Marker marker; - protected String fqcn; + protected @Nullable Marker marker; protected Level level; - protected Message message; - protected Throwable thrown; + protected @Nullable Message message; + protected @Nullable Throwable thrown; private ContextStack contextStack; private long threadId = Thread.currentThread().getId(); private String threadName = Thread.currentThread().getName(); private int threadPriority = Thread.currentThread().getPriority(); - private StackTraceElement location; private Clock clock; private NanoClock nanoClock; + // Location data + protected String fqcn; + private @Nullable StackTraceElement location; + private boolean requiresLocation; - // @Override + // Called right before relinquishing control from the thread. @Override public void translateTo(final RingBufferLogEvent event, final long sequence) { try { final StringMap contextData = event.getContextData(); + // Compute location if necessary event.setValues( asyncLogger, loggerName, @@ -70,7 +77,8 @@ public class RingBufferLogEventTranslator implements EventTranslator<RingBufferL threadId, threadName, threadPriority, - location, + // compute location if necessary + requiresLocation ? StackLocatorUtil.calcLocation(fqcn) : location, clock, nanoClock); } finally { @@ -82,47 +90,36 @@ public class RingBufferLogEventTranslator implements EventTranslator<RingBufferL * Release references held by this object to allow objects to be garbage-collected. */ void clear() { - setBasicValues( - null, // asyncLogger - null, // loggerName - null, // marker - null, // fqcn - null, // level - null, // data - null, // t - null, // contextStack - null, // location - null, // clock - null, // nanoClock - null // contextDataInjector - ); + setBasicValues(null, null, null, null, null, null, null, null, null, null, null, null, false); } public void setBasicValues( - final AsyncLogger anAsyncLogger, - final String aLoggerName, - final Marker aMarker, - final String theFqcn, - final Level aLevel, - final Message msg, - final Throwable aThrowable, - final ContextStack aContextStack, - final StackTraceElement aLocation, - final Clock aClock, - final NanoClock aNanoClock, - final ContextDataInjector aContextDataInjector) { - this.asyncLogger = anAsyncLogger; - this.loggerName = aLoggerName; - this.marker = aMarker; - this.fqcn = theFqcn; - this.level = aLevel; - this.message = msg; - this.thrown = aThrowable; - this.contextStack = aContextStack; - this.location = aLocation; - this.clock = aClock; - this.nanoClock = aNanoClock; - this.contextDataInjector = aContextDataInjector; + final AsyncLogger asyncLogger, + final String loggerName, + final @Nullable Marker marker, + final String fqcn, + final Level level, + final @Nullable Message message, + final @Nullable Throwable throwable, + final ContextStack contextStack, + final @Nullable StackTraceElement location, + final Clock clock, + final NanoClock nanoClock, + final ContextDataInjector contextDataInjector, + final boolean includeLocation) { + this.asyncLogger = asyncLogger; + this.loggerName = loggerName; + this.marker = marker; + this.fqcn = fqcn; + this.level = level; + this.message = message; + this.thrown = throwable; + this.contextStack = contextStack; + this.location = location; + this.clock = clock; + this.nanoClock = nanoClock; + this.contextDataInjector = contextDataInjector; + this.requiresLocation = location == null && includeLocation; } public void updateThreadValues() { diff --git a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/impl/MutableLogEventTest.java b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/impl/MutableLogEventTest.java index 99f0ed408f..09da9ecf2d 100644 --- a/log4j-core-test/src/test/java/org/apache/logging/log4j/core/impl/MutableLogEventTest.java +++ b/log4j-core-test/src/test/java/org/apache/logging/log4j/core/impl/MutableLogEventTest.java @@ -96,7 +96,7 @@ public class MutableLogEventTest { .setTimeMillis(987654321) .build(); final MutableLogEvent mutable = new MutableLogEvent(); - mutable.initFrom(source); + mutable.moveValuesFrom(source); assertEquals(CONTEXT_DATA, mutable.getContextData(), "contextMap"); assertEquals(STACK, mutable.getContextStack(), "stack"); assertTrue(mutable.isEndOfBatch(), "endOfBatch"); @@ -138,7 +138,7 @@ public class MutableLogEventTest { .setTimeMillis(987654321) .build(); final MutableLogEvent mutable = new MutableLogEvent(); - mutable.initFrom(source); + mutable.moveValuesFrom(source); assertEquals("msg in a {}", mutable.getFormat(), "format"); assertEquals("msg in a bottle", mutable.getFormattedMessage(), "formatted"); assertArrayEquals(new String[] {"bottle"}, mutable.getParameters(), "parameters"); @@ -182,7 +182,7 @@ public class MutableLogEventTest { .setTimeMillis(987654321) .build(); final MutableLogEvent mutable = new MutableLogEvent(); - mutable.initFrom(source); + mutable.moveValuesFrom(source); assertNull(mutable.getFormat(), "format"); assertEquals(param.toString(), mutable.getFormattedMessage(), "formatted"); assertArrayEquals(new Object[] {param}, mutable.getParameters(), "parameters"); diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/AbstractLogEvent.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/AbstractLogEvent.java index 80730912e7..30f8c6358c 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/AbstractLogEvent.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/AbstractLogEvent.java @@ -25,6 +25,7 @@ import org.apache.logging.log4j.core.time.Instant; import org.apache.logging.log4j.core.time.MutableInstant; import org.apache.logging.log4j.message.Message; import org.apache.logging.log4j.util.ReadOnlyStringMap; +import org.jspecify.annotations.Nullable; /** * An abstract log event implementation with default values for all methods. The setters are no-ops. @@ -81,6 +82,11 @@ public abstract class AbstractLogEvent implements LogEvent { return null; } + @Override + public @Nullable StackTraceElement peekSource() { + return null; + } + @Override public long getThreadId() { return 0; diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/LogEvent.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/LogEvent.java index c6a2559646..b679494cd6 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/LogEvent.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/LogEvent.java @@ -24,6 +24,7 @@ import org.apache.logging.log4j.core.impl.ThrowableProxy; import org.apache.logging.log4j.core.time.Instant; import org.apache.logging.log4j.message.Message; import org.apache.logging.log4j.util.ReadOnlyStringMap; +import org.jspecify.annotations.Nullable; /** * Provides contextual information about a logged message. Besides containing a @@ -48,18 +49,14 @@ public interface LogEvent { /** * Returns a copy of this log event. + * <p> + * Location information for both events might be computed by this method. + * </p> */ default LogEvent toMemento() { return new MementoLogEvent(this); } - /** - * Returns a copy of this log event and overrides the {@code includeLocation} option. - */ - default LogEvent toMemento(final boolean includeLocation) { - return new MementoLogEvent(this, includeLocation); - } - /** * Returns the {@code ReadOnlyStringMap} object holding context data key-value pairs. * <p> @@ -141,12 +138,22 @@ public interface LogEvent { Instant getInstant(); /** - * Gets the source of logging request. + * Gets the source of the logging call or computes it. * - * @return source of logging request, may be null. + * @return source of logging request, may be {@code null} if {@link #isIncludeLocation()} is {@code false}. + * @implNote The implementation must be idempotent: multiple calls to this method must always return the same value. */ StackTraceElement getSource(); + /** + * Gets the source of the logging call. + * + * @return source of logging request or {@code null} if currently unknown. + * @implNote This method must be side effect free. + */ + @Nullable + StackTraceElement peekSource(); + /** * Gets the thread name. * diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/Logger.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/Logger.java index ccbc4a1284..ab87808b5a 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/Logger.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/Logger.java @@ -140,7 +140,6 @@ public class Logger extends AbstractLogger implements Supplier<LoggerConfig> { return privateConfig.loggerConfig; } - @Override protected boolean requiresLocation() { return privateConfig.requiresLocation; } 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 5b15a9073a..9b43ffc421 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 @@ -162,8 +162,12 @@ public final class AsyncAppender extends AbstractAppender { if (!isStarted()) { throw new IllegalStateException("AsyncAppender " + getName() + " is not active"); } - final LogEvent memento = logEvent.toMemento(includeLocation); + // Modifications to the original `logEvent`: + // 1. Format message, if it is not thread-safe. InternalAsyncUtil.makeMessageImmutable(logEvent.getMessage()); + // 2. Compute location, unless disabled. + InternalAsyncUtil.makeLocationImmutable(this, logEvent); + final LogEvent memento = logEvent.toMemento(); if (!transfer(memento)) { if (blocking) { if (AbstractLogger.getRecursionDepth() > 1) { // LOG4J2-1518, LOG4J2-2031 diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rewrite/RewriteAppender.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rewrite/RewriteAppender.java index 367d686109..a8a0823687 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rewrite/RewriteAppender.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/appender/rewrite/RewriteAppender.java @@ -117,8 +117,7 @@ public final class RewriteAppender extends AbstractAppender { @Override public boolean requiresLocation() { for (final AppenderControl control : appenders.values()) { - final Appender appender = control.getAppender(); - if (appender.requiresLocation()) { + if (control.getAppender().requiresLocation()) { return true; } } diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/InternalAsyncUtil.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/InternalAsyncUtil.java index 8cff3d79d0..795424bd93 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/InternalAsyncUtil.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/InternalAsyncUtil.java @@ -16,9 +16,14 @@ */ package org.apache.logging.log4j.core.async; +import org.apache.logging.log4j.core.LogEvent; +import org.apache.logging.log4j.core.appender.AsyncAppender; +import org.apache.logging.log4j.core.config.LoggerConfig; import org.apache.logging.log4j.core.util.Constants; import org.apache.logging.log4j.message.AsynchronouslyFormattable; import org.apache.logging.log4j.message.Message; +import org.apache.logging.log4j.util.StackLocatorUtil; +import org.jspecify.annotations.Nullable; /** * Helper class providing some async logging-related functionality. @@ -50,4 +55,33 @@ public final class InternalAsyncUtil { return Constants.FORMAT_MESSAGES_IN_BACKGROUND // LOG4J2-898: user wants to format all msgs in background || message.getClass().isAnnotationPresent(AsynchronouslyFormattable.class); // LOG4J2-1718 } + + public static void makeLocationImmutable(final AsyncAppender appender, final LogEvent event) { + makeLocationImmutable(appender.isIncludeLocation(), event); + } + + public static void makeLocationImmutable(final LoggerConfig loggerConfig, final LogEvent event) { + makeLocationImmutable(loggerConfig.isIncludeLocation(), event); + } + + private static void makeLocationImmutable(final boolean includeLocation, final LogEvent event) { + if (includeLocation) { + event.getSource(); + } else { + event.setIncludeLocation(includeLocation); + } + } + + /** + * Computes the location of the logging call + * + * @param fqcn The fully qualified class name of the logger entry point, used to determine the caller class. + * @param location The location of the logging call or {@code null} if unknown. + * @param requiresLocation If {@code true}, forces the computation of the location. + * @return The location of the logging call. + */ + public static @Nullable StackTraceElement getLocation( + final String fqcn, final @Nullable StackTraceElement location, final boolean requiresLocation) { + return location != null ? location : requiresLocation ? StackLocatorUtil.calcLocation(fqcn) : null; + } } diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/Log4jLogEvent.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/Log4jLogEvent.java index 88188b3bb2..0b59f4f950 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/Log4jLogEvent.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/Log4jLogEvent.java @@ -36,13 +36,13 @@ import org.apache.logging.log4j.util.ReadOnlyStringMap; import org.apache.logging.log4j.util.StackLocatorUtil; import org.apache.logging.log4j.util.StringMap; import org.apache.logging.log4j.util.Strings; +import org.jspecify.annotations.Nullable; /** * Implementation of a LogEvent. */ public class Log4jLogEvent implements LogEvent { - private final String loggerFqcn; private final Marker marker; private final Level level; private final String loggerName; @@ -55,11 +55,13 @@ public class Log4jLogEvent implements LogEvent { private long threadId; private String threadName; private int threadPriority; - private StackTraceElement source; - private boolean includeLocation; private boolean endOfBatch = false; /** @since Log4J 2.4 */ private final long nanoTime; + // Location data + private final String loggerFqcn; + private @Nullable StackTraceElement source; + private boolean includeLocation; /** LogEvent Builder helper class. */ public static class Builder implements org.apache.logging.log4j.plugins.util.Builder<LogEvent> { @@ -327,7 +329,7 @@ public class Log4jLogEvent implements LogEvent { final long threadId, final String threadName, final int threadPriority, - final StackTraceElement source, + final @Nullable StackTraceElement source, final long timestampMillis, final int nanoOfMillisecond, final long nanoTime) { @@ -510,13 +512,14 @@ public class Log4jLogEvent implements LogEvent { */ @Override public StackTraceElement getSource() { - if (source != null) { - return source; + if (source == null && loggerFqcn != null) { + source = includeLocation ? StackLocatorUtil.calcLocation(loggerFqcn) : null; } - if (loggerFqcn == null || !includeLocation) { - return null; - } - source = StackLocatorUtil.calcLocation(loggerFqcn); + return peekSource(); + } + + @Override + public @Nullable StackTraceElement peekSource() { return source; } diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/MementoLogEvent.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/MementoLogEvent.java index feb45ec6fc..b70fdb23a6 100644 --- a/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/MementoLogEvent.java +++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/impl/MementoLogEvent.java @@ -19,7 +19,7 @@ package org.apache.logging.log4j.core.impl; import java.util.Objects; import org.apache.logging.log4j.Level; import org.apache.logging.log4j.Marker; -import org.apache.logging.log4j.ThreadContext; +import org.apache.logging.log4j.ThreadContext.ContextStack; import org.apache.logging.log4j.core.LogEvent; import org.apache.logging.log4j.core.config.LoggerConfig; import org.apache.logging.log4j.core.time.Instant; @@ -32,6 +32,7 @@ import org.apache.logging.log4j.util.InternalApi; import org.apache.logging.log4j.util.ReadOnlyStringMap; import org.apache.logging.log4j.util.StringMap; import org.apache.logging.log4j.util.Strings; +import org.jspecify.annotations.Nullable; /** * Immutable copy of a LogEvent. @@ -50,8 +51,8 @@ public class MementoLogEvent implements LogEvent { private boolean endOfBatch; private final Message message; private final ReadOnlyStringMap contextData; - private final ThreadContext.ContextStack contextStack; - private final StackTraceElement source; + private final ContextStack contextStack; + private final @Nullable StackTraceElement source; private final String threadName; private final long threadId; private final int threadPriority; @@ -72,9 +73,9 @@ public class MementoLogEvent implements LogEvent { if (instant.getEpochMillisecond() == 0 && message instanceof TimestampMessage) { instant.initFromEpochMilli(((TimestampMessage) message).getTimestamp(), 0); } - contextData = memento(event.getContextData()); + contextData = mementoOfContextData(event.getContextData()); contextStack = event.getContextStack(); - source = includeLocation ? event.getSource() : null; + source = includeLocation ? event.getSource() : event.peekSource(); threadName = event.getThreadName(); threadId = event.getThreadId(); threadPriority = event.getThreadPriority(); @@ -82,40 +83,27 @@ public class MementoLogEvent implements LogEvent { thrownProxy = event.getThrownProxy(); } - public MementoLogEvent(final LogEvent event, final boolean includeLocation) { - loggerFqcn = event.getLoggerFqcn(); - loggerName = event.getLoggerName(); - instant.initFrom(event.getInstant()); - nanoTime = event.getNanoTime(); - level = event.getLevel(); - marker = event.getMarker(); - locationRequired = includeLocation; - endOfBatch = event.isEndOfBatch(); - message = mementoOfMessage(event); - if (instant.getEpochMillisecond() == 0 && message instanceof TimestampMessage) { - instant.initFromEpochMilli(((TimestampMessage) message).getTimestamp(), 0); + private static ReadOnlyStringMap mementoOfContextData(final ReadOnlyStringMap readOnlyMap) { + if (readOnlyMap instanceof final StringMap stringMap && !stringMap.isFrozen()) { + final StringMap data = ContextDataFactory.createContextData(readOnlyMap); + data.freeze(); + return data; } - contextData = memento(event.getContextData()); - contextStack = event.getContextStack(); - source = includeLocation ? event.getSource() : null; - threadName = event.getThreadName(); - threadId = event.getThreadId(); - threadPriority = event.getThreadPriority(); - thrown = event.getThrown(); - thrownProxy = event.getThrownProxy(); + // otherwise immutable + return readOnlyMap; } - @Override - public LogEvent toImmutable() { - return this; + private static Message mementoOfMessage(final LogEvent event) { + final Message message = event.getMessage(); + if (message instanceof LoggerNameAwareMessage) { + ((LoggerNameAwareMessage) message).setLoggerName(event.getLoggerName()); + } + return message instanceof final ReusableMessage reusable ? reusable.memento() : message; } @Override - public LogEvent toMemento(final boolean includeLocation) { - if (locationRequired || !includeLocation) { - return this; - } - return LogEvent.super.toMemento(true); + public LogEvent toImmutable() { + return this; } @Override @@ -129,7 +117,7 @@ public class MementoLogEvent implements LogEvent { } @Override - public ThreadContext.ContextStack getContextStack() { + public ContextStack getContextStack() { return contextStack; } @@ -170,6 +158,11 @@ public class MementoLogEvent implements LogEvent { @Override public StackTraceElement getSource() { + return peekSource(); + } + + @Override + public @Nullable StackTraceElement peekSource() { return source; } @@ -275,22 +268,4 @@ public class MementoLogEvent implements LogEvent { return "Logger=" + n + " Level=" + level.name() + " Message=" + (message == null ? Strings.EMPTY : message.getFormattedMessage()); } - - private static ReadOnlyStringMap memento(final ReadOnlyStringMap readOnlyMap) { - if (readOnlyMap instanceof StringMap && !((StringMap) readOnlyMap).isFrozen()) { - final StringMap data = ContextDataFactory.createContextData(readOnlyMap); - data.freeze(); - return data; - } - // otherwise immutable - return readOnlyMap; - } - - private static Message mementoOfMessage(final LogEvent event) { - final Message message = event.getMessage(); - if (message instanceof LoggerNameAwareMessage) { - ((LoggerNameAwareMessage) message).setLoggerName(event.getLoggerName()); - } - return message instanceof ReusableMessage ? ((ReusableMessage) message).memento() : message; - } } 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 44e442eb52..fa1f47d5a3 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 @@ -22,7 +22,6 @@ import org.apache.logging.log4j.Marker; import org.apache.logging.log4j.ThreadContext; import org.apache.logging.log4j.core.LogEvent; import org.apache.logging.log4j.core.ReusableLogEvent; -import org.apache.logging.log4j.core.async.InternalAsyncUtil; import org.apache.logging.log4j.core.time.Clock; import org.apache.logging.log4j.core.time.Instant; import org.apache.logging.log4j.core.time.MutableInstant; @@ -39,6 +38,7 @@ import org.apache.logging.log4j.util.StackLocatorUtil; import org.apache.logging.log4j.util.StringBuilders; import org.apache.logging.log4j.util.StringMap; import org.apache.logging.log4j.util.Strings; +import org.jspecify.annotations.Nullable; /** * Mutable implementation of the {@code ReusableLogEvent} interface. @@ -53,7 +53,6 @@ public class MutableLogEvent implements ReusableLogEvent, ReusableMessage, Param private final MutableInstant instant = new MutableInstant(); private long nanoTime; private short parameterCount; - private boolean includeLocation; private boolean endOfBatch = false; private Level level; private String threadName; @@ -66,9 +65,11 @@ public class MutableLogEvent implements ReusableLogEvent, ReusableMessage, Param private ThrowableProxy thrownProxy; private StringMap contextData = ContextDataFactory.createContextData(); private Marker marker; - private String loggerFqcn; - private StackTraceElement source; private ThreadContext.ContextStack contextStack; + // Location information + private String loggerFqcn; + private @Nullable StackTraceElement source; + private boolean includeLocation; public MutableLogEvent() { // messageText and the parameter array are lazily initialized @@ -93,8 +94,7 @@ public class MutableLogEvent implements ReusableLogEvent, ReusableMessage, Param * * @param event the event to copy data from */ - public void initFrom(final LogEvent event) { - this.loggerFqcn = event.getLoggerFqcn(); + public void moveValuesFrom(final LogEvent event) { this.marker = event.getMarker(); this.level = event.getLevel(); this.loggerName = event.getLoggerName(); @@ -109,19 +109,21 @@ public class MutableLogEvent implements ReusableLogEvent, ReusableMessage, Param this.contextData.putAll(event.getContextData()); this.contextStack = event.getContextStack(); - this.source = event.isIncludeLocation() ? event.getSource() : null; this.threadId = event.getThreadId(); this.threadName = event.getThreadName(); this.threadPriority = event.getThreadPriority(); this.endOfBatch = event.isEndOfBatch(); this.includeLocation = event.isIncludeLocation(); this.nanoTime = event.getNanoTime(); + // Location data + this.loggerFqcn = event.getLoggerFqcn(); + this.source = event.peekSource(); + this.includeLocation = event.isIncludeLocation(); setMessage(event.getMessage()); } @Override public void clear() { - loggerFqcn = null; marker = null; level = null; loggerName = null; @@ -129,7 +131,6 @@ public class MutableLogEvent implements ReusableLogEvent, ReusableMessage, Param messageFormat = null; thrown = null; thrownProxy = null; - source = null; if (contextData != null) { if (contextData.isFrozen()) { // came from CopyOnWrite thread context contextData = null; @@ -138,6 +139,9 @@ public class MutableLogEvent implements ReusableLogEvent, ReusableMessage, Param } } contextStack = null; + // Location information + loggerFqcn = null; + source = null; // ThreadName should not be cleared: this field is set in the ReusableLogEventFactory // where this instance is kept in a ThreadLocal, so it usually does not change. @@ -211,15 +215,14 @@ public class MutableLogEvent implements ReusableLogEvent, ReusableMessage, Param } @Override - public void setMessage(final Message msg) { - if (msg instanceof ReusableMessage) { - final ReusableMessage reusable = (ReusableMessage) msg; + public void setMessage(final Message message) { + if (message instanceof final ReusableMessage reusable) { reusable.formatTo(getMessageTextForWriting()); - this.messageFormat = msg.getFormat(); + messageFormat = message.getFormat(); parameters = reusable.swapParameters(parameters == null ? new Object[10] : parameters); parameterCount = reusable.getParameterCount(); } else { - this.message = InternalAsyncUtil.makeMessageImmutable(msg); + this.message = message; } } @@ -373,13 +376,14 @@ public class MutableLogEvent implements ReusableLogEvent, ReusableMessage, Param */ @Override public StackTraceElement getSource() { - if (source != null) { - return source; - } - if (loggerFqcn == null || !includeLocation) { - return null; + if (source == null && loggerFqcn != null) { + return source = includeLocation ? StackLocatorUtil.calcLocation(loggerFqcn) : null; } - source = StackLocatorUtil.calcLocation(loggerFqcn); + return peekSource(); + } + + @Override + public @Nullable StackTraceElement peekSource() { return source; } diff --git a/log4j-flume-ng/src/main/java/org/apache/logging/log4j/flume/appender/FlumeEvent.java b/log4j-flume-ng/src/main/java/org/apache/logging/log4j/flume/appender/FlumeEvent.java index 385e38ada5..4f64038feb 100644 --- a/log4j-flume-ng/src/main/java/org/apache/logging/log4j/flume/appender/FlumeEvent.java +++ b/log4j-flume-ng/src/main/java/org/apache/logging/log4j/flume/appender/FlumeEvent.java @@ -39,6 +39,7 @@ import org.apache.logging.log4j.message.StructuredDataId; import org.apache.logging.log4j.message.StructuredDataMessage; import org.apache.logging.log4j.util.ReadOnlyStringMap; import org.apache.logging.log4j.util.Strings; +import org.jspecify.annotations.Nullable; /** * Class that is both a Flume and Log4j Event. @@ -239,6 +240,11 @@ public class FlumeEvent extends SimpleEvent implements LogEvent { return event.getSource(); } + @Override + public @Nullable StackTraceElement peekSource() { + return event.peekSource(); + } + /** * Returns the Message. * @return the Message. diff --git a/log4j-kit/src/main/java/org/apache/logging/log4j/kit/logger/AbstractLogger.java b/log4j-kit/src/main/java/org/apache/logging/log4j/kit/logger/AbstractLogger.java index 911730ceb3..73dbd78996 100644 --- a/log4j-kit/src/main/java/org/apache/logging/log4j/kit/logger/AbstractLogger.java +++ b/log4j-kit/src/main/java/org/apache/logging/log4j/kit/logger/AbstractLogger.java @@ -34,7 +34,6 @@ import org.apache.logging.log4j.spi.recycler.RecyclerFactory; import org.apache.logging.log4j.util.LambdaUtil; import org.apache.logging.log4j.util.MessageSupplier; import org.apache.logging.log4j.util.PerformanceSensitive; -import org.apache.logging.log4j.util.StackLocatorUtil; import org.apache.logging.log4j.util.Supplier; import org.jspecify.annotations.NullMarked; import org.jspecify.annotations.Nullable; @@ -234,10 +233,9 @@ public abstract class AbstractLogger implements ExtendedLogger { } @PerformanceSensitive - // NOTE: This is a hot method. Current implementation compiles to 15 bytes of byte code. - // This is within the 35 byte MaxInlineSize threshold. Modify with care! - private @Nullable StackTraceElement getLocation(final String fqcn, final @Nullable StackTraceElement location) { - return location != null ? location : requiresLocation() ? StackLocatorUtil.calcLocation(fqcn) : null; + private static @Nullable Throwable getThrowable( + final @Nullable Message message, final @Nullable Throwable throwable) { + return throwable != null ? throwable : message != null ? message.getThrowable() : null; } @PerformanceSensitive @@ -258,7 +256,7 @@ public abstract class AbstractLogger implements ExtendedLogger { final @Nullable Message message, final @Nullable Throwable throwable) { try { - doLog(fqcn, getLocation(fqcn, location), level, marker, message, throwable); + doLog(fqcn, location, level, marker, message, getThrowable(message, throwable)); } catch (final Throwable t) { // LOG4J2-1990 Log4j2 suppresses all exceptions that occur once application called the logger handleLogMessageException(t, fqcn, message); @@ -281,10 +279,6 @@ public abstract class AbstractLogger implements ExtendedLogger { throwable); } - protected boolean requiresLocation() { - return false; - } - // <editor-fold desc="Unconditional logging"> // Methods that always log a message regardless of the current logger level. @@ -296,8 +290,7 @@ public abstract class AbstractLogger implements ExtendedLogger { final @Nullable Marker marker, final CharSequence message, final @Nullable Throwable throwable) { - final Message msg = messageFactory.newMessage(message); - logMessageSafely(fqcn, null, level, marker, msg, throwable); + logMessageSafely(fqcn, null, level, marker, messageFactory.newMessage(message), throwable); } @PerformanceSensitive @@ -307,8 +300,7 @@ public abstract class AbstractLogger implements ExtendedLogger { final @Nullable Marker marker, final Object message, final @Nullable Throwable throwable) { - final Message msg = messageFactory.newMessage(message); - logMessageSafely(fqcn, null, level, marker, msg, throwable); + logMessageSafely(fqcn, null, level, marker, messageFactory.newMessage(message), throwable); } @SuppressWarnings("deprecation") @@ -318,9 +310,7 @@ public abstract class AbstractLogger implements ExtendedLogger { final @Nullable Marker marker, final MessageSupplier messageSupplier, final @Nullable Throwable throwable) { - final Message msg = LambdaUtil.get(messageSupplier); - final Throwable effectiveThrowable = (throwable == null && msg != null) ? msg.getThrowable() : throwable; - logMessageSafely(fqcn, null, level, marker, msg, effectiveThrowable); + logMessageSafely(fqcn, null, level, marker, LambdaUtil.get(messageSupplier), throwable); } @SuppressWarnings("deprecation") @@ -330,9 +320,7 @@ public abstract class AbstractLogger implements ExtendedLogger { final @Nullable Marker marker, final Supplier<?> messageSupplier, final @Nullable Throwable throwable) { - final Message msg = LambdaUtil.getMessage(messageSupplier, messageFactory); - final Throwable effectiveThrowable = (throwable == null && msg != null) ? msg.getThrowable() : throwable; - logMessageSafely(fqcn, null, level, marker, msg, effectiveThrowable); + logMessageSafely(fqcn, null, level, marker, LambdaUtil.getMessage(messageSupplier, messageFactory), throwable); } @PerformanceSensitive @@ -342,15 +330,7 @@ public abstract class AbstractLogger implements ExtendedLogger { final @Nullable Marker marker, final String message, final @Nullable Throwable throwable) { - final Message msg = messageFactory.newMessage(message); - logMessageSafely(fqcn, null, level, marker, msg, throwable); - } - - @PerformanceSensitive - protected void logMessage( - final String fqcn, final Level level, final @Nullable Marker marker, final String message) { - final Message msg = messageFactory.newMessage(message); - logMessageSafely(fqcn, null, level, marker, msg, msg.getThrowable()); + logMessageSafely(fqcn, null, level, marker, messageFactory.newMessage(message), throwable); } @PerformanceSensitive @@ -360,8 +340,7 @@ public abstract class AbstractLogger implements ExtendedLogger { final @Nullable Marker marker, final String message, final Object p0) { - final Message msg = messageFactory.newMessage(message, p0); - logMessageSafely(fqcn, null, level, marker, msg, msg.getThrowable()); + logMessageSafely(fqcn, null, level, marker, messageFactory.newMessage(message, p0), null); } @PerformanceSensitive @@ -372,8 +351,7 @@ public abstract class AbstractLogger implements ExtendedLogger { final String message, final Object p0, final Object p1) { - final Message msg = messageFactory.newMessage(message, p0, p1); - logMessageSafely(fqcn, null, level, marker, msg, msg.getThrowable()); + logMessageSafely(fqcn, null, level, marker, messageFactory.newMessage(message, p0, p1), null); } protected void logMessage( @@ -384,8 +362,7 @@ public abstract class AbstractLogger implements ExtendedLogger { final Object p0, final Object p1, final Object p2) { - final Message msg = messageFactory.newMessage(message, p0, p1, p2); - logMessageSafely(fqcn, null, level, marker, msg, msg.getThrowable()); + logMessageSafely(fqcn, null, level, marker, messageFactory.newMessage(message, p0, p1, p2), null); } protected void logMessage( @@ -397,8 +374,7 @@ public abstract class AbstractLogger implements ExtendedLogger { final Object p1, final Object p2, final Object p3) { - final Message msg = messageFactory.newMessage(message, p0, p1, p2, p3); - logMessageSafely(fqcn, null, level, marker, msg, msg.getThrowable()); + logMessageSafely(fqcn, null, level, marker, messageFactory.newMessage(message, p0, p1, p2, p3), null); } protected void logMessage( @@ -411,8 +387,7 @@ public abstract class AbstractLogger implements ExtendedLogger { final Object p2, final Object p3, final Object p4) { - final Message msg = messageFactory.newMessage(message, p0, p1, p2, p3, p4); - logMessageSafely(fqcn, null, level, marker, msg, msg.getThrowable()); + logMessageSafely(fqcn, null, level, marker, messageFactory.newMessage(message, p0, p1, p2, p3, p4), null); } protected void logMessage( @@ -426,8 +401,7 @@ public abstract class AbstractLogger implements ExtendedLogger { final Object p3, final Object p4, final Object p5) { - final Message msg = messageFactory.newMessage(message, p0, p1, p2, p3, p4, p5); - logMessageSafely(fqcn, null, level, marker, msg, msg.getThrowable()); + logMessageSafely(fqcn, null, level, marker, messageFactory.newMessage(message, p0, p1, p2, p3, p4, p5), null); } protected void logMessage( @@ -442,8 +416,8 @@ public abstract class AbstractLogger implements ExtendedLogger { final Object p4, final Object p5, final Object p6) { - final Message msg = messageFactory.newMessage(message, p0, p1, p2, p3, p4, p5, p6); - logMessageSafely(fqcn, null, level, marker, msg, msg.getThrowable()); + logMessageSafely( + fqcn, null, level, marker, messageFactory.newMessage(message, p0, p1, p2, p3, p4, p5, p6), null); } protected void logMessage( @@ -459,8 +433,8 @@ public abstract class AbstractLogger implements ExtendedLogger { final Object p5, final Object p6, final Object p7) { - final Message msg = messageFactory.newMessage(message, p0, p1, p2, p3, p4, p5, p6, p7); - logMessageSafely(fqcn, null, level, marker, msg, msg.getThrowable()); + logMessageSafely( + fqcn, null, level, marker, messageFactory.newMessage(message, p0, p1, p2, p3, p4, p5, p6, p7), null); } protected void logMessage( @@ -477,8 +451,13 @@ public abstract class AbstractLogger implements ExtendedLogger { final Object p6, final Object p7, final Object p8) { - final Message msg = messageFactory.newMessage(message, p0, p1, p2, p3, p4, p5, p6, p7, p8); - logMessageSafely(fqcn, null, level, marker, msg, msg.getThrowable()); + logMessageSafely( + fqcn, + null, + level, + marker, + messageFactory.newMessage(message, p0, p1, p2, p3, p4, p5, p6, p7, p8), + null); } protected void logMessage( @@ -496,8 +475,13 @@ public abstract class AbstractLogger implements ExtendedLogger { final Object p7, final Object p8, final Object p9) { - final Message msg = messageFactory.newMessage(message, p0, p1, p2, p3, p4, p5, p6, p7, p8, p9); - logMessageSafely(fqcn, null, level, marker, msg, msg.getThrowable()); + logMessageSafely( + fqcn, + null, + level, + marker, + messageFactory.newMessage(message, p0, p1, p2, p3, p4, p5, p6, p7, p8, p9), + null); } @SuppressWarnings("deprecation") @@ -507,8 +491,8 @@ public abstract class AbstractLogger implements ExtendedLogger { final @Nullable Marker marker, final String message, final Supplier<?>... paramSuppliers) { - final Message msg = messageFactory.newMessage(message, LambdaUtil.getAll(paramSuppliers)); - logMessageSafely(fqcn, null, level, marker, msg, msg.getThrowable()); + logMessageSafely( + fqcn, null, level, marker, messageFactory.newMessage(message, LambdaUtil.getAll(paramSuppliers)), null); } @PerformanceSensitive @@ -518,8 +502,7 @@ public abstract class AbstractLogger implements ExtendedLogger { final @Nullable Marker marker, final String message, final Object... params) { - final Message msg = messageFactory.newMessage(message, params); - logMessageSafely(fqcn, null, level, marker, msg, msg.getThrowable()); + logMessageSafely(fqcn, null, level, marker, messageFactory.newMessage(message, params), null); } // </editor-fold> @@ -564,8 +547,7 @@ public abstract class AbstractLogger implements ExtendedLogger { final @Nullable Marker marker, final String format, final Object... params) { - final Message message = new StringFormattedMessage(format, params); - logMessageSafely(fqcn, null, level, marker, message, message.getThrowable()); + logMessageSafely(fqcn, null, level, marker, new StringFormattedMessage(format, params), null); } protected void logThrowingMessage(final String fqcn, final Level level, final Throwable throwable) { @@ -892,7 +874,7 @@ public abstract class AbstractLogger implements ExtendedLogger { public void logIfEnabled( final String fqcn, final Level level, final @Nullable Marker marker, final String message) { if (isEnabled(level, marker, message)) { - logMessage(fqcn, level, marker, message); + logMessage(fqcn, level, marker, message, (Throwable) null); } } @@ -1189,7 +1171,7 @@ public abstract class AbstractLogger implements ExtendedLogger { @Override public void debug(final Marker marker, final @Nullable Message message) { - logIfEnabled(FQCN, Level.DEBUG, marker, message, message != null ? message.getThrowable() : null); + logIfEnabled(FQCN, Level.DEBUG, marker, message, null); } @Override @@ -1225,7 +1207,7 @@ public abstract class AbstractLogger implements ExtendedLogger { @Override public void debug(final @Nullable Message message) { - logIfEnabled(FQCN, Level.DEBUG, null, message, message != null ? message.getThrowable() : null); + logIfEnabled(FQCN, Level.DEBUG, null, message, null); } @Override @@ -1542,7 +1524,7 @@ public abstract class AbstractLogger implements ExtendedLogger { @Override public void error(final @Nullable Marker marker, final @Nullable Message message) { - logIfEnabled(FQCN, Level.ERROR, marker, message, message != null ? message.getThrowable() : null); + logIfEnabled(FQCN, Level.ERROR, marker, message, null); } @Override @@ -1588,7 +1570,7 @@ public abstract class AbstractLogger implements ExtendedLogger { @Override public void error(final @Nullable Message message) { - logIfEnabled(FQCN, Level.ERROR, null, message, message != null ? message.getThrowable() : null); + logIfEnabled(FQCN, Level.ERROR, null, message, null); } @Override @@ -1905,7 +1887,7 @@ public abstract class AbstractLogger implements ExtendedLogger { @Override public void fatal(final @Nullable Marker marker, final @Nullable Message message) { - logIfEnabled(FQCN, Level.FATAL, marker, message, message != null ? message.getThrowable() : null); + logIfEnabled(FQCN, Level.FATAL, marker, message, null); } @Override @@ -1951,7 +1933,7 @@ public abstract class AbstractLogger implements ExtendedLogger { @Override public void fatal(final @Nullable Message message) { - logIfEnabled(FQCN, Level.FATAL, null, message, message != null ? message.getThrowable() : null); + logIfEnabled(FQCN, Level.FATAL, null, message, null); } @Override @@ -2268,7 +2250,7 @@ public abstract class AbstractLogger implements ExtendedLogger { @Override public void info(final @Nullable Marker marker, final @Nullable Message message) { - logIfEnabled(FQCN, Level.INFO, marker, message, message != null ? message.getThrowable() : null); + logIfEnabled(FQCN, Level.INFO, marker, message, null); } @Override @@ -2314,7 +2296,7 @@ public abstract class AbstractLogger implements ExtendedLogger { @Override public void info(final @Nullable Message message) { - logIfEnabled(FQCN, Level.INFO, null, message, message != null ? message.getThrowable() : null); + logIfEnabled(FQCN, Level.INFO, null, message, null); } @Override @@ -2631,7 +2613,7 @@ public abstract class AbstractLogger implements ExtendedLogger { @Override public void log(final Level level, final @Nullable Marker marker, final @Nullable Message message) { - logIfEnabled(FQCN, level, marker, message, message != null ? message.getThrowable() : null); + logIfEnabled(FQCN, level, marker, message, null); } @Override @@ -2692,7 +2674,7 @@ public abstract class AbstractLogger implements ExtendedLogger { @Override public void log(final Level level, final @Nullable Message message) { - logIfEnabled(FQCN, level, null, message, message != null ? message.getThrowable() : null); + logIfEnabled(FQCN, level, null, message, null); } @Override @@ -3049,7 +3031,7 @@ public abstract class AbstractLogger implements ExtendedLogger { @Override public void trace(final @Nullable Marker marker, final @Nullable Message message) { - logIfEnabled(FQCN, Level.TRACE, marker, message, message != null ? message.getThrowable() : null); + logIfEnabled(FQCN, Level.TRACE, marker, message, null); } @Override @@ -3095,7 +3077,7 @@ public abstract class AbstractLogger implements ExtendedLogger { @Override public void trace(final @Nullable Message message) { - logIfEnabled(FQCN, Level.TRACE, null, message, message != null ? message.getThrowable() : null); + logIfEnabled(FQCN, Level.TRACE, null, message, null); } @Override @@ -3412,7 +3394,7 @@ public abstract class AbstractLogger implements ExtendedLogger { @Override public void warn(final @Nullable Marker marker, final @Nullable Message message) { - logIfEnabled(FQCN, Level.WARN, marker, message, message != null ? message.getThrowable() : null); + logIfEnabled(FQCN, Level.WARN, marker, message, null); } @Override @@ -3458,7 +3440,7 @@ public abstract class AbstractLogger implements ExtendedLogger { @Override public void warn(final @Nullable Message message) { - logIfEnabled(FQCN, Level.WARN, null, message, message != null ? message.getThrowable() : null); + logIfEnabled(FQCN, Level.WARN, null, message, null); } @Override diff --git a/log4j-kit/src/test/java/org/apache/logging/log4j/kit/logger/AbstractLoggerTest.java b/log4j-kit/src/test/java/org/apache/logging/log4j/kit/logger/AbstractLoggerTest.java index adc350922e..a8f013b47e 100644 --- a/log4j-kit/src/test/java/org/apache/logging/log4j/kit/logger/AbstractLoggerTest.java +++ b/log4j-kit/src/test/java/org/apache/logging/log4j/kit/logger/AbstractLoggerTest.java @@ -29,6 +29,7 @@ import org.junit.jupiter.api.Test; public class AbstractLoggerTest { private static final int MAX_INLINE_SIZE = 35; + private static final String OBJECT = "Ljava/lang/Object;"; /** * List of methods that currently don't fit into 35 bytes. */ @@ -36,13 +37,12 @@ public class AbstractLoggerTest { "<clinit>()V", "<init>(", "handleLogMessageException(Ljava/lang/Throwable;Ljava/lang/String;Lorg/apache/logging/log4j/message/Message;)V", - // logging methods with Supplier, MessageSupplier or more than 2 parameters - "logMessage(Ljava/lang/String;Lorg/apache/logging/log4j/Level;Lorg/apache/logging/log4j/Marker;Lorg/apache/logging/log4j/util/MessageSupplier;Ljava/lang/Throwable;)V", - "logMessage(Ljava/lang/String;Lorg/apache/logging/log4j/Level;Lorg/apache/logging/log4j/Marker;Lorg/apache/logging/log4j/util/Supplier;Ljava/lang/Throwable;)V", - "logMessage(Ljava/lang/String;Lorg/apache/logging/log4j/Level;Lorg/apache/logging/log4j/Marker;Ljava/lang/String;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;", - "logMessage(Ljava/lang/String;Lorg/apache/logging/log4j/Level;Lorg/apache/logging/log4j/Marker;Ljava/lang/String;[Lorg/apache/logging/log4j/util/Supplier;)V", - // logging methods with more than 3 parameters - "logIfEnabled(Ljava/lang/String;Lorg/apache/logging/log4j/Level;Lorg/apache/logging/log4j/Marker;Ljava/lang/String;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;"); + // unconditional logging methods with more than 7 parameters + "logMessage(Ljava/lang/String;Lorg/apache/logging/log4j/Level;Lorg/apache/logging/log4j/Marker;Ljava/lang/String;" + + OBJECT.repeat(8), + // conditional logging methods with more than 3 parameters + "logIfEnabled(Ljava/lang/String;Lorg/apache/logging/log4j/Level;Lorg/apache/logging/log4j/Marker;Ljava/lang/String;" + + OBJECT.repeat(4)); @Test void does_not_exceed_MaxInlineSize() throws Exception {
