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 Em...@barclayscapital.com on 2009/12/09 16:53:30 UTC
Serious resource leak in Log4J/Log4JLogger
When running Apache Tomcat 5.0.28 configured with Apache Commons Logging
and Log4J there appears to be a serious resource leak which results from
the per thread Nested Diagnostic Context created by Log4J.
Consider the following usage scenario;
A Tomcat-5.0.28 server configured with 50 threads min, and 100 threads
max. And a VM heap of 400mb. The commons logging has been configured to
use Log4j-1.2.15
A Servlet which handles a reasonable volume of data (like a large sql
query or a big xml file) is written and emplaced at "/test"
A testing application can then be written which will deliberately create
100 simultaneous connections to Tomcat, each querying the "/test"
Servlet.
Upon hitting the thread limit of 50, Tomcat will create more threads to
reach its max of 100, each of these threads will in turn make a call to
org.apache.log4j.NDC.push(..) to create a new logging context per
thread. The testing application will then pause for a short while to
allow Tomcat to reduce the Thread count back to 50. When Tomcat reaches
50 threads, references to the previously created 50 temporary threads
are still held in the NDC hashtable. These threads are never freed
unless a call to org.apache.log4j.remove() is made either explicitly per
thread, or once to allow the lazy evaluation and cleanup.
As far as I can tell, in the way that Log4J is used within Tomcat and
Apache Commons Logging described here, this never happens, and the
Servlet developer certainly isn't responsible for calling
org.apache.log4j.remove() as they don't necessarily know they are even
using or deploying on Log4J.
The above scenario can be made to cause Tomcat to run out of memory in
as little as 15 minutes, with a 400mb heap.
As far as I know, this will affect all current and pervious versions of
Tomcat using Log4J and Apache Commons Logging, and any other application
servers with similar logging, i.e. JBoss.
The above results can be verified using a heap profiler in Java 1.6, and
many references to similar problems can be found online.
Emerson
_______________________________________________
This e-mail may contain information that is confidential, privileged or otherwise protected from disclosure. If you are not an intended recipient of this e-mail, do not duplicate or redistribute it by any means. Please delete it and any attachments and notify the sender that you have received it in error. Unless specifically indicated, this e-mail is not an offer to buy or sell or a solicitation to buy or sell any securities, investment products or other financial product or service, an official confirmation of any transaction, or an official statement of Barclays. Any views or opinions presented are solely those of the author and do not necessarily represent those of Barclays. This e-mail is subject to terms available at the following link: www.barcap.com/emaildisclaimer. By messaging with Barclays you consent to the foregoing. Barclays Capital is the investment banking division of Barclays Bank PLC, a company registered in England (number 1026167) with its registered office at 1 Churchill Place, London, E14 5HP. This email may relate to or be sent from other members of the Barclays Group.
_______________________________________________
RE: Serious resource leak in Log4J/Log4JLogger
Posted by Em...@barclayscapital.com.
Apologies, it appears that the developers do indeed call NDC.push() so the fault lies with them... although they do call NDC.pop()
Why is NDC.remove() not called from NDC.pop() do you know ?
A question remains as to whether this problem can occur in the usage created using the Apache Commons Logging framework, are you suggesting that in that scenario NDC.push() does not apply.
-----Original Message-----
From: Clarke, Emerson: IT (LDN)
Sent: 09 December 2009 17:02
To: log4j-dev@logging.apache.org
Cc: ceki@qos.ch
Subject: RE: Serious resource leak in Log4J/Log4JLogger
As far as I know, the developer has no knowledge of the fact that Log4J is being used from within Tomcat.
In the situation I described, the Apache Commons Logging framework is responsible for instantiating Log4J, and it would seem that responsibility should lie there. Although perhaps the problem is also a design issue with Log4J... it may not be possible for downstream users to call NDC.remove() in many of the ways that Log4J gets called from within class factories such as those used in Tomcat.
-----Original Message-----
From: Ceki Gülcü [mailto:ceki@qos.ch]
Sent: 09 December 2009 16:43
To: Log4J Developers List
Subject: Re: Serious resource leak in Log4J/Log4JLogger
Hello,
Is the developer knowingly calling NDC.push? If so, she should also
call NDC.remove() as documented in the NDC javadocs. However, you seem
to be saying that "Tomcat" or some other entity is calling NDC.push
without the developer's intervention, which if were true, I'd be quite
surprised about.
--
Ceki Gülcü
Logback: The reliable, generic, fast and flexible logging framework for Java.
http://logback.qos.ch
Emerson.Clarke@barclayscapital.com wrote:
> When running Apache Tomcat 5.0.28 configured with Apache Commons Logging
> and Log4J there appears to be a serious resource leak which results from
> the per thread Nested Diagnostic Context created by Log4J.
>
> Consider the following usage scenario;
>
> A Tomcat-5.0.28 server configured with 50 threads min, and 100 threads
> max. And a VM heap of 400mb. The commons logging has been configured to
> use Log4j-1.2.15
>
> A Servlet which handles a reasonable volume of data (like a large sql
> query or a big xml file) is written and emplaced at "/test"
>
> A testing application can then be written which will deliberately create
> 100 simultaneous connections to Tomcat, each querying the "/test" Servlet.
>
> Upon hitting the thread limit of 50, Tomcat will create more threads to
> reach its max of 100, each of these threads will in turn make a call to
> org.apache.log4j.NDC.push(..) to create a new logging context per
> thread. The testing application will then pause for a short while to
> allow Tomcat to reduce the Thread count back to 50. When Tomcat reaches
> 50 threads, references to the previously created 50 temporary threads
> are still held in the NDC hashtable. These threads are never freed
> unless a call to org.apache.log4j.remove() is made either explicitly per
> thread, or once to allow the lazy evaluation and cleanup.
>
> As far as I can tell, in the way that Log4J is used within Tomcat and
> Apache Commons Logging described here, this never happens, and the
> Servlet developer certainly isn't responsible for calling
> org.apache.log4j.remove() as they don't necessarily know they are even
> using or deploying on Log4J.
>
> The above scenario can be made to cause Tomcat to run out of memory in
> as little as 15 minutes, with a 400mb heap.
>
>
>
> As far as I know, this will affect all current and pervious versions of
> Tomcat using Log4J and Apache Commons Logging, and any other application
> servers with similar logging, i.e. JBoss.
>
> The above results can be verified using a heap profiler in Java 1.6, and
> many references to similar problems can be found online.
>
> Emerson
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org
_______________________________________________
This e-mail may contain information that is confidential, privileged or otherwise protected from disclosure. If you are not an intended recipient of this e-mail, do not duplicate or redistribute it by any means. Please delete it and any attachments and notify the sender that you have received it in error. Unless specifically indicated, this e-mail is not an offer to buy or sell or a solicitation to buy or sell any securities, investment products or other financial product or service, an official confirmation of any transaction, or an official statement of Barclays. Any views or opinions presented are solely those of the author and do not necessarily represent those of Barclays. This e-mail is subject to terms available at the following link: www.barcap.com/emaildisclaimer. By messaging with Barclays you consent to the foregoing. Barclays Capital is the investment banking division of Barclays Bank PLC, a company registered in England (number 1026167) with its registered office at 1 Churchill Place, London, E14 5HP. This email may relate to or be sent from other members of the Barclays Group.
_______________________________________________
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org
_______________________________________________
This e-mail may contain information that is confidential, privileged or otherwise protected from disclosure. If you are not an intended recipient of this e-mail, do not duplicate or redistribute it by any means. Please delete it and any attachments and notify the sender that you have received it in error. Unless specifically indicated, this e-mail is not an offer to buy or sell or a solicitation to buy or sell any securities, investment products or other financial product or service, an official confirmation of any transaction, or an official statement of Barclays. Any views or opinions presented are solely those of the author and do not necessarily represent those of Barclays. This e-mail is subject to terms available at the following link: www.barcap.com/emaildisclaimer. By messaging with Barclays you consent to the foregoing. Barclays Capital is the investment banking division of Barclays Bank PLC, a company registered in England (number 1026167) with its registered office at 1 Churchill Place, London, E14 5HP. This email may relate to or be sent from other members of the Barclays Group.
_______________________________________________
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org
RE: Serious resource leak in Log4J/Log4JLogger
Posted by Em...@barclayscapital.com.
As far as I know, the developer has no knowledge of the fact that Log4J is being used from within Tomcat.
In the situation I described, the Apache Commons Logging framework is responsible for instantiating Log4J, and it would seem that responsibility should lie there. Although perhaps the problem is also a design issue with Log4J... it may not be possible for downstream users to call NDC.remove() in many of the ways that Log4J gets called from within class factories such as those used in Tomcat.
-----Original Message-----
From: Ceki Gülcü [mailto:ceki@qos.ch]
Sent: 09 December 2009 16:43
To: Log4J Developers List
Subject: Re: Serious resource leak in Log4J/Log4JLogger
Hello,
Is the developer knowingly calling NDC.push? If so, she should also
call NDC.remove() as documented in the NDC javadocs. However, you seem
to be saying that "Tomcat" or some other entity is calling NDC.push
without the developer's intervention, which if were true, I'd be quite
surprised about.
--
Ceki Gülcü
Logback: The reliable, generic, fast and flexible logging framework for Java.
http://logback.qos.ch
Emerson.Clarke@barclayscapital.com wrote:
> When running Apache Tomcat 5.0.28 configured with Apache Commons Logging
> and Log4J there appears to be a serious resource leak which results from
> the per thread Nested Diagnostic Context created by Log4J.
>
> Consider the following usage scenario;
>
> A Tomcat-5.0.28 server configured with 50 threads min, and 100 threads
> max. And a VM heap of 400mb. The commons logging has been configured to
> use Log4j-1.2.15
>
> A Servlet which handles a reasonable volume of data (like a large sql
> query or a big xml file) is written and emplaced at "/test"
>
> A testing application can then be written which will deliberately create
> 100 simultaneous connections to Tomcat, each querying the "/test" Servlet.
>
> Upon hitting the thread limit of 50, Tomcat will create more threads to
> reach its max of 100, each of these threads will in turn make a call to
> org.apache.log4j.NDC.push(..) to create a new logging context per
> thread. The testing application will then pause for a short while to
> allow Tomcat to reduce the Thread count back to 50. When Tomcat reaches
> 50 threads, references to the previously created 50 temporary threads
> are still held in the NDC hashtable. These threads are never freed
> unless a call to org.apache.log4j.remove() is made either explicitly per
> thread, or once to allow the lazy evaluation and cleanup.
>
> As far as I can tell, in the way that Log4J is used within Tomcat and
> Apache Commons Logging described here, this never happens, and the
> Servlet developer certainly isn't responsible for calling
> org.apache.log4j.remove() as they don't necessarily know they are even
> using or deploying on Log4J.
>
> The above scenario can be made to cause Tomcat to run out of memory in
> as little as 15 minutes, with a 400mb heap.
>
>
>
> As far as I know, this will affect all current and pervious versions of
> Tomcat using Log4J and Apache Commons Logging, and any other application
> servers with similar logging, i.e. JBoss.
>
> The above results can be verified using a heap profiler in Java 1.6, and
> many references to similar problems can be found online.
>
> Emerson
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org
_______________________________________________
This e-mail may contain information that is confidential, privileged or otherwise protected from disclosure. If you are not an intended recipient of this e-mail, do not duplicate or redistribute it by any means. Please delete it and any attachments and notify the sender that you have received it in error. Unless specifically indicated, this e-mail is not an offer to buy or sell or a solicitation to buy or sell any securities, investment products or other financial product or service, an official confirmation of any transaction, or an official statement of Barclays. Any views or opinions presented are solely those of the author and do not necessarily represent those of Barclays. This e-mail is subject to terms available at the following link: www.barcap.com/emaildisclaimer. By messaging with Barclays you consent to the foregoing. Barclays Capital is the investment banking division of Barclays Bank PLC, a company registered in England (number 1026167) with its registered office at 1 Churchill Place, London, E14 5HP. This email may relate to or be sent from other members of the Barclays Group.
_______________________________________________
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org
Re: Serious resource leak in Log4J/Log4JLogger
Posted by Ceki Gülcü <ce...@qos.ch>.
Hello,
Is the developer knowingly calling NDC.push? If so, she should also
call NDC.remove() as documented in the NDC javadocs. However, you seem
to be saying that "Tomcat" or some other entity is calling NDC.push
without the developer's intervention, which if were true, I'd be quite
surprised about.
--
Ceki Gülcü
Logback: The reliable, generic, fast and flexible logging framework for Java.
http://logback.qos.ch
Emerson.Clarke@barclayscapital.com wrote:
> When running Apache Tomcat 5.0.28 configured with Apache Commons Logging
> and Log4J there appears to be a serious resource leak which results from
> the per thread Nested Diagnostic Context created by Log4J.
>
> Consider the following usage scenario;
>
> A Tomcat-5.0.28 server configured with 50 threads min, and 100 threads
> max. And a VM heap of 400mb. The commons logging has been configured to
> use Log4j-1.2.15
>
> A Servlet which handles a reasonable volume of data (like a large sql
> query or a big xml file) is written and emplaced at “/test”
>
> A testing application can then be written which will deliberately create
> 100 simultaneous connections to Tomcat, each querying the “/test” Servlet.
>
> Upon hitting the thread limit of 50, Tomcat will create more threads to
> reach its max of 100, each of these threads will in turn make a call to
> org.apache.log4j.NDC.push(..) to create a new logging context per
> thread. The testing application will then pause for a short while to
> allow Tomcat to reduce the Thread count back to 50. When Tomcat reaches
> 50 threads, references to the previously created 50 temporary threads
> are still held in the NDC hashtable. These threads are never freed
> unless a call to org.apache.log4j.remove() is made either explicitly per
> thread, or once to allow the lazy evaluation and cleanup.
>
> As far as I can tell, in the way that Log4J is used within Tomcat and
> Apache Commons Logging described here, this never happens, and the
> Servlet developer certainly isn’t responsible for calling
> org.apache.log4j.remove() as they don’t necessarily know they are even
> using or deploying on Log4J.
>
> The above scenario can be made to cause Tomcat to run out of memory in
> as little as 15 minutes, with a 400mb heap.
>
>
>
> As far as I know, this will affect all current and pervious versions of
> Tomcat using Log4J and Apache Commons Logging, and any other application
> servers with similar logging, i.e. JBoss.
>
> The above results can be verified using a heap profiler in Java 1.6, and
> many references to similar problems can be found online.
>
> Emerson
---------------------------------------------------------------------
To unsubscribe, e-mail: log4j-dev-unsubscribe@logging.apache.org
For additional commands, e-mail: log4j-dev-help@logging.apache.org