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日志文件里面每个区域所代表的意思。
image-20200424215717123.pngGC的原因:
- 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内存大小区域)
[图片上传失败...(image-7af870-1587738242306)]
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(关键性能指标)
image-20200419003042535.pngKey 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)
- 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统计信息)
image-20200419003406219.png image-20200419003443910.pngGC Statistics显示一些GC的统计信息。每种GC总共回收了多少内存、总共用了多长时间、平均时间、以及每种GC的单独统计信息啥的。
2.2.5 Object Stats(对象的一些统计信息)
image-20200419003456250.png2.2.6 GC Causes(GC的原因信息)
image-20200419003507536.png以上就是我们对GC日志文件的一个大致介绍,主要是介绍GC日志文件分析工具,为我们后续分析GC日志文件做准备。
网友评论