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 41012 - OutOfMemoryError performing a CVS checkout
Summary: OutOfMemoryError performing a CVS checkout
Status: VERIFIED FIXED
Alias: None
Product: obsolete
Classification: Unclassified
Component: vcscore (show other bugs)
Version: 3.x
Hardware: PC Windows ME/2000
: P2 blocker (vote)
Assignee: Martin Entlicher
URL:
Keywords: PERFORMANCE, RELNOTE
: 40505 41969 (view as bug list)
Depends on: 32089
Blocks:
  Show dependency tree
 
Reported: 2004-03-15 20:24 UTC by clever
Modified: 2005-07-25 13:30 UTC (History)
4 users (show)

See Also:
Issue Type: DEFECT
Exception Reporter:


Attachments
thread dump during deadlock after CVS Update (7.52 KB, text/plain)
2004-03-17 14:05 UTC, Patrick Keegan
Details
Thread dump [incomplete] (34.36 KB, text/plain)
2004-08-02 17:21 UTC, _ pkuzel
Details
CacheHandler.persistenData eliminaion patch (7.89 KB, patch)
2004-08-20 16:42 UTC, _ pkuzel
Details | Diff

Note You need to log in before you can comment on or make changes to this bug.
Description clever 2004-03-15 20:24:24 UTC
Using build 200403102255, I attempted to checkout
'all' from the NetBeans CVS hive and received an
OutOfMemoryError.  The pertinante clip from my
ide.log is:

...
WARNING TO DEVELOPERS:
Please be warned that attempting to reuse one open
connection for more commands is not supported by
cvs servers very well.
You are advised to open a new Connection each time.
If you still want to proceed, please do:
System.setProperty("javacvs.multiple_commands_warning",
"false")
That will disable this message.
WARNING TO DEVELOPERS:
Please be warned that attempting to reuse one open
connection for more commands is not supported by
cvs servers very well.
You are advised to open a new Connection each time.
If you still want to proceed, please do:
System.setProperty("javacvs.multiple_commands_warning",
"false")
That will disable this message.
*********** Exception occurred ************ at
3:02 PM on Mar 15, 2004
java.lang.OutOfMemoryError

Not a showstopper, as command line CVS is an
alternative, but I think this should work, or have
a better error message if one is possible.

(FYI, I was following the generalized instruction
to do a checkout / export of the 'all' virtual
module at http://nbbuild.netbeans.org/ant-quick.html)
Comment 1 clever 2004-03-15 21:26:13 UTC
New info:
After the error, I reloaded NetBeans and re-attempted a 'checkout'
against all (with 'tomorrow' date).  This time, the copy completed
without error.  So, I believe that it has to do with the sheer number
of files involved with a checkout of 'all'.
HTH!
Comment 2 clever 2004-03-15 21:36:09 UTC
Even more info,
A few minutes later, the OutOfMemoryError did finally appear out of
nowhere.  It seems that although the "Command Finished" for javavcs,
there was some additional processing going on in the background.
Showing details does show additional info:

Annotation: Exception occurred in Request Processor
java.lang.NullPointerException
	at
org.netbeans.modules.vcscore.commands.CommandOutputCollector.freeCommandOutput(CommandOutputCollector.java:214)
	at
org.netbeans.modules.vcscore.commands.CommandOutputCollector.access$100(CommandOutputCollector.java:32)
	at
org.netbeans.modules.vcscore.commands.CommandOutputCollector$1.run(CommandOutputCollector.java:191)
	at org.openide.util.Task.run(Task.java:136)
	at org.openide.util.RequestProcessor$Task.run(RequestProcessor.java:330)
[catch] at
org.openide.util.RequestProcessor$Processor.run(RequestProcessor.java:686)

HTH! -Sean
Comment 3 Martin Entlicher 2004-03-16 10:32:03 UTC
The "WARNING TO DEVELOPERS" that is written into console is already
described in issue #33920. It's just a mistake that this warning is
printed when checkout is executed.

The problem with OutOfMemoryError was already mentioned in issue #40505.

The problem is, that this is not reproducible. It just sometimes
happens and sometimes not. We did not find the cause of this behavior yet.
Comment 4 Martin Entlicher 2004-03-16 13:31:53 UTC
*** Issue 40505 has been marked as a duplicate of this issue. ***
Comment 5 Martin Entlicher 2004-03-16 13:32:29 UTC
It looks like the OOME is caused by a lot of refreshing that is
performed after checkout, not the checkout itself.
Comment 6 Jiri Kovalsky 2004-03-16 13:41:09 UTC
I think this should be documented in the 3.6 release notes.
Comment 7 Patrick Keegan 2004-03-16 14:07:37 UTC
I'm not sure I understand it thoroughly, but I'll propose a relnote to
see if I understand the issue from the user perspective.

"Sometimes after doing a large CVS checkout, an Out Of Memory Error
occurs, which forces you to shut down the IDE. 

Workaround: If you work with an extremely large CVS repository, use
the IDE's command-line CVS client support instead of the built-in CVS
client support. You can specify command-line client support in the
Mount Version Control wizard when you mount the filesystem.
Comment 8 Jiri Kovalsky 2004-03-16 14:40:18 UTC
I would say it's fine however I doubt the mentioned workaround really
works. What do others think ?
Comment 9 dmladek 2004-03-16 14:55:42 UTC
Well, it's only my impression that it happens only on build-in client.
But in fact we don't have any real evidence that's true :-/
So I wouldn't mention the workaround....
Comment 10 Patrick Keegan 2004-03-16 17:10:11 UTC
OK. I will include without the workaround.
Comment 11 clever 2004-03-16 17:38:10 UTC
Well, I was able to reproduce the problem again.  I completely removed
the cvs filesystem from my project, deleted all the files through my
OS, and performed the following tasks:

- Create new CVS filesystem, specifying the netbeans CVS pserver with
anoncvs as the username
- Checkout of 'stable' with no date or tag specified (head revision
was set?)

The checkout completed okay, but the UI module was showing 'Local'. I
then did a refresh against it, which appeared to finish.  Therafter, I
was trying to configure relative mount points for the sources (was
exploring NB 3.6 CVS menus), when I noticed some delay. Subsequently,
I received the OOME.  I'm still trying to gracefully close the IDE.
(Keep getting error and exception windows)

I think I can safely say that it's reproducable, at least for me. I
will try the 'external' CVS option next, and will update this bug with
the results.
Comment 12 Patrick Keegan 2004-03-17 14:05:49 UTC
Created attachment 14017 [details]
thread dump during deadlock after CVS Update
Comment 13 Patrick Keegan 2004-03-17 14:07:38 UTC
I've just attached a thread dump I took when the IDE deadlocked after
I did a CVS Update. AFter I did the thread dump, the IDE started
working again.

I don't know if this is related to the problem. In fact, I didn't ever
get an OOME, but the IDE was unusable (wouldn't repaint, etc.) until I
got the thread dump.
Comment 14 Patrick Keegan 2004-03-17 14:10:22 UTC
BTW, the threaad dump was taken from the 3/14 attempt at an RC build.
Windows XP
Comment 15 Martin Entlicher 2004-04-15 10:11:11 UTC
*** Issue 41969 has been marked as a duplicate of this issue. ***
Comment 16 Martin Entlicher 2004-04-30 10:53:17 UTC
The OOME should be solved by the cache redesign (issue #32089).
Comment 17 _ ttran 2004-05-01 22:11:08 UTC
I increase the priority of this bug to P2.  OOME is deadly, once it
happens the IDE cannot recover which means dataloss.  It's not only a
performance problem.
Comment 18 _ pkuzel 2004-08-02 14:41:03 UTC
Finally I'm able to reproduce.

Till ...vcscore.cmdline.ExecuteCommand.commandFinished()
it takes about 50Mb in char[]s logging command progress into results
table. 

Then avalanche of refresh threads start to initialize cache. Namely
CacheDir.setName() duplicates all strings again. At 120Mb it OOMEed.

Then profiler crashed...

Martin suggested to use (now optimalized) recursive refresh for cache
initialization. I'll try to optimalize CacheDir.setName() and retry.
Comment 19 _ pkuzel 2004-08-02 17:20:55 UTC
Well, with recursive refresh UNLIMITED request processor is overloaded
by waiting tasks, blocking IDE from further processing. The same
effect as OOME.

"Default RequestProcessor" daemon prio=1 tid=0x0ca3dad0 nid=0x31cf in
Object.wait() [5b382000..5b38287c]
        at java.lang.Object.wait(Native Method)
        at java.lang.Object.wait(Object.java:429)
        at
org.netbeans.api.vcs.VcsManager.showCustomizer(VcsManager.java:215)
        - locked <0x4a7188c8> (a
org.netbeans.api.vcs.VcsManager$CustomizationListener)
        at
org.netbeans.modules.vcscore.caching.VcsCache$RefreshProcessStarter.run(VcsCache.java:990)
Comment 20 _ pkuzel 2004-08-02 17:21:38 UTC
Created attachment 16616 [details]
Thread dump [incomplete]
Comment 21 Martin Entlicher 2004-08-02 19:13:54 UTC
This might be a similar problem to issue #40294.
The problem is, that there can be started a lot of tasks one after
another in a short time. These are started lazily in RequestProcessor
and this cause a lot of tasks to be spawned.

Because the command customization is performed lazily in a thread in
RequestProcessor and because the default RP might get full in the mean
time, there are no more free tasks to actually finish the customization.
Comment 22 Martin Entlicher 2004-08-02 19:48:50 UTC
Perhaps the change beween 1.34.2.4 and 1.34.2.5 of
vcscore/src/org/netbeans/modules/vcscore/caching/VcsCache.java can be
revered. However, it must be verified that it would not cause deadlocks.
Comment 23 Martin Entlicher 2004-08-09 17:14:35 UTC
The change is reverted. After brief tests is does not seem to cause
any problems.

/cvs/vcscore/src/org/netbeans/modules/vcscore/caching/VcsCache.java,v
 <--  VcsCache.java
new revision: 1.67; previous revision: 1.66

Refreshes are started synchronously now.
Comment 24 _ pkuzel 2004-08-10 09:31:51 UTC
I'll try to eliminate cache's memory layer. Disk layer has constant
response time (DISKacc). It's usually less than network connection
response time (NETacc). It means that cache without memory layer
saves/adds NETacc-DISKacc time. Comparing to cache with memory layer
it always adds DISKacc overhead (assuming MEMacc => 0).

That's theory let look at reality later on.
Comment 25 _ pkuzel 2004-08-10 14:38:10 UTC
Cache memory requirements decreased. I can checkout "all" without OOME
now. It takes about 60MB of heap. 

Checking in src/org/netbeans/modules/vcscore/cache/CacheDir.java;
/cvs/vcscore/src/org/netbeans/modules/vcscore/cache/CacheDir.java,v 
<--  CacheDir.java
new revision: 1.37; previous revision: 1.36
done
Processing log script arguments...
More commits to come...
Checking in src/org/netbeans/modules/vcscore/caching/VcsCache.java;
/cvs/vcscore/src/org/netbeans/modules/vcscore/caching/VcsCache.java,v
 <--  VcsCache.java
new revision: 1.68; previous revision: 1.67
done
Checking in src/org/netbeans/modules/vcscore/caching/VcsCacheDir.java;
/cvs/vcscore/src/org/netbeans/modules/vcscore/caching/VcsCacheDir.java,v
 <--  VcsCacheDir.java
new revision: 1.52; previous revision: 1.51
done


I'm going to optimalize results table too.
Comment 26 _ pkuzel 2004-08-11 17:12:04 UTC
Martin was forced to rollback because it causes misterious problems in
VSS.

My attempt to use RandomAccessFile based List for storing command
output decreases memory consumption but it does not prevent OOME.
Comment 27 Martin Entlicher 2004-08-11 18:31:48 UTC
Yes, unfortunately I had to rollback the last change.
I'll inspect what was causing the problems later on. We need to
resolve issue #47112 ASAP.

/cvs/vcscore/src/org/netbeans/modules/vcscore/cache/CacheDir.java,v 
<--  CacheDir.java
new revision: 1.38; previous revision: 1.37

/cvs/vcscore/src/org/netbeans/modules/vcscore/caching/VcsCache.java,v
 <--  VcsCache.java
new revision: 1.69; previous revision: 1.68

/cvs/vcscore/src/org/netbeans/modules/vcscore/caching/VcsCacheDir.java,v
 <--  VcsCacheDir.java
new revision: 1.53; previous revision: 1.52
Comment 28 Martin Entlicher 2004-08-12 13:19:50 UTC
Please note, that the last (rollbacked) fix also most probably caused
issue #47135. It's apparent that the cache objects are loaded form
disk again and again. This is unacceptable behavior. We'll have to
tune the removal from memory cache somehow.
Comment 29 Martin Entlicher 2004-08-16 12:56:03 UTC
The change in VcsCache modified and applied. cacheDirs map removed
completely, there is a lookup for the searched CacheDir instead:

/cvs/vcscore/src/org/netbeans/modules/vcscore/caching/VcsCache.java,v
 <--  VcsCache.java
new revision: 1.71; previous revision: 1.70
Comment 30 _ pkuzel 2004-08-18 13:16:45 UTC
I'm removing shadow versioning filesystem. It can help this issue too
because it decreases number of created/handled fileobject to one half.
Comment 31 _ pkuzel 2004-08-19 10:19:39 UTC
VcsCache.java new revision: 1.72

Speeds up cache operations after cacheDirs map removal. It replaces
io.File based operations by String based operations because io.File is
very expensive constructor.
Comment 32 _ pkuzel 2004-08-19 13:58:36 UTC
OOME is still there, but is does not come from heap now (there is 40Mb
free on heap).

It can be caused by String.intern() because pernament area is by
default 64Mb and after NB start there is only 24Mb free (rest is taken
by loaded classes metadata).

jvmstat tool should be able to help here
Comment 33 _ pkuzel 2004-08-19 16:15:47 UTC
I removed string interning and run under jvmstat. After checkout there
is 26Mb perm area, 133Mb old area (112Mb after closing output window).

Recently Tonda set -Xmx128m instead of -Xmx168 (my current).
Comment 34 _ pkuzel 2004-08-20 16:42:51 UTC
Created attachment 16987 [details]
CacheHandler.persistenData eliminaion patch
Comment 35 _ pkuzel 2004-08-20 17:01:12 UTC
CacheHandler.persistentData seems to me like unnecessary map. What was
its original purpose. What's advantage of createChildFromData(), the
only client for stored elements?

Can I remove it as suggested in attached patch? It seems simple but
there are almost always unrelated side effects...
Comment 36 _ pkuzel 2004-08-20 17:48:02 UTC
With patch there are constant memory requirements.

On the other hand many files stay [local] after initial refresh
recursivelly that pupulates cache files. They need to be refreshed
again to show proper statuses.

Most folders are marked [local] even after subsequent refresh. Most of
inproperly annotated folders are in disk cache content. There is
inconstency between disk cache content and it's visualization. Few of
them is missing in disk cache content. There is inconsistency between
disk cache content and real state (assuming the refresh should update
it - it connects to server).

Files are OK, but it would be better to show no status until known
instead of current behaviour - marking them as [local] and rediplaying
later on with proper status got from cache. It can flicker.

So there are serious side effects that does not direclty link to
actual code changes. At my level of understanding the code.
Comment 37 _ pkuzel 2004-08-24 15:19:44 UTC
Using limited size LRU map in CacheHandler.java new revision: 1.19.
It's very similar to the persistent.diff. Short testing with CVS VCS
on Linux have not exposed any problems. Previous regresssions was
probably incorrecly attributed to persistent.diff instead of meanwhile
fixed VcsCache.seekCacheDir().

Further testing is indeed necessary. I have not turned on asserts as
they poped up regurarly (but inconsistencies was not so fatal as
observed before).
Comment 38 Peter Pis 2005-07-25 13:30:14 UTC
Verfied.