如何解决一个偶现的503 bug?
概述突然被人在bug群@了一下,说是管理后台,访问不了,界面上出现了:
503 service temporarily unavailable
我赶紧尝试访问了一下,确实如此,但不是每次都不行,而是偶发503的错误提示。当时我是没有立刻动手去定位问题,而是先拉了一个临时处理群,这样做的原因是:
·先将线上出故障了这件事情同步出去,要让相关的人知道,像运维、测试、你的上级、产品等;
· 一定是先止损,优先【线下去处理故障】,而不是【直接在线上处理故障】;
群拉完后,我简单同步现象后,就开始分析了,首先想的第一点就是:
是不是因为做了线上变更导致的,比如有发版之类的。
从这个点切入去想的原因是源于自己处理线上故障的经验,大部分都是发版导致的,能回滚的优先回滚,第一时间降低影响。因此我打开了发版日历(技术团队是有维护一个发版日历的,记录了每次发版或者变更的内容),发现3月2号当天,在线上做了如下两件事情:
·部分服务接入了阿里云WAF,这个是因为安全原因,需要接入;
· 管理后台对应的前后端服务,确实也发版了;
火速电话公司的安全专家,先临时关闭WAF,但关闭后没有用,访问管理后台还是一直出现503提示,没办法了,得立刻回滚当天上线的内容,正当运维要操作回滚的时候,我反而制止了它。因为:
管理后台突然又能访问了。
跟产品和业务方确认了一下,他们也反馈系统恢复了。好吧,这个也算一个好消息,毕竟可以给技术团队多一些时间去定位问题。
系统临时性恢复后,我这边也就没那么大的压力和紧迫感了,静下心来开始着手仔细分析,找出根因。
分析过程
是否有突增的流量过来
使用阿里云的SLS日志平台,写了个简单的脚本,执行后发现,流量一直很平滑。虽然是管理后台的服务,但是还是要先看看流量的,因为有可能有一些定时任务或者重量级业务操作,导致疯狂的调用管理后台服务。
是否是发版导致的?
由于发版的内容还不少,很难一下子分析出是哪些代码导致的,只能利用阿里的日志平台以及监控平台,从故障发生的时间范围里,寻找一些蛛丝马迹。
首先是查看故障时间内,对应的后端服务有无返回状态码非200的,可以使用阿里的SLS日志平台,写个简单命令查询一下即可:
xxxx_app_id:yyyy not statusCode: 200
上面的一些查询字段,是可以在SLS上自己定义的。最终发现返回的状态码都是200的,这个就有点奇怪,但还是继续看一下有无异常日志。
xxxx_app_id:yyyy and logLevel: ERROR
发现也没有,初步判断,不是后端代码上线导致的,便转而开始用阿里云的监控平台观察后端服务pod节点的运行情况,但也没有什么收获,pod既无重启的情况,内存、CPU usage也都正常,也没有什么慢的请求。
当时就有点摸不着北了,由于那会也比较晚了,后台管理系统也暂时没有出现问题了,我就先回家了。而隔天又有其他重要紧急的事情要处理,我就忘记去跟这个事情了,一直到3月6号早上,又开始出现503问题了,持续时间是两分钟,然后就又自己恢复了。
这次我就把手头上的事情先全部放下,全力跟进这个问题。经过3月2号晚上的分析,感觉跟后端服务没有关系,那会不会是前端的node服务有问题呢? 当然平时如果线上出故障,我很少认为会是前端问题,都是先从后端服务定位起。
但这次没办法,死马当活马医,于是便到阿里云上去看一下前端pod节点的运行情况,发现有重启的情况,我感觉发现新大陆了,马上去确定pod重启时间,但是很遗憾,我没权限看,就临时去看一下这个pod的内存波动情况,一般来说,pod有重启的话,内存会短暂释放,果然,在故障期间,前端的pod的内存占用有下降的趋势,然后故障后的几秒,内存占用又恢复了日常水平。
于是便火急火燎的跑去找了一下运维:
把前端的xxx pod有重启的情况,我怀疑管理后台503问题,是这个原因导致的,你能不能把这个pod重启前的日志发我一下。
当时运维回复说,重启前的日志找不到了哦。当然,这句话我是不信的。就让运维去查一下或者找阿里云的售后,看看怎么拿到pod重启前的日志。果然,可以使用kubectl命令,找到日志:
kubectl describe pod xxxx-pro-vyyyyyyyy | grep 'State: ' -A 5
日志里有几个信息:
·一个是pod重启前的代码报错日志;
· 一个是pod具体的重启时间;
· 一个是Exit Code,这个code等于1,说明pod重启,是服务自身的报错导致的。
报错日志如下:
TypeError : Invalid value "undefined" for header "Content-Length"
到此,基本就清楚了,请求先经过阿里WAF和阿里nginx-ingress后,由nginx-ingress转发给前端的service,进而进入到pod,但是由于pod同一时间都在重启,暂时无法提供服务,service这一层就不知道pod的状态,nginx-ingress自然也就无法知道service的状态,于是便返回了503。等重启完毕后,就又正常提供服务,之所以偶发的出问题,原因就在这里。
于是便找了前端的开发leader去定位原因,最后他回复说,要改一个底层文件,兼容一下Content-Length为空的情况,改完后,简单在在测试环境和预发布环境测试一下,过一下核心主流程,没问题后,就上线了。
那灵魂一问来了,这个底层文件,从2021年来一直都没有改动过,也没出过啥事,为啥最近才开始出问题呢?
学习了
页:
[1]