Glassfish Memory Diagnostics
Hi,
This is with reference to issue which I'm facing on Glassfish. I have two Glassfish instance having same configuration (Memory and GC) but I have observed absurd behaviour on one of the instance.
Instance 1: On this instance GC working properly like when used memory reaches 2GB GC gets triggered and used memory gets released (500MB) it starts rising exponentially after 15 mins when used memory breached 2GB again GC gets triggered which is normal behaviour.
Instance 2: On this instance I have observed some absurd behaviour like on this instance we have continuous GC calls after GC triggered Used memory is released (500MB) then again within minute duration Used memory reaches 2GB as here Used memory released and abruptly gets raised which causes continuous GC calls because of which I’m getting suspension in PurePaths response time.
To trace issue I had trending Snapshot on instance which I’m facing issue which is not helping me to identify objects or classes consuming heap as whenever I have scheduled trending snapshot for trending GC gets called in between because of which used memory drops so I’m not able to identify objects.
Both instance having same configuration and versions also load is equally distributed over two instance.
Please find the attached snap for better understanding. Please revert as issue is critical and observed on production.
Hi,
I have to share one more observation.
As here I have observed that even though GC settings are same on both instance, on instance1 GC is called whenever used heap passed 2GB but on instance2 as we have not crossed used heap 2 GB still we have GC calls.
Please suggest.
Regards,
Amol
Hi Roland,
Thanks for additional info, but I have already checked GC setting on both the instance which is same. Please check below config string.
Instance1:-“Djavax.management.builder.initial=com.sun.enterprise.ee.admin.AppServerMBeanServerBuilder -Djdbc.drivers=org.apache.derby.jdbc.ClientDriver -Djmx.invoke.getters=true -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000 -server -XX:+UnlockDiagnosticVMOptions -Xloggc:/opt/SUNWappserver/domains/AxisITS1/logs/gc.log -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+DoEscapeAnalysis -XX:+PrintCommandLineFlags -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -Xmn2048m -XX:+DisableExplicitGC -XX:ParallelGCThreads=4 -XX:PermSize=512m -Xss256k -Xms5120m -XX:MaxPermSize=512m -Xmx5120m -XX:NewRatio=3 -agentpath:/opt/dynatrace/dynatrace-4.1.0/agent/lib64/libdtagent.so=name=GlassfishIntranet_AxisITS1,server=intranet.collector.axisssl.com:9998 -XX:+LogVMOutput -XX:LogFile=/opt/SUNWappserver/domains/AxisITS1/logs/jvm.log -cp /opt/SUNWappserver/lib/jhall.jar:/opt/SUNWappserver/lib/appserv-launch.jar com.sun.enterprise.server.PELaunch”
Instance2:-“Djavax.management.builder.initial=com.sun.enterprise.ee.admin.AppServerMBeanServerBuilder -Djdbc.drivers=org.apache.derby.jdbc.ClientDriver -Djmx.invoke.getters=true -Dsun.rmi.dgc.client.gcInterval=3600000 -Dsun.rmi.dgc.server.gcInterval=3600000 -server -XX:+UnlockDiagnosticVMOptions -Xloggc:/opt/SUNWappserver/domains/AxisITS2/logs/gc.log -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+DoEscapeAnalysis -XX:+PrintCommandLineFlags -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -Xmn2048m -XX:+DisableExplicitGC -XX:ParallelGCThreads=4 -XX:PermSize=512m -Xss256k -Xms5120m -XX:MaxPermSize=512m -Xmx5120m -XX:NewRatio=3 -agentpath:/opt/dynatrace/dynatrace-4.1.0/agent/lib64/libdtagent.so=name=GlassfishIntranet_AxisITS2,server=intranet.collector.axisssl.com:9998 -XX:+LogVMOutput -XX:LogFile=/opt/SUNWappserver/domains/AxisITS2/logs/jvm.log -cp /opt/SUNWappserver/lib/jhall.jar:/opt/SUNWappserver/lib/appserv-launch.jar com.sun.enterprise.server.PELaunch”
I collected GC information from command line under agent overview and as shown on both instance we have same setting for DisableExplicitGC and Dsun.rmi.dgc settings.
Please suggest and revert if you want any additional information.
Regards,
Amol khawre
Hi Amol,
one reason for GC runs every minute may be RMI.
If you're using a Java version < 1.6 you should have a look on the following link: http://bugs.sun.com/view_bug.do?bug_id=6200091. Before Java 1.6, RMI was triggering GC runs every minute, in Java 1.6 the default value was increased to 1 hour.
If you connect e.g. with JConsole or any other tool to the JMX connector of one Glassfish instance it can already be enough to change the GC behavior (just a guess, but may be an explanation for the different behavior of your instances)
Another reason may be a third part library which is using System.gc().
-XX:-DisableExplicitGC may help. See fore example the following link: http://sumitpal.wordpress.com/2010/05/06/how-we-solved-gc-every-1-minute-on-tomcat/.
But be careful with this setting, i may have some side effect, see for example: http://docs.oracle.com/cd/E18930_01/html/821-2431/abeic.html#scrolltoc (see note in chapter "Disabling Explicit Garbage Collection")
When taking memory snapshots you can configure if GC should be triggered or not. If GC is not triggered you should not see any impact on the memory.
I would look at how many requests (and if that is similar which types of requests) each of the instances gets. If the right instances gets a lot of requests while the left one is not doing a lot the memory charts would make sense.
Best, Roman
Hi Roman,
Thanks for quick reply.I have
kept forced GC uncheck while taking snapshot.But still default GC gets triggered as used memory breached 2 GB by JVM.
Please find the attachment for requests details.
Please suggest.
regards,
Amol
Amol,
I assume you just have a memory pool configuration issue and probably need to optimize your memory/GC settings for the JVMs.
If you are using dynaTrace 4.2 could you post a screenshot of the process health dashboard for the two glassfish processes?
You can access ist via Startcenter - Monitor Applications - Host Health Overview and then select the according host and process.
It should look like this:
Hi Reinhard,
Thanks, But if its issue with memory pool configuration issue then it should be on both the instances because as I mentioned earlier I have same GC and other configurations on both the instance and I have observed weird behaviour only on one instance.
As you mentioned you want host health dashboard which is not working in our case as we have zones in Solaris which is not supported by host agent (as per support team suggestion). Please find the attached screenshot for host health dashboard which is blank because of which I have created custom dashboards attached earlier.
Please suggest.
Regards,
Amol
Its observed that issue with Eden Space.Please find the attached screenshot.
Amol,
even though you are using Solaris you should be able to provide the Process health dashboard for Sun/Oracle JVM.
Reinhard
Amol,
those charts only show that one JVM has different GC runs and memory usage footprint.
It's certainly different behavior of your application (different load/transactions, different threads and/or background processes). You will need to do a more detailed memory analysis. e.g.:
- Object Allocation analysis
- Object Age/Survival analysis
- thread analysis
I guess for that a lot more information is required to triage. Maybe you can contact our Enablement Service to help you with analysis if it's urgent.
Reinhard
