成為JavaGC專家(2)—如何監控Java垃圾回收機制
本文是成為Java GC專家系列文章的第二篇。在第一篇《深入淺出Java垃圾回收機制》中我們學習了不同GC演算法的執行過程,GC是如何工作的,什麼是新生代和老年代,你應該瞭解的JDK7中的5種GC型別,以及這5種類型對於應用效能的影響。
在本文中,我將解釋JVM到底是如何執行垃圾回收處理的。
什麼是GC監控?
垃圾回收收集監控指的是搞清楚JVM如何執行GC的過程,例如,我們可以查明:
1. 何時一個新生代中的物件被移動到老年代時,所花費的時間。
2. Stop-the-world 何時發生的,持續了多長時間。
GC監控是為了鑑別JVM是否在高效地執行GC,以及是否有必要進行額外的效能調優。基於以上資訊,我們可以修改應用程式或者調整GC演算法(GC優化)。
如何監控GC
有很多種方法可以監控GC,但其差別僅僅是GC操作通過何種方式展現而已。GC操作是由JVM來完成,而GC監控工具只是將JVM提供的GC資訊展現給你,因此,不論你使用何種方式監控GC都將得到相同的結果。所以你也就不必去學習所有的監控GC的方法。但是因為學習每種監控方法不會佔用太多時間,瞭解多一點可以幫助你根據不同的場景選擇最為合適的方式。
下面所列的工具以及JVM引數並不適用於所有的HVM供應商。這是因為並沒有關於GC資訊的強制標準。本文我們將使用HotSpot JVM (Oracle JVM)。因為NHN 一直在使用Oracle (Sun) JVM,所以用它作為示例來解釋我們提到的工具和JVM引數更容易些。
首先,GC監控方法根據訪問的介面不同,可以分成CUI 和GUI 兩大類。CUI GC監控方法使用一個獨立的叫做”jstat”的CUI應用,或者在啟動JVM的時候選擇JVM引數”verbosegc”。
GUI GC監控由一個單獨的圖形化應用來完成,其中三個最常用的應用是”jconsole”, “jvisualvm” 和 “Visual GC”。
下面我們來詳細學習每種方法。
jstat
jstat 是HotSpot JVM提供的一個監控工具。其他監控工具還有jps 和jstatd。有些時候,你可能需要同時使用三種工具來監控你的應用。jstat 不僅提供GC操作的資訊,還提供類裝載操作的資訊以及執行時編譯器操作的資訊。本文將只涉及jstat能夠提供的資訊中與監控GC操作資訊相關的功能。
jstat 被放置在$JDK_HOME/bin。因此只要java 和 javac能執行,jstat 同樣可以執行。
你可以在命令列環境下執行如下語句。
12345678 | $> jstat –gc $<vmid$> 1000 S0C S1C S0U S1U EC EU OC OU PC PU YGC YGCT FGC FGCT GCT 3008.0 3072.0 0.0 1511.1 343360.0 46383.0 699072.0 283690.2 75392.0 41064.3 2540 18.454 4 1.133 19.588 3008.0 3072.0 0.0 1511.1 343360.0 47530.9 699072.0 283690.2 75392.0 41064.3 2540 18.454 4 1.133 19.588 3008.0 3072.0 0.0 1511.1 343360.0 47793.0 699072.0 283690.2 75392.0 41064.3 2540 18.454 4 1.133 19.588 $> |
在上圖的例子中,實際的資料會按照如下列輸出:
1 | S0C S1C S0U S1U EC EU OC OU PC |
vmid (虛擬機器 ID),正如其名字描述的,它是虛擬機器的ID,Java應用不論執行在本地還是遠端的機器都會擁有自己獨立的vmid。執行在本地機器上的vmid稱之為lvmid (本地vmid),通常是PID。如果想得到PID的值你可以使用ps命令或者windows工作管理員,但我們推薦使用jps來獲取,因為PID和lvmid有時會不一致。jps 通過Java PS實現,jps命令會返回vmids和main方法的資訊,正如ps命令展現PIDS和程序名字那樣。
首先通過jps命令找到你要監控的Java應用的vmid,並把它作為jstat的引數。當幾個WAS例項執行在同一臺裝置上時,如果你只使用jps命令,將只能看到啟動(bootstrap)資訊。我們建議在這種情況下使用ps -ef | grep java與jps配合使用。
想要得到GC效能相關的資料需要持續不斷地監控,因此在執行jstat時,要規則地輸出GC監控的資訊。
例如,執行”jstat –gc 1000″ (或 1s)會每隔一秒展示GC監控資料。”jstat –gc 1000 10″會每隔1秒展現一次,且一共10次。
引數名稱 | 描述 |
gc | 輸出每個堆區域的當前可用空間以及已用空間(伊甸園,倖存者等等),GC執行的總次數,GC操作累計所花費的時間。 |
gccapactiy | 輸出每個堆區域的最小空間限制(ms)/最大空間限制(mx),當前大小,每個區域之上執行GC的次數。(不輸出當前已用空間以及GC執行時間)。 |
gccause | 輸出-gcutil提供的資訊以及最後一次執行GC的發生原因和當前所執行的GC的發生原因 |
gcnew | 輸出新生代空間的GC效能資料 |
gcnewcapacity | 輸出新生代空間的大小的統計資料。 |
gcold | 輸出老年代空間的GC效能資料。 |
gcoldcapacity | 輸出老年代空間的大小的統計資料。 |
gcpermcapacity | 輸出持久帶空間的大小的統計資料。 |
gcutil | 輸出每個堆區域使用佔比,以及GC執行的總次數和GC操作所花費的事件。 |
你可以只關心那些最常用的命令,你會經常用到 -gcutil (或-gccause), -gc and –gccapacity。
· -gcutil 被用於檢查堆間的使用情況,GC執行的次數以及GC操作所花費的時間。
· -gccapacity以及其他的引數可以用於檢查實際分配記憶體的大小。
使用-gc 引數你可以看到如下輸出:
1234 | S0C S1C … GCT 1248.0 896.0 … 1.246 1248.0 896.0 … 1.246 … … … … |
不同的jstat引數輸出不同型別的列,如下表所示,根據你使用的”jstat option”會輸出不同列的資訊。
列 | 說明 | Jstat引數 |
S0C | 輸出Survivor0空間的大小。單位KB。 | -gc -gccapacity -gcnew -gcnewcapacity |
S1C | 輸出Survivor1空間的大小。單位KB。 | -gc -gccapacity -gcnew -gcnewcapacity |
S0U | 輸出Survivor0已用空間的大小。單位KB。 | -gc -gcnew |
S1U | 輸出Survivor1已用空間的大小。單位KB。 | -gc -gcnew |
EC | 輸出Eden空間的大小。單位KB。 | -gc -gccapacity -gcnew -gcnewcapacity |
EU | 輸出Eden已用空間的大小。單位KB。 | -gc -gcnew |
OC | 輸出老年代空間的大小。單位KB。 | -gc -gccapacity -gcold -gcoldcapacity |
OU | 輸出老年代已用空間的大小。單位KB。 | -gc -gcold |
PC | 輸出持久代空間的大小。單位KB。 | -gc -gccapacity -gcold -gcoldcapacity -gcpermcapacity |
PU | 輸出持久代已用空間的大小。單位KB。 | -gc -gcold |
YGC | 新生代空間GC時間發生的次數。 | -gc -gccapacity -gcnew -gcnewcapacity -gcold -gcoldcapacity -gcpermcapacity -gcutil -gccause |
YGCT | 新生代GC處理花費的時間。 | -gc -gcnew -gcutil -gccause |
FGC | full GC發生的次數。 | -gc -gccapacity -gcnew -gcnewcapacity -gcold -gcoldcapacity -gcpermcapacity -gcutil -gccause |
FGCT | full GC操作花費的時間 | -gc -gcold -gcoldcapacity -gcpermcapacity -gcutil -gccause |
GCT | GC操作花費的總時間。 | -gc -gcold -gcoldcapacity -gcpermcapacity -gcutil -gccause |
NGCMN | 新生代最小空間容量,單位KB。 | -gccapacity -gcnewcapacity |
NGCMX | 新生代最大空間容量,單位KB。 | -gccapacity -gcnewcapacity |
NGC | 新生代當前空間容量,單位KB。 | -gccapacity -gcnewcapacity |
OGCMN | 老年代最小空間容量,單位KB。 | -gccapacity -gcoldcapacity |
OGCMX | 老年代最大空間容量,單位KB。 | -gccapacity -gcoldcapacity |
OGC | 老年代當前空間容量制,單位KB。 | -gccapacity -gcoldcapacity |
PGCMN | 持久代最小空間容量,單位KB。 | -gccapacity -gcpermcapacity |
PGCMX | 持久代最大空間容量,單位KB。 | -gccapacity -gcpermcapacity |
PGC | 持久代當前空間容量,單位KB。 | -gccapacity -gcpermcapacity |
PC | 持久代當前空間大小,單位KB | -gccapacity -gcpermcapacity |
PU | 持久代當前已用空間大小,單位KB | -gc -gcold |
LGCC | 最後一次GC發生的原因 | -gccause |
GCC | 當前GC發生的原因 | -gccause |
TT | 老年化閾值。被移動到老年代之前,在新生代空存活的次數。 | -gcnew |
MTT | 最大老年化閾值。被移動到老年代之前,在新生代空存活的次數。 | -gcnew |
DSS | 倖存者區所需空間大小,單位KB。 | -gcnew |
jstat 的好處是它可以持續的監控GC操作資料,不論Java應用是執行在本地還是遠端,只要有控制檯的地方就可以使用。當使用–gcutil 會輸出如下資訊。在GC優化的時候,你需要特別注意YGC, YGCT, FGC, FGCT 和GCT。
1234 | S0 S1 E O P YGC YGCT FGC FGCT GCT 0.00 66.44 54.12 10.58 86.63 217 0.928 2 0.067 0.995 0.00 66.44 54.12 10.58 86.63 217 0.928 2 0.067 0.995 0.00 66.44 54.12 10.58 86.63 217 0.928 2 0.067 0.995 |
這些資訊很重要,因為它們展示了GC處理到底花費了多少時間。
在這個例子中,YGC 是217而YGCT 是0.928,這樣在簡單的計算資料平均數後,你可以知道每次新生代的GC大概需要4ms(0.004秒),而full GC的平均時間為33ms。
但是,只看資料平均數經常無法分析出真正的GC問題。這是主要是因為GC操作時間嚴重的偏差(換句話說,假如兩次full GC的時間是 67ms,那麼其中的一次full GC可能執行了10ms而另一個可能執行了57ms。)為了更好地檢測每次GC處理時間,最好使用 –verbosegc來替代資料平均數。
-verbosegc
-verbosegc 是在啟動一個Java應用時可以指定的JVM引數之一。而jstat 可以監控任何JVM應用,即便它沒有制定任何引數。 -verbosegc 需要在啟動的時候指定,因此你可能會認為它沒有必要(因為jstat可以替代之)。但是, -verbosegc 會以更淺顯易懂的方式展現GC發生的結果,因此他對於監控監控GC資訊十分有用。
jstat | -verbosegc | |
監控物件 | 執行在本機的Java應用可以把日誌輸出到終端上,或者藉助jstatd命令通過網路連線遠端的Java應用。 | 只有那些把-verbogc作為啟動引數的JVM。 |
輸出資訊 | 堆狀態(已用空間,最大限制,GC執行次數/時間,等等) | 執行GC前後新生代和老年代空間大小,GC執行時間。 |
輸出時間 | Every designated time 每次設定好的時間。 | 每次GC發生的時候。 |
何時有用。 | 當你試圖觀察堆空間變化情況 | 當你試圖瞭解單次GC產生的效果。 |
下面是-verbosegc 的可用引數
· -XX:+PrintGCDetails
· -XX:+PrintGCTimeStamps
· -XX:+PrintHeapAtGC
· -XX:+PrintGCDateStamps (from JDK 6 update 4)
如果只是用了 -verbosegc 。那麼預設會加上 -XX:+PrintGCDetails。 –verbosgc 的附加引數並不是獨立的。而是經常組合起來使用。
使用 –verbosegc後,每次GC發生你都會看到如下格式的結果。
[GC [<collector>: <starting occupancy1> -> <ending occupancy1>, <pause time1> secs] <starting occupancy3> -> <ending occupancy3>, <pause time3> secs]
收集器 | minor gc使用的收集器的名字。 |
starting occupancy1 | GC執行前新生代空間大小。 |
ending occupancy1 | GC執行後新生代空間大小。 |
pause time1 | 因為執行minor GC,Java應用暫停的時間。 |
starting occupancy3 | GC執行前堆區域總大小 |
ending occupancy3 | GC執行後堆區域總大小 |
pause time3 | Java應用由於執行堆空間GC(包括major GC)而停止的時間。 |
這是-verbosegc 輸出的minor GC的例子。
1234 | S0 S1 E O P YGC YGCT FGC FGCT GCT |