PHP 接口偶爾耗時 5s、10s模蜡，但 PHP 無復(fù)雜邏輯漠趁，都是直接通過 curl 調(diào)用 Java 服務(wù)返回相應(yīng)內(nèi)容。遂查看了對應(yīng) Java 服務(wù)忍疾，并無耗時 5s闯传、10s 的接口。
于是在 curl_exec() 后卤妒，通過 curl_getinfo() 獲取 curl 詳細信息甥绿，發(fā)現(xiàn)超時請求的 namelookup_time 時間剛好是 5s字币、10s。
| 字段 | 含義 |
|---|---|
| namelookup_time | 域名解析到 ip 所耗費的時間 |
| connect_time | 建立連接所消耗的時間 |
| pretransfer_time | 從建立連接到準備傳輸所使用的時間 |
| starttransfer_time | 從建立連接到傳輸開始所使用的時間 |
| total_time | 從開始到最后一次傳輸所消耗的時間 |
從返回的結(jié)果看共缕，是域名解析存在問題洗出。
登錄到測試服務(wù)器，通過 tcpdump -w curl_tcpdump.cap 記錄下一段時間內(nèi)的網(wǎng)絡(luò)請求數(shù)據(jù)图谷，并通過 wireshark 打開文件翩活，通過搜索 dns.time > 2 and dns.qry.name contains "youhostname" 查詢到指定域名解析耗時大于2s的 dns 請求，dns 請求耗時長的時候正好是接口訪問耗時的時候便贵。
但為什么 php 通過 curl 調(diào)用會發(fā)生域名解析慢菠镇，java 服務(wù)之間調(diào)用卻是正常的呢（網(wǎng)絡(luò)同事還是認為是開發(fā)同事原因）？
通過寫兩段測試程序承璃，放到測試服務(wù)器利耍，通過 strace -p pid 和 tcpdump 繼續(xù)分析。
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); // 關(guān)閉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);
}
執(zhí)行/usr/local/bin/php curl.php 并查通過 strace -p php_pid 查看系統(tǒng)調(diào)用實際過程绸硕，可以看到系統(tǒng)發(fā)送 查詢 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 對象每次都初始化玻佩，但域名解析只發(fā)生了一次，也就是說域名解析成功后席楚，java 緩存了解析結(jié)果咬崔。
修改 java 程序，讓每 0.02 s 執(zhí)行一次遠程調(diào)用烦秩，通過 dns.qry.name contains "youhostname" 發(fā)現(xiàn)大概 30s 會重新域名解析一次垮斯。
結(jié)果
- 通過 curl_getinfo() 可以獲取到 curl 請求各階段的耗時
- 通過 strace 可以看到 php 和 java 遠程調(diào)用的系統(tǒng)調(diào)用都是一樣的，先域名解析只祠，然后連接連接兜蠕，發(fā)送數(shù)據(jù)
- php 的 curl 每次都會重新域名解析，沒有緩存抛寝，所以正常情況下會比 java 耗時熊杨。java 正常情況還會通過 http 連接池，這樣就省得更多了盗舰。
- 為什么域名解析會不穩(wěn)定晶府，偶爾用時 5s，還是沒找到钻趋。通過
time nslookup youhostname也可以偶爾看到實際域名解析的時間川陆。
