Java heap space, GC, and Promotion Failed

[Rafael Angarita]

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.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20110413/0572df06/attachment.html