High Par New collection times

Erwin tanman12345 at yahoo.com
Tue Jan 4 08:02:42 PST 2011


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


      


More information about the hotspot-gc-use mailing list