轉載請注明文章出處：https://tlanyan.me/upstream_r...

前幾日為了查看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_timekeeps 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_time和upstream_response_time的區別。這些博文中提到的定義，與上面理解的也是一樣的。<https://www.nginx.com>是官方提供付費商業支持的站點，根據其站點上"Using NGINX Logging for Application Performance Monitoring"這篇博文，這個值是靠譜的（坑社區也就算了，不能坑給錢的上帝吧）。

再仔細琢磨這個值，發現怎么有點像時間戳啊？！馬上用PHP驗證一下：

php -a echo 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：[bug] the upstream-response-time value is wrong #206。根據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"

參考

http://nginx.org/en/docs/http...

https://www.nginx.com/blog/us...

https://forum.nginx.org/read....

https://github.com/openresty/...

https://blog.csdn.net/qinyush...

總結

以上是生活随笔為你收集整理的Nginx的upstream_response_time的全部內容，希望文章能夠幫你解決所遇到的問題。

如果覺得生活随笔網站內容還不錯，歡迎將生活随笔推薦給好友。