背景
用户反馈广告主平台上传视频满，在本地尝试重现，发现上传一个30M左右的视频大概花40s左右，多个视频上传还是串行，目前前端已经优化为了并行上传，但一个视频花费40s的问题还是需要解决，因此就想把每个步骤操作时间都记录一下排查问题
流程
浏览器 –> nginx –> server –> 3rd server
疑问
想在nginx日志配置中找到记录请求开始时间的变量，发现没有，一顿查阅得到的信息大致如下：
|
1 2 |
<pre class="inline:true class:language-bash hljs decode:1 " ><span class="hljs-variable">$time_local</span> - <span class="hljs-built_in">local</span> time <span class="hljs-keyword">in</span> the Common Log Format（官方文档，解释的不清不楚，是请求开始时间？还是请求处理时间？还是写这个请求日志的时间？） |
具体解释如下：
|
1 2 3 4 5 6 7 8 9 10 11 12 |
<pre class="inline:true class:language-bash hljs decode:1 " >The <span class="hljs-variable">$time_local</span> variable contains the time when the <span class="hljs-built_in">log</span> entry is written. when the HTTP request header is <span class="hljs-built_in">read</span>, 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 (<span class="hljs-built_in">which</span> can bring the request back to the previous phase) access control phase try_files phase <span class="hljs-built_in">log</span> phase Since the <span class="hljs-built_in">log</span> phase is the last one, <span class="hljs-variable">$time_local</span> variable is much more colse to the end of the request than it<span class="hljs-string">'s start. </span> |
意思就是这个$time_local 是很接近请求处理结束时间
那么怎么去拿到request start time呢？ 有这样的方式，如下：
$msec – $request_time === 该条请求写日志时间戳 减去 请求处理时间 ，即请求开始时间
具体log format的变量解释官方解释如下：
|
1 2 3 4 5 6 |
<pre class="inline:true class:language-bash hljs decode:1 " ><span class="hljs-variable">$request_time</span> – 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 <span class="hljs-variable">$upstream_connect_time</span> – Time spent establishing a connection with an upstream server <span class="hljs-variable">$upstream_header_time</span> – Time between establishing a connection to an upstream server and receiving the first byte of the response header <span class="hljs-variable">$upstream_response_time</span> – Time between establishing a connection to an upstream server and receiving the last byte of the response body <span class="hljs-variable">$msec</span> - time <span class="hljs-keyword">in</span> seconds with a milliseconds resolution at the time of the <span class="hljs-built_in">log</span> write |
中文版本：
|
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 |
<pre class="inline:true class:language-bash hljs decode:1 " ><span class="hljs-variable">$remote_addr</span>, <span class="hljs-variable">$http_x_forwarded_for</span> 记录客户端IP地址 <span class="hljs-variable">$remote_user</span> 记录客户端用户名称 <span class="hljs-variable">$request</span> 记录请求的URL和HTTP协议 <span class="hljs-variable">$status</span> 记录请求状态 <span class="hljs-variable">$body_bytes_sent</span> 发送给客户端的字节数，不包括响应头的大小； 该变量与Apache模块mod_log_config里的“%B”参数兼容。 <span class="hljs-variable">$bytes_sent</span> 发送给客户端的总字节数。 <span class="hljs-variable">$connection</span> 连接的序列号。 <span class="hljs-variable">$connection_requests</span> 当前通过一个连接获得的请求数量。 <span class="hljs-variable">$msec</span> 日志写入时间。单位为秒，精度是毫秒。 <span class="hljs-variable">$pipe</span> 如果请求是通过HTTP流水线(pipelined)发送，pipe值为“p”，否则为“.”。 <span class="hljs-variable">$http_referer</span> 记录从哪个页面链接访问过来的 <span class="hljs-variable">$http_user_agent</span> 记录客户端浏览器相关信息 <span class="hljs-variable">$request_length</span> 请求的长度（包括请求行，请求头和请求正文）。 <span class="hljs-variable">$request_time</span> 请求处理时间，单位为秒，精度毫秒； 从读入客户端的第一个字节开始，直到把最后一个字符发送给客户端后进行日志写入为止。 <span class="hljs-variable">$time_iso8601</span> ISO8601标准格式下的本地时间。 <span class="hljs-variable">$time_local</span> 通用日志格式下的本地时间。 |
参考资料
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
Views: 24