logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Remko Popma (JIRA)" <j...@apache.org>
Subject [jira] [Commented] (LOG4J2-1434) StringBuffer in thread local causes memory leaks.
Date Thu, 16 Jun 2016 07:12:05 GMT

    [ https://issues.apache.org/jira/browse/LOG4J2-1434?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=15333259#comment-15333259
] 

Remko Popma commented on LOG4J2-1434:
-------------------------------------

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: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org


Mime
View raw message