记一次 Redisson 线上问题 → ERR unknown command 'WAIT' 的排查与分析

252 阅读7分钟

开心一刻

昨晚和一个朋友聊天
我:处对象吗,咱俩试试?
朋友:我有对象
我:我不信,有对象不公开?
朋友:不好公开,我当的小三

开心一刻

问题背景

程序在生产环境稳定的跑着;某一天,公司进行组件漏洞扫描,有漏洞的 jar 要进行升级修复;不出意外,我负责的那部分也扫出漏洞了,然后我就按着扫描报告将有漏洞的 jar 修复到指定的版本;自己在开发环境也做了主流业务的测试,没有任何异常,稳如老狗

稳如老狗

提测之后,测试小姐姐也没测出问题,一切尽在我的掌握中;结果升级到生产后,生产日志疯狂报错

org.redisson.client.RedisException: ERR unknown command 'WAIT'

完整的异常堆栈信息类似如下

org.redisson.client.RedisException: ERR unknown command 'WAIT'. channel: [id: 0x84149c6e, L:/192.168.2.40:3592 - R:/47.98.21.100:6379] command: (WAIT), params: [1, 1000]

    at org.redisson.client.handler.CommandDecoder.decode(CommandDecoder.java:346)
    at org.redisson.client.handler.CommandDecoder.decodeCommandBatch(CommandDecoder.java:247)
    at org.redisson.client.handler.CommandDecoder.decodeCommand(CommandDecoder.java:189)
    at org.redisson.client.handler.CommandDecoder.decode(CommandDecoder.java:117)
    at org.redisson.client.handler.CommandDecoder.decode(CommandDecoder.java:102)
    at io.netty.handler.codec.ByteToMessageDecoder.decodeRemovalReentryProtection(ByteToMessageDecoder.java:508)
    at io.netty.handler.codec.ReplayingDecoder.callDecode(ReplayingDecoder.java:366)
    at io.netty.handler.codec.ByteToMessageDecoder.channelRead(ByteToMessageDecoder.java:276)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
    at io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:357)
    at io.netty.channel.DefaultChannelPipeline$HeadContext.channelRead(DefaultChannelPipeline.java:1410)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
    at io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:365)
    at io.netty.channel.DefaultChannelPipeline.fireChannelRead(DefaultChannelPipeline.java:919)
    at io.netty.channel.nio.AbstractNioByteChannel$NioByteUnsafe.read(AbstractNioByteChannel.java:166)
    at io.netty.channel.nio.NioEventLoop.processSelectedKey(NioEventLoop.java:719)
    at io.netty.channel.nio.NioEventLoop.processSelectedKeysOptimized(NioEventLoop.java:655)
    at io.netty.channel.nio.NioEventLoop.processSelectedKeys(NioEventLoop.java:581)
    at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:493)
    at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989)
    at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
    at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
    at java.lang.Thread.run(Thread.java:748)

这是个什么鬼玩意嘛,真是脑阔疼

脑阔疼

先让运维同事回滚,然后就开始了我的问题排查之旅

问题排查

排查问题之前,我先准备个 demo:redisson-spring-boot-demo,执行如下 testLock 方法即可进行测试

/**
 * @author 青石路
 */
@RunWith(SpringRunner.class)
@SpringBootTest
public class RedisTest {

    @Resource
    private RedissonClient redissonClient;

    @Test
    public void testLock() throws Exception {
        RLock lock = redissonClient.getLock("redis:qsl:test");
        boolean locked = lock.tryLock(10, 30, TimeUnit.SECONDS);
        if (locked) {
            System.out.println("锁获取成功,进行业务操作...");
        } else {
            System.out.println("锁获取失败");
        }
    }
}

项目很简单,通过 redisson-spring-boot-starter 引入 redisson。扯点题外的东西,关于 redisson-spring-boot-starter 的配置方式,一共有 4 种:Integration with Spring

  1. 方式1

    spring:
      data:
        redis:
          database: 
          host:
          port:
          password:
          ssl: 
          timeout:
          connectTimeout:
          clientName:
          cluster:
            nodes:
          sentinel:
            master:
            nodes:
    
  2. 方式2

    spring:
      redis:
        database: 
        host:
        port:
        password:
        ssl: 
        timeout:
        connectTimeout:
        clientName:
        cluster:
          nodes:
        sentinel:
          master:
          nodes:
    
  3. 方式3

    spring:
      redis:
       redisson: 
          file: classpath:redisson.yaml
    
  4. 方式4

    spring:
      redis:
       redisson: 
          config: |
            clusterServersConfig:
              idleConnectionTimeout: 10000
              connectTimeout: 10000
              timeout: 3000
              retryAttempts: 3
              retryInterval: 1500
              failedSlaveReconnectionInterval: 3000
              failedSlaveCheckInterval: 60000
              password: null
              subscriptionsPerConnection: 5
              clientName: null
              loadBalancer: !<org.redisson.connection.balancer.RoundRobinLoadBalancer> {}
              subscriptionConnectionMinimumIdleSize: 1
              subscriptionConnectionPoolSize: 50
              slaveConnectionMinimumIdleSize: 24
              slaveConnectionPoolSize: 64
              masterConnectionMinimumIdleSize: 24
              masterConnectionPoolSize: 64
              readMode: "SLAVE"
              subscriptionMode: "SLAVE"
              nodeAddresses:
              - "redis://127.0.0.1:7004"
              - "redis://127.0.0.1:7001"
              - "redis://127.0.0.1:7000"
              scanInterval: 1000
              pingConnectionInterval: 0
              keepAlive: false
              tcpNoDelay: false
            threads: 16
            nettyThreads: 32
            codec: !<org.redisson.codec.Kryo5Codec> {}
            transportMode: "NIO"
    

如果 4 种方式都配置,最终生效的是哪一种?此刻我不想探究最终生效的是哪一种,我只想给你个大嘴巴子

大嘴巴子

这是什么问题嘛,你选其中一种配置不就好了,你同时配置 4 种干嘛?但作为一个宠粉的博主,既然你们都提出这个问题了,那我就盘一盘它;问题又来了:从哪盘,怎么盘?源码之下无密码,我们就从源码去盘,找到自动配置类

关于 spring-boot 的自动配置,参考:springboot2.0.3源码篇 - 自动配置的实现,发现也不是那么复杂

RedissonAutoConfiguration 中有如下代码

@Bean(destroyMethod = "shutdown")
@ConditionalOnMissingBean(RedissonClient.class)
public RedissonClient redisson() throws IOException {
    Config config = null;
    Method clusterMethod = ReflectionUtils.findMethod(RedisProperties.class, "getCluster");
    Method timeoutMethod = ReflectionUtils.findMethod(RedisProperties.class, "getTimeout");
    Object timeoutValue = ReflectionUtils.invokeMethod(timeoutMethod, redisProperties);
    int timeout;
    if(null == timeoutValue){
        timeout = 10000;
    }else if (!(timeoutValue instanceof Integer)) {
        Method millisMethod = ReflectionUtils.findMethod(timeoutValue.getClass(), "toMillis");
        timeout = ((Long) ReflectionUtils.invokeMethod(millisMethod, timeoutValue)).intValue();
    } else {
        timeout = (Integer)timeoutValue;
    }

    if (redissonProperties.getConfig() != null) {
        try {
            config = Config.fromYAML(redissonProperties.getConfig());
        } catch (IOException e) {
            try {
                config = Config.fromJSON(redissonProperties.getConfig());
            } catch (IOException e1) {
                throw new IllegalArgumentException("Can't parse config", e1);
            }
        }
    } else if (redissonProperties.getFile() != null) {
        try {
            InputStream is = getConfigStream();
            config = Config.fromYAML(is);
        } catch (IOException e) {
            // trying next format
            try {
                InputStream is = getConfigStream();
                config = Config.fromJSON(is);
            } catch (IOException e1) {
                throw new IllegalArgumentException("Can't parse config", e1);
            }
        }
    } else if (redisProperties.getSentinel() != null) {
        Method nodesMethod = ReflectionUtils.findMethod(Sentinel.class, "getNodes");
        Object nodesValue = ReflectionUtils.invokeMethod(nodesMethod, redisProperties.getSentinel());

        String[] nodes;
        if (nodesValue instanceof String) {
            nodes = convert(Arrays.asList(((String)nodesValue).split(",")));
        } else {
            nodes = convert((List<String>)nodesValue);
        }

        config = new Config();
        config.useSentinelServers()
            .setMasterName(redisProperties.getSentinel().getMaster())
            .addSentinelAddress(nodes)
            .setDatabase(redisProperties.getDatabase())
            .setConnectTimeout(timeout)
            .setPassword(redisProperties.getPassword());
    } else if (clusterMethod != null && ReflectionUtils.invokeMethod(clusterMethod, redisProperties) != null) {
        Object clusterObject = ReflectionUtils.invokeMethod(clusterMethod, redisProperties);
        Method nodesMethod = ReflectionUtils.findMethod(clusterObject.getClass(), "getNodes");
        List<String> nodesObject = (List) ReflectionUtils.invokeMethod(nodesMethod, clusterObject);

        String[] nodes = convert(nodesObject);

        config = new Config();
        config.useClusterServers()
            .addNodeAddress(nodes)
            .setConnectTimeout(timeout)
            .setPassword(redisProperties.getPassword());
    } else {
        config = new Config();
        String prefix = REDIS_PROTOCOL_PREFIX;
        Method method = ReflectionUtils.findMethod(RedisProperties.class, "isSsl");
        if (method != null && (Boolean)ReflectionUtils.invokeMethod(method, redisProperties)) {
            prefix = REDISS_PROTOCOL_PREFIX;
        }

        config.useSingleServer()
            .setAddress(prefix + redisProperties.getHost() + ":" + redisProperties.getPort())
            .setConnectTimeout(timeout)
            .setDatabase(redisProperties.getDatabase())
            .setPassword(redisProperties.getPassword());
    }
    if (redissonAutoConfigurationCustomizers != null) {
        for (RedissonAutoConfigurationCustomizer customizer : redissonAutoConfigurationCustomizers) {
            customizer.customize(config);
        }
    }
    return Redisson.create(config);
}

最终生效的是哪一种,是不是一目了然了?

有点扯远了,我们继续回到问题,不对,问题还没复现,我们先回到问题复现;redisson-spring-boot-starter 升级前的版本是 3.13.6,此版本在开发、测试、生产环境都是能正常跑的,将它升级到 3.15.0 之后,在开发、测试环境运行正常,上生产后则报错:

org.redisson.client.RedisException: ERR unknown command 'WAIT'

因为没做任何的业务代码修改,所以问题肯定出在升级后的 redisson-spring-boot-starter ,你们说是不是?这个问题我们肯定不是第一个遇到的,肯定有其他的先行者碰到过,所以我们可以去 redisson 的 issues 找找答案;直接搜索关键字:WAIT

Redisson issue搜WAIT

点进去看看明细

阿里云Redis

这不就是我们的生产异常?我立马找运维确认,生产确实用的是阿里云 redis ,并且是代理模式!出于严谨,我们还需要对

3.14.0 是正常的,3.14.1 有异常

这个结论进行验证;因为公司未提供测试环境的阿里云 redis ,所以楼主只能自掏腰包购买一套最低配的阿里云 redis

低配版阿里云Redis

我们来看下验证结果

redisson版本验证

结论确实是对的,楼主又去阿里云翻了一下手册

阿里云redis支持命令

那我们是不是可以把问题范围缩小了,redisson 3.14.0 未引入 wait 命令,而 3.14.1 引入了,所以问题产生了!但这只是我们的猜想,我们需要强有力的支撑,找谁了?肯定还得是源码!

  1. redisson 3.14.0 源码

    redisson 3.14.0

    我们可以看到,真正发送给 redis-server 执行的命令不只是加锁的脚本,还有 WAIT 命令!只是因为异步执行命令,只关注了加锁脚本的执行结果,而并没有关注 WAIT 命令的执行结果

    Redisson3.14.0未关注WAIT结果

    也就是说 3.14.0 也有 WAIT 命令,并且在阿里云 redis 的代理模式下执行是失败的,只是 redisson 并没有去管 WAIT 命令的执行结果,所以只要加锁命令执行是成功的,那么 Redisson 就认为执行结果是成功的,这也就是 3.14.0 执行成功,没有报异常的原因

  2. redisson 3.14.1 源码

    redisson 3.14.1

    真正发送给 redis-server 执行的命令有加锁脚本,也有 WAIT 命令,并且两个命令的执行结果都有关注

    Redisson3.14.1关注WAIT结果

    加锁脚本执行是成功的, redis 已经有对应的记录,而阿里云 redis 的代理模式是不支持 WAIT 命令,所以 WAIT 命令是执行失败的,而最终的执行结果是所有命令的执行结果,所以最终执行结果是失败的!

问题处理

既然根因已找到,那么我们应该如何正确的升级到生产环境了?

  1. 将 redisson 版本降到 3.14.0

    不去关注 WAIT 命令的执行结果,相当于没有 WAIT 命令
    这个可能产生什么问题( redisson 引入 WAIT 命令的意图),转动你们智慧的头脑,评论区告诉我答案

  2. 阿里云 redis 改成直连模式

总结

  1. 环境一致的重要性

    测试环境一定要保证和生产环境一致,否则就会出现和楼主一样的问题,其他环境都没问题,就生产有问题
    环境不一致,排查问题也很棘手

  2. Redisson 很早就会附加 WAIT 命令,只是从 3.14.1 开始才关注 WAIT 命令的执行结果

  3. 对于维护中的老项目,代码能不动就不动,配置能不改就不改,组件能不升就不升

    都说了能不动就别动,非要去调整,出生产事故了吧

    又不是不能用