博客访问延迟分析

Jun 27, 2020 14:30 · 621 words · 2 minute read Network

利用 curl 计算出一个 HTTP 请求各过程所用的时间：

$ cat <<EOF > curl-format.txt
    time_namelookup:  %{time_namelookup}s\n
       time_connect:  %{time_connect}s\n
    time_appconnect:  %{time_appconnect}s\n
   time_pretransfer:  %{time_pretransfer}s\n
      time_redirect:  %{time_redirect}s\n
 time_starttransfer:  %{time_starttransfer}s\n
                    ----------\n
         time_total:  %{time_total}s\n
EOF
$ curl -w "@curl-format.txt" -o /dev/null -s https://blog.crazytaxii.com/
time_namelookup:  0.059940s
       time_connect:  0.081217s
    time_appconnect:  3.406447s
   time_pretransfer:  3.406546s
      time_redirect:  0.000000s
 time_starttransfer:  3.429021s
                    ----------
         time_total:  3.429266s
$ curl -w "@curl-format.txt" -o /dev/null -s https://blog.crazytaxii.com/
time_namelookup:  0.002146s
       time_connect:  0.024345s
    time_appconnect:  3.359812s
   time_pretransfer:  3.359894s
      time_redirect:  0.000000s
 time_starttransfer:  3.382175s
                    ----------
         time_total:  3.382401s
$ curl -w "@curl-format.txt" -o /dev/null -s https://blog.crazytaxii.com/
time_namelookup:  0.002049s
       time_connect:  0.029671s
    time_appconnect:  3.380179s
   time_pretransfer:  3.380329s
      time_redirect:  0.000000s
 time_starttransfer:  3.405146s
                    ----------
         time_total:  3.405392s

总共用时 3.4 秒左右，但是绝大部分时间都消耗在了连接（TCP 握手 + TLS 握手）的过程。

通过 ping 实例 IP 可以排除掉网路问题：

$ ping blog.crazytaxii.com
PING blog.crazytaxii.com (47.97.185.8): 56 data bytes
64 bytes from 47.97.185.8: icmp_seq=0 ttl=50 time=31.035 ms
64 bytes from 47.97.185.8: icmp_seq=1 ttl=50 time=27.652 ms
64 bytes from 47.97.185.8: icmp_seq=2 ttl=50 time=29.349 ms
64 bytes from 47.97.185.8: icmp_seq=3 ttl=50 time=22.783 ms
64 bytes from 47.97.185.8: icmp_seq=4 ttl=50 time=28.454 ms
64 bytes from 47.97.185.8: icmp_seq=5 ttl=50 time=35.859 ms
64 bytes from 47.97.185.8: icmp_seq=6 ttl=50 time=30.060 ms

服务器本身在上海，20-30ms 的延迟很正常。

通过 https://www.ipip.net/ip.html 查询出运营商 NAT 后的公网 IP 为 223.64.145.37。

curl 的同时在实例上抓来自 223.64.145.37 的包 tcpdump -i eth0 port 443 and host 223.64.145.37 -w foo.pcap

用 Wireshark 打开 pcap 文件，不用说 123 行就是 TCP 三次握手，出现明显延迟的地方在第 8 行，也就是 SSL 握手过程中交换客户端密钥的步骤。

当 Server Hello Done 结束后客户端会去 CA 校验博客服务器发来的证书链。blog.crazytaxii.com 所使用的 SSL 证书由 Let’s Encrypt 签发。

我们继续在客户端抓包：

发现客户端在拿到博客服务器发来的证书链后与 isrg.trustid.ocsp.identrust.com 有数据交互，去来花了 1 秒多，而 OSCP 正是用来实时查询证书状态的协议，这个过程造成了非常大的延迟。

$ nslookup isrg.trustid.ocsp.identrust.com
Server:		119.28.28.28
Address:	119.28.28.28#53

Non-authoritative answer:
isrg.trustid.ocsp.identrust.com	canonical name = isrg.trustid.ocsp.identrust.com.edgesuite.net.
isrg.trustid.ocsp.identrust.com.edgesuite.net	canonical name = a279.dscq.akamai.net.
Name:	a279.dscq.akamai.net
Address: 223.119.248.10
Name:	a279.dscq.akamai.net
Address: 223.119.248.26
Name:	a279.dscq.akamai.net
Address: 2600:1417:76::17c7:223a
Name:	a279.dscq.akamai.net
Address: 2600:1417:76::17d2:d739

isrg.trustid.ocsp.identrust.com 背后是 akamai CDN，我们知道 CDN 系统的缓存从边缘节点到中心层层递进的，如果无法命中缓存，就会往上一层缓存去查询，如果都没有命中，只能回源，反而因为多次无效查询造成了更大的延迟。

查看更多