如何解决一个偶现的503 bug?

lsekfe

概述
　　突然被人在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 [ERR_HTTP_INVALID_HEADER_VALUE]: 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年来一直都没有改动过，也没出过啥事，为啥最近才开始出问题呢?

oliver.tang

学习了