博客
关于我
强烈建议你试试无所不能的chatGPT,快点击我
Nginx的upstream_response_time
阅读量:6414 次
发布时间:2019-06-23

本文共 2595 字,大约阅读时间需要 8 分钟。

转载请注明文章出处:

前几日为了查看FPM的性能,在Nginx的配置里增加FPM响应时间的header:

http {  ...  server {    ...    location ~ \.php$ {      ...      add_header X-Upstream-Time $upstream_response_time;    }  }}复制代码

今天闲来查看网页的响应头,发现值与预期的不一致:

要说153毫秒我是相信的,那么数值的单位是纳秒。但这不符合常理:1. 印象中upstream_response_time的单位是毫秒;2. 如果单位是纳秒,就不应该有小数点,精度没这么高(从L1缓存取个值就要0.5~1纳秒,从寄存器取值差不多也要个0.2纳秒)。

难道是我对upstream_response_time理解错了?翻看Nginx官方文档,对该变量的解释是:

$upstream_response_time   keeps time spent on receiving the response from the upstream server; the time is kept in seconds with millisecond resolution. Times of several responses are separated by commas and colons like addresses in the $upstream_addr variable.复制代码

翻译过来:upstream_response_time是与上游(FPM)建立连接开始到接收完内容花费的时间,单位为毫秒。所以理解没有错,那么错在什么地方呢?

所以Nginx版本的bug?试了另外几个版本,情况一致。

搜索"nginx upstream_response_time",出现的内容基本上是request_timeupstream_response_time的区别。这些博文中提到的定义,与上面理解的也是一样的。<https://www.nginx.com>是官方提供付费商业支持的站点,根据其站点上这篇博文,这个值是靠谱的(坑社区也就算了,不能坑给钱的上帝吧)。

再仔细琢磨这个值,发现怎么有点像时间戳啊?!马上用PHP验证一下:

php -aecho date('Y-m-d H:i:s', 1535347303.280);复制代码

PHP shell输出"2018-08-27 13:21:43",证明其就是时间戳。

没给预期的上游处理时间,给一个时间戳算什么事?接续Google "nginx upstream_response_time timestamp",结果列表第一个标题似乎就是我的疑问:"Re: nginx report a timestamp on upstream_response_time"。点进去一看,是官方邮件组中某个讨论的回复自动贴在了官方论坛上。除了知道upstream_response_time初始化为当前值(ngx_timeofday()),暂无对问题解惑的有用信息。

继续往下翻,马上就看到了有人在OpenResty提出的issue:。根据Nginx与OpenResty的关系,这个issue肯定值得看看。章亦春大佬对该issue的回复(也是对upstream_response_time是时间戳的解答)是:

所以upstream_response_time在header中不准确的原因是:其值在log阶段(NGX_HTTP_LOG_PHASE)才会正确生成,发送响应头处于内容生产阶段(NGX_HTTP_CONTENT_PHASE),期间获取到的值是初始化的时间戳,符合预期。

要正确打印其值,可在日志格式中声明:

http {  ...  log_format  main  '$remote_addr - $remote_user [$time_local] "$request" '        '$status $body_bytes_sent "$http_referer" '        '"$http_user_agent" "$http_x_forwarded_for" "$request_time" "$upstream_response_time"';}复制代码

重新加载Nginx配置,刷新网页然后查看日志,每一行最后一列就是我们想要的upstream_response_time

xxxx - - [27/Aug/2018:14:20:13 +0800] "GET xxx HTTP/1.1" 200 7659 "xxx" "Mozilla/5.0 (iPhone; CPU iPhone OS 10_2_1 like Mac OS X) AppleWebKit/602.4.6 (KHTML, like Gecko) Mobile/14D27 MicroMessenger/6.5.5 NetType/WIFI Language/zh_CN" "-" "0.000" "-"xxx - - [27/Aug/2018:14:20:16 +0800] "GET xxx HTTP/1.1" 200 423 "xxx" "Mozilla/5.0 (iPhone; CPU iPhone OS 10_2_1 like Mac OS X) AppleWebKit/602.4.6 (KHTML, like Gecko) Mobile/14D27 MicroMessenger/6.5.5 NetType/WIFI Language/zh_CN" "-" "0.000" "-"xxx - - [27/Aug/2018:14:20:29 +0800] "GET / HTTP/1.0" 200 6775 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/34.0.1847.131 Safari/537.36" "-" "0.185" "0.010"复制代码

参考

你可能感兴趣的文章
Spring 注入bean时的初始化和销毁操作
查看>>
java线程同步原理(lock,synchronized)
查看>>
MyEclipse中使用Hql编辑器找不到Hibernate.cfg.xml文件解决方法
查看>>
yRadio以及其它
查看>>
第四节 对象和类
查看>>
闪迪(SanDisk)U盘防伪查询(官方网站)
查看>>
Android onMeasure方法介绍
查看>>
无锁数据结构
查看>>
MySQL的变量查看和设置
查看>>
android onNewIntent
查看>>
XML特殊符号
查看>>
kaptcha可配置项
查看>>
JavaMail邮箱验证用户注册
查看>>
系统时间——ntpd
查看>>
反射实现AOP动态代理模式(Spring AOP实现原理)
查看>>
Spring MVC 4.x + fastjson 1.2.7,封装的List<?>参数
查看>>
js选中问题
查看>>
protobuf
查看>>
4.Java基础复习--Set
查看>>
七:Mysql的乐观锁与悲观锁机制
查看>>