guava cache大量的WARN日志的问题分析

一、问题显现

2019-04-21 11:16:32 [http-nio-4081-exec-2] warn  com.google.common.cache.localcache - exception thrown during refresh
com.google.common.cache.cacheloader$invalidcacheloadexception: cacheloader returned null for key bkciyear0.
	at com.google.common.cache.localcache$segment.getandrecordstats(localcache.java:2350)
	at com.google.common.cache.localcache$segment$1.run(localcache.java:2331)
	at com.google.common.util.concurrent.moreexecutors$directexecutor.execute(moreexecutors.java:457)
	at com.google.common.util.concurrent.executionlist.executelistener(executionlist.java:156)
	at com.google.common.util.concurrent.executionlist.add(executionlist.java:101)
	at com.google.common.util.concurrent.abstractfuture.addlistener(abstractfuture.java:170)
	at com.google.common.cache.localcache$segment.loadasync(localcache.java:2326)
	at com.google.common.cache.localcache$segment.refresh(localcache.java:2389)
	at com.google.common.cache.localcache$segment.schedulerefresh(localcache.java:2367)
	at com.google.common.cache.localcache$segment.get(localcache.java:2187)
	at com.google.common.cache.localcache.get(localcache.java:3937)
	at com.google.common.cache.localcache.getorload(localcache.java:3941)
	at com.google.common.cache.localcache$localloadingcache.get(localcache.java:4824)
	at com.kcidea.sushibase.service.cache.googlelocalcache.getcachebyname(googlelocalcache.java:42)　　

google的这个开发工具里面的缓存是个轻量化的缓存，类似一个hashmap的实现，google在里面加了很多同步异步的操作。使用起来简单，不用额外搭建redis服务，故项目中使用了这个缓存。

有一天生产环境直接假死了，赶紧上服务器排查，发现日志里面有大量的报warn错误，只要触发cache的get就会报警告，由于cache的触发频率超高，导致了日志磁盘爆满，一天好几个g的日志里面全是warn的错误。但是在开发环境下根本不触发这个错误，怎么调试都没有进这段代码里面。先暂时停用了缓存，然后开始排查。

 

  二、问题排查

1. 根据报错的堆栈，一点一点往上找，直到找到这一行的时候发现了一些端倪，他想找一个newvalue

at com.google.common.cache.localcache$segment.refresh(localcache.java:2389)

2. 继续顺着这条线往里面找，直到找到这段代码，为什么要找newvalue呢，map需要刷新了，过期了，或者主动触发刷新值了。

  if (map.refreshes()
          && (now - entry.getwritetime() > map.refreshnanos)
          && !entry.getvaluereference().isloading()) {
        v newvalue = refresh(key, hash, loader, true);
        if (newvalue != null) {
          return newvalue;
        }
      }

　3. 然后就可以解释问题为什么只在生产环境出现，而开发环境不出现了，因为是触发了过期时间，我们设置的过期时间是30分钟，所以开发环境很少调试超过30分钟的，每次都是重新运行，所以根本触发不到这个超时的地方。

4. 然后接着调试，发现会走到我们一开始初始化cache的代码那边

    /**
     * 缓存队列变量
     */
    static loadingcache<string, object> cache = cachebuilder.newbuilder()
            // 给定时间内没有被读/写访问，则回收。
            .refreshafterwrite(cache_out_time, timeunit.minutes)
            // 缓存过期时间和redis缓存时长一样
            .expireafteraccess(cache_out_time, timeunit.minutes)
            // 设置缓存个数
            .maximumsize(50000).
                    build(new cacheloader<string, object>() {
                        @override
                        public object load(string key) throws exception {
                            //找不到就返回null （1）
                            return null；
                        }
                    });

　注意上面的代码，（1）的位置，找不到就返回null，在网上找的代码里面这里通常写的是return null或者return dothingsthehardway(key)之类的，但是没有详细的dothingsthehardway描述，所以我这里写了个null。

所以根本的问题就是这里返回null导致的错误了。

 

三、解决方案

找到了问题原因，解决方案就相对来说容易的很多了

1. 修改（1）处的代码，将return null修改成return new nullobject()  

    static loadingcache<string, object> cache = cachebuilder.newbuilder()
            // 给定时间内没有被读/写访问，则回收。
            .refreshafterwrite(cache_out_time, timeunit.minutes)
            // 缓存过期时间和redis缓存时长一样
            .expireafteraccess(cache_out_time, timeunit.minutes)
            // 设置缓存个数
            .maximumsize(50000).
                    build(new cacheloader<string, object>() {

                        @override
                        public object load(string key) throws exception {
                            //尝试将这里改成new nullobject，外面进行判断
                            return new nullobject();
                        }
                    });

　　

2. 定义一个空白的类就叫nullobject

/**
 * classname   nullobject
 * author      shenjing
 * date        2019/7/10
 * version     1.0
 **/
public class nullobject {
}

　　

3. 在通用的getcachebyname的方法中进行判断，取到的对象是不是nullobject类型的，如果是，则返回null给外层，进行重新加载。

  private static <t> t getcachebyname(string name) {
        t ret = null;
        try {
            if (cache.asmap().containskey(name)) {
                ret = (t) cache.get(name);
                if (ret.getclass().equals(nullobject.class)) {
                    //缓存已过期，返回null
                    return null;
                }
                log.debug("缓存读取[{}]成功", name);
            }
        } catch (exception ex) {
            log.debug("缓存[{}]读取失败：{}", name, ex.getmessage());
        }

        return ret;
    }