记一次线上问题排查

这次线上问题来的比较突然,影响也大,用博客记录下整个过程,也当作是对这次事故的一次总结归纳。

day1:


2018年06月21号上午10点,收到运营同事通知,http://**.com/api/访问量剧增,日志量达到80G/天,而且有上升趋势。运营同事让我们排查,这种访问是否正常。运营统计访问量:

记一次线上问题排查


收到通知后立即展开摸排:

1:第一时间登录服务器,查看服务状态。
    top命令两台服务器的状态良好。df -h磁盘空间,发现data盘利用率为80%,明显有点高。
2:postman模拟调用线上服务,果不其然503,408错误,服务器基本上接收不了请求,在崩溃的边缘。
3:备份日志,重启服务(在重启服务之前把日志备份是一个良好的习惯)
4:再次请求服务,错误依旧。
5:联系运营同事,了解实时的请求量。大概80W/分钟
6:紧急找到线上一台闲置的机器,部署应用,联系运营同事做负载,再次请求服务,错误依旧。


到这个时候,就知道想短时间恢复服务功能,是不太可能。事情紧急,随后立即汇报领导(这点很关键,这种事情影响比较大,需要立即知会上级,等待上级的处理指示)。

一天10亿+的量,实行第6部根本就是无用功,因为这个服务我们只部署了2台机器,配置是4核8G500M,别说扩一台了,扩几台都对付不了。

现在需要做的是联系联系产品经理,明确近期是否有大批量的用户上线。得到得答复是有产品推出去了,大概10几万的灰度发布。初步得出的结论请求是非正常请求。排查只能从上游调用端着手。联系客户端老大,说明事情严重性。客户端老大建群,把相关人员都拉进来(不得不佩服其高效性)。


我从日志里面费了九牛二虎之力统计出下面结果(awk 命令确实很强大高效):第一列是请求量,第二列是请求状态,最后一列是调用端。可以很清楚的知道始作俑者是谁了。很快,客户端定位出是新发的版本存在重复调用的bug。

记一次线上问题排查

事情到这算是告一段落了。这个时候是2018年06月21号下午3点钟,中午饭还没吃(不得不佩服敬业程度啊),不过总算查到原因了,跟服务端没有直接关系,提着的心总算放下来了。

服务器已经瘫掉,重启也没作用。我老大的意思把接口逻辑屏蔽掉,只是记录日志。修改代码很快打包上线部署,静观日志。

day2:

2018年06月22号上午,接到通知,调用端bug已解决,并于昨晚输出版本(又一声惊叹,佩服互联网之高效率)。联系运营查看接口的访问情况,分钟/1w左右。这几乎算降到一个正常水平,随即重新打包,把注释放开,部署。蛋疼的事发生了,部署几分钟后又出现503等错误。两腿一紧。。。

这个量虽然有点偏高,但凭服务器的性能,对付应该问题不大。赶紧处理吧,又投入到解生产问题的紧张状态中去了。

登录两台api服务器,查看状态都是良好,找到lockback日志,发现error日志量巨大,不得了,快把磁盘沾满了。备份出部分,赶紧清理调。可能那会紧张,命令搞错了(本来应该是echo "" > ***.log),rm -rf ***.log,直接干掉了日志文件。我去,发现事态不对,可为时已晚。卖个关子:知道在高速记日志的情况下,直接干掉日志文件的后果是什么吗?

对的,不多久,发现服务重启不了,报/tmp/****tomcat**valid错误,大概意思是tomcat子模块重启不成功(项目是springboot构建的,自带的tomcat容器)。对的,导致这一问题的元凶就是我手动干掉了日志文件,日志还会继续写,但写的是linux服务器当前登录的用户目录下,对,也就是系统盘,系统盘满了,所以重启不了应用了。

花了不少时间,找运营帮忙删文件,因为自己没有root权限。

查看错误日志,发现都是mongo连接错误,大概的意思是超出了最大500的连接数。想都没想,直接把最大线程连接数改到2000,?waitQueueMultiple=2000。重新发布监控,还是大量抛出错误,错误信息为连接超时。

 目前的访问量为10W/min。看来mongo服务器还是承载不了。登陆上mongo服务器,发现cpu使用率一直是399%,看来四核资源都被它占用了。其实这个量对于mongo来说,根本不是问题,为什么会出现超时呢。登陆进去mongo后台,查看主要的接口文档数据,每个文档的量大概40W左右。进一步排查接口代码,发现代码里面有一段检索的逻辑。灵光乍现,是不是文档里面没有创建索引?查看,果然如此。立即创建文档几个唯一业务数据的索引,一个30个文档,着实花了一段时间。索引创建后,观察mongo服务器的状态,cpu还是没有下来。

奇怪,难道不是索引的问题?再一次查看代码,发现检索的都是传入单个业务字段,而我创建的是复合索引。印个是这个问题。再建吧,30个文档,每个文档创建5个索引。完成后监控服务器,CPU使用率降至4%左右,完美解决!


服务器完成恢复正常!至此,这个事件算是完美解决!

后记,通过这次生产事件,让我反思有很多地方是我们需要改进的:

1:后端接口没有一个实时的监控体系,还是运营发现问题通知到,这个是需要我们改进的。

2:对于访问攻击,接口应该有基本的防护体系,比如对ip限流等

3:在设计mongo文档的时候,一定记得要规范好索引,别等出现问题的时候再去亡羊补牢。