记一次 Redis 不定时命中率降低问题调查

🏷️ Redis

问题现象

后端服务获取用户令牌信息时有几率获取不到。
这个处理是在 Filter 中执行的，在所有业务处理之前。
采用 StringRedisTemplate 操作 Redis 缓存，令牌是个 String 类型的缓存。
令牌缓存的 KEY 在 Redis 中是一直存在的，远没到过期时间。
获取不到令牌的请求，响应也很快，并不是由于 Redis 超时导致的。
使用同一台 Redis（db 不同）的其它服务一切都是正常的，从没出现过类似问题。
线下的测试环境使用的自建 Redis，并没有出现过这个问题。
出问题服务的容器镜像是 9 天前构建的。
服务重启之后会恢复正常，但不确定多长时间之后又会再次出现。
重启后可能一天内都是好的，也可能几分钟之后就又出问题。
与此同时，Redis 性能监控中的命中率图表会出现明显的波动，与服务出问题的时间基本一致。
命中率波动非常大，正常情况下一般在 95% 左右，但出问题时可能会降到 20% 以下。

问题调查

先说明下项目环境，服务端是 SpringBoot，使用 StringRedisTemplate 操作 Redis，使用的 lettuce 连接池。
Redis 服务器是阿里云的 2 节点集群版多分区版。

这里最令人费解的就是如果代码出了问题导致请求没有发送出去，那么 Redis 服务器应该不会有命中率降低的现象；
而如果请求确实是发送到了 Redis 服务器，由于 Key 是存在的，那么同样命中率也不会有降低才对。

为了调查问题原因，采取了一些方法，但一直没有找到原因，而且由于代码很久没有变动过，所以一度怀疑是 Redis 服务器的原因。

检查了相关的代码，最近 1 个月没有动过 Redis 或 RedisTemplate 相关的代码和配置。
代码类似如下处理：

java

String tokenInfo = stringRedisTemplate.opsForValue().get(token);
if (StringUtils.isEmpty(tokenInfo)) {
    log.error("TokenFilter TokenNotExist {} {}", token, request.getRequestURI());
    return;
}

采用请求重放的方式，确认了即使是相同的请求，也有一定几率出现这个问题。
这里用了 jMeter 重放请求。
打印了日志，发现服务段获取到的令牌参数是对的。
以为是 Redis 服务器的问题，找了阿里云客服，最后发现服务器并没有什么异常。
后让采用抓包的方式（Pod 和宿主节点），看一下服务发送的请求内容，但由于运维当时已经回家过年啦，就没执行。
现在回想起来，如果当时抓包的话，应该是有助于发现问题原因的。
以为是 Redis 连接池中的连接问题，修改了 lettuce 线程池的配置，将最低空闲连接数量修改成了 0。
修改了 Redis timeout 配置（超过次空闲时间将断开连接），从 0（永不断开）修改为 60（空闲超过 60 秒断开连接）。
在获取不到令牌信息时，立即尝试重复获取（最多 3 次），但发现若获取不到，则连续的 3 次都获取不到。
以为是多分区 Redis 服务器的原因，后来采用 DTS 的方式无缝切换成了单分区的 Redis，本因为已经好了，但隔天又出现问题。
阿里云的 DTS 不知道什么时候开始已支持 Redis 同步。
记得之前切换 Redis，从备份开始再恢复备份到一台新的 Redis 实例，大概要花费半个小时以上的时间。
现在切换基本上是无缝的，只要修改配置后重新部署容器就行了。

上述调查持续了近一周的时间，最后偶然间想到会不会是我别的处理中曾经用过 Redis 事务的原因。
在启用了 RedisTemplate.multi 之后，之后的请求并不会立即执行，返回的就是 null ，和获取时的现象有点像。
但令牌获取的处理中并没有调用 multi 方法，于是查看了 multi 方法的实现。

java

/*
 * (non-Javadoc)
 * @see org.springframework.data.redis.core.RedisOperations#multi()
 */
@Override
public void multi() {
    execute(connection -> {
        connection.multi();
        return null;
    }, true);
}

可以看到这里调用了 connection 的 multi 方法，正是这里改变了 connection 的状态，而连接池会保持连接，从而导致所有使用这个连接的都可能会出问题。

不知道为什么我这里没有 Javadoc 文档，同事的电脑上有文档说明，上面写了调用了该方法，必须调用 exec 或 discard 方法。
本次问题的根源应该就在这里，因为代码的缺陷，导致没有执行到这两个方法。

另外需要注意 execute 的第二个参数，这里是 true ，这个参数表示是否公开 Redis 连接给调用的方法。
猜测如果这个值是 false ，应该也不会发生此次的问题。

由于默认使用的 lettuce 连接池，这里连接的实例是 LettuceConnection ，其 multi 和 isQueueing 方法代码如下：

java

@Override
public void multi() {
    if (isQueueing()) {
        return;
    }
    isMulti = true;
    try {
        if (isPipelined()) {
            getAsyncDedicatedRedisCommands().multi();
            return;
        }
        getDedicatedRedisCommands().multi();
    } catch (Exception ex) {
        throw convertLettuceAccessException(ex);
    }
}

/*
 * (non-Javadoc)
 * @see org.springframework.data.redis.connection.RedisConnection#isQueueing()
 */
@Override
public boolean isQueueing() {
    return isMulti;
}

正是在这个方法中改变了 connection 的状态。

另外，LettuceStringCommands 的 get 方法代码如下：

java

/*
 * (non-Javadoc)
 * @see org.springframework.data.redis.connection.RedisStringCommands#get(byte[])
 */
@Override
public byte[] get(byte[] key) {

    Assert.notNull(key, "Key must not be null!");

    try {
        if (isPipelined()) {
            pipeline(connection.newLettuceResult(getAsyncConnection().get(key)));
            return null;
        }
        if (isQueueing()) {
            transaction(connection.newLettuceResult(getAsyncConnection().get(key)));
            return null;
        }
        return getConnection().get(key);
    } catch (Exception ex) {
        throw convertLettuceAccessException(ex);
    }
}

此时 isQueueing() 为 true ，这也就解释了，为什么 Redis 中明明有这个缓存， StringRedisTemplate.get 方法却返回的是 null 了。

再看下 LettuceConnection.exec 方法，在此将 isMulti 重置为了 false 。
而如果因为异常等原因导致该方法没被调用，则该连接的 isMulti 将一直是 true，直到下一次 exec 方法的调用。

java

@Override
@SuppressWarnings({ "unchecked", "rawtypes" })
public List<Object> exec() {

    isMulti = false;

    try {
        if (isPipelined()) {
            RedisFuture<TransactionResult> exec = getAsyncDedicatedRedisCommands().exec();

            LettuceTransactionResultConverter resultConverter = new LettuceTransactionResultConverter(
                    new LinkedList<>(txResults), LettuceConverters.exceptionConverter());

            pipeline(newLettuceResult(exec, source -> resultConverter
                    .convert(LettuceConverters.transactionResultUnwrapper().convert((TransactionResult) source))));
            return null;
        }

        TransactionResult transactionResult = (getDedicatedRedisCommands()).exec();
        List<Object> results = LettuceConverters.transactionResultUnwrapper().convert(transactionResult);
        return convertPipelineAndTxResults
                ? new LettuceTransactionResultConverter(txResults, LettuceConverters.exceptionConverter()).convert(results)
                : results;
    } catch (Exception ex) {
        throw convertLettuceAccessException(ex);
    } finally {
        txResults.clear();
    }
}

下面是 discard 方法，这里也会将 isMulti 置为 false ，并丢弃队列中的任务。

java

@Override
public void discard() {
    isMulti = false;
    try {
        if (isPipelined()) {
            pipeline(newLettuceStatusResult(getAsyncDedicatedRedisCommands().discard()));
            return;
        }
        getDedicatedRedisCommands().discard();
    } catch (Exception ex) {
        throw convertLettuceAccessException(ex);
    } finally {
        txResults.clear();
    }
}

下面是事后写的两个测试方法，multi 的正确用法可以参考第二个方法，应该使用 catch 和 finally 确保事务的关闭。

java

@Test
void should_null_when_not_discard_in_catch() {
    String key = "test_key";
    String setValue = "test_value";

    stringRedisTemplate.opsForValue().set(key, setValue);

    try {
        stringRedisTemplate.setEnableTransactionSupport(true);
        stringRedisTemplate.multi();

        throw new Exception("");

        // stringRedisTemplate.exec();
    } catch (Exception ex) {
        // stringRedisTemplate.discard();
    } finally {
        stringRedisTemplate.setEnableTransactionSupport(false);
    }

    String getValue = stringRedisTemplate.opsForValue().get(key);

    Assertions.assertNull(getValue);
}

@Test
void should_not_null_when_discard_in_catch() {
    String key = "test_key";
    String setValue = "test_value";

    stringRedisTemplate.opsForValue().set(key, setValue);

    try {
        stringRedisTemplate.setEnableTransactionSupport(true);
        stringRedisTemplate.multi();

        throw new Exception("");

        // stringRedisTemplate.exec();
    } catch (Exception ex) {
        stringRedisTemplate.discard();
    } finally {
        stringRedisTemplate.setEnableTransactionSupport(false);
    }

    String getValue = stringRedisTemplate.opsForValue().get(key);

    Assertions.assertNotNull(getValue);
    Assertions.assertEquals(getValue, setValue);
}

对策

修改前代码如下：

java

stringRedisTemplate.setEnableTransactionSupport(true);
stringRedisTemplate.multi();
// do some redis operations
stringRedisTemplate.exec();
stringRedisTemplate.setEnableTransactionSupport(false);

虽然暂时还不知道什么原因导致的 exec 方法没有调用（没有看到任何相关的错误日志，而且这段代码运行了有近半年了），但是能说明至今出现的所有现象。
特别是命中率的问题，虽然 Key 存在，但由于获取时仅仅只是将获取的任务放到了命令队列中，而在执行时，这些任务可能会被分配到不存在这个 Key 的节点（Redis 是集群版），从而导致出现了命中率降低的现象。
这也可以解释为什么服务重启之后一切就都正常了，为什么出现问题的时间不确定，为什么重复多次获取总是失败。

这也侧面说明了，代码没有出现问题，不代表没有问题。
=。=|||

知道问题在哪里就好修改了，参考上面的第二个测试方法，在使用 multi 命令时，确保其被执行或取消就行了，另外事务也需要确保被关闭。

java

try {
    stringRedisTemplate.setEnableTransactionSupport(true);
    stringRedisTemplate.multi();

    // do some redis operations

    stringRedisTemplate.exec();
} catch (Exception ex) {
    stringRedisTemplate.discard();
} finally {
    stringRedisTemplate.setEnableTransactionSupport(false);
}

记一次 Redis 不定时命中率降低问题调查 ​

问题现象 ​

问题调查 ​

对策 ​

记一次 Redis 不定时命中率降低问题调查

问题现象

问题调查

对策