前两天生产服务突然出现大量慢请求,紧接着服务不可用问题,下面复盘一下由Redis大key导致的生产事故。
时间线
15:28
接到业务部门反馈,A系统打开很慢,卡顿问题。
15:30
通过服务监控观察到A系统大量接口慢请求,而这些接口大多是调用B系统的。
观察A系统错误日志,主要为一下2类异常
java.util.concurrent.RejectedExecutionException: event executor terminated
org.redisson.client.RedisTimeoutException: Redis server response timeout
观察B系统错误日志,主要为后者 RedisTimeoutException
由于A、B服务共用一台Redis实例,初步猜测是Redis服务挂了。
15:35
Redis服务是购买的云厂商的服务,规格为 2G 主备 128Mb带宽。因为平时利用率大多在50%左右,不太可能出问题。
查看性能监控,内存,CPU利用率也并不高,慢查询日志也没有,看似服务很正常。
通过云厂商的实例诊断,发现可能存在以下问题
- 耗时命令:执行了O(N)时间复杂度命令:[‘keys’, ‘hgetall’, ‘lrange’]
- 网络异常:瞬时流量过大,Redis响应变慢
通过检查代码排查keys *
指令是被限制的,常用的列表指令,操作的数据量也不大,此项暂时没找到问题。
再次回到性能监控面板,发现带宽使用率已超100%,流控次数也较大。
原来带宽被占满了,问题是被什么占满了呢,有没有什么大key?
指定db查询大key:
redis-cli -h 192.0.0.10 -p 6379 -n 64 --bigkeys
果然有所发现,某个开发同学将一个大json文本存进了Redis,这个文本约1MB。 结合上文提到的Redis带宽128Mb,简单计算128Mb/8=16MB 也就是如果16个并发读就会造成带宽被占满。
15:45
临时将该key置为空,通知业务暂时停止使用相关功能,服务恢复。
后续将该key存内存中修复上线。
事后分析
RejectedExecutionException
异常
Tomcat总线程数达到maximumPoolSize(对应maxThreads 默认200)就会拒绝服务,在此次事故中,由于A调用B接口,而超时时间设置时间2分钟,导致这些请求线程不会被释放,后续超时时间需设置一个合理值。
服务监控告警
由于是小团队,没有专业运维,服务告警机制还不完善,我想需要做到比业务部门先行知道系统已存在的问题,这个要一步步来。
Code review
想了想Code review还是很重要,对于关键业务还是要过一遍,在早期发现问题及时改正。