Concurrent mode failure... fragmentation?

Clemens Eisserer linuxhippy at gmail.com
Thu Jun 4 16:13:38 UTC 2009


If nothing helps, you can still disable -XX:+DisableExplicitGC and
call System.gc() when there isn't any time-critical load, maybe once a
day.
G1 could be a big win in this situation.

- Clemens

2009/6/3 kristoffer <kristoffer.sjogren at ericsson.com>:
>
> Hi
>
> I have a tricky problem with the CMS: "concurrent mode failure" occurs every
> now and then which causes a STW pause for roughly 7-8 seconds. It seems that
> this is a case of fragmentation, since it occurs way before the heap is
> full. I tried playing around with UseCMSCompactAtFullCollection,
> CMSInitiatingOccupancyFraction and different Xmx/Xms settings but nothing
> seems to fix the problem.
>
> Im running out of ideas... im not sure if fragmentation is the problem - is
> there any way to force compaction at an earlier stage?
>
> I have attached the gc.log and some other statistics that can be useful.
>
> Cheers,
> -Kristoffer
>
> Running SLES 10 SP1, JDK 1.6.06, Glassfish 2.1
>
> -Dcom.sun.corba.ee.transport.ORBWaitForResponseTimeout=60000
> -Dorg.omg.CORBA.ORBClass=com.sun.corba.ee.impl.orb.ORBImpl
> -Dorg.omg.CORBA.ORBSingletonClass=com.sun.corba.ee.impl.orb.ORBSingleton
> -Dsun.rmi.dgc.client.gcInterval=3600000
> -Dsun.rmi.dgc.server.gcInterval=3600000
> -server
> -XX:+UnlockDiagnosticVMOptions
> -XX:CMSFullGCsBeforeCompaction=0
> -XX:+UseCMSCompactAtFullCollection
> -Xmn200m
> -Xmx3600m
> -Xms3600m
> -XX:+DisableExplicitGC
> -XX:SurvivorRatio=20000
> -XX:MaxTenuringThreshold=0
> -XX:LargePageSizeInBytes=2m
> -XX:+UseParNewGC
> -XX:ParallelGCThreads=8
> -XX:+UseConcMarkSweepGC
> -XX:+UseCMSInitiatingOccupancyOnly
> -XX:CMSInitiatingOccupancyFraction=5
> -XX:+CMSParallelRemarkEnabled
> -XX:+CMSConcurrentMTEnabled
> -XX:ParallelCMSThreads=4
> -XX:MaxPermSize=512m
> -XX:PermSize=512m
> -XX:+CMSClassUnloadingEnabled
> -verbose:gc
> -XX:+PrintGCApplicationStoppedTime
> -XX:+PrintGCTimeStamps
> -XX:+PrintGCDetails
> -XX:+PrintHeapAtGC
> -XX:+LogVMOutput
> -XX:+UnlockDiagnosticVMOptions
>
>
> gc.log:
>
> 123592.046: [GC 123592.046: [ParNew: 204672K->0K(204736K), 0.0484480 secs]
> 1627282K->1438351K(3686336K), 0.0490060 secs] [Times: user=0.24 sys=0.03,
> real=0.05 secs]
> Heap after GC invocations=96778 (full 27780):
>  par new generation   total 204736K, used 0K [0x00002aaaae260000,
> 0x00002aaabaa60000, 0x00002aaabaa60000)
>  eden space 204672K,   0% used [0x00002aaaae260000, 0x00002aaaae260000,
> 0x00002aaabaa40000)
>  from space 64K,   0% used [0x00002aaabaa40000, 0x00002aaabaa40000,
> 0x00002aaabaa50000)
>  to   space 64K,   0% used [0x00002aaabaa50000, 0x00002aaabaa50000,
> 0x00002aaabaa60000)
>  concurrent mark-sweep generation total 3481600K, used 1438351K
> [0x00002aaabaa60000, 0x00002aab8f260000, 0x00002aab8f260000)
>  concurrent-mark-sweep perm gen total 524288K, used 182144K
> [0x00002aab8f260000, 0x00002aabaf260000, 0x00002aabaf260000)
> }
> Total time for which application threads were stopped: 0.0616680 seconds
> 123592.342: [CMS-concurrent-mark: 1.749/1.967 secs] [Times: user=12.46
> sys=0.74, real=1.97 secs]
> 123592.342: [CMS-concurrent-preclean-start]
> {Heap before GC invocations=96778 (full 27780):
>  par new generation   total 204736K, used 204672K [0x00002aaaae260000,
> 0x00002aaabaa60000, 0x00002aaabaa60000)
>  eden space 204672K, 100% used [0x00002aaaae260000, 0x00002aaabaa40000,
> 0x00002aaabaa40000)
>  from space 64K,   0% used [0x00002aaabaa40000, 0x00002aaabaa40000,
> 0x00002aaabaa50000)
>  to   space 64K,   0% used [0x00002aaabaa50000, 0x00002aaabaa50000,
> 0x00002aaabaa60000)
>  concurrent mark-sweep generation total 3481600K, used 1438351K
> [0x00002aaabaa60000, 0x00002aab8f260000, 0x00002aab8f260000)
>  concurrent-mark-sweep perm gen total 524288K, used 182144K
> [0x00002aab8f260000, 0x00002aabaf260000, 0x00002aabaf260000)
> 123592.382: [GC 123592.383: [ParNew (promotion failed):
> 204672K->204672K(204736K), 0.1170700 secs]123592.500: [CMS123592.813:
> [CMS-concurrent-preclean: 0.303/0.471 secs] [Times: user=0.73 sys=0.02,
> real=0.47 secs]
>  (concurrent mode failure): 1445845K->1299108K(3481600K), 8.1608190 secs]
> 1643023K->1299108K(3686336K), 8.2785780 secs] [Times: user=8.37 sys=0.05,
> real=8.28 secs]
> Heap after GC invocations=96779 (full 27780):
>  par new generation   total 204736K, used 0K [0x00002aaaae260000,
> 0x00002aaabaa60000, 0x00002aaabaa60000)
>  eden space 204672K,   0% used [0x00002aaaae260000, 0x00002aaaae260000,
> 0x00002aaabaa40000)
>  from space 64K,   0% used [0x00002aaabaa50000, 0x00002aaabaa50000,
> 0x00002aaabaa60000)
>  to   space 64K,   0% used [0x00002aaabaa40000, 0x00002aaabaa40000,
> 0x00002aaabaa50000)
>  concurrent mark-sweep generation total 3481600K, used 1299108K
> [0x00002aaabaa60000, 0x00002aab8f260000, 0x00002aab8f260000)
>  concurrent-mark-sweep perm gen total 524288K, used 182141K
> [0x00002aab8f260000, 0x00002aabaf260000, 0x00002aabaf260000)
> }
> Total time for which application threads were stopped: 8.2904010 seconds
>
>
> http://www.nabble.com/file/p23847470/deviap112_iap_logs_gc_timeline.png
> http://www.nabble.com/file/p23847470/deviap112_iap_logs_old_heap_size.png
> http://www.nabble.com/file/p23847470/deviap112_iap_logs_gc_stats.png
>
> --
> View this message in context: http://www.nabble.com/Concurrent-mode-failure...-fragmentation--tp23847470p23847470.html
> Sent from the OpenJDK Hotspot Garbage Collection mailing list archive at Nabble.com.
>
>



More information about the hotspot-gc-dev mailing list