使用 curl 来分析请求各个阶段的耗时

How

这个功能用到的是 curl 的 -w 选项，让我们来先看看 curl 的 man page：

-w, --write-out <format>
       Make curl display information on stdout after a completed transfer. The format is  a  string  that  may  contain lain  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 de‐ scribed below. All variables are specified as %{variable_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.

       The output will be written to standard output, but this can be switched to standard error by using %{stderr}.使用 curl 命令分析请求的耗时情况

下面的内容就是各种内置变量了，我们可以通过这些变量的值来一窥请求的真实信息。

以下有一个“广为流传”的格式：

    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

将如上内容写至 curl-format 文件中，然后在当前目录运行：

$ curl -w @curl-format -o /dev/null -s -L http://triplez.cn

• -w @curl-format ：使用 curl-format 文件模板进行输出。

• -o /dev/null ：忽略输出内容。

• -s ：不输出多余信息。

• -L ：支持跳转（如 HTTP 跳转至 HTTPS）。

就会看到像这样的输出：

    time_namelookup:  0.001931
       time_connect:  0.032337
    time_appconnect:  0.120072
      time_redirect:  0.000000
   time_pretransfer:  0.120124
 time_starttransfer:  0.151386
                    ----------
         time_total:  0.152068

这些变量的意义是：

• time_namelookup：DNS 域名解析的耗时。
• time_connect：TCP 连接建立耗时。
• time_appconnect：SSL/SSH 等上层协议建立连接的耗时，比如 connect/handshake 耗时（从此处也可看出，最后还是请求了 https://triplez.cn ，否则 HTTP 不会产生 time_appconnect 的耗时。
• time_redirect：从开始到最后一个请求事务的耗时。
• time_pretransfer：从请求开始到响应开始传输的耗时。
• time_starttransfer：从请求开始到第一个字节将要传输的耗时。
• time_total：这次请求的总耗时。

One more thing...

reorx 写了个 Python 的小工具 httpstat，让命令行分析请求耗时更加直观。通过以下命令即可安装：

$ pip install httpstat

让我们来试一下：

$ httpstat -L http://triplez.cn
Connected to 123.206.208.167:443 from 192.168.0.10:34372

HTTP/1.1 302 Found
Date: Mon, 11 May 2020 15:24:00 GMT
Server: Apache
Location: https://triplez.cn/
Content-Length: 203
Content-Type: text/html; charset=iso-8859-1

HTTP/1.1 200 OK
Date: Mon, 11 May 2020 15:24:00 GMT
Server: Apache
Last-Modified: Sun, 08 Mar 2020 07:48:35 GMT
ETag: "7258f-f13-5a0531d213ac0"
Accept-Ranges: bytes
Content-Length: 3859
Content-Type: text/html; charset=UTF-8

Body stored in: /tmp/tmpkeq3ospo

  DNS Lookup   TCP Connection   Server Processing   Content Transfer
[    32ms    |      66ms      |       73ms        |        1ms       ]
             |                |                   |                  |
    namelookup:32ms           |                   |                  |
                        connect:98ms              |                  |
                                      starttransfer:266ms            |
                                                                 total:267ms  

从输出上我们就可以很直观地看出来，从 http://triplez.cn 到 https://triplez.cn 中完成了一次 302 跳转，在输出末尾的示意图上我们也可以清楚地看到各阶段的耗时。

Happy hacking 😛

References

• 使用 curl 命令分析请求的耗时情况