You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@logging.apache.org by ck...@apache.org on 2018/05/04 13:45:14 UTC
logging-log4j2 git commit: [LOG4J2-2333] Handle errors thrown in
disruptor ExceptionHandler
Repository: logging-log4j2
Updated Branches:
refs/heads/master 06334e135 -> 9d57fe27b
[LOG4J2-2333] Handle errors thrown in disruptor ExceptionHandler
Previously this would kill the background thread and stop processing
events.
Project: http://git-wip-us.apache.org/repos/asf/logging-log4j2/repo
Commit: http://git-wip-us.apache.org/repos/asf/logging-log4j2/commit/9d57fe27
Tree: http://git-wip-us.apache.org/repos/asf/logging-log4j2/tree/9d57fe27
Diff: http://git-wip-us.apache.org/repos/asf/logging-log4j2/diff/9d57fe27
Branch: refs/heads/master
Commit: 9d57fe27b7353985814ea81c8cd807ee8350fac4
Parents: 06334e1
Author: Carter Kozak <ck...@apache.org>
Authored: Thu May 3 12:37:19 2018 -0400
Committer: Carter Kozak <ck...@apache.org>
Committed: Fri May 4 09:43:13 2018 -0400
----------------------------------------------------------------------
.../async/AbstractAsyncExceptionHandler.java | 69 +++++++++++++
...syncLoggerConfigDefaultExceptionHandler.java | 32 +-----
.../AsyncLoggerDefaultExceptionHandler.java | 31 +-----
.../async/AsyncLoggerConfigErrorOnFormat.java | 101 +++++++++++++++++++
.../AsyncLoggerConfigErrorOnFormat.xml | 19 ++++
src/changes/changes.xml | 6 ++
6 files changed, 197 insertions(+), 61 deletions(-)
----------------------------------------------------------------------
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/9d57fe27/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AbstractAsyncExceptionHandler.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AbstractAsyncExceptionHandler.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AbstractAsyncExceptionHandler.java
new file mode 100644
index 0000000..42c53f6
--- /dev/null
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AbstractAsyncExceptionHandler.java
@@ -0,0 +1,69 @@
+/*
+ * 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;
+
+/**
+ * Default disruptor exception handler for errors that occur in the AsyncLogger background thread.
+ */
+abstract class AbstractAsyncExceptionHandler<T> implements ExceptionHandler<T> {
+
+ @Override
+ public void handleEventException(final Throwable throwable, final long sequence, final T event) {
+ try {
+ // Careful to avoid allocation in case of memory pressure.
+ // Sacrifice performance for safety by writing directly
+ // rather than using a buffer.
+ System.err.print("AsyncLogger error handling event seq=");
+ System.err.print(sequence);
+ System.err.print(", value='");
+ try {
+ System.err.print(event);
+ } catch (final Throwable t) {
+ System.err.print("ERROR calling toString() on ");
+ System.err.print(event.getClass().getName());
+ System.err.print(": ");
+ System.err.print(t.getClass().getName());
+ System.err.print(": ");
+ System.err.print(t.getMessage());
+ }
+ System.err.print("': ");
+ System.err.print(throwable.getClass().getName());
+ System.err.print(": ");
+ System.err.println(throwable.getMessage());
+ // Attempt to print the full stack trace, which may fail if we're already
+ // OOMing We've already provided sufficient information at this point.
+ throwable.printStackTrace();
+ } catch (final Throwable ignored) {
+ // LOG4J2-2333: Not much we can do here without risking an OOM.
+ // Throwing an error here may kill the background thread.
+ }
+ }
+
+ @Override
+ public void handleOnStartException(final Throwable throwable) {
+ System.err.println("AsyncLogger error starting:");
+ throwable.printStackTrace();
+ }
+
+ @Override
+ public void handleOnShutdownException(final Throwable throwable) {
+ System.err.println("AsyncLogger error shutting down:");
+ throwable.printStackTrace();
+ }
+}
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/9d57fe27/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerConfigDefaultExceptionHandler.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerConfigDefaultExceptionHandler.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerConfigDefaultExceptionHandler.java
index 961c349..a0faa69 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerConfigDefaultExceptionHandler.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerConfigDefaultExceptionHandler.java
@@ -16,39 +16,9 @@
*/
package org.apache.logging.log4j.core.async;
-import com.lmax.disruptor.ExceptionHandler;
-
/**
* Default disruptor exception handler for errors that occur in the AsyncLogger background thread.
*/
public class AsyncLoggerConfigDefaultExceptionHandler
- implements ExceptionHandler<AsyncLoggerConfigDisruptor.Log4jEventWrapper> {
-
- @Override
- public void handleEventException(final Throwable throwable, final long sequence,
- final AsyncLoggerConfigDisruptor.Log4jEventWrapper event) {
- final StringBuilder sb = new StringBuilder(512);
- sb.append("AsyncLogger error handling event seq=").append(sequence).append(", value='");
- try {
- sb.append(event);
- } catch (final Exception ignored) {
- sb.append("[ERROR calling ").append(event.getClass()).append(".toString(): ");
- sb.append(ignored).append("]");
- }
- sb.append("':");
- System.err.println(sb);
- throwable.printStackTrace();
- }
-
- @Override
- public void handleOnStartException(final Throwable throwable) {
- System.err.println("AsyncLogger error starting:");
- throwable.printStackTrace();
- }
-
- @Override
- public void handleOnShutdownException(final Throwable throwable) {
- System.err.println("AsyncLogger error shutting down:");
- throwable.printStackTrace();
- }
+ extends AbstractAsyncExceptionHandler<AsyncLoggerConfigDisruptor.Log4jEventWrapper> {
}
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/9d57fe27/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerDefaultExceptionHandler.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerDefaultExceptionHandler.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerDefaultExceptionHandler.java
index e224e1e..6f1eea5 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerDefaultExceptionHandler.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerDefaultExceptionHandler.java
@@ -16,37 +16,8 @@
*/
package org.apache.logging.log4j.core.async;
-import com.lmax.disruptor.ExceptionHandler;
-
/**
* Default disruptor exception handler for errors that occur in the AsyncLogger background thread.
*/
-public class AsyncLoggerDefaultExceptionHandler implements ExceptionHandler<RingBufferLogEvent> {
-
- @Override
- public void handleEventException(final Throwable throwable, final long sequence, final RingBufferLogEvent event) {
- final StringBuilder sb = new StringBuilder(512);
- sb.append("AsyncLogger error handling event seq=").append(sequence).append(", value='");
- try {
- sb.append(event);
- } catch (final Exception ignored) {
- sb.append("[ERROR calling ").append(event.getClass()).append(".toString(): ");
- sb.append(ignored).append("]");
- }
- sb.append("':");
- System.err.println(sb);
- throwable.printStackTrace();
- }
-
- @Override
- public void handleOnStartException(final Throwable throwable) {
- System.err.println("AsyncLogger error starting:");
- throwable.printStackTrace();
- }
-
- @Override
- public void handleOnShutdownException(final Throwable throwable) {
- System.err.println("AsyncLogger error shutting down:");
- throwable.printStackTrace();
- }
+public class AsyncLoggerDefaultExceptionHandler extends AbstractAsyncExceptionHandler<RingBufferLogEvent> {
}
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/9d57fe27/log4j-core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerConfigErrorOnFormat.java
----------------------------------------------------------------------
diff --git a/log4j-core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerConfigErrorOnFormat.java b/log4j-core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerConfigErrorOnFormat.java
new file mode 100644
index 0000000..57ed7fd
--- /dev/null
+++ b/log4j-core/src/test/java/org/apache/logging/log4j/core/async/AsyncLoggerConfigErrorOnFormat.java
@@ -0,0 +1,101 @@
+/*
+ * 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 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.config.ConfigurationFactory;
+import org.apache.logging.log4j.core.impl.DefaultLogEventFactory;
+import org.apache.logging.log4j.message.AsynchronouslyFormattable;
+import org.apache.logging.log4j.message.Message;
+import org.junit.AfterClass;
+import org.junit.BeforeClass;
+import org.junit.Test;
+import org.junit.experimental.categories.Category;
+
+import java.io.BufferedReader;
+import java.io.File;
+import java.io.FileReader;
+
+import static org.hamcrest.Matchers.containsString;
+import static org.junit.Assert.assertNull;
+import static org.junit.Assert.assertThat;
+import static org.junit.Assert.assertTrue;
+
+@Category(AsyncLoggers.class)
+public class AsyncLoggerConfigErrorOnFormat {
+
+ @BeforeClass
+ public static void beforeClass() {
+ System.setProperty("log4j2.is.webapp", "false");
+ System.setProperty(ConfigurationFactory.CONFIGURATION_FILE_PROPERTY, "AsyncLoggerConfigErrorOnFormat.xml");
+ // Log4jLogEvent.toString invokes message.toString
+ System.setProperty("log4j2.logEventFactory", DefaultLogEventFactory.class.getName());
+ }
+
+ @AfterClass
+ public static void afterClass() {
+ System.clearProperty("log4j2.is.webapp");
+ System.clearProperty("log4j2.logEventFactory");
+ }
+
+ @Test
+ public void testError() throws Exception {
+ final File file = new File("target", "AsyncLoggerConfigErrorOnFormat.log");
+ assertTrue("Deleted old file before test", !file.exists() || file.delete());
+
+ final Logger log = LogManager.getLogger("com.foo.Bar");
+ log.info(new ThrowsErrorOnFormatMessage());
+ log.info("Second message");
+ CoreLoggerContexts.stopLoggerContext(file); // stop async thread
+
+ final BufferedReader reader = new BufferedReader(new FileReader(file));
+ final String line1 = reader.readLine();
+ final String line2 = reader.readLine();
+ reader.close();
+ file.delete();
+
+ assertThat(line1, containsString("Second message"));
+ assertNull("Expected only one line", line2);
+ }
+
+ @AsynchronouslyFormattable // Shouldn't call getFormattedMessage early
+ private static final class ThrowsErrorOnFormatMessage implements Message {
+
+ @Override
+ public String getFormattedMessage() {
+ throw new Error("getFormattedMessage invoked on " + Thread.currentThread().getName());
+ }
+
+ @Override
+ public String getFormat() {
+ return null;
+ }
+
+ @Override
+ public Object[] getParameters() {
+ return null;
+ }
+
+ @Override
+ public Throwable getThrowable() {
+ return null;
+ }
+ }
+}
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/9d57fe27/log4j-core/src/test/resources/AsyncLoggerConfigErrorOnFormat.xml
----------------------------------------------------------------------
diff --git a/log4j-core/src/test/resources/AsyncLoggerConfigErrorOnFormat.xml b/log4j-core/src/test/resources/AsyncLoggerConfigErrorOnFormat.xml
new file mode 100644
index 0000000..2b6f380
--- /dev/null
+++ b/log4j-core/src/test/resources/AsyncLoggerConfigErrorOnFormat.xml
@@ -0,0 +1,19 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<Configuration status="ERROR">
+ <Appenders>
+ <RandomAccessFile name="File"
+ fileName="target/AsyncLoggerConfigErrorOnFormat.log"
+ bufferedIO="false"
+ immediateFlush="true"
+ append="false">
+ <PatternLayout>
+ <Pattern>%d %p %c{1.} [%t] %m %ex%n</Pattern>
+ </PatternLayout>
+ </RandomAccessFile>
+ </Appenders>
+ <Loggers>
+ <AsyncRoot level="info">
+ <AppenderRef ref="File"/>
+ </AsyncRoot>
+ </Loggers>
+</Configuration>
http://git-wip-us.apache.org/repos/asf/logging-log4j2/blob/9d57fe27/src/changes/changes.xml
----------------------------------------------------------------------
diff --git a/src/changes/changes.xml b/src/changes/changes.xml
index fb0817f..687cb50 100644
--- a/src/changes/changes.xml
+++ b/src/changes/changes.xml
@@ -168,6 +168,9 @@
<action issue="LOG4J2-2331" dev="ckozak" type="fix" due-to="Mike Baranski">
RollingFileManager debug logging avoids string concatenation and errant braces in favor of parameterized logging.
</action>
+ <action issue="LOG4J2-2333" dev="ckozak" type="fix">
+ Handle errors thrown in default disruptor ExceptionHandler implementations to avoid killing background threads.
+ </action>
</release>
<release version="2.11.1" date="2018-MM-DD" description="GA Release 2.11.1">
<action issue="LOG4J2-2268" dev="rgoers" type="fix" due-to="Tilman Hausherr">
@@ -229,6 +232,9 @@
<action issue="LOG4J2-2331" dev="ckozak" type="fix" due-to="Mike Baranski">
RollingFileManager debug logging avoids string concatenation and errant braces in favor of parameterized logging.
</action>
+ <action issue="LOG4J2-2333" dev="ckozak" type="fix">
+ Handle errors thrown in default disruptor ExceptionHandler implementations to avoid killing background threads.
+ </action>
</release>
<release version="2.11.0" date="2018-xx-xx" description="GA Release 2.11.0">
<action issue="LOG4J2-2104" dev="rgoers" type="fix">