PHP 接口偶尔耗时 5s、10s，但 PHP 无复杂逻辑，都是直接通过 curl 调用 Java 服务返回相应内容。遂查看了对应 Java 服务，并无耗时 5s、10s 的接口。
于是在 curl_exec() 后，通过 curl_getinfo() 获取 curl 详细信息，发现超时请求的 namelookup_time 时间刚好是 5s、10s。
| 字段 | 含义 |
|---|---|
| namelookup_time | 域名解析到 ip 所耗费的时间 |
| connect_time | 建立连接所消耗的时间 |
| pretransfer_time | 从建立连接到准备传输所使用的时间 |
| starttransfer_time | 从建立连接到传输开始所使用的时间 |
| total_time | 从开始到最后一次传输所消耗的时间 |
从返回的结果看，是域名解析存在问题。
登录到测试服务器，通过 tcpdump -w curl_tcpdump.cap 记录下一段时间内的网络请求数据，并通过 wireshark 打开文件，通过搜索 dns.time > 2 and dns.qry.name contains "youhostname" 查询到指定域名解析耗时大于2s的 dns 请求，dns 请求耗时长的时候正好是接口访问耗时的时候。
但为什么 php 通过 curl 调用会发生域名解析慢，java 服务之间调用却是正常的呢（网络同事还是认为是开发同事原因）？
通过写两段测试程序，放到测试服务器，通过 strace -p pid 和 tcpdump 继续分析。
PHP 程序
<?php
set_time_limit(0);
error_reporting(E_ALL);
$url = "http://youhostname";
$start = date("y-m-d H:i:s");
$end = strtotime("+10 minutes", $start);
$count = 0;
while (true) {
curlPost($url);
sleep(0.001);
if (strtotime() >= $end) {
break;
}
$count;
}
function curlPost($url, $data = null)
{
$ret = false;
$ch = curl_init($url);
curl_setopt($ch, CURLOPT_CUSTOMREQUEST, "POST");
curl_setopt($ch, CURLOPT_POSTFIELDS, $data);
curl_setopt($ch, CURLOPT_RETURNTRANSFER, true);
curl_setopt($ch, CURLOPT_TIMEOUT, 60);
curl_setopt($ch, CURLOPT_IPRESOLVE, CURL_IPRESOLVE_V4);
$headers = array(
'Content-Type: application/json',
'Content-Length: ' . strlen($data),
'Expect:'
);
curl_setopt($ch, CURLOPT_HTTPHEADER, $headers);
$ret = curl_exec($ch);
$curl_info = curl_getinfo($ch);
logInfo($curl_info);
curl_close($ch); // 关闭CURL会话
return $ret;
}
function logInfo($content) {
$file = 'curl_info.txt';
file_put_contents($file, date("y-m-d H:i:s").' '.json_encode($content).PHP_EOL, FILE_APPEND);
}
执行/usr/local/bin/php curl.php 并查通过 strace -p php_pid 查看系统调用实际过程，可以看到系统发送 查询 dns 请求后在 poll 等待事件阶段超时了。
Java 程序
@Test
void useHttpClient() {
httpClientService.useHttpClient("youhostname");
httpClientService.useHttpClient("youhostname");
httpClientService.useHttpClient("youhostname");
}
public void useHttpClient(String url){
CloseableHttpClient closeableHttpClient = HttpClients.createDefault();
HttpPost httpPost = new HttpPost(url);
httpPost.setHeader("Content-Type","application/json");
long startTimeMillis = System.currentTimeMillis();
try {
closeableHttpClient.execute(httpPost);
long endTimeMillis = System.currentTimeMillis();
long time = endTimeMillis - startTimeMillis;
if (time > 2000) {
log.error("耗时：{} {}", time + "ms", url);
} else {
log.info("耗时：{} {}", time + "ms", url);
}
} catch (Exception e) {
long endTimeMillis = System.currentTimeMillis();
log.error("耗时：{} {}, e:{}", (endTimeMillis - startTimeMillis) + "ms", url, e);
}
}
通过 strace 和 tcpdump分析，虽然 httpclient 对象每次都初始化，但域名解析只发生了一次，也就是说域名解析成功后，java 缓存了解析结果。
修改 java 程序，让每 0.02 s 执行一次远程调用，通过 dns.qry.name contains "youhostname" 发现大概 30s 会重新域名解析一次。
结果
- 通过 curl_getinfo() 可以获取到 curl 请求各阶段的耗时
- 通过 strace 可以看到 php 和 java 远程调用的系统调用都是一样的，先域名解析，然后连接连接，发送数据
- php 的 curl 每次都会重新域名解析，没有缓存，所以正常情况下会比 java 耗时。java 正常情况还会通过 http 连接池，这样就省得更多了。
- 为什么域名解析会不稳定，偶尔用时 5s，还是没找到。通过
time nslookup youhostname也可以偶尔看到实际域名解析的时间。
