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 205437 - OOME with enormous output produced by several instances of running user projects
Summary: OOME with enormous output produced by several instances of running user projects
Status: VERIFIED FIXED
Alias: None
Product: platform
Classification: Unclassified
Component: Output Window (show other bugs)
Version: 7.1
Hardware: PC All
: P2 normal with 3 votes (vote)
Assignee: Jaroslav Havlin
URL:
Keywords:
: 199744 204272 205538 207737 208172 (view as bug list)
Depends on:
Blocks:
 
Reported: 2011-11-22 16:25 UTC by misterm
Modified: 2012-02-10 10:42 UTC (History)
12 users (show)

See Also:
Issue Type: DEFECT
Exception Reporter: 183166


Attachments
messages.log (76.77 KB, application/octet-stream)
2011-11-23 13:04 UTC, misterm
Details
Ubuntu message log (152.41 KB, text/x-log)
2011-11-23 14:05 UTC, Michel Graciano
Details
Thread dump for Ubuntu (43.11 KB, text/plain)
2011-11-23 14:09 UTC, Michel Graciano
Details

Note You need to log in before you can comment on or make changes to this bug.
Description misterm 2011-11-22 16:25:37 UTC
Product Version: NetBeans IDE Dev (Build 20111122-b2ebb6bae35a)
Java: 1.6.0_19; Java HotSpot(TM) Client VM 16.2-b04
System: Windows 7 version 6.1 running on x86; Cp1252; en_US (nb)

After this is thrown, the IDE is unusable. Cannot even generate a thread dump (jstack):

java.lang.OutOfMemoryError
	at sun.misc.Unsafe.allocateMemory(Native Method)
	at java.nio.DirectByteBuffer.<init>(DirectByteBuffer.java:99)
	at java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:288)
	at sun.nio.ch.Util.getTemporaryDirectBuffer(Util.java:57)
	at sun.nio.ch.IOUtil.read(IOUtil.java:205)
	at sun.nio.ch.FileChannelImpl.read(FileChannelImpl.java:622)
	at org.netbeans.core.output2.FileMapStorage.getReadBuffer(FileMapStorage.java:360)
	at org.netbeans.core.output2.AbstractLines.getText(AbstractLines.java:135)
	at org.netbeans.core.output2.OutputDocument.getText(OutputDocument.java:214)
	at org.netbeans.core.output2.ExtPlainView.getText(ExtPlainView.java:170)
	at org.netbeans.core.output2.ExtPlainView.getLineWidth(ExtPlainView.java:310)
	at org.netbeans.core.output2.ExtPlainView.updateDamage(ExtPlainView.java:339)
	at javax.swing.text.PlainView.insertUpdate(PlainView.java:425)
	at javax.swing.plaf.basic.BasicTextUI$RootView.insertUpdate(BasicTextUI.java:1590)
	at javax.swing.plaf.basic.BasicTextUI$UpdateHandler.insertUpdate(BasicTextUI.java:1849)
	at org.netbeans.core.output2.OutputDocument.fireDocumentEvent(OutputDocument.java:501)
	at org.netbeans.core.output2.OutputDocument.stateChanged(OutputDocument.java:482)
	at org.netbeans.core.output2.AbstractLines.run(AbstractLines.java:246)
	at org.openide.util.Mutex.doEvent(Mutex.java:1341)
	at org.openide.util.Mutex.readAccess(Mutex.java:348)
	at org.netbeans.core.output2.AbstractLines.fire(AbstractLines.java:240)
	at org.netbeans.core.output2.AbstractLines.actionPerformed(AbstractLines.java:213)
	at javax.swing.Timer.fireActionPerformed(Timer.java:271)
	at javax.swing.Timer$DoPostEvent.run(Timer.java:201)
	at java.awt.event.InvocationEvent.dispatch(InvocationEvent.java:209)
	at java.awt.EventQueue.dispatchEvent(EventQueue.java:597)
	at org.netbeans.core.TimableEventQueue.dispatchEvent(TimableEventQueue.java:162)
	at java.awt.EventDispatchThread.pumpOneEventForFilters(EventDispatchThread.java:269)
	at java.awt.EventDispatchThread.pumpEventsForFilter(EventDispatchThread.java:184)
	at java.awt.EventDispatchThread.pumpEventsForHierarchy(EventDispatchThread.java:174)
	at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:169)
	at java.awt.EventDispatchThread.pumpEvents(EventDispatchThread.java:161)
	at java.awt.EventDispatchThread.run(EventDispatchThread.java:122)
Comment 1 Jiri Kovalsky 2011-11-22 16:44:44 UTC
It would be good to generate a heap dump next time this happens. Thanks Michael.
Comment 2 Petr Cyhelsky 2011-11-22 16:56:50 UTC
Can you please look into your ~/.netbeans/dev/var/log/ directory and look if there is a file heapdump.hprof or heapdump.hprof.old (it is generated automatically on OOME) and if so, zip it and somehow (using megashare.com or some other similar free service and paste link here) share it with us. Please reopen the issue when it is done.
Comment 3 Petr Cyhelsky 2011-11-22 16:59:55 UTC
And also if you have messages.log from that time please attach it here too.
Comment 4 misterm 2011-11-22 17:01:16 UTC
It neither generates the heap dump (or thread dump) automatically or on demand. It gives: Not enough storage is available to process this command .
Comment 5 misterm 2011-11-22 17:15:06 UTC
Ok, I was able to generate a heap dump:

http://www.MegaShare.com/3743311
Comment 6 Tomas Hurka 2011-11-23 07:50:55 UTC
(In reply to comment #5)
> Ok, I was able to generate a heap dump:
> 
> http://www.MegaShare.com/3743311

You don't need to 'generate'  heap dump. It is generated automatically by JVM. That's why Petr asked you to look for it in the userdir. Did you find it there?
Comment 7 Tomas Hurka 2011-11-23 07:51:53 UTC
(In reply to comment #0)
> Product Version: NetBeans IDE Dev (Build 20111122-b2ebb6bae35a)
> Java: 1.6.0_19; Java HotSpot(TM) Client VM 16.2-b04
> System: Windows 7 version 6.1 running on x86; Cp1252; en_US (nb)
> 
> After this is thrown, the IDE is unusable. 
[..] 
Please provide steps how to reproduce it. Thanks.
Comment 8 Tomas Hurka 2011-11-23 08:13:10 UTC
The heap dump shows that 500M is taken by org.netbeans.core.output2.HeapStorage. Assigning to platform/output window. The actual OOME is not OOME from heap, but from native Windows process.
Comment 9 Jaroslav Havlin 2011-11-23 09:23:23 UTC
Output data are normally stored in a file on the disk. Heap storage is used only if there is not enough space on the disk. It seems that you have very limited disk space and that your output is too big for your free memory as well.
Is this that case? If so, I'm afraid we can't do much about it.
Comment 10 misterm 2011-11-23 11:21:06 UTC
I have 220 GB of free space in this disk. I can also do the same thing in my NB 7.0 installation with no problems. This OOME happens at least 3 times per day using the daily build, sometimes more. I can tell it is related to the amount of info logged in the output window.
Comment 11 misterm 2011-11-23 11:22:11 UTC
The JVM couldn't generate the heap dump or the stack trace due to how constrained resources were. I've included the message I was getting in a previous comment.
Comment 12 Jaroslav Havlin 2011-11-23 12:24:25 UTC
That is quite strange. Could you please describe steps to reproduce (if any) and attach IDE log?
How many lines is in the output window when the IDE crashes? Could you write a simple program that generates some problematic output?
Thank you.
Comment 13 misterm 2011-11-23 12:26:51 UTC
I can try to reproduce it consistently, but I can assure you there is no relevant info in the messages log file, just the normal initialization messages and *sometimes* the stack trace for the OOME - it seems it gets so bad sometimes it cannot even log that. 

I will attach the messages.log for the next occurrence though anyway. I am just building the IDE right now.
Comment 14 misterm 2011-11-23 13:04:37 UTC
Created attachment 113467 [details]
messages.log
Comment 15 misterm 2011-11-23 13:07:13 UTC
Steps to reproduce:

1 - Create the following class:


package test;

import java.util.Arrays;

public class OutputCrasher {
   public static void main(String[] args) {
      for (int i = 0; i < 10000; i++) {
         char[] c = new char[1000];
         Arrays.fill(c, (char)('a' + 25 * Math.random()));
         System.out.println(new String(c));
      }
   }
}

2- Shift + F6 twice (while the first one is running, just to make it happen quicker)

Shouldn't take long for the IDE to freeze and to throw the OOME (around 1 min here).

10000 lines of log is pretty common for any application.
Comment 16 Jaroslav Havlin 2011-11-23 13:52:08 UTC
I am sorry, I was not able to reproduce it.

The problem originates probably in file <netbeans source dir>\core.output2\src\org\netbeans\core\output2\FileMapStorage.java, line 352.
Method FileChannel.map throws an IOException, then FileChanell.read is called instead of it to get some data, but OutOfMemoryError is thrown. Then FileMapStorage.lowDiskSpace is set to true (to prevent further errors), which means that HeapStorage will be used onwards and that even more memory will be needed.

Can you please debug NetBeans to see what happens in FileMapStorage, near line 352?

Thank you for your help.
Comment 17 misterm 2011-11-23 14:01:23 UTC
BTW, for some reason it is much easier to reproduce this using the standard cluster than the java cluster. java takes way longer and requires more parallel instances to be running (3 in my case).
Comment 18 Michel Graciano 2011-11-23 14:04:39 UTC
I was able to reproduce using my Ubuntu workstation. I ran 6 instances of the
proposed test case and after some minutes (something like 5 minutes) the IDE
frozen. I am uploading the heap dump right now and will attach the link here
asap.
Comment 19 Michel Graciano 2011-11-23 14:05:41 UTC
Created attachment 113472 [details]
Ubuntu message log
Comment 20 Michel Graciano 2011-11-23 14:09:48 UTC
Created attachment 113473 [details]
Thread dump for Ubuntu
Comment 21 Michel Graciano 2011-11-23 15:08:26 UTC
For the record, I tried it at 7.1RC1, with 6 instances running and it took 27 minutes and 3 seconds to finish without any problem, so looks like some change after the 7.1 branch is causing this problem.
Comment 22 Michel Graciano 2011-11-23 15:09:40 UTC
You can download the Ubuntu heap dump at http://www.MegaShare.com/3745776
Comment 23 Jaroslav Havlin 2011-11-23 17:01:12 UTC
Thank you, Michel, for the heap dump. It seems it is "correct", i.e. I cannot see any memory leaks or incorrect values there. The memory was probably consumed by standard objects, e.g. swing components displaying the output. 
But in the first heap dump, there is a big HeapStorage object that should not be there.

>so looks like some change after the 7.1 branch is causing this problem
No changes has been made in output window sources since 7.1 branching.
Comment 24 misterm 2011-11-23 18:17:26 UTC
I can confirm this behaviour started somewhat recently, maybe in the last 3-4 weeks, very likely after 7.1 was branched.
Comment 25 Antonin Nebuzelsky 2011-11-24 10:59:35 UTC
michel, misterm, can you please retest extensively with 7.1 RC1 so that we are sure this does not affect 7.1? (in case we don't find the cause soon enough it is important to know if this is a stopper for 7.1). Thanks.
Comment 26 Jaroslav Havlin 2011-11-24 17:39:47 UTC
I was able to reproduce on Windows 7 with 32bit JDK. 

The only recent change that affects memory consumption of output window is fix for bug 203739. I tried to revert this change. The performance improved, but the error still appeared.

Misterm also kindly tested reverted module and wrote:
> It improved a lot, but is not as good as before. It didn't crash at
> all with two, even though there were apparently some full GCs going
> on, since it would hang every now and then. Then I tried it with four
> and it still crashes.

The memory consumption was partly affected by fix for bug 203739 and partly probably by other modules. The solution is quite complex and quick fix would be dangerous. The plan is to show only tail of output (several thousand lines), and to store the rest of output in a file (this fix will be contained in version 7.2).
Comment 27 Antonin Nebuzelsky 2011-11-24 17:58:05 UTC
Decreasing the priority. This problem does not impact the majority of the users and is not a stopper for 7.1.

The solution will be complex and will be targeted into the next release.
Comment 28 misterm 2011-11-24 18:21:27 UTC
I strongly disagree with this assessment. To me, this happens with a single compilation in my freeform project. It takes 6 or 7 minutes from the time I boot the IDE to reproduce this. It is just I couldn't send it to you. 

I'm pretty sure several tasks, such as starting an application server inside the IDE will produce enough log for the error to happen. This has nothing to do with multiple copies running.

We have a team of 10 developers here, many of which use Windows. We have been using NB in this project for 7 years. Are we really saying we cannot upgrade to 7.1?
Comment 29 Michel Graciano 2011-11-24 19:05:03 UTC
I was able to reproduce it at 7.1RC1, take a look at
http://statistics.netbeans.org/analytics/exception.do?id=545783

Looks like it is a dup of #199744 which was closed as INCOMPLETE. Maybe Michael
was able to create a way to reproduce it now. Maybe it is a stopper anyway...
Comment 30 Michel Graciano 2011-11-24 19:17:42 UTC
*** Bug 205538 has been marked as a duplicate of this bug. ***
Comment 31 Marian Mirilovic 2011-11-25 07:49:10 UTC
*** Bug 199744 has been marked as a duplicate of this bug. ***
Comment 32 Marian Mirilovic 2011-11-25 07:56:19 UTC
(In reply to comment #28)
> I strongly disagree with this assessment. To me, this happens with a single
> compilation in my freeform project. It takes 6 or 7 minutes from the time I
> boot the IDE to reproduce this. It is just I couldn't send it to you. 

Agreed, for now not a stopper, but still on radar for 7.1 ...

Tonda/Honza, could we add some logging or anything else ?
Comment 33 misterm 2011-11-25 13:03:28 UTC
Yes, I was able to reproduce it with NB 7.1-RC1. However, I was also able to narrow down the issue: it has something to do with output produced by Ant.

We have a Hudson installation set up here that builds the project twice for each commit (because it uses two JDK installations). Therefore, its output is more than twice as big as a single execution (there is the CVS log and other small messages). I was able to "Show console" for the last 8 builds with the same NB 7.1 RC 1 installation that crashed for a single local build.
Comment 34 Jaroslav Havlin 2011-11-25 14:36:57 UTC
core-main/rev/f842abcd6ee9

Releasing of mapped byte buffers improved.

With this change, I was able to print whole output (10,000 lines; 10,000,000 characters) of two simultaneous invocations of code from comment 15. Before, I was able to print 1500 lines only (with 32 bit JDK 6 on Window 7).
Comment 35 Antonin Nebuzelsky 2011-11-29 14:40:43 UTC
Considering for integration into 7.1. Code review will be done. QA will also need to give go.
Comment 36 Antonin Nebuzelsky 2011-11-29 16:43:25 UTC
Considered by QA too risky for 7.1 this late.

Planning for the first 7.1 patch.
Comment 37 Jaroslav Havlin 2011-11-29 17:04:11 UTC
core-main/rev/891145f7c403

Improved exception handling.
Comment 38 Quality Engineering 2011-12-01 12:09:06 UTC
Integrated into 'main-golden'
Changeset: http://hg.netbeans.org/main-golden/rev/891145f7c403
User: Jaroslav Havlin <jhavlin@netbeans.org>
Log: #205437 - OOME with enormous output... - improved exception handling
Comment 39 Jaroslav Havlin 2011-12-07 12:33:03 UTC
*** Bug 204272 has been marked as a duplicate of this bug. ***
Comment 40 Jaroslav Havlin 2012-01-10 10:52:03 UTC
Workaround for this bug in NetBeans 7.1:
http://wiki.netbeans.org/Bug205437inNB71
Comment 41 Jaroslav Havlin 2012-01-19 10:01:05 UTC
*** Bug 207476 has been marked as a duplicate of this bug. ***
Comment 42 Tomas Danek 2012-01-23 11:35:50 UTC
Michel G, Misterm, 
can you please try fix on dev build and mark as Verified, if everything is fine?
Without verification issue fix cannot go 7.1 patch 1. Thanks in advance!
Comment 43 Michel Graciano 2012-01-24 14:52:48 UTC
V. Build 20120123-0a001538c65d
Comment 44 Tomas Mysik 2012-01-27 08:12:01 UTC
*** Bug 207737 has been marked as a duplicate of this bug. ***
Comment 46 Jaroslav Havlin 2012-02-10 10:42:26 UTC
*** Bug 208172 has been marked as a duplicate of this bug. ***