You are viewing a plain text version of this content. The canonical link for it is here.
Posted to log4j-dev@logging.apache.org by "Remko Popma (JIRA)" <ji...@apache.org> on 2015/10/21 05:17:28 UTC
[jira] [Issue Comment Deleted] (LOG4J2-1159) ThreadLocal leaks in
Tomcat8 (org.apache.logging.log4j.core.async.AsyncLogger.Info)
[ https://issues.apache.org/jira/browse/LOG4J2-1159?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Remko Popma updated LOG4J2-1159:
--------------------------------
Comment: was deleted
(was: {code}
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/LoggerContext.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/LoggerContext.java
index 57409ac..f82a760 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/LoggerContext.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/LoggerContext.java
@@ -30,11 +30,13 @@
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.core.async.AsyncLogger;
+import org.apache.logging.log4j.core.async.AsyncLoggerContextSelector;
import org.apache.logging.log4j.core.config.Configuration;
import org.apache.logging.log4j.core.config.ConfigurationFactory;
import org.apache.logging.log4j.core.config.ConfigurationListener;
import org.apache.logging.log4j.core.config.ConfigurationSource; // SUPPRESS CHECKSTYLE
import org.apache.logging.log4j.core.config.DefaultConfiguration;
+import org.apache.logging.log4j.core.config.LoggerConfig;
import org.apache.logging.log4j.core.config.NullConfiguration;
import org.apache.logging.log4j.core.config.Reconfigurable;
import org.apache.logging.log4j.core.impl.Log4jLogEvent;
@@ -460,12 +462,14 @@
LOGGER.error("Could not reconfigure JMX", t);
}
Log4jLogEvent.setNanoClock(NanoClockFactory.createNanoClock());
- try {
- AsyncLogger.setNanoClock(NanoClockFactory.createNanoClock());
- } catch (Throwable ignored) {
- // LMAX Disruptor jar may not be in the classpath. Ignore this.
- LOGGER.debug("Could not set AsyncLogger NanoClock. Ignoring: " + ignored.toString());
- }
+ if (AsyncLoggerContextSelector.isSelected()) {
+ try {
+ AsyncLogger.setNanoClock(NanoClockFactory.createNanoClock());
+ } catch (Throwable ignored) {
+ // LMAX Disruptor jar may not be in the classpath. Ignore this.
+ LOGGER.debug("Could not set AsyncLogger NanoClock. Ignoring: " + ignored.toString());
+ }
+ }
return prev;
} finally {
configLock.unlock();
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLogger.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLogger.java
index 032ecd1..b45dd10 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLogger.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLogger.java
@@ -115,9 +115,9 @@
private static final ExecutorService EXECUTOR = Executors.newSingleThreadExecutor(new DaemonThreadFactory(
"AsyncLogger-"));
+ private final ThreadLocal<Info> THREADLOCAL = new ThreadLocal<Info>();
static {
- initInfoForExecutorThread();
LOGGER.debug("AsyncLogger.ThreadNameStrategy={}", THREAD_NAME_STRATEGY);
final int ringBufferSize = calculateRingBufferSize();
@@ -141,6 +141,8 @@
*/
public AsyncLogger(final LoggerContext context, final String name, final MessageFactory messageFactory) {
super(context, name, messageFactory);
+ LOGGER.info("Created AsyncLogger " + name);
+ initInfoForExecutorThread();
}
private static int calculateRingBufferSize() {
@@ -167,14 +169,14 @@
* to {@code false}. This allows us to detect Logger.log() calls initiated from the appender thread, which may cause
* deadlock when the RingBuffer is full. (LOG4J2-471)
*/
- private static void initInfoForExecutorThread() {
+ private void initInfoForExecutorThread() {
EXECUTOR.submit(new Runnable() {
@Override
public void run() {
final boolean isAppenderThread = true;
final Info info = new Info(new RingBufferLogEventTranslator(), //
Thread.currentThread().getName(), isAppenderThread);
- Info.THREADLOCAL.set(info);
+ THREADLOCAL.set(info);
}
});
}
@@ -215,13 +217,6 @@
* Tuple with the event translator and thread name for a thread.
*/
static class Info {
- private static final ThreadLocal<Info> THREADLOCAL = new ThreadLocal<Info>() {
- @Override
- protected Info initialValue() {
- // by default, set isAppenderThread to false
- return new Info(new RingBufferLogEventTranslator(), Thread.currentThread().getName(), false);
- }
- };
private final RingBufferLogEventTranslator translator;
private final String cachedThreadName;
private final boolean isAppenderThread;
@@ -238,6 +233,16 @@
return THREAD_NAME_STRATEGY.getThreadName(this);
}
}
+
+ private Info getInfo() {
+ Info result = THREADLOCAL.get();
+ if (result == null) {
+ // by default, set isAppenderThread to false
+ result = new Info(new RingBufferLogEventTranslator(), Thread.currentThread().getName(), false);
+ THREADLOCAL.set(result);
+ }
+ return result;
+ }
@Override
public void logMessage(final String fqcn, final Level level, final Marker marker, final Message message,
@@ -253,7 +258,7 @@
private void logMessage0(final Disruptor<RingBufferLogEvent> theDisruptor, final String fqcn, final Level level,
final Marker marker, final Message message, final Throwable thrown) {
- final Info info = Info.THREADLOCAL.get();
+ final Info info = getInfo();
logMessageInAppropriateThread(info, theDisruptor, fqcn, level, marker, message, thrown);
}
@@ -406,7 +411,7 @@
}
temp.shutdown(); // busy-spins until all events currently in the disruptor have been processed
EXECUTOR.shutdown(); // finally, kill the processor thread
- Info.THREADLOCAL.remove(); // LOG4J2-323
+ // Info.THREADLOCAL.remove(); // LOG4J2-323
}
/**
diff --git a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerContextSelector.java b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerContextSelector.java
index c871a39..0dfe867 100644
--- a/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerContextSelector.java
+++ b/log4j-core/src/main/java/org/apache/logging/log4j/core/async/AsyncLoggerContextSelector.java
@@ -23,6 +23,8 @@
import org.apache.logging.log4j.core.LoggerContext;
import org.apache.logging.log4j.core.selector.ContextSelector;
+import org.apache.logging.log4j.core.util.Constants;
+import org.apache.logging.log4j.util.PropertiesUtil;
/**
* {@code ContextSelector} that returns the singleton {@code AsyncLoggerContext}.
@@ -33,6 +35,11 @@
private static final AsyncLoggerContext CONTEXT = new AsyncLoggerContext("AsyncLoggerContext@"
+ AsyncLoggerContext.class.hashCode());
+ public static boolean isSelected() {
+ return AsyncLoggerContextSelector.class.getName().equals(
+ PropertiesUtil.getProperties().getStringProperty(Constants.LOG4J_CONTEXT_SELECTOR));
+ }
+
@Override
public LoggerContext getContext(final String fqcn, final ClassLoader loader, final boolean currentContext) {
return CONTEXT;
{code})
> ThreadLocal leaks in Tomcat8 (org.apache.logging.log4j.core.async.AsyncLogger.Info)
> -----------------------------------------------------------------------------------
>
> Key: LOG4J2-1159
> URL: https://issues.apache.org/jira/browse/LOG4J2-1159
> Project: Log4j 2
> Issue Type: Bug
> Components: Core
> Affects Versions: 2.4, 2.4.1
> Reporter: Robin Jansohn
> Assignee: Remko Popma
> Fix For: 2.5
>
>
> Since v2.4 there a TreadLocal warnings reported by Tomcat. This happens even when the application is not configured to use Async Loggers.
> A minimal webapp to reproduce can be found here: https://github.com/jansohn/log4j2-threadlocal
> {noformat}
> WARNUNG: The web application [log4j2webapp] appears to have started a thread named [AsyncLogger-1] but has failed to stop it. This is very likely to create a memory leak. Stack trace of thread:
> sun.misc.Unsafe.park(Native Method)
> java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
> com.lmax.disruptor.BlockingWaitStrategy.waitFor(BlockingWaitStrategy.java:45)
> com.lmax.disruptor.ProcessingSequenceBarrier.waitFor(ProcessingSequenceBarrier.java:55)
> com.lmax.disruptor.BatchEventProcessor.run(BatchEventProcessor.java:123)
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> java.lang.Thread.run(Thread.java:745)
> Okt 14, 2015 1:06:48 PM org.apache.catalina.loader.WebappClassLoaderBase checkThreadLocalMapForLeaks
> SCHWERWIEGEND: The web application [log4j2webapp] created a ThreadLocal with key of type [org.apache.logging.log4j.core.async.AsyncLogger$Info$1] (value [org.apache.logging.log4j.core.async.AsyncLogger$Info$1@1d29f54]) and a value of type [org.apache.logging.log4j.core.async.AsyncLogger.Info] (value [org.apache.logging.log4j.core.async.AsyncLogger$Info@1ea59ba]) but failed to remove it when the web application was stopped. Threads are going to be renewed over time to try and avoid a probable memory leak.
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org