我们在日常工作中,经常会遇到由于JVM内存溢出,频繁GC导致服务不可用的情况,这时候就需要我们对JVM的堆内存进行分析和问题排查,找出问题所在。
GC日志
排查GC问题,第一个想法就是从服务器上导出GC日志查看,找到导致服务器不可用的具体原因,是yonggc还是频繁的fullgc,还是方法区(JDK1.8元数据区)扩容导致。
讲到GC日志,就带点题外话讲讲JVM的堆参数设置,只谈及部分最基础的
堆参数
参数 | 描述 |
-Xms | 设置JVM启动的时候堆内存的初始化大小 |
-Xmx | 设置堆内存的最大值 |
-Xmn | 设置堆内年轻代的大小,剩下的空间为老年代大小 |
-XX:PermGen | 设置方法区的初始化大小(JDK1.8中为-XX:MetaSpaceSize) |
-XX:MaxPermGen | 设置方法区的最大值(JDK1.8中为-XX:MaxMetaSpaceSize) |
-XX:SurvivorRatio | 设置Eden和survivor区的大小比例,默认为8:1:1(这个问题我还遇到过,当时记错了,还很自信的回答是4) |
-XX:NewRatio | 年轻代和老年代的比例大小,默认1:2 |
GC日志参数
参数 | 描述 |
-XX:+PrintGC | 输出GC日志 |
-XX:+PrintGCDetails | 输出GC的详细日志 |
-XX:+PrintGCTimeStamps | 输出GC的时间戳(以基准时间的形式) |
-XX:+PrintGCDateStamps | 输出GC的时间戳(以日期的形式,如 2013-05-04T21:53:59.234+0800) |
-XX:+PrintHeapAtGC | 在进行GC的前后打印出堆的信息 |
-Xloggc:…/logs/gc.log | 日志文件的输出路径 |
用一段代码模拟了一下内存溢出
public static void main(String[] args) {
List<byte[]> list = new ArrayList<>();
while (true) {
list.add(new byte[1024]);
}
}
设置的JVM参数
-Xms70m
-Xmx70m
-XX:+PrintGC
-XX:+PrintGCDetails
-XX:+PrintGCTimeStamps
-XX:+PrintGCDateStamps
-XX:+PrintHeapAtGC
打印的GC的日志,我截取了一部分
younggc
2020-04-12T18:50:01.120+0800: 0.200: [GC (Allocation Failure) [PSYoungGen: 18432K->2538K(20992K)] 18432K->18586K(69120K), 0.0062611 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
Heap after GC invocations=1 (full 0):
PSYoungGen total 20992K, used 2538K [0x00000000fe900000, 0x0000000100000000, 0x0000000100000000)
eden space 18432K, 0% used [0x00000000fe900000,0x00000000fe900000,0x00000000ffb00000)
from space 2560K, 99% used [0x00000000ffb00000,0x00000000ffd7a9a0,0x00000000ffd80000)
to space 2560K, 0% used [0x00000000ffd80000,0x00000000ffd80000,0x0000000100000000)
ParOldGen total 48128K, used 16048K [0x00000000fba00000, 0x00000000fe900000, 0x00000000fe900000)
object space 48128K, 33% used [0x00000000fba00000,0x00000000fc9ac000,0x00000000fe900000)
Metaspace used 3229K, capacity 4496K, committed 4864K, reserved 1056768K
class space used 350K, capacity 388K, committed 512K, reserved 1048576K
}
fullgc
2020-04-12T18:50:01.138+0800: 0.218: [Full GC (Ergonomics) [PSYoungGen: 2529K->0K(20992K)] [ParOldGen: 36592K->34936K(48128K)] 39121K->34936K(69120K), [Metaspace: 3229K->3229K(1056768K)], 0.0181538 secs] [Times: user=0.08 sys=0.00, real=0.02 secs]
Heap after GC invocations=3 (full 1):
PSYoungGen total 20992K, used 0K [0x00000000fe900000, 0x0000000100000000, 0x0000000100000000)
eden space 18432K, 0% used [0x00000000fe900000,0x00000000fe900000,0x00000000ffb00000)
from space 2560K, 0% used [0x00000000ffd80000,0x00000000ffd80000,0x0000000100000000)
to space 2560K, 0% used [0x00000000ffb00000,0x00000000ffb00000,0x00000000ffd80000)
ParOldGen total 48128K, used 34936K [0x00000000fba00000, 0x00000000fe900000, 0x00000000fe900000)
object space 48128K, 72% used [0x00000000fba00000,0x00000000fdc1e320,0x00000000fe900000)
Metaspace used 3229K, capacity 4496K, committed 4864K, reserved 1056768K
class space used 350K, capacity 388K, committed 512K, reserved 1048576K
}
2020-04-12T18:50:01.120+0800: 0.200:GC发生的时间
GC (Allocation Failure) :GC的类型,这里是年轻代空间分配失败导致的younggc
PSYoungGen: 2529K->0K(20992K):年轻代:GC前年轻代内存占用->GC后占用(年轻代总大小)
老年代和元数据区同理
Heap after GC invocations=1:第一次younggc
(full 1):处于fullgc第几次周期
用jps和jstat监控堆内存状况
虽然一般在生产环境中不会让你直接在服务器上用jps和jstat监控堆内存变化,但是知道总不是什么坏事
先通过jps获得进程id
E:\Workspaces\leetcode_cgua>jps
16308
19524 Solution
10152 Launcher
7144 Jps
然后使用jstat监控对应pid的进程
jstat -gcutil 195234 1000 100
会得到对应的堆内存情况,截取一部分
S0 S1 E O M CCS YGC YGCT FGC FGCT GCT
0.00 92.65 100.00 96.88 66.37 68.26 15 5.809 16 53.784 59.593
0.00 92.65 100.00 96.88 66.37 68.26 15 5.809 16 53.784 59.593
讲一下各个参数的作用
S0:幸存1区当前使用比例
S1:幸存2区当前使用比例
E:伊甸园区使用比例
O:老年代使用比例
M:元数据区使用比例
CCS:压缩使用比例
YGC:年轻代垃圾回收次数
FGC:老年代垃圾回收次数
FGCT:老年代垃圾回收消耗时间
GCT:垃圾回收消耗总时间
事实上jstat很有很多使用方式,功能也尽不相同,但是我只用过这一种,其他的就不一一贴上去了。
快照分析
生产上最多的就是在产生OOM以后,通过生成的快照文件来分析是哪里出现的问题。
这里用idea模拟一下OOM的产生:
代码:
public static void main(String[] args) {
List<byte[]> list = new ArrayList<>();
while(true) {
list.add(new byte[1024]);
}
}
JVM参数配置
-Xms70m
-Xmx70m
-XX:+HeapDumpOnOutOfMemoryError
-XX:HeapDumpPath=E:\GC
运行main方法之后,会在指定的路径生成文件
使用对应的工具打开,进行分析
我这边使用的是IBM heapAnalyzer
在cmd使用命令启动
java -Xmx1024m -jar ha457.jar
打开对应的快照文件
可以看到内存中的字节数组占据了最多的内存
这是最简单的状况
具体的GC问题还需要具体分析,我这里不做具体例子