users@glassfish.java.net

Big CMS GC pauses (a few seconds), CMS starts too early

From: <glassfish_at_javadesktop.org>
Date: Sun, 11 Jan 2009 02:10:17 PST

Hi,
We are running Glassfish on T1 platform. The problem is - Garbage collector pauses (CMS stop the world phases) are too big (a few seconds). And CMS GC starts much earlier than specified 60% old spase usage threshold.

Here is a part of GC log:
...
Application time: 0.7233430 seconds
Total time for which application threads were stopped: 0.0225951 seconds
Application time: 0.2143799 seconds
Total time for which application threads were stopped: 0.0026535 seconds
Application time: 0.0001222 seconds
81.135: [GC [1 CMS-initial-mark: 53632K(4063232K)] 162505K(4193344K), 0.4672062 secs] [Times: user=0.46 sys=0.01, real=0.47 secs]
Total time for which application threads were stopped: 0.4703977 seconds
81.603: [CMS-concurrent-mark-start]
Application time: 0.0017790 seconds
Total time for which application threads were stopped: 0.0091741 seconds
Application time: 0.0002857 seconds
Total time for which application threads were stopped: 0.0214153 seconds
82.582: [CMS-concurrent-mark: 0.363/0.979 secs] [Times: user=3.87 sys=0.08, real=0.98 secs]
82.582: [CMS-concurrent-preclean-start]
82.795: [CMS-concurrent-preclean: 0.211/0.213 secs] [Times: user=0.66 sys=0.02, real=0.21 secs]
82.796: [CMS-concurrent-abortable-preclean-start]
Application time: 2.3996964 seconds
...

The first run of CMS was at 81st second of JVM running while heap usage was only 52 MB. And it took about half a second instead of expected less than 100 ms.
Why does CMS run so early?
Why does it take so much time for stop-the-world pauses?

Glassfish version: Sun Java System Application Server 9.1_02 (build b04-fcs)
JVM settings:
      <java-config classpath-suffix="/opt/glassfish/lib" debug-enabled="false" debug-options="-Xdebug -Xrunjdwp:transport=dt_socket,server=y,suspend=n,address=9009" env-classpath-ignored="true" java-home="${com.sun.aas.javaRoot}" javac-options="-g" rmic-options="-iiop -poa -alwaysgenerate -keepgenerated -g">
        <!-- various required jvm-options -->
        <jvm-options>-Xms4G</jvm-options>
        <jvm-options>-Xmx4G</jvm-options>
        <jvm-options>-XX:+CMSClassUnloadingEnabled</jvm-options>
        <jvm-options>-XX:+DisableExplicitGC</jvm-options>
        <jvm-options>-XX:MaxNewSize=128m</jvm-options>
        <jvm-options>-XX:NewSize=128m</jvm-options>
        <jvm-options>-XX:MaxPermSize=128m</jvm-options>
        <jvm-options>-XX:PermSize=128m</jvm-options>
        <jvm-options>-XX:+UseParNewGC</jvm-options>
        <jvm-options>-XX:+UseConcMarkSweepGC</jvm-options>
        <jvm-options>-XX:MaxTenuringThreshold=0</jvm-options>
        <jvm-options>-XX:SurvivorRatio=128</jvm-options>
        <jvm-options>-XX:CMSInitiatingOccupancyFraction=60</jvm-options>
        <jvm-options>-XX:+UseCMSInitiatingOccupancyOnly</jvm-options>
        <jvm-options>-XX:+CMSParallelRemarkEnabled</jvm-options>
        <jvm-options>-verbose:gc</jvm-options>
        <jvm-options>-Xloggc:${com.sun.aas.instanceRoot}/logs/gc.log</jvm-options>
        <jvm-options>-XX:+PrintGCTimeStamps</jvm-options>
        <jvm-options>-XX:+PrintGCDetails</jvm-options>
        <jvm-options>-XX:+PrintTenuringDistribution</jvm-options>
        <jvm-options>-XX:+PrintGCApplicationConcurrentTime</jvm-options>
        <jvm-options>-XX:+PrintGCApplicationStoppedTime</jvm-options>
        <jvm-options>-d64</jvm-options>
        <jvm-options>-Djava.library.path=/opt/TimesTen/tt70/lib</jvm-options>
        <jvm-options>-Djava.rmi.server.codebase=file:/home/aabalmasov/tmp/mpcc-jee-transport.jar</jvm-options>
        <jvm-options>-server</jvm-options>
        <jvm-options>-Djava.endorsed.dirs=${com.sun.aas.installRoot}/lib/endorsed</jvm-options>
        <jvm-options>-Djava.security.policy=${com.sun.aas.instanceRoot}/config/server.policy</jvm-options>
        <jvm-options>-Djava.security.auth.login.config=${com.sun.aas.instanceRoot}/config/login.conf</jvm-options>
        <jvm-options>-Djavax.net.ssl.keyStore=${com.sun.aas.instanceRoot}/config/keystore.jks</jvm-options>
        <jvm-options>-Djavax.net.ssl.trustStore=${com.sun.aas.instanceRoot}/config/cacerts.jks</jvm-options>
        <jvm-options>-Djava.ext.dirs=${com.sun.aas.javaRoot}/lib/ext${path.separator}${com.sun.aas.javaRoot}/jre/lib/ext${path.separator}${com.sun.aas.instanceRoot}/lib/ext${path.separator}${com.sun.aas.derbyRoot}/lib</jvm-options>
        <jvm-options>-Djdbc.drivers=org.apache.derby.jdbc.ClientDriver</jvm-options>
        <jvm-options>-Djavax.management.builder.initial=com.sun.enterprise.admin.server.core.jmx.AppServerMBeanServerBuilder</jvm-options>
        <jvm-options>-Dcom.sun.enterprise.config.config_environment_factory_class=com.sun.enterprise.config.serverbeans.AppserverConfigEnvironmentFactory</jvm-options>
        <jvm-options>-Dcom.sun.enterprise.taglibs=appserv-jstl.jar,jsf-impl.jar</jvm-options>
        <jvm-options>-Dcom.sun.enterprise.taglisteners=jsf-impl.jar</jvm-options>
        <jvm-options>-Djava.security.manager</jvm-options>
      </java-config>
Hardware:
Sun Microsystems sun4v Sun Fire(TM) T1000
System clock frequency: 200 MHz
Memory size: 8184 Megabytes
6 cores, 1 GHz
[Message sent by forum member 'theme_theme' (theme_theme)]

http://forums.java.net/jive/thread.jspa?messageID=325209