nginx log记录请求响应时间

2018.10.22 阿里云对默认nginx log的分析功能详细介绍。

有时为了方便分析接口性能等，须要记录请求的时长，经过修改nginx的日志格式能够作到，如

添加一个新的log_format

log_format  timed_combined  '$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';

 而后引用这个新的日志格式

access_log  /var/log/nginx/access.log  timed_combined;

几个时间变量的解释

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

若是使用是阿里云，就能够使用他们的日志服务，方便的查询到各执行时间了，以下图：

后记：

2019.9.25 注意，并发请求时，时间有可能会累计，致使对单个请求的时长统计并不许确。

2019.9.26 这个时间跟请求的客户端网速有关系，不是纯的内部处理时长。若是请求客户端网速越慢，时长越大。并且若是你没有使用upstream配置，返回的也是整个请求的处理时长（亦跟客户端网速有关）。

Nginx还支持自定义时间参数的下钻功能，只要在http头上添加相关头字段，并在log_format配置上就能够提取获得了。如在php代码中输出响应头db_read_time，而后在Nginx.conf配置log_format记录此头的值，如

log_format main 'app_db_read_time=$upstream_http_db_read_time '

参考

https://www.nginx.com/blog/using-nginx-logging-for-application-performance-monitoring/#var_upstream_response_time

https://lincolnloop.com/blog/tracking-application-response-time-nginx/

https://www.nginx.com/blog/using-nginx-logging-for-application-performance-monitoring/