[
https://issues.apache.org/jira/browse/LOG4J2-1434?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15333259#comment-15333259
]
Remko Popma edited comment on LOG4J2-1434 at 6/16/16 7:15 AM:
--------------------------------------------------------------
I did a lot of investigation in ThreadLocals and it turns out that ThreadLocals
only result in memory leaks if non-JDK classes are held in the ThreadLocal map.
Look at the Tomcat message:
{quote}
SEVERE: The web application \[App] created a ThreadLocal with key of type
\[org.apache.logging.log4j.core.layout.PatternLayout$1] (value
\[org.apache.logging.log4j.core.layout.PatternLayout$1@14391aaf]) and a value
of type \[java.lang.StringBuilder] (value \[2015-09-30 14:22:27.832
\[localhost-startStop-1] ERROR AppLogger - Error log. ]) 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.
{quote}
Notice that the _value_ is a StringBuilder, which is a JDK class and cannot
cause a memory leak. However, the _key_ in the threadlocal map is a
{{org.apache.logging.log4j.core.layout.PatternLayout$1}} inner class. Looking
at the
[diff|https://github.com/apache/logging-log4j2/commit/8025bb18ce4444b76822a7965776bb075bd52aa9]
you linked to, at that time PatternLayout code looked like this:
{code}
private static ThreadLocal<StringBuilder> strBuilder = new
ThreadLocal<StringBuilder>() { // anonymous inner class that subclasses
ThreadLocal
@Override
protected StringBuilder initialValue() {
return new StringBuilder(1024);
}
};
{code}
The above code creates an anonymous subclass of ThreadLocal, and this class is
loaded by the web application's class loader. This caused the memory leak
because the class was held in the threadlocal map and could not be garbage
collected. So the above idiom of providing an initial value in the declaration
was what caused the memory leak.
We have since then changed the way we use ThreadLocals. Log4j code now adheres
to the idiom below:
{code}
// just declare a plain ThreadLocal, don't create anonymous subclass to
populate initial value
private static final ThreadLocal<StringBuilder> threadLocal = new
ThreadLocal<>();
// all code interested in getting the cached StringBuilder needs to go through
this accessor method
protected static StringBuilder getStringBuilder() {
StringBuilder result = threadLocal.get();
if (result == null) {
result = new StringBuilder(DEFAULT_STRING_BUILDER_SIZE);
threadLocal.set(result);
}
result.setLength(0);
return result;
}
{code}
This avoids the creation of the anonymous subclass and therefore the key in the
threadlocal map is a plain JDK ThreadLocal, and the value is a plain JDK
StringBuilder. This will not cause memory leaks. So I disagree with your
statement that this issue was "ignored in LOG4J2-1142". It was addressed and
resolved.
For other places where we had to store non-JDK classes in ThreadLocals,
# the use of ThreadLocals is avoided if Log4j detects that it is used in a web
container: when the {{javax.servlet.Servlet}} class is in the classpath, or
when system property {{log4j2.is.webapp}} is set to "true"
# users can manually disable Log4j's use of non-JDK classes in ThreadLocals by
setting system property {{log4j2.enable.threadlocals}} to "false".
was (Author: [email protected]):
I did a lot of investigation in ThreadLocals and it turns out that ThreadLocals
only result in memory leaks if non-JDK classes are held in the ThreadLocal map.
Look at the Tomcat message:
{quote}
SEVERE: The web application \[App] created a ThreadLocal with key of type
\[org.apache.logging.log4j.core.layout.PatternLayout$1] (value
\[org.apache.logging.log4j.core.layout.PatternLayout$1@14391aaf]) and a value
of type \[java.lang.StringBuilder] (value \[2015-09-30 14:22:27.832
\[localhost-startStop-1] ERROR AppLogger - Error log. ]) 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.
{quote}
Notice that the _value_ is a StringBuilder, which is a JDK class and cannot
cause a memory leak. However, the _key_ in the threadlocal map is a
{{org.apache.logging.log4j.core.layout.PatternLayout$1}} inner class. Looking
at the
[diff|https://github.com/apache/logging-log4j2/commit/8025bb18ce4444b76822a7965776bb075bd52aa9]
you linked to, at that time PatternLayout code looked like this:
{code}
private static ThreadLocal<StringBuilder> strBuilder = new
ThreadLocal<StringBuilder>() { // anonymous inner class that subclasses
ThreadLocal
@Override
protected StringBuilder initialValue() {
return new StringBuilder(1024);
}
};
{code}
The above code creates an anonymous subclass of ThreadLocal, and this class is
loaded by the web application's class loader. This caused the memory leak
because the class was held in the threadlocal map and could not be garbage
collected. So the above idiom of providing an initial value in the declaration
was what caused the memory leak.
We have since then changed the way we use ThreadLocals. Log4j code now adheres
to the idiom below:
{code}
// just declare a plain ThreadLocal, don't create anonymous subclass to
populate initial value
private static final ThreadLocal<StringBuilder> threadLocal = new
ThreadLocal<>();
// all code interested in getting the cached StringBuilder needs to go through
this accessor method
protected static StringBuilder getStringBuilder() {
StringBuilder result = threadLocal.get();
if (result == null) {
result = new StringBuilder(DEFAULT_STRING_BUILDER_SIZE);
threadLocal.set(result);
}
result.setLength(0);
return result;
}
{code}
This avoids the creation of the anonymous subclass and therefore the key in the
threadlocal map is a plain JDK ThreadLocal, and the value is a plain JDK
StringBuilder. This will not cause memory leaks.
For other places where we had to store non-JDK classes in ThreadLocals,
# the use of ThreadLocals is avoided if Log4j detects that it is used in a web
container: when the {{javax.servlet.Servlet}} class is in the classpath, or
when system property {{log4j2.is.webapp}} is set to "true"
# users can manually disable Log4j's use of non-JDK classes in ThreadLocals by
setting system property {{log4j2.enable.threadlocals}} to "false".
> StringBuffer in thread local causes memory leaks.
> -------------------------------------------------
>
> Key: LOG4J2-1434
> URL: https://issues.apache.org/jira/browse/LOG4J2-1434
> Project: Log4j 2
> Issue Type: Bug
> Affects Versions: 2.6.1
> Reporter: Luke Butters
>
> In an effort to speed up logging ThreadLocals have been introduced see
> LOG4J2-1125 however this does causes memory issues reported
> http://stackoverflow.com/questions/32867327/log4j2-threadlocal-memory-leak-in-servletcontextlistener
> and subsequently ignored in LOG4J2-1142
> The problem of the ThreadLocal occurs when threads are re-used which is an
> absolutely valid way of using java. For example an executor service can
> re-use threads as well as Jetty.
> Below I demonstrate a contrived example of the memory leak:
> {code}
> int stringSize = 1024*1024*10; //~10MB maybe 20MB for UTF-16
> StringBuilder sb = new StringBuilder(stringSize);
> for(int i = 0; i < stringSize; i++) {
> sb.append('a' + i % 5);
> }
>
> String largeString = sb.toString();
>
> sb = null; //Let it be GC'ed
> ExecutorService es = Executors.newFixedThreadPool(100);
> final CountDownLatch countDownLatch = new CountDownLatch(100);
> for(int i = 0; i < 100; i++) {
> es.execute(()-> {
> //Log the big string to demonstrate the issue.
> log.fatal(largeString);
>
> //Ensure we use all 100 of our threads by not releasing this
> thread yet.
> countDownLatch.countDown();
> });
>
> //We sleep for 2s so we more easily watch memory growth
> Thread.sleep(2000);
> }
> {code}
> I recommend that log4j2 immediately remove the ThreadLocal as a small gain in
> performance does not outweigh the problems associated with memory leaks.
> Finally other options for caching the StringBuilder with a ThreadLocal could
> be considered for example we might re-use StringBuilders that are no larger
> than 3k while removing the ones which are larger than 3k.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
