前一段时间上线了一个新功能,需要和其他公司的业务进行对接,对方服务部署在阿里云上。
后来发现一些接口经常会出现超时的情况。但是经对方开发人员排查,他们的接口没有任何问题,可以正常返回数据
后续我们针对日志进行详细排查,发现从请求开始,到发现超时报错,时间大概在15s左右,或15s的倍数
我使用Curl语句直接访问对方公网域名,Curl语句上加上输出时间变量的参数,方便观察
关于Curl语句可以使用的参数可以参考官方文档: Curl官方帮助文档
这里我使用的命令是:
curl -w ’ time_namelookup: %{time_namelookup}\n time_connect: %{time_connect}\n time_appconnect: %{time_appconnect}\n time_pretransfer: %{time_pretransfer}\n time_total: %{time_total}\n time_starttransfer: %{time_starttransfer}\n’ ‘http://xxx.xxx.xxx/’
多次调用后的到失败结果:
time_namelookup: 0.012339 time_connect: 15.413093 time_appconnect: 0.000000 time_pretransfer: 15.413238 time_total: 0.000000 time_starttransfer: 15.445295
time_namelookup: 0.012377 time_connect: 32.079944 time_appconnect: 0.000000 time_pretransfer: 32.080012 time_total: 32.112682 time_starttransfer: 32.112509
其中time_connect表示的是TCP连接的时间,三次握手的时间 time_pretransfer表示的是从请求开始到响应开始传输的时间
可以看到,三次握手的时间较长,而达到15s或30s左右时,直接返回了超时响应,当时我们怀疑是一些网络配置问题,故将问题反馈给运维团队,经排查,是阿里云SLB有个空闲连接超时时间,之前设置的是15S。将时间改为了60s后,恢复了正常
通过这次问题排查,主要是了解了可以通过Curl语句查看请求过程中各部分的耗时情况,学习了一下Curl语句数据时间变量信息,之后再遇到类似问题可以更快速的进行排查并迅速定位问题