使用curl命令分析請(qǐng)求的耗時(shí)情況
最近工作中遇到一個(gè)問(wèn)題,某個(gè)請(qǐng)求的響應(yīng)特別慢,因此我就希望有一種方法能夠分析到底請(qǐng)求的哪一步耗時(shí)比較長(zhǎng),好進(jìn)一步找到問(wèn)題的原因。在網(wǎng)絡(luò)上搜索了一下,發(fā)現(xiàn)了一個(gè)非常好用的方法, curl 命令就能幫你分析請(qǐng)求的各個(gè)部分耗時(shí)。
curl 命令提供了 -w 參數(shù),這個(gè)參數(shù)在 manpage 是這樣解釋的:
- -w, --write-out
- Make curl display information on stdout after a completed transfer. The format is a string that may contain plain text mixed with any number of variables. The format
- can be specified as a literal "string", or you can have curl read the format from a file with "@filename" and to tell curl to read the format from stdin you write
- "@-".
- The variables present in the output format will be substituted by the value or text that curl thinks fit, as described below. All variables are specified as %{vari‐
- able_name} and to output a normal % you just write them as %%. You can output a newline by using \n, a carriage return with \r and a tab space with \t.
它能夠按照指定的格式打印某些信息,里面可以使用某些特定的變量,而且支持 \n 、 \t 和 \r 轉(zhuǎn)義字符。提供的變量很多,比如 status_code 、 local_port 、 size_download 等等,這篇文章我們只關(guān)注和請(qǐng)求時(shí)間有關(guān)的變量(以 time_ 開(kāi)頭的變量)。
先往文本文件 curl-format.txt 寫(xiě)入下面的內(nèi)容:
- ➜ ~ cat curl-format.txt
- time_namelookup: %{time_namelookup}\n
- time_connect: %{time_connect}\n
- time_appconnect: %{time_appconnect}\n
- time_redirect: %{time_redirect}\n
- time_pretransfer: %{time_pretransfer}\n
- time_starttransfer: %{time_starttransfer}\n
- ----------\n
- time_total: %{time_total}\n
那么這些變量都是什么意思呢?我解釋一下:
- time_namelookup :DNS 域名解析的時(shí)候,就是把 https://zhihu.com 轉(zhuǎn)換成 ip 地址的過(guò)程
- time_connect :TCP 連接建立的時(shí)間,就是三次握手的時(shí)間
- time_appconnect :SSL/SSH 等上層協(xié)議建立連接的時(shí)間,比如 connect/handshake 的時(shí)間
- time_redirect :從開(kāi)始到***一個(gè)請(qǐng)求事務(wù)的時(shí)間
- time_pretransfer :從請(qǐng)求開(kāi)始到響應(yīng)開(kāi)始傳輸?shù)臅r(shí)間
- time_starttransfer :從請(qǐng)求開(kāi)始到***個(gè)字節(jié)將要傳輸?shù)臅r(shí)間
- time_total :這次請(qǐng)求花費(fèi)的全部時(shí)間
我們先看看一個(gè)簡(jiǎn)單的請(qǐng)求,沒(méi)有重定向,也沒(méi)有 SSL 協(xié)議的時(shí)間:
- ➜ ~ curl -w "@curl-format.txt" -o /dev/null -s -L "http://cizixs.com"
- time_namelookup: 0.012
- time_connect: 0.227
- time_appconnect: 0.000
- time_redirect: 0.000
- time_pretransfer: 0.227
- time_starttransfer: 0.443
- ----------
- time_total: 0.867
可以看到這次請(qǐng)求各個(gè)步驟的時(shí)間都打印出來(lái)了,每個(gè)數(shù)字的單位都是秒(seconds),這樣可以分析哪一步比較耗時(shí),方便定位問(wèn)題。這個(gè)命令各個(gè)參數(shù)的意義:
- -w :從文件中讀取要打印信息的格式
- -o /dev/null :把響應(yīng)的內(nèi)容丟棄,因?yàn)槲覀冞@里并不關(guān)心它,只關(guān)心請(qǐng)求的耗時(shí)情況
- -s :不要打印進(jìn)度條
從這個(gè)輸出,我們可以算出各個(gè)步驟的時(shí)間:
- DNS 查詢:12ms
- TCP 連接時(shí)間:pretransfter(227) - namelookup(12) = 215ms
- 服務(wù)器處理時(shí)間:starttransfter(443) - pretransfer(227) = 216ms
- 內(nèi)容傳輸時(shí)間:total(867) - starttransfer(443) = 424ms
來(lái)個(gè)比較復(fù)雜的,訪問(wèn)某度首頁(yè),帶有中間有重定向和 SSL 協(xié)議:
- ➜ ~ curl -w "@curl-format.txt" -o /dev/null -s -L "https://baidu.com"
- time_namelookup: 0.012
- time_connect: 0.018
- time_appconnect: 0.328
- time_redirect: 0.356
- time_pretransfer: 0.018
- time_starttransfer: 0.027
- ----------
- time_total: 0.384
可以看到 time_appconnect 和 time_redirect 都不是 0 了,其中 SSL 協(xié)議處理時(shí)間為 328-18=310ms 。而且 pretransfer 和 starttransfer 的時(shí)間都縮短了,這是重定向之后請(qǐng)求的時(shí)間。