为 Nginx 启用带请求消耗时间的 access log

我是用 Nginx 作为 Proxy 来跑 Web Server 的,最近想做一件事情,就是 Profile 一下我的 Web Server 的运行状况,其中一个基本的点就是:性能。在参考了一些资料后,我打算先从 Web Server 的请求时间做起来。

默认情况下,Nginx 的 access log 是不会显示请求时间(request time)的,这需要我们给它的配置文件自定义一下 log format。

编辑 /etc/nginx/nginx.conf,在 http 那块配置里面,加上如下代码:

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

然后,在具体的 nginx server 配置里的 access_log 后面,加上一句 timed_combined 即可:

access_log /path/to/access.log timed_combined;

这样,在 access_log 的最后一行,就会出现 0.xxx (单位秒)的数据出现,代表 Nginx 从收到客户端请求、到发送完响应的整个时间,叫 request_time

于是这里会有一个问题冒出来,如果 Nginx 本身接受用户请求花了比较久的时间,比如用户 POST 比较大的文件数据,那么少说得好几秒吧,这时 request_time 就反应不了后端 Upstream 的运行情况了。所以这里建议再同时启用一个:upstream_response_time

这个 upstream_response_time 很明白,就是在 Nginx 接受完 client 的请求后,再和 upstream server 请求的过程,这个指标才能真正反应 upstream server 的响应情况,虽然通常它的值会和 request_time 一样,但是也强烈建议加上。

所以新的 log_format 如下:

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

加好以后,来软启动一下 Nginx,以下 tip 复制自 Nginx 官网 Log Rotation

$ mv access.log access.log.0
$ kill -USR1 `cat master.nginx.pid`
$ sleep 1
$ gzip access.log.0    # do something with access.log.0

最后,等新的 access.log 产生以后,过个一段时间,你就可以用来分析 Web Server 的性能了。

<推广> 奇点 是一个为 iOS 设计的第三方微博客户端,拥有高效、无广告、标准的时间等设计,让你再次爱上刷微博的感觉。

7 Comments

有啥比较好的汇总access.log的工具推荐吗?

tualatrix 回复 @石樱灯笼

我也正在了解中,了解好了再写文章。

石樱灯笼 回复 @tualatrix

有结论之后一定要写啊。 我自己测过不少类似工具,但是都不好用。我甚至都想自己写一个分析工具了,但是完全没有时间。

石樱灯笼 回复 @tualatrix

几个月过去了,有结论了么?

vehiclee 回复 @石樱灯笼

goaccess

拖鞋门吹雪

timed_combined=>time_combined

Leave a Comment