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 225028 - Out of memory: Too many FCLSupport$DispatchEventWrapper
Summary: Out of memory: Too many FCLSupport$DispatchEventWrapper
Status: RESOLVED WORKSFORME
Alias: None
Product: platform
Classification: Unclassified
Component: Filesystems (show other bugs)
Version: 7.3
Hardware: PC Solaris
: P1 normal (vote)
Assignee: Jaroslav Tulach
URL:
Keywords: PERFORMANCE
Depends on:
Blocks:
 
Reported: 2013-01-17 13:49 UTC by Alexander Simon
Modified: 2013-07-30 12:44 UTC (History)
3 users (show)

See Also:
Issue Type: DEFECT
Exception Reporter:


Attachments
1.3G in queue (2.20 MB, text/plain)
2013-01-18 11:14 UTC, Alexander Simon
Details
messages.log file (813.76 KB, text/x-log)
2013-07-24 11:36 UTC, Dusan Balek
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Alexander Simon 2013-01-17 13:49:42 UTC
IDE, ergonomics mode, info:
>Log Session: Thursday, January 17, 2013 5:23:44 PM MSK
>System Info: 
  Product Version         = NetBeans IDE Dev (Build 20130117-dd3f9558c33d) (#dd3f9558c33d)
  Operating System        = SunOS version 5.10 running on x86
  Java; VM; Vendor        = 1.7.0_11; Java HotSpot(TM) Client VM 23.6-b04; Oracle Corporation
  Runtime                 = Java(TM) SE Runtime Environment 1.7.0_11-b21
  Java Home               = /usr/jdk/instances/jdk1.7.0_11/jre


I create new C/C++ project with existing code.
Source code is located on auto mounted NFS.
While creating IDE print warnings:
WARNING [org.netbeans.modules.masterfs.filebasedfs.utils.FileChangedManager]: 3,754 ms in new File("/net/nbproject/project.xml").exists()
WARNING [org.netbeans.modules.masterfs.filebasedfs.utils.FileChangedManager]: 3,900 ms in new File("/net/pom.xml").exists()
WARNING [org.netbeans.modules.masterfs.filebasedfs.utils.FileChangedManager]: 2,904 ms in new File("/net/nbproject/project.xml").exists()
WARNING [org.netbeans.modules.masterfs.filebasedfs.utils.FileChangedManager]: 3,614 ms in new File("/net/grails-app").exists()
WARNING [org.netbeans.modules.masterfs.filebasedfs.utils.FileChangedManager]: 3,825 ms in new File("/net/nbproject/project.xml").exists()
WARNING [org.netbeans.modules.masterfs.filebasedfs.utils.FileChangedManager]: 3,877 ms in new File("/net/nbproject/project.xml").exists()
WARNING [org.netbeans.modules.masterfs.filebasedfs.utils.FileChangedManager]: 3,051 ms in new File("/net/nbproject/project.xml").exists()
WARNING [org.netbeans.modules.masterfs.filebasedfs.utils.FileChangedManager]: 4,227 ms in new File("/net/pom.xml").exists()
WARNING [org.netbeans.modules.masterfs.filebasedfs.utils.FileChangedManager]: 3,660 ms in new File("/net/nbproject/project.xml").exists()
WARNING [org.netbeans.modules.masterfs.filebasedfs.utils.FileChangedManager]: 3,862 ms in new File("/net/nbproject/project.xml").exists()
WARNING [org.netbeans.modules.masterfs.filebasedfs.utils.FileChangedManager]: 4,630 ms in new File("/net/nbproject/project.xml").exists()
WARNING [org.netbeans.modules.masterfs.filebasedfs.utils.FileChangedManager]: 2,782 ms in new File("/net/nbproject/project.xml").exists()
WARNING [org.netbeans.modules.masterfs.filebasedfs.utils.FileChangedManager]: 4,504 ms in new File("/net/grails-app").exists()
WARNING [org.netbeans.modules.masterfs.filebasedfs.utils.FileChangedManager]: 2,906 ms in new File("/net/nbproject/project.xml").exists()

Investigation:
One of the stack is:
org.netbeans.modules.masterfs.filebasedfs.utils.FileChangedManager.exists(FileChangedManager.java:162)
org.netbeans.modules.masterfs.filebasedfs.fileobjects.FileObjectFactory.touchExists(FileObjectFactory.java:396)
org.netbeans.modules.masterfs.filebasedfs.fileobjects.FileObjectFactory.issueIfExist(FileObjectFactory.java:334)
org.netbeans.modules.masterfs.filebasedfs.fileobjects.FileObjectFactory.getFileObject(FileObjectFactory.java:209)
org.netbeans.modules.masterfs.filebasedfs.fileobjects.FileObjectFactory.getValidFileObject(FileObjectFactory.java:734)
org.netbeans.modules.masterfs.filebasedfs.fileobjects.FolderObj.getFileObject(FolderObj.java:128)
org.netbeans.modules.ide.ergonomics.fod.FeatureProjectFactory$Data.hasFile(FeatureProjectFactory.java:155)
org.netbeans.modules.ide.ergonomics.fod.FeatureInfo.isNbProject(FeatureInfo.java:261)
org.netbeans.modules.ide.ergonomics.fod.FeatureInfo.isProject(FeatureInfo.java:177)
org.netbeans.modules.ide.ergonomics.fod.FeatureProjectFactory.loadProject(FeatureProjectFactory.java:238)
org.netbeans.api.project.ProjectManager.createProject(ProjectManager.java:371)
org.netbeans.api.project.ProjectManager.access$300(ProjectManager.java:86)
org.netbeans.api.project.ProjectManager$2.run(ProjectManager.java:292)
org.netbeans.api.project.ProjectManager$2.run(ProjectManager.java:235)
org.openide.util.Mutex.readAccess(Mutex.java:332)
org.netbeans.api.project.ProjectManager.findProject(ProjectManager.java:235)
org.netbeans.modules.projectapi.SimpleFileOwnerQueryImplementation.getOwner(SimpleFileOwnerQueryImplementation.java:129)
org.netbeans.api.project.FileOwnerQuery.getOwner(FileOwnerQuery.java:101)
org.netbeans.modules.csl.core.ProjectClassPathProvider.findClassPath(ProjectClassPathProvider.java:66)
org.netbeans.api.java.classpath.ClassPath.getClassPath(ClassPath.java:628)
org.netbeans.modules.parsing.impl.indexing.errors.Utilities.getSourceClassPathFor(Utilities.java:66)
org.netbeans.modules.parsing.impl.indexing.errors.ErrorAnnotator$1.run(ErrorAnnotator.java:315)
org.openide.util.RequestProcessor$Task.run(RequestProcessor.java:1454)
org.openide.util.RequestProcessor$Processor.run(RequestProcessor.java:2048)

Variables in classes:
f in ErrorAnnotator is:
/net/enum/export1/sside/oss_build/spicabuild32/src/lang@cf4be2e1:1f31c0
file in FileChangedManager is:
/net/nbproject/project.xml
Comment 1 Alexander Simon 2013-01-18 11:14:53 UTC
Created attachment 130356 [details]
1.3G in queue

It results to overflow Queue in org.openide.filesystems.FCLSupport.q 
and out of memory (1.3G in q see attached report)
Comment 2 Alexander Simon 2013-02-05 07:21:26 UTC
P2 because data lost due to OOM
Comment 3 Jan Lahoda 2013-02-05 10:23:48 UTC
From what I can say, ErrorAnnotator is legitimately asking for a ClassPath (on a background thread). I can't see why that should be a problem in ErrorAnnotator/parsing.api - seems more like a problem between ergonomics and filesystems.
Comment 4 Jaroslav Tulach 2013-02-06 11:32:06 UTC
#1: use faster disk.

#2: I don't see any relation between the warning and out of memory situation.

#3: Can you find out who creates so many org.openide.filesystems.FCLSupport$DispatchEventWrapper and why they don't get garbage collected?
Comment 5 Alexander Simon 2013-02-06 13:05:43 UTC
(In reply to comment #4)
> #1: use faster disk.
I use fast NFS folder, but IDE try to resolve unnecessary entries (/net/nbproject/project.xml, /net/grails-app, /net/pom.xml) nany times.

> #2: I don't see any relation between the warning and out of memory situation.
It is direct relation. If log contains a lot of FileChangedManager warnings, the probability of OOM is increased.
 
> #3: Can you find out who creates so many
> org.openide.filesystems.FCLSupport$DispatchEventWrapper and why they don't get
> garbage collected?
It seems I already explained.
FileChangedManager process slow events.
Change listener puts a lot of own events.
FileChangedManager query grows => OOM
Comment 6 Jaroslav Tulach 2013-02-08 11:50:04 UTC
I have a heap dump from Lahváč. There are two threads doing something with filesystem. I was trying to convince OQL in profiler to print me histogram of all listeners held in the linked list. Unsuccessfully. However it seems there is a lot of FileChangeImpl references.
Comment 7 Jan Lahoda 2013-02-26 08:38:55 UTC
Happens *very* often to me. Even right after starting the IDE, it is sometimes hogged for minutes trying to process the queue (I have seen heap dump with more than 5 *million* instances of the DispatchEventWrapper - that is clearly insane). And even if it handles to startup, it sometimes does the same after working with the IDE for some time. E.g. right now, my IDE is basically out-of-memory and unusable (shutdown is running for about 5 *minutes* now and still not done), and the heap histogram shows:
   1:      16655438      399730512  java.util.concurrent.ConcurrentLinkedQueue$Node
   2:      16655430      399730320  org.openide.filesystems.FCLSupport$DispatchEventWrapper
   3:        956446      124351232  [C
   4:        229121       99806288  [B
   5:        480398       33473336  [Ljava.lang.Object;
   6:        208405       33362712  <constMethodKlass>
   7:         21985       28702560  <constantPoolKlass>
   8:        895957       28670624  java.util.HashMap$Entry
   9:        208405       28360936  <methodKlass>
  10:        922167       22132008  java.lang.String

This really interferes with my daily work, so marking as P1.
Comment 8 Jan Lahoda 2013-02-27 15:26:35 UTC
Right now:
$ jmap -histo:live 8855
 num     #instances         #bytes  class name
----------------------------------------------
   1:       9349836      224396064  java.util.concurrent.ConcurrentLinkedQueue$Node
   2:       9349830      224395920  org.openide.filesystems.FCLSupport$DispatchEventWrapper
   3:        125395       57696264  [B
   4:        482419       53167216  [C
   5:        167849       27137488  <constMethodKlass>
   6:         17831       23677752  <constantPoolKlass>
   7:        167849       22844936  <methodKlass>
   8:        486803       15577696  java.util.HashMap$Entry
   9:         17831       14936504  <instanceKlassKlass>
  10:        199174       13925520  [Ljava.lang.Object;

What is so important on the DEW, that we need 9 *million* of them?
Comment 9 Jaroslav Tulach 2013-03-12 14:08:10 UTC
I don't know. I have never seen the problem. If you can run in debugging mode, let me know when reproduce, we can debug what is happening.
Comment 10 Jaroslav Tulach 2013-03-21 12:34:01 UTC
As I said, I have never seen the problem, but to allow better analysis, I am adding logging into creation of FileEvents: http://hg.netbeans.org/ergonomics/rev/d2652aab14d2
Comment 11 Dusan Balek 2013-07-24 11:35:22 UTC
Test J2SE project with two simple classes. More than 7 million of FCLSupport$DispatchEventWrapper instances in a couple of minutes. Attaching messages.log file with the additional logging of FileEvents creation enabled.
Comment 12 Dusan Balek 2013-07-24 11:36:58 UTC
Created attachment 137685 [details]
messages.log file
Comment 13 Jaroslav Tulach 2013-07-25 08:04:22 UTC
There is a lot of file events created for tmp directory. Looks like 80% of the log is filled by that:

~$ grep /tmp/ messages.log   | wc -l
4318
~$ wc -l messages.log 
4957 messages.log

Do you have any idea of what is happening in your /tmp directory, or why some part of the IDE listens on that directory?
Comment 14 Dusan Balek 2013-07-25 08:45:41 UTC
In reply to Comment 13:

No idea except of the fact that '/tmp/retouche' is my IDE userdir.
Comment 15 Jaroslav Tulach 2013-07-25 10:17:01 UTC
If the problem manifested itself only if your user directory is in /tmp, then we could lower the priority, I guess.
Comment 16 Jaroslav Tulach 2013-07-30 11:03:57 UTC
Dušane, have you managed to reproduce the bug with userdir elsewhere than in /tmp?
Comment 17 Dusan Balek 2013-07-30 11:20:32 UTC
Unfortunately, I'm not able to reproduce the issue now (even with userdir still present in /tmp/retouche) :-(
Comment 18 Jaroslav Tulach 2013-07-30 11:57:01 UTC
Who might have been creating files like /tmp/4d22d74770a59 in your temporary directory? Some unit test? Maybe that is a way to reproduce the problem.