起因:
最近上线了一版关于敏感内容过滤的一个需求,半夜上线时,一切正常,but....在第二天中午时段,突然报警并有线上反馈相关功能有问题,查elk日志显示相关接口耗时很大,并且有部分连接都超时了(包括redis mysql 以及部分调用外部的http请求也是,系统响应巨慢,平常几毫秒十几毫秒的接口,突然变的无比的慢)本来是午饭午休时间,但是看到这些问题,瞬间我就清醒了,吓得我浑身哆嗦。
排查
说清这次排查,因为是线上,于是没有直接dump线程文件啥的,而是先看日志,看监控表盘,可以说监控表盘已经很明显了。 由于是事后补稿子,所以这里象征性找几张当时截下来的图片看看
看监控仪表盘检测系统各项指标
- cpu tcp 相关状态图
-
文件描述符相关监控图:
-
内存与线程状态图:
-
一些说明:
- 首先当时上线后,问题不是立马就出现的,说明系统有一段时间是在 "蓄积",其实很多连接 cpu 或者关于gc的问题都会这样,会有一个蓄积的过程,直到达到某个点或者某个范围,影响开始可视化!!
- 从以上三张图可以看到,文件描述符使用很高,线程很多timed_waiting ,cpu内存等都不太正常,可能有些不正常是因为受某个不正常因素的间接影响导致,总之我们知道系统存在问题就对了。
- 在7月9号中午左右,我们重启了下服务,发现异常现象比如:文件描述符,cpu,线程,tcp一些不正常的指标直接就降下来了。然后在10号凌晨发布了bugfix版本
分析elk中相关功能的日志
- 由于看日志这里涉及到隐私,而且当时内容没截取全,所以这里不贴图了,简单文字描述下:
一、大致逻辑如下: 1:拿到要检测的内容->2:(使用腾讯 sdk)构建调用对象(cosClient)->3:调用腾讯敏感检测相关接口->4:返回。
二、而通过观察日志发现在(2)处用时很久,大概占整个接口的90%甚至更多 ,于是我赶紧看了看这块的代码。三、代码很简单,就是构建cosCleint对象,来调用对应的api(sdk形式调用) ,我一步步跟了进去,发现里边做了很多工作。四、时间原因 具体细节我也没一点点debug,于是我把希望转向了腾讯的文档,翻开文档无意间我发现有这么一段描述:
解决发现的问题
看完这段我终于明白哪里出了问题,于是赶紧将每次都new一个调用对象改成单例的(fuck.....没想到是因为这个疏忽。。。。正符合了那句话:大意失荆州啊!我没想到会在这块上绊倒)
在bugfix版本中,我将new对象改成如下这段代码:
Singleton.get(XXX.class, yyy, zzz);
复制代码
发版后问题得到解决。回家睡觉!
总结
- 通过本次线上事故,我明白了四点:
- 日志,监控系统以及打印精准有效的日志是多么的重要!
- 系统上线后要有段观察期,不能说当时验收没问题就一切ok了。
- 与外部对接的东西,一定要仔细阅读对接或接口文档,确保无遗漏。
- 敬畏每一行代码,对每一行代码都有思考!!!