服务器日志和chrome开发人员工具中的响应时间之间存在差异

Question

我正在对一个站点进行负载测试,并注意到我从Web服务器(在这种情况下,龙卷风Web服务器)和Chrome开发者工具收到的时间信息之间存在相当大的差异.Web服务器提供一个作为进程运行的服务(实际上,由主管管理的几个进程)在nginx后面.还有一个与此服务交互的Web界面.这个龙卷风Web服务器可以相当快地检索查询(平均30毫秒).但是,Chrome开发者工具显示的响应时间要慢得多(大约240毫秒).

每个查询都会检索一些信息,并需要查询其他资源(主要是图像).我认为这是造成这么大差异的主要原因,但我尝试使用curl并time_starttransfer测量172ms.

另一方面,对nginx使用此日志记录指令:

log_format timed_combined '$remote_addr - $remote_user [$time_local] '
    '"$request" $status $body_bytes_sent '
    '"$http_referer" "$http_user_agent" '
    '$request_time $upstream_response_time $pipe';

我能够检查它request_time并且upstream_response_time实际上非常小(45毫秒).

可能是造成这种响应时间差异的原因是什么？

UPDATE

这是Firebug的截图:

我不认为我可以用有限的信息找出延迟.

更新2

我能够通过curl获得更好的信息.不过我不确定它是否准确:

    time_namelookup:  0.000
       time_connect:  0.062
    time_appconnect:  0.000
   time_pretransfer:  0.062
      time_redirect:  0.000
 time_starttransfer:  0.172
                    ----------
         time_total:  0.240

从我所看到的,time_starttransfer - time_pretransfer = content_generation所以0.172 - 0.062 = 0.110s.但是,查看日志,Web服务器报告0.044秒,并且request_time从nginx同意(0.045秒).此外,time_connect在curl输出中,我认为应该是延迟,并不是那么大(0.062s).

有趣的是,time_starttransfer - time_connect*2 = 0.048它类似于nginx或龙卷风报道的时间(0.048 vs 0.044).但这种计算不应该是正确的.有谁知道什么是正确的方法来证明chrome开发人员工具/ curl与web服务器/ nginx的响应时间之间的差异？

Answer 1

TL; DR

您正在将苹果与橙子进行比较...检查您的RTD ping.

HTTP请求处理

单个HTTP(S)请求的简化(但仍然非常复杂)步骤集如下:

1. 客户端执行DNS查找以解析URL中的主机名.
2. 客户端建立与主机服务器的TCP连接.
3. 客户端可选地进行TLS协商(仅适用于HTTPS连接).
4. 客户端最终通过连接发送请求 - 此阶段的开始是客户端即将发送第一个字节.
5. Web服务器接收请求并开始处理它.
6. Web服务器开始发送响应.
7. 客户端开始接收它 - 即它接收响应的第一个字节.
8. 服务器继续将数据流式传输到服务器,直到它到达响应的末尾.
9. 客户端接收最后一个数据.

正如您所看到的,Web服务器只知道步骤5到8(因为许多初始连接设置将超出其控制范围),并且只能测量5-6和5-8.但是,客户端知道步骤1到9.此外,它还可以测量完全相反的数据点列表.

网络延迟

任何请求或响应都必须通过网络(通常是用于公共服务的Internet)传输,因此在数据从一台机器传输到另一台机器时会产生延迟.两台机器之间的最短时间(从一台机器到另一台机器再返回)称为往返时间(RTT)或往返延迟(RTD).这会影响所有通信,通常使用类似的工具进行测量ping.

该RTD影响所有通信,并且HTTP请求也不例外,因此它将非常接近上述步骤中步骤4-5和6-7之间的延迟之和.

净结果

把这些全部放在一起,然后,您应该发现curl已经测量了步骤1-4(好,到4的开头)为您返回time_pretransfer.此外,它还为您测量了1-7(同样是7的开头)time_starttransfer.但是,服务器已经测量了5-6的时间.

你错过了4-5到6-7之间的时间,我们上面看到的基本上是RTD.

因此你应该找到 time_starttransfer = time_pretransfer + request_time + RTD