【GC日志和OOM日志分析】JVM GC日志和OOM Dump文件分析

1 缘起

充电、充电、充电。
增加一些必备的知识，帮助后续使用。

2 配置JVM参数

为分析GC日志以及OOM相关信息，配置JVM参数，分为三个部分：
（1）堆内存，包括年轻代、最大堆内存；
（2）GC日志配置；
（3）OOM转存dump配置。
完整参数：
-Xmn10m -Xmx70m -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./logs/gc.log -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=D:\data\jvm

-Xmn10m -Xmx70m -XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./logs/gc.log -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=D:\data\jvm

2.1 堆参数

参数	描述
-Xmn10m	年轻代分配10MB内存
-Xmx70m	最大堆分配70MB内存，其中，最大堆内存=年轻代+老年代

2.2 GC日志参数

参数	描述
-XX:+PrintGCDetails	开启GC日志打印
-XX:+PrintGCDateStamps	GC日志日期戳，格式： 2024-10-05T20:26:21.145+0800: 234.514
-Xloggc:./logs/gc.log	指定GC日志输出文件路径

2.3 OOM dump转储参数

参数	描述
-XX:+HeapDumpOnOutOfMemoryError	开启OOM转储Dump文件
-XX:HeapDumpPath=D:\data\jvm	配置Dump文件路径

开启GC日志并写入到指定目录下，添加启动参数：

-XX:+PrintGCDetails -XX:+PrintGCDateStamps -Xloggc:./logs/gc.log

启动服务后，在日志文件gc.log中查看GC内容如下，这里开启了时间戳（PrintGCDateStamps）。

3 GC分析

GC分析其实是分析GC日志内容，了解当前JVM GC状态，主要包括GC频率、回收内存大小，通过这些信息可以了解JVM状态。
依据这些状态，为我们优化JVM（主要是堆内存）提供理论数据支持，这里主要是解析GC日志参数，并没有依据这些状态指导JVM调优。
GC日志：

3.1 YGC

YGC日志如下，Allocation Failure说明分配内存失败，需要内存回收。
PSYoungGen：年轻代内存回收，
以第一行数据为例，
2024-10-05T20:25:28.185+0800: 181.555: [GC (Allocation Failure) [PSYoungGen: 7424K->192K(8704K)] 65370K->58146K(70144K), 0.0024832 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]

2024-10-05T20:25:28.185+0800: 181.555: [GC (Allocation Failure) [PSYoungGen: 7424K->192K(8704K)] 65370K->58146K(70144K), 0.0024832 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 

首先分析日志内容，各信息分析如下：

YGC回收频率以及内存回收大小可以通过JConsole或者Visual VM可视化，可视化的原始数据来自于GC日志。
每分钟YGC3~4次，每次回收内存：如4256K-96K=4160K=4MB。

2.2 Full GC

FullGC发生的情况是：年轻代已不足以为新对象分配内存+老年代仍不足以为新对象分配内存，触发Full GC，同时清理年轻代和老年代内存，Full GC直接影响系统的稳定性，我们要最大限度地减少Full GC（依据实际情况而定）。
Full GC日志如下：

2024-10-05T20:26:33.546+0800: 246.916: [Full GC (Ergonomics) [PSYoungGen: 4096K->0K(7168K)] [ParOldGen: 60327K->48792K(61440K)] 64423K->48792K(68608K), [Metaspace: 73978K->73972K(1116160K)], 0.0804215 secs] [Times: user=0.12 sys=0.00, real=0.08 secs]

Full GC各部分信息如下：

在模拟的请求中，主动触发Full GC，日志如下，
由日志可知，Full GC有两种情况：Ergonomics和Allocation Failure，当发生Full GC时，如果无法释放出足够内存给新对象使用，会一直进行Full GC，并抛出OOM异常，OOM异常会在Error日志中。

OOM Error日志，通过OOM日志，我们仅可知道发生了OOM，而无法确定发生OOM的位置，需要通过Dump文件分析。

4 OOM分析

通过GC日志，我们仅能了解到发生了Full GC，并不能直接定位到引发Full GC的位置，
最终导致无法定位引发OOM的原因，
因此，配置OOM发生后转储Dump文件，通过分析OOM Dump文件寻找引发OOM的原因。
通过异常日志可以直接发现发生OOM。
配置OOM Dump转储：
-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=D:\data\jvm

-XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=D:\data\jvm

4.1 OOM日志

当发生OOM时，日志中会给出异常日志，java.lang.OutOfMemoryError，
模拟OOM异常日志如下，配置OOM转储Dump文件，可以在指定的路径找到。

4.2 OOM Dump文件

通过Visual VM载入OOM Dump文件，文件后缀：hprof。

Visual VM载入hprof文件，步骤以及OOM信息如下：

通过OOM Error线程信息可以查看引发OOM的位置，位置信息如下，
这里的OOM信息是我在项目中模拟出来的，
位置是接口方法：testUserInfo，因此，我们可以分析这个接口的所有逻辑，找出OOM的原因，三类方案：
（1）增加年轻代和老年代内存；
（2）调整业务逻辑，优化数据拼装，减小内存占用；
（3）接口限流。

5 小结

（1）GC通过日志可以呈现的有：YGC和Full GC，其中，YGC中展示的信息中是新生代Eden区垃圾回收情况，并且Eden区和Survivor的比例是会发生变化的；Full GC展示的信息有新生代Eden区和老年代；
（2）OOM异常信息仅能提供发生了OOM，无法直接定位在哪里导致的OOM，需要通过Dump文件分析；
（3）配置GC日志和OOM转存参数：

参数	描述
-XX:+PrintGCDetails	开启GC日志打印
-XX:+PrintGCDateStamps	GC日志日期戳，格式： 2024-10-05T20:26:21.145+0800: 234.514
-Xloggc:./logs/gc.log	指定GC日志输出文件路径
-XX:+HeapDumpOnOutOfMemoryError	开启OOM转储Dump文件
-XX:HeapDumpPath=D:\data\jvm	配置Dump文件路径