五一上线了一个小的预约程序，配置通过Nginx进行访问入口，默认的日志是没有请求时间的，因此需要配置一下，将每一次的请求的访问响应时间记录出来，备查与优化使用.

一、默认的日志格式

默认的日志格式如下(默认是注解掉的，系统也自动会使用)：

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

    #access_log  logs/access.log  main;

二、我使用的日志格式

我仅仅在默认的基础上加上响应时间的两个我较关心的参数：request_time与upstream_response_time 将以下的配置开放并修改(我后面用了格式2，时间在前面，容易查看)：

带时间数据参数的日志格式1

log_format  main  $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  logs/access.log  main;

调整了下时间参数的显示顺序的格式2:

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

    access_log  logs/access.log  main;

注意的是：log_format与access_log的注释都要放开，仅放开log_format也是不生效的.

#设置成格式2后，可以用相应的正则表达式，查看大于1秒的日志，分两步如下：

##1.高亮时间数据的正则表达式
tail -f access.log |grep "[[0-9].[0-9][0-9][0-9] [0-9].[0-9][0-9][0-9]]"

##2.大于1秒的日志的正则表达式,即将第一个数字改成[1-9]即可
tail -f access.log |grep "[[1-9].[0-9][0-9][0-9] [0-9].[0-9][0-9][0-9]]"

三、参数

说明

四、测试效果

修改前默认日志

127.0.0.1 - - [03/May/2022:12:02:51 +0800] "GET /byhsyyfront/byPages/ HTTP/1.1" 304 0 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/99.0.4844.51 Safari/537.36"
127.0.0.1 - - [03/May/2022:12:02:51 +0800] "GET /byhsyyGateway/byhsyySystem/verifyCode/getVerifyCode HTTP/1.1" 200 2553 "http://localhost:8881/byhsyyfront/byPages/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/99.0.4844.51 Safari/537.36"

修改后日志

127.0.0.1 - - [03/May/2022:12:00:47 +0800] "GET /byhsyyfront/byPages/ HTTP/1.1" 304 0 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/99.0.4844.51 Safari/537.36" "-" "0.025" "0.025"
127.0.0.1 - - [03/May/2022:12:00:47 +0800] "GET /byhsyyGateway/byhsyySystem/verifyCode/getVerifyCode HTTP/1.1" 200 2178 "http://localhost:8881/byhsyyfront/byPages/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/99.0.4844.51 Safari/537.36" "-" "0.037" "0.037"

可以看到修改后的最后多了两个关于时间的参数数据，可以用于响应时间快慢分析.