记一次线上异常流程问题

问题起因

某日开始 "告警服务" 开始收到一些奇怪的报文,以下是日志

[notifier-web/index]page not found:/api/stat/rt/js?appId=20021&log=%7B%22ai%22%3A20021%2C%22dm%22%3A%22www.814aa.com%22%2C%22ul%22%3A%22https%3A%2F%2Fwww.814aa.com%2Fhtm%2Fmovieplay3%2F8465.htm%22%2C%22tt%22%3A%22%E5%A5%BD%E8%89%B2%E9%98%BF%E5%A6%88%E7%88%B1%E8%82%8F%E9%80%BC%20-%20%E6%AC%A7%E7%BE%8E%E7%B2%BE%E5%93%81%EF%BC%B7%EF%BC%B7%EF%BC%B7%EF%BC%8E%EF%BC%98%EF%BC%91%EF%BC%94%EF%BC%A1%EF%BC%A1%EF%BC%8E%EF%BC%A3%EF%BC%AF%EF%BC%AD%22%2C%22sn%22%3A%22360x640%22%2C%22cd%22%3A32%2C%22rr%22%3A%22%22%2C%22ua%22%3A%22Mozilla%2F5.0%20(Linux%3B%20Android%206.0.1%3B%20vivo%20Y66%20Build%2FMMB29M)%20AppleWebKit%2F537.36%20(KHTML%2C%20like%20Gecko)%20Version%2F4.0%20Chrome%2F38.0.2125.102%20Mobile%20Safari%2F537.36%20VivoBrowser%2F5.3.3%22%2C%22lg%22%3A%22zh-CN%22%2C%22ci%22%3A%2290e44ca7cbc7939f2936117d571495f8%22%2C%22clientType%22%3A%22android%22%2C%22sourceType%22%3A%22lianmeng%22%2C%22ii%22%3A%22tp%22%2C%22tp%22%3A16309%2C%22tm%22%3A1518339802%7D&v=1.0&sig=24fecb33225bd233b6a5cab1bb72687d

找了半天,这个接口并不是我们这边的
到处问人,才问到这个接口是xx专用链里面的上报的统计数据,就是本来会去 elt 服务的报文,被转发到我这了
但是为什么会到我这边,完全没有头绪

了解两个概念

1.专用链 这个xx专用链本质上就是一个js文件,其他服务网站想用xx服务的,直接在页面中嵌入这个js
2.网络架构 一个正常的报文大致流程是lvs集群 => nginx 集群 => 各个服务网关 => 微服务,nginx会根据请求的host域名负责负载均衡

寻求线索

1.
这种问题肯定不能在线上debug的,而且测试环境是不能复现的
只能倒推导报文的网络流程
首先仔细看 到 "alarm 服务"的异常报文中,竟然包含同样的Host字段

host: 112.80.23.202  

这个应该是客户端的ip,难道是被人扫描了?竟然都是同样的host
询问运维该ip是不是我们维护的机器ip
才知道这个ip 是xx的一台 lvs 机器ip
显然是有问题的,host应当携带域名,才能被nginx配置识别,转发过来的

2.
寻求运维协助,过滤nginx日志,看看真实来源ip是不是跟告警服务这边一致

proxy_set_header X-Real-IP $remote_addr;  
proxy_set_header X-Forwarded-For $proxy_add_x_forwarded_for;  

nginx 日志上面显示的ip 竟然也是 112.80.23.202

3.
很是怀疑nginx修改了网络包中ip,于是再去抓了 nginx集群 => 服务 这一层的报文

 tcpdump -i any host {{内网告警服务ip}} and port {{内网告警服务端口}} -vv -w /tmp/nginx-alarm.cap

流量量级太大了,所以只选择了一台nginx、一台内网告警服务,瞬间敲完命令,瞬间关闭
还是可以看到ip是 112.80.23.202

4
到这里问题定位已经卡住了,如果不能确定报文里 etl域名 什么 时候变成了 ip,就没办法知道具体原因
这时候换了思路又去报文里看了看,看见reffer字段,尝试顺向从源头看能不能复现问题

这里面注意,如果发现主网站是https,那么上报的请求协议会变成 https
我去过滤一下所有接收到的异常报文,发现reffer里面的网站都是强制使用https
alarm服务平均一台机器每秒接收到2条异常报文
也就是说某种状态下,使用xx专用链的网站上报etl服务出现了异常

5.
以此来看,很大程度上是用户访问使用的客户端出现了问题,为了验证这一点,还是需要知道lvs集群 => nginx集群,这一层发生了什么
最后还是得抓包确认问题,但是有两点需要注意
1. 量级太大
2. 报文https是加密的,需要解密

6.
为了解决问题,没办法,量大也只能在线上抓取,另外跟运维商量从线上拿了私钥证书准备解密
首先验证解密过程,监听本地(注意是自己的电脑)与 lvs 之间报文,尝试解密验证的时候,发现解密不了
最后终于在这篇文章中,找到了答案

ssl_ciphers "ECDHE-RSA-AES256-GCM-SHA384:ECDHE-RSA-AES128-GCM-SHA256:DHE-RSA-AES256-GCM-SHA384:DHE-RSA-AES128-GCM-SHA256:ECDHE-RSA-AES256-SHA384:ECDHE-RSA-AES128-SHA256:ECDHE-RSA-AES256-SHA:ECDHE-RSA-AES128-SHA:DHE-RSA-AES256-SHA256:DHE-RSA-AES128-SHA256:DHE-RSA-AES256-SHA:DHE-RSA-AES128-SHA:ECDHE-RSA-DES-CBC3-SHA:EDH-RSA-DES-CBC3-SHA:AES256-GCM-SHA384:AES128-GCM-SHA256:AES256-SHA256:AES128-SHA256:AES256-SHA:AES128-SHA:DES-CBC3-SHA:HIGH:!aNULL:!eNULL:!EXPORT:!DES:!MD5:!PSK:!RC4";  

上面是nginx其中一条配置,SSL Session使用了Diffie-Hellman加密算法,导致wireshark解不了密

7.
知道以上问题,选择了修改其中一台nginx服务器配置
(这个修改会导致线上https的服务暂时不可用,犹豫了很久才决策的)
抓取 lvs 到 nginx集群这一层报文
解密成功,找到了其中异常报文,发现其中的host ip竟然是112.80.23.202,这时候基本已经能确认是用户的"浏览客户端"有问题了,因为lvs是ios模型第四层网络层,是不会修改应用层host字段的

8.
继续找原因,查看是哪些"用户客户端"发包的,找到报文中的"UA"字段
发现竟然都是含有"OPPO"的字眼,但是手机型号类型是不一样的
根据型号找了一个跟日志中相同的手机浏览器测试

使用本地fillder抓包,但是抓包报文host显示正常

9.
最终找到原因。。

这里面有几个大坑:
这里面有个网络加速,会很大概率上将报文中host修改成ip,而且发生这种情况时候,fillder是抓不到https报文(应该是优化成了tcp链接由服务器发包),又不能多次修改线上nginx ssl服务,所以不能使用wireshark验证
验证采用直接访问网站url,在url加上一些特定的字符串如"12345678",然后去alarm日志里面过滤reffer 字段里面含有该特殊字符串的

后记

上报其实采用的使用google那一套,访问一个1px的图片,初步估计oppo是想优化图片下载
密码自己的,不对外公布