guava缓存使用不当导致的FullGC

背景

同事跑路，接手了一个sdk，提供了从redis上查询数据，缓存到本地的功能。最近发现接入了该sdk的项目每天都会发生一两次FullGC（在用户访问高峰期发生FullGC会导致服务响应卡顿，应该尽量避免），特别是有个项目没接入前是没有FullGC产生的，接入之后有了FullGC。每个项目的老年代都是10GB左右，每次FullGC完了，老年代的内存占用又回到很低的水平，并不是有内存泄漏，导致一直回收不掉的那种情况。
使用guava的配置如下：

//这里就用DemoObject来脱敏了，生产环境的对象名字不是这个
    private static Cache<Long, DemoObject> cache = CacheBuilder.newBuilder()
            .concurrencyLevel(4)
            .expireAfterWrite(180, TimeUnit.SECONDS)
            .initialCapacity(8)
            .maximumSize(50000)
            .build();
1
2
3
4
5
6
7

排查过程

我们在一些机器老年代内存增长到快要触发FullGC的时候，将机器隔离，然后通过jmap dump快照下载下来分析。发现DemoObject的数量不到50000个，也就是说还没有达到guava cache配置的maximum大小。DemoObject对象也不大，几万个对象也就占用60MB。
看样子似乎和guava没关系，但是接入了我们sdk的服务都有fullgc，并且有个项目有个开关，只要开关关闭，即不使用我们sdk的功能，老年代就不明显增长，只要开关打开，就很明显增长。我们sdk内部就是一个查询redis上的数据，然后反序列化成java对象，放到guava cache中的功能。所以，不得不又得回到怀疑guava cache的路上来。
上网查了一下guava cache导致fullgc的文章，发现有些说的是没有设置maximumSize导致的fullgc，但是我们设置了。后来又发现有些文章提到设置weakKeys、weakValues、softValues。
我们决定本地试试看能否复现。

本地复现

新建maven工程，pom.xml内容如下:

<project xmlns="http://maven.apache.org/POM/4.0.0"
         xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
         xsi:schemaLocation="http://maven.apache.org/POM/4.0.0 http://maven.apache.org/xsd/maven-4.0.0.xsd">
    <modelVersion>4.0.0modelVersion>

    <groupId>org.examplegroupId>
    <artifactId>fullgc-researchartifactId>
    <version>1.0version>

    <properties>
        <maven.compiler.source>8maven.compiler.source>
        <maven.compiler.target>8maven.compiler.target>
    properties>

    <dependencies>
        <dependency>
            <groupId>com.google.guavagroupId>
            <artifactId>guavaartifactId>
            <version>19.0version>
        dependency>
    dependencies>

    <build>
        <plugins>
            <plugin>
                <groupId>org.apache.maven.pluginsgroupId>
                <artifactId>maven-shade-pluginartifactId>
                <version>2.4.1version>
                <executions>
                    <execution>
                        <phase>packagephase>
                        <goals>
                            <goal>shadegoal>
                        goals>
                        <configuration>
                            <transformers>
                                <transformer implementation="org.apache.maven.plugins.shade.resource.ManifestResourceTransformer">
                                    <mainClass>MainClassmainClass>
                                transformer>
                            transformers>
                        configuration>
                    execution>
                executions>
            plugin>
        plugins>
    build>
project>
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48

有两个类，一个是main方法所在的类：

import com.google.common.cache.Cache;
import com.google.common.cache.CacheBuilder;
import com.google.common.util.concurrent.RateLimiter;

import java.util.concurrent.TimeUnit;

/**
 * @author pilaf
 * @description
 * @date 2022-08-20 10:37
 **/
public class MainClass {
    /**
     * 本地缓存，如果不设置.weakKeys().weakValues()，在持续不断往cache中放入新对象的时候，会导致老年代占用越来越大，最终导致FullGC
     * 如果设置.weakKeys().weakValues()，老年代不会占用越来越大
     */
    private static Cache<Long, DemoObject> cache = CacheBuilder.newBuilder()
            .concurrencyLevel(4)
            .expireAfterWrite(180, TimeUnit.SECONDS)
            .weakKeys()
            .weakValues()
            .initialCapacity(8)
            .maximumSize(50000)
            .build();

    /**
     * 写入缓存限流
     */
    private static RateLimiter writeLimiter = RateLimiter.create(20000);

    public static void main(String[] args) {
        loopWrite();
    }

    /**
     * 启动一个线程，往guava cache中写入大量对象
     */
    private static void loopWrite() {
        new Thread(() -> {
            Long id = 0L;
            //限制一共写入500万个对象
            while (id < 500_0000) {
                writeLimiter.acquire();
                cache.put(id, new DemoObject());
                id++;
            }
        }).start();
    }
}

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50

另一个是DemoObject：

/**
 * @author pilaf
 * @description 填充一个1kB的数组的对象
 * @date 2022-08-20 10:38
 **/
public class DemoObject {

    /**
     * 4kB
     */
    private int[] array = new int[1024];
}
1
2
3
4
5
6
7
8
9
10
11
12

打包成jar包之后，通过如下命令启动jar：

java  -jar -Xms1528m -Xmx1528m -Xmn848m -XX:MetaspaceSize=192m -XX:MaxMetaspaceSize=256m -XX:+UseConcMarkSweepGC -XX:MaxTenuringThreshold=8 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=本地路径/error.dump -XX:+ExplicitGCInvokesConcurrentAndUnloadsClasses -XX:CMSInitiatingOccupancyFraction=90 -XX:+PrintGCDateStamps -XX:+UseCMSInitiatingOccupancyOnly -XX:+UnlockDiagnosticVMOptions -XX:+UnsyncloadClass -XX:+UseParNewGC -XX:+PrintGCDetails -Xloggc:本地路径/gc_detail.log -XX:ActiveProcessorCount=4 当前工程路径/fullgc-reasech/target/fullgc-research-1.0.jar
1

说明：
上面启动命令给堆内存分配了1528MB，新生代848MB，剩下老年代700MB左右。采用CMS垃圾回收器。
CMSInitiatingOccupancyFraction=90表示老年代占用超过90%的时候执行fullgc
MaxTenuringThreshold=8表示对象经过8次younggc的时候会被放入老年代，如果是大对象，没到次数也会被放入老年代
gc_detail.log文件中搜索FullGC相关的日志：
GC (CMS Initial Mark)表示这是CMS开始对老年代进行垃圾圾收集的初始标记阶段，该阶段从垃圾回收的“根对象”开始，且只扫描直接与“根对象”直接关联的对象，并做标记，需要暂停用户线程（Stop The Word，下面统称为STW），速度很快。
理解gc log相关内容参考：https://www.jianshu.com/p/ba768d8e9fec

我们通过jprofiler工具attach到本地的java进程。
不设置weakKeys、weakValues的时候，CMS老年代使用如下：

老年代一会就触发fullgc了，然后回收完不一会儿又上升到触发fullgc的高度。

设置了weakKeys、weakValues的时候，CMS老年代使用如下：

老年代等了一会才有占用，而且一直处在很低的占用，且很平稳。

我理解的原因，不知道是否真的对，仅供参考：
1.不设置weakKeys、weakValues的时候，guava cache中的（没有被淘汰的）对象都是强引用（Strong Reference），垃圾回收不掉，虽然刚放入缓存的对象在新生代，但是经过一定次数的younggc后，就进入老年代了。进入老年代后，即使guava cache中的对象数量达到上限5万（我们这边一个对象占用1kB多，5万个也就占用50MB多）或者超过过期时间，导致有些对象该被从缓存中淘汰出去，但是因为被淘汰出去的对象已经处在老年代，younggc回收不到这儿。然后随着不断往cache中放入新对象，挤出老对象，老年代占用越来越大，最终导致fullgc。
2.设置weakKeys、weakValues的时候，guava cache中的对象，都是弱引用了，younggc的时候可以将弱引用的对象回收掉。这样guava cache中的未被回收的对象数量会比较少，导致它不是一个大对象，在经过几次youggc后（达到我们java -jar命令中设置的8次），它也会被移动到老年代。因为我们放入guava cache的速度很快，导致缓存中的对象很快进入，很快被挤出，也就是说缓存中的对象数量不会太多，所以看到的老年代占用只有2.51MB左右。但是这样缓存中的对象数量很少，起不到缓存的作用了。

说明：因为为了本地快速观察现象，所以故意把限流值调高，放入guava cache的速度很快，如果读者有时间慢工出细活，想观察更多现象，可以将writeLimiter调小一点。

guava cache设置weak、soft引用的含义

guava cache builder中设置weakKeys、weakValues其实就是让原本是强引用变成弱引用。注意，这里是对所有放到cache中的对象而言，并不是说（超过缓存大小或到过期时间）被淘汰的对象会由强引用变成弱引用。这一点在guava api的注释中有说明：each key、each value，说的是所有的key，所有的value。by default，strong reference are used说的是，如果不设置weak或soft，默认就是使用强引用。

什么场景用guava cache比较合适？

我们的使用场景是缓存5万个对象（总大小估计有100MB左右），对象3分钟过期，然后又回换一批，如果不用弱引用，会导致老年代时间久了fullgc，如果用弱引用，其实会导致缓存中的弱引用对象在younggc的时候会被回收掉，在younggc比较频繁的时候，缓存的效果不太理想，因为缓存中的对象大部分被清理掉，来查询缓存的时候发现缓存中没有，还得去请求redis，这样本地缓存的效果大打折扣。
思考一下，guava cache似乎更适合那种不会大量频繁更换的对象的缓存，这样可以把过期时间设置大一些。或者缓存频繁刷新的时候，要把过期时间设置小一点，这样可以在younggc次数达到你配置的最大上限之前就把缓存中的对象在新生代就给回收掉，不至于进入老年代。

---

工程git地址：https://github.com/sqdf1990/fullgc-research
参考：https://www.jianshu.com/p/ba768d8e9fec
java中的强、弱、软、虚引用相关的介绍请参考：
https://stackoverflow.com/questions/299659/whats-the-difference-between-softreference-and-weakreference-in-java