记一次线上问题及反思

1,085 阅读4分钟

背景介绍

我们团队是做程序化广告的,我所在小组主要做 DSP 方向,对接外部 ADX,提供广告检索服务(对广告系统不熟悉的不要着急,后面有时间会给大家分享广告相关的文章)

10 月 21 日上线了一个支持头条的需求,其实主要就是在展示和点击监控链接中增加了一个,比如请求 url 为:xxx.com/n/d/?fid=aaa&h_oaid={OAID},当我们的广告竞价成功后一般就会展示到头条上,当广告展示后,头条会给我们发送展示通知,如果用户点击后,也会给我们发送点击通知,这样我们就可以根据这些回调进行计费。但当我晚上上完线后,陆续收到了线上报警,广告曝光比前一天同时刻下降超过 50 % 的报警。以为是上线波动导致,就继续上线了,半夜十二点左右报警越来越频繁 ......

排查过程

10 月 21 日 半夜

通过看监控平台,发现获胜数据是正常的,只是展示和点击出了问题,然后看业务日志(其实我们排查的过程有问题,应该先看 tomcat 请求日志的),发现头条的展示和点击回调没有请求过来,但这次需求只是在 url 中增加了 h_oaid={OAID}的宏呀,难道是它影响了?

此时可以回滚的,可是回滚比较麻烦,我们采取的方式是把本次上线的宏去掉后重新上了一版,发现问题解决了,至少止损了,先睡觉吧,第二天再排查

10 月 22 日

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.团队的力量是强大的,期间非常感谢我的队友们的支持

欢迎关注公众号 【每天晒白牙】,获取最新文章,我们一起交流,共同进步!