[zeromicro/go-zero]redis 读取缓慢

在请求中包含较为费时的操作时，例如： err = bcrypt.CompareHashAndPassword([]byte(userInfo.Password), []byte(in.Password)) 压测时redis读取缓慢： {"@timestamp":"2021-04-12T13:40:07.826+08","level":"slow","duration":"440.9ms","content":"[REDIS] slowcall on executing: get cache#BaseMember#id#17"}

猜测是不是redis连接池的问题

weisttl

要看你的redis qps能到多少

kevwan

userInfo, err := l.svcCtx.UserModel.FindOneByMobile(in.Mobile)
    switch err {
    case nil:
        err = bcrypt.CompareHashAndPassword([]byte(userInfo.Password), []byte(in.Password))
        if err != nil {
            return nil, errorIncorrectPassword
        }
        token, err:= l.GetJwtToken(userInfo.Id)
        if err != nil {
            return nil, err
        }
        return &types.UserReply{
            Uid:      userInfo.Id,
            Username: userInfo.Username,
            Mobile:   userInfo.Mobile,
            JwtToken: token,
        }, nil
    case model.ErrNotFound:
        return nil, errorUsernameUnRegister
    default:
        return nil, err
    }

上面这段代码压测的结果：

➜  test wrk -t4 -c100 -d15s -T10s --script=login.lua  --latency http://127.0.0.1:8000/auth/login
Running 15s test @ http://127.0.0.1:8000/auth/login
  4 threads and 100 connections
  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency   205.68ms  151.61ms   1.21s    78.90%
    Req/Sec   131.89     39.46   232.00     72.01%
  Latency Distribution
     50%  172.08ms
     75%  261.43ms
     90%  383.11ms
     99%  761.56ms
  7889 requests in 15.10s, 3.43MB read
Requests/sec:    522.57
Transfer/sec:    232.71KB

同时日志输出：

{"@timestamp":"2021-04-13T09:39:20.522+08","level":"slow","content":"[HTTP] 200 - /auth/login - 127.0.0.1:56497 -  - slowcall(688.2ms)","trace":"6189a75df405602b","span":"0"}
{"@timestamp":"2021-04-13T09:39:20.877+08","level":"slow","duration":"111.0ms","content":"[REDIS] slowcall on executing: get cache#BaseMember#mobile#18621637805"}
{"@timestamp":"2021-04-13T09:39:21.183+08","level":"slow","duration":"166.5ms","content":"[REDIS] slowcall on executing: get cache#BaseMember#mobile#18621637805"}
{"@timestamp":"2021-04-13T09:39:21.419+08","level":"slow","duration":"108.1ms","content":"[REDIS] slowcall on executing: get cache#BaseMember#id#20"}

当我把err = bcrypt.CompareHashAndPassword([]byte(userInfo.Password), []byte(in.Password))注释掉之后，qps就能达到10000多了

  Thread Stats   Avg      Stdev     Max   +/- Stdev
    Latency     7.45ms    3.63ms  45.13ms   71.29%
    Req/Sec     3.41k   308.77     4.08k    70.83%
  Latency Distribution
     50%    6.94ms
     75%    9.44ms
     90%   12.20ms
     99%   18.38ms
  203702 requests in 15.01s, 88.59MB read
Requests/sec:  13569.63
Transfer/sec:      5.90MB

weisttl

err = bcrypt.CompareHashAndPassword([]byte(userInfo.Password), []byte(in.Password)) 这句跟redis没有关系呀

kevwan

但是在同一请求中会导致redis读取变慢，我猜想是不是因为这句比较耗费CPU时间，导致redis连接没有及时释放，阻塞了后续redis操作？

weisttl

这个跟go-zero确实没啥关系，你自己做下profiling哈

kevwan

[zeromicro/go-zero]redis 读取缓慢

回答

相关问题