Java heap space, GC, and Promotion Failed

[Y. S. Ramakrishna]

Hi Rafael --

Looks like you need more heap: size your -Xmx bigger to
accommodate all of the objects that your Eclipse project creates.
Here's the state of the old gen in the penultimate display:-

>> [Full GC [CMS[CMS-concurrent-mark: 8.811/9.001 secs] [Times: user=10.95 
>> sys=0.02, real=9.00 secs] 
>>  (concurrent mode failure): 2008891K->2014802K(2015232K), 24.2053380 
>> secs] 2038395K->2014802K(2044736K), [CMS Perm : 50779K->50779K(86244K)] 
>> icms_dc=100 , 24.2054320 secs] [Times: user=24.16 sys=0.03, real=24.20 
>> secs] 
>> [GC [1 CMS-initial-mark: 2014802K(2015232K)] 2015335K(2044736K), 
>> 0.0023250 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 

The last line shows that the old gen has:-
  2015232 - 2014802 = 430 KB
of free space. Perhaps you were trying to allocate an object bigger than that.
I'd suggest running with a larger heap (possibly using a 64-bit JVM if
you need more Java heap).

However, the end of your message does not show the heap to be too full.
Perhaps Eclipse catches the OOM, and drops all of the objects before it exits,
so you see the heap as not full in the final display:-
(Eclipse experts on the list might want to weigh in.)

>> This is the end of the output:
>> 
>> Heap
>>  par new generation   total 29504K, used 23591K [0x2e8b0000, 0x308b0000, 
>> 0x308b0000)
>>   eden space 26240K,  77% used [0x2e8b0000, 0x2fc89f20, 0x30250000)
>>   from space 3264K, 100% used [0x30580000, 0x308b0000, 0x308b0000)
>>   to   space 3264K,   0% used [0x30250000, 0x30250000, 0x30580000)
>>  concurrent mark-sweep generation total 2015232K, used 61766K 
>> [0x308b0000, 0xab8b0000, 0xab8b0000)
>>  concurrent-mark-sweep perm gen total 87828K, used 52696K [0xab8b0000, 
>> 0xb0e75000, 0xb38b0000)


Asides:-
Never, never use values for MaxTenuringThreshold exceeding 15, unless
you are sure you want that kind of behaviour. I'd suggest
just leave that option out unless you know how to tune for it (there's
lots of experience on this alias with tuning that though, should
you need to tune that for performance in the future).

More asides (specific to CMS):-
Depending on what your platform is, if it has anything more than 2 cores,
i'd advise dropping the -XX:+CMSIncrementalMode option. (You'd then
want to drop other options starting with "CMSIncremental".
CMS does not unload classes by default. With Eclipse etc. you would
want to unload classes concurrently so as not to get OOM's:
use -XX:+CMSClassUnloadingEnabled (and if on older JVM's -XX:+CMSPermGenSweepingEnabled).

Bottom line: looks like you need more Java heap.
-- ramki

On 04/13/11 10:25, Rafael Angarita wrote:
> Hello everybody,
> 
> I'm building a code generation application as an Eclipse and one of my 
> test projects contains around 15000 source files. My application started 
> having memory problems, so after doing some optimizations especific to 
> the framework I'm using to develope my DSL, I started learning about GC, 
> but I think I'm still lost.
> 
> I have tried with different JVM options for the GC with no success. 
> Currently, I'm trying:
> 
> -Xms2000m -Xmx2000m -verbosegc -XX:+PrintGCDetails 
>  -XX:+HeapDumpOnOutOfMemoryError -XX:+UseConcMarkSweepGC 
> -XX:+CMSIncrementalMode 
> -XX:+CMSIncrementalPacing -XX:CMSInitiatingOccupancyFraction=5 
> -XX:MaxTenuringThreshold=300 -XX:+UseCMSInitiatingOccupancyOnly 
> -XX:CMSIncrementalDutyCycleMin=1
> 
> but this is just one of the several things I have tried.
> 
> At first everything seems to go fine, but after awhile I get "promotion 
> failed" and everything gets really slow, and finally the application 
> crash with java.lang.OutOfMemoryError: Java heap space.
> 
> 
> CMS-concurrent-abortable-preclean: 0.070/0.587 secs] [Times: user=0.66 
> sys=0.02, real=0.58 secs] 
> [GC[YG occupancy: 28574 K (29504 K)][Rescan (parallel) , 0.0198420 
> secs][weak refs processing, 0.0015200 secs] [1 CMS-remark: 
> 1961760K(2015232K)] 1990335K(2044736K), 0.0215890 secs] [Times: 
> user=0.03 sys=0.00, real=0.03 secs] 
> [GC [ParNew: 29096K->2087K(29504K), 0.0270900 secs] 
> 1990735K->1965523K(2044736K) icms_dc=100 , 0.0271650 secs] [Times: 
> user=0.05 sys=0.00, real=0.03 secs] 
> [GC [ParNew: 28327K->3264K(29504K), 0.0430410 secs] 
> 1990448K->1969326K(2044736K) icms_dc=100 , 0.0431180 secs] [Times: 
> user=0.07 sys=0.01, real=0.04 secs] 
> [GC [ParNew: 29504K->3264K(29504K), 0.0658260 secs] 
> 1995091K->1975795K(2044736K) icms_dc=100 , 0.0659090 secs] [Times: 
> user=0.11 sys=0.00, real=0.07 secs] 
> [GC [ParNew: 29504K->3264K(29504K), 0.0630250 secs] 
> 2001944K->1982760K(2044736K) icms_dc=100 , 0.0631060 secs] [Times: 
> user=0.11 sys=0.00, real=0.06 secs] 
> [GC [ParNew: 29504K->3263K(29504K), 0.0435130 secs] 
> 2008711K->1985752K(2044736K) icms_dc=100 , 0.0436310 secs] [Times: 
> user=0.07 sys=0.00, real=0.04 secs] 
> [CMS-concurrent-sweep: 1.813/2.058 secs] [Times: user=3.76 sys=0.02, 
> real=2.05 secs] 
> [CMS-concurrent-reset: 0.035/0.035 secs] [Times: user=0.06 sys=0.00, 
> real=0.04 secs] 
> [GC [ParNew (promotion failed): 29503K->29504K(29504K), 0.5729750 
> secs][CMS[Unloading class sun.reflect.GeneratedConstructorAccessor6]
> [Unloading class sun.reflect.GeneratedConstructorAccessor26]
> [Unloading class sun.reflect.GeneratedMethodAccessor9]
> [Unloading class sun.reflect.GeneratedConstructorAccessor17]
> [Unloading class sun.reflect.GeneratedConstructorAccessor20]
> [Unloading class sun.reflect.GeneratedMethodAccessor4]
> [Unloading class sun.reflect.GeneratedMethodAccessor8]
> [Unloading class sun.reflect.GeneratedConstructorAccessor25]
> [Unloading class sun.reflect.GeneratedMethodAccessor18]
> [Unloading class sun.reflect.GeneratedMethodAccessor17]
> [Unloading class sun.reflect.GeneratedConstructorAccessor27]
> [Unloading class sun.reflect.GeneratedConstructorAccessor19]
> [Unloading class sun.reflect.GeneratedConstructorAccessor12]
> [Unloading class sun.reflect.GeneratedMethodAccessor2]
> [Unloading class sun.reflect.GeneratedConstructorAccessor14]
> [Unloading class sun.reflect.GeneratedConstructorAccessor28]
> [Unloading class sun.reflect.GeneratedConstructorAccessor5]
> [Unloading class sun.reflect.GeneratedMethodAccessor16]
> [Unloading class sun.reflect.GeneratedMethodAccessor19]
> [Unloading class sun.reflect.GeneratedConstructorAccessor9]
> [Unloading class sun.reflect.GeneratedConstructorAccessor11]
> [Unloading class sun.reflect.GeneratedConstructorAccessor8]
> [Unloading class sun.reflect.GeneratedConstructorAccessor29]
> [Unloading class sun.reflect.GeneratedMethodAccessor3]
> [Unloading class sun.reflect.GeneratedConstructorAccessor24]
> [Unloading class sun.reflect.GeneratedConstructorAccessor18]
> [Unloading class sun.reflect.GeneratedMethodAccessor15]
> [Unloading class sun.reflect.GeneratedConstructorAccessor10]
> [Unloading class sun.reflect.GeneratedConstructorAccessor16]
> [Unloading class sun.reflect.GeneratedConstructorAccessor15]
> 
> [Full GC [CMS[CMS-concurrent-mark: 8.811/9.001 secs] [Times: user=10.95 
> sys=0.02, real=9.00 secs] 
>  (concurrent mode failure): 2008891K->2014802K(2015232K), 24.2053380 
> secs] 2038395K->2014802K(2044736K), [CMS Perm : 50779K->50779K(86244K)] 
> icms_dc=100 , 24.2054320 secs] [Times: user=24.16 sys=0.03, real=24.20 
> secs] 
> [GC [1 CMS-initial-mark: 2014802K(2015232K)] 2015335K(2044736K), 
> 0.0023250 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
> 
> This is the end of the output:
> 
> Heap
>  par new generation   total 29504K, used 23591K [0x2e8b0000, 0x308b0000, 
> 0x308b0000)
>   eden space 26240K,  77% used [0x2e8b0000, 0x2fc89f20, 0x30250000)
>   from space 3264K, 100% used [0x30580000, 0x308b0000, 0x308b0000)
>   to   space 3264K,   0% used [0x30250000, 0x30250000, 0x30580000)
>  concurrent mark-sweep generation total 2015232K, used 61766K 
> [0x308b0000, 0xab8b0000, 0xab8b0000)
>  concurrent-mark-sweep perm gen total 87828K, used 52696K [0xab8b0000, 
> 0xb0e75000, 0xb38b0000)
> 
> 
> I would appreciate if anybody can give me an advise about this.
> 
> Thank you very much for your help.
> 
> 
> ------------------------------------------------------------------------
> 
> _______________________________________________
> hotspot-gc-use mailing list
> hotspot-gc-use at openjdk.java.net
> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use