redis：慢查询日志

什么是 SLOWLOG

慢查询日志

所谓慢查询日志就是系统在命令执行前后计算每条命令执行的时间,，当超过阈值，就将这条命令的相关信息(比如：发生时间、耗时、命令的详细信息)记录下来，redis也提供了类似的功能

对于redis

如下图所示，redis客户端执行一条命令分为四个部分

• 发送命令
• 命令排队
• 命令执行
• 返回结果

慢查询只统计步骤3的时候，所以没有慢查询并不代表客户端没有超时问题

slowlog

• Slow log 是 Redis 用来记录查询执行时间的日志系统。
• 查询执行时间指的是不包括像客户端响应(talking)、发送回复等 IO 操作，而单单是执行一个查询命令所耗费的时间。
• 另外，slow log 保存在内存里面，读写速度非常快，因此你可以放心地使用它，不必担心因为开启 slow log 而损害 Redis 的速度。

慢查询的两个配置参数

配置

对于慢查询功能，需要明确两件事

• 预设阈值怎么设置
• 慢查询寄存保存在哪里（保存在内存里面，无需设置）

Redis提供了slowlog-log-slower-than和slowlog-max-len配置来解决这两个问题。

• slowlog-log-slower-than：
  • 预设的阈值，它的单位是微秒(1秒=1000毫秒=1000 000微秒)，默认值时10 000
  • 假如执行了一条“很慢”的命令(例如keys *)，如果它的执行时间超过了10 000微秒，那么它将被记录在慢查询日志中
  • 如果这个值为0，那么会记录所有的命令
  • 如果这个值小于0，那么什么命令都不会记录
• slowlog-max-len：
  • 慢查询日志最多能够存储多少条，并没有说明列表存放在哪里
  • 实际上redis使用了一个列表来存储慢查询日志，slowlog-max-len就是这个列表的最大长度
  • 一个新的命令满足慢查询条件被插入到这个列表时，当查询日志列表已经出于最大长度时，最早插入的一个命令就会被从列表中移除

修改配置

在Redis中有两种修改配置的方法

• 一种是修改配置文件
• 另一种就是使用config set 命令动态修改。

例如下面使用config set 命令将slowlog-log-slower-than设置为20 000微秒，slowlog-max-len设置为1000。

    config set slowlog-log-slower-than 20000
    config set slowlog-max-len 1024
    config rewrite

如果需要将Redis将配置持久化到本地配置文件,要执行config rewrite命令.如下:

查看配置

使用 CONFIG GET 命令可以查询两个选项的当前值：

redis> CONFIG GET slowlog-log-slower-than
1) "slowlog-log-slower-than"
2) "1000"

redis> CONFIG GET slowlog-max-len
1) "slowlog-max-len"
2) "1000"

访问和管理日志

虽然慢查询日志是存放在redis内存列表中，但是redis并没有暴露这个键，而是通过一组命令来实现对慢查询日志的访问和管理。下面来看看这几个命令

查看 slow log

要查看 slow log ，可以使用 SLOWLOG GET 或者 SLOWLOG GET number 命令
-SLOWLOG GET打印所有 slow log ，最大长度取决于 slowlog-max-len 选项的值，

• 而 SLOWLOG GET number 则只打印指定数量的日志。

最新的日志会最先被打印：

# 为测试需要，将 slowlog-log-slower-than 设成了 10 微秒

redis> SLOWLOG GET
1) 1) (integer) 12                      # 唯一性(unique)的日志标识符
   2) (integer) 1324097834              # 被记录命令的执行时间点，以 UNIX 时间戳格式表示
   3) (integer) 16                      # 查询执行时间，以微秒为单位
   4) 1) "CONFIG"                       # 执行的命令，以数组的形式排列
      2) "GET"                          # 这里完整的命令是 CONFIG GET slowlog-log-slower-than
      3) "slowlog-log-slower-than"

2) 1) (integer) 11
   2) (integer) 1324097825
   3) (integer) 42
   4) 1) "CONFIG"
      2) "GET"
      3) "*"

3) 1) (integer) 10
   2) (integer) 1324097820
   3) (integer) 11
   4) 1) "CONFIG"
      2) "GET"
      3) "slowlog-log-slower-than"

# ...

• 日志的唯一 id 只有在 Redis 服务器重启的时候才会重置，这样可以避免对日志的重复处理(比如你可能会想在每次发现新的慢查询时发邮件通知你)。
• 可以看到每个慢查询日志有4个属性组成，分别是慢查询日志的标识 id、发生时间戳、命令耗时、执行命令和参数

查看当前日志的数量

使用命令 SLOWLOG LEN 可以查看当前日志的数量。

请注意这个值和 slower-max-len 的区别，它们一个是当前日志的数量，一个是允许记录的最大日志的数量。

redis> SLOWLOG LEN
(integer) 14

清空日志

使用命令 SLOWLOG RESET 可以清空 slow log

redis> SLOWLOG LEN
(integer) 14

redis> SLOWLOG RESET
OK

redis> SLOWLOG LEN
(integer) 0

建议

慢查询功能可以有效地帮助我们找到redis可能存在的瓶颈，但是在实际使用过程中还需要注意如下几点：

• slowlog-max-len配置建议：
  • 线上建议加大慢查询列表，记录慢查询时Redis会对常命令做阶段操作，并不会占用大量内存。
  • 慢查询列表可以减缓查询被剔除的可能，例如线上可设置为1000以上。
• slowlog-log-slower-than配置建议：
  • 默认值超过10毫秒判定为慢查询，需要根据Redis的并发量对该值进行调整。
  • 由于Redis采用单线程响应命令，对于高流量的场景，如果命令执行时间在1毫秒以上，那么Redis最多可支撑QPS不到1000。
  • 因此对于高QPS场景的Redis建议设置为1毫秒。
• 慢查询只记录命令查询时间，并不包括命令排队和网络传输时间。
  • 为此客户端执行命令的时间会大于实际执行时间
  • 因为命令排队机制，慢查询会导致其他命令级联阻塞
  • 因此当客户端出现请求超时，需要检测该时间点是否有对应的慢查询，从而分析出是否为慢查询
• 由于慢查询是一个先入先出队列，也就是说如果慢查询比较多的情况下，可能会丢失部分慢查询命令，为了防止这种情况的发生，可以定期执行slow get命令将慢查询持久化到其他存储中，然后可以定制可视化界面进行查询