Caffeine 本地缓存测试频繁 GC 场景及部分源码分析

Caffeine 本地缓存测试频繁 GC 场景及部分源码分析

Caffeine 缓存缓存在本地，如果不加以限制很可能会出现频繁 GC 甚至 OOM 异常，所以就通过 JVM 调优来还原一下这个场景

验证代码

    public static void main(String[] args) {
        Runtime runtime = Runtime.getRuntime();
        //打印JVM内存信息
        System.out.println("JVM最大内存:" + runtime.maxMemory() / 1024 / 1024 + "MB");
        System.out.println("JVM空闲内存:" + runtime.freeMemory() / 1024 / 1024 + "MB");
        System.out.println("JVM总内存:" + runtime.totalMemory() / 1024 / 1024 + "MB");
        System.out.println("JVM使用内存:" + (runtime.totalMemory() - runtime.freeMemory()) / 1024 / 1024 + "MB");
        
        Cache<Object, Object> cache = Caffeine.newBuilder().initialCapacity(100)
                .maximumSize(1000)
                .build();
        for (int i = 0; i < 1000000; i++) {
            cache.put(i, i);
            if (i % 100000 == 0) {
                System.out.println("size=" + cache.estimatedSize());
            }
        }
        System.out.println("sizeTotal=" + cache.estimatedSize());
    }

代码中设置了一个 Caffeine 缓存项，并不断往缓存项中添加一百万条数据，测试默认 JVM 堆内存的场景，控制台输出如下。

JVM最大内存:3593MB
JVM空闲内存:238MB
JVM总内存:243MB
JVM使用内存:5MB
size=1
size=3718
size=1741
size=1582
size=1341
size=2608
size=3320
size=2203
size=1777
size=2159
sizeTotal=1256

可以看到 Caffeine 缓存的数量明显超过设置的最大值。

现在通过设置 JVM 参数来运行这段代码：

JVM 参数

-Xmx5M -Xms5M -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCApplicationConcurrentTime

控制台输出

[GC (Allocation Failure) [PSYoungGen: 1024K->504K(1536K)] 1024K->719K(5632K), 0.0004400 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Application time: 0.0173222 seconds
[GC (Allocation Failure) [PSYoungGen: 1520K->504K(1536K)] 1735K->1023K(5632K), 0.0004841 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Application time: 0.0145365 seconds
[GC (Allocation Failure) [PSYoungGen: 1528K->504K(1536K)] 2047K->1275K(5632K), 0.0004711 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
JVM最大内存:5MB
JVM空闲内存:3MB
JVM总内存:5MB
JVM使用内存:1MB
Application time: 0.0058228 seconds
[GC (Allocation Failure) [PSYoungGen: 1526K->504K(1536K)] 2297K->1447K(5632K), 0.0004399 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Application time: 0.0148082 seconds
[GC (Allocation Failure) [PSYoungGen: 1528K->504K(1536K)] 2471K->1615K(5632K), 0.0004126 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Application time: 0.0114254 seconds
[GC (Allocation Failure) [PSYoungGen: 1528K->512K(1536K)] 2639K->1815K(5632K), 0.0006096 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Application time: 0.0093270 seconds
[GC (Allocation Failure) [PSYoungGen: 1536K->512K(1536K)] 2839K->2135K(5632K), 0.0005227 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Application time: 0.0069513 seconds
[GC (Allocation Failure) [PSYoungGen: 1536K->448K(1536K)] 3159K->2199K(5632K), 0.0003356 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
size=1
Application time: 0.0072869 seconds
[GC (Allocation Failure) [PSYoungGen: 1472K->480K(1536K)] 3223K->2527K(5632K), 0.0004597 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Application time: 0.0082897 seconds
[GC (Allocation Failure) [PSYoungGen: 1504K->480K(1536K)] 3551K->2751K(5632K), 0.0004257 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Application time: 0.0035578 seconds
[GC (Allocation Failure) [PSYoungGen: 1504K->384K(1536K)] 3775K->2983K(5632K), 0.0004133 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 
Application time: 0.0038165 seconds
[GC (Allocation Failure) [PSYoungGen: 1408K->320K(1536K)] 4007K->2983K(5632K), 0.0004985 secs] [Times: user=0.16 sys=0.00, real=0.00 secs] 
Application time: 0.0031722 seconds
[GC (Allocation Failure) [PSYoungGen: 1344K->320K(1536K)] 4007K->3063K(5632K), 0.0003808 secs] [Times: user=0.00 sys&