京公网安备11010502063487号SLOWLOG 是排查 Redis 延迟的第一个工具,但它记录什么、不记录什么,很多人并不清楚。这篇用一个 50 万 key 的实例把它的边界逐条验证:阈值、队列长度、参数截断,以及最重要的一条——它不含排队时间。
SLOWLOG LEN = 2 id=1 时间戳=1790706012 耗时=23198 µs 命令=['KEYS', 'k:1*'] 客户端=127.0.0.1:58044 名字='' id=0 时间戳=1790706012 耗时=60023 µs 命令=['DEBUG', 'SLEEP', '0.05'] 客户端=127.0.0.1:58044 名字=''
超过阈值的 KEYS(约 21 ms)和 DEBUG SLEEP 0.05(约 50 ms)被记录;SORT nosuch、SET 很快,没有记录。
SLOWLOG LEN = 5;id 依次为 [9, 8, 7, 6, 5](id 单调递增,最旧的被挤掉了)
slowlog-max-len 5:超过 5 条后最旧的被挤掉,id 继续递增。生产上要把长度设得够大,或者定期用脚本把慢日志取走。
阈值 0 之后 PING、GET 各执行一次: [['GET', 'fast'], ['PING'], ['CONFIG', 'SET', 'slowlog-log-slower-than', '0']] (最新在前;第三条是把阈值改成 0 的 CONFIG SET 自己,因为改完之后它才执行完) 阈值 -1 之后 DEBUG SLEEP 0.05:SLOWLOG LEN = 0
0 = 记录所有命令;-1 = 关闭。
MSET 80 个参数、value 各 300 字节 → 记录下来的参数个数 32;第 2 个参数被截成 148 字节(末尾 'vv... (172 more bytes)');最后一个参数 = '... (50 more arguments)'
记录下来的参数最多 32 个,每个参数最多 128 字节,超出部分用「... (N more arguments)」「... (N more bytes)」代替。
PING 客户端感受到的耗时 251 ms;SLOWLOG 里的记录: [('DEBUG', 310037)]一个连接执行 DEBUG SLEEP 0.3 占住主线程时,另一个连接的 PING 排队等了 251 ms,但慢日志里只有那条 DEBUG(310 ms)。所以慢日志回答「谁占着主线程」;要回答「客户端为什么慢」,还要看延迟监控(第 97、98 篇)和客户端侧的测量。