nginx 請求開始時間

背景

用戶反饋廣告主平台上傳視頻滿，在本地嘗試重現，發現上傳一個30M左右的視頻大概花40s左右，多個視頻上傳還是串行，目前前端已經優化為了並行上傳，但一個視頻花費40s的問題還是需要解決，因此就想把每個步驟操作時間都記錄一下排查問題

流程

瀏覽器 --> nginx --> server --> 3rd server

疑問

想在nginx日志配置中找到記錄請求開始時間的變量，發現沒有，一頓查閱得到的信息大致如下：

$time_local -  local time in the Common Log Format（官方文檔，解釋的不清不楚，是請求開始時間？還是請求處理時間？還是寫這個請求日志的時間？）

具體解釋如下：

The $time_local variable contains the time when the log entry is written.

when the HTTP request header is read, nginx does a lookup of the associated virtual server configuration. If the virtual server is found, the request goes through six phases:

server rewrite phase
location phase
location rewrite phase (which can bring the request back to the previous phase)
access control phase
try_files phase
log phase
Since the log phase is the last one, $time_local variable is much more colse to the end of the request than it's start.

意思就是這個$time_local 是很接近請求處理結束時間


那么怎么去拿到request start time呢？ 有這樣的方式，如下：
$msec - $request_time ===   該條請求寫日志時間戳 減去 請求處理時間 ，即請求開始時間


具體log format的變量解釋官方解釋如下：

$request_time – Full request time, starting when NGINX reads the first byte from the client and ending when NGINX sends the last byte of the response body
$upstream_connect_time – Time spent establishing a connection with an upstream server
$upstream_header_time – Time between establishing a connection to an upstream server and receiving the first byte of the response header
$upstream_response_time – Time between establishing a connection to an upstream server and receiving the last byte of the response body
$msec - time in seconds with a milliseconds resolution at the time of the log write

中文版本：

$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 過程時間節點
nginx接收到請求時間點（這里就是我們這次的目的） --> nginx 跟 upstream 建立連接 -- nginx 發送給upstream時間點 -- nginx 接受到upstream的時間點 --  nginx給出response的時間點
  

參考資料

http://www.ttlsa.com/linux/the-nginx-log-configuration/
http://nginx.org/en/docs/http/ngx_http_log_module.html
https://www.nginx.com/blog/using-nginx-logging-for-application-performance-monitoring/#var_upstream_response_time
https://nginx.org/en/docs/http/ngx_http_upstream_module.html?&_ga=2.132295757.2109258733.1589278738-1303059860.1589278738#var_upstream_response_time
https://serverfault.com/questions/532560/how-to-log-the-start-time-of-a-request-in-nginx/859293