记一次网络请求耗时问题分析解决过程

一、问题背景

两个月前的一个版本需要对接腾讯会议相关接口,需要接收腾讯会议事件变更回调,腾讯会议通过webhook的形式发送http请求到我们的测试环境服务中,暂且称之为A服务,假设域名为a.test.abc.com

在保存接口配置的时候,腾讯会议对接口url进行可用性的校验,3秒内进行响应,并正确返回即可进行配置。

二、问题现象

在配置的过程中出现了异常提示,无法正常保存配置,反复操作十几次后,才正常保存成功一次(具体原因可参考文末第五节)。如图所示:

三、问题排查

1.排查接口是否存在复杂逻辑

  • 接口是简单的GET请求返回base64解码后的字符串,没有做任何特殊处理。
  • 排查controller层发现无特殊的aop耗时逻辑。
  • 在本地电脑上使用Postman模拟请求,无论是公司内网或者外网调用接口响应时间都很快,均在200ms内响应。

2.与相关方收集接口请求数据

与腾讯会议后端负责人沟通,腾讯后端负责人排查日志发现,腾讯会议后端发起http调用A服务测试环境url超时

3.临时解决方案

为了避免影响送测,我们临时在线上阿里云服务上的某个服务做了一层请求中转,让腾讯云把请求打到了线上服务,线上服务通过okhttp发起第二次http请求转发到测试服务中。

经过这层中转临时解决了问题,实现了业务正常回调。

可是对于测试环境来说,阿里云线上的服务器一样是外网环境,为什么我们的服务调用测试环境没有问题,而腾讯的服务调用就超时呢?文末第五节有谈到问题解析

4.排查网络链路问题

排查链路问题之前,尝试用自己的服务器和线上服务器部署了简单的web服务,提供回调接口,均可正常配置。基本可以确定腾讯会议服务访问A服务测试环境存在耗时问题

4.1模拟外网请求测试环境接口,查看耗时

使用curl模拟外网请求测试环境接口,打印各个环节耗时:

  • 选择阿里云多台容器测试
  • 使用腾讯云服务器测试

可以发现,在域名查找(time_namelookup)这个环节耗费了绝大部分时间。

而tcp连接、http请求响应、数据传输的环节耗时非常低,均在200ms左右。

curl代码示例

curl -w "time_namelookup:%{time_namelookup}\ntime_connect:%{time_connect}\ntime_pretransfer:%{time_pretransfer}\ntime_starttransfer:%{time_starttransfer}\ntime_total:%{time_total}\n" -o /dev/null -s -L  "https://a.test.abc.com/server-main/api/v1/meeting/disable/callback?check_str=xxx(此处填上url)"

curl部分参数对应关系

4.2观察服务入口流量

使用tcpdump对A服务流量入口进行抓包操作,将日志dump到本地,使用wireshark进行分析可以发现。从建立TCP连接开始到发起http请求,耗时确实很低,与上面打印的时间相符

tcpdump命令

tcpdump   -i  eth0  -s  0  -w  tcp.pcap

4.3观察外网调用方发起http请求的流量详情

依然通过tcpdump进行抓包和分析,可以发现,仅使用0.3ms,dns服务器就已经返回了域名对应的ip地址。但是完成这步操作之后,客户端没有开始建立tcp连接,而是继续查找AAAA a.test.abc.com的操作,而这一步耗时长达5秒多,完全符合4.1中的耗时情况。

此处query AAAA的操作为查找ipv6地址,每一次curl请求都发出了两次DNS query,一个是A记录,另外一个是AAAA记录,也就是同时请求了IPV4和IPV6地址。IPV4很快就返回了结果,而IPV6则常常耗时长达5秒(IPV6请求会被forward到upstream的DNS),且最终返回NXDomain无IP结果。

4.4验证问题

对curl请求加上-4参数,直接使用Ipv4地址进行请求,验证是否是ipv6地址查询耗时导致。确实非常快得到了响应。至此,问题已经被验证。

四、解决方案

带着问题和数据包,向运维求助。最终由运维的同事针对.test.abc.com的泛cname做ipv6的假响应配置*,即不做任何处理,直接返回NXDomain。问题得到解决。

五、过程遇到的其他问题

1.阿里云线上环境请求测试环境也存在耗时的情况,那为什么在临时解决方案中使用了中转服务可以正常使用呢?

定位okhttp的源码可以发现,okhttp会解析http请求url的域名,在域名第一次请求获取ip的时候,将域名和ip进行一一对应的缓存,并且这个缓存操作与操作系统级别的dns缓存不同,是没有过期时间的

所以可能会存在第一次请求的时候耗时较长的情况。但是经过第一次请求后,后面发起的http请求都是直接用ip地址进行请求,无需再次解析。

代码位置:java.net.InetAddress#getAllByName0(java.lang.String, java.net.InetAddress, boolean)

2.腾讯会议服务多次保存只有少数次可以成功

猜测依然是与上面一样存在ip缓存的机制,由于现在绝大部分web服务都是分布式地部署多台容器,多次http请求中,只要有两次走到了同一台机器上,即可使用组件缓存的ip地址直接请求。

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 204,921评论 6 478
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 87,635评论 2 381
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 151,393评论 0 338
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 54,836评论 1 277
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 63,833评论 5 368
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 48,685评论 1 281
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 38,043评论 3 399
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 36,694评论 0 258
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 42,671评论 1 300
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 35,670评论 2 321
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 37,779评论 1 332
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 33,424评论 4 321
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 39,027评论 3 307
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 29,984评论 0 19
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 31,214评论 1 260
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 45,108评论 2 351
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 42,517评论 2 343

推荐阅读更多精彩内容