Nginx的upstream_response_time
前幾日為了查看FPM的性能，在Nginx的配置里增加FPM響應時間的header:
http {...server {...location ~ \.php$ {...add_header X-Upstream-Time $upstream_response_time;}} }今天閑來查看網(wǎng)頁的響應頭，發(fā)現(xiàn)值與預期的不一致：
要說153毫秒我是相信的，那么數(shù)值的單位是納秒。但這不符合常理：1. 印象中upstream_response_time的單位是毫秒；2. 如果單位是納秒，就不應該有小數(shù)點，精度沒這么高（從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）建立連接開始到接收完內(nèi)容花費的時間，單位為毫秒。所以理解沒有錯，那么錯在什么地方呢？
所以Nginx版本的bug？試了另外幾個版本，情況一致。
搜索"nginx upstream_response_time"，出現(xiàn)的內(nèi)容基本上是request_time和upstream_response_time的區(qū)別。這些博文中提到的定義，與上面理解的也是一樣的。<https://www.nginx.com>是官方提供付費商業(yè)支持的站點，根據(jù)其站點上"Using NGINX Logging for Application Performance Monitoring"這篇博文，這個值是靠譜的（坑社區(qū)也就算了，不能坑給錢的上帝吧）。
再仔細琢磨這個值，發(fā)現(xiàn)怎么有點像時間戳啊？！馬上用PHP驗證一下：
php -a echo date('Y-m-d H:i:s', 1535347303.280);PHP shell輸出"2018-08-27 13:21:43"，證明其就是時間戳。
沒給預期的上游處理時間，給一個時間戳算什么事？接續(xù)Google "nginx upstream_response_time timestamp"，結(jié)果列表第一個標題似乎就是我的疑問："Re: nginx report a timestamp on upstream_response_time"。點進去一看，是官方郵件組中某個討論的回復自動貼在了官方論壇上。除了知道upstream_response_time初始化為當前值（ngx_timeofday()），暫無對問題解惑的有用信息。
繼續(xù)往下翻，馬上就看到了有人在OpenResty提出的issue：[bug] the upstream-response-time value is wrong #206。根據(jù)Nginx與OpenResty的關(guān)系，這個issue肯定值得看看。章亦春大佬對該issue的回復（也是對upstream_response_time是時間戳的解答）是：
所以upstream_response_time在header中不準確的原因是：其值在log階段(NGX_HTTP_LOG_PHASE)才會正確生成，發(fā)送響應頭處于內(nèi)容生產(chǎn)階段(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配置，刷新網(wǎng)頁然后查看日志，每一行最后一列就是我們想要的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"參考
總結(jié)
以上是生活随笔為你收集整理的Nginx的upstream_response_time的全部內(nèi)容，希望文章能夠幫你解決所遇到的問題。
- 上一篇： 洛谷P2518 [HAOI2010]计数
- 下一篇： 第一篇:Django基础