换掉整段握手只省下 194 毫秒,剩下七成时间在等第一个字节
核对一批接口的耗时,习惯性先看总时间,越看越糊涂:同一个地址,有时 400 毫秒,有时 700 毫秒。 总时间是个混合指标,握手、发送、等待、接收全压在一个数里,看不出该改哪一段。
于是把它拆成四段量:域名解析、TCP、TLS、首字节。先用 curl 自带的计时粗看一遍:
curl -o /dev/null -w '%{time_namelookup} %{time_connect} %{time_appconnect} %{time_starttransfer}\n' \
https://bbs.huaweicloud.com/blogs
0.0265 0.0532 0.1195 0.4026
四个数依次是:解析 26 毫秒,TCP 连上 53 毫秒,TLS 握手结束 120 毫秒,第一个字节 403 毫秒。 注意第三和第四之间那一大段——从 120 到 403,中间 283 毫秒里我什么都没做,只是在等服务端把页面吐出来。
把「建连接」和「发请求」分开量
curl 一次只能盯着一条连接。要知道复用连接到底省多少,得自己控制套接字。用标准库写了个很小的探针: 先连四次,每次连完就关;再连一次,在同一条连接上连发四个请求。
c = http.client.HTTPSConnection(HOST)
c.connect() # 这一行包含解析 + TCP + TLS
for i in range(4):
t0 = time.perf_counter()
c.request("GET", "/blogs")
r = c.getresponse(); r.read()
print((time.perf_counter() - t0) * 1000)
量出来的数字是这样的(毫秒。握手那列是新连接从 connect 到握手完成,复用连接那列是 0):
| 方式 | 握手 | 发送 | 等首字节 | 总计 |
|---|---|---|---|---|
| 新连接 1 | 176.8 | 0.2 | 553.7 | 730.7 |
| 新连接 2 | 131.1 | 0.2 | 473.0 | 604.3 |
| 新连接 3 | 109.6 | 0.2 | 413.3 | 523.2 |
| 新连接 4 | 125.8 | 0.2 | 413.1 | 539.1 |
| 复用 1 | 0 | 0.2 | 423.4 | 423.6 |
| 复用 2 | 0 | 0.3 | 398.6 | 398.9 |
| 复用 3 | 0 | 0.3 | 390.9 | 391.2 |
| 复用 4 | 0 | 0.2 | 405.7 | 405.9 |
平均下来:新连接 599.3 毫秒,复用 404.9 毫秒,差 194.4 毫秒。 省下来的正好是握手那一段(四次均值 135.8 毫秒,加上两次调用之间的零碎开销)。
反常识的地方在「发送」那一列
我原本以为本机这一段是瓶颈。结果「发送」只有 0.2 毫秒——请求体就几百字节,写完马上返回。 握手 110 到 177 毫秒,占新连接总耗时的两成多;剩下七成多全在「等首字节」:390 到 554 毫秒。
换句话说,把连接复用做掉,一个请求省三分之一;但只要服务端算这个页面要 400 毫秒, 剩下那三分之二就永远省不掉。这也解释了我最早的困惑:总耗时在 400 到 730 之间晃, 晃的那部分主要是首字节,不是网络。
用两个比例来下判断
- 固定一行计时输出:
namelookup / connect / appconnect / starttransfer / total,别只看 total。 appconnect 减 connect是 TLS 那一段。超过 300 毫秒,去看证书链和会话复用。starttransfer 减 appconnect是服务端那一段。它超过总耗时的一半,优化方向就在服务端和缓存,不在网络。- 要连着打很多请求时优先复用连接:这里一次省 194 毫秒,六十次就是十一秒多。
最后一条自己踩出来的提醒:量出来的数别只比大小,要比比例。哪一段占多数,改动才落在点子上。 比例不看,改完只是从 730 变成 600,看着有进步,其实一直在错误的层上打转。
- 点赞
- 收藏
- 关注作者
评论(0)