背景介绍
我们团队是做程序化广告的,我所在小组主要做 DSP 方向,对接外部 ADX,提供广告检索服务(对广告系统不熟悉的不要着急,后面有时间会给大家分享广告相关的文章)
10 月 21 日上线了一个支持头条的需求,其实主要就是在展示和点击监控链接中增加了一个宏,比如请求 url 为:xxx.com/n/d/?fid=aaa&h_oaid={OAID},当我们的广告竞价成功后一般就会展示到头条上,当广告展示后,头条会给我们发送展示通知,如果用户点击后,也会给我们发送点击通知,这样我们就可以根据这些回调进行计费。但当我晚上上完线后,陆续收到了线上报警,广告曝光比前一天同时刻下降超过 50 % 的报警。以为是上线波动导致,就继续上线了,半夜十二点左右报警越来越频繁 ……
通过看监控平台,发现获胜数据是正常的,只是展示和点击出了问题,然后看业务日志(其实我们排查的过程有问题,应该先看 tomcat 请求日志的),发现头条的展示和点击回调没有请求过来,但这次需求只是在 url 中增加了 h_oaid={OAID}的宏呀,难道是它影响了?
此时可以回滚的,可是回滚比较麻烦,我们采取的方式是把本次上线的宏去掉后重新上了一版,发现问题解决了,至少止损了,先睡觉吧,第二天再排查
22 号到了公司开始联系头条方希望能够一起排查下,因为我们怀疑是链接中新增加了宏,可能头条方没有给我们发起回调,我们给对方提供了一些唯一请求标识,经过一段时间的排查和沟通,发现头条确实给我们发了回调请求,但是他们没有把宏给替换,所以返回的 url 请求中依然带着 {OAID} 这个宏,而且我们返回的状态码是 400,重点来了。我们猜测难道是特殊字符 { 和 }影响了?(这里也暴露了一些知识点的匮乏),赶紧查看 tomcat 的日志,果不其然,日志早就已经说明了问题,只是一直没关注系统系统,光看业务日志了。
tomcat日志异常
通过异常信息,我们可以知道是特殊字符违反了 RFC 规范,所以我们把 {OAID} 去掉后解决了问题,正常应该是头条帮我们把宏替换掉的,这样就不会有违反规范的特殊字符,请求也就可以正常响应了
通过查资料,我们发现 tomcat 的一些版本还是允许请求 url 中带有 |,{,} 这三个特殊字符的,只是需要修改下配置文件,如下
tomcat.util.http.parser.HttpParser.requestTargetAllow=|{}
规范
该配置在 tomcat 一下版本生效
- 8.5.x for 8.5.12 onwards
- 8.0.x for 8.0.42 onwards
- 7.0.x for 7.0.76 onwards
我们线上的 tomcat 版本是符合的,只是我们没有采取这种修改配置文件的方法,只是先把宏给去掉了,等头条上线最新的替换宏的代码,我们再次上线
当然后面我们从运维团队要到了出问题时间段的 nginx 请求日志,过滤出有问题的请求,然后重新跑数计算影响了多少数据,这个重新跑数的过程也需要扎实的 linux 基础和对业务的深入理解,因为最开始对业务理解不足,跑的数据是有问题的。
前面说的有些啰嗦了,其实就是请求 url 中带有特殊字符,违反了 RFC 规范,导致返回 400 状态码,这暴露出该知识点处在我的知识盲区,而且应该早些查看 tomcat 系统日志,而不是一直关注业务日志,毕竟请求进入到 tomcat 后,才会有业务日志。
经过这次线上问题,总结下我的反思
1.一定要敬畏线上报警短信,既然报警一定是有原因的 2.自测的时候,多测试一些 bad case ,当然这也取决于自己的知识点和经验 3.排查问题,不能太依赖业务日志,要遵循一些流程,从根源查找问题原因 4.在对接外部系统时,一定要沟通好,考虑全面些 5.不断完善自己的知识库,当然这也需要不断踩坑的经验积累 6.要对业务深入理解才能写出正确的代码 7.团队的力量是强大的,期间非常感谢我的队友们的支持