3 Replies Latest reply on Mar 12, 2012 5:37 PM by peterj

    Interpreting GC verbose data for JBoss Server

    todd.beckwith

      Greetings All. TIA for any guidance you may be able to provide.

       

      Prior to the beginning of last week, the only thing I knew about JBoss was that we used it in providing our internal users access to webpages created in a production called Natural for Ajax. I've been working in my current position for about 6 months and prior to that, developed applications for Telnet screens in a language called Natural. My IT director in my current position has been unhappy with performance of the webpages created in Natural for Ajax but I started my crash course in JBoss after fulfilling a request to add a new menu system to all of the webpages in our new system. All was well as we slowly shifted users to the new menus but once we opened it up to everyone, we began getting performance complaints. The users were experiencing 8 to 10 second hangs during round trips with the server. We ultimately had to remove a majority of users from the new menu system. After ruling out other components of the system and extensive Internet searching, I began to suspect garbage collection may be the problem.

       

      I have since made a few changes that allow me to capture the GC statistics. I immediately noted that full GC was occuring every two minutes, even on our test system without any users. Other than the changes to capture GC data, the only other change I've made to date is to set -XX:+DisableExplicitGC. I do not have statistics on GC with all users on the new menu but I have little doubt that we will see a performance impact if we throw everyone back on it without making additional changes.

       

      So, my question is, now that I have a days worth of GC data, how do I go about interpreting it? My gut tells me that new gen space is probably too small right now but I'm not sure how to determine a new size for new gen or calculate a survivor space ratio based on the data collected. Does anyone have a good link to information on how to make heads or tails out of what I am seeing in the GC logs?

       

      I have attached the current GC data. Users don't really start hitting our system until the 149049.856 mark in the file.

       

      Below are the current parameters being used.

       

      JBoss Version:4.2.3.GA

       

      Current heap size:1,266,187 kbytes
      Maximum heap size:2,796,224 kbytes
      Committed memory:2,071,552 kbytes
      Uptime:2 days 0 hours 12 minutes
      Garbage collector:Name = 'PS MarkSweep', Collections = 5, Total time spent = 48.361 seconds
      Garbage collector:Name = 'PS Scavenge', Collections = 1,318, Total time spent = 1 minute

       

      Operating System:HP-UX B.11.31
      Architecture:IA64N
      Number of processors:4
      Committed virtual memory:-1 kbytes
      Total physical memory:33,451,448 kbytes
      Free physical memory:19,695,784 kbytes
      Total swap space:16,777,216 kbytes
      Free swap space:16,777,216 kbytes

       

      VM arguments:

        -Dprogram.name=run.sh

        -Xms3g

        -Xmx3g

        -Dsun.rmi.dgc.client.gcInterval=3600000

        -Dsun.rmi.dgc.server.gcInterval=3600000

        -Dcom.sun.management.jmxremote

        -verbose:gc

        -Xloggc:/SAG/java/jboss_gc_20120310133545.log

        -XX:+PrintGCDetails

        -XX:+PrintGCTimeStamps

        -XX:+DisableExplicitGC

        -Djava.endorsed.dirs=/opt/jboss/jboss-4.2.3.GA/lib/endorsed

       

      Thank you.

        • 1. Re: Interpreting GC verbose data for JBoss Server
          peterj

          For suggestions on how to gather GC data and analyze it, see these white papers:

          Java Garbage Collection Statistical Analysis 101

          Java Garbage Collection Performance Analysis 201

          at http://www.cmg.org/cgi-bin/search.cgi?q=java+peter+johnson&x=30&y=10

           

          Which version of the JVM are you using? If earlier than 1.6, you should also set the young generation size. I recommend about 1/3 to 1/4 the heap size, so 1g should be about right (see the white papers for details).

           

          The full GC every 2 minutes seems to indicate that there is a thread that runs every two minutes and calls Syste,.gc(). I assume that once you set -XX:+DisableExplicitGC that you no longer see the full GCs every two minutes.

          1 of 1 people found this helpful
          • 2. Re: Interpreting GC verbose data for JBoss Server
            todd.beckwith

            Peter,

             

            The Java version is 1.6.0.02.

             

            DisableExplicitGC did help with no reported problems from the users. It took about 2 hours for the first full GC and they are now occuring about every 45 minutes. This change alone has resulted in a significant reduction in the number of full collections and time spent in data collection. Based on some of my previous reading, I suspect there may still be room to increase the young generation and further reduce the number of full collections. I'll take a look at the membership requirements for the link you provided and see if the info there can help me out.

             

            Thanks Peter.

            • 3. Re: Interpreting GC verbose data for JBoss Server
              peterj

              My experience with the 1.6.0 version of the JVM is that it does a very good job of automatically sizing the young generation, usually using 1/3 the heap size. So for 1.6.0 you don't need to set the young gen size. (The white papers I mentioned are fairly old and concern mostly 1.3.1 and 1.4.2, though the techniques described are still valid. Some of my later papers cover 1.5 and 1.6 and some of the tuning differences.)