1.问题现象
- 16:55 发生告警
- 16:57 发现服务有3台实例重启
- 16:58 节点重启完成,功能接口恢复正常
2.结论
安全组攻防调用了管理后台旧接口,由于旧接口是提供给管理后台使用,参数校验不够充分,攻防组调用接口时未传参数,导致查询没有条件,把全表2多千万数据到内存中,
发生内存溢出,然后服务一直gc,cpu达到100%,触发容器在长时间高cpu重启的机制
3.排查过程
1、发生重启以及cpu 100%告警后,立马查看监控,发现只有3台节点cpu接近100%,同时gc的次数很高,由于不是所有节点的彪高,说明不是大流量这类的请求过来,我们的排查方向就
大致定位是:定时任务、某些请求导致触发了特殊逻辑导致内存一直占用不释放
CPU:
内存:
2、查看运维给出的Moss数据,我们仔细看了一下后,发现这里给出的内存和cpu的指标都是正常的,并无问题,
再看时间点,发现16:57分的时候,其实服务cpu已经是开始下降的差不多了,导致这个时间抓出来的线程和内存指标不是没有出现问题的现场,只能继续找别的线索
3、接下来我们排查是不是有定时任务导致的,我们把时间线拉长,并未发现有周期性的cpu、内存占用很高的问题,所以暂时往别的方向排查。
4、开始排查云日志,找耗时长的请求,但是这个时间点虽然挺多耗时长的请求,但不确定就是引起问题的请求,这里花了不少时间,但是因为这个时间点服务处理很慢了,任何请求都有可能变慢,同时请求太多,有些慢也不一定会导致这个cpu高、内存高问题
5、考虑到内存一直涨,在gc,那有可能一直在查数据,那么查数据可能会导致redis或者数据库相关的中间件cpu或者其他指标波动。带着这个思路我们发现那3台机器的下行带宽很大,那就大致吻合了这个猜想,说明节点一直在查什么数据。
6、既然带宽这么大,那么就开始看redis或者数据库有没有什么异常,因为一般这些数据的来源都是周边的中间件,同时这么大流量也有可能会导致一些指标异常,我们就需要找出这些异常的点,然后反推出我们的容器在做什么操作。
redis:
这里看redis很正常,然后继续查看mycat也是正常的
7、查看mysql,这个时候我们发现在那个点数据库的cpu很高,同时上行带宽也相对较大
8、找DBA帮忙拉出那个时间段的慢sql情况,发现问题了,有3条sql全表查,这张表又有2千万多数据。
9、通过这条sql,我们定位出了代码位置。会产生上面的sql肯定是由于if里面的条件都是false导致的
10.通过日志我们找到了调用的请求,时间点和请求路径以及重启的节点,都是对得上,至此问题就找了,就是由于这3个请求导致全表查数据,oom了
11、通过看操作日志的人,发现是安全组调用的,绕开了我们的前端正常逻辑,直接调用的接口,没有任何传参,导致sql变成了全表扫描。