Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Improve implementations of LogEvent.toImmutable() and ReusableMessage.memento() #3171

Open
wants to merge 1 commit into
base: 2.x
Choose a base branch
from
Open
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -105,7 +105,6 @@ public LoggingEvent rewrite(final LoggingEvent source) {
.setThrown(source.getThrowableInformation().getThrowable())
.setTimeMillis(source.getTimeStamp())
.setNanoTime(0)
.setThrownProxy(null)
.build();
}
return new LogEventAdapter(event);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -110,7 +110,6 @@ public LoggingEvent rewrite(final LoggingEvent source) {
.setThrown(source.getThrowableInformation().getThrowable())
.setTimeMillis(source.getTimeStamp())
.setNanoTime(0)
.setThrownProxy(null)
.build();
}
return new LogEventAdapter(event);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -128,7 +128,9 @@ public <S> void forEachParameter(final ParameterConsumer<S> action, final S stat

@Override
public Message memento() {
return new ObjectMessage(obj);
Message message = new ObjectMessage(obj);
message.getFormattedMessage();
return message;
}

@Override
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -114,7 +114,9 @@ public <S> void forEachParameter(final ParameterConsumer<S> action, final S stat

@Override
public Message memento() {
return new ParameterizedMessage(messagePattern, getTrimmedParams());
Message message = new ParameterizedMessage(messagePattern, getTrimmedParams());
message.getFormattedMessage();
return message;
}

private void init(final String messagePattern, final int argCount, final Object[] args) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -85,7 +85,9 @@ public <S> void forEachParameter(final ParameterConsumer<S> action, final S stat

@Override
public Message memento() {
return new SimpleMessage(charSequence);
SimpleMessage message = new SimpleMessage(charSequence);
message.getFormattedMessage();
return message;
}

// CharSequence impl
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -35,7 +35,6 @@
import org.apache.logging.log4j.core.config.plugins.PluginBuilderFactory;
import org.apache.logging.log4j.core.config.plugins.PluginElement;
import org.apache.logging.log4j.core.config.plugins.validation.constraints.Required;
import org.apache.logging.log4j.core.impl.MutableLogEvent;
import org.apache.logging.log4j.core.layout.SerializedLayout;
import org.awaitility.Awaitility;

Expand Down Expand Up @@ -121,12 +120,7 @@ public ListAppender(
public void append(final LogEvent event) {
final Layout<? extends Serializable> layout = getLayout();
if (layout == null) {
if (event instanceof MutableLogEvent) {
// must take snapshot or subsequent calls to logger.log() will modify this event
events.add(((MutableLogEvent) event).createMemento());
} else {
events.add(event);
}
events.add(event.toImmutable());
} else if (layout instanceof SerializedLayout) {
final byte[] header = layout.getHeader();
final byte[] content = layout.toByteArray(event);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -33,7 +33,6 @@
import org.apache.logging.log4j.core.config.plugins.PluginElement;
import org.apache.logging.log4j.core.config.plugins.PluginFactory;
import org.apache.logging.log4j.core.config.plugins.validation.constraints.Required;
import org.apache.logging.log4j.core.impl.Log4jLogEvent;

/**
* Appender that can be halted and resumed, for testing queue-full scenarios.
Expand All @@ -58,7 +57,7 @@ public void append(final LogEvent event) {
// may be a reusable event, make a copy, don't keep a reference to the original event
final List<LogEvent> events = logEvents;
if (events != null) {
events.add(Log4jLogEvent.createMemento(event));
events.add(event.toImmutable());
}

if (countDownLatch == null) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -29,6 +29,7 @@
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.Marker;
import org.apache.logging.log4j.MarkerManager;
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.impl.ThrowableProxy;
Expand Down Expand Up @@ -202,7 +203,7 @@ void testSerializationDeserialization() throws IOException, ClassNotFoundExcepti
final Level level = Level.TRACE;
final Message data = new SimpleMessage("message");
final Throwable t = new InternalError("not a real error");
final ContextStack contextStack = null;
final ContextStack contextStack = ThreadContext.getImmutableStack();
final String threadName = "main";
final StackTraceElement location = null;
evt.setValues(
Expand All @@ -223,25 +224,31 @@ void testSerializationDeserialization() throws IOException, ClassNotFoundExcepti
new DummyNanoClock(1));
((StringMap) evt.getContextData()).putValue("key", "value");

final RingBufferLogEvent other = SerialUtil.deserialize(SerialUtil.serialize(evt));
assertThat(other.getLoggerName()).isEqualTo(loggerName);
assertThat(other.getMarker()).isEqualTo(marker);
assertThat(other.getLoggerFqcn()).isEqualTo(fqcn);
assertThat(other.getLevel()).isEqualTo(level);
assertThat(other.getMessage()).isEqualTo(data);
assertThat(other.getThrown()).isNull();
assertThat(other.getThrownProxy()).isEqualTo(new ThrowableProxy(t));
assertThat(other.getContextData()).isEqualTo(evt.getContextData());
assertThat(other.getContextStack()).isEqualTo(contextStack);
assertThat(other.getThreadName()).isEqualTo(threadName);
assertThat(other.getSource()).isEqualTo(location);
assertThat(other.getTimeMillis()).isEqualTo(12345);
assertThat(other.getInstant().getNanoOfMillisecond()).isEqualTo(678);
final LogEvent other = SerialUtil.deserialize(SerialUtil.serialize(evt));
assertThat(other.getLoggerName()).as("Logger name").isEqualTo(loggerName);
assertThat(other.getMarker()).as("Marker").isEqualTo(marker);
assertThat(other.getLoggerFqcn())
.as("Fully qualified class name of logger implementation")
.isEqualTo(fqcn);
assertThat(other.getLevel()).as("Log event level").isEqualTo(level);
assertThat(other.getMessage()).as("Log event message").isEqualTo(data);
assertThat(other.getThrown()).as("Thrown exception").isNull();
assertThat(other.getThrownProxy())
.as("Serialization proxy for thrown exception")
.isEqualTo(new ThrowableProxy(t));
assertThat(other.getContextData()).as("Context data map").isEqualTo(evt.getContextData());
assertThat(other.getContextStack()).as("Context data stack").isEqualTo(contextStack);
assertThat(other.getThreadName()).as("Thread name").isEqualTo(threadName);
assertThat(other.getSource()).as("Log event location").isEqualTo(location);
assertThat(other.getTimeMillis()).as("Log event timestamp in millis").isEqualTo(12345);
assertThat(other.getInstant().getNanoOfMillisecond())
.as("Log event timestamp in nanos of millis")
.isEqualTo(678);
}

@SuppressWarnings("deprecation")
@Test
void testCreateMementoReturnsCopy() {
void testToImmutableReturnsCopy() {
final RingBufferLogEvent evt = new RingBufferLogEvent();
final String loggerName = "logger.name";
final Marker marker = MarkerManager.getMarker("marked man");
Expand Down Expand Up @@ -270,7 +277,7 @@ void testCreateMementoReturnsCopy() {
new DummyNanoClock(1));
((StringMap) evt.getContextData()).putValue("key", "value");

final LogEvent actual = evt.createMemento();
final LogEvent actual = evt.toImmutable();
assertThat(actual.getLoggerName()).isEqualTo(evt.getLoggerName());
assertThat(actual.getMarker()).isEqualTo(evt.getMarker());
assertThat(actual.getLoggerFqcn()).isEqualTo(evt.getLoggerFqcn());
Expand All @@ -289,7 +296,7 @@ void testCreateMementoReturnsCopy() {
}

@Test
void testCreateMementoRetainsParametersAndFormat() {
void testToImmutableRetainsParametersAndFormat() {
final RingBufferLogEvent evt = new RingBufferLogEvent();
// Initialize the event with parameters
evt.swapParameters(new Object[10]);
Expand Down Expand Up @@ -322,7 +329,7 @@ void testCreateMementoRetainsParametersAndFormat() {
new DummyNanoClock(1));
((StringMap) evt.getContextData()).putValue("key", "value");

final Message actual = evt.createMemento().getMessage();
final Message actual = evt.toImmutable().getMessage();
assertThat(actual.getFormat()).isEqualTo("Hello {}!");
assertThat(actual.getParameters()).isEqualTo(new String[] {"World"});
assertThat(actual.getFormattedMessage()).isEqualTo("Hello World!");
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -137,7 +137,7 @@ public void testInitFromReusableCopiesFormatString() {
assertEquals("msg in a bottle", memento.getFormattedMessage(), "formatted");
assertArrayEquals(new String[] {"bottle"}, memento.getParameters(), "parameters");

final Message eventMementoMessage = mutable.createMemento().getMessage();
final Message eventMementoMessage = mutable.toImmutable().getMessage();
assertEquals("msg in a {}", eventMementoMessage.getFormat(), "format");
assertEquals("msg in a bottle", eventMementoMessage.getFormattedMessage(), "formatted");
assertArrayEquals(new String[] {"bottle"}, eventMementoMessage.getParameters(), "parameters");
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -16,16 +16,13 @@
*/
package org.apache.logging.log4j.core.net;

import static org.hamcrest.CoreMatchers.instanceOf;
import static org.hamcrest.CoreMatchers.is;
import static org.hamcrest.MatcherAssert.assertThat;
import static org.assertj.core.api.Assertions.assertThat;
import static org.junit.jupiter.api.Assertions.assertEquals;

import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.appender.SmtpAppender;
import org.apache.logging.log4j.core.async.RingBufferLogEvent;
import org.apache.logging.log4j.core.impl.Log4jLogEvent;
import org.apache.logging.log4j.core.impl.MementoMessage;
import org.apache.logging.log4j.core.impl.MutableLogEvent;
import org.apache.logging.log4j.core.util.ClockFactory;
import org.apache.logging.log4j.core.util.DummyNanoClock;
Expand Down Expand Up @@ -72,17 +69,14 @@ private void testAdd(final LogEvent event) {
.setBufferSize(10)
.build();
final MailManager mailManager = appender.getManager();
assertThat("is instance of SmtpManager", mailManager instanceof SmtpManager);
assertThat(mailManager).isInstanceOf(SmtpManager.class);
final SmtpManager smtpManager = (SmtpManager) mailManager;
smtpManager.removeAllBufferedEvents(); // in case this smtpManager is reused
smtpManager.add(event);

final LogEvent[] bufferedEvents = smtpManager.removeAllBufferedEvents();
assertThat("unexpected number of buffered events", bufferedEvents.length, is(1));
assertThat(
"expected the immutable version of the event to be buffered",
bufferedEvents[0].getMessage(),
is(instanceOf(MementoMessage.class)));
assertThat(bufferedEvents).as("Buffered events").hasSize(1);
assertThat(bufferedEvents[0].getMessage()).as("Immutable message").isNotInstanceOf(ReusableMessage.class);
}

// LOG4J2-3172: make sure existing protections are not violated
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -51,6 +51,7 @@ public interface LogEvent extends Serializable {
* Returns an immutable version of this log event, which MAY BE a copy of this event.
*
* @return an immutable version of this log event
* @since 2.8.1
*/
LogEvent toImmutable();

Expand Down Expand Up @@ -187,7 +188,9 @@ public interface LogEvent extends Serializable {
* Gets throwable proxy associated with logging request.
*
* @return throwable, may be null.
* @deprecated since 2.25.0. This method should be replaced with {@link #getThrown()}.
*/
@Deprecated
ThrowableProxy getThrownProxy();

/**
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -235,7 +235,6 @@ private void logWithThreadLocalTranslator(

final RingBufferLogEventTranslator translator = getCachedTranslator();
initTranslator(translator, fqcn, level, marker, message, thrown);
initTranslatorThreadValues(translator);
publish(translator);
}

Expand Down Expand Up @@ -263,7 +262,6 @@ private void logWithThreadLocalTranslator(

final RingBufferLogEventTranslator translator = getCachedTranslator();
initTranslator(translator, fqcn, location, level, marker, message, thrown);
initTranslatorThreadValues(translator);
publish(translator);
}

Expand Down Expand Up @@ -355,13 +353,6 @@ private void initTranslator(
);
}

private void initTranslatorThreadValues(final RingBufferLogEventTranslator translator) {
// constant check should be optimized out when using default (CACHED)
if (THREAD_NAME_CACHING_STRATEGY == ThreadNameCachingStrategy.UNCACHED) {
translator.updateThreadValues();
}
}
Comment on lines -358 to -363
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Instances of RingBufferLogEventTranslator are always used on the same thread that created them.


/**
* Returns the caller location if requested, {@code null} otherwise.
*
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -183,7 +183,9 @@ private void handleQueueFull(final LogEvent event) {

private void populateLazilyInitializedFields(final LogEvent event) {
event.getSource();
event.getThreadId();
event.getThreadName();
event.getThreadPriority();
}

void logInBackgroundThread(final LogEvent event) {
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -367,14 +367,14 @@ private LogEvent prepareEvent(final LogEvent event) {
LogEvent logEvent = ensureImmutable(event);
if (logEvent.getMessage() instanceof ReusableMessage) {
if (logEvent instanceof Log4jLogEvent) {
((Log4jLogEvent) logEvent).makeMessageImmutable();
logEvent = logEvent.toImmutable();
} 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 = ((MutableLogEvent) logEvent).createMemento();
logEvent = logEvent.toImmutable();
}
} else { // custom log event, with a ReusableMessage
showWarningAboutCustomLogEventWithReusableMessage(logEvent);
Expand Down Expand Up @@ -436,7 +436,7 @@ private LogEvent ensureImmutable(final LogEvent event) {
// 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 = ((RingBufferLogEvent) event).createMemento();
result = event.toImmutable();
}
return result;
}
Expand Down
Loading