request_time和upstream_response_time的区别

定义

一个正常的请求过程如下:

  1. 用户发出请求
  2. 建立NGINX连接
  3. 发送响应
  4. 接收程序的响应数据
  5. 关闭NGINX连接

request_time
request processing time in seconds with a milliseconds resolution; time elapsed between the first bytes were read from the client and the log write after the last bytes were sent to the client.

指的就是从接受用户请求的第一个字节到发送完响应数据的时间,即包括接收请求数据时间、程序响应时间、输出响应数据时间。
对于此部分对应的是1+2+3+4+5。

upstream_response_time
keeps times of responses obtained from upstream servers; times are kept in seconds with a milliseconds resolution. Several response times are separated by commas and colons like addresses in the $upstream_addr variable.
是指从Nginx向后端(php-cgi)建立连接开始到接受完数据然后关闭连接为止的时间。
对于此部分对应的是2+3+4+5。

从上面的描述可以看出,$request_time肯定大于等于$upstream_response_time,特别是使用POST方式传递参数时,因为Nginx会把request body缓存住,接受完毕后才会把数据一起发给后端。所以如果用户网络较差,或者传递数据较大时,$request_time会比$upstream_response_time大很多。

如果要从access_log中查看较慢的接口的话,可以在log_format中加入$upstream_response_time

分析

从网上看到下列一组图片,感觉画的很形象。

  • request_time是从接收到客户端的第一个字节开始,到把所有的响应数据都发送完为止。
    1637907742862.png
  • upstream_response_time是从与后端建立TCP连接开始到接收完响应数据并关闭连接为止。
    1637907762851.png

所以,request_time会大于等于upstream_response_time

性能优化

对于较高的request—_time很可能是由于连接速度较慢的客户端造成的,对此无能为力,但是较高的request_time并不代表服务器或者程序的性能不够。总体来说,没必要在request_time上花费较多时间,而是应该重点关注upstream_response_time。

nginx log_format

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
$remote_addr,$http_x_forwarded_for  #记录客户端IP地址
$remote_user #记录客户端用户名称
$request #记录请求的URL和HTTP协议
$status #记录请求状态
$body_bytes_sent #发送给客户端的字节数,不包括响应头的大小;该变量与Apache模块mod_log_config李的“%B”参数兼容
$bytes_sent #发送给客户端的总字节数
$connection #连接到序列号
$connection_requests #当前通过一个链接获得的请求数量
$msec #日志写入时间,单位为秒精度是毫秒。
$pipe #如果请求是通过HTTP流水线(pipelined)发送,pipe值为“p”,否则为".".
$http_referer #记录从那个页面链接访问过来的
$http_user_agent #记录客户端浏览器相关信息
$request_length #请求的长度(包括请求行,请求头和请求正文)。
$request_time #请求处理时间,单位为秒,精度毫秒;从读入客户端的第一个字节开始,知道把最后一个字符发送给客户端后进行日志写入位置。
$time_iso8601 ISO8601标准格式下的本地时间
$time_local #通用日志格式下的本地时间

NGINX的文件传输

sendile

参数sendfile on 用于开启文件高效传输模式,同时配合tcp_nopush on 和tcp_nodelay on 两个指令,可防止网络及磁盘I/O阻塞,提升Nginx工作效率。但需要注意的是,linux内核版本2.5.9以后的版本中两者是可以兼容的。

三个指令都开启的好处是,sendfile可以开启高效的文件传输模式,tcp_nopush开启可以确保在发送到客户端之前数据包已经充分“填满”, 这大大减少了网络开销,并加快了文件发送的速度。 然后,当它到达最后一个可能因为没有“填满”而暂停的数据包时,Nginx会忽略tcp_nopush参数, 然后,tcp_nodelay强制套接字发送数据。

1637918539854.png

tcp_nopush

当有数据时,先别着急发送, 确保数据包已经装满数据, 避免了网络拥塞。需要我们等到数据量达到最大时才通过网络一次发送全部数据,这种数据传输方式有益于大量数据的通信性能,典型的应用就是文件服务器。
对于nginx配置文件中的tcp_nopush,默认就是tcp_nopush,不需要特别指定,这个选项对于www,ftp等大文件很有帮助。

tcp_nodelay

有时要抓紧发货, 确保数据尽快发送, 提高可数据传输效率。

总结

平时对request_time和upstream_response_time这两个参数没什么研究,关注的不多,主要关注request_time。但是最近阿里云的日志服务统计数据出现了异常,request_time和upstream_response_time的值完全违反了字段定义的原则。理论上request_time无论如何也会大于upstream_response_time的,但是客服死活不承认。无奈之下,好好研究一番,通过阿里云官网文档截图和历史正常数据已经现在的异常数据,客服最终承认存在问题,表示整改。
事实证明,阿里云的客服技术水平也是良莠不齐。

经过此次事件,也遇到了一些Markdown语法的问题,不过幸运的是vs code提供了很多帮助,能直接定位到问题,而对应的问题都有参考方案。

参考

------ 本文结束 ------

版权声明

Medivh's Notes by Medivh is licensed under a Creative Commons BY-NC-ND 4.0 International License.
Medivh创作并维护的Medivh's Notes博客采用创作共用保留署名-非商业-禁止演绎4.0国际许可证
本文首发于Medivh 博客( http://www.mknight.cn ),版权所有,侵权必究。