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 196260 - Big projects - IDE consumes CPU when idle
Summary: Big projects - IDE consumes CPU when idle
Status: RESOLVED FIXED
Alias: None
Product: cnd
Classification: Unclassified
Component: Project (show other bugs)
Version: 7.0
Hardware: PC Linux
: P2 normal (vote)
Assignee: Alexander Simon
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2011-03-03 20:55 UTC by Egor Ushakov
Modified: 2011-03-09 10:08 UTC (History)
1 user (show)

See Also:
Issue Type: DEFECT
Exception Reporter:


Attachments
snapshot (1.33 MB, application/octet-stream)
2011-03-03 20:55 UTC, Egor Ushakov
Details
stacktrace (23.58 KB, text/plain)
2011-03-03 20:56 UTC, Egor Ushakov
Details
another snapshot (226.50 KB, application/octet-stream)
2011-03-03 20:56 UTC, Egor Ushakov
Details
another stacktrace (18.27 KB, text/plain)
2011-03-03 20:57 UTC, Egor Ushakov
Details
snapshot after focus change (179.98 KB, application/octet-stream)
2011-03-03 23:55 UTC, Egor Ushakov
Details
snapshot from idle IDE (48.28 KB, application/octet-stream)
2011-03-04 01:02 UTC, Egor Ushakov
Details
new snapshot after focus change (249.84 KB, application/octet-stream)
2011-03-04 20:48 UTC, Egor Ushakov
Details
snapshot of full project open (936.08 KB, application/octet-stream)
2011-03-04 21:06 UTC, Egor Ushakov
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Egor Ushakov 2011-03-03 20:55:48 UTC
Created attachment 106673 [details]
snapshot

Steps to reproduce:
- create a very big project from sources
- wait until all import steps and parsing are finished
IDE will still a lot of cpu power,
I attach stacktraces and snapshots
Comment 1 Egor Ushakov 2011-03-03 20:56:19 UTC
Created attachment 106674 [details]
stacktrace
Comment 2 Egor Ushakov 2011-03-03 20:56:42 UTC
Created attachment 106675 [details]
another snapshot
Comment 3 Egor Ushakov 2011-03-03 20:57:03 UTC
Created attachment 106676 [details]
another stacktrace
Comment 4 Egor Ushakov 2011-03-03 20:58:03 UTC
sorry for mistype:
IDE will still consume a lot of CPU even when idle
Comment 5 Egor Ushakov 2011-03-03 21:11:14 UTC
It will stop after some time if you do not touch the IDE but once you're back it will start again
Comment 6 Alexander Simon 2011-03-03 21:21:32 UTC
(In reply to comment #0)
> Created an attachment (id=106673) [details]
> snapshot
> 
> Steps to reproduce:
> - create a very big project from sources
What is a very big project?
How many files project contains?
Do you have example of such project?
How many memory did you give NB?
Comment 7 Egor Ushakov 2011-03-03 21:29:41 UTC
The project is jdk,
NB had ~1Gb of max memory
Comment 8 Vladimir Voskresensky 2011-03-03 23:02:10 UTC
Egor, either give it 2Gb or use 32bit java
Comment 9 Egor Ushakov 2011-03-03 23:16:38 UTC
With 2gb of memory it still utilize 100% of one core for several minutes on every foxus change.
Is it checking for external changes again?
File system load is not very big, but CPU load is huge.
Comment 10 Vladimir Voskresensky 2011-03-03 23:24:30 UTC
what's your system? Solaris?
I see thread "Attach listeners to all disk folders" and "Refresh-After-WindowActivated" in the first stack
and
only "Attach listeners to all disk folders" in the second.

"Attach listeners to all disk folders" activity should be finished although takes time.

What's in stack after completeness of that activity and next focus change? "Refresh-After-WindowActivated"?
Are you on Linux? Solaris?
Comment 11 Egor Ushakov 2011-03-03 23:28:30 UTC
It is Ubuntu 10.10, I think second snapshot is all about the situation after focus change. I will attach another one.
Comment 12 Egor Ushakov 2011-03-03 23:55:22 UTC
Created attachment 106680 [details]
snapshot after focus change
Comment 13 Vladimir Voskresensky 2011-03-04 00:49:00 UTC
there are two greedy processes, all others are in wait or timed_wait states:
- File Watcher - 100% on CPU
-- impl of native Linux watcher
- Waiter Number 0 - 100% on CPU
-- com.sun.tools.swdev.glue.CBInfo$Waiter.run()
Comment 14 Leonid Lenyashin 2011-03-04 00:56:08 UTC
(In reply to comment #13)
> there are two greedy processes, all others are in wait or timed_wait states:
> - File Watcher - 100% on CPU
> -- impl of native Linux watcher
> - Waiter Number 0 - 100% on CPU
> -- com.sun.tools.swdev.glue.CBInfo$Waiter.run()

Wow... That is scary
Comment 15 Egor Ushakov 2011-03-04 01:02:56 UTC
Created attachment 106684 [details]
snapshot from idle IDE

I think they are both blocked in native code and java profiler shows them as 100% though it is not true.
Here is a snapshot from really idle IDE (cpu consumption is almost zero), the same 100% for both of them.
Conclusion: it is NOT native Linux watcher or glue.CBInfo$Waiter consuming CPU
Comment 16 Vladimir Voskresensky 2011-03-04 01:22:48 UTC
then, please, provide threads dump, not profiler snaps
Comment 17 Vladimir Voskresensky 2011-03-04 01:28:09 UTC
(In reply to comment #15)
> Created an attachment (id=106684) [details]
> snapshot from idle IDE
> 
> I think they are both blocked in native code and java profiler shows them as
> 100% though it is not true.
I'm not sure... below is part of thread from my idle java ide

"File Watcher" prio=10 tid=0x09a47400 nid=0x76d0 runnable [0x945f6000]
   java.lang.Thread.State: RUNNABLE
	at com.sun.jna.Function.invokeInt(Native Method)
	at com.sun.jna.Function.invoke(Function.java:344)
	at com.sun.jna.Function.invoke(Function.java:276)
	at com.sun.jna.Library$Handler.invoke(Library.java:216)
	at org.netbeans.modules.masterfs.watcher.$Proxy6.read(Unknown Source)
	at org.netbeans.modules.masterfs.watcher.LinuxNotifier.nextEvent(LinuxNotifier.java:122)
	at org.netbeans.modules.masterfs.watcher.Watcher$Ext.run(Watcher.java:176)
	at java.lang.Thread.run(Thread.java:619)
Comment 18 Alexander Simon 2011-03-04 11:22:04 UTC
Investigation of user project:
1. Recursive ls on surce root:
#time ls -R > /dev/null
gets:
real    1m57.201s
2. Project has 9 different hg repositories  (in different subfolders under source root).
3. Project has about 80K files.
Comment 19 Alexander Simon 2011-03-04 11:33:18 UTC
another user project statistic:
Number of C/C++ files:
- *.c   1196
- *.h   1320
- *.cpp 1362
- *.hpp  994
Comment 20 Alexander Simon 2011-03-04 12:09:30 UTC
Analyzing snap shots show that:
- IDE consume CPU for refreshing file system every time when IDE gets focus.
- CND one time after project creating/opening makes recursive ls to find changes in project view. It takes 37 seconds in background thread and cannot be issue.

So reassign to file system to evaluation.
Comment 21 Jaroslav Tulach 2011-03-04 14:18:35 UTC
The cpuload6.npss shows that there is at least 500 folders being refreshed. You need to find out which ones are that. I'd suggest to enable logging for
-J-Dorg.netbeans.modules.masterfs.REFRESH.level=FINEST

Btw. The folders under addRecursiveListener(...) root (e.g. most of files in classical projects) are not refreshed on window activation. It seems like you have more than 500 directories outside of project source roots...
Comment 22 Egor Ushakov 2011-03-04 14:35:50 UTC
It looks like we do not add source folder to the project source roots
Comment 23 Vladimir Voskresensky 2011-03-04 15:55:59 UTC
It's not true.
the reason is usage of FileUtil.addFileChangeListener(this, folderFile); 
500 times instead of 
FileUtil.addRecursiveListener(this, folderFile);
once for top level folder
Comment 24 Alexander Simon 2011-03-04 16:56:49 UTC
fixed, change set:
http://hg.netbeans.org/cnd-main/rev/bf01559d10c6
Comment 25 Egor Ushakov 2011-03-04 20:48:51 UTC
Created attachment 106731 [details]
new snapshot after focus change

Fix helped but after focus change I still see ~1 minute of cpu load
Comment 26 Egor Ushakov 2011-03-04 21:06:08 UTC
Created attachment 106732 [details]
snapshot of full project open

add listeners still takes very long with no visual notification to user
Comment 27 Quality Engineering 2011-03-05 05:42:35 UTC
Integrated into 'main-golden', will be available in build *201103050000* on http://bits.netbeans.org/dev/nightly/ (upload may still be in progress)
Changeset: http://hg.netbeans.org/main/rev/bf01559d10c6
User: Alexander Simon <alexvsimon@netbeans.org>
Log: fixed  Bug #196260 Big projects - IDE consumes CPU when idle
Comment 28 Vladimir Voskresensky 2011-03-05 16:53:11 UTC
I can see that cnd holds references to 16K FileObjects
But refresh takes just 7-9 seconds second time and further.

FS.refresh statistics (16,464FileObjects):
  FileSystem refresh: 1 calls in 7288ms
  Invocation of FileChangeListeners: 0 calls in 0ms
  Folder refresh: 0 calls in 0ms
  File refresh: 10 calls in 1ms
Comment 29 Vladimir Voskresensky 2011-03-05 17:00:57 UTC
If I turn on FINEST logging and leave on FINE
FS.refresh statistics (16,439FileObjects):
  FileSystem refresh: 1 calls in 773ms
  Invocation of FileChangeListeners: 0 calls in 0ms
  Folder refresh: 0 calls in 0ms
  File refresh: 10 calls in 0ms

So, it's really immediate
Comment 30 Vladimir Voskresensky 2011-03-05 17:06:25 UTC
attach listeners takes 8 sec
Let's check when you come back if can be reproduced
Comment 31 Egor Ushakov 2011-03-09 10:08:43 UTC
sources were on a mounted ntfs file system, that also could have been the issue