成为JavaGC专家Part II — 如何监控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 一样能够执行。
你能够在命令行环境下执行以下语句。

 

1 2 3 4 5 6 7 8

$> 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 参数你能够看到以下输出：

1 2 3 4

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。

1 2 3 4

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的例子。

1 2 3 4

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

这是 Full GC发生时的例子

1	[Full GC [Tenured: 3485K->4095K(4096K), 0.1745373 secs] 61244K->7418K(63104K), [Perm : 10756K->10756K(12288K)], 0.1762129 secs] [Times: user=0.19 sys=0.00, real=0.19 secs]

若是使用了 CMS collector，那么以下CMS信息也会被输出。
因为 –verbosegc 参数在每次GC事件发生的时候都会输出日志，咱们能够很轻易地观察到GC操做对于堆空间的影响。

(Java) VisualVM  + Visual GC

Java Visual VM是由Oracle JDK提供的图形化的汇总和监控工具。

图1: VisualVM 截图

除了JDK中自带的版本，你还能够直接从官网下载Visual VM。出于便利性的考虑，JDK中包含的版本被命名为Java VisualVM (jvisualvm),而官网提供的版本被命名为Visual VM (visualvm)。二者的功能基本相同，只有一些细小的差异，例如安装组件的时候。就我的而言，我更喜欢能够从官网下载的Visual VM。

图 2: Viusal GC 安装截图

经过Visual GC，你能够更直观的看到执行jstatd 所获得的信息。

 

图3: Visual GC 执行截图

HPJMeter

HPJMeter 能够很方便的分析 -verbosegc 输出的结果，若是Visual GC能够视做jstat的图形化版本，那么HPJMeter就至关于 –verbosgc的图形化版本。固然，GC分析只是HPJMeter提供的众多功能之一，HPJMeter是由惠普开发的性能监控工具，他能够支持HP-UX，Linux以及MS Windows。
起初，一个成为HPTune 被设计用来图形化的分析-verbosegc.输出的结果。可是，随着HPTune的功能被集成到HPJMeter 3.0版本以后，就没有必要单独下载HPTune了。但运行一个应用时， -verbosegc 的结果会被输出到一个独立的文件中。
你能够用HPJMeter直接打开这个文件，以便更直观的分析GC性能数据。

 图4: HPJMeter

下次预告

本文咱们主要讲述了若是监控GC操做信息，这将是GC优化的前提。就我我的经验而言，我推荐使用jstat 来监控GC操做，若是你感受到GC操做的执行时间过长，那就可使用verbosegc 参数来分析GC。GC优化的大致步骤就是在添加verbosegc 参数后，调整GC参数，分析修改后的结果。在下一篇文章中，咱们将经过真实的例子来说解优化GC的最佳选择。 做者Sangmin Lee, NHN公司，性能工程师实验室高级工程师。