我的服务器端架构,是一个nginx+4个python的tornado服务,nginx做负载均衡,我在nginx中使用以下日志来记录每次请求的服务器端处理时间:
log_format mylog '$remote_addr - $remote_user [$time_local] '
' "$request $status cost:$request_time" $body_bytes_sent '
' "$http_referer" "$http_user_agent" "$http_host" ';
其中:$request_time表示每次请求的耗费时间(秒)
但是我发现这个时间和tornado端打印出来的时间存在一个数量级的差距,,nginx显示几百毫秒,而对应接口在tornado端只用了几十毫秒
以下为tornado端日志
2015-11-23 11:00:09,586:web.py:log_request:[line:1816] INFO 200 GET /posts_act (144.0.8.123) 23.29ms
以下为nginx端日志:
"GET /posts_act HTTP/1.1 200 cost:1.346"
"GET /posts_act HTTP/1.1 200 cost:0.116"
请问,我应该以哪个为准,,为什么相差这么大?如何做到统一,至少不会差距这么大?也妨碍了我进行系统监控,不知道问题出在nginx还是tornado
$request_time和$upstream_response_time之间差别:
$request_time包含了用户数据接收时间,而真正程序的响应时间应该用$upstream_response_time
下面介绍下2者的差别:
1、request_time
官网描述:request processing time in seconds with a milliseconds resolution; time elapsed between the first bytes were read from the client and the log write after the last bytes were sent to the client 。
指的就是从接受用户请求的第一个字节到发送完响应数据的时间,即包括接收请求数据时间、程序响应时间、输出
响应数据时间。
2、upstream_response_time
官网描述:keeps times of responses obtained from upstream servers; times are kept in seconds with a milliseconds resolution. Several response times are separated by commas and colons like addresses in the $upstream_addr variable
http://blog.sina.com.cn/s/blog_4f9fc6e10102uxib.html