周三下午三点,钉钉群里先是订单组的同学问:“Redis 是不是抖了?”过了一分钟,用户中心组也冒出来:“我这边偶发超时。”又过了一分钟,风控组发了个表情包——一只小猫盯着屏幕流泪。
我打开监控:Redis 实例没宕机、内存没涨、CPU 也就 30%,可业务侧 Jedis/Lettuce 的超时日志像雪一样飘:Command timed out after 3 second(s)。最诡异的是——它是“隔几分钟抽一下”,抽完自己又好了。这类“间歇性、全局性”的卡顿,我的第一直觉是:有人在 Redis 这个单线程里干了一件很慢的事,所有人都得排队等他。
一、现象:不是慢,是“停摆”
先理解一个前提:Redis 命令执行是(基本上)单线程的。官方延迟文档里写得很清楚:一个请求处理得慢,其他所有客户端都要等它。所以“一条慢命令”对别的业务而言,效果等同于“Redis 整体不可用了 N 秒”。
我们当时看到的证据:
- 业务日志:多个不同业务、不同 key 的
GET/HGET同时超时(这些命令本身是 O(1),不可能慢,所以它们是“被拖累”的); - Redis 监控:
instantaneous_ops_per_sec出现周期性“凹陷”——不是流量下降,是那几秒 Redis 根本没在处理; - 网络流出流量(
net output)出现尖刺:某一刻突然输出了几百 MB,这是个很重要的线索,后面解释; - Redis 所在机器 CPU 正常,没有 swap,磁盘 IO 也正常(用
vmstat 1、iostat -xk 1排除过)。
先做一个 30 秒的小实验,判断是不是“Redis 自己停摆”,而不是网络问题:
$ redis-cli -h 10.0.0.21 -p 6379 --latency-history -i 5
min: 0, max: 1, avg: 0.19 (1314 samples) -- 5.01 seconds range
min: 0, max: 1, avg: 0.18 (1299 samples) -- 5.00 seconds range
min: 0, max: 2314, avg: 27.65 (312 samples) -- 5.01 seconds range
min: 0, max: 1, avg: 0.20 (1301 samples) -- 5.00 seconds range--latency-history 每隔 -i 秒重新统计一段(默认 15 秒),单位是毫秒。前两段最大 1ms 很健康,第三段 max 高达 2314ms,样本数从 1300 掉到 312——PING 都被卡了两秒多,说明 Redis 这两秒确实在忙别的、没空回复。至此,“单线程被某个慢操作占住”成立。
二、排查路线图
Redis 偶发整体卡顿,我的排查顺序是:先看慢命令,再看大 key,然后才怀疑持久化、fork、swap 这些系统层面的原因。
三、动手:一步步把凶手揪出来
第 1 步:SLOWLOG GET——谁在占着单线程
Redis 的慢日志会记录执行时间超过阈值的命令,阈值由 slowlog-log-slower-than 决定(单位微秒,默认 10000,即 10ms),最多保留 slowlog-max-len 条。先确认配置,再看内容:
$ redis-cli -h 10.0.0.21 config get slowlog-log-slower-than
1) "slowlog-log-slower-than"
2) "10000"
$ redis-cli -h 10.0.0.21 config get slowlog-max-len
1) "slowlog-max-len"
2) "128"
$ redis-cli -h 10.0.0.21 slowlog get 5
1) 1) (integer) 4823
2) (integer) 1730272931
3) (integer) 1874553
4) 1) "HGETALL"
2) "cart:promo:hot"
5) "10.0.2.15:52344"
6) "order-service"
2) 1) (integer) 4822
2) (integer) 1730272611
3) (integer) 2130971
4) 1) "HGETALL"
2) "cart:promo:hot"
5) "10.0.2.16:41188"
6) "order-service"
3) 1) (integer) 4821
2) (integer) 1730272301
3) (integer) 312044
4) 1) "SMEMBERS"
2) "user:tags:all"
5) "10.0.3.7:38820"
6) "profile-service"
...每条记录含 6~7 个字段(第 7 个参数总数是新版本才有的):唯一 ID、Unix 时间戳、执行耗时(微秒)、命令与参数、客户端 IP:端口、客户端名(需要 CLIENT SETNAME,所以建议客户端都配名字,这一步会直接告诉你是哪个服务)。
解读:第一条 1874553 微秒 = 1.87 秒,命令是 HGETALL cart:promo:hot;第二条 2.13 秒,还是它;间隔大约 5 分钟(时间戳 1730272611 → 1730272931 差 320 秒)——正好对应“隔几分钟抽一下”。第三条是 SMEMBERS user:tags:all,312ms,也不是善茬。
顺带说一下,SLOWLOG 记的是命令执行本身的时间,不含网络 IO。所以如果是“返回值太大、发送很慢”,SLOWLOG 可能只记到一部分,还要配合网络流量曲线看。
第 2 步:INFO commandstats——从统计上再确认一次
$ redis-cli -h 10.0.0.21 info commandstats | egrep 'hgetall|smembers|keys|get:|hget:'
cmdstat_get:calls=918273645,usec=1102394817,usec_per_call=1.20,rejected_calls=0,failed_calls=0
cmdstat_hget:calls=88123411,usec=112009231,usec_per_call=1.27,rejected_calls=0,failed_calls=0
cmdstat_hgetall:calls=48211,usec=39823310977,usec_per_call=826043.51,rejected_calls=0,failed_calls=0
cmdstat_smembers:calls=9021,usec=1204993211,usec_per_call=133572.09,rejected_calls=0,failed_calls=0看 usec_per_call:GET 平均 1.2 微秒,HGETALL 平均 826 毫秒,差了 近 70 万倍。调用次数才 4 万多,总耗时(usec)却是 GET 的 36 倍。这一行数据足以说服任何人:问题不是“请求多”,而是“少数请求太慢”。
第 3 步:redis-cli --bigkeys / --memkeys——谁家的 value 这么胖
命令本身是 O(N),慢在 N 大。N 是谁?找大 key。redis-cli --bigkeys 内部用 SCAN 遍历,不会像 KEYS * 那样阻塞服务;还可以用 -i 0.1 每 100 次 SCAN 睡 0.1 秒来降低对线上的冲击。建议在从库上执行,新版本对 cluster 从节点也支持。
$ redis-cli -h 10.0.0.22 --bigkeys -i 0.1
# Scanning the entire keyspace to find biggest keys as well as
# average sizes per key type. You can use -i 0.1 to sleep 0.1 sec
# per 100 SCAN commands (not usually needed).
[00.00%] Biggest string found so far '"session:8a3f..."' with 512 bytes
[03.11%] Biggest hash found so far '"cart:promo:hot"' with 412007 fields
[17.52%] Biggest set found so far '"user:tags:all"' with 903112 members
[41.90%] Biggest hash found so far '"cart:promo:hot"' with 2018733 fields
...
-------- summary -------
Sampled 4823017 keys in the keyspace!
Total key length in bytes is 121803321 (avg len 25.25)
Biggest hash found '"cart:promo:hot"' has 2018733 fields
Biggest set found '"user:tags:all"' has 903112 members
Biggest string found '"cfg:rules:json"' has 3145728 bytes
0 lists with 0 items (00.00% of keys, avg size 0.00)
2811003 hashs with 6871390 fields (58.29% of keys, avg size 2.44)
1930811 strings with 812340111 bytes (40.03% of keys, avg size 420.71)
...真凶现身:一个叫 cart:promo:hot 的 Hash,有 201 万个 field。它是几个月前某个“活动促销参与记录”功能建的:把所有参与用户都塞进同一个 Hash(field = 用户 ID,value = 参与信息),当时活动才几千人,谁能想到后来这个 key 会长成“胖子”。
注意 --bigkeys 衡量的是元素个数(字符串是字节数),不是占多少内存。一个 200 万个短 field 的 Hash 不一定比一个 3MB 的 String 更占内存,但对 O(N) 命令的伤害是元素个数决定的。想看内存视角,用 --memkeys:
$ redis-cli -h 10.0.0.22 --memkeys -i 0.1
...
Biggest hash found '"cart:promo:hot"' has 187436412 bytes
Biggest set found '"user:tags:all"' has 74510223 bytes
Biggest string found '"cfg:rules:json"' has 3145784 bytes然后用 MEMORY USAGE 对可疑 key 精确复核,并用 HLEN/SCARD 看元素数(这两个都是 O(1),可以放心敲):
$ redis-cli -h 10.0.0.22 memory usage cart:promo:hot samples 0
(integer) 187436472
$ redis-cli -h 10.0.0.22 hlen cart:promo:hot
(integer) 2018733
$ redis-cli -h 10.0.0.22 type cart:promo:hot
hash
$ redis-cli -h 10.0.0.22 object encoding cart:promo:hot
"hashtable"约 178 MB、201 万 field。MEMORY USAGE 对嵌套类型默认只抽样 5 个元素估算总大小,SAMPLES 0 表示全部采样,更准但对超大 key 本身也会花时间——所以在从库上敲,别在主库上对着最大的 key 玩。
第 4 步:LATENCY DOCTOR——让 Redis 自己“交代”
Redis 2.8.13 起提供延迟监控子系统。默认关闭,需要设置阈值(毫秒)才会记录:
$ redis-cli -h 10.0.0.21 config set latency-monitor-threshold 100
OK
# 等下一次卡顿后:
$ redis-cli -h 10.0.0.21 latency latest
1) 1) "command"
2) (integer) 1730273251
3) (integer) 1874
4) (integer) 2130
$ redis-cli -h 10.0.0.21 latency doctor
Dave, I have observed latency spikes in this Redis instance. You don't mind talking about it, do you Dave?
1. command: 5 latency spikes (average 1533ms, mean deviation 412ms, period 302.20 sec). Worst all time event 2130ms.
I have a few advices for you:
- Check your Slow Log to understand what are the commands you are running which are too slow to execute. Please check http://redis.io/commands/slowlog for more information.
- Deleting, expiring or evicting (because of maxmemory policy) large objects is a blocking operation. If you have very large objects that are often deleted, expired, or evicted, try to fragment those objects into multiple smaller objects.
三个信息互相印证:command 事件出现了 5 次超过阈值的延迟尖刺,平均 1533ms,周期约 302 秒——和 SLOWLOG 里 5 分钟的间隔吻合;doctor 给的建议也直指“慢命令 + 大对象”。(latency latest 的四列依次是:事件名、最近一次发生的时间戳、最近一次耗时 ms、历史最大耗时 ms。)
如果这里看到的是 fork、aof-write、expire-cycle 之类的事件,那就是另一个方向了:fork 是 RDB/AOF 重写时 fork 子进程造成的(内存越大越慢,还要关透明大页),expire-cycle 是大量 key 同一秒过期(上一篇写击穿时提过)。别一看到卡顿就认定是大 key,先让证据说话。
第 5 步:谁在调用它?
SLOWLOG 里带了客户端地址和名字,直接找到 order-service。翻代码,看到这么一段“聪明”的逻辑:
// 每次下单前,把活动参与记录整个拉回来,在内存里判断用户是否参与过
Map<String, String> all = stringRedisTemplate.opsForHash().entries("cart:promo:hot");
boolean joined = all.containsKey(String.valueOf(userId));200 万个 field 一次性拉回来,只为判断“某个用户在不在里面”。Redis 里每个 field 有 O(1) 的存在性检查(HEXISTS),根本不需要 HGETALL。而另一个 SMEMBERS user:tags:all 是画像服务每 5 分钟同步一次全量标签,同样是“拿全部再本地过滤”。
这就解释了“网络流出尖刺”:一次 HGETALL 要序列化并发送 178MB 的回复,Redis 不但要遍历 201 万个元素,还要把这么大的回复写进输出缓冲区,客户端也要吃下这些数据(顺便还给 JVM 带来一次 Young GC 压力)。
四、根因:单线程 + O(N) + 大 key = 全场陪跑
把机制讲透,有三层:
- 单线程串行:Redis 处理命令的主线程一次只执行一个命令。
HGETALL、SMEMBERS、LRANGE 0 -1、KEYS *、SORT、SUNION这类命令的复杂度是 O(N),N 越大执行越久,别人就得等。官方文档专门提醒:生产环境使用KEYS是最常见的延迟来源之一,应该改用SCAN、SSCAN、HSCAN、ZSCAN增量遍历。 - 大 key 放大 O(N):一个 field 少的 Hash 上
HGETALL只要几十微秒,随着元素涨到百万级就变成秒级。大 key 不一定马上出问题,它是一颗“随业务增长而变大”的定时炸弹。 - 删除大 key 也会卡:
DEL一个 200 万元素的 Hash 需要同步释放所有元素的内存,同样会阻塞主线程好几百毫秒到数秒;过期、淘汰(maxmemory)时删除大 key 也一样——上面 LATENCY DOCTOR 的建议里就提到了这一点。UNLINK(Redis 4.0+)只在主线程里把 key 从键空间摘掉(O(1)),真正回收内存交给后台线程。
五、止血与修复
止血:先让抽风停下来
- 立刻停掉“罪魁调用”:让 order-service 下线那段
HGETALL逻辑,或者通过配置中心把它降级为“跳过活动校验”;画像服务的全量同步任务先暂停; - 不要在主库上直接
DEL大 key!用UNLINK,让内存释放在后台线程完成; - 如果是 Redis 6+ 且需要“兜底”,可以通过 ACL 禁用危险命令,或者在 Redis 前面的代理层拦截
KEYS、FLUSHALL。
# 先看看有多大,再决定怎么删
$ redis-cli -h 10.0.0.21 hlen cart:promo:hot
(integer) 2018733
# 方案 A:整个 key 都不要了,异步删除(Redis 4.0+)
$ redis-cli -h 10.0.0.21 unlink cart:promo:hot
(integer) 1
# 方案 B:key 还要留,但想分批瘦身(避免一次性大删除)——用 HSCAN 分批删 field
$ redis-cli -h 10.0.0.21 hscan cart:promo:hot 0 count 500
1) "1048576"
2) 1) "u_100001"
2) "{\"joined\":true}"
...分批删 field 的 Java 示例(每批 500,批间小睡,避免占用主线程太久):
public void shrinkBigHash(String key) throws InterruptedException {
ScanOptions opts = ScanOptions.scanOptions().count(500).build();
try (Cursor<Map.Entry<Object, Object>> cursor = redis.opsForHash().scan(key, opts)) {
List<Object> batch = new ArrayList<>(500);
while (cursor.hasNext()) {
batch.add(cursor.next().getKey());
if (batch.size() >= 500) {
redis.opsForHash().delete(key, batch.toArray());
batch.clear();
Thread.sleep(10); // 让出主线程,别人还要用
}
}
if (!batch.isEmpty()) redis.opsForHash().delete(key, batch.toArray());
}
}根治 1:把 O(N) 命令换成 O(1)/O(logN),或增量遍历
| 危险写法 | 替代 | 说明 |
|---|---|---|
KEYS pattern | SCAN cursor MATCH pattern COUNT 100 | 增量、非阻塞,但可能返回重复 key,需要客户端去重 |
HGETALL big | HGET / HMGET / HEXISTS / HSCAN | 要判断“在不在”就用 HEXISTS,要全量遍历用 HSCAN 分批 |
SMEMBERS big | SISMEMBER / SSCAN | 判断成员关系是 O(1) |
LRANGE big 0 -1 | LRANGE big 0 99 分页 | 大 list 永远别全取 |
DEL big | UNLINK big | Redis 4.0+,后台线程回收内存;也可配 lazyfree-lazy-user-del yes 让 DEL 变异步 |
# 用 SCAN 替代 KEYS 的命令行写法
$ redis-cli -h 10.0.0.22 --scan --pattern 'cart:promo:*' -i 0.01 | head
# 用 HEXISTS 判断用户是否参与(O(1))
$ redis-cli -h 10.0.0.21 hexists cart:promo:hot u_100001
(integer) 1上面代码里那段“拉回全部再 containsKey”,改成一行:
boolean joined = Boolean.TRUE.equals(stringRedisTemplate.opsForHash().hasKey("cart:promo:hot", String.valueOf(userId)));根治 2:拆 key——把一个大 key 变成一群小 key
200 万 field 的 Hash,按用户 ID 做分桶(sharding),变成 1024 个小 Hash,每个约 2000 个 field:
// 分桶键:cart:promo:{bucket},bucket = hash(userId) % 1024
private String bucketKey(long userId) {
int bucket = (int) (Math.abs(Long.hashCode(userId)) % 1024);
return "cart:promo:" + bucket;
}
redis.opsForHash().put(bucketKey(userId), String.valueOf(userId), json);
redis.opsForHash().hasKey(bucketKey(userId), String.valueOf(userId));拆分后每次操作只落在一个小 Hash 上,HGETALL 即便误用也只是 2000 个元素(微秒级)。拆分时要注意两点:第一,迁移过程用双写 + 灰度,别一刀切;第二,Redis Cluster 下不同分桶会落到不同槽位/节点,这是好事(数据分散),但需要跨桶的 Lua/事务会受限。
另外几个“常见胖子”的拆法:
- 大 List(如消息流水):按日期/序号分段,如
msg:{uid}:{yyyyMMdd},或者干脆换成 Stream 并限长(XADD ... MAXLEN ~ 10000); - 大 Set(如用户标签全集):反过来存,从“标签 → 所有用户”改成“用户 → 自己的标签”,查询按用户走;
- 大 String(如几 MB 的 JSON 配置):压缩后存、或按模块拆成多个 key、或改成本地缓存 + 版本号轮询;
- 给大 key 设 TTL,避免无限增长——但要记得“过期删除大 key 也会阻塞”,所以最终还是要拆。
根治 3:把大 key 发现变成常规巡检
# 每周在从库上跑一次,输出存档;-i 0.1 降低压力
$ redis-cli -h 10.0.0.22 --bigkeys -i 0.1 > /data/redis-audit/bigkeys-$(date +%F).txt
# 同时打开延迟监控和慢日志,并调小慢日志阈值(单位微秒,这里 5ms)
$ redis-cli -h 10.0.0.21 config set slowlog-log-slower-than 5000
$ redis-cli -h 10.0.0.21 config set slowlog-max-len 1000
$ redis-cli -h 10.0.0.21 config set latency-monitor-threshold 50
# 让 DEL/过期/淘汰默认走后台线程回收(Redis 4.0+ 的 lazy free)
$ redis-cli -h 10.0.0.21 config set lazyfree-lazy-user-del yes
$ redis-cli -h 10.0.0.21 config set lazyfree-lazy-expire yes
$ redis-cli -h 10.0.0.21 config set lazyfree-lazy-eviction yes客户端统一 CLIENT SETNAME(Lettuce/Jedis 配置里都有 clientName),这样 SLOWLOG 里直接看到“是谁干的”,不用去翻 IP 对应哪台机器。
六、验证
$ redis-cli -h 10.0.0.21 --latency-history -i 15
min: 0, max: 1, avg: 0.17 (1350 samples) -- 15.01 seconds range
min: 0, max: 1, avg: 0.18 (1348 samples) -- 15.00 seconds range
min: 0, max: 2, avg: 0.18 (1349 samples) -- 15.00 seconds range
$ redis-cli -h 10.0.0.21 slowlog get 3
(empty array)连续观察一个小时,业务侧再没有出现“集体超时”,网络流出尖刺也消失了,SLOWLOG 是空的。
七、复盘
| 做法 | 为什么 |
|---|---|
| Redis 必须开启慢日志,阈值调到几毫秒,最大长度别用默认 128 | 单线程下“慢”就是“全局慢”,慢命令是第一嫌疑 |
客户端配置 CLIENT SETNAME | SLOWLOG 第 6 个字段直接指向责任服务 |
生产禁用 KEYS,统一用 SCAN/HSCAN/SSCAN/ZSCAN | 增量遍历不会长时间占住主线程 |
禁止 HGETALL / SMEMBERS / LRANGE 0 -1 用在会增长的集合上 | 元素数会随业务增长,今天几百明天几百万 |
删除大 key 用 UNLINK,并开启 lazyfree 系列配置 | 释放内存交后台线程,主线程只做 O(1) 摘链 |
| 设计阶段控制单 key 体积(经验值:String 几十 KB、集合元素数万级以内) | 大 key 一旦形成,拆分成本远高于设计时多想一步 |
定期在从库跑 --bigkeys / --memkeys,接入巡检告警 | 提前发现“会长胖的 key”,而不是等它出事 |
监控 usec_per_call、instantaneous_ops_per_sec 凹陷、网络出流量尖刺 | 这三条曲线组合基本就是“O(N) 命令阻塞”的指纹 |
一句话备忘:Redis 偶发整体卡顿 →
latency-history确认停摆 →SLOWLOG GET找命令 →--bigkeys / --memkeys / MEMORY USAGE找 key →UNLINK删、SCAN遍历、拆 key 降体积。
后来那个 Hash 拆完,我在代码 review 里给自己立了条规矩:看到 HGETALL 就问一句“它会长到多大”。同事说我像个只会问“您有预约吗”的前台。没办法,Redis 是单线程,任何一个人插队,队伍里的所有人都得陪着站。
参考资料
- Redis 官方文档:SLOWLOG GET——慢日志条目的字段含义、slowlog-log-slower-than 与 slowlog-max-len,以及执行时间不含网络 IO 的说明。
- Redis 官方文档:Diagnosing latency issues——单线程特性、慢命令、KEYS 的危害、fork、AOF、swap、过期周期导致延迟的完整排查清单。
- Redis 官方文档:Latency monitoring——latency-monitor-threshold 与 LATENCY LATEST/DOCTOR 等子命令、监控的事件列表。
- Redis 官方文档:redis-cli——--bigkeys、--memkeys、--scan、--latency-history 的用法与说明。
- Redis 官方文档:UNLINK——与 DEL 的区别:O(1) 摘除、后台线程回收内存。
- Redis 官方文档:MEMORY USAGE——SAMPLES 选项及估算方式。
一起聊聊