This Bugzilla instance is a read-only archive of historic NetBeans bug reports. To report a bug in NetBeans please follow the project's instructions for reporting issues.

Bug 189905 - PermGen leak through o.n.m.glassfish.common.LogViewMgr$LoggerRunnable
Summary: PermGen leak through o.n.m.glassfish.common.LogViewMgr$LoggerRunnable
Status: RESOLVED FIXED
Alias: None
Product: serverplugins
Classification: Unclassified
Component: GlassFish (show other bugs)
Version: 7.0
Hardware: All All
: P3 normal (vote)
Assignee: Vince Kraemer
URL:
Keywords: PERFORMANCE, RANDOM
: 188052 (view as bug list)
Depends on:
Blocks: 183587 190336
  Show dependency tree
 
Reported: 2010-08-26 12:13 UTC by Petr Jiricka
Modified: 2010-12-29 16:03 UTC (History)
5 users (show)

See Also:
Issue Type: DEFECT
Exception Reporter:


Attachments
Top 100 classloaders by the number of classes (7.55 KB, text/plain)
2010-08-26 12:13 UTC, Petr Jiricka
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Petr Jiricka 2010-08-26 12:13:29 UTC
Created attachment 101684 [details]
Top 100 classloaders by the number of classes

From time to time I am getting PermGen out of memory errors on Mac OS X 10.5.8 (64bit VM). Last time I saw this was on a build from ~Aug 17.

Tomas Hurka helped me analyze the heap dump, I am attaching the top 100 classloaders sorted by the number of classes.

Based on this output, there does not seem to be a leak, and these mostly seem to be just IDE classes. So, could it be that the default permgen setting (200 MB) is too small (especially given the fact that 64bit JDK takes up more space)?
Comment 1 Jaroslav Tulach 2010-08-26 13:36:15 UTC
Try to run with higher value and you'll see.
Comment 2 Petr Jiricka 2010-08-26 13:45:08 UTC
I can do that, but how does it help us decide about this issue? If I run with a higher permgen for a week and do not get a PermGen error, then we will increase the value in the launcher? What value should I test with? 300MB (currently 200MB)?
Comment 3 Petr Nejedly 2010-08-30 07:24:43 UTC
> Based on this output, there does not seem to be a leak
To the contrary, there is an obvious leak visible in the first few lines of your top-100 list

{ loader:org.apache.tools.ant.module.bridge.AntBridge$MainClassLoader#4, count:768, }
{ loader:org.apache.tools.ant.module.bridge.AntBridge$MainClassLoader#2, count:746, }
{ loader:org.apache.tools.ant.module.bridge.AntBridge$MainClassLoader#1, count:745, }
{ loader:org.apache.tools.ant.module.bridge.AntBridge$MainClassLoader#3, count:745, }
{ loader:org.apache.tools.ant.module.bridge.AntBridge$MainClassLoader#5, count:464, }

I see the Ant implementation loaded 5 times. Each case means ~10MB of permgen.
I have seen this before and Jesse was fixing something on this account for 6.9.
Comment 4 Jesse Glick 2010-09-20 20:15:21 UTC
I don't know why there would be multiple copies of the Ant core loaded. Are there leaking references to the older ones? If reproducible, I can fix.
Comment 5 Antonin Nebuzelsky 2010-10-12 12:48:27 UTC
Found one reproducible test case which most probably matches what PetrJ was doing in his IDE.

Each run of Enterprise Application ant-based project adds additional instance of org/apache/tools/ant/module/bridge/AntBridge$MainClassLoader. These instances are held on heap by instances of org.netbeans.modules.glassfish.common.LogViewMgr$LoggerRunnable.

See RP and readInputStreams() in LogViewMgr.

Reassigning to glassfish plugin.

jmap -permstat shows ~6.5M is held by each AntBridge$MainClassLoader.
Comment 6 Petr Hejl 2010-10-13 10:33:37 UTC
(In reply to comment #5)
> Found one reproducible test case which most probably matches what PetrJ was
> doing in his IDE.
> 
> Each run of Enterprise Application ant-based project adds additional instance
> of org/apache/tools/ant/module/bridge/AntBridge$MainClassLoader. These
> instances are held on heap by instances of
> org.netbeans.modules.glassfish.common.LogViewMgr$LoggerRunnable.
> 
> See RP and readInputStreams() in LogViewMgr.
> 
> Reassigning to glassfish plugin.
> 
> jmap -permstat shows ~6.5M is held by each AntBridge$MainClassLoader.

I can't reproduce it this way. There is still only one org/apache/tools/ant/module/bridge/AntBridge$MainClassLoader instance in my case.

Can you share a heap dump?
Comment 7 Antonin Nebuzelsky 2010-10-13 12:01:37 UTC
http://www.easy-share.com/1912613522/189905-heap.dump
Comment 8 Petr Hejl 2010-10-13 13:02:15 UTC
Does not seem to be reproducible in Linux.

Should the classloader count encrease with each run of same project or with each distinct project executed?
Comment 9 Antonin Nebuzelsky 2010-10-13 13:51:49 UTC
> Does not seem to be reproducible in Linux.

I am on Linux. I don't think this is platform dependent in any way.

> Should the classloader count encrease with each run of same project
> or with each distinct project executed?

In my case it was one EE project.
Comment 10 Petr Hejl 2010-10-13 14:46:31 UTC
I don't see the real problem in thread dump. There are two instances of AntBridge$MainClassLoader. There are two instances of LogViewMgr, which I think is ok (output and error stream).

Reference chain to the first classloader is as follows

Java Local Reference (from org.openide.util.RequestProcessor$Processor@0x73d82980) :
--> org.netbeans.modules.glassfish.common.LogViewMgr$LoggerRunnable@0x73ea8208 (22 bytes) (field this$0:)
--> org.netbeans.modules.glassfish.common.LogViewMgr@0x73eb7a38 (72 bytes) (??:)
--> class org.netbeans.modules.glassfish.common.LogViewMgr (84 bytes) (static field RP:)
--> org.openide.util.RequestProcessor@0x73ea81d8 (43 bytes) (field processors:)
--> java.util.HashSet@0x73eb7b08 (12 bytes) (field map:)
--> java.util.HashMap@0x73ec9198 (40 bytes) (field table:)
--> [Ljava.util.HashMap$Entry;@0x73ed3508 (72 bytes) (Element 6 of [Ljava.util.HashMap$Entry;@0x73ed3508:)
--> java.util.HashMap$Entry@0x73eda4e8 (24 bytes) (field key:)
--> org.openide.util.RequestProcessor$Processor@0x73d82980 (117 bytes) (field inheritedAccessControlContext:)
--> java.security.AccessControlContext@0x73d8b390 (21 bytes) (field context:)
--> [Ljava.security.ProtectionDomain;@0x73d8bf08 (64 bytes) (Element 13 of [Ljava.security.ProtectionDomain;@0x73d8bf08:)
--> java.security.ProtectionDomain@0x73642c50 (30 bytes) (field classloader:)
--> org.apache.tools.ant.module.bridge.AuxClassLoader@0x7363a9e8 (66 bytes) (field acc:)
--> java.security.AccessControlContext@0x7363af10 (21 bytes) (field context:)
--> [Ljava.security.ProtectionDomain;@0x7363af28 (28 bytes) (Element 4 of [Ljava.security.ProtectionDomain;@0x7363af28:)
--> java.security.ProtectionDomain@0x735f8000 (30 bytes) (field classloader:)
--> org.apache.tools.ant.module.bridge.AuxClassLoader@0x735f7fb8 (66 bytes) (field parent:)
--> org.apache.tools.ant.module.bridge.AntBridge$MainClassLoader@0x735f7ec8 (62 bytes) 

And to the second:

Java Local Reference (from org.openide.util.RequestProcessor$Processor@0x73d82980) :
--> org.netbeans.modules.glassfish.common.LogViewMgr$LoggerRunnable@0x73ea8208 (22 bytes) (field this$0:)
--> org.netbeans.modules.glassfish.common.LogViewMgr@0x73eb7a38 (72 bytes) (??:)
--> class org.netbeans.modules.glassfish.common.LogViewMgr (84 bytes) (static field RP:)
--> org.openide.util.RequestProcessor@0x73ea81d8 (43 bytes) (field processors:)
--> java.util.HashSet@0x73eb7b08 (12 bytes) (field map:)
--> java.util.HashMap@0x73ec9198 (40 bytes) (field table:)
--> [Ljava.util.HashMap$Entry;@0x73ed3508 (72 bytes) (Element 6 of [Ljava.util.HashMap$Entry;@0x73ed3508:)
--> java.util.HashMap$Entry@0x73eda4e8 (24 bytes) (field key:)
--> org.openide.util.RequestProcessor$Processor@0x73d82980 (117 bytes) (field inheritedAccessControlContext:)
--> java.security.AccessControlContext@0x73d8b390 (21 bytes) (field context:)
--> [Ljava.security.ProtectionDomain;@0x73d8bf08 (64 bytes) (Element 12 of [Ljava.security.ProtectionDomain;@0x73d8bf08:)
--> java.security.ProtectionDomain@0x73640440 (30 bytes) (field classloader:)
--> org.apache.tools.ant.module.bridge.AntBridge$MainClassLoader@0x7363a668 (62 bytes) 

So these are held from RequestProcessor. I'm not sure what could be wrong here.


In my case when everything works (I'm not able to reproduce) the chain is

Java Local Reference (from org.openide.util.RequestProcessor$Processor@0x7fd7b3ac3f70) :
--> org.netbeans.modules.glassfish.common.LogViewMgr$LoggerRunnable@0x7fd7d241ee20 (42 bytes) (??:)
--> class org.netbeans.modules.glassfish.common.LogViewMgr$LoggerRunnable (160 bytes) (??:)
--> org.netbeans.StandardModule$OneModuleClassLoader@0x7fd7b42e27e0 (166 bytes) (field parent:)
--> sun.misc.Launcher$AppClassLoader@0x7fd7b3aa2258 (122 bytes) (field classes:)
--> java.util.Vector@0x7fd7b3aa57e0 (36 bytes) (field elementData:)
--> [Ljava.lang.Object;@0x7fd7b3aa5808 (2576 bytes) (Element 44 of [Ljava.lang.Object;@0x7fd7b3aa5808:)
--> class org.openide.util.RequestProcessor$Processor (160 bytes) (static field pool:)
--> java.util.Stack@0x7fd7b37979a8 (36 bytes) (field elementData:)
--> [Ljava.lang.Object;@0x7fd7b7be25a8 (176 bytes) (Element 3 of [Ljava.lang.Object;@0x7fd7b7be25a8:)
--> org.openide.util.RequestProcessor$Processor@0x7fd7b6175d40 (189 bytes) (field inheritableThreadLocals:)
--> java.lang.ThreadLocal$ThreadLocalMap@0x7fd7b6176248 (32 bytes) (field table:)
--> [Ljava.lang.ThreadLocal$ThreadLocalMap$Entry;@0x7fd7b6176268 (144 bytes) (Element 9 of [Ljava.lang.ThreadLocal$ThreadLocalMap$Entry;@0x7fd7b6176268:)
--> java.lang.ThreadLocal$ThreadLocalMap$Entry@0x7fd7d2b32218 (56 bytes) (field value:)
--> org.apache.tools.ant.property.LocalPropertyStack@0x7fd7d2b32250 (24 bytes) (??:)
--> class org.apache.tools.ant.property.LocalPropertyStack (160 bytes) (??:)
--> org.apache.tools.ant.module.bridge.AntBridge$MainClassLoader@0x7fd7b778beb0 (122 bytes)
Comment 11 Petr Hejl 2010-10-13 14:53:05 UTC
To avoid confusion
 - two instances of classloader:I guess it is bad
 - however it is not related to two instances of LogViewMgr$LoggerRunnable which is ok

Looks like in Tonda's heapdump there is a reference from RP, while in my case there is no such reference.
Comment 12 Antonin Nebuzelsky 2010-10-13 15:47:30 UTC
Now I was playing with the same project and steps again to be able to write down exact steps. I saw one classloader, after more repetitions I saw two as in the attached heap dump, but then with more repetitions it did not increase. Yesterday I saw one-two and then three after one more repetion after summarizing the findings here. But, unfortunately, I cannot tell how to reproduce it consistently.
Comment 13 Vince Kraemer 2010-10-14 23:05:13 UTC
I am closing this as incomplete for now.  Re-open this issue if you get more info and steps to reproduce this.
Comment 14 Jesse Glick 2010-10-15 19:00:14 UTC
As to there being >1 instance of MainClassLoader: in the current code, the currently active AntInstance, which has one associated MCL (loading ant.jar etc.), is held with a SoftReference, permitting the Ant subsystem to be collected after all Ant processes are stopped. (If you change Ant configuration, such as the installation location, the AI is discarded.) Unfortunately this means that if someone holds an illegal reference to the MCL, it is possible for the AI to be collected when the MCL is not, so when the next Ant process is run, a new AI and a new MCL are created. I think I can fix this so that either both are collected or neither are, which should help mitigate the impact of leaks of this kind; they will only be observed as a leak in case you change Ant configuration.

In this case, it looks like use of RequestProcessor is the culprit: when the RP thread is created from inside an Ant task, its access control context somehow holds onto the Ant class loader involved in loading the custom task. Since the RP field is now static (see bug #183587), the processor created during a certain Ant run holds onto that context. I would recommend not using RP at all here; use a fresh Thread for each stream until it is closed. RP is anyway more useful for many tiny "requests" which should reuse a thread pool where possible, whereas in this case you have a handful of long-lived threads reading input.
Comment 15 Jesse Glick 2010-10-15 19:09:29 UTC
(In reply to comment #14)
> I think I can fix this so that either both are collected or neither are

core-main #b0c38a1866fe
Comment 16 Jesse Glick 2010-10-15 20:29:13 UTC
*** Bug 188052 has been marked as a duplicate of this bug. ***
Comment 17 Quality Engineering 2010-12-29 07:11:39 UTC
Integrated into 'main-golden', will be available in build *201012290001* on http://bits.netbeans.org/dev/nightly/ (upload may still be in progress)
Changeset: http://hg.netbeans.org/main/rev/424895eeef95
User: vince kraemer <vkraemer@netbeans.org>
Log: #189905 : remove RP to help prevent PermGen leak
Comment 18 Vince Kraemer 2010-12-29 16:03:18 UTC
in main