JVM GC日志文件分析

Posted 2022-04-16 tuacy

JVM GC日志文件分析

       GC 是垃圾回收(Garbage Collection)的缩写。两个关键名词：垃圾、回收。那何谓垃圾呢，JVM认为没有任何引用指向的对象就是垃圾对象，JVM里面判定为垃圾的算法有：应用计数法、可达性分析法。何谓回收呢，回收就是把认为是垃圾对象的内存回收回来，JVM里面的回收算法有：标记-清除算法、复制算法、标记整理算法、分代收集算法。GC日志文件就是JAVA虚拟机产生的一种对垃圾回收情况描述性的日志文件。 通过阅读GC日志文件，我们可以了解JAVA虚拟机内存分配情况(因为垃圾回收的对象就是内存)和垃圾回收信息。

GC的对象是内存，又因为内存是在JVM堆区分配的，换句话说GC的对象是JVM堆区(当然也包括方法区的内存)。

一 GC日志文件生成

1.1 GC日志文件JVM相关参数

GC日志文件相关的选项	解释
-XX:+PrintGC (或者-verbose:gc)	输出GC日志(可以认为-verbose:gc 是 -XX:+PrintGC的别名)
-XX:+PrintGCDetails	输出 GC 详细的日志, 包括 GC 使用的收集器, 发生 GC 的区域, GC 空间收集情况等信息，该参数会自动开启-XX:+PrintGC
-XX:+PrintGCTimeStamps	在输出 GC 日志的时候输出时间戳, 这个时间戳是相对于虚拟机的启动时间
-XX:+PrintGCDateStamps	在输出 GC 日志的时候输出 GC 发生的时间（以日期的形式，如2013-05-04T21:53:59.234+0800）
-XX:+PrintHeapAtGC	在发生 GC 时输出 GC 前后各区域空间详细的对比信息, 对 -XX:PrintGCDetails 更加详细的补充
-XX:+PrintReferenceGC	在 GC 的时候打印系统中的软引用, 弱引用和虚引用等引用的数量信息
-Xloggc	输出 GC 日志到文件, 方便排查问题, 如果不配置路径, GC 日志将直接在控制台输出,格式为，-Xloggc:/path/xxx.log，或者-Xloggc:/path/gc-%t.log
-XX:+UseGCLogFileRotation	是否启用 GC 日志文件自动转储, GC 日志文件按大小切割时需要设置
XX:GCLogFileSize	控制 GC 日志文件的大小, 用于 GC 日志的切割, 不宜设置太大, 太大由于写日志需要进行 I/O 操作, I/O 操作需要在用户态和和心态之间切换, 会直接影响 user time 大小和 sys time 大小, 最终影响到 real time 大小, real time 就是 GC 耗费的时间。例如：-XX:GCLogFileSize=50M
-XX:NumberOfGClogFiles	GC 日志文件最多保存的个数。例如：-XX:NumberOfGClogFiles=10
-XX:+PrintGCApplicationStopedTime	查看GC造成的应用暂停时间
-XX:+PrintTenuringDistribution	对象晋升的日志
-XX:+HeapDumpOnOutOfMemoryError	内存溢出时输出 dump 文件

1.2 GC日志文件生成

       比如我们可以在我们的应用程序java -jar启动的时候添加如下参数，这样程序运行过程中会把GC日志文件输出到gclogs文件里面去。拿到GC日志文件之后，我们可以对gclogs文件做相应的分析。

-XX:+PrintGCDateStamps -XX:+PrintGCDetails -Xloggc:./gclogs

二 GC日志文件分析

2.1 GC日志文件解读

       当我们拿到GC日志文件之后，用文本方式打开文件可以看到一堆的文字和数据信息。其实里面的内容不复杂就是文件比较多而已。我们得先来介绍下GC日志文件格式，GC日志文件包含哪些内容，每个内容代表啥意思。在了解了日志文件格式之后我们才可以对GC日志文件做简单的分析。这里为了简单我就通过一个图来介绍GC日志文件里面每个区域所代表的意思。

GC的原因：

• Allocation Failure：年轻代中没有足够的空间存储数据了。
• Metadata GC Threshold：元空间没有足够的空间存储数据了。
• Ergonomics：GC的原因是因为要自动调解GC暂停时间和吞吐量之间的平衡
• System.gc()：GC的原因是因为调用了System.gc()函数

2.2 GC日志文件分析工具

       GC日志文件的内容信息，我们上面分析清楚了。接下来就是对GC日志文件做简单的分析了。为了节约咱们得分析时间。我们直接介绍一个非常好用GC日志文件在线分析工具gceasy。对应官网 https://gceasy.io/ 。打开网址，把我们生成的GC日志文件导入进去。就会以图形化的界面帮我们展示GC日志文件里面所有你需要的信息了。展示的信息简单直接明了。

2.2.1 JVM memory size（JVM内存大小区域）

        JVM memory size，gceasy给展示了年轻代，老年代，元空间。JVM给分配的大小和程序运行过程中实际使用的峰值大小。

        从JVM memory size展示的信息，我们可以判断是否需要做如下几件事情：

• 是否需要修改JVM内存(-Xms、-Xmx…)相关设置。比如年轻代和老年代峰值大小远远小于分配的大小。这个时候我们可以适当的减少内存设置。

• 是否需要调整年轻代和老年代的比例(-XX:NewSize(-Xns)、-XX:MaxNewSize(-Xmn)、-XX:SurvivorRatio=8)。比如老年代的峰值一直小于老年代申请的内存，这个时候我们就可以稍微多分点空间给年轻代；

• 是否需要修改元空间(XX:MetaspaceSize，-XX:MaxMetaspaceSize)相关设置。

年轻代，老年代属于堆区。元空间属于非堆区(直接对接的是机器的内存)。

2.2.2 Key Performance Indicators（关键性能指标）

        Key Performance Indicators给我们展示了GC吞吐量(应用程序线程用时占程序总用时的比例，越高越好)、每次GC的平均耗时(建议控制在50毫秒以下)、GC最长耗时、每个时间段的GC次数等信息。

        Key Performance Indicators显示的信息里面，我们得关注点应该在以下几个方面：

• 吞吐量，应用花在非GC上的时间百分比(引用花在生产任务上的百分比)。所以吞吐量越高越好。

• 每次GC的平均耗时。越小越好，建议50毫秒一下。

• GC最长耗时。越小越好。如果你的应用是一个后台程序，并且任何请求不超过10秒。那么GC最长耗时就不能超过10秒。

       根据内存调优准则，以上这三个优化指标，你最多只能三者取其二

• 如果你想要比较好的吞吐量和延迟，那就得在CPU消耗上有所牺牲
• 如果你想要比较好的吞吐量和CPU消耗，那就得在延迟上有所牺牲
• 如果你想要比较好的延迟和CPU消耗，那就得在吞吐量上有所牺牲

2.2.3 Interactive Graphs(交互图)

       Interactive Graphs展示了Heap after GC、Heap before GC、GC Duration、Reclaimed Bytes、Young Gen、Old Gen、Meta Space、A & P对应的信息。

• Heap after GC: 每次GC后堆的内存信息。

• Heap before GC: 每次GC前堆的内存信息。

• GC Duration: 每次GC的持续时间。(注意红色的是Full GC)

OWIxZjk4ZjIxNDFjZjkucG5n?x-oss-process=image/format,png)

• Reclaimed Bytes: 每次GC回收掉的垃圾对象的内存大小。

• Young Gen: 三条曲线分别展示年轻代每次GC的时候JVM给年轻代分配的内存大小、GC前使用内存大小、GC后使用内存大小。

• Old Gen: 三条曲线分别展示老年代每次GC的时候JVM给老年代分配的内存大小、GC前使用内存大小、GC后使用内存大小。

• Meta Space: 三条曲线分别展示元空间每次GC的时候给分配的内存大小、GC前使用内存大小、GC后使用内存大小。

• A & P: 每次GC的时候堆内存分配和晋升情况。其中红色的线表示每次GC的时候年轻代里面有多少内存(对象)晋升到了老年代。

2.2.4 GC Statistics(GC统计信息)

       GC Statistics显示一些GC的统计信息。每种GC总共回收了多少内存、总共用了多长时间、平均时间、以及每种GC的单独统计信息啥的。

2.2.5 Object Stats(对象的一些统计信息)

2.2.6 GC Causes(GC的原因信息)

---

以上就是我们对GC日志文件的一个大致介绍，主要是介绍GC日志文件分析工具，为我们后续分析GC日志文件做准备。