1. 问题:
线上的一个服务需要做缓存,并且每隔 10s 刷新一次缓存,使用了 Ehcache 框架。
为了避免缓存的并发读写问题(仔细研究 ehcache 就会发现这并不是问题),当时设计了两个 Cache 对象轮流使用的方式,即 使用(读取)缓存 A 的过程中刷新缓存 B,时间到之后使用缓存 B,使用缓存B的过程中再去刷新缓存 A,循环往复。
上线一段时间后,服务在峰值期间会在某个时间点开始 young GC 变得非常频繁,老年代大小快速增长随后引发多次 mixed GC(使用的是G1),服务峰值过后会自愈,但服务峰值期间重启无效。
2. 问题分析
使用 jmap 得到 mixed gc 发生前后的直方图,发现 mixed gc 时有大量的
org.ehcache.impl.internal.concurrent.ConcurrentHashMap$Node
,即问题出现 ehcache 缓存上。
因为是频繁的young gc 然后引发多次的 mixed gc 并且 mixed gc 能回收大量堆内存,所以肯定是因为某种原因持续不断的产生了大量对象,并且这种对象经过多次 young gc 仍然存活然后进入了老年代。
首先想到的是服务峰值期间 young gc 太频繁,导致 10s 缓存期间缓存对象的 gc 年龄达到了最大值,进入了老年代。那么观察两个指标:
- young gc 频率
- jvm 设置的老年代晋升年龄
对应如下:
- 10s刷新一次缓存,AB轮流,所以缓存最长生存 20s(不可能达到20s),发生问题时服务平均 30s 进行一次 young gc
- 使用的是默认晋升年龄15(实际上晋升年龄是动态调整的,但是这里不影响)
所以不可能通过正常的 young gc 产生这么多晋升老年代的 缓存对象。
运维通过压测得出结论,当缓存数量超过19.8万时才会出现这个问题。说明这些被缓存的Node对象正常是能够被 young GC 回收掉的,并没有进入老年代。那么为什么数据到达 19.8 万之后这些对象就没有被回收掉呢?
仔细看 gc 日志,偶然注意到发生 mixed gc之前开始出现多次:
[GC pause (G1 Humongous Allocation)
意味着发生了大对象直接分配在老年代。
在G1中,如果一个对象的大小超过分区大小的一半,该对象就被定义为大对象(Humongous Object)。大对象时直接分配到老年代分区,分配之后也不会被移动。
如果缓存作为大对象分配在老年代,那么缓存的Node因为被缓存集合对象引用,也无法回收,最终进入老年代?
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 了,这时候就是个大对象了。
刚要兴奋,找到了问题,突然一想又不对。虽然大对象 HashMap 在老年代,但是这些Node 只是在 HashMap 中有个引用,Node 本体还是在年轻代,10s后就作为垃圾回收了,并不会进入老年代。
这时候我们的任务就变成了寻找为什么Node会进入老年代。这是一个很曲折的过程,怎么发现的已经回想不清,这里只能给出结果。
3. ehcache的clear()方法的特殊之处
首先我们来看一段代码。java.util.ConcurrentHashMap 有一个 clear() 方法,用于清楚当前所持有的所有 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() 就是最终操作,它做了什么呢?
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 指向新对象,即使用这个新对象来存储缓存数据。旧对象呢?旧对象不再被引用,变成垃圾。如果频繁使用 clear() 方法,就会产生大量的等待回收的 EvictingConcurrentMap 对象。
在我们这里,这些 clear() 后产生的 HashMap 都是大对象,那么发生 mixed gc 之前就不会被回收,被引用的Node也就不能被回收,从而经过多次 young gc 之后进入老年代,导致老年代迅速增长:
- 每10s增加一个HashMap对象2M
- HashMap的key-value分别为 Long 和 CopiedOnHeapValueHolder,所以持有的对象数组是
Node<Long, CopiedOnHeapValueHolder<Object>>[]
, 其中 Object 就是缓存的数据,一个Node 大概 136 byte,20w 个就是 27M
。定时任务每10s一次,每次29M,半小时 27M * 6 * 30 = 5.22G,不到半小时就要产生一次 mixed gc。
4. clear() 方法创建 EvictingConcurrentMap 对象的解释
这里使用了函数式接口,如果不了解函数式接口可能会看不懂为什么 clear() 方法会新建一个 EvictingConcurrentMap 对象。
realMapSupplier 是 OnHeapStore 类的属性,它的类型是 Supplier<EvictingConcurrentMap<K, OnHeapValueHolder<V>>>, 而 Supplier 是一个带泛型的函数式接口:
@FunctionalInterface
public interface Supplier<T> {
T get();
}
任意一个类如果实现了 get() 方法,就是实现了这个函数式接口,而 java 类的构造函数恰好可以算作实现了 get() 方法。
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 对象。