成为Java GC专家（2）― 如何监控Java垃圾回收机制
hqly7321
8年前
<p>本文是成为Java GC专家系列文章的第二篇。在第一篇<a href="http://www.open-open.com/lib/view/open1462435876740.html">《深入浅出Java垃圾回收机制》</a>中我们学习了不同GC算法的执行过程，GC是如何工作的，什么是新生代和老年代，你应该了解的JDK7中的5种GC类型，以及这5种类型对于应用性能的影响。</p> <p> </p> <h2>什么是GC监控？</h2> <p>垃圾回收收集监控指的是搞清楚JVM如何执行GC的过程，例如，我们可以查明：</p> <p>1. 何时一个新生代中的对象被移动到老年代时，所花费的时间。</p> <p>2. Stop-the-world 何时发生的，持续了多长时间。</p> <p>GC监控是为了鉴别JVM是否在高效地执行GC，以及是否有必要进行额外的性能调优。基于以上信息，我们可以修改应用程序或者调整GC算法（GC优化）。</p> <h2>如何监控GC</h2> <p>有很多种方法可以监控GC，但其差别仅仅是GC操作通过何种方式展现而已。GC操作是由JVM来完成，而GC监控工具只是将JVM提供的GC信息展现给你，因此，不论你使用何种方式监控GC都将得到相同的结果。所以你也就不必去学习所有的监控GC的方法。但是因为学习每种监控方法不会占用太多时间，了解多一点可以帮助你根据不同的场景选择最为合适的方式。</p> <p>下面所列的工具以及JVM参数并不适用于所有的HVM供应商。这是因为并没有关于GC信息的强制标准。本文我们将使用HotSpot JVM (Oracle JVM)。因为NHN 一直在使用Oracle (Sun) JVM，所以用它作为示例来解释我们提到的工具和JVM参数更容易些。<br> 首先，GC监控方法根据访问的接口不同，可以分成CUI 和GUI 两大类。CUI GC监控方法使用一个独立的叫做”jstat”的CUI应用，或者在启动JVM的时候选择JVM参数”verbosegc”。<br> GUI GC监控由一个单独的图形化应用来完成，其中三个最常用的应用是”jconsole”, “jvisualvm” 和 “Visual GC”。<br> 下面我们来详细学习每种方法。</p> <h2>jstat</h2> <p>jstat 是HotSpot JVM提供的一个监控工具。其他监控工具还有jps 和jstatd。有些时候，你可能需要同时使用三种工具来监控你的应用。jstat 不仅提供GC操作的信息，还提供类装载操作的信息以及运行时编译器操作的信息。本文将只涉及jstat能够提供的信息中与监控GC操作信息相关的功能。</p> <p>jstat 被放置在$JDK_HOME/bin。因此只要java 和 javac能执行，jstat 同样可以执行。</p> <p>你可以在命令行环境下执行如下语句。</p> <pre> <code>$> 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 $></code></pre> <p><br> 在上图的例子中，实际的数据会按照如下列输出：</p> <pre> <code>S0C S1C S0U S1U EC EU OC OU PC</code></pre> <p>vmid (虚拟机 ID)，正如其名字描述的，它是虚拟机的ID，Java应用不论运行在本地还是远程的机器都会拥有自己独立的vmid。运行在本地机器上的vmid称之为lvmid (本地vmid)，通常是PID。如果想得到PID的值你可以使用ps命令或者windows任务管理器，但我们推荐使用jps来获取，因为PID和lvmid有时会不一致。jps 通过Java PS实现，jps命令会返回vmids和main方法的信息，正如ps命令展现PIDS和进程名字那样。</p> <p>首先通过jps命令找到你要监控的Java应用的vmid，并把它作为jstat的参数。当几个WAS实例运行在同一台设备上时，如果你只使用jps命令，将只能看到启动（bootstrap）信息。我们建议在这种情况下使用ps -ef | grep java与jps配合使用。<br> 想要得到GC性能相关的数据需要持续不断地监控，因此在执行jstat时，要规则地输出GC监控的信息。<br> 例如，执行”jstat –gc 1000″ (或 1s)会每隔一秒展示GC监控数据。”jstat –gc 1000 10″会每隔1秒展现一次，且一共10次。</p> <table border="0" cellpadding="0" cellspacing="0"> <tbody> <tr> <td> <p>参数名称</p> </td> <td> <p>描述</p> </td> </tr> <tr> <td> <p>gc</p> </td> <td> <p>输出每个堆区域的当前可用空间以及已用空间（伊甸园，幸存者等等），GC执行的总次数，GC操作累计所花费的时间。</p> </td> </tr> <tr> <td> <p>gccapactiy</p> </td> <td> <p>输出每个堆区域的最小空间限制（ms）/最大空间限制（mx），当前大小，每个区域之上执行GC的次数。（不输出当前已用空间以及GC执行时间）。</p> </td> </tr> <tr> <td> <p>gccause</p> </td> <td> <p>输出-gcutil提供的信息以及最后一次执行GC的发生原因和当前所执行的GC的发生原因</p> </td> </tr> <tr> <td> <p>gcnew</p> </td> <td> <p>输出新生代空间的GC性能数据</p> </td> </tr> <tr> <td> <p>gcnewcapacity</p> </td> <td> <p>输出新生代空间的大小的统计数据。</p> </td> </tr> <tr> <td> <p>gcold</p> </td> <td> <p>输出老年代空间的GC性能数据。</p> </td> </tr> <tr> <td> <p>gcoldcapacity</p> </td> <td> <p>输出老年代空间的大小的统计数据。</p> </td> </tr> <tr> <td> <p>gcpermcapacity</p> </td> <td> <p>输出持久带空间的大小的统计数据。</p> </td> </tr> <tr> <td> <p>gcutil</p> </td> <td> <p>输出每个堆区域使用占比，以及GC执行的总次数和GC操作所花费的事件。</p> </td> </tr> </tbody> </table> <p>你可以只关心那些最常用的命令，你会经常用到 -gcutil (或-gccause), -gc and –gccapacity。</p> <p>· -gcutil 被用于检查堆间的使用情况，GC执行的次数以及GC操作所花费的时间。</p> <p>· -gccapacity以及其他的参数可以用于检查实际分配内存的大小。</p> <p>使用-gc 参数你可以看到如下输出：</p> <pre> <code>S0C S1C … GCT 1248.0 896.0 … 1.246 1248.0 896.0 … 1.246 … … … …</code></pre> <p><br> <br> 不同的jstat参数输出不同类型的列，如下表所示，根据你使用的”jstat option”会输出不同列的信息。</p> <table> <tbody> <tr> <td>列</td> <td>说明</td> <td>Jstat参数</td> </tr> <tr> <td>S0C</td> <td>输出Survivor0空间的大小。单位KB。</td> <td>-gc<br> -gccapacity<br> -gcnew<br> -gcnewcapacity</td> </tr> <tr> <td>S1C</td> <td>输出Survivor1空间的大小。单位KB。</td> <td>-gc<br> -gccapacity<br> -gcnew<br> -gcnewcapacity</td> </tr> <tr> <td>S0U</td> <td>输出Survivor0已用空间的大小。单位KB。</td> <td>-gc<br> -gcnew</td> </tr> <tr> <td>S1U</td> <td>输出Survivor1已用空间的大小。单位KB。</td> <td>-gc<br> -gcnew</td> </tr> <tr> <td>EC</td> <td>输出Eden空间的大小。单位KB。</td> <td>-gc<br> -gccapacity<br> -gcnew<br> -gcnewcapacity</td> </tr> <tr> <td>EU</td> <td>输出Eden已用空间的大小。单位KB。</td> <td>-gc<br> -gcnew</td> </tr> <tr> <td>OC</td> <td>输出老年代空间的大小。单位KB。</td> <td>-gc<br> -gccapacity<br> -gcold<br> -gcoldcapacity</td> </tr> <tr> <td>OU</td> <td>输出老年代已用空间的大小。单位KB。</td> <td>-gc<br> -gcold</td> </tr> <tr> <td>PC</td> <td>输出持久代空间的大小。单位KB。</td> <td>-gc<br> -gccapacity<br> -gcold<br> -gcoldcapacity<br> -gcpermcapacity</td> </tr> <tr> <td>PU</td> <td>输出持久代已用空间的大小。单位KB。</td> <td>-gc<br> -gcold</td> </tr> <tr> <td>YGC</td> <td>新生代空间GC时间发生的次数。</td> <td>-gc<br> -gccapacity<br> -gcnew<br> -gcnewcapacity<br> -gcold<br> -gcoldcapacity<br> -gcpermcapacity<br> -gcutil<br> -gccause</td> </tr> <tr> <td>YGCT</td> <td>新生代GC处理花费的时间。</td> <td>-gc<br> -gcnew<br> -gcutil<br> -gccause</td> </tr> <tr> <td>FGC</td> <td>full GC发生的次数。</td> <td>-gc<br> -gccapacity<br> -gcnew<br> -gcnewcapacity<br> -gcold<br> -gcoldcapacity<br> -gcpermcapacity<br> -gcutil<br> -gccause</td> </tr> <tr> <td>FGCT</td> <td>full GC操作花费的时间</td> <td>-gc<br> -gcold<br> -gcoldcapacity<br> -gcpermcapacity<br> -gcutil<br> -gccause</td> </tr> <tr> <td>GCT</td> <td>GC操作花费的总时间。</td> <td>-gc<br> -gcold<br> -gcoldcapacity<br> -gcpermcapacity<br> -gcutil<br> -gccause</td> </tr> <tr> <td>NGCMN</td> <td>新生代最小空间容量，单位KB。</td> <td>-gccapacity<br> -gcnewcapacity</td> </tr> <tr> <td>NGCMX</td> <td>新生代最大空间容量，单位KB。</td> <td>-gccapacity<br> -gcnewcapacity</td> </tr> <tr> <td>NGC</td> <td>新生代当前空间容量，单位KB。</td> <td>-gccapacity<br> -gcnewcapacity</td> </tr> <tr> <td>OGCMN</td> <td>老年代最小空间容量，单位KB。</td> <td>-gccapacity<br> -gcoldcapacity</td> </tr> <tr> <td>OGCMX</td> <td>老年代最大空间容量，单位KB。</td> <td>-gccapacity<br> -gcoldcapacity</td> </tr> <tr> <td>OGC</td> <td>老年代当前空间容量制，单位KB。</td> <td>-gccapacity<br> -gcoldcapacity</td> </tr> <tr> <td>PGCMN</td> <td>持久代最小空间容量，单位KB。</td> <td>-gccapacity<br> -gcpermcapacity</td> </tr> <tr> <td>PGCMX</td> <td>持久代最大空间容量，单位KB。</td> <td>-gccapacity<br> -gcpermcapacity</td> </tr> <tr> <td>PGC</td> <td>持久代当前空间容量，单位KB。</td> <td>-gccapacity<br> -gcpermcapacity</td> </tr> <tr> <td>PC</td> <td>持久代当前空间大小，单位KB</td> <td>-gccapacity<br> -gcpermcapacity</td> </tr> <tr> <td>PU</td> <td>持久代当前已用空间大小，单位KB</td> <td>-gc<br> -gcold</td> </tr> <tr> <td>LGCC</td> <td>最后一次GC发生的原因</td> <td>-gccause</td> </tr> <tr> <td>GCC</td> <td>当前GC发生的原因</td> <td>-gccause</td> </tr> <tr> <td>TT</td> <td>老年化阈值。被移动到老年代之前，在新生代空存活的次数。</td> <td>-gcnew</td> </tr> <tr> <td>MTT</td> <td>最大老年化阈值。被移动到老年代之前，在新生代空存活的次数。</td> <td>-gcnew</td> </tr> <tr> <td>DSS</td> <td>幸存者区所需空间大小，单位KB。</td> <td>-gcnew</td> </tr> </tbody> </table> <p>jstat 的好处是它可以持续的监控GC操作数据，不论Java应用是运行在本地还是远程，只要有控制台的地方就可以使用。当使用–gcutil 会输出如下信息。在GC优化的时候，你需要特别注意YGC, YGCT, FGC, FGCT 和GCT。</p> <pre> <code> 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</code></pre> <p> </p> <p>这些信息很重要，因为它们展示了GC处理到底花费了多少时间。</p> <p>在这个例子中，YGC 是217而YGCT 是0.928，这样在简单的计算数据平均数后，你可以知道每次新生代的GC大概需要4ms（0.004秒），而full GC的平均时间为33ms。<br> 但是，只看数据平均数经常无法分析出真正的GC问题。这是主要是因为GC操作时间严重的偏差（换句话说，假如两次full GC的时间是 67ms，那么其中的一次full GC可能执行了10ms而另一个可能执行了57ms。）为了更好地检测每次GC处理时间，最好使用 –verbosegc来替代数据平均数。</p> <p>-verbosegc</p> <p>-verbosegc 是在启动一个Java应用时可以指定的JVM参数之一。而jstat 可以监控任何JVM应用，即便它没有制定任何参数。 -verbosegc 需要在启动的时候指定，因此你可能会认为它没有必要（因为jstat可以替代之）。但是， -verbosegc 会以更浅显易懂的方式展现GC发生的结果，因此他对于监控监控GC信息十分有用。</p> <table> <tbody> <tr> <td>jstat</td> <td>-verbosegc</td> </tr> <tr> <td>监控对象</td> <td>运行在本机的Java应用可以把日志输出到终端上，或者借助jstatd命令通过网络连接远程的Java应用。</td> <td>只有那些把-verbogc作为启动参数的JVM。</td> </tr> <tr> <td>输出信息</td> <td>堆状态（已用空间，最大限制，GC执行次数/时间，等等）</td> <td>执行GC前后新生代和老年代空间大小，GC执行时间。</td> </tr> <tr> <td>输出时间</td> <td>Every designated time<br> 每次设定好的时间。</td> <td>每次GC发生的时候。</td> </tr> <tr> <td>何时有用。</td> <td>当你试图观察堆空间变化情况</td> <td>当你试图了解单次GC产生的效果。</td> </tr> </tbody> </table> <p>下面是-verbosegc 的可用参数<br> · -XX:+PrintGCDetails<br> · -XX:+PrintGCTimeStamps<br> · -XX:+PrintHeapAtGC<br> · -XX:+PrintGCDateStamps (from JDK 6 update 4)</p> <p>如果只是用了 -verbosegc 。那么默认会加上 -XX:+PrintGCDetails。 –verbosgc 的附加参数并不是独立的。而是经常组合起来使用。<br> 使用 –verbosegc后，每次GC发生你都会看到如下格式的结果。</p> <p>[GC [<collector>: <starting occupancy1> -> <ending occupancy1>, <pause time1> secs] <starting occupancy3> -> <ending occupancy3>, <pause time3> secs]</p> <table> <tbody> <tr> <td>收集器</td> <td>minor gc使用的收集器的名字。</td> </tr> <tr> <td>starting occupancy1</td> <td>GC执行前新生代空间大小。</td> </tr> <tr> <td>ending occupancy1</td> <td>GC执行后新生代空间大小。</td> </tr> <tr> <td>pause time1</td> <td>因为执行minor GC，Java应用暂停的时间。</td> </tr> <tr> <td>starting occupancy3</td> <td>GC执行前堆区域总大小</td> </tr> <tr> <td>ending occupancy3</td> <td>GC执行后堆区域总大小</td> </tr> <tr> <td>pause time3</td> <td>Java应用由于执行堆空间GC（包括major GC）而停止的时间</td> </tr> </tbody> </table> <p>这是-verbosegc 输出的minor GC的例子。</p> <pre> <code>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</code></pre> <p><br> 这是 Full GC发生时的例子</p> <pre> <code> [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]</code></pre> <p><br> <br> 如果使用了 CMS collector，那么如下CMS信息也会被输出。<br> 由于 –verbosegc 参数在每次GC事件发生的时候都会输出日志，我们可以很轻易地观察到GC操作对于堆空间的影响。</p> <p>(Java) VisualVM + Visual GC</p> <p>Java Visual VM是由Oracle JDK提供的图形化的汇总和监控工具。</p> <p style="text-align: center;"><img alt="成为JavaGC专家（2）―如何监控Java垃圾回收机制" src="https://simg.open-open.com/show/dfe396b4e61d1ecf37c91227a45cb67a.png"></p> <p style="text-align: center;">图1: VisualVM 截图</p> <p>除了JDK中自带的版本，你还可以直接从官网下载Visual VM。出于便利性的考虑，JDK中包含的版本被命名为Java VisualVM (jvisualvm),而官网提供的版本被命名为Visual VM (visualvm)。两者的功能基本相同，只有一些细小的差别，例如安装组件的时候。就个人而言，我更喜欢可以从官网下载的Visual VM。</p> <p style="text-align: center;"><img alt="成为JavaGC专家（2）―如何监控Java垃圾回收机制" src="https://simg.open-open.com/show/dfe396b4e61d1ecf37c91227a45cb67a.png"></p> <p style="text-align: center;">图 2: Viusal GC 安装截图</p> <p>通过Visual GC，你可以更直观的看到执行jstatd 所得到的信息。</p> <p style="text-align: center;"><img alt="成为JavaGC专家（2）―如何监控Java垃圾回收机制" src="https://simg.open-open.com/show/26b1690706c6fb86a1fbfefe43e3a41a.png"></p> <p style="text-align: center;">图3: Visual GC 执行截图</p> <p>HPJMeter</p> <p>HPJMeter 可以很方便的分析 -verbosegc 输出的结果，如果Visual GC可以视作jstat的图形化版本，那么HPJMeter就相当于 –verbosgc的图形化版本。当然，GC分析只是HPJMeter提供的众多功能之一，HPJMeter是由惠普开发的性能监控工具，他可以支持HP-UX，Linux以及MS Windows。<br> 起初，一个成为HPTune 被设计用来图形化的分析-verbosegc.输出的结果。但是，随着HPTune的功能被集成到HPJMeter 3.0版本之后，就没有必要单独下载HPTune了。但运行一个应用时， -verbosegc 的结果会被输出到一个独立的文件中。<br> 你可以用HPJMeter直接打开这个文件，以便更直观的分析GC性能数据。</p> <p style="text-align: center;"><img alt="成为JavaGC专家（2）―如何监控Java垃圾回收机制" src="https://simg.open-open.com/show/803a9d8321aaf44927a5fc0775e76d86.png"></p> <p style="text-align: center;">图4: HPJMeter</p> <p>来源：http://www.importnew.com/2057.html</p>