GC running at startup
Hi,
I'm running the JBoss AS 4.0.3SP1 and suddenly I'v gotten problems with GC messages just after I start the JBoss server. The startup log looks like this.
linux-java-test01:/u01/jboss/bin# =========================================================================
JBoss Bootstrap Environment
JBOSS_HOME: /u01/jboss
JAVA: /opt/jdk1.6.0_18/bin/java
JAVA_OPTS: -server -Xms1024m -Xmx1024m -Xss256k -XX:+DisableExplicitGC -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000 -XX:NewSize=128m -XX:MaxNewSize=128m -XX:PermSize=64m -XX:MaxPermSize=128m -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:+CMSParallelRemarkEnabled -XX:SoftRefLRUPolicyMSPerMB=10000 -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC -XX:+PrintGCDetails -Dprogram.name=run.sh
CLASSPATH: /u01/jboss/bin/run.jar:/opt/jdk1.6.0_18/lib/tools.jar
=========================================================================
14:40:34,052 INFO [Server] Starting JBoss (MX MicroKernel)...
14:40:34,060 INFO [Server] Release ID: JBoss [Zion] 4.0.3SP1 (build: CVSTag=JBoss_4_0_3_SP1 date=200510231054)
14:40:34,061 INFO [Server] Home Dir: /u01/jboss
14:40:34,062 INFO [Server] Home URL: file:/u01/jboss/
14:40:34,063 INFO [Server] Patch URL: null
14:40:34,063 INFO [Server] Server Name: default
14:40:34,063 INFO [Server] Server Home Dir: /u01/jboss/server/default
14:40:34,063 INFO [Server] Server Home URL: file:/u01/jboss/server/default/
14:40:34,063 INFO [Server] Server Temp Dir: /u01/jboss/server/default/tmp
14:40:34,064 INFO [Server] Root Deployment Filename: jboss-service.xml
14:40:34,495 INFO [ServerInfo] Java version: 1.6.0_18,Sun Microsystems Inc.
14:40:34,496 INFO [ServerInfo] Java VM: Java HotSpot(TM) 64-Bit Server VM 16.0-b13,Sun Microsystems Inc.
14:40:34,496 INFO [ServerInfo] OS-System: Linux 2.6.26-2-amd64,amd64
14:40:34,988 INFO [Server] Core system initialized
14:40:36,901 INFO [WebService] Using RMI server codebase: http://linux-java-test01:8083/
14:40:36,914 INFO [Log4jService$URLWatchTimerTask] Configuring from URL: resource:log4j.xml
{Heap before GC invocations=0 (full 0):
def new generation total 118016K, used 104960K [0x00007f558cf90000, 0x00007f5594f90000, 0x00007f5594f90000)
eden space 104960K, 100% used [0x00007f558cf90000, 0x00007f5593610000, 0x00007f5593610000)
from space 13056K, 0% used [0x00007f5593610000, 0x00007f5593610000, 0x00007f55942d0000)
to space 13056K, 0% used [0x00007f55942d0000, 0x00007f55942d0000, 0x00007f5594f90000)
concurrent mark-sweep generation total 917504K, used 0K [0x00007f5594f90000, 0x00007f55ccf90000, 0x00007f55ccf90000)
concurrent-mark-sweep perm gen total 65536K, used 18571K [0x00007f55ccf90000, 0x00007f55d0f90000, 0x00007f55d4f90000)
5.878: [GC 5.879: [DefNew: 104960K->9800K(118016K), 0.0447440 secs] 104960K->9800K(1035520K), 0.0448350 secs] [Times: user=0.05 sys=0.00, real=0.04 secs]
Heap after GC invocations=1 (full 0):
def new generation total 118016K, used 9800K [0x00007f558cf90000, 0x00007f5594f90000, 0x00007f5594f90000)
eden space 104960K, 0% used [0x00007f558cf90000, 0x00007f558cf90000, 0x00007f5593610000)
from space 13056K, 75% used [0x00007f55942d0000, 0x00007f5594c62178, 0x00007f5594f90000)
to space 13056K, 0% used [0x00007f5593610000, 0x00007f5593610000, 0x00007f55942d0000)
concurrent mark-sweep generation total 917504K, used 0K [0x00007f5594f90000, 0x00007f55ccf90000, 0x00007f55ccf90000)
concurrent-mark-sweep perm gen total 65536K, used 18571K [0x00007f55ccf90000, 0x00007f55d0f90000, 0x00007f55d4f90000)
}
{Heap before GC invocations=1 (full 0):
def new generation total 118016K, used 114760K [0x00007f558cf90000, 0x00007f5594f90000, 0x00007f5594f90000)
eden space 104960K, 100% used [0x00007f558cf90000, 0x00007f5593610000, 0x00007f5593610000)
from space 13056K, 75% used [0x00007f55942d0000, 0x00007f5594c62178, 0x00007f5594f90000)
to space 13056K, 0% used [0x00007f5593610000, 0x00007f5593610000, 0x00007f55942d0000)
concurrent mark-sweep generation total 917504K, used 0K [0x00007f5594f90000, 0x00007f55ccf90000, 0x00007f55ccf90000)
concurrent-mark-sweep perm gen total 65536K, used 25674K [0x00007f55ccf90000, 0x00007f55d0f90000, 0x00007f55d4f90000)
8.770: [GC 8.770: [DefNew: 114760K->9934K(118016K), 0.0722620 secs] 114760K->19637K(1035520K), 0.0723560 secs] [Times: user=0.07 sys=0.00, real=0.07 secs]
Heap after GC invocations=2 (full 0):
def new generation total 118016K, used 9934K [0x00007f558cf90000, 0x00007f5594f90000, 0x00007f5594f90000)
eden space 104960K, 0% used [0x00007f558cf90000, 0x00007f558cf90000, 0x00007f5593610000)
from space 13056K, 76% used [0x00007f5593610000, 0x00007f5593fc3ad0, 0x00007f55942d0000)
to space 13056K, 0% used [0x00007f55942d0000, 0x00007f55942d0000, 0x00007f5594f90000)
concurrent mark-sweep generation total 917504K, used 9702K [0x00007f5594f90000, 0x00007f55ccf90000, 0x00007f55ccf90000)
concurrent-mark-sweep perm gen total 65536K, used 25674K [0x00007f55ccf90000, 0x00007f55d0f90000, 0x00007f55d4f90000)
}
And it continue with the "Heap after GC invocations" messages if I browse to the server. I only get these messages when running on linux (debian and red-hat), not in windows. The really strange thing is that I can't remember that I had these GC messages in the startup a couple of months ago and no changes has been done to the Jboss installation or deployments to the server, but I could be wrong (maybe just missed them before). However I would like to know if they are serious, and if they are, what I can do to configure my server the right way so it doesn't have to run GC all the time. My linux servers are virtual servers that are based on VMware if that maybe has an impact. The virtual server has 4GB of memory so it shouldn't be a problem with available memory.
/Andreas
