logging-log4j-dev mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Luke Butters (JIRA)" <j...@apache.org>
Subject [jira] [Comment Edited] (LOG4J2-1434) StringBuffer in ThreadLocal can cause excessive memory usage after large log messages
Date Fri, 17 Jun 2016 22:57:05 GMT

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

Luke Butters edited comment on LOG4J2-1434 at 6/17/16 10:56 PM:
----------------------------------------------------------------

Yes I have experienced problems in micro bench marking before, so I think it will be useful.
Thank you.

So I imagine code would look like: (From https://github.com/apache/logging-log4j2/blob/73b4bcffeccc22fd148b4ccc9c0cba1516dcb519/log4j-core/src/main/java/org/apache/logging/log4j/core/layout/GelfLayout.java#L144
)
{code}
    @Override
    public byte[] toByteArray(final LogEvent event) {
    try(ThreadLocalStringBuilderProvider stringBuilderProvider = new ThreaLocalStringBuilderProvider())
{
        StringBuilder sb = stringBuilderProvider.getStringBuilder();
        final StringBuilder text = toText(event, sb, false);
        final byte[] bytes = getBytes(text.toString());
        return compressionType != CompressionType.OFF && bytes.length > compressionThreshold
? compress(bytes) : bytes;
    }
    }
{code}

Assuming the JVM does nothing special it is not garbage free, as I create a new object. To
get Java to show a warning when a resource is not closed, you have to create the resource
with the keyword {{new}}. Perhaps the JVM can however not create a new {{ThreadLocalStringBuilderProvider}}
and instead inline everything. 


was (Author: lukebutters7):
Yes I have experienced problems in micro bench marking before, so I think it will be useful.
Thank you.

So I imagine code would look like: (From https://github.com/apache/logging-log4j2/blob/73b4bcffeccc22fd148b4ccc9c0cba1516dcb519/log4j-core/src/main/java/org/apache/logging/log4j/core/layout/GelfLayout.java#L144
)
{code}
    @Override
    public byte[] toByteArray(final LogEvent event) {
    try(ThreadLocalStringBuilderProvider stringBuilderProvider = new ThreaLocalStringBuilderProvider())
{
        StringBuilder sb = stringBuilderProvider.getStringBuilder();
        final StringBuilder text = toText(event, sb, false);
        final byte[] bytes = getBytes(text.toString());
        return compressionType != CompressionType.OFF && bytes.length > compressionThreshold
? compress(bytes) : bytes;
    }
{code}

Assuming the JVM does nothing special it is not garbage free, as I create a new object. To
get Java to show a warning when a resource is not closed, you have to create the resource
with the keyword {{new}}. Perhaps the JVM can however not create a new {{ThreadLocalStringBuilderProvider}}
and instead inline everything. 

> StringBuffer in ThreadLocal can cause excessive memory usage after large log messages
> -------------------------------------------------------------------------------------
>
>                 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
>            Assignee: Remko Popma
>
> In an effort to speed up logging ThreadLocals have been introduced see LOG4J2-1125 however
this does causes memory issues.
> 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