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 185688 - Saving a self-profiling snapshot is very, very slow
Summary: Saving a self-profiling snapshot is very, very slow
Status: RESOLVED WORKSFORME
Alias: None
Product: profiler
Classification: Unclassified
Component: Ide (show other bugs)
Version: 6.x
Hardware: PC Mac OS X
: P3 normal (vote)
Assignee: issues@profiler
URL:
Keywords: PERFORMANCE
: 186691 (view as bug list)
Depends on:
Blocks:
 
Reported: 2010-05-07 12:03 UTC by Petr Jiricka
Modified: 2011-02-03 10:46 UTC (History)
4 users (show)

See Also:
Issue Type: DEFECT
Exception Reporter:


Attachments
Thread dumps + console output (143.14 KB, text/plain)
2010-05-07 12:03 UTC, Petr Jiricka
Details
Screenshot of the heap dump (178.17 KB, image/png)
2010-05-07 14:27 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-05-07 12:03:49 UTC
Created attachment 98619 [details]
Thread dumps + console output

I initiated the Profile Me button during scanning. Then when I finished profiling (still during scanning), the "Saving Snapshot" progress bar appeared, but it is taking a very long time. After 13 minutes the progress bar is at 25%, so it looks like it is going to take an hour. I am attaching a few thread dumps intermixed with IDE console output.
Comment 1 Tomas Pavek 2010-05-07 12:26:59 UTC
IDE build number?

Saving a self-profiling snapshot is not that slow, under normal conditions it is significantly shorter than the duration of profiling.

The log contains "Not enough memory to compile folder..." several times, so I guess the slowness was due to low free memory. Can you reproduce it and watch the memory usage, possibly create a heap dump?
Comment 2 Petr Jiricka 2010-05-07 14:27:56 UTC
Created attachment 98633 [details]
Screenshot of the heap dump

It's today's continuous build web-main #3183. I am afraid I may not be able to reproduce. I created a thread dump after everything finished and NetBeans calmed down (330 MB), and did not see anything suspicious when I computed the retained sizes - I can provide the file. I am attaching the screenshot of the heap dump overview + retained sizes.
Comment 3 Petr Nejedly 2010-05-07 15:47:18 UTC
From the original log:
concurrent mark-sweep generation total 481728K, used 434903K 

That means the heap was almost full and the concurrent collector was running all the time. Either concurrently or maybe even in the stop-the-world fashion.
Comment 4 Petr Nejedly 2010-05-07 16:04:39 UTC
The thread dump also uncovers slight problem with org.netbeans.modules.editor.errorstripe.AnnotationView - each instance creates its own RequestProcessor (almost OK) and all of them fire at once (problem).
This forces RP to allocate many threads and run all the tasks in parallel.
It seems that during the startup, many AnnotationViews are created (how comes?*)
and they schedule a refresh for the same time (+100ms).
Ideally, the AnnotationView (or each such activity) should have single (static) shared RP and allocate tasks from that.

*) If that is caused by restoring many editor TopComponents, we have a problem with lazy loading. If it is caused by scanning w/o having the editors really opened, we have much bigger problem. If it is caused by, say, a property change event out of finished scanning through the already initialized editors, the solution is outlined above.
Comment 5 Jaroslav Tulach 2010-05-07 16:24:31 UTC
Will somebody morph this bug for Jan or will we rather create a new one?
Comment 6 Jan Lahoda 2010-05-07 17:45:50 UTC
(In reply to comment #5)
> Will somebody morph this bug for Jan or will we rather create a new one?

Local changeset c6d5f17ef82d will introduce one RP for all instances of AnnotationView. It of course does not answer the question why all the AVs have been created at once.
Comment 7 Quality Engineering 2010-05-10 09:26:45 UTC
Integrated into 'main-golden', will be available in build *201005100200* on http://bits.netbeans.org/dev/nightly/ (upload may still be in progress)
Changeset: http://hg.netbeans.org/main/rev/
User: 
Log:
Comment 8 Petr Jiricka 2010-05-11 14:21:19 UTC
I saw this problem again in build web-main #3205, which includes Honza's partial fix. Please let me know how I can help to diagnose this. Thanks.
Comment 9 Petr Jiricka 2010-05-20 15:17:00 UTC
Still happening even in the latest build.
Comment 10 Tomas Pavek 2010-05-20 15:53:04 UTC
So what is the free heap memory (according to memory toolbar) when you start and when you are stopping the self-profiling? If the heap when stopping is close to limit, the sampler has problems creating the snapshot. Would be good to know what "close to limit" is in your case.

If we find the current sampler too demanding on memory for saving a snapshot, it might be worth considering to use the old sampler from profiler when possible (which OTOH has bigger overhead when collecting data).
Comment 11 Petr Jiricka 2010-05-21 07:31:09 UTC
You are right that even before self-profiling, the heap is already close to the limit (>450 MB). So there is a different problem other than the sampling code itself. I have a heap dump taken during the snapshot saving - jlahoda was helping me analyze it yesterday. 
Still, the memory overhead while the snapshot is being saved is >50 MB, which I think is quite a lot, considering the fact that the size of the resulting snapshot file on the disk is some 400 KB.
Comment 12 Tomas Pavek 2010-05-26 08:43:59 UTC
Reassigning to profiler - this issue can represent request to provide more efficient snapshot saving and opening (e.g. using the older sampler from profiler in an IDE that includes profiler).
Comment 13 Tomas Hurka 2010-05-27 06:41:57 UTC
*** Bug 186691 has been marked as a duplicate of this bug. ***
Comment 14 Tomas Hurka 2011-02-03 10:46:33 UTC
Closing as works-for-me. Please reopen, if you can reproduce it in recent dev. build. Thanks.