Imagine this: A user has deployed an application to a Tomcat server. After the application is movedinto production and is under load, it periodically stops managing the requests. As Daniel Mikusa,VMware SpringSource engineer explains in a post today, many times, the culprit is garbage collection.
While there are multiple possible causes to this problem like blocked threads, too much load on the server, or even application specific problems, the one cause of this problem that I see over and over is excessive garbage collection.
As an application runs it creates objects. As it continues to run, many of these objects are no longer needed. In Java, the unused objects remain in memory until a garbage collection occurs and frees up the memory used by the objects. In most cases, these garbage collections run very quickly, but occasionally the garbage collector will need to run a “full” collection.When a full collection is run, not only does it take a considerable amount of time, but the entire JVM has to be paused while the collector runs. It is this “stop-the-world” behavior that causes Tomcat to fail to respond to a request.
Garbage collection is necessary, however the goal to minimize performance impacts is to have full garbage collection run as fast and as infrequently as possible. To do this, the secret is to measure the duration of garbage collection, adjust your Apache Tomcat configuration or application logic, and then measure again after each adjustment. If you follow this pattern, you will always know exactly how the change you made affects the performance of your Tomcat instance. Because many garbage collection issues only occur under load, it's important generate some load on your system while you are taking measurements. Not only will this help you to more accurately replicate and test garbage collection issues, but it will also help you to minimize potential problems when you migrate you rnew garbage collection settings into production.
Do not blindly apply configuration settings to your Tomcat instance. Unless you've measured the performance before and after, you may not even know that you've just hurt the performance of your Tomcat instance.
To measure the performance of garbage collection we simply enable garbage collection logging.
This is done by adding the following JVM options to the CATALINA_OPTS variable in the bin/setenv.sh|bat file for your Tomcat instance.
-Xloggc:$CATALINA_HOME/logs/gc.log or Xloggc:%CATALINA_HOME%/logs/gc.log
-XX:+PrintHeapAtGC
-XX:+PrintGCDetails
-XX:+PrintGCTimeStamps
-XX:-HeapDumpOnOutOfMemoryError
Once these options are added and Tomcat is restarted, you should see a file logs/gc.log which will contain logging statements from the garbage collector. In that log file, you should see lines telling you when garbage collection has run and if it was full garbage collection. Some examples:
Partial garbage collection:
1.612: [GC [PSYoungGen: 12998K->1568K(18496K)] 12998K->1568K(60864K),0.0054130 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
Full garbage collection:
1.617: [Full GC (System) [PSYoungGen: 1568K->0K(18496K)] [PSOldGen: 0K->1483K(42368K)] 1568K->1483K(60864K) [PSPermGen: 9458K->9458K(21248K)],0.0294590 secs] [Times: user=0.02 sys=0.00, real=0.03 secs]
Continue to adjust your configuration or application to reach the goal of both a minimal number of garbage collections and a minimal amount of time spent on garbage collections. For more explanation on setting up performance tuning for garbage collection, check out the full article here.