1、背景

作者所在项目组为第三方提供身份管控组件，组件中有个高频接口GetToken，主要作用是验证用户登录后颁发的token是否有效。文中涉及到的redis集群都为redis cluster部署方式

2、问题

近期某业务线报了一个bug，说在压测业务线某个接口时并发压到100之后99%报接口超时，业务线查看日志发现是因为GetToken接口超时。

3、接口逻辑

GetToken接口的逻辑并不复杂，是通过go语言开发的微服务，主要流程如下：

1、将收到的token做base64解密得到实际token

2、连接redis

3、根据token拼出key

4、用key到redis中获取value

5、如果拿到value就反序列化成对象返回

6、拿不到value说明token已过期，返回错误

4、调查过程

最开始接到这个bug的第一感觉是一定是业务线哪块配置错了，因为这个GetToken我们组已识别它为高频接口，测试已经压测过，至少可以达到1000qps。

4.1 第一次尝试

因为坚信代码没有问题，所以第一时间去检查了业务线的配置项，发现redis地址给配了两个一样的redis节点地址：

cache=redis://:password@10.41.xx.xx:16379,10.41.xx.xx:16379

问了下ops发现使用的是redis集群，三个ip，每个ip三个端口，相当于9节点。

因为这边使用的第三方组件go-redis作为redis客户端，也是支持redis集群的，所以让ops把全部9个节点都填上，替换之前的配置：

cache=redis://:password@10.41.xx.xx:16379,10.41.xx.xx:16380,10.41.xx.xx:16381,10.41.xx.xx:16379,10.41.xx.xx:16380,10.41.xx.xx:16381,10.41.xx.xx:16379,10.41.xx.xx:16380,10.41.xx.xx:16381

但是问题依旧。

4.2 第二次尝试

既然第一次尝试没有成功，那就从头开始吧。先复现问题。

因为测试休假了，我把她的jmeter测试脚本要过来，方便自己测试，发现并发量可以到60，到70就会有部分接口超时，大于80之后基本就99%超时了。

• 并发40的成功率是100%，qps 13.54
• 并发80的成功率是0.38%，qps 15.31
• 并发60的成功率是100%，qps 13.41

结合redis监控发现，不管并发为10，50还是100，达到redis的流量一直稳定在116左右，流量并没有被打到redis。

本地启动服务，使用apache ab test压一下我们自己的接口，发现能到700多qps

将本地服务的redis配置换成业务线的redis集群，发现并发100时，qps只有13。

此时我的思路已经怀疑到了业务线的k8s网络和redis集群本身的问题上了。

4.3 第三次尝试

我在调查问题的同时，让ops测试一下redis集群是否有问题，结果ops用redis-benchmark测试发现集群没有任何问题，qps轻松上几万

所以再试下网络是否有问题，最简单的方法是直接去组件所在的pod执行下redis-benchmark，发现网络也没有任何问题

一切似乎回到了原点。

4.4 第四次尝试

经过了一天的休整，我有了新的思路，既然想证明是redis集群的问题，那就使用之前压测用过的redis集群试下，结果令人惊喜，换了个集群之后果然qps可以上1000了。虽然还没有找到根本原因，但是我已经可以将问题返给业务线了。业务线得知结果后也在积极调查问题。但是心里却一直放不下，为什么两个集群看起来都没什么问题，一个可以另一个就不行呢？

4.5 第五次尝试

我想到了redis客户端是不是不支持业务线的集群配置方式，查了下代码发现目前使用的是go-redis v6，还是项目3年之前启动时使用的版本，最新的版本已经到v8了，是否是版本不匹配的原因呢？

所以我用两个版本分别写了连接redis集群，并获取key的测试代码，果然不出所料，v6的代码使用业务线的redis集群并发获取key，一次需要3000ms级别，而v8的代码只需要10ms级别，换回以前压测过的redis集群，v6和v8就都一样快了。

最后确认下业务线的redis版本为redis6，之前我们自己压测时使用的是redis5，说明go-redis v6 还可以适配redis5集群，但是不能适配redis6集群。

最后业务线那边将redis集群换成单机模式发现也是可以的。

5、解决方案

最终的解决方案有三种：

1、将redis集群降到redis5

2、将我们引用的go-redis升级到v8

3、单独给我们的组件搭一个单机redis

方案1的缺点是有可能会影响其他使用redis集群的组件

方案2的缺点是需要改我们组件的代码，因为v6到v8有不兼容升级，改代码之后需要回归测试

方案3的缺点是业务方不能对redis进行统一维护

6、刨根问底

只知其然不知其所以然，我们还是没有找到go-redis v6不能兼容redis v6集群的根本原因。

我编写测试代码连接redis v6的集群环境。

package main
import (
    "fmt"
    "net/http"
    _ "net/http/pprof"
    "sync"
    "time"

    "github.com/go-redis/redis"
)
func main() {
   
  go func() {
        http.ListenAndServe("0.0.0.0:18005", nil)
    }() 
    n := 100
    c := redis.NewUniversalClient(redisUniversalOptionsV6())
    f := func() {
        wg := sync.WaitGroup{}
        wg.Add(n)
        for i := 0; i < n; i++ {
            go func() {
                start := time.Now()
                val := c.Get("3").String()
                fmt.Printf("span=%dms,res:%v\n", time.Since(start).Milliseconds(), val)
            }()
            wg.Done()
        }
        wg.Wait()

    }
    for {
        f()
        time.Sleep(1 * time.Second)
    }
}
func redisUniversalOptionsV6() *redis.UniversalOptions {
    return &redis.UniversalOptions{
  
        Addrs:        []string{"xxx:16381"},
        Password:     "xxx",
        DialTimeout:  10 * time.Second,
        ReadTimeout:  30 * time.Second,
        WriteTimeout: 30 * time.Second,

        MaxRedirects: 8,

        PoolSize:           10,
        PoolTimeout:        30 * time.Second,
        IdleTimeout:        time.Minute,
        IdleCheckFrequency: 100 * time.Millisecond,
    }
}

go mod 里将 go-redis包替换为本地包

replace github.com/go-redis/redis => ../github.com/go-redis/redis

将本地包切换为v6.15.9

cd ../github.com/go-redis/redis git checkout v6.15.9

查看pprof发现没有什么特别异常的地方，只是觉得getConn不应该耗时这么多

所以到代码中查看defaultProcess方法，发现有个方法是通过command命令获取Slot和Node信息

获取command info

这里redis客户端有一个优化，就是将拿到的command info放缓存中，从而不必每次都向服务端发送command命令

这里使用了go-redis自己封装的once.Do，经过日志分析，发现时间大部分消耗在这里

里面实际执行了传入的函数，耗时并不在传入的函数，而是上锁耗时最严重

既然加锁严重耗时，那么一定是测试代码的并发都走到了这里，导致冲突严重

如果正常情况下通过o.done变量的作用下，Once.Do只会执行一次，所以这里一定是出现了异常，能出现异常的地方只能是err不为nil，打印下err发现是这个错误

我使用redis-cli分别连接redis5集群和redis6集群并分别执行command命令，发现确实redis5集群返回的切片是6个元素，而redis6集群返回的切片是7个元素

接下来就好办了，首先找到注册进来的函数即c.fn，是创建cmdsInfoCache对象时传入的

找到调用newCmdsInfoCache的地方

发现传入的是ClusterClient的cmdsInfo方法，它的主要工作是在所有redis实例地址中循环调用command命令，收集command信息

继续追下去发现就是在解析command结果的时候报的错

最终发现slice长度如果不等于6就会报错。

查看最新的代码已经兼容redis6和redis7集群了，说明官方已经修复了这个问题，但是需要使用go-redis v8版本

7、总结

这个问题改起来非常容易，但是调查时会让人一时蒙住，一般情况下并不会遇到类似问题，但是由此总结出来的调查思路很重要。在排查问题时，需要尽可能的发现可能的故障环节，然后依次排除，结合替换和实验两大方法就能够更容易的定位到问题的根本原因。

其实官方在2020年6月就修改了这个bug，我们的项目是在2019年引用的go-redis之后就再没升级过，直到遇到这个问题才发现go-redis的这个bug，由此总结出的另一个经验是，定期升级依赖包还是有必要的，特别是一些常用中间件有了大版本升级，否则极有可能踩到不必要的坑里。