ehcache的clear()方法使用不当引起的gc

1. 问题:

线上使用 ehcache 做了一个缓存,缓存刷新时间间隔为 10s。

为了避免缓存刷新过程中的并发读写问题,设计了两个 Cache 缓存对象轮流使用的方式,即:

  1. 使用(读取)缓存 A 的过程中刷新缓存 B,10s 之后时间到,转而使用缓存 B;
  2. 使用缓存B的过程中再去刷新缓存 A,循环往复。

上线一段时间后,服务在峰值期间会在某个时间点开始 young GC 变得非常频繁,同时老年代占用空间快速增长,随后引发 mixed GC(使用的是G1)次数增长。
峰值过后会自愈,但峰值期间重启无效。

2. 问题分析

使用 jmap 得到 mixed gc 发生前后的直方图,发现 mixed gc 前有大量的缓存对象:
org.ehcache.impl.internal.concurrent.ConcurrentHashMap$Node
mixed gc 后被回收。所以问题出在 ehcache 缓存上。

因为是频繁的young gc 然后引发多次的 mixed gc 并且 mixed gc 能回收大量堆内存,所以肯定是因为某种原因持续不断的产生了大量对象,并且这种对象经过多次 young gc 仍然存活然后进入了老年代。顺着这个思路往下分析。


首先想到的是服务峰值期间 young gc 太频繁,导致 10s 缓存期间缓存对象的 gc 年龄达到了最大值,进入了老年代。那么观察两个指标:

  1. young gc 频率
  2. jvm 设置的老年代晋升年龄

对应如下:

  1. 10s刷新一次缓存,AB两个缓存轮流使用,所以缓存最长生存 20s(不可能达到20s),发生问题时服务平均 30s 进行一次 young gc
  2. 使用的是默认晋升年龄 15,后面看 gc 日志发现发生了动态年龄调整

同时,运维通过压测得出结论,当缓存数量超过19.8万时才会出现这个问题。说明这些被缓存的 Node 对象在平常是能够被 young GC 回收掉的。那么为什么数据到达 19.8 万之后这些对象就会进入老年代呢?


仔细看 gc 日志,偶然注意到发生 mixed gc之前开始出现多次:
[GC pause (G1 Humongous Allocation)
以及
[GC pause (G1 evacuation Pause)(young) Desired survivor size 127926272 bytes, new threshold 2 (max 15)
意味着发生了大对象直接分配在老年代,以及动态年龄阈值调整。

2.1 大对象

在G1中,如果一个对象的大小超过分区大小的一半,该对象就被定义为大对象(Humongous Object)。大对象是直接分配到老年代,分配之后也不会被移动。
G1的分区大小对照表:

最小堆大小 分区的大小
heap < 4GB 1MB
4GB <= heap < 8GB 2MB
8GB <= heap < 16GB 4MB
16GB <= heap < 32GB 8MB
32GB <= heap < 64GB 16MB
64GB <= heap 32MB
我们的服务是8G的堆,所以大于 2MB 就是大对象。
我们来算一下存放 19.8w 个 Node 的 ConcurrentHashMap 应该是多大:

HashMap 中 Node 数组大小应该是 2 的 n 次方,并且算上承载因子 0.75 后应该大于19.8万,最后计算得到应该是 262144 个。
4 byte * 262144 = 1M (HashMap保存的是Node的引用,引用压缩之后是 4 byte,压测数据还是很靠谱的)。
如果大于19.8w个,HashMap需要翻倍扩容,就大于 2M 了,确实是个大对象。

缓存使用的大对象被分配在老年代,那么存放具体缓存数据的 Node 因为被HashMap引用,也无法被 young gc 回收,最终进入老年代。

2.2 动态年龄调整

对象在新生代经历 young gc,每存活一次年龄加1,当年龄达到阈值时,就会晋升老年代。
这个阈值最大15,可以通过 jvm 参数设置,但是 jvm 也会动态调整。
例如一次 young gc 后,survivor 区放不下所有存活对象,这时候所有对象从最大年龄到最小年龄,每个年龄的对象作为一批,依次转移到老年代,直到剩下的对象可以放进 survivor 区。最后一批转移对象的年龄就会变成晋升老年代的年龄阈值(因为最终结果是大于等于此年龄的对象都晋升了老年代)。

2.3 还是有一点问题解释不通

缓存对象使用的 HashMap 作为一个大对象,晋升到了老年代,这没有问题。但是存放具体数据的 Node 只是在 HashMap 中有个引用,Node 本体还是在年轻代,10s 这些 Node 被释放,此时就可以作为垃圾被 young gc 回收了。而且因为缓存对象并不大(哪怕是服务峰值期间总大小也只有30M左右,下文有计算),回收之前并不会因为 survivor 区放不下而提前晋升。
但实际观察到的现象是 Node 一直没被 young gc 回收并且最终进入了老年代。
这时候我们的任务就变成了寻找为什么 Node 一直不能回收。这是一个很曲折的过程,因为查问题查了很久,所以怎么发现的已经回想不清,这里只能给出结果。

3. ehcache的clear()方法的特殊之处

在切换AB缓存时,使用了 ehcache 的 clear() 方法,意识是清空缓存。clear() 方法在 jdk 的结合类中使用的很多。
以 java.util.ConcurrentHashMap 为例我们来看一下它的 clear() 方法,用于清除 hashmap 当前所持有的所有 key-value 数据:

public void clear() {
    long delta = 0L; 
    int i = 0;
    Node<K,V>[] tab = table;
    while (tab != null && i < tab.length) {
        int fh;
        Node<K,V> f = tabAt(tab, i);
        if (f == null)
            ++i;
        else if ((fh = f.hash) == MOVED) {
            tab = helpTransfer(tab, f);
            i = 0; // restart
        }
        else {
            synchronized (f) {
                if (tabAt(tab, i) == f) {
                    Node<K,V> p = (fh >= 0 ? f :
                                   (f instanceof TreeBin) ?
                                   ((TreeBin<K,V>)f).first : null);
                    while (p != null) {
                        --delta;
                        p = p.next;
                    }
                    setTabAt(tab, i++, null);
                }
            }
        }
    }
    if (delta != 0L) {
        addCount(delta, -1);
    }
}
复制代码

即使你看不懂这段代码也没关系,你应该能看出来这段代码在把当前 map 中的数据去掉。这个操作很符合我们对于 clear() 的认知,事实上 jdk 中集合类的 clear() 方法也基本是这个效果。
我们仔细去debug ehcache 的 clear() 方法(一定要debug,不然接口有多个实现类根本不知道是哪个):
Ehcache.clear() -> EhcacheBase.clear() -> OnHeapStore.clear() -> SimpleBackend.clear()
SimpleBackend.clear() 就是最终的 clear 操作,它做了什么呢?

public void clear() {
    // 如果你去下载源码,就可以看到下面的注释,"这比清理map快"
    // This is faster than performing a clear on the underlying map
    this.realMap = (EvictingConcurrentMap)this.realMapSupplier.get();
}
复制代码

每次 clear() 都是创建了一个新的 EvictingConcurrentMap 对象,让 SimpleBackend 的属性 realMap 指向这个新对象,并使用这个新对象来存储缓存数据。旧对象呢?旧对象的 HashMap 被释放,和 Node 一起等待垃圾回收。
但是 HashMap 已经因为是大对象而提前晋升老年代,所以 mixed gc 之前不会被回收,而 Node 被 HashMap 引用,即使在年轻代,也不会被回收。
每隔 10s 就调用一次 clear() 方法,意味着每隔 10s 就产生一批 young gc 无法回收的 Node 对象。
我们来算一下产生的 Node 对象的总大小:

HashMap 的 key-value 分别为 Long 和 CopiedOnHeapValueHolder,所以持有的对象数组是 Node<Long, CopiedOnHeapValueHolder<Object>>[] , 其中 Object 就是缓存的数据,一个Node 大概 136 byte,20w 个就是 27M

定时任务每10s一次,每次29M,半小时 27M * 6 * 30 = 5.22G,这些 Node 对象无法被 young gc 回收 survivor 区又放不下,只能提前晋升老年代。大量 Node 对象占满老年代又触发了 mixed gc。

4. clear() 方法创建 EvictingConcurrentMap 对象的解释

这里涉及到函数式接口,如果不了解函数式接口可能会看不懂为什么 clear() 方法会新建一个 EvictingConcurrentMap 对象。
realMapSupplier 是 OnHeapStore 类的属性,它的类型是 Supplier<EvictingConcurrentMap<K, OnHeapValueHolder<V>>>
而 Supplier 是一个带泛型的函数式接口:

// 这个注解就表明是函数式接口,编译期会检查
// 没有这个注解也可以用作函数式接口,但是编译期不会检查
@FunctionalInterface
public interface Supplier<T> {
    T get();
}
复制代码

任意一个返回一个 java 对象的方法都是实现了这个函数式接口,而 java 类的构造函数就是返回一个自身类的对象,恰好可以算作是实现了Supplier接口。
realMapSupplier 的初始化在 OnHeapStore 的构造函数中,OnHeapStore 的构造函数的调用在自己的子类 Provider 中:

OnHeapStore<K, V> onHeapStore = new OnHeapStore(storeConfig, timeSource, keyCopier, valueCopier, >sizeOfEngine, eventDispatcher, ConcurrentHashMap::new);
复制代码

所以 realMapSupplier 的实现就是 ConcurrentHashMap::new 即 ConcurrentHashMap 的构造函数, 每次调用 realMapSupplier.get() 就会得到一个 ConcurrentHashMap 对象。