上一篇【第60篇】二进制位数组——Redis的BitMap有多好用下一篇【第62篇】# Redis监视器——MONITOR命令的原理与实战程序员A“线上Redis突然变慢了怎么办”程序员B“慌什么查慢查询日志啊。”程序员A“慢查询日志是啥”程序员B“……你被优化了。”在Redis的使用过程中性能问题是最让人头疼的。你可能会遇到响应时间突然飙升、QPS下降、甚至超时报警等情况。面对这些问题盲人摸象式地排查是行不通的你需要一个记录仪来帮你找出罪魁祸首——这就是Redis的慢查询日志Slow Log。一、什么是慢查询日志慢查询日志顾名思义就是记录那些跑得慢的命令。当一个命令的执行时间超过你设定的阈值时Redis就会把这个命令记录下来。这里有一个关键点要强调慢查询日志记录的是命令执行时间而不是整个请求的网络往返时间。也就是说从客户端发送命令到Redis收到命令这段时间是不算在内的只有Redis真正开始执行到执行完毕的时间才会被记录。客户端 Redis服务器 | | |--- 发送 KEYS * 命令 -----------------| 网络传输时间不计入 | | 排队等待时间不计入 | | 执行计时开始 | | 遍历所有Key... (500万条记录) | | 执行计时结束 |-- 返回 500万个Key --------------------| | | 总耗时3000ms | 执行耗时2900ms被记录为慢查询所以如果你的慢查询日志里空空如也但客户端还是觉得慢那问题可能出在网络延迟、客户端处理逻辑、或者Redis在排队被其他慢命令阻塞。二、慢查询日志的两个核心配置Redis提供了两个配置项来控制慢查询日志的行为2.1 slowlog-log-slower-than执行时间阈值这个配置项设定了多慢才算慢的门槛单位是微秒microsecond1秒 1,000,000微秒。# redis.conf 配置 slowlog-log-slower-than 10000 # 默认值10000微秒 10毫秒几个典型值配置值含义10000默认执行时间超过10ms才记录0记录所有命令调试时用生产慎用-1关闭慢查询日志不推荐1000执行时间超过1ms才记录较严格500000执行时间超过500ms才记录较宽松生产环境建议设置为10001ms左右这样能捕获大部分有问题的命令同时不会产生太多噪音。2.2 slowlog-max-len日志最大条数Redis的慢查询日志保存在内存中一个固定长度的队列所以需要限制最大条数。# redis.conf 配置 slowlog-max-len 128 # 默认值最多保留128条工作原理当慢查询日志条数达到上限时Redis会采用**FIFO先进先出**策略淘汰最早的那条记录。这意味着如果你设置得太小新产生的慢查询可能会把旧的挤掉导致你来不及分析。内存中的慢查询日志队列 慢查询日志固定长度队列 ┌──────────────────────────────────────────────────┐ │ [最新] id:156 SLOWLOG GET 2.3ms │ │ id:155 KEYS * 150ms │ │ id:154 LRANGE bigkey 0 -1 80ms │ │ id:153 HGETALL big-hash 45ms │ │ ... │ │ [最早] id:29 FLUSHALL 3ms │ └──────────────────────────────────────────────────┘ ↑ 新记录从头部插入满了就从尾部删除最旧的生产环境建议设置为500或更高确保有足够的历史记录用于分析。2.3 动态修改配置好消息是这两个参数都支持运行时动态修改无需重启Redis# 修改慢查询阈值为1ms127.0.0.1:6379CONFIG SET slowlog-log-slower-than1000OK# 修改日志最大条数为500127.0.0.1:6379CONFIG SET slowlog-max-len500OK# 查看当前配置127.0.0.1:6379CONFIG GET slowlog-log-slower-than1)slowlog-log-slower-than2)1000当然记得把配置也写到redis.conf里否则重启后就失效了。三、慢查询日志的存储结构慢查询日志存储在Redis服务器的内存中不写入磁盘。这意味着Redis重启后慢查询日志会清空慢查询日志本身几乎不占额外磁盘空间查询慢查询日志非常快零I/O开销每条慢查询日志记录包含4个字段┌─────────────────────────────────────────────────────────────┐ │ 一条 Slowlog 记录的结构 │ ├──────────────┬──────────────────────────────────────────────┤ │ 字段 │ 说明 │ ├──────────────┼──────────────────────────────────────────────┤ │ id │ 日志的唯一标识ID自增从1开始 │ ├──────────────┼──────────────────────────────────────────────┤ │ timestamp │ 命令执行时的UNIX时间戳秒级 │ ├──────────────┼──────────────────────────────────────────────┤ │ duration │ 命令执行耗时单位微秒 │ ├──────────────┼──────────────────────────────────────────────┤ │ args │ 命令及其参数以数组形式保存 │ └──────────────┴──────────────────────────────────────────────┘实际输出示例127.0.0.1:6379SLOWLOG GET11)1)(integer)156# 日志ID2)(integer)1716278400# 时间戳3)(integer)2300# 执行耗时2300微秒 2.3毫秒4)1)LRANGE# 命令2)user:messages:10086# 参数13)0# 参数24)-1# 参数3注意一个细节Redis会对命令参数进行脱敏处理。比如运行AUTH password命令时密码会被替换成******防止敏感信息泄露在日志中。四、慢查询日志的三大操作命令4.1 SLOWLOG GET获取慢查询日志# 获取所有慢查询日志最多显示slowlog-max-len条127.0.0.1:6379SLOWLOG GET# 获取最近10条127.0.0.1:6379SLOWLOG GET10输出格式是嵌套数组不太方便阅读。实际使用中建议配合脚本或工具进行格式化展示。4.2 SLOWLOG LEN查看日志数量127.0.0.1:6379SLOWLOG LEN(integer)42这个命令适合用来做监控告警——当慢查询日志数量快速增长时说明系统可能出了问题。4.3 SLOWLOG RESET清空慢查询日志127.0.0.1:6379SLOWLOG RESET OK踩坑提示SLOWLOG RESET 会清空所有慢查询日志操作前请确保你已经分析完或导出了需要的数据。建议在执行前先用 SLOWLOG GET 导出备份。五、生产实践慢查询分析流程知道了命令怎么用关键是怎么在实际生产中运用。这里给你一套系统的慢查询分析流程┌─────────────────────────────────────────────────────────────────┐ │ 慢查询分析流程 │ │ │ │ ┌──────────┐ ┌──────────┐ ┌──────────┐ ┌──────────┐ │ │ │ 1.设置 │───│ 2.定期 │───│ 3.统计 │───│ 4.针对性 │ │ │ │ 合理阈值 │ │ 采集日志 │ │ 分析归因 │ │ 优化解决 │ │ │ └──────────┘ └──────────┘ └──────────┘ └──────────┘ │ │ │ │ │ │ │ ┌──────────┐ │ │ │ └─────────────│ 5.持续 │─────────────────────┘ │ │ │ 监控验证 │ │ │ └──────────┘ │ └─────────────────────────────────────────────────────────────────┘5.1 设置合理的阈值# 步骤1设置1ms阈值捕获更多信息CONFIG SET slowlog-log-slower-than1000CONFIG SET slowlog-max-len10005.2 定期采集和分析写一个简单的脚本定期采集慢查询日志统计分析# slowlog_analyzer.py - 简单的慢查询分析脚本importredisfromcollectionsimportCounter rredis.Redis(hostlocalhost,port6379)slowlogsr.slowlog_get(200)# 获取最近200条# 统计各命令的慢查询次数cmd_counterCounter()forloginslowlogs:cmdlog[command].split()[0]# 取命令名cmd_counter[cmd]1# 输出Top 10慢查询命令print( Top 10 慢查询命令 )forcmd,countincmd_counter.most_common(10):print(f{cmd}:{count}次)# 找出执行时间最长的10条sorted_logssorted(slowlogs,keylambdax:x[duration],reverseTrue)print(\n 执行时间最长的10条 )forloginsorted_logs[:10]:duration_mslog[duration]/1000print(f [{duration_ms:.2f}ms]{log[command][:80]})5.3 常见慢查询命令及优化建议这是实战中最有价值的部分——遇到慢查询了怎么优化慢查询命令慢的原因优化方案KEYS *O(N) 全量扫描所有Key用SCAN替代增量式遍历LRANGE key 0 -1一次性取出整个List用LLEN判断长度 分批LRANGEHGETALL key大Hash取出所有字段用HSCAN增量获取 或只取需要的字段SMEMBERS key大Set取出所有成员用SSCAN增量获取ZRANGE key 0 -1大ZSet取出所有成员用ZSCAN或限定范围FLUSHALL清空整个数据库用UNLINK或DEL删除特定KeySORT key对大数据量排序预计算/在业务层排序/限制排序范围SUNION多个大Set多个大Set取并集拆分操作/控制Set大小踩坑提示KEYS *是慢查询排行榜的常客。生产环境严禁使用KEYS改用SCAN命令。SCAN是游标式的迭代器不会阻塞Redis。SCAN 替代 KEYS 的示例# 危险生产环境不要用KEYS user:*# 安全用SCAN替代SCAN0MATCH user:* COUNT100# 返回: 1) 12345 (下次迭代用的游标)# 2) 1) user:1001# 2) user:1002# ...六、搭配 INFO commandstats 深入分析慢查询日志能帮你找到最慢的命令但它有一个局限只记录超过阈值的命令。有些命令执行不算慢比如每次0.5ms但调用极其频繁每秒10000次累积起来的影响也是巨大的。这时候INFO commandstats就派上用场了127.0.0.1:6379INFO commandstats# Commandstatscmdstat_get:calls15234567,usec7654321,usec_per_call0.50cmdstat_set:calls8923456,usec3456789,usec_per_call0.39cmdstat_lrange:calls345678,usec2345678,usec_per_call6.79cmdstat_hgetall:calls56789,usec1234567,usec_per_call21.74每个命令的统计信息包含三个关键字段calls调用次数usec总耗时微秒usec_per_call平均每次调用耗时通过INFO commandstats你可以发现一些慢查询日志遗漏的问题高频低延迟命令单次快但总量大如GET/SET低频高延迟命令频率不高但单次很慢如HGETALL# 提取有用的统计信息127.0.0.1:6379INFO commandstats|grep-Ecmdstat_|usec_per_callcmdstat_get:calls15234567,usec7654321,usec_per_call0.50cmdstat_hgetall:calls56789,usec1234567,usec_per_call21.74# 平均21.74ms需优化七、慢查询与 LATENCY HISTORY 的配合除了慢查询日志和INFO commandstatsRedis还提供了LATENCY系列命令来监控延迟# 查看最近的延迟事件127.0.0.1:6379LATENCY LATEST# 查看延迟的历史统计每秒采样一次127.0.0.1:6379LATENCY HISTORYcommand1)1)(integer)17162783002)(integer)5002)1)(integer)17162783012)(integer)12003)1)(integer)17162783022)(integer)300# 查看延迟图表终端输出ASCII柱状图127.0.0.1:6379LATENCY DOCTORLATENCY DOCTOR会给出一份诊断报告自动分析延迟原因并给出建议就像Redis自带的老中医。三者配合使用的最佳实践┌──────────────────────┐ │ 慢查询日志 (SLOWLOG) │─── 找出最慢的单次命令 └──────────────────────┘ ┌──────────────────────┐ │ INFO commandstats │─── 发现高频但累积慢的命令 └──────────────────────┘ ┌──────────────────────┐ │ LATENCY 系列 │─── 监控整体延迟趋势和异常 └──────────────────────┘ 三者配合 → 全面掌握Redis性能状况小结慢查询日志是Redis性能调优的第一站。通过合理配置slowlog-log-slower-than和slowlog-max-len结合SLOWLOG GET/LEN/RESET三大命令再搭配INFO commandstats和LATENCY系列你就能构建一套完整的Redis性能监控体系。记住几个关键点阈值建议设为10001ms日志条数建议500慢查询日志存在内存中重启会丢失不在慢查询日志里不代表没问题还要看INFO commandstats遇到KEYS *、LRANGE 0 -1、HGETALL要果断优化上一篇【第60篇】二进制位数组——Redis的BitMap有多好用下一篇【第62篇】# Redis监视器——MONITOR命令的原理与实战
【Redis从入门到精通】第61篇：慢查询日志——找出Redis性能瓶颈的利器
上一篇【第60篇】二进制位数组——Redis的BitMap有多好用下一篇【第62篇】# Redis监视器——MONITOR命令的原理与实战程序员A“线上Redis突然变慢了怎么办”程序员B“慌什么查慢查询日志啊。”程序员A“慢查询日志是啥”程序员B“……你被优化了。”在Redis的使用过程中性能问题是最让人头疼的。你可能会遇到响应时间突然飙升、QPS下降、甚至超时报警等情况。面对这些问题盲人摸象式地排查是行不通的你需要一个记录仪来帮你找出罪魁祸首——这就是Redis的慢查询日志Slow Log。一、什么是慢查询日志慢查询日志顾名思义就是记录那些跑得慢的命令。当一个命令的执行时间超过你设定的阈值时Redis就会把这个命令记录下来。这里有一个关键点要强调慢查询日志记录的是命令执行时间而不是整个请求的网络往返时间。也就是说从客户端发送命令到Redis收到命令这段时间是不算在内的只有Redis真正开始执行到执行完毕的时间才会被记录。客户端 Redis服务器 | | |--- 发送 KEYS * 命令 -----------------| 网络传输时间不计入 | | 排队等待时间不计入 | | 执行计时开始 | | 遍历所有Key... (500万条记录) | | 执行计时结束 |-- 返回 500万个Key --------------------| | | 总耗时3000ms | 执行耗时2900ms被记录为慢查询所以如果你的慢查询日志里空空如也但客户端还是觉得慢那问题可能出在网络延迟、客户端处理逻辑、或者Redis在排队被其他慢命令阻塞。二、慢查询日志的两个核心配置Redis提供了两个配置项来控制慢查询日志的行为2.1 slowlog-log-slower-than执行时间阈值这个配置项设定了多慢才算慢的门槛单位是微秒microsecond1秒 1,000,000微秒。# redis.conf 配置 slowlog-log-slower-than 10000 # 默认值10000微秒 10毫秒几个典型值配置值含义10000默认执行时间超过10ms才记录0记录所有命令调试时用生产慎用-1关闭慢查询日志不推荐1000执行时间超过1ms才记录较严格500000执行时间超过500ms才记录较宽松生产环境建议设置为10001ms左右这样能捕获大部分有问题的命令同时不会产生太多噪音。2.2 slowlog-max-len日志最大条数Redis的慢查询日志保存在内存中一个固定长度的队列所以需要限制最大条数。# redis.conf 配置 slowlog-max-len 128 # 默认值最多保留128条工作原理当慢查询日志条数达到上限时Redis会采用**FIFO先进先出**策略淘汰最早的那条记录。这意味着如果你设置得太小新产生的慢查询可能会把旧的挤掉导致你来不及分析。内存中的慢查询日志队列 慢查询日志固定长度队列 ┌──────────────────────────────────────────────────┐ │ [最新] id:156 SLOWLOG GET 2.3ms │ │ id:155 KEYS * 150ms │ │ id:154 LRANGE bigkey 0 -1 80ms │ │ id:153 HGETALL big-hash 45ms │ │ ... │ │ [最早] id:29 FLUSHALL 3ms │ └──────────────────────────────────────────────────┘ ↑ 新记录从头部插入满了就从尾部删除最旧的生产环境建议设置为500或更高确保有足够的历史记录用于分析。2.3 动态修改配置好消息是这两个参数都支持运行时动态修改无需重启Redis# 修改慢查询阈值为1ms127.0.0.1:6379CONFIG SET slowlog-log-slower-than1000OK# 修改日志最大条数为500127.0.0.1:6379CONFIG SET slowlog-max-len500OK# 查看当前配置127.0.0.1:6379CONFIG GET slowlog-log-slower-than1)slowlog-log-slower-than2)1000当然记得把配置也写到redis.conf里否则重启后就失效了。三、慢查询日志的存储结构慢查询日志存储在Redis服务器的内存中不写入磁盘。这意味着Redis重启后慢查询日志会清空慢查询日志本身几乎不占额外磁盘空间查询慢查询日志非常快零I/O开销每条慢查询日志记录包含4个字段┌─────────────────────────────────────────────────────────────┐ │ 一条 Slowlog 记录的结构 │ ├──────────────┬──────────────────────────────────────────────┤ │ 字段 │ 说明 │ ├──────────────┼──────────────────────────────────────────────┤ │ id │ 日志的唯一标识ID自增从1开始 │ ├──────────────┼──────────────────────────────────────────────┤ │ timestamp │ 命令执行时的UNIX时间戳秒级 │ ├──────────────┼──────────────────────────────────────────────┤ │ duration │ 命令执行耗时单位微秒 │ ├──────────────┼──────────────────────────────────────────────┤ │ args │ 命令及其参数以数组形式保存 │ └──────────────┴──────────────────────────────────────────────┘实际输出示例127.0.0.1:6379SLOWLOG GET11)1)(integer)156# 日志ID2)(integer)1716278400# 时间戳3)(integer)2300# 执行耗时2300微秒 2.3毫秒4)1)LRANGE# 命令2)user:messages:10086# 参数13)0# 参数24)-1# 参数3注意一个细节Redis会对命令参数进行脱敏处理。比如运行AUTH password命令时密码会被替换成******防止敏感信息泄露在日志中。四、慢查询日志的三大操作命令4.1 SLOWLOG GET获取慢查询日志# 获取所有慢查询日志最多显示slowlog-max-len条127.0.0.1:6379SLOWLOG GET# 获取最近10条127.0.0.1:6379SLOWLOG GET10输出格式是嵌套数组不太方便阅读。实际使用中建议配合脚本或工具进行格式化展示。4.2 SLOWLOG LEN查看日志数量127.0.0.1:6379SLOWLOG LEN(integer)42这个命令适合用来做监控告警——当慢查询日志数量快速增长时说明系统可能出了问题。4.3 SLOWLOG RESET清空慢查询日志127.0.0.1:6379SLOWLOG RESET OK踩坑提示SLOWLOG RESET 会清空所有慢查询日志操作前请确保你已经分析完或导出了需要的数据。建议在执行前先用 SLOWLOG GET 导出备份。五、生产实践慢查询分析流程知道了命令怎么用关键是怎么在实际生产中运用。这里给你一套系统的慢查询分析流程┌─────────────────────────────────────────────────────────────────┐ │ 慢查询分析流程 │ │ │ │ ┌──────────┐ ┌──────────┐ ┌──────────┐ ┌──────────┐ │ │ │ 1.设置 │───│ 2.定期 │───│ 3.统计 │───│ 4.针对性 │ │ │ │ 合理阈值 │ │ 采集日志 │ │ 分析归因 │ │ 优化解决 │ │ │ └──────────┘ └──────────┘ └──────────┘ └──────────┘ │ │ │ │ │ │ │ ┌──────────┐ │ │ │ └─────────────│ 5.持续 │─────────────────────┘ │ │ │ 监控验证 │ │ │ └──────────┘ │ └─────────────────────────────────────────────────────────────────┘5.1 设置合理的阈值# 步骤1设置1ms阈值捕获更多信息CONFIG SET slowlog-log-slower-than1000CONFIG SET slowlog-max-len10005.2 定期采集和分析写一个简单的脚本定期采集慢查询日志统计分析# slowlog_analyzer.py - 简单的慢查询分析脚本importredisfromcollectionsimportCounter rredis.Redis(hostlocalhost,port6379)slowlogsr.slowlog_get(200)# 获取最近200条# 统计各命令的慢查询次数cmd_counterCounter()forloginslowlogs:cmdlog[command].split()[0]# 取命令名cmd_counter[cmd]1# 输出Top 10慢查询命令print( Top 10 慢查询命令 )forcmd,countincmd_counter.most_common(10):print(f{cmd}:{count}次)# 找出执行时间最长的10条sorted_logssorted(slowlogs,keylambdax:x[duration],reverseTrue)print(\n 执行时间最长的10条 )forloginsorted_logs[:10]:duration_mslog[duration]/1000print(f [{duration_ms:.2f}ms]{log[command][:80]})5.3 常见慢查询命令及优化建议这是实战中最有价值的部分——遇到慢查询了怎么优化慢查询命令慢的原因优化方案KEYS *O(N) 全量扫描所有Key用SCAN替代增量式遍历LRANGE key 0 -1一次性取出整个List用LLEN判断长度 分批LRANGEHGETALL key大Hash取出所有字段用HSCAN增量获取 或只取需要的字段SMEMBERS key大Set取出所有成员用SSCAN增量获取ZRANGE key 0 -1大ZSet取出所有成员用ZSCAN或限定范围FLUSHALL清空整个数据库用UNLINK或DEL删除特定KeySORT key对大数据量排序预计算/在业务层排序/限制排序范围SUNION多个大Set多个大Set取并集拆分操作/控制Set大小踩坑提示KEYS *是慢查询排行榜的常客。生产环境严禁使用KEYS改用SCAN命令。SCAN是游标式的迭代器不会阻塞Redis。SCAN 替代 KEYS 的示例# 危险生产环境不要用KEYS user:*# 安全用SCAN替代SCAN0MATCH user:* COUNT100# 返回: 1) 12345 (下次迭代用的游标)# 2) 1) user:1001# 2) user:1002# ...六、搭配 INFO commandstats 深入分析慢查询日志能帮你找到最慢的命令但它有一个局限只记录超过阈值的命令。有些命令执行不算慢比如每次0.5ms但调用极其频繁每秒10000次累积起来的影响也是巨大的。这时候INFO commandstats就派上用场了127.0.0.1:6379INFO commandstats# Commandstatscmdstat_get:calls15234567,usec7654321,usec_per_call0.50cmdstat_set:calls8923456,usec3456789,usec_per_call0.39cmdstat_lrange:calls345678,usec2345678,usec_per_call6.79cmdstat_hgetall:calls56789,usec1234567,usec_per_call21.74每个命令的统计信息包含三个关键字段calls调用次数usec总耗时微秒usec_per_call平均每次调用耗时通过INFO commandstats你可以发现一些慢查询日志遗漏的问题高频低延迟命令单次快但总量大如GET/SET低频高延迟命令频率不高但单次很慢如HGETALL# 提取有用的统计信息127.0.0.1:6379INFO commandstats|grep-Ecmdstat_|usec_per_callcmdstat_get:calls15234567,usec7654321,usec_per_call0.50cmdstat_hgetall:calls56789,usec1234567,usec_per_call21.74# 平均21.74ms需优化七、慢查询与 LATENCY HISTORY 的配合除了慢查询日志和INFO commandstatsRedis还提供了LATENCY系列命令来监控延迟# 查看最近的延迟事件127.0.0.1:6379LATENCY LATEST# 查看延迟的历史统计每秒采样一次127.0.0.1:6379LATENCY HISTORYcommand1)1)(integer)17162783002)(integer)5002)1)(integer)17162783012)(integer)12003)1)(integer)17162783022)(integer)300# 查看延迟图表终端输出ASCII柱状图127.0.0.1:6379LATENCY DOCTORLATENCY DOCTOR会给出一份诊断报告自动分析延迟原因并给出建议就像Redis自带的老中医。三者配合使用的最佳实践┌──────────────────────┐ │ 慢查询日志 (SLOWLOG) │─── 找出最慢的单次命令 └──────────────────────┘ ┌──────────────────────┐ │ INFO commandstats │─── 发现高频但累积慢的命令 └──────────────────────┘ ┌──────────────────────┐ │ LATENCY 系列 │─── 监控整体延迟趋势和异常 └──────────────────────┘ 三者配合 → 全面掌握Redis性能状况小结慢查询日志是Redis性能调优的第一站。通过合理配置slowlog-log-slower-than和slowlog-max-len结合SLOWLOG GET/LEN/RESET三大命令再搭配INFO commandstats和LATENCY系列你就能构建一套完整的Redis性能监控体系。记住几个关键点阈值建议设为10001ms日志条数建议500慢查询日志存在内存中重启会丢失不在慢查询日志里不代表没问题还要看INFO commandstats遇到KEYS *、LRANGE 0 -1、HGETALL要果断优化上一篇【第60篇】二进制位数组——Redis的BitMap有多好用下一篇【第62篇】# Redis监视器——MONITOR命令的原理与实战
