配置nginx，Tomcat日志记录请求耗时

由于公司的业务比较特殊，对速度比较在意，客户最近反应我们的平台时间比较久，处理一个请求十秒左右才返回，领导要求找出原因，我想让nginx日志记录请求处理用了多长时间，后端处理用了多长时间，总共用了多长时间，哪里出现的瓶颈好进行针对性解决

配置nginx统计请求和后端服务Tomcat服务响应时间

编辑nginx的配置文件nginx.conf

log_format main '$remote_addr - $remote_user [$time_local] "$request" '
           '$status $body_bytes_sent "$http_referer" '
           '"$http_user_agent" "$http_x_forwarded_for" "$upstream_response_time" "$request_time"';

上面的日志是我找的默认形式的，在你原先的日志基础就加入两点即可

$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 。

说明：就是指从接受用户的第一个字节到发送完响应数据的时间，即包括接收请求数据时间、程序响应时间、输出响应时间等

$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

说明：是指从nginx向后端建立连接开始到后端处理完数据然后关闭连接为止的时间

从上面的描述可以看出$request_time可能会比$upstream_response_time值大一点，特别是使用POST方式传递参数时，因为nginx会把request body缓存住，接受完毕后才会把数据一起发送给后端。所以如果用户网络较差，或者传递数据较大时，$request_time会比$upstream_response_time的值大很多

Tomcat：

Tomcat则是通过改server.xml的日志格式%D %T统计请求响应时间

        <Valve className="org.apache.catalina.valves.AccessLogValve" directory="logs"
               prefix="localhost_access_log." suffix=".txt"
               pattern="%h %l %u %t "%r" %s %b %D %F" />

%D - 官方解释：Time taken to process the request, in millis，处理请求的时间，以毫秒为单位

%T - 官方解释：Time taken to process the request, in seconds，处理请求的时间，以秒为单位

%F - 官方解释：Time taken to commit the response, in millis，提交响应的时间，以毫秒为单位

详细说明：http://tomcat.apache.org/tomcat-7.0-doc/config/valve.html#Access_Logging

使用awk文本处理命令辅助统计access.log

统计nginx访问日志access.log的每分钟请求数

awk -F: '{count[$2":"$3]++} END {for (minute in count) print minute, count[minute]}' ./access.log | sort > count.log

[root@60 logs]# cat count.log 
01:18  102
01:38  77
02:10  53
02:20  89
02:28  66
02:43  123
02:44  44
02:48  53
03:12  26
04:07  90
04:09  21
············

统计请求响应时间超过10秒的记录

awk '($NF > 10){print $0}' ./access.log > t10_20180525.log