Redis设计与实现学习笔记第二十三章慢查询日志

本文链接：https://blog.youkuaiyun.com/tus00000/article/details/144123500

Redis的慢查询日志功能用于记录执行时间超过给定时长的命令请求，用户可以通过这个功能产生的日志来监视和优化查询速度。

服务器配置有两个和慢查询日志相关的选项：
1.slowlog-log-slower-than选项指定执行时间超过多少微秒的命令请求会被记录到日志上。

2.slowlog-max-len选项指定服务器最多保存多少条慢查询日志。

服务器使用先进先出方式保存多条慢查询日志，当服务器存储的慢查询日志数量等于slowlog-max-len选项的值时，服务器在添加一条新的慢查询日志前，会先将最旧的一条慢查询日志删除。

我们看一个慢查询日志功能的例子，首先用CONFIG SET命令将slowlog-log-slower-than选项的值设为0微秒，这样Redis服务器执行的任何命令都会被记录到慢查询日志中，接着将slowlog-max-len选项的值设为5，让服务器最多只保存5条慢查询日志：
在这里插入图片描述
接着，我们用客户端发送几条命令请求：

然后用SLOWLOG GET命令查看服务器保存的慢查询日志：

如果这时再执行一条SLOWLOG GET命令，那么我们将看到最旧的、ID为0的慢查询日志已经被删除，服务器的慢查询日志仍为5条：
在这里插入图片描述

23.1 慢查询记录的保存

服务器状态中包含了几个和慢查询日志功能有关的属性：

struct redisServer {
    // ...
    // 下一条慢查询日志的ID
    long long slowlog_entry_id;
    // 保存了所有慢查询日志的链表
    list *slowlog;
    // 服务器配置slowlog-log-slower-than选项的值
    long long slowlog_log_slower_than;
    // 服务器配置slowlog-max-len选项的值
    unsigned long slowlog_max_len;
    // ...
};

slowlog_entry_id属性的初始值为0，每当创建一条新的慢查询日志时，这个属性的值就会用作新日志的id值，之后程序会对这个属性的值增一。

slowlog链表保存了服务器中的所有慢查询日志，链表中的每个节点都保存了一个slowlogEntry结构，每个slowlogEntry结构代表一条慢查询日志：

typedef struct slowlogEntry {
    // 唯一标识符
    long long id;
    // 命令执行时的时间，格式为UNIX时间戳
    time_t time;
    // 执行命令消耗的时间，以微秒为单位
    long long duration;
    // 命令与命令参数
    robj **argv;
    // 命令与命令参数的数量
    int argc;
} slowlogEntry;

例如，对于以下慢查询日志来说：
在这里插入图片描述
图23-1展示的就是上图日志对应的slowlogEntry结构：

图23-2展示了服务器状态中和慢查询功能有关的属性：

上图中：
1.slowlog_entry_id的值为6，表示服务器下条慢查询日志的id将为6。

2.slowlog链表包含了id为5至1的慢查询日志，最新的5号日志排在链表的表头，这表明slowlog链表是使用插入到表头的方式来添加新日志的。

3.slowlog_log_slower_than记录了服务器配置slowlog-log-slower-than选项的值为0，这表示任何执行时间超过0微秒的命令都会被慢查询日志记录。

4.slowlog-max-len属性记录了服务器配置slowlog-max-len选项的值为5，表示服务器最多储存五条慢查询日志。

因为版面空间不足，图23-2展示的各个slowlogEntry结构都省略了argv数组。

23.2 慢查询日志的阅览和删除

我们用伪代码描述用来查看慢查询日志的SLOWLOG GET命令：

def SLOWLOG_GET(number=None):
    # 用户没有给定number参数
    # 那么打印服务器包含的全部慢查询日志
    if number is None:
        number = SLOWLOG_LEN()
    
    # 遍历服务器中的慢查询日志
    for log in redisServer.slowlog:
        if number <= 0:
            # 打印的日志数量已经足够，跳出循环
            break
        else:
            # 继续打印，将计数器的值减一
            number -= 1
        
        # 打印日志
        printLog(log)

查看日志数量的SLOWLOG LEN命令可用以下伪代码表示：

def SLOWLOG_LEN():
    # slowlog链表的长度就是慢查询日志的条目数量
    return len(redisServer.slowlog)

用于清除所有慢查询日志的SLOWLOG RESET命令可用以下伪代码表示：

def SLOWLOG_RESET():
    # 遍历服务器中的所有慢查询日志
    for log in redisServer.slowlog:
        # 删除日志
        deleteLog(log)

23.3 添加新日志

每次执行命令的之前和之后，程序都会记录微秒格式的当前UNIX时间戳，这两个时间戳之间的差就是服务器执行命令所耗费的时长，服务器会将这个时长作为参数之一传送给slowlogPushEntryIfNeeded函数，此函数会检查是否需要为这次执行的命令创建慢查询日志。以下伪代码展示了这一过程：

# 记录执行命令前的时间
before = unixtime_now_in_us()
# 执行命令
execute_command(argv, argc, client)
# 记录执行命令后的时间
after = unixtime_now_in_us()
# 检查是否需要创建新的慢查询日志
slowlogPushEntryIfNeeded(argv, argc, before-after)

slowlogPushEntryIfNeeded函数的作用：
1.检查命令的执行时长是否超过slowlog-log-slower-than选项所设置的时间，如果是，就为命令创建一个新日志，并将新日志添加到slowlog链表的表头。

2.检查慢查询日志的长度是否超过slowlog-max-len选项设置的长度，如果是，那么将多出来的日志从slowlog链表中删掉。

以下是slowlogPushEntryIfNeeded函数的实现代码：

void slowlogPushEntryIfNeeded(robj **argv, int argc, long long duration) {
    // 慢查询功能未开启，直接返回
    if (server.slowlog_log_slower_than < 0) return;
    
    // 如果执行时间超过服务器设置的上限，那么将命令添加到慢查询日志
    if (duration >= server.slowlog_log_slower_than)
        // 新日志添加到链表表头
        listAddNodeHead(server.slowlog, slowlogCreateEntry(argv, argc, duration));
    
    // 如果日志数量过多，那么进行删除
    while (listLength(server.slowlog) > server.slowlog_max_len)
        listDelNode(server.slowlog, listLast(server.slowlog));    
}

以上函数中的slowlogCreateEntry函数会根据传入的参数，创建一个新的慢查询日志，并将redisServer.slowlog_entry_id的值增1。

例如，服务器当前的慢查询日志信息如图23-2所示，如果我们执行命令设置键msg的过期时间：
在这里插入图片描述
服务器在执行完这个EXPIRE命令后，就会调用slowlogPushEntryIfNeeded函数，函数将为EXPIRE命令创建一条id为6的慢查询日志，并将这条新日志添加到slowlog链表的表头，如图23-3所示：

上图中，除了slowlog链表发生了变化外，slowlog_entry_id的值也从6变为7了。