How to log Application Response Time with Nginx

Edit the nginx.conf file

sudo vi /etc/nginx/nginx.conf

and add the following log format under http > Logging Settings

log_format apm '"$time_local" client=$remote_addr '
               'method=$request_method request="$request" '
               'request_length=$request_length '
               'status=$status bytes_sent=$bytes_sent '
               'body_bytes_sent=$body_bytes_sent '
               'referer=$http_referer '
               'user_agent="$http_user_agent" '
               'upstream_addr=$upstream_addr '
               'upstream_status=$upstream_status '
               'request_time=$request_time '
               'upstream_response_time=$upstream_response_time '
               'upstream_connect_time=$upstream_connect_time '
               'upstream_header_time=$upstream_header_time';

Now use this newly created apm log format in for your site like below

server {
    ...
    ...
    access_log /var/log/nginx/your-website.com.log apm;
    ...
    ...
}

After changing the server config, restart your Nginx

sudo systemctl restart nginx

After restart you will start seeing the detailed logs as defined in apm log_format, you can check the response time in upstream_response_time field. Following is a sample log statement

"15/Sep/2017:18:14:33 +0000" client=xxx.xxx.xx.xxx method=GET request="GET / HTTP/1.1" request_length=827 status=200 bytes_sent=8279 body_bytes_sent=8009 referer=- user_agent="Mozilla/5.0 (Macintosh; Intel Mac OS X 10_12_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/60.0.3112.113 Safari/537.36" upstream_addr=127.0.0.1:xxxx upstream_status=200 request_time=0.005 upstream_response_time=0.005 upstream_connect_time=0.000 upstream_header_time=0.005

In the log you can see that the upstream_response_time=0.005 means server took 5 milliseconds to serve that perticular request.