记一次生产事故：30万单就这样没了！

男娘i 2022-12-10 07:04 139阅读 0赞

# 背景 #

你好，我是彤哥。

昨天晚上下班回家，在地铁上，老大突然打来电话，B系统生产环境响应缓慢，影响了A系统的使用，几万小哥收不了单，大概有30万单卡住了，你去帮忙定位一下。

我8点半左右到家，立马上线入会。

# 重启 #

我入会的时候，已经有同事在帮忙定位了，俗话说的好，重启能解决80%的问题，如果重启解决不了，那肯定是重启的次数还不够，呸，不对，重启解决不了，就真的要去定位了。

事实证明，重启后走一波压测依然没什么用，1000个并发，平均响应时间在3~4秒，连续压了几次都是这样的结果。

# 升级配置 #

重启看来是无效了，进入第二个阶段——升级配置，2台4核8G的实例升级到6台8核16G，数据库的配置也翻了一倍，能用钱解决的问题，我们一般不会投入太多的人力^^

事实证明，加配置也没什么卵用，1000个并发，压测的平均响应时间还是在3~4秒。

有点意思了。

此时，彤哥我介入了。

# 查看监控 #

我上线之后，查看了一下监控，实例的CPU、内存、磁盘、网络IO、JVM堆内存使用情况好像都没啥问题，这真是个头疼的问题。

# 本地压测 #

我们分成两波同学，一波去准备本地压测，一波继续分析，经过本地压测，我们发现，本地环境，单机，1000个并发，妥妥的，毛问题都没有，平均响应基本维持在几百毫秒。

看来，确实跟服务本身没有问题。

# 代码走查 #

实在没有办法了，拿出代码，一群大老爷们一起看代码，研发同学给我们讲解业务逻辑，当然，他已经被各位大佬给骂死了，写的什么破代码，其实，在彤哥介入之前，他们已经改过一波代码了，有个地方把redis命令`scan`改成了`keys *`，这里埋了个坑，但是，现在不是主要问题，后面我们会说。

代码一路走读下来，发现有很多的redis操作，还有个for循环里面在调redis的get命令，其它的都是常规的数据库操作，而且都加了索引的，所以，初步排查，数据库这里应该是没有什么问题，主要问题可能还是集中在redis这块，调用太频繁了。

# 加日志 #

代码走查下来，除了那个`scan`改成了`keys *`（这个我还不知道），基本上没有什么问题，加日志吧， 一小段一小段的加上日志，OK，重启服务，压测来一波。

当然了，结果没有什么变化，分析日志。

通过日志，我们发现，调用redis的时候时而很快，时而很慢，看起来像是连接池不够的样子，也就是一批请求先行，一批请求在等待空闲的redis连接。

# 修改redis连接数 #

查看redis配置，用的是单机模式，1G内存， 连接数默认的8，客户端还是比较老的jedis，果断改成springboot默认的lettuce，连接数先调整为50，重启服务，压一波。

平均响应时间从34秒降到了23秒，并不明显，继续加大连接数，因为我们是1000个并发，每个请求都有很多次redis操作，所以，肯定会有等待，这次我们把连接数直接干到了1000，重启服务，压一波。

事实证明，并没有明显地提升。

# 再次查看日志 #

此时，已经没有什么好的解决办法了，我们再次回到日志中，查看redis相关操作的时间，发现99%的get操作都是很快返回的，基本上是在05毫秒之间，但是，总有那么几个达到了800900毫秒才返回。

我们以为redis这块没什么问题了。

但是，压测了好几次，时间一直提不上去。

很无奈了，此时，已经半夜3点多了，领导发话，把华为云的人喊起来。

# 华为云排查 #

最后，我们把华为云相关的人员喊起来一起排查问题，当然，他们是不情愿的，但是，谁让我们给钱了呢^^

华为云的负责人，把redis的专家搞起来，帮我们看了下redis的指标，最后，发现是redis的带宽满了，然后触发了限流机制。

他们临时把redis的带宽增大三倍，让我们再压测一波。

握了颗草，平均响应时间一下子降到了200~300毫秒！！！！

真的是握了颗草了，这就有点坑了，你限流就算了，带宽满了也不报警一下的么。。

这真是个蛋疼的问题。

到这里，我们以为问题就这样解决了，领导们也去睡觉了~~

# 上生产 #

既然问题原因找到了，那就上生产压一波吧~

我们让华为云的专家把生产的带宽也增大了三倍大小。

从生产提交拉一个hotfix分支，关闭签名，重启服务，压测走一波。

完蛋，生产环境更差，平均响应时间在5~6秒。

测试环境我们是改了连接池配置的，生产环境还是jedis，改之，走一波。

并没有什么实际作用，还是5~6秒。

真是个蛋疼的问题。

# 查看监控 #

查看华为云中redis的监控，这次带宽、流控都是正常的。

这次不正常的变成了CPU，redis的CPU压测的时候直接飙到了100%，导到应用响应缓慢。

# 再次唤醒华为云redis专家 #

已经凌晨四点多了，大家已经没什么思路了，华为云的redis专家，你给我再起来！

再次唤醒华为云的redis专家，帮我们分析了下后台，发现10分钟内进行了14万次scan~~

> 关注公主号彤哥读源码，查看更多干货好文！

# 万恶的scan #

询问研发人员哪里用到了scan（前面他们改的，我不知道），发现，每次请求都会调用scan去拿某个前缀开头的key，每次扫描1000条数据，查看redis键总数，大概有11万条，也就是说，一个请求就要scan100次，1000并发，大概就是10几万次scan，我们知道，redis中`scan`和`keys *`是要进行全表扫描的，非常消耗CPU，14万次scan操作，直接让CPU上天了。

# 为什么测试环境CPU没有上天呢？ #

对比了下，测试环境和生产环境redis的键总数，测试环境只有900个key，每次请求也就scan一次或者`keys *`一次，毛线问题都没有。

# 为什么生产环境有这么多key？ #

询问研发人员，为什么生产环境有这么多key，没有设置过期时间吗？

研发人员说设置了的，是另一个同事写的代码，打开代码，真是一段魔性的代码，具体代码我就不方便贴出来了，里面有根据条件判断要不要设置过期时间，经过分析，大部分情况下，都没有设置过期时间成功。

# 当前解决办法 #

此时，已经凌晨4点半了，虽然大家还很兴奋，但是，经过领导决策，暂时先不动了，因为，目前A系统已经暂停调用B系统了，所以，此时B系统可以说流量几乎为0了，我们白天再分两个阶段来修复这个问题。

第一步，先清理掉生产环境redis的数据，只保留一小部分必要的数据。

第二步，修改scan某前缀开头的数据，改成hash存储，这样可以减少扫描的范围。

好了，本次生产事故排查就到这里了，后续，彤哥，也会继续跟进的。

# 总结 #

本次生产事件跟以往遇到的事件都略有不同，大概总结一下：

1.  以往都是应用服务本身的CPU、内存、磁盘、JVM这些问题，redis的带宽和限流还是第一次遇见；
2.  上了华为云以后，很多东西还没有弄得熟练，包括监控指标这些，还需要慢慢摸索；
3.  redis一定要禁用掉keys和scan命令，且大部分key应该设置过期时间！

好了，本次事件大概就写这么多，后续有新的情况彤哥也会继续跟进的，当然，最好不要有新的情况^^

发表评论取消回复

表情：

评论列表（有 0 条评论，139人围观）

还没有评论，来说两句吧...

相关阅读

相关 redis引发的一次生产事故

问题描述：发版后回归测试，不定时出现token失效，导致自动退出到登录界面。如果操作的人员较多，token失效的就比较快，操作的人员较少token失效的相对

电玩女神/ 2024年03月25日 22:18/ 0 赞/ 42 阅读

相关一次生产环境P0级事故分析

事件背景作者所在的公司核心业务是做政府信息化软件的，就是为政府部门开发信息化系统。其中有一款信息化软件是客户每天需要使用的，并且他们面向的客户就是老百姓。某

分手后的思念是犯贱/ 2023年09月26日 11:05/ 0 赞/ 72 阅读

相关记一次生产事故OOM问题排查

背景线上应用需要进行一个涉及600W数据的操作，之前我们应用从来没有一次性应对这么大量的数据，最多就一次数十万而已。结果，这次600W的数据操作引起了生产事故，直接导致

迷南。/ 2023年02月13日 11:28/ 0 赞/ 26 阅读

相关记一次重大的生产上线事故，借此反思成长

目录写在前面生产上线出现问题问题1：logger日志没打印报错信息问题2：日志打印不全的问题问题3：equals报空指针问题问题4：还是空指针问题问

我会带着你远行/ 2023年01月11日 09:27/ 0 赞/ 112 阅读

相关记一次 MySQL 启动导致的事故

`MySQL` 启动存在端口被监听, 但服务没完全启动的情况. 背景 `MySQL` 启动时会进行 `第一次` 初始化数据库, 等待 `MySQL` 完全启动后, 再进

墨蓝/ 2022年12月28日 01:37/ 0 赞/ 241 阅读

相关记一次生产事故：30万单就这样没了！

背景你好，我是彤哥。昨天晚上下班回家，在地铁上，老大突然打来电话，B系统生产环境响应缓慢，影响了A系统的使用，几万小哥收不了单，大概有30万单卡住了，你去帮忙定位一

男娘i/ 2022年12月10日 07:04/ 0 赞/ 140 阅读

相关记一次Kakfa消费者集群的生产事故

由于项目业务需要，在之前的Kafka Consumer集群的自动提交设置为手动提交，先介绍一下怎么设置为手动提交。设置手动提交 consumer @Co

太过爱你忘了你带给我的痛/ 2022年11月26日 01:46/ 0 赞/ 134 阅读

相关记一次生产事故-mysql执行update导致锁整表

我第一次知道，执行update的时候，where条件如果不走索引，会导致锁全表！然后这个事务执行时间较长，导致后面的除了select语句，其他语句都被锁住不能执行

系统管理员/ 2022年10月27日 02:27/ 0 赞/ 187 阅读

相关记一次事故分析

1. 事故业务通过Web项目将计费明细数据发送至EBS(2.7亿) 2. 事故时间事故产生时间: 2018-8-16 22：54：00

绝地灬酷狼/ 2022年05月14日 04:37/ 0 赞/ 277 阅读

相关记一次线上hystrix的事故

我们线上有个系统是有若干个服务组成，服务之间通过thrift rpc进行通信，在调用rpc服务的时候加了一层hystrix，目的是防止“雪崩”。这样的系统架构算是一个比较“中规

系统管理员/ 2021年05月12日 11:55/ 0 赞/ 534 阅读