如何查看HTTP请求耗时

HTTP 请求流程

一次完整的 HTTP 请求流程主要包括以下几个阶段：

域名解析

当 HTTP 请求的是域名时，需要先进行域名解析，将域名转换为 IP 地址后再进行网络连接。

域名解析的流程涉及查询操作系统 DNS 缓存、请求外部 DNS 服务器解析等，最终得到域名对应的 IP 地址。

建立 TCP 连接

当客户端拿到目标的 IP 地址后，就向目标发起建立 TCP 连接的请求，即 TCP 的三次握手，结束后即完成了 TCP 连接的建立。

建立 SSL/TLS 连接

当请求的协议是 HTTPS 时，需要先与目标建立 SSL/TLS 连接，通过获得的秘钥对后续的通信消息进行加密。

发送 HTTP 消息

发送具体的 HTTP 请求消息体，等待目标服务器返回。

服务器响应并返回

发送具体的 HTTP 请求消息体，等待目标服务器返回。

当我们在实际业务中发现某个 HTTP 请求响应非常慢时，就需要分析是上述哪个阶段的耗时较长，本文介绍两种方式来查看 HTTP 请求流程中各个阶段的耗时情况。

Node.js 查看请求耗时

事件 Event

在 Node.js 中，一个 http 请求的各个阶段是通过事件来定义的，即到达某个阶段后就会抛出对应的时间，我们可以通过监听这些事件，然后进行逻辑处理，从而实现统计各个阶段的耗时。

相关事件及对应的模块如下：

阶段	事件	模块	触发时机
创建一个 socket 对象	socket	http.ClientRequest	当一个 socket 对象被分配给当前 request 对象之后
域名解析	lookup	net.Socket	完成域名解析之后，建立连接之前
建立 TCP 连接	connect	net.Socket	当 socket 连接建立完成之后
建立 TLS 连接	secureConnect	tls.TLSSocket	TLS 连接握手完成之后
服务器开始返回消息	readable	stream.Readable	当 response 中的数据可读时
服务器返回数据	data	stream.Readable	当 response 中有一块数据可以被读取时
服务器完成返回	end	stream.Readable	当 response 中没有数据可被读取时

一个例子：app.js

request 模块

request 模块已经提供了成熟的统计 HTTP 请求耗时的功能，只需要在 options 中配置 time 字段为 true 即可：

const request = require('request');

const url = 'https://www.baidu.com';
const options = {
  url, method: 'GET', time: true,
};
request(options, (error, response) => {
  if (error) {
    console.error(error);
  }
  console.log(response.timings);
  console.log(response.timingPhases);
});

输出结果如下：

{ socket: 34.420195999999976,
  lookup: 47.29232500000006,
  connect: 63.71983800000004,
  response: 128.208279,
  end: 131.76554800000002 }
{ wait: 34.420195999999976,
  dns: 12.872129000000086,
  tcp: 16.427512999999976,
  firstByte: 64.48844099999997,
  download: 3.5572690000000193,
  total: 131.76554800000002 }

可以看到，response.timings 统计了各个阶段的时间戳，response.timingPhases 统计了各个阶段的耗时。

注意：低版本的 request 模块可能不具备该功能。

curl 查看请求耗时

curl 指令是一个功能非常强大的指令，也可以统计 HTTP 请求各个阶段的耗时，使用如下：

curl -o /dev/null -s -w "time_namelookup: %{time_namelookup}\ntime_connect: %{time_connect}\ntime_appconnect: %{time_appconnect}\ntime_redirect: %{time_redirect}\ntime_pretransfer: %{time_pretransfer}\ntime_starttransfer: %{time_starttransfer}\ntime_total: %{time_total}\n" "https://www.baidu.com"

参数解析：

• -o /dev/null 把返回值丢掉，不用输出
• -s 静默输出，不输出进度条
• -w 按指定格式打印信息，其中包含一些特定的参数：
  • time_namelookup：从开始到域名解析完成时的耗时
  • time_connect：从开始到 TCP 连接建立完成的耗时
  • time_appconnect：从开始到 TLS 连接建立完成的耗时
  • time_redirect：多次重定向（如果有）的耗时
  • time_pretransfer：从开始到准备发送请求消息前的耗时
  • time_starttransfer：从开始到服务器准备返回第一个字节时的耗时
  • time_total：整个 HTTP 请求操作耗时

输出结果如下：

time_namelookup: 0.002275
time_connect: 0.013750
time_appconnect: 0.039952
time_redirect: 0.000000
time_pretransfer: 0.040041
time_starttransfer: 0.051713
time_total: 0.135286

通过上述输出，我们可以计算出各个步骤的时间，例如：

• DNS 解析：2ms
• TCP 连接：time_connect(13ms) - time_namelookup(2ms) = 11ms
• 服务器处理：time_starttransfer(51ms) - time_pretransfer(40ms) = 11ms