Java GC 調試手記

摘要

本文記錄GC調試的一次實驗過程和結果。

GC知識要點回顧

問題1：爲何要調試GC參數？
在32核處理器的系統上，10%的GC時間致使75%的吞吐量損失。因此在大型系統上，調試GC是以小博大的不錯選擇。'small improvements in reducing such a bottleneck can produce large gains in performance.'

問題2：怎麼樣調試GC?

調試GC，有三個主要的參數：

• 選擇合適的GC Collector

• 整個JVM Heap堆的大小

• Young Generation的大小(-Xmn?m or -XX:NewRatio=?)

問題3：有哪些不一樣的GC Collector?

Tony Printezis (JVM大牛)在Garbage Collection in the Java HotSpot Virtual Machine有圖爲證，還有一篇更早的sun開發人員介紹GC調試也是有圖爲證

neo4j總結以下

GC shortname	Generation	Command line parameter	Comment
Copy	Young	-XX:+UseSerialGC	The Copying collector
MarkSweepCompact	Tenured	-XX:+UseSerialGC	The Mark and Sweep Compactor
ConcurrentMarkSweep	Tenured	-XX:+UseConcMarkSweepGC	The Concurrent Mark and Sweep Compactor
ParNew	Young	-XX:+UseParNewGC	The parallel Young Generation Collector—can only be used with the Concurrent mark and sweep compactor.
PS Scavenge	Young	-XX:+UseParallelGC	The parallel object scavenger
PS MarkSweep	Tenured	-XX:+UseParallelGC	The parallel mark and sweep collector

簡而言之，Young和Tenured各類三種Collector，分別是

• Serial 單線程

• Parallel 多線程並行, GC線程和App線程取一運行，即GC要Stop the (app) world。

• Concurrent 多線程併發，GC線程和App線程可同時運行。(注: Young generation 沒有CMS，取而代之的是可和CMS(Old)一塊兒運行的ParNew)

問題4：如何選擇Collector?

Serial能夠直接排除掉，如今最普通的服務器也有雙核64位\8G內存，默認的Collector是PS Scavenge和PS MarkSweep。因此Collector在並行(Parallel)和併發(Concurrent)二者之間選擇。

問題5：選擇的標準(參數指標)是什麼?如何獲得這些參數值(How to measure it)?

throughput和latency。garbage-collection-in-java-part-3從GC的耗時給出了吞吐量和響應速度的公式

Total Execution Time = Useful Time + Paused Time

throughput = Useful Time / Total Execution Time

latency = average paused time

如何獲得Useful time 和 Paused Time?即如何獲得JVM的GC時間，有如下幾種方式

GC Log

打印GC log，java 啓動參數中加入下面的語句(本文爲tomcat應用)。GC Log 記錄每次GC時間，可根據GC Log計算平均GC時間和累積GC時間。

[plain] view plain copy

1. CATALINA_OPTS="$CATALINA_OPTS -verbose:gc -Xloggc:/usr/local/tomcat/gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps"  

Jconsole

JDK自帶工具，java 啓動參數中加入下面的語句(本文爲tomcat應用)，而後在監控端能夠遠程鏈接1090端口。在內存一項，有累積GC時間和次數。注意在以min爲單位顯示時，只顯示整數部分，如1min20s顯示爲1min。

[plain] view plain copy

1. CATALINA_OPTS="$CATALINA_OPTS -Dcom.sun.management.jmxremote.port=1090 -Dcom.sun.management.jmxremote.ssl=false -Dcom.sun.management.jmxremote.authenticate=false"  

VisualGC

JVM監控工具，未同JDK一塊兒發佈，可在JVisualvm(JDK自帶)中以插件的方式使用，本文爲獨立使用。有累積GC時間和次數，並有曲線圖直觀顯示。

首先在Server端啓動jstatd

[plain] view plain copy

1. vi jstatd.all.policy  

2.   

3. grant codebase "file:${java.home}/../lib/tools.jar" {  

4.     permission java.security.AllPermission;  

5. };  

6.   

7. jstatd -J-Djava.security.policy=jstatd.all.policy  

而後在監控啓動VisualGC，遠程鏈接服務端進程id

visualgc 102592@remote.domain

問題5：應用請求的吞吐量和響應是否能夠反映JVM的性能?

正是咱們調優的目標。本文使用Jmeter來作壓力測試，並給出吞吐量和響應 report。

測試

硬件環境

操做系統:  Linux 2.6.18-53.el5 體系結構:  amd64 處理器的數目:  2 分配的虛擬內存:  2,680,408 Kb

物理內存總量:  8,175,632 Kb 可用物理內存:  1,140,520 Kb 交換空間總量:  8,594,764 Kb 可用交換空間:  8,594,680 Kb

Test case

1. 使用用Jmeter壓力測試

2. 共6個client，每一個client啓動30個線程發送請求

3. 每一個請求從16種測試樣例中隨機挑選一個，發送到server端

4. 測試持續10min

參數值

1. server使用默認GC(PS Scavenge和PS MarkSweep)

2. server使用CMS(-XX:+UseConcMarkSweepGC-XX:+UseParNewGC)

3. server使用CMS(-XX:+UseConcMarkSweepGC -XX:+UseParNewGC)，設置Young generation的大小爲200m(-Xmn200m)

4. server使用CMS(-XX:+UseConcMarkSweepGC -XX:+UseParNewGC)，設置Young generation的大小爲600m(-Xmn600m)

觀察值

1. Jmeter請求的summary report

2. server端累積GC時間和次數

測試結果

1) CMS和Parallel比較

1.1) 吞吐量和響應

(PS Scavenge和PS MarkSweep)

(ParNew和CMS)

從 Jmeter的report中能夠看出, 使用CMS後吞吐量(對應總的請求數)降低18%，而最大響應時間(包括最小響應時間)有近30%的提高(變小)。這驗證了Tony Printezis在Step-by-Step:Garbage Collection Tuning in the Java HotSpot Virtual Machine中說使用CMS應用的吞吐量會相對降低，但有更好的最差響應時間。

• Expect longer young GC times

  • Due to slower allocations into the old gen

• Expect better worst-case latencies

  • CMS does its work mostly-concurrently

  • Shorter worst-case pauses

• Expect lower throughput

  • CMS does more work

在官方的JVM性能調優中給出的建議也是，若是你的應用對峯值處理有要求，而對一兩秒的停頓能夠接受，則使用(-XX:+UseParallelGC)；若是應用對響應有更高的要求，停頓最好小於一秒，則使用(-XX:+UseConcMarkSweepGC)。

1.2) GC 累積時間和次數

(PS Scavenge和PS MarkSweep)

(ParNew和CMS)

PS累積GC時間(visualgc)爲1min25s，其中Eden 189次，共52s；old 13次，共33s。

CMS 累積GC(visualgc)爲2min2s，其中Eden 2333次，共1min46s；old 55次，共16s。(Jconsole和GC log卻顯示沒有Full GC，從understanding cms gc logs和jstat顯示的full GC次數與CMS週期的關係中我推測visualgc與jstat顯示一致，都是統計old的回收次數；而Full GC則是Young和Old一塊兒回收，在其餘類型的GC裏，Old只有Full GC時才觸發)。

能夠看到PS的GC頻率相對低，但每次GC時間長，每次Full在3s左右徘徊，Yong在0.3s左右；CMS則是短頻快，頻繁快速回收，yong在0.03s(<0.1s)左右，old<0.5s。從JMeter上，使用PS GC，Request Report會有間歇性的停頓，即server沒有任何響應；CMS則相對較少，停頓不那麼明顯。

2) CMS下不一樣Xmn的比較

因爲CMS Young太多頻繁，又測試了分別調整Xmn爲200m和600m以後的結果。200m是仿照cassandra中100m * cpu #來設置Young gen的大小；600m則是與PS下的Young gen一致。

200m

600m

隨着Young gen的增大(40m -> 200m -> 600m)，Young 的回收次數減小，Old的回收次數增長，整體GC累積時間降低，應用吞吐量上升，最差響應時間變慢(即使和PS比較也更差，是個人測試有問題?)。

結論

app停頓3s是不可接受的，所以傾向於使用CMS；CMS的default young gen至關小，因而設置Xmn。對於更加Prefer響應的應用，下面配置是不是黃金標配:

JVM_OPTS="$JVM_OPTS -XX:+UseParNewGC" JVM_OPTS="$JVM_OPTS -XX:+UseConcMarkSweepGC" JVM_OPTS="$JVM_OPTS -XX:+CMSParallelRemarkEnabled" JVM_OPTS="$JVM_OPTS -XX:SurvivorRatio=8" JVM_OPTS="$JVM_OPTS -XX:MaxTenuringThreshold=1"JVM_OPTS="$JVM_OPTS -XX:CMSInitiatingOccupancyFraction=75"JVM_OPTS="$JVM_OPTS -XX:+UseCMSInitiatingOccupancyOnly"