Bug 224577 - OOME while trying to look at file local revisions
Summary: OOME while trying to look at file local revisions
Status: CLOSED WONTFIX
Alias: None
Product: Platform
Classification: Eclipse Project
Component: Team (show other bugs)
Version: 3.4   Edit
Hardware: PC Windows XP
: P3 normal (vote)
Target Milestone: ---   Edit
Assignee: Platform Team Inbox CLA
QA Contact:
URL:
Whiteboard: stalebug
Keywords: investigate, performance
Depends on:
Blocks:
 
Reported: 2008-03-28 08:28 EDT by Frederic Fusier CLA
Modified: 2020-07-16 15:43 EDT (History)
4 users (show)

See Also:


Attachments
Snapshot of memory consumption (148.85 KB, image/jpeg)
2008-04-03 13:55 EDT, Frederic Fusier CLA
no flags Details
Heap Memory Usage screen shot (25.60 KB, image/png)
2008-05-12 06:27 EDT, Tomasz Zarna CLA
no flags Details

Note You need to log in before you can comment on or make changes to this bug.
Description Frederic Fusier CLA 2008-03-28 08:28:30 EDT
Using I20080326-1950.

I got an OOME while trying to compare a java file local revisions:
!ENTRY org.eclipse.core.jobs 4 2 2008-03-28 12:50:33.062
!MESSAGE An internal error occurred during: "Fetching local history revisions".
!STACK 0
java.lang.OutOfMemoryError: Java heap space
        at java.util.Arrays.copyOf(Arrays.java:2882)
        at java.lang.AbstractStringBuilder.expandCapacity(AbstractStringBuilder.java:100)
        at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:515)
        at java.lang.StringBuffer.append(StringBuffer.java:306)
        at org.eclipse.jdt.internal.ui.compare.JavaCompareUtilities.readString(JavaCompareUtilities.java:300)
        at org.eclipse.jdt.internal.ui.compare.JavaCompareUtilities.readString(JavaCompareUtilities.java:330)
        at org.eclipse.jdt.internal.ui.compare.JavaStructureCreator.getContents(JavaStructureCreator.java:320)
        at org.eclipse.team.internal.ui.history.EditionHistoryPage.contentsEqual(EditionHistoryPage.java:252)
        at org.eclipse.team.internal.ui.history.EditionHistoryPage.filterRevisions(EditionHistoryPage.java:223)
        at org.eclipse.team.internal.ui.history.EditionHistoryPage.update(EditionHistoryPage.java:202)
        at org.eclipse.team.internal.ui.history.LocalHistoryPage$RefreshFileHistory.run(LocalHistoryPage.java:199)
        at org.eclipse.core.internal.jobs.Worker.run(Worker.java:55)

My Local History preferences are:
Days to keep files: 365
Maximum entries per files: 1000
Maximum file size (MB): 100
Comment 1 Frederic Fusier CLA 2008-03-28 08:30:33 EDT
Close all History views and garbage releases the memory. Then, I'm able to continue to work in my wksp. However, reopen the History and play a little bit with revisions, makes this exception happening again...
Comment 2 Dani Megert CLA 2008-03-28 09:06:36 EDT
Looks like the view is holding on to the data.
Comment 3 Dani Megert CLA 2008-03-28 09:33:44 EDT
You only see this when choosing
    Local History > ...
in the editor, right?

>Looks like the view is holding on to the data.
Not directly but
org.eclipse.team.internal.ui.history.EditionHistoryPage.filterRevisions(ITypedElement, IFileRevision[], IProgressMonitor) requests the contents of all(!) stored revisions in order to filter. This causes the OOME as the garbage collector has no time to react.
Comment 4 Frederic Fusier CLA 2008-03-28 10:40:34 EDT
(In reply to comment #3)
> You only see this when choosing
>     Local History > ...
> in the editor, right?
> 
I see the strong memory consumption (and so potentially get the OOME) as soon as I try to replace or compare a java file with local histories (there are around 300 versions in the list).

In fact my report was not entirely correct; I didn't get the exception again, but only noticed that the memory was increasing and sometimes reached the Java Heap size. But the memory was released each time I closed the replace/compare histories editor.

In fact I remember that the exception occurred after having played during a long time with revisions comparison in the editor without closing it.
Comment 5 Frederic Fusier CLA 2008-04-03 13:44:00 EDT
This problem really annoys me while working with my dvpt workspaces which have high history properties (365 days / 1000 files / 100 Mb). I cannot work on this kind of workspace more than several hours. After, I began to have memory troubles ; the OOME seldom happens but all my box is slown down because the eclipse session heat too much memory and gives too little room for other applications as Lotus Notes, Sametime, etc...

Would it be possible to look at this rapidly (at least address this issue for M7)?

Thanks in advance
Comment 6 Frederic Fusier CLA 2008-04-03 13:55:04 EDT
Created attachment 94757 [details]
Snapshot of memory consumption

Here's a snapshot of a Yourkit memory snapshot. I started my eclipse session using -Xmx521M VM argument...
If you're interested in, I can provide the corresponding Yourkit 'memory' file. I didn't attach it as it's really large: more than 700Mb!
Comment 7 Frederic Fusier CLA 2008-04-03 14:00:37 EDT
I forgot to add that this time, the garbage collection didn't work. I made the Yourkit snapshot after having closed all my editors, history views, JUnit views, etc. and performed many garbage collect, but the consumed memory was still over 360Mo...
Comment 8 Frederic Fusier CLA 2008-04-05 16:34:22 EDT
I got the OOME now systematically when I try to replace my java file with the content of a local revision. I'm now *obliged* to start my eclipse session with -Xmx512M VM argument otherwise I cannot perform this action. So, increase the severity as a basic functionality is no longer working using default eclipse.ini arguments...
Comment 9 Tomasz Zarna CLA 2008-04-07 10:50:32 EDT
Frederic, I'm on it. I'll try to reproduce it with the steps you provide. Also, I hope profiling it will get me some extra information about the issue.
Comment 10 Frederic Fusier CLA 2008-04-07 12:23:57 EDT
(In reply to comment #9)
> Frederic, I'm on it. I'll try to reproduce it with the steps you provide. Also,
> I hope profiling it will get me some extra information about the issue.
> 
Thanks a lot :-)
Comment 11 Tomasz Zarna CLA 2008-04-24 07:21:07 EDT
I created a similar working environment to the one Frederic has: I've got couple of huge files in my workspace (both plain texts and Java classes), I modified the default settings for the local history and finally I made dozens of changes in these files to make the history revisions consume half of my disk space :). As the result I was served with couple of OOMEs, all with heap dumps. btw, I even got one UNEXPECTED_EXCEPTION_... from the JVM. Unfortunately, none of the OOMEs was similar to the one by Frederic. To be more precise, most of them were thrown from either JDT or JFace. Moreover, after analyzing their accompanying head dumps, I found out that none of them indicated that it's EditionHistoryPage which consumes a lot of memory. 

As the next step I will try to dump the heap while working with the workbench (I won't wait for an OOME to be thrown). Maybe this time I'll be more lucky...

Before I do that I need to ask Frederic another question: are you sure the OOME happened "while trying to compare a java file local revisions"? I know it was some time ago, and you might not remember. afaik the RefreshHistoryJob is run in this type of situations:
* new input is set 
* "Refresh" action is used
* "Group by date" action is used
* resource's delta was changed (new revision added)
* searching for an existing History Page for an object (opening/reusing the History Page)

None of the above scenarios is related to comparing files. I'm not saying you're trying to mislead me here ;) I just want to gather as detailed information as possible.
Comment 12 Frederic Fusier CLA 2008-04-24 09:27:06 EDT
(In reply to comment #11)
> Before I do that I need to ask Frederic another question: are you sure the OOME
> happened "while trying to compare a java file local revisions"? I know it was
> some time ago, and you might not remember. afaik the RefreshHistoryJob is run
> in this type of situations:
> * new input is set 
> * "Refresh" action is used
> * "Group by date" action is used
> * resource's delta was changed (new revision added)
> * searching for an existing History Page for an object (opening/reusing the
> History Page)
> 
> None of the above scenarios is related to comparing files. I'm not saying
> you're trying to mislead me here ;) I just want to gather as detailed
> information as possible.
> 
Unfortunately, as you said, I can't remember precisely what I was doing at that time. I think that "while trying to compare" meant that I was in the comparison dialog... Not sure if I was looking at the comparison of two revisions or just waiting that the revisions list was populated. The last point " * searching for an existing History Page..." would make me thought that it was perhaps the latter rather than the former. May be the RefreshHistoryJob is also run to retrieve the revisions to display them in this dialog as is it used for the history page?
Comment 13 Tomasz Zarna CLA 2008-05-12 06:27:45 EDT
Created attachment 99671 [details]
Heap Memory Usage screen shot

 (In reply to comment #7)
> I forgot to add that this time, the garbage collection didn't work. I made the
> Yourkit snapshot after having closed all my editors, history views, JUnit views,
> etc. and performed many garbage collect, but the consumed memory was still over
> 360Mo...

I do confirm that replace/compare with operation can consume a lot of memory. Especially while working with that big amount of data. As mentioned couple comments above, I tried to create a similar conditions you've got there Frederic. In my case the GC did manage to do his job every time, when I closed the Compare editor and History view. The VM is getting hot, that's a fact, but just for a while. Did the GC didn't work for you only this time or every time?

In the meantime I will take a look at a dump I made when the VM was red hot.
Comment 14 Frederic Fusier CLA 2008-05-12 07:17:34 EDT
(In reply to comment #13)
> Created an attachment (id=99671) [details]
> Heap Memory Usage screen shot
> 
> I do confirm that replace/compare with operation can consume a lot of memory.
> Especially while working with that big amount of data. As mentioned couple
> comments above, I tried to create a similar conditions you've got there
> Frederic. In my case the GC did manage to do his job every time, when I closed
> the Compare editor and History view. The VM is getting hot, that's a fact, but
> just for a while. Did the GC didn't work for you only this time our every time?
> 
It didn't work that time (i.e. when I opened the bug). After that I cannot remember such GC issue, but my configuration has been different since then as I set -Xmx512M while starting this specific workspace and also do not open the History when possible to avoid this exception again (I was really busy on other fronts and didn't have time to experiment new OOME...)

> In the meantime I will take a look at a dump I made when the VM was red hot.
> 

Comment 15 Tomasz Zarna CLA 2008-08-21 08:56:00 EDT
During my last talk with Frederic he suggested that I should set Local History settings in my development workspace to same values as he has (Days to keep files: 365; Maximum entries per files: 1000; Maximum file size (MB): 100). Even though almost 4 months have passed since that time, I'm still not able to observe anything unusual (in terms of memory consumption) while working with the workspace. I use default vm settings (ie -Xms40m -Xmx256m -XX:MaxPermSize=256m). I am aware that Frederic's history gathered over years is much bigger than mine, however I do have revisions, which with the default setting would be there (local revisions from April, May).

Failing there, I decided to give one more try to Yourkit profiler. Again, I used the workspace from comment 11, with huge txt and java files and rich local history for each of them. Making the vm hot, while working with that workspace was a piece of cake. The memory consumption went higher and higher with every click. However, both 3.3 and 3.4 behave fine (except of speed) most of the time, even though the memory was reaching its limit. Of course, there were OOMEs, but they happened for both 3.3 and 3.4. Memory dumps didn't point to any particular leak/reason.

Frederic also pointed out that memory doesn't get released despite the fact he closed all the editors, views etc (comment 7). He documented it with the snapshot from comment 6. I tried to get the same effect. For both 3.3 and 3.4 it seemed that GC did his job. The memory consumption got reduced from almost 254 (almost all memory used) to ca 50 megs. Comparing the snapshots made then didn't show any major differences either. Number of objects, shallow or retained sizes for such classes as org.eclipse.jface.text.Line, Position, Document etc was comparable. The biggest difference I spotted was +8%, but this of course might be caused by number of revisions I compared while profiling.

To sum up, I wasn't able to observe any significant differences in the way Eclipse 3.3 and 3.4 works with Local history. I tried that during normal, day-to-day development and with a profiler (according to my knowledge how to do it). In other words, at this moment, with the observations I made, it doesn't look like a regression to me.

Any tips on what else I can try are welcome.
Comment 16 Dani Megert CLA 2008-08-21 09:06:54 EDT
>Any tips on what else I can try are welcome.
He could send you his workspace or you debug it together with him on his machine.
Comment 17 Frederic Fusier CLA 2008-08-21 09:48:20 EDT
(In reply to comment #15 + comment #16)
I do not think my workspace could be helpful in this case. Tomasz also got the OOME or slow performances with these history parameters, so we can say that he reproduced my issue... I agree that this was perhaps not a regression of 3.4 vs. 3.3, but my feeling is that the History view may consume too much memory when the history size is really big. The problem should be the same for the revision comparison dialog.

So my guess was that the memory consumption could be optimized to avoid OOME or perfs degradation which forced me to change my VM heap size on my eclipse session.

However, if no one else complain about this and if no optimization is possible (i.e. it's just an Eclipse limitation while using such parameter values), then I agree to reduce the severity of this bug and defer it to next release (or never...).
Comment 18 Tomasz Zarna CLA 2008-08-25 05:10:13 EDT
Since it doesn't seem to be a regression I'm reducing the severity and thus removing 3.4.1 target milestone. It is an issue which we will keep on our radar.
Comment 19 Frederic Fusier CLA 2008-08-26 11:49:52 EDT
Got an OOME again today with following history preferences:
Days: 365
Max entries: 100
Max size: 20

The file size was: 642,378  bytes

My session Heap Size was: 256Mb

I've sent to Tomazs the memory snapshot I took with Yourkit. Looking at it, I can see the EditHistoryPage holding a map which consumes 55Mb of memory, which is the biggest amount of retained memory of my session.

Expanding this map, it looks like each entry holds a string which size id around 1.2Mb and strangely looks like the content of the edited file...! As the entry look like a local revision, would it be possible that the history stores the entire file content for each revision!?

If so, this would explain the memory problem I experienced with my history preferences...
Comment 20 Eclipse Genie CLA 2020-07-16 15:43:27 EDT
This bug hasn't had any activity in quite some time. Maybe the problem got resolved, was a duplicate of something else, or became less pressing for some reason - or maybe it's still relevant but just hasn't been looked at yet. As such, we're closing this bug.

If you have further information on the current state of the bug, please add it and reopen this bug. The information can be, for example, that the problem still occurs, that you still want the feature, that more information is needed, or that the bug is (for whatever reason) no longer relevant.

--
The automated Eclipse Genie.