High Par New collection times

Y. S. Ramakrishna y.s.ramakrishna at oracle.com
Tue Jan 4 17:27:19 UTC 2011


Don't know which version of the JVM you are using, but the following may be relevant:-

http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6631166
http://bugs.sun.com/bugdatabase/view_bug.do?bug_id=6999988

The  latter is still under investigation.
-- ramki

On 01/04/11 08:02, Erwin wrote:
> Hello,
> 
>>From time to time, we would get a high collection time for ParNew and it would indicate promotion failed. This would then show CPU starvation message on the SystemOut.log. We're using Solaris10 and WAS 7.0.0.9 NDE.
> 
> Below is our JVM arguments. Any help would be appreciated.
> -server -Xmn1000m -XX:PermSize=512m -XX:+UseConcMarkSweepGC -XX:+HeapDumpOnOutOfMemoryError -DUseSunHttpHandler=true -Djavax.xml.soap.MessageFactory=weblogic.xml.saaj.MessageFactoryImpl -Doracle.jdbc.V8Compatible=true -XX:CMSInitiatingOccupancyFraction=70 -XX:+CMSClassUnloadingEnabled -verbose:gc -XX:+PrintGCTimeStamps -XX:+PrintGCDetails -XX:-TraceClassUnloading -XX:+PrintGCApplicationStoppedTime -XX:+PrintHeapAtGC  -XX:MaxPermSize=694m -XX:+DisableExplicitGC -XX:+CMSParallelRemarkEnabled
> 
> {Heap before GC invocations=12800 (full 1163):
>  par new generation   total 921600K, used 906365K [0xfffffffdc0000000, 0xfffffffdfe800000, 0xfffffffdfe800000)
>   eden space 819200K, 100% used [0xfffffffdc0000000, 0xfffffffdf2000000, 0xfffffffdf2000000)
>   from space 102400K,  85% used [0xfffffffdf2000000, 0xfffffffdf751f498, 0xfffffffdf8400000)
>   to   space 102400K,   0% used [0xfffffffdf8400000, 0xfffffffdf8400000, 0xfffffffdfe800000)
>  concurrent mark-sweep generation total 5136384K, used 2809586K [0xfffffffdfe800000, 0xffffffff38000000, 0xffffffff38000000)
>  concurrent-mark-sweep perm gen total 524288K, used 249119K [0xffffffff38000000, 0xffffffff58000000, 0xffffffff63800000)
> 1598527.649: [GC 1598527.649: [ParNew (promotion failed): 906365K->921600K(921600K), 0.6504370 secs]1598528.300: [CMS: 2969343K->2818470K(5136384K), 30.8057620 secs] 3715951K->2818470K(6057984K), [CMS Perm : 249119K->248229K(524288K)], 31.4567688 secs] [Times: user=33.09 sys=0.26, real=31.46 secs] 
> Heap after GC invocations=12801 (full 1164):
>  par new generation   total 921600K, used 0K [0xfffffffdc0000000, 0xfffffffdfe800000, 0xfffffffdfe800000)
>   eden space 819200K,   0% used [0xfffffffdc0000000, 0xfffffffdc0000000, 0xfffffffdf2000000)
>   from space 102400K,   0% used [0xfffffffdf8400000, 0xfffffffdf8400000, 0xfffffffdfe800000)
>   to   space 102400K,   0% used [0xfffffffdf2000000, 0xfffffffdf2000000, 0xfffffffdf8400000)
>  concurrent mark-sweep generation total 5136384K, used 2818470K [0xfffffffdfe800000, 0xffffffff38000000, 0xffffffff38000000)
>  concurrent-mark-sweep perm gen total 524288K, used 248229K [0xffffffff38000000, 0xffffffff58000000, 0xffffffff63800000)
> }
> 
> Other times are fine
> {Heap before GC invocations=12798 (full 1163):
>  par new generation   total 921600K, used 921600K [0xfffffffdc0000000, 0xfffffffdfe800000, 0xfffffffdfe800000)
>   eden space 819200K, 100% used [0xfffffffdc0000000, 0xfffffffdf2000000, 0xfffffffdf2000000)
>   from space 102400K, 100% used [0xfffffffdf2000000, 0xfffffffdf8400000, 0xfffffffdf8400000)
>   to   space 102400K,   0% used [0xfffffffdf8400000, 0xfffffffdf8400000, 0xfffffffdfe800000)
>  concurrent mark-sweep generation total 5136384K, used 2677208K [0xfffffffdfe800000, 0xffffffff38000000, 0xffffffff38000000)
>  concurrent-mark-sweep perm gen total 524288K, used 248923K [0xffffffff38000000, 0xffffffff58000000, 0xffffffff63800000)
> 1598495.024: [GC 1598495.024: [ParNew: 921600K->88036K(921600K), 0.2590699 secs] 3598808K->2871275K(6057984K), 0.2594312 secs] [Times: user=2.73 sys=0.10, real=0.26 secs] 
> Heap after GC invocations=12799 (full 1163):
>  par new generation   total 921600K, used 88036K [0xfffffffdc0000000, 0xfffffffdfe800000, 0xfffffffdfe800000)
>   eden space 819200K,   0% used [0xfffffffdc0000000, 0xfffffffdc0000000, 0xfffffffdf2000000)
>   from space 102400K,  85% used [0xfffffffdf8400000, 0xfffffffdfd9f9168, 0xfffffffdfe800000)
>   to   space 102400K,   0% used [0xfffffffdf2000000, 0xfffffffdf2000000, 0xfffffffdf8400000)
>  concurrent mark-sweep generation total 5136384K, used 2783239K [0xfffffffdfe800000, 0xffffffff38000000, 0xffffffff38000000)
>  concurrent-mark-sweep perm gen total 524288K, used 248923K [0xffffffff38000000, 0xffffffff58000000, 0xffffffff63800000)
> }
> Total time for which application threads were stopped: 0.2631313 seconds
> Total time for which application threads were stopped: 0.0089191 seconds
> Total time for which application threads were stopped: 0.0065184 seconds
> Total time for which application threads were stopped: 0.0022136 seconds
> Total time for which application threads were stopped: 0.0072144 seconds
> Total time for which application threads were stopped: 0.0093864 seconds
> Total time for which application threads were stopped: 0.0022413 seconds
> Total time for which application threads were stopped: 0.0022476 seconds
> {Heap before GC invocations=12799 (full 1163):
>  par new generation   total 921600K, used 907236K [0xfffffffdc0000000, 0xfffffffdfe800000, 0xfffffffdfe800000)
>   eden space 819200K, 100% used [0xfffffffdc0000000, 0xfffffffdf2000000, 0xfffffffdf2000000)
>   from space 102400K,  85% used [0xfffffffdf8400000, 0xfffffffdfd9f9168, 0xfffffffdfe800000)
>   to   space 102400K,   0% used [0xfffffffdf2000000, 0xfffffffdf2000000, 0xfffffffdf8400000)
>  concurrent mark-sweep generation total 5136384K, used 2783239K [0xfffffffdfe800000, 0xffffffff38000000, 0xffffffff38000000)
>  concurrent-mark-sweep perm gen total 524288K, used 249075K [0xffffffff38000000, 0xffffffff58000000, 0xffffffff63800000)
> 1598514.042: [GC 1598514.043: [ParNew: 907236K->87165K(921600K), 0.1946563 secs] 3690475K->2896751K(6057984K), 0.1950345 secs] [Times: user=1.55 sys=0.07, real=0.20 secs] 
> Heap after GC invocations=12800 (full 1163):
>  par new generation   total 921600K, used 87165K [0xfffffffdc0000000, 0xfffffffdfe800000, 0xfffffffdfe800000)
>   eden space 819200K,   0% used [0xfffffffdc0000000, 0xfffffffdc0000000, 0xfffffffdf2000000)
>   from space 102400K,  85% used [0xfffffffdf2000000, 0xfffffffdf751f498, 0xfffffffdf8400000)
>   to   space 102400K,   0% used [0xfffffffdf8400000, 0xfffffffdf8400000, 0xfffffffdfe800000)
>  concurrent mark-sweep generation total 5136384K, used 2809586K [0xfffffffdfe800000, 0xffffffff38000000, 0xffffffff38000000)
>  concurrent-mark-sweep perm gen total 524288K, used 249075K [0xffffffff38000000, 0xffffffff58000000, 0xffffffff63800000)
> }
> Total time for which application threads were stopped: 0.2034239 seconds
> Total time for which application threads were stopped: 0.0075922 seconds
> Total time for which application threads were stopped: 0.0022152 seconds
> 
> Thanks,
> Erwin
> 
> 
>       
> _______________________________________________
> hotspot-gc-use mailing list
> hotspot-gc-use at openjdk.java.net
> http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use
_______________________________________________
hotspot-gc-use mailing list
hotspot-gc-use at openjdk.java.net
http://mail.openjdk.java.net/mailman/listinfo/hotspot-gc-use



More information about the hotspot-gc-dev mailing list