Re: Memory leak with log4j 2.13

[Ralph Goers <ra...@dslextreme.com>]

Attachments generally do not make it to the mailing lists. There is no leak report attached to the email.

I think you are going to have to explain a little more as to what your application was doing that would cause so many Console Appenders.  While there is a Default Configuration there is no such thing as a Default Console Appender. If you are passing custom patterns to the Console Appender then, by definition, you can’t possibly be using the Default Configuration. 

There should never be a reason for there to be more than one Console Appender in a Configuration. If you need multiple patterns Log4j provides a PatternSelector that you can configure on your Appender to do that. Note that these are not dynamically created - you use one of a few patterns based on data in the Log Event.   Because of this Log4j has no need to protect itself from the problem you describe because it is, plain and simple, user error.

It sounds like you have created custom code for Log4j 2. When migrating from Log4j 1 to Log4j 2 many teams seem to want to take the approach of “We have customization X, what do I have to do to make that customization to Log4j 2”. That is always the wrong approach.

The steps for migrations should be:
1. What are our requirements for logging?  What destinations do we need to log to and under what circumstances?
2. What facilities does Log4j 2 provide out of the box to meet those requirements?  
3. We aren’t sure which approach is the best to meet requirement n - we should seek advice on a Log4j mailing list or StackOverflow.
4. Based on those recommendations, implement what is left.


Ralph


> On Feb 26, 2020, at 5:25 AM, Srijith Kochunni <Sr...@microfocus.com> wrote:
> 
> Hi All,
>  
>              We recently upgraded our application to log4j 2.13 from log4j 1.2.15. Since the upgrade, we’ve noticed in one of our test setups that the application is running out of heap space. Upon inspecting the heap dump, we found that there are almost a 100 thousand entries in the HashMap owned by AbstractManager instance. Upon further investigation of the heap dump, we were able to determine that this is because a large number of Default Console Appender instances are being created. We have reason to suspect that one of our modules might be passing multiple different patterns during logging and the Pattern Layout is invoking the init of DefaultConfiguration due to the pattern being different every time. We are looking at determining the faulty modules and fixing them, but is there not a way to ensure these Console Appender instances are garbage collected later or turn off the creation of these Default Console Appender instances ? I did not see any such flags to stop this in the code but still wondering if we really need to have so many instances loaded in memory.
>  
>           I’ve attached the leak report here. Not attaching the heap dump, because I have some proprietary information on it. Saw a reference to https://issues.apache.org/jira/browse/LOG4J2-1176 <https://issues.apache.org/jira/browse/LOG4J2-1176> in the code, but the problem description did not match.
>  
>  
> Thanks,
> Srijith.

RE: Memory leak with log4j 2.13

[Srijith Kochunni <Sr...@microfocus.com>]

My Bad. I forgot the part about attachments. 

What we see in the leak report is as follows

The class "org.apache.logging.log4j.core.appender.AbstractManager", loaded by
"java.net.URLClassLoader @ 0x74083d7d0", occupies 1,702,398,136 (82.46%)
bytes. The memory is accumulated in one instance of "java.util.HashMap$Node[]"
loaded by "<system class loader>".
Keywords
java.net.URLClassLoader @ 0x74083d7d0
org.apache.logging.log4j.core.appender.AbstractManager
java.util.HashMap$Node[]

You're right, the problem is in our code. What we were doing incorrectly is that during logging of every message, we were instantiating the PatternLayout builder, by calling PatternLayout.newBuilder() which was the cause of the problem. This was falling back to DefaultConfiguration every time. The setToDefault method invoked in AbstractConfiguration was creating a ConsoleAppender every time for the new Configuration instance that was thus created. 

From your response, I understood that we should probably have had one Configuration created via ConfigurationFactory and have it passed around. We will look into it. If there are any specific links you want me to look at, do share.

Thanks,
Srijith.

-----Original Message-----
From: Ralph Goers <ra...@dslextreme.com> 
Sent: 26 February 2020 09:01
To: dev@logging.apache.org
Cc: Logging General <ge...@logging.apache.org>; Log4J Users List <lo...@logging.apache.org>; Sri Darshan Sreedharan <Sr...@microfocus.com>
Subject: Re: Memory leak with log4j 2.13

Caution: This email originated from outside the organization. Do not click links or open attachments unless you have verified this email is legitimate.



Attachments generally do not make it to the mailing lists. There is no leak report attached to the email.

I think you are going to have to explain a little more as to what your application was doing that would cause so many Console Appenders.  While there is a Default Configuration there is no such thing as a Default Console Appender. If you are passing custom patterns to the Console Appender then, by definition, you can’t possibly be using the Default Configuration.

There should never be a reason for there to be more than one Console Appender in a Configuration. If you need multiple patterns Log4j provides a PatternSelector that you can configure on your Appender to do that. Note that these are not dynamically created - you use one of a few patterns based on data in the Log Event.   Because of this Log4j has no need to protect itself from the problem you describe because it is, plain and simple, user error.

It sounds like you have created custom code for Log4j 2. When migrating from Log4j 1 to Log4j 2 many teams seem to want to take the approach of “We have customization X, what do I have to do to make that customization to Log4j 2”. That is always the wrong approach.

The steps for migrations should be:
1. What are our requirements for logging?  What destinations do we need to log to and under what circumstances?
2. What facilities does Log4j 2 provide out of the box to meet those requirements?
3. We aren’t sure which approach is the best to meet requirement n - we should seek advice on a Log4j mailing list or StackOverflow.
4. Based on those recommendations, implement what is left.


Ralph


> On Feb 26, 2020, at 5:25 AM, Srijith Kochunni <Sr...@microfocus.com> wrote:
>
> Hi All,
>
>              We recently upgraded our application to log4j 2.13 from log4j 1.2.15. Since the upgrade, we’ve noticed in one of our test setups that the application is running out of heap space. Upon inspecting the heap dump, we found that there are almost a 100 thousand entries in the HashMap owned by AbstractManager instance. Upon further investigation of the heap dump, we were able to determine that this is because a large number of Default Console Appender instances are being created. We have reason to suspect that one of our modules might be passing multiple different patterns during logging and the Pattern Layout is invoking the init of DefaultConfiguration due to the pattern being different every time. We are looking at determining the faulty modules and fixing them, but is there not a way to ensure these Console Appender instances are garbage collected later or turn off the creation of these Default Console Appender instances ? I did not see any such flags to stop this in the code but still wondering if we really need to have so many instances loaded in memory.
>
>           I’ve attached the leak report here. Not attaching the heap dump, because I have some proprietary information on it. Saw a reference to https://issues.apache.org/jira/browse/LOG4J2-1176 <https://issues.apache.org/jira/browse/LOG4J2-1176> in the code, but the problem description did not match.
>
>
> Thanks,
> Srijith.