老废物乐园

菜单

Administrator
发布于 2020-09-09 / 3584 阅读
100

Redis 大 key 删除导致线上抖动的一次复盘

#Redis#大key

凌晨三点的抖动：Redis 响应时间突然飙到 800ms

九月九号大促那天晚上我值班，凌晨三点被叫起来。监控大屏上 Redis 的 P99 响应时间从平时的 0.4ms 冲到 812ms，持续了大概 40 秒，然后自己恢复了。

应用侧的连锁反应更难看：商品详情页接口 TP99 从 45ms 涨到 3200ms，超时率 12%，Sentinel 熔断触发了一次，降级了 30 秒。

先排除：不是我的锅，但和我有关

我第一反应是热点 key 或者大促流量。查了下 QPS，凌晨三点是低谷，只有 800 QPS，平时大促峰值 12000 都扛住了。排除流量。

再看 Redis 自己的监控：

$ redis-cli -h 10.20.1.31 info stats | grep -E 'instantaneous_ops|total_commands'
instantaneous_ops_per_sec:812
total_commands_processed:482331902

$ redis-cli -h 10.20.1.31 --latency-history -i 10
min: 0, max: 812, avg: 0.42 (1621 samples) -- 10.01 seconds range

命令数正常，但延迟峰值 812ms。这种"命令数不变但延迟暴涨"的特征，基本指向单条慢命令阻塞了单线程。

于是去翻 slow log：

$ redis-cli -h 10.20.1.31 slowlog get 10
 1) 1) (integer) 8823412
    2) (integer) 1599619231
    3) (integer) 803742                     # 耗时 803 毫秒！
    4) 1) "DEL"
       2) "promo:activity:20200909:items"
    5) "10.20.1.45:51322"
    6) ""
 2) 1) (integer) 8823411
    2) (integer) 1599619198
    3) (integer) 742118                     # 742 毫秒
    4) 1) "DEL"
       2) "promo:activity:20200909:coupons"

slowlog 的默认阈值是 10000 微秒（10ms），所以只记录了超过 10ms 的。两条 DEL，803ms 和 742ms，正好对应监控上那两个尖刺。

promo:activity:20200909:items 这个 key 是我们大促活动的商品列表缓存，我认得它。

大 key 到底有多大

用 MEMORY USAGE 看一下（Redis 4.0 之后有这个命令）：

$ redis-cli -h 10.20.1.31 memory usage promo:activity:20200909:coupons
(integer) 1342177280

1.25GB。 这是一个 list，里面塞了本次大促发放的所有优惠券码，180 万个元素。

$ redis-cli -h 10.20.1.31 llen promo:activity:20200909:coupons
(integer) 1803421

$ redis-cli -h 10.20.1.31 object encoding promo:activity:20200909:coupons
"quicklist"

$ redis-cli -h 10.20.1.31 debug object promo:activity:20200909:coupons
Value at:0x7f9a2c103440 refcount:1 encoding:quicklist serializedlength:1180693400
lru:8823411 lru_seconds_idle:311

serializedlength 1.18GB，编码是 quicklist（list 在 Redis 3.2 之后用 quicklist，是 ziplist 组成的双向链表）。

为什么删一个 key 要 800ms

这里要区分两件事：释放内存和从结构中摘除。

Redis 的 DEL 是同步的，它在主线程里做两件事：调用 decrRefCount 递归释放这个对象占用的所有内存（1.25GB 的 quicklist，180 万个节点，意味着 180 万次 zfree）；然后从全局 dict 里把这个 key 摘掉、更新过期字典等。

释放 1.25GB 内存、180 万次 zfree 调用，803ms 完全说得通。而且因为 Redis 是单线程处理命令的，这 803ms 内所有其他客户端的请求全部在排队。

我本地复现过，构造一个 1000 万元素的 list：

# 造一个大 key
$ redis-cli debug populate 10000000 test:biglist 100
OK
$ redis-cli memory usage test:biglist
(integer) 1124000128

# 同步删除
$ redis-cli --latency
$ redis-cli del test:biglist
(integer) 10000000
# 延迟监控上能看到一个 900ms+ 的尖刺

顺便说下，DEL 慢只是大 key 危害的一部分。完整的危害清单：

  • 删除阻塞：就是这次的事故。
  • 网络传输：读一个 1.25GB 的 key，就算带宽 1Gbps，也要 10 秒。客户端超时是必然。
  • 主从同步：主库删大 key 时，从库也要花同样久的时间。我们当时观察从库延迟涨到了 6 秒。
  • AOF 重写：DEL 大 key 会在 AOF 里记一条命令，但重写 AOF 时要重新序列化剩余数据。大 key 的存在让 fork 出的子进程 copy-on-write 开销巨大。
  • 内存不均：集群模式下单个 slot 扛着 1.25GB，其他节点很闲，扩容无效。
  • 过期也是同步的：给大 key 设 TTL，到期时 Redis 的主动过期清理同样会阻塞。这个更隐蔽，因为是"自己会炸"。

怎么找出线上的大 key

事后我给所有 Redis 实例做了一次全面扫描。

方法一：redis-cli --bigkeys（最方便）

$ redis-cli -h 10.20.1.31 --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 '"item:snapshot:88213"' with 2097152 bytes
[00.12%] Biggest list   found so far '"promo:activity:20200909:coupons"' with 1803421 items
[05.31%] Biggest hash   found so far '"user:profile:cache"' with 512004 fields
[12.44%] Biggest zset   found so far '"rank:daily:20200908"' with 892341 members

-------- summary -------

Sampled 3128434 keys in the keyspace!
Total key length in bytes is 122843412 (avg len 39.26)

Biggest   list found '"promo:activity:20200909:coupons"' has 1803421 items
Biggest   hash found '"user:profile:cache"' has 512004 fields
Biggest string found '"item:snapshot:88213"' has 2097152 bytes
Biggest   zset found '"rank:daily:20200908"' has 892341 members

3128434 strings with 42188234123 bytes (100.00% of keys, avg size 13485.53)
0 lists with 0 items (00.00% of keys, avg size 0)

注意加 -i 0.1，让 SCAN 每 100 次迭代睡眠 0.1 秒，降低对线上 QPS 的影响。我们 312 万个 key，加了 -i 0.1 之后扫描耗时 3 分 20 秒，期间主库 QPS 下降约 8%，可以接受。

这个命令的原理是 SCAN + TYPE + 各类型的 size 命令（STRLEN/LLEN/HLEN/SCARD/ZCARD）。有个明显的局限：它只按元素个数统计，不看实际字节数。一个 100 万元素的 list，如果每个元素只有 1 字节，实际很小，也会被报出来。反之一个 string 只有 1 个元素但占 2MB，它按字节报，是准的。

方法二：memory usage 精确统计（推荐）

写个脚本，SCAN 遍历 + MEMORY USAGE 精确测量，输出 top N：

#!/bin/bash
# scan_bigkeys.sh  用法: ./scan_bigkeys.sh 10.20.1.31 6379 1048576
HOST=$1
PORT=$2
THRESHOLD=${3:-1048576}    # 默认 1MB

cursor=0
echo "key,type,bytes" > /tmp/bigkeys_report.csv

while true; do
    reply=$(redis-cli -h "$HOST" -p "$PORT" SCAN "$cursor" COUNT 1000)
    cursor=$(echo "$reply" | head -1)
    keys=$(echo "$reply" | tail -n +2)

    for key in $keys; do
        size=$(redis-cli -h "$HOST" -p "$PORT" MEMORY USAGE "$key")
        if [ "$size" -gt "$THRESHOLD" ]; then
            type=$(redis-cli -h "$HOST" -p "$PORT" TYPE "$key")
            echo "$key,$type,$size" >> /tmp/bigkeys_report.csv
        fi
    done

    [ "$cursor" == "0" ] && break
done

echo "=== TOP 20 by bytes ==="
sort -t, -k3 -rn /tmp/bigkeys_report.csv | head -20

扫出来的结果（部分）：

key类型大小元素数
promo:activity:20200909:couponslist1.25GB1803421
user:profile:cachehash412MB512004
rank:daily:20200908zset128MB892341
item:snapshot:88213string2MB1

MEMORY USAGE 的局限是它要对每个 key 单独发一次命令，比 --bigkeys 慢得多。312 万 key 跑完要 40 多分钟。折中做法是先用 --bigkeys 粗筛，再对可疑的 key 用 MEMORY USAGE 精确测。

方法三：RDB 离线分析（对线上零影响）

如果实在不敢在线上扫，可以把 RDB 文件拉下来离线分析。用 redis-rdb-tools：

$ pip install rdbtools python-lzf

$ rdb -c memory /data/redis/dump.rdb --bytes 1048576 -f memory.csv
$ head -3 memory.csv
database,type,key,size_in_bytes,encoding,num_elements,len_largest_element,expiry
0,list,promo:activity:20200909:coupons,1342177280,quicklist,1803421,18,
0,hash,user:profile:cache,431890432,hashtable,512004,1024,

$ awk -F, 'NR>1 {print $4" "$3}' memory.csv | sort -rn | head -20

在从库上执行 BGSAVE 拿到 RDB，拉到本地分析，对主库完全没有影响。我们后来把这个做成了每周一次的例行任务，产出大 key 报告发到群里，谁建的谁去拆。

解决方案：异步删除

UNLINK：DEL 的异步版本（Redis 4.0+）

最直接的办法，把所有 DEL 换成 UNLINK：

redis> UNLINK promo:activity:20200909:coupons
(integer) 1                      # 立即返回，实际释放在后台线程做

UNLINK 做的是：先把 key 从全局 dict 里摘掉（这一步是 O(1)，非常快），让这个 key 立刻不可见；然后把对象的释放任务丢给后台的 bio 线程（Redis 有自己的三个后台线程：close、fsync、lazyfree），主线程不等待。

实测对比（同样是 1000 万元素的 list）：

$ redis-cli del test:biglist
(integer) 10000000
# 客户端阻塞 912ms

$ redis-cli unlink test:biglist2
(integer) 10000000
# 客户端阻塞 0.3ms

差 3000 倍。

Java 客户端里改：

// Spring Data Redis 2.3 已经支持 unlink
redisTemplate.delete(key);        // 底层用的是 DEL
redisTemplate.unlink(key);        // 用 UNLINK，推荐

// 批量
redisTemplate.unlink(keys);

要注意的是 Lettuce 的 delete() 底层是 DEL。我们全局替换了一遍，把业务代码里的 delete 全换成 unlink。有些地方（比如依赖 delete 返回的实际删除数量做判断的逻辑）要改一下，因为 UNLINK 返回的也是删除的 key 数量，语义一致，基本不用动。

lazyfree 配置：让过期和淘汰也异步

UNLINK 解决主动删除，但还有一种情况：key 自己过期了。Redis 的过期清理有两种，惰性的（访问时发现过期才删）和主动的（每 100ms 随机抽查 20 个 key）。主动清理发现大 key 过期时，同样是同步删除，同样阻塞。

解决办法是打开 lazyfree 开关。我们在 Redis 6.0 的配置里加了这四条：

# redis.conf
lazyfree-lazy-eviction yes      # 内存淘汰时异步释放
lazyfree-lazy-expire yes        # 过期删除时异步释放
lazyfree-lazy-server-del yes    # 隐式删除（如 RENAME 覆盖）时异步
replica-lazy-flush yes          # 从库清空数据时异步

这几个参数 Redis 4.0 引入，6.0 里 lazyfree-lazy-eviction 和 lazyfree-lazy-expire 默认还是 no，需要显式打开。配完要重启或者动态设置：

$ redis-cli config set lazyfree-lazy-expire yes
$ redis-cli config set lazyfree-lazy-eviction yes
$ redis-cli config rewrite          # 写回配置文件

另外 FLUSHALL / FLUSHDB 也有异步版本，测试环境清库时用 FLUSHALL ASYNC，别用同步的（清 300 万 key 同步要 8 秒）。

异步删除的代价：内存不是立刻释放

用了 lazyfree 之后要注意一个副作用：内存释放是异步的，所以 INFO memory 里看到的 used_memory 不会立刻下降。有个专门的指标看等待释放的量：

$ redis-cli info memory | grep -E 'used_memory:|mem_fragmentation'
used_memory:8241883412
used_memory_human:7.68G

$ redis-cli info stats | grep lazyfree
lazyfree_pending_objects:1803421        # 还有 180 万个对象等待后台释放

lazyfree_pending_objects 不为 0 说明后台线程还没释放完。我们把它加进了监控，如果这个数持续不降，说明删除速度跟不上，需要关注。

治本：别建出大 key

异步删除只是避免删除时卡顿，大 key 的传输、同步、内存不均问题依然存在。那几个大 key 我们后来都拆了：

1.25GB 的优惠券 list：根本不该放 Redis。180 万个券码，改成写 MySQL 表 + 按需分页查询，Redis 只缓存"剩余数量"这种聚合值（一个 string）。删除的时候走数据库归档。

412MB 的用户 profile hash：这是把所有用户的资料塞进一个 hash（当时想着"一个 hash 省 key"）。改成每个用户一个 hash：user:profile:{userId}，用 HGETALL 单独取。这是典型的把 Redis 当数据库用的错误——Redis 的 hash 在 field 数量超过 hash-max-ziplist-entries（默认 512）之后会从 ziplist 转成 hashtable，内存占用翻好几倍。

128MB 的排行榜 zset：改成只保留 top 10000，用 ZREMRANGEBYRANK rank:daily:20200908 0 -10001 定期裁剪。

拆完之后，最大的 key 是 2MB 的商品快照 string，也在我们的告警阈值（5MB）之内。

长效机制

事故之后我做了三件事：

  1. 慢日志阈值从 10ms 降到 5ms：config set slowlog-log-slower-than 5000。并且把 slowlog 采集到 ELK，出现 DEL / KEYS / HGETALL 这类危险命令就告警。
  2. 每周一次 RDB 离线分析，大 key 报告发到业务群。超过 10MB 的 key 要求限期拆分。
  3. 在公共 Redis 工具类里禁用危险命令：封装了一层，直接把 keys() 方法标为 @Deprecated 并在调用时打 warn 日志，delete 内部改调 unlink。

小结

  1. DEL 是同步的，删除 1.25GB 的 key 阻塞了 803ms，导致所有请求排队。命令数不变但延迟暴涨，就是这个特征。
  2. Redis 4.0 的 UNLINK 把释放丢给后台线程，只摘引用不释放内存，实测快 3000 倍。
  3. 过期和内存淘汰也可能是同步删除，必须开 lazyfree-lazy-expire 和 lazyfree-lazy-eviction。
  4. 找大 key：--bigkeys（按元素数，快）、MEMORY USAGE（按字节，准，慢）、rdb-tools 离线分析（对线上零影响，推荐例行化）。
  5. 异步删除治标不治本。大 key 本质上是数据模型用错了——别把 Redis 当数据库存全量数据。

参考

Arthas 上手：不重启应用定位...
Redis 管道与 Lua 脚本：...