You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by vy...@apache.org on 2021/07/23 11:54:52 UTC
[logging-log4j2] branch release-2.x updated: LOG4J2-2816 Handle
Disruptor event translation exceptions.
This is an automated email from the ASF dual-hosted git repository.
vy pushed a commit to branch release-2.x
in repository https://gitbox.apache.org/repos/asf/logging-log4j2.git
The following commit(s) were added to refs/heads/release-2.x by this push:
new d6a512b LOG4J2-2816 Handle Disruptor event translation exceptions.
d6a512b is described below
commit d6a512bd367459be40f5d8897f36a5d4587c1370
Author: Volkan Yazici <vo...@gmail.com>
AuthorDate: Fri Jul 23 13:54:02 2021 +0200
LOG4J2-2816 Handle Disruptor event translation exceptions.
---
.../log4j/core/async/RingBufferLogEvent.java | 11 ++
.../core/async/RingBufferLogEventHandler.java | 8 +-
.../core/async/RingBufferLogEventTranslator.java | 17 +--
.../AsyncLoggerEventTranslationExceptionTest.java | 148 +++++++++++++++++++++
.../log4j/core/async/RingBufferLogEventTest.java | 28 ++++
src/changes/changes.xml | 4 +
6 files changed, 207 insertions(+), 9 deletions(-)
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 ccf4445..9b199ca 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
@@ -62,6 +62,7 @@ public class RingBufferLogEvent implements LogEvent, ReusableMessage, CharSequen
}
}
+ private boolean populated;
private int threadPriority;
private long threadId;
private final MutableInstant instant = new MutableInstant();
@@ -107,6 +108,7 @@ public class RingBufferLogEvent implements LogEvent, ReusableMessage, CharSequen
this.contextData = mutableContextData;
this.contextStack = aContextStack;
this.asyncLogger = anAsyncLogger;
+ this.populated = true;
}
private void initTime(final Clock clock) {
@@ -155,6 +157,13 @@ public class RingBufferLogEvent implements LogEvent, ReusableMessage, CharSequen
}
/**
+ * @return {@code true} if this event is populated with data, {@code false} otherwise
+ */
+ public boolean isPopulated() {
+ return populated;
+ }
+
+ /**
* Returns {@code true} if this event is the end of a batch, {@code false} otherwise.
*
* @return {@code true} if this event is the end of a batch, {@code false} otherwise
@@ -389,6 +398,8 @@ public class RingBufferLogEvent implements LogEvent, ReusableMessage, CharSequen
* Release references held by ring buffer to allow objects to be garbage-collected.
*/
public void clear() {
+ this.populated = false;
+
this.asyncLogger = null;
this.loggerName = null;
this.marker = null;
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEventHandler.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEventHandler.java
index dfec3e4..0414fd2 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEventHandler.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEventHandler.java
@@ -43,7 +43,13 @@ public class RingBufferLogEventHandler implements
public void onEvent(final RingBufferLogEvent event, final long sequence,
final boolean endOfBatch) throws Exception {
try {
- event.execute(endOfBatch);
+ // RingBufferLogEvents are populated by an EventTranslator. If an exception is thrown during event
+ // translation, the event may not be fully populated, but Disruptor requires that the associated sequence
+ // still be published since a slot has already been claimed in the ring buffer. Ignore any such unpopulated
+ // events. The exception that occurred during translation will have already been propagated.
+ if (event.isPopulated()) {
+ event.execute(endOfBatch);
+ }
}
finally {
event.clear();
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEventTranslator.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEventTranslator.java
index 417394b..eec2cbb 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEventTranslator.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/RingBufferLogEventTranslator.java
@@ -56,14 +56,15 @@ public class RingBufferLogEventTranslator implements
// @Override
@Override
public void translateTo(final RingBufferLogEvent event, final long sequence) {
-
- event.setValues(asyncLogger, loggerName, marker, fqcn, level, message, thrown,
- // config properties are taken care of in the EventHandler thread
- // in the AsyncLogger#actualAsyncLog method
- INJECTOR.injectContextData(null, (StringMap) event.getContextData()), contextStack,
- threadId, threadName, threadPriority, location, clock, nanoClock);
-
- clear(); // clear the translator
+ try {
+ event.setValues(asyncLogger, loggerName, marker, fqcn, level, message, thrown,
+ // config properties are taken care of in the EventHandler thread
+ // in the AsyncLogger#actualAsyncLog method
+ INJECTOR.injectContextData(null, (StringMap) event.getContextData()), contextStack,
+ threadId, threadName, threadPriority, location, clock, nanoClock);
+ } finally {
+ clear(); // clear the translator
+ }
}
/**
diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerEventTranslationExceptionTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerEventTranslationExceptionTest.java
new file mode 100644
index 0000000..b57ea3f
--- /dev/null
+++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerEventTranslationExceptionTest.java
@@ -0,0 +1,148 @@
+/*
+ * 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.core.async;
+
+import com.lmax.disruptor.ExceptionHandler;
+import org.apache.logging.log4j.Level;
+import org.apache.logging.log4j.LogManager;
+import org.apache.logging.log4j.Logger;
+import org.apache.logging.log4j.categories.AsyncLoggers;
+import org.apache.logging.log4j.core.CoreLoggerContexts;
+import org.apache.logging.log4j.core.util.Constants;
+import org.apache.logging.log4j.message.Message;
+import org.apache.logging.log4j.message.ReusableSimpleMessage;
+import org.apache.logging.log4j.spi.AbstractLogger;
+import org.junit.experimental.categories.Category;
+import org.junit.jupiter.api.AfterAll;
+import org.junit.jupiter.api.BeforeAll;
+import org.junit.jupiter.api.Test;
+
+import static org.junit.jupiter.api.Assertions.*;
+
+/**
+ * Test an exception thrown in {@link RingBufferLogEventTranslator#translateTo(RingBufferLogEvent, long)}
+ * does not cause another exception to be thrown later in the background thread
+ * in {@link RingBufferLogEventHandler#onEvent(RingBufferLogEvent, long, boolean)}.
+ *
+ * @see <a href="https://issues.apache.org/jira/browse/LOG4J2-2816">LOG4J2-2816</a>
+ */
+@Category(AsyncLoggers.class)
+class AsyncLoggerEventTranslationExceptionTest {
+
+ @BeforeAll
+ public static void beforeAll() {
+ System.setProperty(Constants.LOG4J_CONTEXT_SELECTOR, AsyncLoggerContextSelector.class.getName());
+ System.setProperty("AsyncLogger.ExceptionHandler", TestExceptionHandler.class.getName());
+ }
+
+ @AfterAll
+ public static void afterAll() {
+ System.clearProperty(Constants.LOG4J_CONTEXT_SELECTOR);
+ System.clearProperty("AsyncLogger.ExceptionHandler");
+ }
+
+ @Test
+ void testEventTranslationExceptionDoesNotCauseAsyncEventException() {
+
+ final Logger log = LogManager.getLogger("com.foo.Bar");
+
+ assertTrue(
+ TestExceptionHandler.INSTANTIATED,
+ "TestExceptionHandler was not configured properly");
+
+ final Message exceptionThrowingMessage = new ExceptionThrowingMessage();
+ assertThrows(
+ TestMessageException.class,
+ () -> ((AbstractLogger) log).logMessage(
+ "com.foo.Bar",
+ Level.INFO,
+ null,
+ exceptionThrowingMessage,
+ null));
+
+ CoreLoggerContexts.stopLoggerContext(); // stop async thread
+
+ assertFalse(
+ TestExceptionHandler.EVENT_EXCEPTION_ENCOUNTERED,
+ "ExceptionHandler encountered an event exception");
+
+ }
+
+ public static final class TestExceptionHandler implements ExceptionHandler<RingBufferLogEvent> {
+
+ private static boolean INSTANTIATED = false;
+
+ private static boolean EVENT_EXCEPTION_ENCOUNTERED = false;
+
+ public TestExceptionHandler() {
+ INSTANTIATED = true;
+ }
+
+ @Override
+ public void handleEventException(final Throwable error, final long sequence, final RingBufferLogEvent event) {
+ EVENT_EXCEPTION_ENCOUNTERED = true;
+ }
+
+ @Override
+ public void handleOnStartException(final Throwable error) {
+ fail("Unexpected start exception: " + error.getMessage());
+ }
+
+ @Override
+ public void handleOnShutdownException(final Throwable error) {
+ fail("Unexpected shutdown exception: " + error.getMessage());
+ }
+
+ }
+
+ private static class TestMessageException extends RuntimeException {}
+
+ private static final class ExceptionThrowingMessage extends ReusableSimpleMessage {
+
+ @Override
+ public String getFormattedMessage() {
+ throw new TestMessageException();
+ }
+
+ @Override
+ public String getFormat() {
+ throw new TestMessageException();
+ }
+
+ @Override
+ public Object[] getParameters() {
+ throw new TestMessageException();
+ }
+
+ @Override
+ public void formatTo(final StringBuilder buffer) {
+ throw new TestMessageException();
+ }
+
+ @Override
+ public Object[] swapParameters(final Object[] emptyReplacement) {
+ throw new TestMessageException();
+ }
+
+ @Override
+ public short getParameterCount() {
+ throw new TestMessageException();
+ }
+
+ }
+
+}
diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/async/RingBufferLogEventTest.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/async/RingBufferLogEventTest.java
index aff0d76..e350c85 100644
--- a/log4j-core/src/test/java/org/apache/logging/log4j/core/async/RingBufferLogEventTest.java
+++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/async/RingBufferLogEventTest.java
@@ -58,6 +58,34 @@ public class RingBufferLogEventTest {
Assert.assertNotSame(logEvent, logEvent.toImmutable());
}
+ /**
+ * @see <a href="https://issues.apache.org/jira/browse/LOG4J2-2816">LOG4J2-2816</a>
+ */
+ @Test
+ public void testIsPopulated() {
+ final RingBufferLogEvent evt = new RingBufferLogEvent();
+
+ assertFalse(evt.isPopulated());
+
+ final String loggerName = null;
+ final Marker marker = null;
+ final String fqcn = null;
+ final Level level = null;
+ final Message data = null;
+ final Throwable t = null;
+ final ContextStack contextStack = null;
+ final String threadName = null;
+ final StackTraceElement location = null;
+ evt.setValues(null, loggerName, marker, fqcn, level, data, t, (StringMap) evt.getContextData(),
+ contextStack, -1, threadName, -1, location, new FixedPreciseClock(), new DummyNanoClock(1));
+
+ assertTrue(evt.isPopulated());
+
+ evt.clear();
+
+ assertFalse(evt.isPopulated());
+ }
+
@Test
public void testGetLevelReturnsOffIfNullLevelSet() {
final RingBufferLogEvent evt = new RingBufferLogEvent();
diff --git a/src/changes/changes.xml b/src/changes/changes.xml
index d485598..c2daabf 100644
--- a/src/changes/changes.xml
+++ b/src/changes/changes.xml
@@ -78,8 +78,12 @@
Allow a PatternSelector to be specified on GelfLayout.
</action>
<!-- FIXES -->
+ <action issue="LOG4J2-2816" dev="vy" type="fix" due-to="Jacob Shields">
+ Handle Disruptor event translation exceptions.
+ </action>
<action issue="LOG4J2-3121" dev="ggregory" type="fix" due-to="Markus Spann">
log4j2 config modified at run-time may trigger incomplete MBean re-initialization due to InstanceAlreadyExistsException.
+ </action>
<action issue="LOG4J2-3107" dev="vy" type="fix" due-to="Markus Spann">
SmtpManager.createManagerName ignores port.
</action>