关于java:一次年轻代GC长暂停问题的解决与思考

52次阅读

共计 6575 个字符，预计需要花费 17 分钟才能阅读完成。

问题形容

公司某规定引擎零碎，在每次发版启动会手动预热，预热实现当流量切进来之后会偶发的呈现一次长达 1 - 2 秒的年老代 GC（流量并不大，并且 LB 下的每一台服务都会呈现该状况）

在这次长暂停之后，每一次的年老代 GC 暂停工夫又都复原在 20-100ms 以内

2s 尽管看起来不长，然而比照规定引擎每次 10ms 左右的响应工夫来说，还是不能够承受的；并且因为该规定引擎响应超时，还会导致出单超时失败

问题剖析

在剖析该零碎 GC 日志后发现，2s 暂停产生在 Young GC 阶段，而且每次产生长暂停的 Young GC 都会随同着新生代对象的降职(Promotion)

外围 JVM 参数（Oracle JDK7）

-Xms10G 
-Xmx10G 
-XX:NewSize=4G 
-XX:PermSize=1g 
-XX:MaxPermSize=4g 
-XX:+UseConcMarkSweepGC

启动后第一次年老代 GC 日志

2020-04-23T16:28:31.108+0800: [GC2020-04-23T16:28:31.108+0800: [ParNew2020-04-23T16:28:31.229+0800: [SoftReference, 0 refs, 0.0000950 secs]2020-04-23T16:28:31.229+0800: [WeakReference, 1156 refs, 0.0001040 secs]2020-04-23T16:28:31.229+0800: [FinalReference, 10410 refs, 0.0103720 secs]2020-04-23T16:28:31.240+0800: [PhantomReference, 286 refs, 2 refs, 0.0129420 secs]2020-04-23T16:28:31.253+0800: [JNI Weak Reference, 0.0000000 secs]
Desired survivor size 214728704 bytes, new threshold 1 (max 15)
- age   1:  315529928 bytes,  315529928 total
- age   2:   40956656 bytes,  356486584 total
- age   3:    8408040 bytes,  364894624 total
: 3544342K->374555K(3774912K), 0.1444710 secs] 3544342K->374555K(10066368K), 0.1446290 secs] [Times: user=1.46 sys=0.09, real=0.15 secs]

长暂停年老代 GC 日志

2020-04-23T17:18:28.514+0800: [GC2020-04-23T17:18:28.514+0800: [ParNew2020-04-23T17:18:29.975+0800: [SoftReference, 0 refs, 0.0000660 secs]2020-04-23T17:18:29.975+0800: [WeakReference, 1224 refs, 0.0001400 secs]2020-04-23T17:18:29.975+0800: [FinalReference, 8898 refs, 0.0149670 secs]2020-04-23T17:18:29.990+0800: [PhantomReference, 600 refs, 1 refs, 0.0344300 secs]2020-04-23T17:18:30.025+0800: [JNI Weak Reference, 0.0000210 secs]
Desired survivor size 214728704 bytes, new threshold 15 (max 15)
- age   1:   79203576 bytes,   79203576 total
: 3730075K->304371K(3774912K), 1.5114000 secs] 3730075K->676858K(10066368K), 1.5114870 secs] [Times: user=6.32 sys=0.58, real=1.51 secs]

从这个长暂停的 GC 日志来看，是产生了降职的，在 Young GC 后，有 363M+ 的对象降职到了老年代，这个降职操作因该就是耗时起因（ps: 查看过 safepoint 起因，不存在异样）

因为日志参数中没有配置 -XX:+PrintHeapAtGC 参数，这里是手动计算的降职大小：

年老代年老变动 - 全堆容量变动 = 降职大小
(304371K - 3730075K) - (676858K - 3730075K) = 372487K(363M)

下一次年老代 GC 日志

2020-04-23T17:23:39.749+0800: [GC2020-04-23T17:23:39.749+0800: [ParNew2020-04-23T17:23:39.774+0800: [SoftReference, 0 refs, 0.0000500 secs]2020-04-23T17:23:39.774+0800: [WeakReference, 3165 refs, 0.0002720 secs]2020-04-23T17:23:39.774+0800: [FinalReference, 3520 refs, 0.0021520 secs]2020-04-23T17:23:39.776+0800: [PhantomReference, 150 refs, 1 refs, 0.0051910 secs]2020-04-23T17:23:39.782+0800: [JNI Weak Reference, 0.0000100 secs]
Desired survivor size 214728704 bytes, new threshold 15 (max 15)
- age   1:   17076040 bytes,   17076040 total
- age   2:   40832336 bytes,   57908376 total
: 3659891K->90428K(3774912K), 0.0321300 secs] 4032378K->462914K(10066368K), 0.0322210 secs] [Times: user=0.30 sys=0.00, real=0.03 secs]

乍一看其实没什么问题，认真想想发现了一些不失常，为什么程序刚启动第二次 gc 就产生了降职呢

这里应该是动静年龄断定导致的，GC 中降职年龄阈值并不是固定的 15，而是 jvm 每次 gc 后动静计算的

年老代降职机制

为了能更好地适应不同程序的内存情况，虚拟机并不是永远地要求对象的年龄必须达到了 MaxTenuringThreshold 能力降职老年代，如果在 Survivor 空间中雷同年龄所有对象大小的总和大于 Survivor 空间的一半，年龄大于或等于该年龄的对象就能够间接进入老年代，毋庸等到 MaxTenuringThreshold 中要求的年龄

《深刻了解 Java 虚拟机》一书中提到，对象降职年龄的阈值是动静断定的。

不过经查阅其余材料和验证后，发现此处和《深刻了解 Java 虚拟机》解释的有些出入（或者是书上解释的不够分明）

其实就是按年龄给对象分组，取 total（累加值，小于等与以后年龄的对象总大小）最大的年龄分组，如果该分组的 total 大于 survivor 的一半，就将降职年龄阈值更新为该分组的年龄

留神：不是是超过 survivor 一半就降职，超过 survivor 一半只会从新设置降职阈值（threshold），在下一次 GC 才会应用该新阈值

3544342K->374555K(3774912K), 0.1444710 secs] 年老代

3544342K->374555K(10066368K), 0.1446290 secs] 全堆

从下面第一次的 GC 日志也能够证实这个论断，在这次 GC 中全堆的内存变动和年老代内存变动是相等的，所以并没有产生对象的降职

就像下面的日志中，第一次 GC 只是将 threshold 设置为 1，因为此时 survivor 一半为 214728704 bytes，而年龄为 1 的对象总和有 315529928 bytes，超过了 Desired survivor size，所以在本次 GC 后将 threshold 设置为年龄为 1 的对象年龄 1 

这里更新了对象降职年龄阈值为 1
Desired survivor size 214728704 bytes, new threshold 1 (max 15)
- age   1:  315529928 bytes,  315529928 total
- age   2:   40956656 bytes,  356486584 total
- age   3:    8408040 bytes,  364894624 total

这里顺便解释下这个年龄散布的输入内容：

- age   1:  315529928 bytes,  315529928 total

- age 1示意年龄为 1 的对象分组，315529928 bytes示意年龄为 1 的对象占用内存大小

315529928 total这个是一个累加值，示意小于等于以后分组年龄的对象总大小。先把对象按年龄分组，age 1 的分组 total 为 age 1 总大小（后面的 xxx bytes），age 2 的分组 total 为 age 1 + age 2 总大小，age n 的分组 total 为 age 1 + age 2 + ... +age n 的总大小，累加规定如下图所示

当 total 最大的分组的 total 值超过了 survivor/ 2 时，就会更新降职阈值

在第二次年老代 GC“长暂停年老代 GC 日志”中，因为新的降职年龄阈值为 1，所以那些经验了一次 GC 并存活并且当初依然可达（reachable）的对象们就会产生降职了

因为此次 GC 产生了 363M 的对象降职，所以导致了长暂停

思考

JVM 中这个“动静对象年龄断定”真的是正当的吗？集体认为机制是好的，能够更好的适应不同程序的内存情况，但不是任何场景都适宜，比方在本文中这个刚启动不就 GC 的场景下就会有问题

因为在程序刚启动时，大多数对象年龄都是 0 或者 1，很容易呈现年龄为 1 的大量存活对象；在这个“动静对象年龄断定”机制下，就会导致新的降职阈值被设置为 1，导致这些不该降职的对象产生了降职

比方程序在初始化，正在加载各种资源时产生了 Young GC，加载逻辑还在执行中，很多新建的对象年龄在这次 GC 时还是可达的（reachable）

经验了这次 GC 后，这些对象年龄更新为 1，然而因为“动静对象年龄断定”机制的影响，降职年龄阈值更新为了“最大的对象年龄分组”的年龄，也就是这批刚经验了一次 GC 的对象们

在这次 GC 之后不久，资源初始化实现了，波及的相干对象有很可能不可达了，然而因为方才降职年龄阈值被更新为了 1，在下一次失常的 Young GC 这批年龄为 1 的对象会间接产生降职，提前或者说谬误的产生了降职

解决方案

经查阅文档、材料，发现“动静年龄断定”这个机制并不能禁用，所以如果想解决这个问题，只有靠“绕过”这个计算规定了

动静年龄的断定，是依据 Survivor 空间中雷同年龄所有对象大小的总和大于 Survivor 空间的一半来断定的，那么依据这个机制解决也很简略

因为咱们足够理解本人的零碎，分明的晓得加载资源所需的大略内存，齐全能够设定一个大于这些临时可达的对象总和的数值来作为 survivor 的容量

比方下面的日志中，第一次 GC 后年龄为 1 的对象有 315529928 Bytes(300M)，Desired survivor size 为（survivor size /2）214728704 bytes(204M)，那么 survivor 就能够设置为 600M 以上。

不过为了稳当，还是将 survivor 调到 800M，这样 desired survivor size 就是 400M 左右，在第一次 Young GC 后，就不会因年龄为 1 的对象总和超过了 desired survivor size 而导致降职年龄阈值的更新了，从而也就不会有提前 / 谬误降职而导致的 GC 长暂停问题

survivor 不能够间接指定大小，不过能够通过 -XX:SurvivorRatio 这种调节比例的形式来调节 survivor 大小

-XX:SurvivorRatio=8

示意两个 Survivor 和 Edgen 区的比，8 示意两个 Survivor:Eden=2:8，即一个 Survivor 占新生代的 1 /10。

计算形式为：

Survivor Size(1) = Young Generation Size / (2+SurvivorRatio)
Eden Size = Young Generation Size / (2+SurvivorRatio) * SurvivorRatio

扩大浏览

为什么降职 300M 比年老代回收 3G 还要慢这么多倍

依据复制算法的个性，复制算法的工夫耗费次要取决于存活对象的大小，而不是总空间的大小

比方下面 4G 的年老代（理论只有 Eden+S0 可用），GC 时只须要从 GC ROOTS 开始遍历对象图，将可达的对象复制至 S1 即可，并不需要遍历整个年老代

复制算法的具体介绍能够参考我的另一篇文章《垃圾回收算法实现之 – 复制算法（残缺可运行 C 语言代码）》

在下面那次长暂停 GC 日志中，产生了 363M 的降职，300M 左右的回收，比照第一次 GC 根本能够得出，破费的 1.5S 基本上都是在降职操作

那么为什么降职操作这么耗时呢？

这里没有深入研究 Oracle JVM 实现的年老代降职细节，不过降职波及跨代复制（其实都年老代和老年代都是 heap，在复制这件事上实质上没什么区别，都是 memcpy 而已，只是须要额定解决的逻辑更多了）
，所需解决的逻辑会更简单一些，比方指针的更新等操作，更耗时也是能够了解的，

本地代码模仿

这里也附上一段能够在本地模仿问题的代码，Oracle JDK7 下可间接运行测试

//jdk7.。import java.io.IOException;
import java.util.ArrayList;
import java.util.HashMap;
import java.util.List;

public class PromotionTest {public static void main(String[] args) throws IOException {
        // 模仿初始化资源场景
        List<Object> dataList = new ArrayList<>();
        for (int i = 0; i < 5; i++) {dataList.add(new InnerObject());
        }
        // 模仿流量进入场景
        for (int i = 0; i < 73; i++) {if(i == 72){System.out.println("Execute young gc...Adjust promotion threshold to 1");
            }
            new InnerObject();}
        System.out.println("Execute full gc...dataList has been promoted to cms old space");
        // 这里留神 dataList 中的对象在这次 Full GC 后会进入老年代
        System.gc();}
    public static byte[] createData(){
        int dataSize = 1024*1024*4;//4m
        byte[] data = new byte[dataSize];
        for (int j = 0; j < dataSize; j++) {data[j] = 1;
        }
        return data;
    }
    static class InnerObject{
        private Object data;

        public InnerObject() {this.data = createData();
        }
    }
}

jvm options

-server -Xmn400M -XX:SurvivorRatio=9 -Xms1000M -Xmx1000M -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintTenuringDistribution -XX:+PrintHeapAtGC -XX:+PrintReferenceGC -XX:+PrintGCApplicationStoppedTime -XX:+UseConcMarkSweepGC

参考

  • 《深刻了解 JAVA 虚拟机》– 周志明 著
  • https://blog.codecentric.de/e…

正文完
java
发表至： java
2020-04-29
 0
关于java:类加载机制和双亲委派模型
关于java:应用服务-和-模板方法-擦出的火花
关于java:Java-开发如何高效正确管理-IDEA
关于java:聊一个不常见的面试题为什么数据库连接池不采用-IO-多路复用