本文记录 FullGC 和 OOM 排查思路,分两部分:1.总结描述文中涉及到的JVM概念知识 2.通过示例代码模拟常见的频繁GC和OOM场景以及总结一些通用的异常解决方法。

1 相关知识介绍

1.1 基础概念

1.JVM的内存区域
程序计数器:线程私有,用来表示当前线程执行到哪一条字节码指令。
虚拟机栈:线程私有,每个方法被执行的时候,Java虚拟机都会同步创建一个栈帧。栈帧内有局部变量表、操作数栈、动态链接、方法出口等
本地方法栈:线程私有,每个线程会创建一个本地方法栈,
堆内存:线程共享的,存放创建的各种对象,对象的成员变。
方法区(jdk8前由永久代实现,jdk8后由元数据区实现):存放类信息,jdk8之前方法区也存放静态变量
堆外内存:不归JVM管的内存 ,例如NIO中的allocateDirect就可以在堆外分配内存,然后通过DirectByteBuffer来操作堆外内存
2.对象触及状态
可触及的:从根节点开始,可以到达这个对象。
可复活的:对象的所有引用都被释放,但是对象有可能在finalize()函数中复活。
不可触及的:对象的finalize()函数被调用,并且没有复活,那么就会进入不可触及状态,不可触及的对象不可能被复活,因为finalize()函数只会被调用一次。
3.垃圾回收相关算法
引用计数法(Reference Counting)、标记清除法(Mark-Sweep)、复制算法(Copying)、标记压缩法(Mark-Compact)、可达性算法、分代算法(Generational Collecting)、分区算法(Region)
4.常见垃圾收集器
串行回收器 Serial和SerialOld (单线程,JDK1.3以后)
并行回收:ParallelGC+ParallelOldGC(吞吐量优先,吞吐量=运行用户代码时间/(运行用户代码时间+垃圾回收时间))
ParNew回收器+CMS回收器(JDK5至JDK 8版本)
G1回收器(Garbage-First)(JDK 1.7以后)
ZGC回收器(Z Garbage Collector(JDK11以后)
5.对象回收和引用类型
强引用:强引用的对象是可触及的(从根节点开始,可以到达这个对象),不会被回收
软引用:正常垃圾回收后,堆空间仍不足时,就会被回收。
弱引用:只要发现弱引用,不管系统堆空间使用情况如何,都会将对象进行回收
虚引用:虚引用的对象,和没有引用几乎是一样的,随时都可能被垃圾回收器回收。虚引用必须和引用队列一起使用,它的作用在于跟踪垃圾回收过程。
6.浅堆和深堆
(1)浅堆(Shallow Heap)是指一个对象所消耗的内存,不包括其内部引用对象的大小。在32位系统中,一个对象引用会占据4字节,一个int类型变量会占据4字节,一个long类型变量会占据8字节,每个对象头需要占用8字节。根据堆快照格式不同,对象的大小可能会向8字节对齐。以String对象为例,如图7.13所示,显示了String对象的几个属性(JDK 1.7,与JDK 1.6有差异)。
(2)深堆(Retained Heap)一个对象的深堆指只能通过该对象访问到的(直接或间接)所有对象的浅堆之和,即对象被回收后,可以释放的真实空间。
Image_20220506195133.png
图中对象A引用了对象C和D,对象B引用了对象C和E。那么对象A的浅堆大小只是A本身,不含对象C和D,而A的实际大小为对象A、C、D三者之和。而对象A的深堆大小为对象A与D之和,由于对象C还可以通过对象B访问到,因此不在对象A的深堆范围内。

1.2 对象分配和流转总结

1.2.1 对象如何分配流程

Image_20220506195200.png
对象分配并不是全部直接在新生代分配,首先
(1)判断是否可以在栈上分配,如果可以在栈上分配则优先在栈上分配。
栈上分配判断条件
A.参数-XX:+DoEscapeAnalysis是否启用逃逸分析,开始逃逸分析才允许栈上分配
B.参数-XX:+EliminateAllocations是否开启标量替换(默认打开),开启标量替换才允许将对象打散分配在栈上
C.对象的作用域是否会逃逸出函数体(是否逃逸对象),非逃逸对象允许栈上分配。
栈上分配好处:可以在函数调用结束后自行销毁,而不需要垃圾回收器的介入,从而提高系统的性能。
对于那些线程私有的对象(例如方法内临时创建的对象),Java虚拟机提供的一项优化技术,可以将它们打散分配在栈上,而不是分配在堆上。分配在栈上的好处是可以在函数调用结束后自行销毁,而不需要垃圾回收器的介入,从而提高系统的性能。栈上分配的一个技术基础是进行逃逸分析。逃逸分析的目的是判断对象的作用域是否有可能逃逸出函数体。
(2)判断是否允许TLAB分配,若允许则优先在线程本地分配缓存(Thread Local Allocation Buffer简称TLAB)分配。
默认情况下TLAB大小为Eden 空间的 1%,参数-XX:TLABWasteTargetPercent可设置 TLAB 空间所占用 Eden 空间的百分比大小。
TLAB分配上分配判断条件
A.参数-XX:UseTLAB启用线程本地分配缓存,默认开始
B.参数-XX:+DoEscapeAnalysis是否启用逃逸分析,开始逃逸分析才允许TLAB分析
C.当前线程的 TLAB 大小足够,或者当前 TLAB 剩余空间小于最大浪费空间refill_waste(TLABRefillWasteFraction参数控制,默认64,即1/64的TLAB大小)限制,才允许TLAB上分配。
Image_20220506195224.png
默认情况下,TLAB和refill_waste的大小都是会在运行时不断调整的,参数-XX:-ResizeTLAB可关闭自动调整TLAB的大小,并使用-XX:TLABSize手工指定TLAB的大小。
(3)判断是否符合大对象直接在老年代分配,如果符合则在老年代分配
老年代分配判断条件
A.对象容积很大,eden和survivor是否无法容纳?若是则直接在老年代分配
B.对于ParNew,参数PretenureSizeThreshold(单位:字节),对象容积大小大于该值直接进入老年代。(对于ParallelGC默认为0不指定最大的晋升大小;对于G1,则有Humongous regions用于存放大对象,对象容积大小大于region的大小即判定为大对象)

1.2.2 对象流转和GC流程

对象分配后,对象如何转移到老年代以及如何被回收的呢?限于篇幅,以下以ParNew+CMS为例进行讲解。
Image_20220506195244.png
当对象在Eden分配,Eden区占满后,此时对象有可能跃迁到老年代。具体条件如下
(1)判断老年代可用空间是否大于年轻代的所有对象?
A.若小于,则进行老年代空间担保机制判断,参数-XX:HandlePromotionFailure默认打开。若关闭则新生代对象转移到老年代,当打开时进入(2)
B.老年代可用空间虽然小于年轻代的全部对象容积大小,但是大于历次YGC新生代转移到老年代的空间大小则进行YGC,否则执行一次FGC
(2)YGC回收后,判断S区能否足够存放存活对象,若是则执行(3),否则对象进入老年代。
(3)动态年龄判断
参数-XX:TargetSurvivorRatio默认为50%,当大于某一年龄的对象大小总和大于S区空间的50%则进入老年代,否则执行4
(4)年龄阈值判断
参数-XX:MaxTenuringThreshold默认为15(jdk8默认是6),当对象年龄大于该值时则进入老年代。否则对象留在S区(从From到To)
(5)老年代对象达阈值时进行回收
参数-XX:CMSInitiatingOccupancyFaction设置老年代占用多少比例的时候触发CMS垃圾回收,默认值是92%。预留8%的空间给并发回收期间转移到老年代的对象。若回收期间,存活老年代对象超过该值,会发生Concurrent Mode Failure,此时发垃圾回收转变为“Serial Old”垃圾回收器替代CMS。

2 FullGC 和 OOM 排查

2.1 FullGC

说明:Full GC会包含Young GC、Old GC和元空间GC、直接内存GC。即触发Full GC的时候,可能就会去回收年轻代、老年代、元空间和直接内存的垃圾对象。

2.1.1 触发时机

通过上文对象流转我们可以发现Full GC(old)的触发时机总结如下
(1)发生Young GC之前进行检查,如果“老年代可用的连续内存空间”<“新生代历次Young GC后升入老年代的对象总和的平均大小”。说明本次Young GC后可能升入老年代的对象大小,可能超过了老年代当前可用内存空间。此时必须先触发一次Old GC给老年代腾出更多的空间,然后再执行Young GC
(2)执行Young GC之后有一批对象需要放入老年代,此时老年代就是没有足够的内存空间存放这些对象了,此时必须立即触发一次Old GC
(3)老年代内存使用率超过了92%,也要直接触发Old GC.当然这个比例是可以通过参数调整的。其实说白了,上述三个条件你概括成一句话,就是老年代空间也不够了,没法放入更多对象了,这个时候务必执行Old GC对老年代进行垃圾回收。
(4)元空间回收

2.1.2 FullGC的原因

(1)内存分配(参数设置)不合理

由于内存分配(参数设置)不合理,导致对象频繁进入老年代,进而引发频繁的Full GC。
系统承载高并发请求,或者处理数据量过大,导致Young GC很频繁.而且每次Young GC过后存活对象太多。内存分配不合理Survivor区域过小,导致对象频繁进入老年代.频繁触发Full GC。

  1. public class HeapFullGCDemo {
  2. public static void main(String[] args) {
  3. byte[] bytes = null;
  4. for (int i = 1; i <= 100; i++) {
  5. System.out.println("第" + i + "次");
  6. bytes = new byte[1024 * 1024 * 2];
  7. }
  8. }
  9. }

-Xms60M -Xmx60M -Xmn10M -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:SurvivorRatio=8 -XX:PretenureSizeThreshold=6m -XX:+PrintGCDetails -XX:+PrintCommandLineFlags
//堆空间60m,新生代10m,E:S0:S1=8:1:1,超过6m的的大对象在老年代分配

执行日志
Image_20220506195329.png
从日志中(日志解读下文会详细介绍)我们看到由于S区设置过小,导致每次YGC后有2M对象进入老年代。在下第35次分配对象时进行FullGC(包含新生代回收)
解决:可调大新生代空间或调小SurvivorRatio值,从使S区增大。

-Xms60M -Xmx60M -Xmn20M -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:SurvivorRatio=6 -XX:PretenureSizeThreshold=6m -XX:+PrintGCDetails -XX:+PrintCommandLineFlags
//如调大新生代20m,E:s0:s1=6:2:2

执行日志
Image_20220507092327.png
可以看到分配的对象不会进入老年代,老年代在稳定运行后没有增长。不会发生FGC
说明:1)s区大小设置不能“刚刚好”够存放存活对象。因为上文我们说过,动态判断规则,大于某年龄的存活对象大小总和大于S区50%时(默认)会进入老年代。如上例中若只调E:S0:S1=6:2:2,新生代保持10m时仍然存在FGC。
2)分代年龄设置过小同样会导致对象很快进入老年代,同样可能导致频繁FGC

(2)存在内存泄漏等问题

内存泄漏即内存里驻留了大量的对象塞满了老年代.导致稍微有一些对象进入老年代就会引发Full GC
1)系统发生了内存泄漏,莫名其妙创建大量的对象一直占用在老年代里,频繁触发FuIIGC
2)系统一次性加载过多数据进内存,存在大对象,导致频繁有大对象进入老年代.必然频繁触发Full GC

-Xms60M -Xmx60M -Xmn20M -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:SurvivorRatio=6 -XX:PretenureSizeThreshold=1m -XX:+PrintGCDetails -XX:+PrintCommandLineFlags
//修改大对象阈值为1m,超过1m直接在老年代分配

执行上例代码,GC日志如下
Image_20220507092359.png
我们看到,其只进行OldGC,且频繁进行OldGC
说明这里FGC通常包含YGC和OldGC Metaspace GC 等,往往OldGC前我们通常会设置期望进行一次YGC,所以通常描述的OldGC 大致和FullGC 等价(不太严谨)

(3)元Metaspace(永久代)加载类过多

Metaspace(永久代)因为加载类过多,或Metaspace设置过小,频繁占满该区域,导致触发Full GC
调大Metaspace,同时避免加载过多的类(动态加载的类需要缓存)

(4)其他

误调用System.gc()触发Full GC

  1. public class HeapFullGCDemo {
  2. public static void main(String[] args) {
  3. byte[] bytes = null;
  4. for (int i = 1; i <= 100; i++) {
  5. System.out.println("第" + i + "次");
  6. bytes = new byte[1024 * 1024 * 2];
  7. bytes = null;
  8. System.gc();
  9. }
  10. }
  11. }

-Xms60M -Xmx60M -Xmn20M -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:SurvivorRatio=6 -XX:PretenureSizeThreshold=6m -XX:+PrintGCDetails -XX:+PrintCommandLineFlags

执行日志如下
Image_20220507092445.png
日志明显看出频繁FGC

2.1.3 排查和处理

(1)总结
常见的频繁FullGC问题基本就上文所述几种,所以大家在线上处理FullGC的时候,就从这几个角度人手去分析即可。
分析可以通过GC日志和jstat命令去分析同时可以参照监控分析堆内存情况,有必要可以通过Dump内存,通过MAT等工具去找出导致大对象或者内存泄漏的代码,通常是代码原因,优化代码即可。

(2)GC信息需关注以下指标

新生代对象增长的速率:可以通过jstat查看每秒钟/每分钟,新生代增长多少对象。该指标可以大致估算多久可以填满Eden?多久会进行YGC?
Young GC的触发频率:可以通过GC日志查看YGC日志触发频率,是否有频繁YGC
Young GC的耗时:重点关注指标之一,YGC耗时是否合理?为什么耗时高?
Young GC后对象的存活率:jstat和GC日志可观测每次YGC后有多少对象是存活下来的。存活对象是否太多?可以初步分析为什么对象存活率高?大量引用没释放?rpc接口耗时?……
Young GC后老年代对象增长的速率:YGC后有平均多少对象进入了老年代?从中可以大致知道多久可以填满老年代。让对象尽可能的在新生代被回收。
Full GC的触发频率:尽量减少FGC,如FGC频率很高?需要关注,是否内存分配(参数设置)不合理?是否存在内存泄漏可能?是否存在大量大对象?……
Full GC的耗时:重点关注指标之一,可通过GC日志分析FGC哪一个阶段回收耗时高?并发回收效率低退化为串行回收?标记清除存在碎片?
停顿时间:关注YGC的耗时lFGC的耗时
吞吐量:吞吐量=运行用户代码时间/(运行用户代码时间+垃圾回收时间)。可以看到垃圾回收时间短停顿时间短,则吞吐量高。通常线上面向用户的应用服务,我们更关注停顿时间,而不是吞吐量。

2.2 OOM原因

内存溢出(OutOfMemory,简称OOM)顾名思义,有限的内存(通常出现在某一块内存空间耗尽的时候)中放了过多存活的对象,此时无法继续放入更多对象,导致“溢出”。内存溢出是一个令人头痛的问题,到底哪些区域会导致内存溢出?
我们上文讲到,堆内存达到一定的条件后会触发GC回收垃圾对象,但是如果占满堆空间的对象都是存活的,那么对象无法被回收掉。就会导致堆内存溢出。除了堆空间还有哪些区域会导致内存溢出?

2.2.1 从JVM执行流程看哪些区域会OOM

我们先简单了解下JVM进程怎么执行我们写的那些代码呢?

  1. public class Test {
  2. public static void main(String[] args) {
  3. Test aTest = new Test();
  4. System.out.println("test");
  5. }
  6. }

Image_20220507092524.png
A.从图中我们可以看出我们编写的java源代码经过编译加载后存放到元空间(Metaspace,jdk1.8以后)。而元空间,大小是有限的,若加载的类过多那么会导致内存溢出。
B.堆空间新生代和老年代,我们看到如果存在大量存活的对象,若无法GC回收,同样会导致堆溢出;
C.虚拟机栈帧存放局部变量等信息,帧栈大小也是有限的,若递归等调用深度深的情况即会导致栈溢出。另外我们看到除了元空间和堆空间。剩下的内存空间也是有限的。如果线程太多,栈空间占用内存也会增多,达阈值则可能会溢出。
下面我们针对这几种可能溢出的区域展开讨论。

2.2.2 OOM可能的区域和原因

(1)永久区(Metaspace)溢出

到底什么情况下会发生Metaspace内存溢出?我们来模拟下元空间溢出的场景
1)Metaspace溢出模拟

  1. public class MetaspaceOOM {
  2. public static void main(String[] args) {
  3. try {
  4. for (int i = 0; i < 100000; i++) {
  5. Enhancer enhancer = new Enhancer();
  6. //Enhancer生成BusinessTest类的子类
  7. enhancer.setSuperclass(BusinessTest.class);
  8. enhancer.setUseCache(false);
  9. enhancer.setCallback(new MethodInterceptor() {
  10. @Override
  11. public Object intercept(Object o, Method method, Object[] objects, MethodProxy methodProxy) throws Throwable {
  12. //执行doBusiness前拦截
  13. System.out.println("do check.....");
  14. return methodProxy.invokeSuper(o, objects);
  15. }
  16. });
  17. BusinessTest businessTest = (BusinessTest) enhancer.create();
  18. System.out.println("创建第" + i + "个子类");
  19. businessTest.doBusiness();
  20. }
  21. } catch (Error e) {
  22. e.printStackTrace();
  23. }
  24. }
  25. }
  26. public class BusinessTest {
  27. public void doBusiness(){
  28. System.out.println("do business.....");
  29. }
  30. }


JVM参数如下
-XX:MetaspaceSize=15m -XX:MaxMetaspaceSize=15m
执行结果如下
Image_20220507092608.png
我们可以看到,发生了OOM,原因是Metaspace溢出
2)总结
一般来稳定运行的系统很少会导致元空间溢出,常见溢出可能
A.新系统没有设置Metaspace区大小或者设置值过小,导致OOM
B.业务代码中使用动态生成类,大量生成新的类没有控制好,导致OOM
3)解决
A.增大MaxPermSize的值
B.缓存动态生成的类,避免频繁创建
C.使用ClassLoader合理地装载各个类,并定期进行回收

(2)栈溢出

1)线程的虚拟机栈内存溢出模拟

  1. public class StackOOM {
  2. public static void main(String[] args) {
  3. doBusiness(0);
  4. }
  5. public static void doBusiness(int i) {
  6. System.out.println("第" + i + "次");
  7. if (i == 1000000) {
  8. return;
  9. } else {
  10. doBusiness(++i);
  11. }
  12. }
  13. }

JVM参数
-Xss1m
执行结果
Image_20220507092640.png
2)总结
我们看到过多的栈递归调用,第6741次时发生了溢出,StackOverflowError。这种溢出常见于栈-Xss设置过小或者不加控制的递归调用导致的错误。
3)解决
适当调大-Xss值,把控代码递归调用出口、避免死循环等
4)线程过多导致的OOM模拟

  1. public class MultiThreadOOM {
  2. public static void main(String[] args) {
  3. for (int i = 0; i < 2000000; i++) {
  4. Thread thread = new Thread(() -> {
  5. System.out.println("do business start...");
  6. try {
  7. Thread.sleep(100000);
  8. } catch (InterruptedException e) {
  9. e.printStackTrace();
  10. }
  11. System.out.println("do business end...");
  12. });
  13. thread.start();
  14. System.out.println(i);
  15. }
  16. }
  17. }

执行结果
Image_20220507092713.png
5)总结
我们看到执行到线程7623抛出了OOM,进程内存达上线,系统线程数量饱和,这种常见于高并发常见,同时堆空间和元空间占用过大,用于创建线程的内存过少
6)解决
适当减少堆空间占用或线程栈大小调小,即可容纳更多的线程

(3)堆内存溢出

1)模拟堆内存溢出

  1. public class HeapOOM {
  2. public static void main(String[] args) {
  3. int count = 0;
  4. List<String> list = new ArrayList<>();
  5. while (true) {
  6. list.add("hello hello hello hello");
  7. System.out.println(++count);
  8. }
  9. }
  10. }

JVM参数
-Xms16m -Xmx32m
执行结果
Image_20220507092738.png
2)分析
为什么会堆溢出?
ygc后很多请求还没处理完毕,存活对象太多,在Survivor区域放不下了,此时对象转移到老年代。若老年代GC过后,有很多存活对象。由于堆空间是有限的则会导致堆空间放不下而溢出。
3)总结
这种现象常见于:
A.系统承载高并发请求,或业务处理过慢,导致大量对象都是存活的,导致大量对象滞留堆区没被GC掉,引发OOM。
B.系统有内存泄漏的问题,创建大量存活的对象,没有及时取消对他们的引用导致OOM。
如JDK1.6的中String.substring(),其实现并没有从原串中截取需要的部分作为新串,而是使用了原串的value引用,只是修改了offset和count。若业务代码中没有注意,大量对大字符串使用substring()且持有这些引用,就会产生这种内存泄漏问题。

(4)直接内存溢出

1)模拟直接内存溢出

  1. public class DirectBufferOOM {
  2. public static void main(String[] args) {
  3. List<ByteBuffer> list = new ArrayList<>();
  4. for (int i = 0; i < 100; i++) {
  5. ByteBuffer byteBuffer = ByteBuffer.allocateDirect(1024*1024*100);
  6. list.add(byteBuffer);
  7. System.out.println(i);
  8. }
  9. }
  10. }

JVM参数
-Xmx1G -XX:+PrintGCDetails
执行结果
Image_20220507092810.png
2)分析
在Java的NIO(New I/O)中,直接向操作系统申请直接内存(堆外的内存空间)使用。直接内存的申请速度较慢存慢,但访问速度要快。适用于可复用且会被经常访问的空间,以提高系统性能的。但由于直接内存没有被Java虚拟机完全托管,使用不当易触发直接内存溢出,导致宕机。
3)解决
参数-XX:MaxDirectMemorySize可设置最大使用直接内存,若不设置默为最大堆空间-Xmx的值。当直接内存使用量达到阈值就会触发垃圾回收,如果垃圾回收不能有效释放足够的空间,直接内存溢出依然会引起系统的OOM,所以需要控制好直接内存的使用

(5)其他(GC效率低下引起的OOM)

一般情况下,虚拟机会检查以下几种情况:
A.花在GC上的时间是否超过了98%。
B.老年代释放的内存是否小于2%。
C. eden区释放的内存是否小于2%。
D. 是否连续5次GC
如果同时满足上述所有条件虚拟机才有可能抛出如下OOM:java.lang.OutOfMemoryError: GC overhead limit exceeded
因此虚拟机并不强制一定要开启这个错误提示,可以通过关闭-XX:-UseGCOverheadLimit来禁止这种OOM产生

2.3 问题排查

1.读懂虚拟机日志

(1)日志打印

首先我们排查问题需要辅助打印一些关键日志信息
使用参数-XX:+PrintGC(JDK9、JDK10默认使用G1作为垃圾回收器,使用参数-Xlog:gc来打印GC日志),启动Java虚拟机后只要遇到GC,就会打印日志
使用参数-XX:+PrintGCTimeStamps(JDK9、JDK10中使用-Xlog:gc*已经默认打印出时间)如果需要分析GC发生的时间
使用参数-XX:+PrintGCApplicationConcurrentTime可以打印应用程序的执行时间
使用参数-XX:+PrintGCApplicationStoppedTime可以打印应用程序由于GC而产生的停顿时间
使用参数-verbose:class跟踪类的加载/卸载,也可以单独使用参数-XX:+TraceClassLoading(在JDK9、JDK10中建议使用-Xlog:class+load=info)跟踪类的加载,以及使用参数-XX:+TraceClassUnloading(在JDK9、JDK10中建议使用-Xlog:class+unload=info)跟踪类的卸载。
使用参数-XX:PrintGCDetails可以打印GC详细信息
使用参数-XX:+PrintHeapAtGC(JDK9开始已经删除此参数)可以在每次GC前、后分别打印堆的信息,和-XX:+PrintGCDetails的输出结果类似。
使用参数-XX:+PrintCommandLineFlags可以打印传递给虚拟机的显式和隐式参数

(2)查看日志

1)parNew日志
2022-04-24T14:38:07.276+0800: 8000.318: [GC (Allocation Failure) 2022-04-24T14:38:07.276+0800: 8000.318: [ParNew: 3359717K->2522K(3774912K), 0.0106372 secs] 3488850K->131738K(5872064K), 0.0108545 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
//8000.318 JVM运行了8000.318S
// [ParNew: 3359717K->2522K(3774912K), 0.0106372 secs] 使用ParNew回收,新生代总空间大小3774912K(3.6G),回收前占用3359717K(3.2G),回收后剩余2522K(2.4M),回收耗时10.6ms
//3488850K->131738K(5872064K), 0.0108545 secs 总堆空间5872064K(5.6G),回收前堆占用3488850K(3.32G),回收后堆占用131738K(128M)
//老年代总空间5872064K(5.6G)-3774912K(3.6G)=2,097,152K(2G),老年代占用3488850K(3.32G)-3359717K(3.2G)=129,133K(126.1M),回收后老年代131738K(128M)-2522K(2.4M)=129,216K(126.1M)
//Times: user=0.02 sys=0.00, real=0.01 secs user用户态耗时0.02s sys系统耗时0 real执行实际耗时0.01s ,多线程情况下通常user+sys>real
2)CMS日志
//初始标志:标记可直达的存活对象
[GC (CMS Initial Mark) [1 CMS-initial-mark: 55K(64K)] 5017K(18496K), 0.0009905 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
//并发标志:通过遍历第一个阶段(initial Mark)标记出来存活的对象,继续递归遍历老年代,并标记可直接或间接到达的所有老年代存活对象
[CMS-concurrent-mark-start]
[CMS-concurrent-mark: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
//并发预清理:将会重新扫描前一个阶段标记的Dirty 对象,并标记被Dirty对象直接或者间接引用的对象,然后清除Card标识
[CMS-concurrent-preclean-start]
[CMS-concurrent-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
//可终止的并发预清理:尽可能承担更多的并发预处理工作,从而减轻在Final Remark阶段的Stop-the-world,处理fromTo区的对象,标记可达的老年代对象,并处理dirty对象。
[CMS-concurrent-abortable-preclean-start]
[CMS-concurrent-abortable-preclean: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
//重新标记:重新扫描之前并发处理阶段所有残留更新对象
[GC (CMS Final Remark) [YG occupancy: 11366 K (18432 K)][Rescan (parallel) , 0.0008940 secs][weak refs processing, 0.0000592 secs][class unloading, 0.0003139 secs][scrub symbol table, 0.0006042 secs][scrub string table, 0.0001389 secs][1 CMS-remark: 55K(64K)] 11422K(18496K), 0.0021115 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
//并发清理:清理所有未被标记的死亡对象,回收被占用的空间
[CMS-concurrent-sweep-start]
[CMS-concurrent-sweep: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
//并发重置:清理并恢复在CMS过程中的各种状态,重新初始化CMS相关数据结构
[CMS-concurrent-reset-start]
[CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
3)G1日志
//94756.981s发生新生代回收,回收时长0.0162274S
2022-04-25T14:48:59.195+0800: 94756.981: [GC pause (G1 Evacuation Pause) (young), 0.0162274 secs]
//GC线程总的花费时间13.4毫秒,两个线程
[Parallel Time: 13.4 ms, GC Workers: 2]
//线程在平均94756981.1S时启动(Avg)、最小94756981.1s、最大94756981.2s、最大最小差值0.0
[GC Worker Start (ms): Min: 94756981.1, Avg: 94756981.1, Max: 94756981.2, Diff: 0.0]
//根扫描的耗时
[Ext Root Scanning (ms): Min: 2.4, Avg: 2.5, Max: 2.6, Diff: 0.2, Sum: 5.0]
//更新记忆集(Remembered Set)的耗时
[Update RS (ms): Min: 7.7, Avg: 7.7, Max: 7.7, Diff: 0.1, Sum: 15.4]
[Processed Buffers: Min: 272, Avg: 273.5, Max: 275, Diff: 3, Sum: 547]
//扫描RS的时间
[Scan RS (ms): Min: 0.8, Avg: 0.9, Max: 0.9, Diff: 0.1, Sum: 1.7]
//扫描code root耗时
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
//拷贝活的对象到新region的耗时
[Object Copy (ms): Min: 2.1, Avg: 2.2, Max: 2.2, Diff: 0.1, Sum: 4.4]
//线程花在终止阶段的耗时
[Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 2]
//GC线程花费在其他任务中的耗时
[GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
[GC Worker Total (ms): Min: 13.3, Avg: 13.3, Max: 13.3, Diff: 0.0, Sum: 26.6]
[GC Worker End (ms): Min: 94756994.5, Avg: 94756994.5, Max: 94756994.5, Diff: 0.0]
//用来将code root修正到正确的 evacuate 之后的对象位置所花费的时间
[Code Root Fixup: 0.0 ms]
//清除code root的耗时code root中的引用已经失效,不再指向Region中的对象所以需要被清除
[Code Root Purge: 0.0 ms]
//清除 RSet 扫描元数据(scanning meta-data)的 card table 消耗的时间.
[Clear CT: 0.7 ms]
[Other: 2.2 ms]
//选定要进行垃圾回收的region集合时消耗的时间。通常很小在必须选择old区时会稍微长
[Choose CSet: 0.0 ms]
//处理 soft, weak, 等引用所花费的时间
[Ref Proc: 0.1 ms]
//将 soft, weak, 等引用放置到待处理列表(pending list)花费的时间
[Ref Enq: 0.0 ms]
//在回收过程中被修改的card将会被重置为dirty
[Redirty Cards: 0.0 ms]
//巨型对象
[Humongous Register: 0.1 ms]
[Humongous Reclaim: 0.1 ms]
[Free CSet: 1.2 ms]
//新生代Eden、S区和堆空间情况
[Eden: 3682.0M(3682.0M)->0.0B(3680.0M) Survivors: 4096.0K->6144.0K Heap: 4039.2M(6144.0M)->334.7M(6144.0M)]
[Times: user=0.03 sys=0.00, real=0.02 secs]
oppo云平台提供日志分析工具,具体路径 云平台->Java Profiler->GC分析->GC日志分析,如下
Image_20220507092920.png

2.查看虚拟机运行信息

JStat命令:查看虚拟机运行时信息
云平台JStat路径:Java Profiler->GC分析->JStat分析
Image_20220507092938.png
查看堆内存信息指标,可借助云平台Java Profiler->JVM监控查看
Image_20220507092952.png

3.内存快照分析

(1)异常Dump内存快照

参数-XX:+HeapDumpOnOutOfMemoryError可以在内存溢出时导出整个堆的信息。参数-XX:HeapDumpPath可以指定导出堆的存放路径。
使用jmap了解系统运行时的对象分布jmap -histo PID
使用jmap生成堆内存转储快照jmap -dump:live,format=b,file=dump.hprof PID
Visual VM本地或远程连接,“线程 Dump”可以导出当前所有线程的堆栈信息(相当于使用jstack命令),“堆Dump”,可以导出当前应用的内存快照(相当于使用jmap命令)。

(2)借助辅助工具分析

以下以MAT为例,限于篇幅以下简要概述问题排查过程。
我们以上例堆溢出代码为例,查找大对象
(注MAT工具可在https://www.eclipse.org/mat/downloads.php下载)

  1. public class HeapOOM {
  2. public static void main(String[] args) {
  3. int count = 0;
  4. List<String> list = new ArrayList<>();
  5. while (true) {
  6. list.add("hello hello hello hello");
  7. System.out.println(++count);
  8. }
  9. }
  10. }

JVM参数

-Xms16m -Xmx32m -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=D:\work\
//溢出后在D:\work\目录dump堆内存

导入堆
我们在mat主界面点击“File”->”Open Head Dump…”选择 -XX:HeapDumpPath=目录下的。hprof文件
*分析堆

打开后如下
Image_20220507093026.png
Image_20220507093040.png
我们通过饼图和Histogram可以看到java.lang.Object[]数组占据了大量的内存.
Image_20220507093102.png
通过threa_overview可以找到HeadOOM中ArrayList有2734845个元素。

4.其他辅助工具

top命令:Linux常用的性能分析工具,能够实时显示系统中各个进程的资源占用状况。
vmstat命令:可以统计CPU、内存使用情况、Swap使用情况等信息。和sar工具类似,vmstat也可以指定采样周期和采样次数。
iostat命令:监控I/O
pidstat工具:多功能诊断器
jps命令:查看Java进程
jps命令:查看虚拟机运行时信息
jinfo命令:查看虚拟机参数
jmap命令:导出堆到文件
jhat命令:JDK自带的堆分析工具(jhat命令在JDK9、JDK10中已经被删除,官方建议用VisualVm代替)
jstack命令:查看线程堆栈
jstatd命令:远程主机信息收集
jcmd命令:多功能命令行
hprof:性能统计工具(说明:hprof在JDK9、JDK10中已经被删除,官方建议用VisualVM代替)
JConsole:图形化虚拟机监控工具
Visual VM:可视化性能监控工具
Flight Recorder:飞行记录器

附录一

(一)常用的GC参数

1.与串行回收器相关的参数
-XX:+UseSerialGC:在新生代和老年代使用串行回收器。
-XX:SurvivorRatio:设置eden区大小和survivior区大小的比例。
-XX:PretenureSizeThreshold:设置大对象直接进入老年代的阈值。当对象的大小超
过这个值时,将直接被分配在老年代。
-XX:MaxTenuringThreshold:设置对象进入老年代的年龄的最大值。每一次 Minor GC后,对象年龄就加1。任何大于这个年龄的对象,一定会进入老年代。
2.与并行GC相关的参数
-XX:+UseParNewGC(考虑到兼容性问题,JDK 9、JDK 10已经删除):在新生代
使用并行回收器。
-XX:+UseParallelOldGC:老年代使用并行回收器。
-XX:ParallelGCThreads:设置用于垃圾回收的线程数。通常情况下可以和CPU数量相等,但在CPU数量比较多的情况下,设置相对较小的数值也是合理的。
-XX:MaxGCPauseMillis:设置最大垃圾回收停顿时间。它的值是一个大于0的整数。回收器在工作时,会调整 Java 堆大小或者其他一些参数,尽可能地把停顿时间控制在MaxGCPauseMillis以内。
-XX:GCTimeRatio:设置吞吐量大小。它的值是一个 0 到 100 之间的整数。假设GCTimeRatio的值为n,那么系统将花费不超过1/(1+n)的时间用于垃圾回收。
-XX:+UseAdaptiveSizePolicy:打开自适应GC策略。在这种模式下,新生代的大小、eden区和survivior区的比例、晋升老年代的对象年龄等参数会被自动调整,以达到在堆大小、吞吐量和停顿时间之间的平衡。
3.与CMS回收器相关的参数(JDK9、JDK10已经开始废弃CMS回收器,建议使用G1回收器)
-XX:+UseConcMarkSweepGC:新生代使用并行回收器,老年代使用CMS+串行回收器。
-XX:ParallelCMSThreads:设定CMS的线程数量。
-XX:CMSInitiatingOccupancyFraction:设置 CMS 回收器在老年代空间被使用多少后触发,默认为68%。
-XX:+UseCMSCompactAtFullCollection:设置 CMS 回收器在完成垃圾回收后是否要进行一次内存碎片的整理。
-XX:CMSFullGCsBeforeCompaction:设定进行多少次CMS垃圾回收后,进行一次内存压缩。
-XX:+CMSClassUnloadingEnabled:允许对类元数据区进行回收。
-XX:CMSInitiatingPermOccupancyFraction:当永久区占用率达到这一百分比时,启动CMS回收(前提是激活了-XX:+CMSClassUnloadingEnabled)。
-XX:UseCMSInitiatingOccupancyOnly:表示只在到达阈值的时候才进行CMS回收。
-XX:+CMSIncrementalMode:使用增量模式,比较适合单CPU。增量模式在JDK 8中标记为废弃,并且将在JDK 9中彻底移除。
4.与G1回收器相关的参数
-XX:+UseG1GC:使用G1回收器。
-XX:MaxGCPauseMillis:设置最大垃圾回收停顿时间。
-XX:GCPauseIntervalMillis:设置停顿间隔时间。
5.TLAB相关
-XX:+UseTLAB:开启TLAB分配。
-XX:+PrintTLAB(考虑到兼容性问题,JDK 9、JDK 10不再支持此参数):打印
TLAB相关分配信息。
-XX:TLABSize:设置TLAB区域大小。
-XX:+ResizeTLAB:自动调整TLAB区域大小。
6.其他参数
-XX:+DisableExplicitGC:禁用显式GC。
-XX:+ExplicitGCInvokesConcurrent:使用并发方式处理显式GC。
参考文献
《深入理解Java虚拟机》周志明
《实战Java虚拟机》葛一鸣
《解密Java虚拟机》封亚飞