情景再现
最近同事的一个项目在测试环境出来了一个奇怪的问题,说项目一登录就卡死,接口一直没响应,也不报错,正式环境也没有这个问题,感觉很奇怪,他找了很长时间找不出问题,让我帮忙排查一下是什么原因,排查了一上午的时间终于找到原因了,代码逻辑其实很简单,大致逻辑如下模拟代码:
@Cacheable(cacheNames = {"user","user"},key = "#id",sync =true)
public String getById(String id) {
System.out.println("get from db");
return "user:" + id;
}
重要线索
他说只要把 @Cacheable去掉就不卡,加上就卡,这是一条非常重要的线索,肯定是这个导致的卡卡死,首先可以确定,不是数据库查询问题。
排查步骤
-
查看缓存有没有数据
我在想这肯定是走缓存了,那就打开redis 客户端看看有没有这个缓存,发现有一个user~lock这个Key 它的值为locked,看来是Redis线程死锁了,如果他看一下Redis数据库估计也就找到原因。
-
找到CacheAspectSupport
有个execute()方法,有个 if (contexts.isSynchronized())判断,如果设置了sync=true的话,设置Redis缓存时会加锁
-
找到死锁代码 RedisCache waitForLock()方法
这里就是个死循环,每隔300毫秒去Redis查询一下有没有 user~lock这个key,而且这个 key的有效期是永久的,所以就是卡在这里一直循环出不去了。
解决方法
redis中删除 lock这个Key 就OK了
问题出现的原因
在RedisWriteThroughCallback 的 doInRedis中会先lock一个,在 finally会unlock(connection);
我猜测应该是测试环境停用服务使用的是 kill -9 导致finally中的unlock方法没有执行, 而且这个key没有设置过期时间,所以就永久死循环了,如果不加sync =true 也不会加锁了。
static class RedisWriteThroughCallback extends AbstractRedisCacheCallback<byte[]> {
public RedisWriteThroughCallback(BinaryRedisCacheElement element, RedisCacheMetadata metadata) {
super(element, metadata);
}
@Override
public byte[] doInRedis(BinaryRedisCacheElement element, RedisConnection connection) throws DataAccessException {
try {
lock(connection);
try {
byte[] value = connection.get(element.getKeyBytes());
if (value != null) {
return value;
}
.........
return value;
} catch (RuntimeException e) {
if (!isClusterConnection(connection)) {
connection.discard();
}
throw e;
}
} finally {
unlock(connection);
}
}
};