记一次Redis溢出故障处理

1,199 阅读8分钟

本文首发于我的个人网站 Jamki的个人网站

问题起因

某天早上我还在上班途中的公交上刷着手机,突然部门群里一阵骚动,”站点打不开了?!“ ”概率性页面报障“ ”咋回事啊“.... 还睡意蒙胧的我立马吓的手机差点掉到地上去了,心急如焚的我直接就想在公交上掏出电脑来看,在惶恐的十分钟后,我迅速下了公交冲回公司自己的工位上,开始排查。

定位问题

打开了阿里云的控制台,看了下近半个小时的报错,基本都是同一个:

2020-12-10 08:50:19,868 ERROR 168244 [-/127.0.0.1/-/195ms POST /user/site/list] 
nodejs.ReplyError: OOM command not allowed when used memory > 'maxmemory'.

啥意思?就是redis溢出啦!当前redis的内存超过了它设定的最大内存容量。

赶紧登上服务器,开始作业

查看下redis内存信息先:

redis-cli info memory

乖乖,最大容量的才4.66G,已用4.65G,就是箭头指的那两个位置

当时情况着急没截图,这里放出来的只是查看redis内存占用的栗子,内存情况不是当时的。

那现在已经是实锤redis溢出了,看下是啥占用了那么多,查看占内存比较高的键

redis-cli --bigkeys

输出就是下面的样子(数据不是当时的)

redis-cli --bigkeys输出会显示最大占用内存的字符串key、set key、及hash key是啥,分别占了多少字节跟其他信息。但是最大那个key也不过几十M,不可能是某个key造成的,有可能是某种情况引发了百万级别的key创建塞满了redis内存。

输出的summary信息证实了我的猜想:

-------- summary -------
Sampled 11998929 keys in the keyspace! 
Total key length in bytes is 430089742 (avg len 35.84) 
Biggest string found 'xxxx' has 789970 bytes
Biggest set found 'xxxx' has 20841 members 
Biggest hash found 'xxxx' has 3393675 fields

redis里一共存了1000多万条记录!我倒吸一口凉气,还能这样搞的吗,一千多万。。。。

排查过程

为了确定这一千多万的记录的key是何种形式的,我把所有的key都保存到了文本,一方面是想着分析过程中会频繁用到数据,频繁去大规模查取数据会影响到正常redis读取,另一方面也是为了保存‘证据’,方便分析故障原因

保存记录到文本里:

redis-cli keys "*" > /data/redis-key.log

注意,一般来说生产环境下keys * 是不建议用的,因为这个真的很耗性能,特别是在量级比较大的redis中查,有时候还会卡上一阵子,导致其他redis读取受到影响。但这非常时期,故障都出现了,用下也是可以理解的。

好的现在所有key都拿到了,我要看是哪种类型的key占满了内存,首先根据我的程序中出现的关于redis的写入的所有key,我查了了它们在key文本中出现的行数,如我查看key形式为以sitemap_开头的有多少行

cat /data//redis-key.log | grep 'sitemap_' | wc -l

结果显示我所查询的最大的那类型的key也才几万个而已

还有啥呢?

那我随机找十万条key数据看下啥样子的

shuf -n 100000 /data/redis-key.log  > /data/redis-ramdom-key-100000.log

我随机捞了10万条记录出来,看下是啥样子的

less /data/redis-ramdom-key-100000.log

(这里顺便提下,在linux常用到查看日志或者文本的命令有几个像catlesstail等,cat会把整个文本到显示出来,适合输出小文本;less是小部分的展示,滚动加载,适合大文本查看;tail常用于实时的输出日志,或者输出日志或文本的倒数第几行;哪种场合应该用哪个命令查看文本心里应该清楚才行)

看输出的内容,清一色都是这种格式:

f30a0485-b59f-4939-a41d-3955786b37e0

我恍然大悟,这是egg-session创建的会话id啊,原来是中间层创建会话出了问题啊;

我记得会话过期时间是设置了两天,难道会话过期时间设置没生效,导致会话记录一直积在redis里面导致溢出? 为了验证我的想法,我得去看下那些现有会话的存活时长有没有超过两天

查看key存活时间是用命令redis-cli ttl来实现的,具体的可以自行查阅文档 随便从我捞出来的会话ID列表里选一个看有没有超过两天(ttl查询结果单位是按毫秒,2天就是172800000毫秒

redis-cli ttl 'f30a0485-b59f-4939-a41d-3955786b37e0'

结果显示没有超过两天,

然后我把随机捞出来的十万条拿去查:

cat /data/redis-ramdom-key-100000.log | xargs -I key redis-cli ttl key > /data/key_ttl.log

上面的命令的主要意思是:把那十万条数据输出(不显示),通过管道 传给 xrags, xrags把接受到的每个输入当作一个参数,记作key, 然后把这个key交给redis-cli ttl执行,就是查这个key的存活时间;把时间保存到文本key_ttl.log里 这里多说一句,xrags真的非常强大,好用,如果你想你的shell语句写的飘逸,xrags你值得拥有。

接着看下有哪些时间大于两天的,直接输出好了:

cat /data/key_ttl.log | awk '{if($0 > 172800) print $0}'

这里意思是把刚才拿到的十万条记录的存活时间做个筛选,把大于两天的就打印出来
注:awk是文本处理工具,同样十分强大,推荐去了解一下

但是让我困惑的是,居然没有输出结果,证明存活时间都小于两天!oh no

既然过期时间设置没问题,就看创建出了什么问题,我随便拿了一个会话id的key,打印出它的值

redis-cli get 'f30a0485-b59f-4939-a41d-3955786b37e0'

具体结构就不展示了,但我得到了一个重要信息,这会话里面没有存有会话信息跟业务信息,只存了几个可有可无的值;我纳闷了,会话里不应该存登录信息用户信息啥的吗,为啥用户信息都是空的,这也能创建一个会话啊? 证明没有登录就可以创建会话?为了验证我的想法,我去实验了一下:

打开我本地的项目,事先清了redis相关记录,我打开页面,没有登录,我立马回去看redis信息,oh no它果真给我创建了一个会话。。。。。我这算是彻底知道咋回事了,肯定有人刷我们的网站,导致会话不断给创建。

后知后觉的我打开的nginx 的访问日志,

tail -f xxxxx.log

果然,清一色的请求,滔滔不绝,我想,不应该啊,不是程序对ip做了限流吗,怎么还能刷过来?我从nginx日志里拿了几天比较相似的立即出来,拿它的ip去查中间层的限流记录,每个ip只记录到了3词,那就是说刷的人有个很庞大的ip池,避免给我们屏蔽,每个Ip只请求了3次立马就换。我心想,这人厉害啊,那么大的ip池,真够下本

现在还有一个疑点,就是为啥不登录会给我创建了会话,让那些刷量的人有可乘之机,我得改下才行!不然这样太危险了。!

探索解决方法

经过盘查,发现会话是egg的一个插件egg-seesion-redis自动创建的,只要请求来的没带我们规定的会话key键,而且有数据要写入(不管写入内容是啥,即便为空),就会立马给你创建一个会话,但是这不是我想要的结果,我想要的是登录后再创建会话。 经过对egg-seesionegg-session-redis, koa-session源码的研读,我发现了可以操作的地方:

这是egg-session-redis插件替我创建会话的代码现场,那我只需要在redis.set之前做好判断再决定写不写就好了嘛

还有一个就是这是插件里的代码,有两个方法可以达到我想要的目的: 1.改写这个插件,然后发布到npm,自己拿来用 2、egg.js根目录下可以新建个app.js, 里面有几个生命周期函数,里面有个didLoad函数,详情戳这; 当所有配置文件已经加载完成时执行,这时候我在覆盖app.seeionStore就行了

考虑到时间、以及操作复杂度,我毫无疑问选择了第二种

完结

最终,顺利解决了故障,redis内存降了下来并维持在正常水平;这次故障处理也学了几个有趣且实用的liux命令, 像xagrs, shuf, awk等,熟练运用对我们大有裨益。好啦,最后希望大家一起进步,我是 Jamki